Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 25 Mar 2014 10:52:38 +0000
From:      Karl Pielorz <kpielorz_lst@tdx.co.uk>
To:        Kevin Oberman <rkoberman@gmail.com>, Marcelo Gondim <gondim@bsdinfo.com.br>
Cc:        FreeBSD Stable Mailing List <freebsd-stable@freebsd.org>
Subject:   Re: sshd with zombie process on FreeBSD 10.0-STABLE - workaround
Message-ID:  <7419ED158F7CE99854773527@Mail-PC.tdx.co.uk>
In-Reply-To: <CAN6yY1sf0z_jBJgBy2dZX0a3JJnyTnq76_DepXzG32GWgHHO6A@mail.gmail.com>
References:  <53016D97.5030909@bsdinfo.com.br> <CAN6yY1uucfkdXxkCF30w1Q9vffRpDLxM90Sz1XVbdn5W69vQMg@mail.gmail.com> <5329D81E.7040709@bsdinfo.com.br> <201403201058.38555.jhb@freebsd.org> <532B7DEC.7010809@bsdinfo.com.br> <CAN6yY1sf0z_jBJgBy2dZX0a3JJnyTnq76_DepXzG32GWgHHO6A@mail.gmail.com>

next in thread | previous in thread | raw e-mail | index | archive | help


--On 21 March 2014 22:02 -0700 Kevin Oberman <rkoberman@gmail.com> wrote:

> Ideally I'd look to try and capture the packets st the end of the session.
> Can you do something to trigger this reliably? if so "standard" "tcpdump
> -pw file.bpf host HOST". I seem to recall that these connections are
> scheduled. If so, you can put the packet capture in a crontab to run at
> the same time. If you feed this to a tool like wireshark, you should get
> a good idea of what is happening, if not why. I understand that the
> timing of this might be very tricky.

Ok, fwiw as I have this issue as well - I've done a packet capture (it's 
below). This box has 59 'CLOSED' sockets from ssh on it, and 60 sshd stuck.

Also - initially I thought this was a Xen issue - so there's a couple of 
posts on that list from a couple of weeks ago, in brief - the sshd 
processes I have are stuck in 'urdlck' - one of the Xen guys commented "It 
seems like the process is stuck while trying to acquire a rw mutex in read 
mode."

