Bug #2429: TCP-session and wrong alert timestamp - Suricata - Open Information Security Foundation

Actions

Copy link

Bug #2429

closed

TCP-session and wrong alert timestamp

Added by Andrey Kiryukhin almost 7 years ago. Updated about 1 year ago.

Status:

Rejected

Priority:

Normal

Assignee:

OISF Dev

Target version:

TBD

Affected Versions:

Effort:

Difficulty:

Label:

Description

Suricata 4.0.3 (also reproduced on suricata 3.0.2 and 4.0)

I have simple net dump, which contain one tcp-session (see attach for pcap):

pcap trace..pcap trace..

15:04:50.767186 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [S], seq 3153782711, win 29200, options [mss 1460,sackOK,TS val 645097 ecr0,nop,wscale 7], length 0 15:04:50.767561 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [S.], seq 895349628, ack 3153782712, win 28960, options [mss 1460,sackOK,TS val 507409790 ecr 645097,nop,wscale 7], length 0 15:04:50.767598 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [.], ack 1, win 229, options [nop,nop,TS val 645097 ecr 507409790], length 0 15:04:52.881885 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 1:8, ack 1, win 229, options [nop,nop,TS val 645625 ecr 507409790], length 7 15:04:52.882199 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 8, win 227, options [nop,nop,TS val 507411905 ecr 645625], length 0 15:04:53.112006 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 8:11, ack 1, win 229, options [nop,nop,TS val 645683 ecr 507411905], length 3 15:04:53.112240 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 11, win 227, options [nop,nop,TS val 507412134 ecr 645683], length 0 15:04:53.291222 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 11:13, ack 1, win 229, options [nop,nop,TS val 645728 ecr 507412134], length 2 15:04:53.291500 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 13, win 227, options [nop,nop,TS val 507412314 ecr 645728], length 0 15:04:54.060623 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 13:17, ack 1, win 229, options [nop,nop,TS val 645920 ecr 507412314], length 4 15:04:54.060883 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 17, win 227, options [nop,nop,TS val 507413083 ecr 645920], length 0 15:04:56.042481 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 17:22, ack 1, win 229, options [nop,nop,TS val 646415 ecr 507413083], length 5 15:04:56.042766 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 22, win 227, options [nop,nop,TS val 507415065 ecr 646415], length 0 15:04:56.431254 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 22:26, ack 1, win 229, options [nop,nop,TS val 646513 ecr 507415065], length 4 15:04:56.431904 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 26, win 227, options [nop,nop,TS val 507415454 ecr 646513], length 0 15:04:56.647552 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 26:29, ack 1, win 229, options [nop,nop,TS val 646567 ecr 507415454], length 3 15:04:56.647800 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 29, win 227, options [nop,nop,TS val 507415670 ecr 646567], length 0 15:04:56.826973 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 29:31, ack 1, win 229, options [nop,nop,TS val 646612 ecr 507415670], length 2 15:04:56.827221 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 31, win 227, options [nop,nop,TS val 507415849 ecr 646612], length 0 15:04:57.007120 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 31:35, ack 1, win 229, options [nop,nop,TS val 646657 ecr 507415849], length 4 15:04:57.007403 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 35, win 227, options [nop,nop,TS val 507416030 ecr 646657], length 0 15:04:58.502805 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 35:39, ack 1, win 229, options [nop,nop,TS val 647031 ecr 507416030], length 4 15:04:58.503039 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 39, win 227, options [nop,nop,TS val 507417525 ecr 647031], length 0 15:05:02.349810 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 39:40, ack 1, win 229, options [nop,nop,TS val 647992 ecr 507417525], length 1 15:05:02.350067 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 40, win 227, options [nop,nop,TS val 507421372 ecr 647992], length 0 15:05:02.582109 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 40:41, ack 1, win 229, options [nop,nop,TS val 648050 ecr 507421372], length 1 15:05:02.582413 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 41, win 227, options [nop,nop,TS val 507421604 ecr 648050], length 0 15:05:05.082504 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 41:54, ack 1, win 229, options [nop,nop,TS val 648675 ecr 507421604], length 13 15:05:05.082746 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 54, win 227, options [nop,nop,TS val 507424105 ecr 648675], length 0 15:05:05.373542 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 54:58, ack 1, win 229, options [nop,nop,TS val 648748 ecr 507424105], length 4 15:05:05.373790 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 58, win 227, options [nop,nop,TS val 507424396 ecr 648748], length 0 15:05:05.628330 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 58:62, ack 1, win 229, options [nop,nop,TS val 648812 ecr 507424396], length 4 15:05:05.628595 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 62, win 227, options [nop,nop,TS val 507424650 ecr 648812], length 0 15:05:06.014253 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 62:63, ack 1, win 229, options [nop,nop,TS val 648908 ecr 507424650], length 1 15:05:06.014547 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 63, win 227, options [nop,nop,TS val 507425036 ecr 648908], length 0 15:05:06.225345 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 63:67, ack 1, win 229, options [nop,nop,TS val 648961 ecr 507425036], length 4 15:05:06.225607 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 67, win 227, options [nop,nop,TS val 507425248 ecr 648961], length 0 15:05:06.404309 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 67:70, ack 1, win 229, options [nop,nop,TS val 649006 ecr 507425248], length 3 15:05:06.404563 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 70, win 227, options [nop,nop,TS val 507425427 ecr 649006], length 0 15:05:06.579484 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 70:73, ack 1, win 229, options [nop,nop,TS val 649050 ecr 507425427], length 3 15:05:06.579939 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 73, win 227, options [nop,nop,TS val 507425602 ecr 649050], length 0 15:05:08.947010 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [P.], seq 73:105, ack 1, win 229, options [nop,nop,TS val 649642 ecr 507425602], length 32 15:05:08.947301 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [.], ack 105, win 227, options [nop,nop,TS val 507427969 ecr 649642], length 0 15:05:09.915135 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [F.], seq 105, ack 1, win 229, options [nop,nop,TS val 649884 ecr 507427969], length 0 15:05:09.915836 IP 192.168.56.102.9999 > 192.168.56.101.35825: Flags [F.], seq 1, ack 106, win 227, options [nop,nop,TS val 507428938 ecr 649884], length 0 15:05:09.915853 IP 192.168.56.101.35825 > 192.168.56.102.9999: Flags [.], ack 2, win 229, options [nop,nop,TS val 649884 ecr 507428938], length 0

