Hi,
On Wed, 10 Jul 2019, Jakub Jankowski wrote:
> On 2019-07-10, Jozsef Kadlecsik wrote:
>
> > On Wed, 10 Jul 2019, Jakub Jankowski wrote:
> >
> > > We're debugging a weird issue. tl;dr: I have a .pcap file of connection
> > > setup that makes conntrack apply TCP_CONNTRACK_RETRANS timeout (300s by
> > > default) instead of TCP_CONNTRACK_ESTABLISHED (5d by default). The .pcap
> > > is a recording of some app traffic running on Windows (SAP, I believe).
> > >
> > > The offending handshake is:
> > >
> > > root@testhost0:~# tcpdump -v -nn --absolute-tcp-sequence-numbers -r
> > > replayed-traffic.pcap
> > > reading from file replayed-traffic.pcap, link-type EN10MB (Ethernet)
> > > 01:13:25.070622 IP (tos 0x0, ttl 128, id 35410, offset 0, flags [DF],
> > > proto
> > > TCP (6), length 52)
> > > 10.88.15.142.51451 > 10.88.1.2.3230: Flags [S], cksum 0x1473
> > > (correct),
> > > seq 962079611, win 64240, options [mss 1460,nop,wscale 8,nop,nop,sackOK],
> > > length 0
> > > 01:13:26.070462 IP (tos 0x0, ttl 53, id 29815, offset 0, flags [DF], proto
> > > TCP
> > > (6), length 48)
> > > 10.88.1.2.3230 > 10.88.15.142.51451: Flags [S.], cksum 0x70cf
> > > (correct),
> > > seq 1148284782, ack 962079612, win 65535, options [mss 1380,nop,wscale 3],
> > > length 0
> > > 01:13:27.070449 IP (tos 0x0, ttl 128, id 35411, offset 0, flags [DF],
> > > proto
> > > TCP (6), length 40)
> > > 10.88.15.142.51451 > 10.88.1.2.3230: Flags [.], cksum 0x9a46
> > > (correct),
> > > ack 1148284783, win 512, length 0
> > >
> > > This conversation results in the following conntrack events:
> > >
> > > root@testhost0:~# conntrack -E --orig-src 10.88.15.142
> > > [NEW] tcp 6 120 SYN_SENT src=10.88.15.142 dst=10.88.1.2
> > > sport=51451
> > > dport=3230 [UNREPLIED] src=10.88.1.2 dst=10.88.15.142 sport=3230
> > > dport=51451
> > > [UPDATE] tcp 6 60 SYN_RECV src=10.88.15.142 dst=10.88.1.2
> > > sport=51451
> > > dport=3230 src=10.88.1.2 dst=10.88.15.142 sport=3230 dport=51451
> > > [UPDATE] tcp 6 312 ESTABLISHED src=10.88.15.142 dst=10.88.1.2
> > > sport=51451 dport=3230 src=10.88.1.2 dst=10.88.15.142 sport=3230
> > > dport=51451
> > > [ASSURED]
> > >
> > >
> > > After enabling all pr_debug()s in nf_conntrack_proto_tcp.c, the above
> > > handshake results in this:
> >
> > Thanks for the thorough report, but the kernel debug log above does not
> > correspond to the packet replay: the TCP parameters do not match. Please
> > send the proper debug log, so we can look into it.
>
> Argh. My bad, wrong copy&paste, sorry. Here goes the correct debug snippet:
The kernel does not print enough information. Could you apply the attached
patch to your kernel at the test machine, rerun the test and send the
logs?
Best regards,
Jozsef
-
E-mail : kadlec@xxxxxxxxxxxxxxxxx, kadlecsik.jozsef@xxxxxxxxxxxxx
PGP key : http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address : Wigner Research Centre for Physics, Hungarian Academy of Sciences
H-1525 Budapest 114, POB. 49, Hungarydiff --git a/net/netfilter/nf_conntrack_proto_tcp.c b/net/netfilter/nf_conntrack_proto_tcp.c
index 37ef35b861f2..fecc20036882 100644
--- a/net/netfilter/nf_conntrack_proto_tcp.c
+++ b/net/netfilter/nf_conntrack_proto_tcp.c
@@ -526,11 +526,14 @@ static bool tcp_in_window(const struct nf_conn *ct,
pr_debug("seq=%u ack=%u+(%d) sack=%u+(%d) win=%u end=%u\n",
seq, ack, receiver_offset, sack, receiver_offset, win, end);
pr_debug("tcp_in_window: sender end=%u maxend=%u maxwin=%u scale=%i "
- "receiver end=%u maxend=%u maxwin=%u scale=%i\n",
+ "receiver end=%u maxend=%u maxwin=%u scale=%i "
+ "last dir=%d seq=%u ack=%u end=%u win=%u retrans=%d\n",
sender->td_end, sender->td_maxend, sender->td_maxwin,
sender->td_scale,
receiver->td_end, receiver->td_maxend, receiver->td_maxwin,
- receiver->td_scale);
+ receiver->td_scale,
+ state->last_dir, state->last_seq, state->last_ack,
+ state->last_end, state->last_win, state->retrans);
if (sender->td_maxwin == 0) {
/*
@@ -715,10 +718,15 @@ static bool tcp_in_window(const struct nf_conn *ct,
}
}
- pr_debug("tcp_in_window: res=%u sender end=%u maxend=%u maxwin=%u "
- "receiver end=%u maxend=%u maxwin=%u\n",
+ pr_debug("tcp_in_window: res=%u sender end=%u maxend=%u maxwin=%u scale=%i "
+ "receiver end=%u maxend=%u maxwin=%u scale=%i "
+ "last dir=%d seq=%u ack=%u end=%u win=%u retrans=%d\n",
res, sender->td_end, sender->td_maxend, sender->td_maxwin,
- receiver->td_end, receiver->td_maxend, receiver->td_maxwin);
+ sender->td_scale,
+ receiver->td_end, receiver->td_maxend, receiver->td_maxwin,
+ receiver->td_scale,
+ state->last_dir, state->last_seq, state->last_ack,
+ state->last_end, state->last_win, state->retrans);
return res;
}
