[Oisf-users] Alert Timestamps Off/Incorrect

[Jason Holmes]

Hi,

This afternoon we detected an event via several different sensors.  Two 
of the sensors logged the event within seconds of when it happened with 
timestamps within seconds of the corresponding network traffic. 
Suricata received the same traffic at the same time but logged it much 
later and when it did, the timestamps for the alerts in the fast.log 
were off by a significant amount of time and not at all representative 
of when the network traffic for the event occurred.

The event consisted largely of one-way communication - inbound 
communication matched sensor rules but the traffic was blocked between 
the sensors and the target once a device in front of the target detected 
the event.  My wild guess is that enough traffic was allowed for 
Suricata to start tracking a flow and when the return traffic was 
blocked, Suricata didn't log anything until the flow timed out and when 
it did log, it used the timestamp from when the flow timed out, not from 
when malicious network traffic was seen.  This theory is supported to 
some extent since the offset between when the event happened and when 
Suricata logged it happens to match nicely with our setting for the TCP 
established flow timeout.

I have two questions based on this:

1. What are the timestamps that Suricata uses in its alert files 
representative of?  Are they supposed to represent when an event 
occurred, when the log line was written, or something else?

2. Is the above delayed logging behavior intended?  If this behavior is 
not intended and any of the developers would like more information to 
dig into this, I can provide it privately.

This was with Suricata 3.0rc1.

Thanks,

--
Jason Holmes