0

I am running into this issue where the first time I run sudo the command takes about 30 seconds before it will prompt me for my password. (NOTE: after I have entered my password, all the following sudo commands run instantly)

I have gotten as far as running the below commands:

# As Root
chmod u+s /usr/bin/strace

# As My User
strace -r -o trace1.log sudo echo hi

Which did show me where the slowdown is happening. The problem is that the log is a little beyond my understanding. Here is what the log says:

 0.000039 read(11, "AGREE_UNIX_FD\r\n", 2048) = 15
 0.000038 poll([{fd=11, events=POLLOUT}], 1, -1) = 1 ([{fd=11, revents=POLLOUT}])
 0.000036 sendto(11, "BEGIN\r\n", 7, MSG_NOSIGNAL, NULL, 0) = 7
 0.000085 poll([{fd=11, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=11, revents=POLLOUT}])
 0.000054 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\0\0\0\0\1\0\0\0n\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=128}, {iov_base="", iov_len=0}], msg_iovlen=2, msg_controllen=0, msg_flags=0},              MSG_NOSIGNAL) = 128
 0.000539 poll([{fd=11, events=POLLIN}], 1, 25000) = 1 ([{fd=11, revents=POLLIN}])
 0.000060 recvmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\2\1\1\v\0\0\0\1\0\0\0=\0\0\0\6\1s\0\6\0\0\0:1.834\0\0"..., iov_len=2048}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) =   262
 0.000086 recvmsg(11, {msg_namelen=0}, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
 0.000050 eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK) = 12
 0.000039 fstat(11, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
 0.000032 fcntl(11, F_GETFL)        = 0x802 (flags O_RDWR|O_NONBLOCK)
 0.000145 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\1\1\204\0\0\0\2\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=144}, {iov_base="\177\0\0\0type='signal',sender='net.re"..., iov_len=132}],            msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 276
 0.000245 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\1\1\246\0\0\0\3\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=144}, {iov_base="\241\0\0\0type='signal',sender='org.fr"..., iov_len=166}],            msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 310
 0.000239 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\33\0\0\0\4\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=144}, {iov_base="\26\0\0\0net.reactivated.Fprint\0", iov_len=27}], msg_iovlen=2,        msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 171
 0.000250 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\0\0\0\0\5\0\0\0\203\0\0\0\1\1o\0\37\0\0\0/net/rea"..., iov_len=152}, {iov_base="", iov_len=0}], msg_iovlen=2, msg_controllen=0, msg_flags=0},           MSG_NOSIGNAL) = 152
 0.005535 poll([{fd=11, events=POLLIN}], 1, 25000) = 1 ([{fd=11, revents=POLLIN}])
 0.000064 recvmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\3\1\1G\0\0\0\3\0\0\0u\0\0\0\6\1s\0\6\0\0\0:1.834\0\0"..., iov_len=2048}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) =    207
 0.000099 write(12, "\1\0\0\0\0\0\0\0", 8) = 8
 0.000038 recvmsg(11, {msg_namelen=0}, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
 0.000037 poll([{fd=11, events=POLLIN}], 1, 25000) = 1 ([{fd=11, revents=POLLIN}])
24.999999 recvmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\3\1\1c\0\0\0\4\0\0\0m\0\0\0\6\1s\0\6\0\0\0:1.834\0\0"..., iov_len=2048}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) =    227
 0.000096 write(12, "\1\0\0\0\0\0\0\0", 8) = 8
 0.000035 recvmsg(11, {msg_namelen=0}, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
 0.000121 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\1\1\204\0\0\0\6\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=144}, {iov_base="\177\0\0\0type='signal',sender='net.re"..., iov_len=132}],            msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 276
 0.000081 sendmsg(11, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\1\1\246\0\0\0\7\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/fre"..., iov_len=144}, {iov_base="\241\0\0\0type='signal',sender='org.fr"..., iov_len=166}],            msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 310
 0.000151 close(11)                 = 0
 0.000058 close(12)                 = 0
 0.000045 getuid()                  = 1001

My Question: What exactly do these logs mean, and how do I fix sudo taking so long to login?

This is a VM running Fedora 26.

Also, I believe these issues only started occurring after running the following commands as root. So this is more than likely due to do with a permissions issue, but I don't know for sure.

rpm --setperms -a
rpm --setugids -a

Update:

After running journalctl /usr/bin/dbus-daemon I find a bunch of errors like this:

Oct 13 11:25:32 server.example.com dbus-daemon[718]: [system] Activating via systemd: service name='net.reactivated.Fprint' unit='fprintd.service' requested by ':1.848' (uid=0 pid=29713 comm="sudo vim trace.log " label="unconfined_u:unconfined
Oct 13 11:25:57 server.example.com dbus-daemon[718]: [system] Failed to activate service 'net.reactivated.Fprint': timed out (service_start_timeout=25000ms)
Oct 13 11:26:04 server.example.com dbus-daemon[718]: [system] Activating via systemd: service name='net.reactivated.Fprint' unit='fprintd.service' requested by ':1.850' (uid=0 pid=29769 comm="sudo vim trace.log " label="unconfined_u:unconfined
Oct 13 11:26:29 server.example.com dbus-daemon[718]: [system] Failed to activate service 'net.reactivated.Fprint': timed out (service_start_timeout=25000ms)
Oct 13 13:44:07 server.example.com dbus-daemon[718]: [system] Activating via systemd: service name='net.reactivated.Fprint' unit='fprintd.service' requested by ':1.908' (uid=0 pid=31397 comm="sudo vim trace.log " label="unconfined_u:unconfined
Oct 13 13:44:32 server.example.com dbus-daemon[718]: [system] Failed to activate service 'net.reactivated.Fprint': timed out (service_start_timeout=25000ms)
Nicholas Summers
  • 123
  • 5
  • 1
    often such problems are related with DNS/hostname settings on the machine and name resolution problems, sudo among many other commands need a properly set DNS resolving to work fast. Alternatively you can make sure that you have proper entries in `/etc/hosts` for the hostname that you are using (perhaps the hostname has changed and now it cannot be resolved because of missing `/etc/hosts` entry) – bocian85 Oct 13 '17 at 16:00
  • Looking more closely into the strace I believe it might be problem with dbus / systemd conflict / being unresponsive - check for the errors about `org.freedesktop` in your system logs. – bocian85 Oct 13 '17 at 16:03
  • @bocian85 Updateed the post with what I found, does that help? – Nicholas Summers Oct 13 '17 at 17:56
  • It looks like some kind of fingerprint recognition software. It might seem weird, but if you have and ever used some kind of fingerprint enrollment device on this computer try swiping your finger over it after issuing sudo command. If that is not the case, then find a way to disable this service or ban sudo from using it. – bocian85 Oct 13 '17 at 18:05
  • @bocian85 Nevermind, was able to track the issue down. Ultimately `sudo` is looking for a fingerprint reader (on a headless server) but timing out after 25 seconds because it can't find it. I haven't the slightest idea why it would do this by default, but I found a fix here: https://serverfault.com/questions/768839/fprintd-message-no-devices-in-use-exit - While that looks like a completely different problem, the answer given fixes the issue. – Nicholas Summers Oct 13 '17 at 18:08
  • If you want to make a similar answer here, I will give you credit for it. Also, thanks for all your help. – Nicholas Summers Oct 13 '17 at 18:10
  • Thanks, I will make an answer when I get to computer, hard to do formatting from the phone – bocian85 Oct 13 '17 at 19:33
  • Just to add a little something, possibly you don't need to remove the fprintd daemon completely, but just remove its PAM entries... – Zip Oct 15 '17 at 16:33
  • It's a headless server on a VM. It's not ever going to have a fingerprint reader, so removing it works just as well. – Nicholas Summers Oct 15 '17 at 16:35

0 Answers0