[Oisf-users] TCP-session and alert on one packet

[Kiryukhin Andrey]

Hello! 
Can somebody explain me, is it normal behavior or not both Suricata 4.0 and 3.2. 

I have sample net dump, which contain one tcp-session:

11:20:41.787698 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [S], seq 2474726826, win 29200, options [mss 1460,sackOK,TS val 2516658250 ecr 0,nop,wscale 7], length 0
11:20:41.787722 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [S.], seq 3807570994, ack 2474726827, win 28960, options [mss 1460,sackOK,TS val 3447113398 ecr 2516658250,nop,wscale 7], length 0
11:20:41.787867 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [.], ack 1, win 229, options [nop,nop,TS val 2516658250 ecr 3447113398], length 0
11:20:44.290843 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [P.], seq 1:6, ack 1, win 229, options [nop,nop,TS val 2516658876 ecr 3447113398], length 5
11:20:44.290871 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [.], ack 6, win 227, options [nop,nop,TS val 3447114024 ecr 2516658876], length 0
11:20:48.554696 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [P.], seq 6:11, ack 1, win 229, options [nop,nop,TS val 2516659942 ecr 3447114024], length 5
11:20:48.554711 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [.], ack 11, win 227, options [nop,nop,TS val 3447115090 ecr 2516659942], length 0
11:21:19.531316 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [P.], seq 11:16, ack 1, win 229, options [nop,nop,TS val 2516667686 ecr 3447115090], length 5
11:21:19.531343 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [.], ack 16, win 227, options [nop,nop,TS val 3447122834 ecr 2516667686], length 0
11:21:22.195568 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [P.], seq 16:21, ack 1, win 229, options [nop,nop,TS val 2516668352 ecr 3447122834], length 5
11:21:22.195584 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [.], ack 21, win 227, options [nop,nop,TS val 3447123500 ecr 2516668352], length 0
11:21:22.931479 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [F.], seq 21, ack 1, win 229, options [nop,nop,TS val 2516668536 ecr 3447123500], length 0
11:21:22.931554 IP 1.1.1.10.9090 > 1.1.1.2.36632: Flags [F.], seq 1, ack 22, win 227, options [nop,nop,TS val 3447123684 ecr 2516668536], length 0
11:21:22.931645 IP 1.1.1.2.36632 > 1.1.1.10.9090: Flags [.], ack 2, win 229, options [nop,nop,TS val 2516668536 ecr 3447123684], length 0


In one packet (time stamp 11:20:48.554696 )  exist sample test pattern "TEST".

in my my_rules.rules: 
alert tcp any any -> any any (msg:"my_rules.rules|Test sig #1";  content: "TEST"; sid: 90022222; )

next start suricata:

suricata -c /usr/local/etc/suricata/suricata.yaml -S my_rules.rules -r  1_session.pcap -l /usr/local/var/log/suricata/

result: 
 
10/03/2017-11:21:22.931479  [**] [1:90022222:0] my_rules.rules|Test sig #1 [**] [Classification: (null)] [Priority: 3] {TCP} 1.1.1.2:36632 -> 1.1.1.10:9090 

And question is, why alert time equal TCP Fyn packet  time 11:21:22.931479 ?  I expect, that time must be 11:20:48.554696 (time of packet, containing test string). 


Ps. 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, containing pattern. 

pps. in suricata 3.2 alert fix time of last packet  11:21:22.931645 instead fin packet. 


Best Regards, Kiryukhin Andrey
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openinfosecfoundation.org/pipermail/oisf-users/attachments/20180125/aa216694/attachment.html>