I did a backtrace of a stuck process - I can post that if you want (or 
check the FreeBSD-Xen list for 'stuck sshd in urdlck'.

Also, if I ssh into this host, 90% of the time (seems to get worse the 
longer the box is up) I get:

"
ssh_exchange_identification: Connection closed by remote host
"

That does not leave a lingering CLOSED socket. In fact, a successful ssh 
login - and logout, does not in testing appear to leave a lingering CLOSED 
socket, nor sshd stuck in urdlck - so I'm not entirely sure where they're 
coming from, or how often they are created.

tcpdump from the start of a successful ssh connect:

10:47:04.777765 IP (tos 0x0, ttl 61, id 4058, offset 0, flags [DF], proto 
TCP (6), length 60)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [S], cksum 0x57ce 
(correct), seq 634709832, win 65535, options [mss 1368,nop,wscale 
3,sackOK,TS val 1019391535 ecr 0], length 0

10:47:04.777776 IP (tos 0x0, ttl 64, id 10060, offset 0, flags [DF], proto 
TCP (6), length 60)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [S.], cksum 0x7ef8 
(incorrect -> 0x69d8), seq 2316386788, ack 634709833, win 65535, options 
[mss 1368,nop,wscale 6,sackOK,TS val 805368299 ecr 1019391535], length 0

10:47:04.804218 IP (tos 0x0, ttl 61, id 4059, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [.], cksum 0x77d3 
(correct), ack 1, win 8305, options [nop,nop,TS val 1019391538 ecr 
805368299], length 0

10:47:04.809692 IP (tos 0x0, ttl 64, id 10061, offset 0, flags [DF], proto 
TCP (6), length 99)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x7f1f 
(incorrect -> 0x5799), seq 1:48, ack 1, win 1038, options [nop,nop,TS val 
805368328 ecr 1019391538], length 47

10:47:04.836110 IP (tos 0x0, ttl 61, id 4060, offset 0, flags [DF], proto 
TCP (6), length 92)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [P.], cksum 0x8afa 
(correct), seq 1:41, ack 48, win 8305, options [nop,nop,TS val 1019391541 
ecr 805368328], length 40

10:47:04.836669 IP (tos 0x0, ttl 64, id 10062, offset 0, flags [DF], proto 
TCP (6), length 1596)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x84f8 
(incorrect -> 0x4d42), seq 48:1592, ack 41, win 1038, options [nop,nop,TS 
val 805368358 ecr 1019391541], length 1544


And the end of the session:

10:47:15.243540 IP (tos 0x10, ttl 61, id 4132, offset 0, flags [DF], proto 
TCP (6), length 100)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [P.], cksum 0x6364 
(correct), seq 2321:2369, ack 3520, win 8305, options [nop,nop,TS val 
1019392582 ecr 805375068], length 48

10:47:15.243736 IP (tos 0x10, ttl 64, id 10125, offset 0, flags [DF], proto 
TCP (6), length 100)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x7f20 
(incorrect -> 0x3ea8), seq 3520:3568, ack 2369, win 1038, options 
[nop,nop,TS val 805378765 ecr 1019392582], length 48

10:47:15.243796 IP (tos 0x10, ttl 64, id 10126, offset 0, flags [DF], proto 
TCP (6), length 100)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x7f20 
(incorrect -> 0xdd22), seq 3568:3616, ack 2369, win 1038, options 
[nop,nop,TS val 805378765 ecr 1019392582], length 48

10:47:15.244627 IP (tos 0x10, ttl 64, id 10127, offset 0, flags [DF], proto 
TCP (6), length 84)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x7f10 
(incorrect -> 0x86ed), seq 3616:3648, ack 2369, win 1038, options 
[nop,nop,TS val 805378765 ecr 1019392582], length 32

10:47:15.244812 IP (tos 0x10, ttl 64, id 10128, offset 0, flags [DF], proto 
TCP (6), length 212)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [P.], cksum 0x7f90 
(incorrect -> 0x431c), seq 3648:3808, ack 2369, win 1038, options 
[nop,nop,TS val 805378765 ecr 1019392582], length 160

10:47:15.271439 IP (tos 0x10, ttl 61, id 4134, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [.], cksum 0x3381 
(correct), ack 3616, win 8299, options [nop,nop,TS val 1019392585 ecr 
805378765], length 0

10:47:15.272238 IP (tos 0x10, ttl 61, id 4135, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [.], cksum 0x32d9 
(correct), ack 3808, win 8275, options [nop,nop,TS val 1019392585 ecr 
805378765], length 0

10:47:15.273515 IP (tos 0x10, ttl 61, id 4137, offset 0, flags [DF], proto 
TCP (6), length 84)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [P.], cksum 0x43cc 
(correct), seq 2369:2401, ack 3808, win 8305, options [nop,nop,TS val 
1019392585 ecr 805378765], length 32

10:47:15.276199 IP (tos 0x10, ttl 61, id 4138, offset 0, flags [DF], proto 
TCP (6), length 116)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [P.], cksum 0xb169 
(correct), seq 2401:2465, ack 3808, win 8305, options [nop,nop,TS val 
1019392585 ecr 805378765], length 64

10:47:15.276220 IP (tos 0x10, ttl 64, id 10129, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [.], cksum 0x7ef0 
(incorrect -> 0x4ea3), ack 2465, win 1037, options [nop,nop,TS val 
805378793 ecr 1019392585], length 0

10:47:15.276970 IP (tos 0x10, ttl 61, id 4140, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [F.], cksum 0x325a 
(correct), seq 2465, ack 3808, win 8305, options [nop,nop,TS val 1019392585 
ecr 805378765], length 0

10:47:15.276978 IP (tos 0x10, ttl 64, id 10130, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [.], cksum 0x7ef0 
(incorrect -> 0x4e9c), ack 2466, win 1038, options [nop,nop,TS val 
805378798 ecr 1019392585], length 0

10:47:15.277212 IP (tos 0x10, ttl 64, id 10131, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.138.22 > 192.168.0.37.31139: Flags [F.], cksum 0x7ef0 
(incorrect -> 0x4e9b), seq 3808, ack 2466, win 1038, options [nop,nop,TS 
val 805378798 ecr 1019392585], length 0

10:47:15.303993 IP (tos 0x10, ttl 61, id 4142, offset 0, flags [DF], proto 
TCP (6), length 52)
    192.168.0.37.31139 > 192.168.0.138.22: Flags [.], cksum 0x3235 
(correct), ack 3809, win 8305, options [nop,nop,TS val 1019392588 ecr 
805378798], length 0


This box has no services running on it at present, and just sits there 
idle. I'll periodically check on it and see if the CLOSED socket count, or 
hung sshd count goes up.

It's runing as a PVHVM domU under XenServer 6.2

-Karl



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?7419ED158F7CE99854773527>