Skip to content

Instantly share code, notes, and snippets.

@pothos
Last active January 3, 2018 11:30
Show Gist options
  • Save pothos/a788ba6c58d916bb12d071b881f7ab03 to your computer and use it in GitHub Desktop.
Save pothos/a788ba6c58d916bb12d071b881f7ab03 to your computer and use it in GitHub Desktop.
smoltcp's trace and PCAP for reordered fin
TRACE:smoltcp::socket::set: [0]: adding
connecting
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: state=CLOSED=>SYN-SENT
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: outgoing segment will update window
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: sending SYN
DEBUG:smoltcp::iface::ethernet: address 143.248.197.1 not in neighbor cache, sending ARP request
TRACE:smoltcp::socket::meta: #0: neighbor 78.46.93.45 missing, silencing until t+3000ms
TRACE:smoltcp::iface::neighbor: filled 143.248.197.1 => 00-1a-1e-00-41-a0 (was empty)
TRACE:smoltcp::socket::meta: #0: neighbor 78.46.93.45 discovered, unsilencing
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: outgoing segment will update window
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: sending SYN
DEBUG:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: retransmitting at t+100ms
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: retransmit timer expired
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: sending SYN
DEBUG:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: retransmitting at t+201ms
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: retransmit timer expired
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: sending SYN
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:50180:78.46.93.45:80: received SYN|ACK
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: state=SYN-SENT=>ESTABLISHED
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: outgoing segment will acknowledge
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: sending ACK
sending request
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: sending PSH|ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: segment not in receive window (2645676907..2645676908 not intersecting 2645676908..2645677932), will send challenge ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: retransmitting at t+101ms
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: sending PSH|ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: segment not in receive window (2645676907..2645676908 not intersecting 2645676908..2645677932), will send challenge ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: retransmitting at t+200ms
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: sending PSH|ACK
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: tx buffer: dequeueing 54 octets (now 0)
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: state=ESTABLISHED=>CLOSE-WAIT
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: outgoing segment will acknowledge
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:50180:78.46.93.45:80: sending ACK
received complete response
$ tcpdump -r log-fail.pcap
reading from file log-fail.pcap, link-type EN10MB (Ethernet)
09:00:00.012000 IP hsmoltcp.50180 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.112000 IP hsmoltcp.50180 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.213000 IP hsmoltcp.50180 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.327000 IP remote.xy.http > hsmoltcp.50180: Flags [S.], seq 2645676907, ack 1, win 14600, options [mss 1386], length 0
09:00:00.327000 IP hsmoltcp.50180 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.327000 IP hsmoltcp.50180 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.426000 IP remote.xy.http > hsmoltcp.50180: Flags [S.], seq 2645676907, ack 1, win 14600, options [mss 1386], length 0
09:00:00.426000 IP hsmoltcp.50180 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.428000 IP hsmoltcp.50180 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.527000 IP remote.xy.http > hsmoltcp.50180: Flags [S.], seq 2645676907, ack 1, win 14600, options [mss 1386], length 0
09:00:00.527000 IP hsmoltcp.50180 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.528000 IP hsmoltcp.50180 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.642000 IP remote.xy.http > hsmoltcp.50180: Flags [.], ack 55, win 14600, length 0
09:00:00.642000 IP remote.xy.http > hsmoltcp.50180: Flags [F.], seq 372, ack 55, win 14600, length 0
09:00:00.642000 IP hsmoltcp.50180 > remote.xy.http: Flags [.], ack 2, win 1024, length 0
TRACE:smoltcp::socket::set: [0]: adding
connecting
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: state=CLOSED=>SYN-SENT
DEBUG:smoltcp::iface::ethernet: address 143.248.197.1 not in neighbor cache, sending ARP request
DEBUG:smoltcp::iface::ethernet: cannot dispatch response packet: unaddressable destination
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: outgoing segment will update window
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: sending SYN
TRACE:smoltcp::socket::meta: #0: neighbor 78.46.93.45 missing, silencing until t+3000ms
TRACE:smoltcp::iface::neighbor: filled 143.248.197.1 => 00-1a-1e-00-41-a0 (was empty)
TRACE:smoltcp::socket::meta: #0: neighbor 78.46.93.45 discovered, unsilencing
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: outgoing segment will update window
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: sending SYN
DEBUG:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: retransmitting at t+100ms
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: retransmit timer expired
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: sending SYN
DEBUG:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: retransmitting at t+201ms
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: retransmit timer expired
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: sending SYN
TRACE:smoltcp::socket::tcp: #0:0.0.0.0:59460:78.46.93.45:80: received SYN|ACK
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: state=SYN-SENT=>ESTABLISHED
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will acknowledge
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending ACK
sending request
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending PSH|ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: segment not in receive window (3259108279..3259108280 not intersecting 3259108280..3259109304), will send challenge ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: retransmitting at t+100ms
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending PSH|ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: retransmitting at t+201ms
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will send data or flags
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: tx buffer: sending 54 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending PSH|ACK
DEBUG:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: segment not in receive window (3259108279..3259108280 not intersecting 3259108280..3259109304), will send challenge ACK
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: tx buffer: dequeueing 54 octets (now 0)
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: rx buffer: receiving 371 octets at offset 0
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: rx buffer: enqueueing 371 octets (now 371)
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: state=ESTABLISHED=>CLOSE-WAIT
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will acknowledge
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending ACK
HTTP/1.1 301 Moved Permanently
Server: nginx/1.7.6
[…] (HTTP data printed here)
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: outgoing segment will update window
TRACE:smoltcp::socket::tcp: #0:143.248.197.145:59460:78.46.93.45:80: sending ACK
received complete response
$ tcpdump -r log-ok.pcap
reading from file log-ok.pcap, link-type EN10MB (Ethernet)
09:00:00.083000 IP hsmoltcp.59460 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.183000 IP hsmoltcp.59460 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.284000 IP hsmoltcp.59460 > remote.xy.http: Flags [S], seq 0, win 1024, options [mss 1446], length 0
09:00:00.415000 IP remote.xy.http > hsmoltcp.59460: Flags [S.], seq 3259108279, ack 1, win 14600, options [mss 1386], length 0
09:00:00.415000 IP hsmoltcp.59460 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.416000 IP hsmoltcp.59460 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.514000 IP remote.xy.http > hsmoltcp.59460: Flags [S.], seq 3259108279, ack 1, win 14600, options [mss 1386], length 0
09:00:00.514000 IP hsmoltcp.59460 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.516000 IP hsmoltcp.59460 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.617000 IP hsmoltcp.59460 > remote.xy.http: Flags [P.], seq 1:55, ack 1, win 1024, length 54: HTTP: GET / HTTP/1.1
09:00:00.620000 IP remote.xy.http > hsmoltcp.59460: Flags [S.], seq 3259108279, ack 1, win 14600, options [mss 1386], length 0
09:00:00.620000 IP hsmoltcp.59460 > remote.xy.http: Flags [.], ack 1, win 1024, length 0
09:00:00.746000 IP remote.xy.http > hsmoltcp.59460: Flags [.], ack 55, win 14600, length 0
09:00:00.747000 IP remote.xy.http > hsmoltcp.59460: Flags [P.], seq 1:372, ack 55, win 14600, length 371: HTTP: HTTP/1.1 301 Moved Permanently
09:00:00.747000 IP remote.xy.http > hsmoltcp.59460: Flags [F.], seq 372, ack 55, win 14600, length 0
09:00:00.747000 IP hsmoltcp.59460 > remote.xy.http: Flags [.], ack 373, win 653, length 0
09:00:00.748000 IP hsmoltcp.59460 > remote.xy.http: Flags [.], ack 373, win 1024, length 0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment