unexpected TCP resets (RST) in 12.0-RELEASE
Michael Tuexen
tuexen at freebsd.org
Fri Jun 21 10:26:52 UTC 2019
> On 21. Jun 2019, at 10:19, Igor Grinchenko <igor-fbsdnet at grinchenko.org> wrote:
>
> Hello,
>
> 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.
>
> I ran several tests and here are a few samples and scenarios and a way to replicate the problem.
>
> ###
> CASE 1 - RST after a SYN.
>
> 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:
>
> No. Time Source Destination Protocol Length Info
> 14717 6.240595 10.0.0.81 10.0.0.60 TCP 74 60293 → 9000 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=128 SACK_PERM=1 TSval=3108212602 TSecr=0
>
> 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 .... = Version: 4
> .... 0101 = 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 .... = 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]
>
> No. Time Source Destination Protocol Length Info
> 14719 6.240617 10.0.0.60 10.0.0.81 TCP 54 9000 → 60293 [RST, ACK] Seq=1 Ack=1 Win=0 Len=0
>
> 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 .... = Version: 4
> .... 0101 = 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 .... = 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]
>
> 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=1
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
>
> ###
> CASE 2 - packets processed out of order. and a simple way to replicate it.
>
> #setup: hostA(11.2-RELEASE with defaults) - switch - hostB(12.0-RELEASE with defaults)
> -install tcpkali from ports or via pkg on hostA.
> -start the tcpdump capture on any of the hosts: tcpdump -i em0 -n -v 'tcp[tcpflags] & (tcp-rst) != 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.
>
> a fully captured pcap shows the following TCP stream which ends with resets.
>
> No. Time Source Destination Protocol Length Info
> 7023 76.041587 192.168.44.2 192.168.44.3 TCP 74 27697 → 22 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=64 SACK_PERM=1 TSval=4283665081 TSecr=0
> 7024 76.041601 192.168.44.3 192.168.44.2 TCP 74 22 → 27697 [SYN, ACK] Seq=0 Ack=1 Win=65535 Len=0 MSS=1460 WS=64 SACK_PERM=1 TSval=1662309011 TSecr=4283665081
> 7026 76.041919 192.168.44.2 192.168.44.3 TCP 66 27697 → 22 [ACK] Seq=1 Ack=1 Win=65664 Len=0 TSval=4283665081 TSecr=1662309011
> 7050 76.047586 192.168.44.2 192.168.44.3 TCP 66 27697 → 22 [FIN, ACK] Seq=1 Ack=1 Win=65664 Len=0 TSval=4283665086 TSecr=1662309011
> 7051 76.047590 192.168.44.3 192.168.44.2 TCP 66 22 → 27697 [ACK] Seq=1 Ack=2 Win=65664 Len=0 TSval=1662309017 TSecr=4283665086
> 7072 76.064230 192.168.44.3 192.168.44.2 TCP 104 22 → 27697 [PSH, ACK] Seq=1 Ack=2 Win=65664 Len=38 TSval=1662309033 TSecr=4283665086
> 7073 76.064415 192.168.44.3 192.168.44.2 TCP 66 22 → 27697 [FIN, ACK] Seq=39 Ack=2 Win=65664 Len=0 TSval=1662309034 TSecr=4283665086
> 7074 76.064538 192.168.44.2 192.168.44.3 TCP 60 27697 → 22 [RST] Seq=2 Win=0 Len=0
> 7075 76.064710 192.168.44.2 192.168.44.3 TCP 60 27697 → 22 [RST] Seq=2 Win=0 Len=0
>
>
> 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.
>
> when the same tcpkali test is executed the other direction, 11.2-RELEASE doesn't produce a single reset like that.
> ##
>
> 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).
>
> 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.
>
> Regards,
>
> --
> Igor
>
>
> _______________________________________________
> freebsd-net at freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-net
> To unsubscribe, send any mail to "freebsd-net-unsubscribe at freebsd.org"
More information about the freebsd-net
mailing list