On 4/16/19 12:46 PM, Michal Soltys wrote:
> When using hash_mode == 0 with default event_mask, it looks like
> destruction entry has uninitialized (or having some specific meaning)
> flow.start.sec and flow.start.usec - as the former converts to early 1970.
>
> Peeking at the code in event_handler_no_hashtable() it looks like it
> should be set correctly, but alas something seems amiss.
>
> creation event:
>
> {"timestamp": "2019-04-16T12:02:30+0200", "dvc": "testdev",
> "orig.ip.protocol": 6, "orig.l4.sport": 43562, "orig.l4.dport": 22,
> "orig.raw.pktlen": 0, "orig.raw.pktcount": 0, "reply.ip.protocol": 6,
> "reply.l4.sport": 22, "reply.l4.dport": 43562, "reply.raw.pktlen": 0,
> "reply.raw.pktcount": 0, "ct.mark": 0, "ct.id": 784049088, "ct.event":
> 1, "flow.start.sec": 1555408950, "flow.start.usec": 517694,
> "oob.family": 2, "oob.protocol": 0, "src_ip": "192.168.0.254",
> "dest_ip": "10.151.151.22", "reply.ip.saddr.str": "10.151.151.22",
> "reply.ip.daddr.str": "192.168.0.254"}
>
> destruction event:
>
> {"timestamp": "2019-04-16T12:05:00+0200", "dvc": "testdev",
> "orig.ip.protocol": 6, "orig.l4.sport": 43562, "orig.l4.dport": 22,
> "orig.raw.pktlen": 115789, "orig.raw.pktcount": 2011,
> "reply.ip.protocol": 6, "reply.l4.sport": 22, "reply.l4.dport": 43562,
> "reply.raw.pktlen": 28701079, "reply.raw.pktcount": 13119, "ct.mark": 0,
> "ct.id": 784049088, "ct.event": 4, "flow.start.sec": 4084,
> "flow.start.usec": 805056, "flow.end.sec": 1555409100, "flow.end.usec":
> 321544, "oob.family": 2, "oob.protocol": 0, "src_ip": "192.168.0.254",
> "dest_ip": "10.151.151.22", "reply.ip.saddr.str": "10.151.151.22",
> "reply.ip.daddr.str": "192.168.0.254"}
>
> flow.start.sec is 4084 == Thu, 01 Jan 1970 02:08:04 +0100
>
> Any ideas ?
>
For the record, the same unusual timestamp is shown when monitoring with conntrack:
[NEW] tcp 6 120 SYN_SENT src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 [UNREPLIED] src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572
[UPDATE] tcp 6 60 SYN_RECV src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572
[UPDATE] tcp 6 432000 ESTABLISHED src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 [ASSURED]
[UPDATE] tcp 6 120 FIN_WAIT src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 [ASSURED]
[UPDATE] tcp 6 60 CLOSE_WAIT src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 [ASSURED]
[UPDATE] tcp 6 30 LAST_ACK src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 [ASSURED]
[UPDATE] tcp 6 120 TIME_WAIT src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 [ASSURED]
[DESTROY] tcp 6 src=192.168.0.254 dst=10.151.151.22 sport=44572 dport=22 packets=55 bytes=6577 src=10.151.151.22 dst=192.168.0.254 sport=22 dport=44572 packets=51 bytes=8919 [ASSURED] delta-time=1555405003 [start=Thu Jan 1 04:58:06 1970] [stop=Tue Apr 16 14:54:49 2019]
