A symptom:
Every login action like ssh, su, sudo or even a exit by a user take near a minute long.
A SSH call is slow here:
debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
And if i do strace -f su - juan ls process is slow here:
open("/etc/login.defs", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=10551, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2c32202000
read(4, "#\n# /etc/login.defs - Configurat"..., 4096) = 4096
read(4, " issuing \n# the \"mesg y\" command"..., 4096) = 4096
read(4, " algorithm compatible with the o"..., 4096) = 2359
read(4, "", 4096) = 0
close(4) = 0
munmap(0x7f2c32202000, 4096) = 0
sendto(3, "<86>Feb 10 17:36:33 su[4088]: + "..., 52, MSG_NOSIGNAL, NULL, 0
The problem is here, when a process tried to write to /dev/log:
12:12:23 connect(1, {sa_family=AF_LOCAL, sun_path="/dev/log"}, 110) = 0 <0.000008>
12:12:23 sendto(1, "<13>Feb 11 12:12:23 juan: hello "..., 37, MSG_NOSIGNAL, NULL, 0) = 37 <15.931766>
Debug of rsyslog:
2042.323399028:7f5a60003700: --------imuxsock calling select, active file descriptors (max 4): 0 4
2042.323419636:7f5a60003700: Message from UNIX socket: #0
2042.323434226:7f5a60003700: main Q: queue nearly full (10000 entries), but could not drop msg (iRet: 0, severity 6)
2042.323437267:7f5a60003700: main Q: doEnqSingleObject: queue FULL - waiting 2000ms to drain.
2044.323585582:7f5a60003700: main Q: doEnqSingleObject: cond timeout, dropping message!
2044.323616781:7f5a60003700: main Q: EnqueueMsg advised worker start
/var/log/syslog and /var/log/messages are empty
Santiago Trujillo
As you properly explained on your question the problem is on the logging part, you get one socket (1) for /dev/log, then use it to sendto a silly message "hello juan", but it takes 15 seconds.
I'm seeing the same with a vsftpd, its nothing about the service itself, the problem is with your rsyslog. Probably if you restart it the 15 seconds will go down to almost nothing, but it will build up over time.
Also, your rsyslog queue is nearly full, which means that your remote server is not working or your disk where you write the logs is utterly slow, my guess is with the remote option.
This is an important message :
doEnqSingleObject: queue FULL - waiting 2000ms to drain.
I can not provide more information since I'm here because I have my own problems, but maybe changing the queue type could help.
This can happen for a wide variety of reasons, I would suggest a good place to start debugging this would be to use the -vvv argument to output a more detailed trace of what is happening, you should hopefully then be able to spot which part of the process it is hanging on
so your command should look something like : ssh foo@domain.com -vvv
Exactly the issue of slow acceptance to a ssh session could have multiple reasons for the cause. It depends on whether the user you are logging on is locally based or ldap or AD based. ssh with -vvv is a good option to check the ssh with max debugging log level, that will give you best idea where it is getting hanged. Please check the number of hops in between the server from where you trying to login the server through traceroute.