timer delays between different events for same connection

So I am seeing some weird stuff in my sample pcap of scanners. May be too
obvious and I am just not seeing why/how of it.

Here is the issue : ( I have time in human format for easier read):

SO I just pick one session from conn.log and this is the connection in
question: (there are many more like this):

$ fgrep CspAa42NoEGEaXK4ci conn.log | cf
Apr 12 05:37:42 CspAa42NoEGEaXK4ci 191.254.157.138 45107 128.3.97.204 23 tcp - - - - S0 F T 0 S 1 40 0 0 -

Now as part of debugging I have dumped network_time for various events which
process this connection:

Apr 12 05:37:42 new_connection CspAa42NoEGEaXK4ci
Apr 12 06:13:48 connection_attempt CspAa42NoEGEaXK4ci
Apr 12 06:13:48 connection_state_remove CspAa42NoEGEaXK4ci

Now my understanding is there are various timers involved upon whose expirations
bro infers events such as connection_attempt, connection_reset etc etc. Timers
such as tcp_attempt_delay, tcp_SYN_timeout, tcp_close_delay amongst others. But
all these timers are generally 5 seconds.

Q. Why would connection_attempt event kick in after 36 minutes and 6 seconds ? (
06:13:48 - 05:37:42 ) ?

I have a pcap to share if anyone is interested and replicate on their end.

Aashish

So I am seeing some weird stuff in my sample pcap of scanners. May be too
obvious and I am just not seeing why/how of it.

It's a straight forward answer but not completely obvious. :slight_smile:

Q. Why would connection_attempt event kick in after 36 minutes and 6 seconds ? (
06:13:48 - 05:37:42 ) ?

I bet that you have a jump in timestamps in your pcap. Since Bro's internal clock is driven forward by seeing timestamps associated with packets it's possible that your pcap has a 36 minute jump in timestamps so Bro couldn't have possibly expired anything in the time before that because from its perspective there was an immediate jump in time. You don't normally experience the effects of this behavior in traffic you're sniffing live because you will tend to have many packets every second so you see Bro's clock driven forward in very tiny increments as you would expect. If you go a long time without receiving a packet is when stuff gets tricky.

   .Seth

Ah! it is obvious now!

Yep that was it. Its a relatively slow scan and I only extracted all activity
for this specific source IP out of timemachine.

I didn't see this behavior in other test cases because there I pull scanners
based on ports so somewhat of more 'fluid' traffic.

Thanks,
Aashish