8

The first sudo I enter on my Ubuntu 14.04 server is always slow. The password prompt displays immediately, but after I press enter it takes about 10-15 seconds until the output is printed. All sudo commands after this execute instantly.

Running something like sudo strace -S time -c sudo echo hi does not show anything useful in this case, since the sudo from sudo echo hi is already the second sudo and executes fast. If some time passes and I have to re-enter the password in a running session, it is slow again.

All the solutions I found were about adding your hostname as resolution for 127.0.0.1 in the /etc/hosts file, which I did to no avail. su root executes instantly. The only thing I remember changing in the last days is the netmask of a subnet the server is routing, installing samba, dnsutils and bind9. But none of those processes are running and the problem remains, in physical access, ssh sessions as well as tmux sessions.

EDIT: New Approach

I tried running sudo tcpdump -vvvi any > tcpdump.log while having all NIC's disconnected. The log shows a lot of the following:

18:35:09.453399 IP (tos 0x0, ttl 64, id 49112, offset 0, flags [DF], proto UDP (17), length 76)
    localhost.38498 > localhost.domain: [bad udp cksum 0xfe4b -> 0x1050!] 58546+ SRV? _kerberos._udp.KF.OURLOCALDOMAIN.DE. (48)
18:35:09.457412 IP (tos 0x0, ttl 64, id 49113, offset 0, flags [none], proto UDP (17), length 76)
    localhost.domain > localhost.38498: [bad udp cksum 0xfe4b -> 0x8fcd!] 58546 ServFail q: SRV? _kerberos._udp.KF.OURLOCALDOMAIN.DE. 0/0/0 (48)

Same entries show up with tcp instad of udp. I replaced the domain name of our university with OURLOCALDOMAIN.

Now I think kerberos might have something to do with it, but I deleted the /etc/krb5.conf and rebooted, still no change. It seems to me, that the server tries to validate itself on a central kerberos server from our university network. I know that some years prior, this IP was registered to a server that ran samba for our departement. Could there be a connection? I changed my hostname to the one that was used back then, no change in sudo behavior. Lmwangi suggests something about PAM, which i have little knowledge about, so I don't know how to approach this. I also remembered I switched from Heimdal Kerberos to MIT Kerberos when installing samba, because i had troubles during the samba installation. I am also going to try the ideas from the comments in the next days, but I will be traveling for a couple days so it might take some time.

EDIT 2: Solved

There was a legacy dns-search entry in the /etc/network/interfacesthat messed everything up. I feel very stupid. Everything works now.

  • 1
    Temporarily setting the set-uid bit on strace will allow you to run it without the first sudo. It might also help to use the -o <file> option to save the output to a file for analysis. – garethTheRed Nov 4 '14 at 16:34
  • 1
    That's the one. Then follow it with sudo -k to remove your cached credential. I found strace -Tro sudo.log sudo echo hi was useful as the last column shows the time in each call. grep for uname and socket as a starter. – garethTheRed Nov 4 '14 at 16:47
  • 1
    The 5.005153 seconds is from the -r option (which should maybe be removed). Start by looking for the long calls from the -T option - they are the ones within the < and > - 0.000097 sec in your case. – garethTheRed Nov 4 '14 at 18:11
  • 1
    Have you checked ps, top and all the system log files in the event there is something else happening to cause the slowness? – mdpc Nov 4 '14 at 18:27
  • 1
    Can you post your pam configuration? strace will get you there eventually but this is probably a higher level configuration issue. Most long pauses during authentication are due to failing to access remote servers and having to wait for a timeout. It may be that the subnet change put the authentication server on a different subnet as this one. sudo temporarily saves a record of successful auth underneath /var so this is probably why subsequent invocations go through instantly. – Bratchley Nov 4 '14 at 19:31
2

I'd suspect that your box is attempting to contact an external authentication service (think of NIS/LDAP) using PAM...

If I understand PAM right, you wouldn't be able to see the PAM lookup in your strace calls. I'd suggest that you run tshark/tcpdump and see if you can correlate specific network traffic to your sudo attempts. Suspects here would be DNS lookups &| LDAP calls.

tcpdump -i eth0 -w network.pcap -s0 -Av

If you do find out what's causing the lookups, find out the relevant PAM module to edit and fix the issue. Alternatively, if it's a DNS lookup, just add an /etc/hosts entry to fake the name and redirect to localhost. This will make your sudo fast since the lookup will be fast and will redirect to the localhost and the network transaction will fail fast since there's nothing listening on localhost...

  • Now this seems to go in a good direction. I have a lot of "bad udp cksum" and "bad tcp cksum" calls in my log. It is too long to post in a comment so i will update the OP in a second. – zerweck Nov 5 '14 at 23:08

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.