Bug #1325
closedtls detection leads to tcp stream reassembly sequence gaps
Description
Hello, I am new to suricata - 2.0.4 stable Ubuntu PPA (Ubuntu 12.04).
When app-layer.protocols.tls.enabled is set to yes or detection only, the tcp.reassembly_gap counter increases quickly (depending on the amount of ssl traffic). When I set app-layer.protocols.tls.enabled to no, the tcp.reassembly_gap stays at 0. So my suspicion is that it's not a matter of packet loss (why would it concern only tls and not non-tls traffic?), but rather some problem in the tls routine.
I use nfqueue IPS mode, most other settings on default values.
As a sidenote I would mention that the tcp.invalid_checksum counter increases as well, but in a rather steady manner, not related to the amount of ssl traffic, and it continues to increase even with app-layer.protocols.tls.enabled=no. I don't think that this is related to the tcp reassembly gaps, and I suspect rather some problem in my system as a culprit, but I prefer to mention it just in case there is a link that I am not aware of.
Updated by Victor Julien about 10 years ago
Can you reproduce this with a pcap as well?
Updated by Martin Küchler about 10 years ago
Well, yes and no - while during live logging this error is very frequent, like one error message per 2 https sites you open (or so), I cannot get it reliably on the pcap. I have taken lots of pcap logs, both from tcpdump -s 0 and from suricata (running at the same time), and sometimes the reassembly gap that is logged by suricata can be reproduced on suricata's pcap but not on the tcpdump of the same traffic and sometimes vice versa, mostly on none of them. I don't understand this. Anyway, I can provide you with several pcaps of the same traffic, some with errors and some without. I just don't want to upload them here, because I don't know how to make them personal data-free...
Aside from the pcap issue, I have looked a bit closer at the logs, it seems to me that there is some pattern - all packets logged as "reassembly gap" are either a normal tcp packet (with payload) which immediately follows an "ACK" from the other side, or are linked to a TCP RST packet - the latter case is a bit strange, suricata finds a packet in the opposite sense of the rst packet, like this:
+================
TIME: 12/04/2014-21:04:43.922254
PKT SRC: stream
SRC IP: 2a03:2880:2130:cf05:face:b00c:0000:0001
DST IP: 2a01:0170:1073:0001:021f:3bff:fe37:00cd
PROTO: 6
SRC PORT: 443
DST PORT: 49902
TCP SEQ: 0
TCP ACK: 3935835768
FLOW: to_server: FALSE, to_client: TRUE
FLOW Start TS: 12/04/2014-21:04:43.388891
FLOW IPONLY SET: TOSERVER: TRUE, TOCLIENT: TRUE
FLOW ACTION: DROP: FALSE
FLOW NOINSPECTION: PACKET: FALSE, PAYLOAD: TRUE, APP_LAYER: TRUE
FLOW APP_LAYER: DETECTED: TRUE, PROTO 4
PACKET LEN: 60
PACKET:
0000 60 00 00 00 00 14 06 3F 2A 03 28 80 21 30 CF 05 `......? *.(.!0..
0010 FA CE B0 0C 00 00 00 01 2A 01 01 70 10 73 00 01 ........ *..p.s..
0020 02 1F 3B FF FE 37 00 CD 01 BB C2 EE 00 00 00 00 ..;..7.. ........
0030 EA 98 16 78 50 04 00 00 83 88 00 00 ...xP... ....
ALERT CNT: 1
ALERT MSG [00]: SURICATA STREAM reassembly sequence GAP -- missing packet(s)
ALERT GID [00]: 1
ALERT SID [00]: 2210048
ALERT REV [00]: 1
ALERT CLASS [00]: <none>
ALERT PRIO [00]: 3
ALERT FOUND IN [00]: PACKET
ALERT IN TX [00]: N/A
when the stream looks like this (extract taken from suricata's own pcap log):
21:04:43.911517 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [.], ack 390, win 65, options
[nop,nop,TS val 545898491 ecr 1854544], length 0
21:04:43.914513 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [.], ack 431, win 65, options
[nop,nop,TS val 545898494 ecr 1854544], length 0
21:04:43.919513 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [.], ack 458, win 65, options
[nop,nop,TS val 545898499 ecr 1854544], length 0
21:04:43.919531 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [P.], seq 3419:3460, ack 458,
win 65, options [nop,nop,TS val 545898499 ecr 1854544], length 41
21:04:43.919539 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [P.], seq 3460:3487, ack 458,
win 65, options [nop,nop,TS val 545898499 ecr 1854544], length 27
21:04:43.920510 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [F.], seq 3487, ack 458, win
65, options [nop,nop,TS val 545898499 ecr 1854544], length 0
21:04:43.922254 IP6 2a01:170:1073:1:21f:3bff:fe37:cd.49902 > 2a03:2880:2130:cf05:face:b00c:0:1.443: Flags [R], seq 3935835768, win 0, length 0
21:04:43.923016 IP6 2a01:170:1073:1:21f:3bff:fe37:cd.49902 > 2a03:2880:2130:cf05:face:b00c:0:1.443: Flags [R], seq 3935835768, win 0, length 0
21:04:43.924674 IP6 2a01:170:1073:1:21f:3bff:fe37:cd.49902 > 2a03:2880:2130:cf05:face:b00c:0:1.443: Flags [R], seq 3935835768, win 0, length 0
21:04:43.925514 IP6 2a03:2880:2130:cf05:face:b00c:0:1.443 > 2a01:170:1073:1:21f:3bff:fe37:cd.49902: Flags [.], ack 459, win 65, options [nop,nop,TS val 545898501 ecr 1854544], length 0
21:04:43.927367 IP6 2a01:170:1073:1:21f:3bff:fe37:cd.49902 > 2a03:2880:2130:cf05:face:b00c:0:1.443: Flags [R], seq 3935835769, win 0, length 0
(note the [R] packets with the identical timestamp, and whose seq no. matches the TCP ACK no. suricata sees.
Updated by Victor Julien about 10 years ago
- Status changed from New to Assigned
- Assignee set to Victor Julien
I see this as well in my IPS setup.
Updated by Victor Julien about 10 years ago
- Status changed from Assigned to Closed
- % Done changed from 0 to 100
Fixed through https://github.com/inliniac/suricata/pull/1273