Date: Fri, 21 Jun 2019 12:26:46 +0200 From: Michael Tuexen <tuexen@freebsd.org> To: Igor Grinchenko <igor-fbsdnet@grinchenko.org> Cc: freebsd-net@freebsd.org Subject: Re: unexpected TCP resets (RST) in 12.0-RELEASE Message-ID: <D977D765-1043-4789-81DB-0985D256BA71@freebsd.org> In-Reply-To: <20190621081941.GM94573@sun.grinchenko.org> References: <20190621081941.GM94573@sun.grinchenko.org>
next in thread | previous in thread | raw e-mail | index | archive | help
> On 21. Jun 2019, at 10:19, Igor Grinchenko =
<igor-fbsdnet@grinchenko.org> wrote:
>=20
> Hello,
>=20
> I have been trying to debug several issues where a 12.0-RELEASE (all =
the way from p0 to p6) server would unexpectedly send RST packets to =
clients either some time after the initial 3-way handshake is completed =
or right after it gets the first SYN on an open port.
>=20
> I ran several tests and here are a few samples and scenarios and a way =
to replicate the problem.
>=20
> ###
> CASE 1 - RST after a SYN.
>=20
> this is when I noticed the issue after upgrading to 12.0-RELEASE. Port =
is open by an app with plenty of somaxconn and there is a lot of healthy =
traffic exchanging. Once every few minutes I would see this:
>=20
> No. Time Source Destination =
Protocol Length Info
> 14717 6.240595 10.0.0.81 10.0.0.60 TCP =
74 60293 =E2=86=92 9000 [SYN] Seq=3D0 Win=3D65535 Len=3D0 =
MSS=3D1460 WS=3D128 SACK_PERM=3D1 TSval=3D3108212602 TSecr=3D0
>=20
> Frame 14717: 74 bytes on wire (592 bits), 74 bytes captured (592 bits)
> Ethernet II, Src: IntelCor_f1:7f:8c (a0:36:9f:f1:7f:8c), Dst: =
IntelCor_d4:36:d0 (a0:36:9f:d4:36:d0)
> Internet Protocol Version 4, Src: 10.0.0.81, Dst: 10.0.0.60
> 0100 .... =3D Version: 4
> .... 0101 =3D Header Length: 20 bytes (5)
> Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
> Total Length: 60
> Identification: 0x0000 (0)
> Flags: 0x4000, Don't fragment
> Time to live: 64
> Protocol: TCP (6)
> Header checksum: 0x2630 [validation disabled]
> [Header checksum status: Unverified]
> Source: 10.0.0.81
> Destination: 10.0.0.60
> Transmission Control Protocol, Src Port: 60293, Dst Port: 9000, Seq: =
0, Len: 0
> Source Port: 60293
> Destination Port: 9000
> [Stream index: 1548]
> [TCP Segment Len: 0]
> Sequence number: 0 (relative sequence number)
> [Next sequence number: 0 (relative sequence number)]
> Acknowledgment number: 0
> 1010 .... =3D Header Length: 40 bytes (10)
> Flags: 0x002 (SYN)
> Window size value: 65535
> [Calculated window size: 65535]
> Checksum: 0xa7f7 [unverified]
> [Checksum Status: Unverified]
> Urgent pointer: 0
> Options: (20 bytes), Maximum segment size, No-Operation (NOP), =
Window scale, SACK permitted, Timestamps
> [Timestamps]
>=20
> No. Time Source Destination =
Protocol Length Info
> 14719 6.240617 10.0.0.60 10.0.0.81 TCP =
54 9000 =E2=86=92 60293 [RST, ACK] Seq=3D1 Ack=3D1 Win=3D0 Len=3D0=
>=20
> Frame 14719: 54 bytes on wire (432 bits), 54 bytes captured (432 bits)
> Ethernet II, Src: IntelCor_d4:36:d0 (a0:36:9f:d4:36:d0), Dst: =
IntelCor_f1:7f:8c (a0:36:9f:f1:7f:8c)
> Internet Protocol Version 4, Src: 10.0.0.60, Dst: 10.0.0.81
> 0100 .... =3D Version: 4
> .... 0101 =3D Header Length: 20 bytes (5)
> Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
> Total Length: 40
> Identification: 0x0000 (0)
> Flags: 0x4000, Don't fragment
> Time to live: 64
> Protocol: TCP (6)
> Header checksum: 0x0000 [validation disabled]
> [Header checksum status: Unverified]
> Source: 10.0.0.60
> Destination: 10.0.0.81
> Transmission Control Protocol, Src Port: 9000, Dst Port: 60293, Seq: =
1, Ack: 1, Len: 0
> Source Port: 9000
> Destination Port: 60293
> [Stream index: 1548]
> [TCP Segment Len: 0]
> Sequence number: 1 (relative sequence number)
> [Next sequence number: 1 (relative sequence number)]
> Acknowledgment number: 1 (relative ack number)
> 0101 .... =3D Header Length: 20 bytes (5)
> Flags: 0x014 (RST, ACK)
> Window size value: 0
> [Calculated window size: 0]
> [Window size scaling factor: -1 (unknown)]
> Checksum: 0x14a7 [unverified]
> [Checksum Status: Unverified]
> Urgent pointer: 0
> [SEQ/ACK analysis]
> [Timestamps]
>=20
> It doesn't seem to matter what app that is, doesn't matter what event =
mechanism is used (kqueue or select). TCP stack just refuses to =
handshake from time to time. The rate of these increases with the rate =
of incoming connections. 12.0-RELEASE-p6 seems to be producing fewer of =
these, it could be due to the fix in =
https://www.freebsd.org/security/advisories/FreeBSD-EN-19:11.net.asc . =
While my guess is not very scientific, it seems to be related to the new =
epoch(9) based synchronization. A 11.2-RELEASE host, serving the same =
exact traffic, which I kept for baselining is rock-solid and doesn't =
produce TCP resets like these.
Hi Igor,
could you do
sudo sysctl net.inet.tcp.log_debug=3D1
on the host sending the RST segments and see if you get some messages in =
/var/log/messages.
Do you see these messages? If yes, what is logged?
Do you have a way to reproduce this issue?
Best regards
Michael
>=20
> ###
> CASE 2 - packets processed out of order. and a simple way to replicate =
it.
>=20
> #setup: hostA(11.2-RELEASE with defaults) - switch - =
hostB(12.0-RELEASE with defaults)
> -install tcpkali from ports or via pkg on hostA.=20
> -start the tcpdump capture on any of the hosts: tcpdump -i em0 -n =
-v 'tcp[tcpflags] & (tcp-rst) !=3D 0' and port 22
> -run on hostA: tcpkali -c 100 --connect-rate 50 --channel-lifetime 1 =
hostB:22 -T 120
> - wait up to 2 minutes. you will see sshd logging successful empty =
connections and then you will see resets returned to the client for some =
of the connections. Those same connections would not be logged by sshd.
>=20
> a fully captured pcap shows the following TCP stream which ends with =
resets.
>=20
> No. Time Source Destination =
Protocol Length Info
> 7023 76.041587 192.168.44.2 192.168.44.3 TCP =
74 27697 =E2=86=92 22 [SYN] Seq=3D0 Win=3D65535 Len=3D0 MSS=3D1460=
WS=3D64 SACK_PERM=3D1 TSval=3D4283665081 TSecr=3D0
> 7024 76.041601 192.168.44.3 192.168.44.2 TCP =
74 22 =E2=86=92 27697 [SYN, ACK] Seq=3D0 Ack=3D1 Win=3D65535 =
Len=3D0 MSS=3D1460 WS=3D64 SACK_PERM=3D1 TSval=3D1662309011 =
TSecr=3D4283665081
> 7026 76.041919 192.168.44.2 192.168.44.3 TCP =
66 27697 =E2=86=92 22 [ACK] Seq=3D1 Ack=3D1 Win=3D65664 Len=3D0 =
TSval=3D4283665081 TSecr=3D1662309011
> 7050 76.047586 192.168.44.2 192.168.44.3 TCP =
66 27697 =E2=86=92 22 [FIN, ACK] Seq=3D1 Ack=3D1 Win=3D65664 =
Len=3D0 TSval=3D4283665086 TSecr=3D1662309011
> 7051 76.047590 192.168.44.3 192.168.44.2 TCP =
66 22 =E2=86=92 27697 [ACK] Seq=3D1 Ack=3D2 Win=3D65664 Len=3D0 =
TSval=3D1662309017 TSecr=3D4283665086
> 7072 76.064230 192.168.44.3 192.168.44.2 TCP =
104 22 =E2=86=92 27697 [PSH, ACK] Seq=3D1 Ack=3D2 Win=3D65664 =
Len=3D38 TSval=3D1662309033 TSecr=3D4283665086
> 7073 76.064415 192.168.44.3 192.168.44.2 TCP =
66 22 =E2=86=92 27697 [FIN, ACK] Seq=3D39 Ack=3D2 Win=3D65664 =
Len=3D0 TSval=3D1662309034 TSecr=3D4283665086
> 7074 76.064538 192.168.44.2 192.168.44.3 TCP =
60 27697 =E2=86=92 22 [RST] Seq=3D2 Win=3D0 Len=3D0
> 7075 76.064710 192.168.44.2 192.168.44.3 TCP =
60 27697 =E2=86=92 22 [RST] Seq=3D2 Win=3D0 Len=3D0
>=20
>=20
> it seems like the actual packet with the payload(#7072) is processed =
after the FIN is received and that is not the order they are sent by =
tcpkali running on hostA.
> this doesn't seem to be replicatable over lo0, there has to be =
physical exchange of packets via the NICs. I have not tried running it =
in bhyve.
>=20
> when the same tcpkali test is executed the other direction, =
11.2-RELEASE doesn't produce a single reset like that.
> ##
>=20
> 11.2-RELEASE (any patch level) doesn't have any of these problems, so =
this must be a regression somewhere in the TCP stack. In all these cases =
OS was installed with all defaults untouched. NICs are either ix or em =
(tried stock drivers and intel-ix-kmod and intel-em-kmod, which didn't =
seem to matter).
>=20
> I can provide dmesgs, raw pcaps, etc, if necessary. I am curious why =
this hasn't been reported by now(checked mailing lists and open bugs) as =
it seems like a relatively serious issue. But then again, maybe I'm =
missing something obvious, in which case, I'd like to get educated.
>=20
> Regards,
>=20
> --=20
> Igor
>=20
>=20
> _______________________________________________
> freebsd-net@freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-net
> To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?D977D765-1043-4789-81DB-0985D256BA71>