Report this

What is the reason for this report?

Long timeouts with sudo and systemctl

Posted on December 25, 2019

Here is my system:

bill@Bill2:~$ lsb_release -a LSB Version: core-9.20170808ubuntu1-noarch:security-9.20170808ubuntu1-noarch Distributor ID: Ubuntu Description: Ubuntu 18.10 Release: 18.10 Codename: cosmic

My Droplet has been running very smoothly for many months. I do a lot of software development on it as well as hosting a minimal web site. Suddenly, this morning (Christmas morning, can you believe it), things started going haywire. Specifically, the sudo command now has a very long timeout, and systemctl does the same.

Here is a timed example of a simple systemctl command:

bill@Bill2:~$ time systemctl status caddy.service Failed to get properties: Connection timed out

real 1m30.065s user 0m0.003s sys 0m0.007s

Notice the 1 1/2 minute time out. Also, note the weak reference to a connection timing out (there is no indication of what connection that is).

Here is an example of a simple application of sudo:

bill@Bill2:~$ time sudo ls /root [sudo] password for bill: Desktop Documents Downloads Music Pictures Public Templates Videos snap

real 1m41.903s user 0m0.010s sys 0m0.009s

Again notice the long timeout. Below is a simple attempt to use strace for additional information. I have just included the tail end of the strace output because it refers to a timeout while attempting to access a server.

bill@Bill2:~$ strace systemctl status … writev(2, [{iov_base=“Failed to read server status: Co”…, iov_len=50}, {iov_base=“\n”, iov_len=1}], 2) = 51 close(3Failed to read server status: Connection timed out ) = 0 dup2(6, 1) = 1 close(6) = 0 dup2(7, 2) = 2 close(7) = 0 kill(7853, SIGCONT) = 0 waitid(P_PID, 7853, {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=7853, si_uid=1000, si_status=0, si_utime=0, si_stime=0}, WEXITED, NULL) = 0 — SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=7853, si_uid=1000, si_status=0, si_utime=0, si_stime=0} — exit_group(0) = ? +++ exited with 0 +++

Here is a strace example of a simple ls command:

bill@Bill2:~$ strace ls /root … sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=“\0AUTH EXTERNAL “, iov_len=15}, {iov_base=“31303030”, iov_len=8}, {iov_base=”\r\nNEGOTIATE_UNIX_FD\r\nBEGIN\r\n”, iov_len=28}], msg_iovlen=3, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 51 gettid() = 8146 getrandom(“\x93\xcd\x9d\x13\x0d\x32\xdd\x75\x57\x69\x54\x30\x3d\x9e\xfd\xb0”, 16, GRND_NONBLOCK) = 16 gettid() = 8146 ioctl(1, TCGETS, {B38400 opost isig icanon echo …}) = 0 ioctl(2, TCGETS, {B38400 opost isig icanon echo …}) = 0 ioctl(1, TIOCGWINSZ, {ws_row=35, ws_col=100, ws_xpixel=0, ws_ypixel=0}) = 0 ioctl(1, TIOCGWINSZ, {ws_row=35, ws_col=100, ws_xpixel=0, ws_ypixel=0}) = 0 pipe2([4, 5], O_CLOEXEC) = 0 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fbd25671c10) = 8147 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 fcntl(1, F_DUPFD_CLOEXEC, 3) = 6 dup2(5, 1) = 1 fcntl(2, F_DUPFD_CLOEXEC, 3) = 7 dup2(5, 2) = 2 close(4) = 0 close(5) = 0 prlimit64(0, RLIMIT_NOFILE, {rlim_cur=161024, rlim_max=161024}, NULL) = 0 uname({sysname=“Linux”, nodename=“Bill2”, …}) = 0 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=89, tv_nsec=997330000}, NULL, 8

While watching the output I noticed the terminal cursor sitting on the ppoll system call as if the sudo software, or some library, is waiting for an Internet response. I also notice a reference to OAUTH at the beginning of the dump.

I will continue to investigate, but I think I’m going to need your help.

The developer cloud

Scale up as you grow — whether you're running one virtual machine or ten thousand.

Start building today

From GPU-powered inference and Kubernetes to managed databases and storage, get everything you need to build, scale, and deploy intelligent applications.