In one packet (time stamp 15:04:56.042481 ) exist sample test pattern "TEST".

in my test_sig.rules:
alert tcp any any -> any any (msg: "Test sig"; content: "TEST"; sid: 9000000; classtype: unknown;)

next start suricata:
sudo suricata -c /usr/local/etc/suricata/suricata.yaml -S test_sig.rules -k none -r init_dump.pcap
result:
01/27/2018-15:05:09.915135 [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999

Expected, that alert time must be 15:04:56.042481 (time of packet, containing test string), but it's time 15:05:09.915135 (corresponding to FYN packet).

I reproduce this case on different ways, such, as live replaying it on net, change ip search pattern and ip addresses, but i always got the same result - alert fix time of FIN packet, but not time of packet with pattern.

Files

init_dump.pcap (3.82 KB) init_dump.pcap

Andrey Kiryukhin, 01/27/2018 06:47 AM

Related issues 1 (1 open — 0 closed)

Actions

Copy link

Updated by Andreas Herz almost 7 years ago

Assignee set to OISF Dev
Target version set to TBD

Actions

Copy link

Updated by Andreas Herz over 5 years ago

I can confirm that with 5.0 beta, but might be even intentional to be like that?

Actions

Copy link

Updated by Victor Julien over 5 years ago

This is probably because TCP data is inspected when its ACKd. What if you enable IPS simulation (--simulate-ips). This will put the stream inspection in a more real time mode.

Actions

Copy link

Updated by Andreas Herz over 5 years ago

This is w ith simulate-ips :)

01/27/2018-13:04:56.042481  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:04:56.431254  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:04:56.647552  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:04:56.826973  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:04:57.007120  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:04:58.502805  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:02.349810  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:02.582109  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:05.082504  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:05.373542  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:05.628330  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:06.014253  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:06.225345  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:06.404309  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:06.579484  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999
01/27/2018-13:05:08.947010  [**] [1:9000000:0] Test sig [**] [Classification: Unknown Traffic] [Priority: 3] {TCP} 192.168.56.101:35825 -> 192.168.56.102:9999

Actions

Copy link