Weird behavior in Katrina's code.

Hello,

I've noticed weird behavior in Katrina's code. For the following connection (the format is <TS, 4-tuple, ip-len, tcp-len, seq, ack, flags>)

1266506673.653157 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506673.653530 ip2 port2 ip1 port1 40 0 1921250427 888448967 RA
1266506676.651348 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506676.651708 ip2 port2 ip1 port1 40 0 570721244 888448967 RA
1266506682.651195 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506682.651622 ip2 port2 ip1 port1 40 0 1779909088 888448967 RA
1266506694.651297 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506694.651669 ip2 port2 ip1 port1 40 0 2051408459 888448967 RA
1266506718.651252 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506718.651676 ip2 port2 ip1 port1 60 0 3793171500 888448967 SA
1266506718.654752 ip1 port1 ip2 port2 52 0 888448967 3793171501 A
1266506722.256532 ip2 port2 ip1 port1 53 1 3793171501 888448967 PA
1266506722.259266 ip1 port1 ip2 port2 52 0 888448967 3793171502 A
1266506722.260621 ip1 port1 ip2 port2 53 1 888448967 3793171502 PA
1266506722.260981 ip2 port2 ip1 port1 52 0 3793171502 888448968 A
1266506722.261452 ip2 port2 ip1 port1 84 32 3793171502 888448968 PA
1266506722.300346 ip1 port1 ip2 port2 53 1 888448968 3793171534 PA
1266506722.307635 ip1 port1 ip2 port2 52 0 888448969 3793171534 FA
1266506722.340965 ip2 port2 ip1 port1 52 0 3793171534 888448970 A
1266506722.551004 ip2 port2 ip1 port1 52 0 3793171534 888448970 FA
1266506722.554092 ip1 port1 ip2 port2 52 0 888448970 3793171535 A

Katrina's code with conn.bro script produces:

1266506673.653157 48.654478 ip1 ip2 port1 port2 tcp 2 1871921106 RSTR X SrrrrhAdDaFf

While trunk Bro 1.5.1 produces the following (correct) output:

1266506673.653157 0.000373 ip1 ip2 other port1 port2 tcp ? ? REJ X Sr
1266506676.651348 0.000360 ip1 ip2 other port1 port2 tcp ? ? REJ X Sr
1266506682.651195 0.000427 ip1 ip2 other port1 port2 tcp ? ? REJ X Sr
1266506694.651297 0.000372 ip1 ip2 other port1 port2 tcp ? ? REJ X Sr
1266506718.651252 3.899752 ip1 ip2 other port1 port2 tcp 2 33 SF X ShAdDaFf

In both cases connection compressor is off.

The byte count 1871921106 in Katrina's case is the seq number in FIN packet 3793171534 minus seq number 1921250427 announced by ip2 in its first reset, i.e. the code somehow thinks that it's the same connection.

Any thoughts on why this happens?

1266506673.653157 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506673.653530 ip2 port2 ip1 port1 40 0 1921250427 888448967 RA
1266506676.651348 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506676.651708 ip2 port2 ip1 port1 40 0 570721244 888448967 RA
1266506682.651195 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506682.651622 ip2 port2 ip1 port1 40 0 1779909088 888448967 RA
1266506694.651297 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506694.651669 ip2 port2 ip1 port1 40 0 2051408459 888448967 RA
1266506718.651252 ip1 port1 ip2 port2 60 0 888448966 0 S
1266506718.651676 ip2 port2 ip1 port1 60 0 3793171500 888448967 SA

This is a pattern that Bro will interpret differently depending on the
setting of various timeouts defined in bro.init. I'm not sure exactly
which ones would apply here, but it could for example be

  # Upon seeing a RST, flush state after this much time.
  const tcp_reset_delay = 5 secs &redef;

or

  # Upon seeing a normal connection close, flush state after this much time.
  const tcp_close_delay = 5 secs &redef;

If those were different for the runs, that would explain why you're getting
different results from the two Bro runs.

Could that be what's going on?

    Vern

I've checked this, all the timeouts in bro.init are exactly the same, so this not what is going on.

This was tricky to track down. Basically, I had screwed up the connection state when doing a check for un-acked data after a reset. It's now correct, and conn.log should have the expected output.