Packet loss during log rotation

Zeek
1

I’m trying to set up a new standalone Bro instance, but I seem to be experiencing regular packet loss. The host is processing minimal traffic – always <10Mbps, usually around 2Mbps – but I’ve noticed that the packet loss almost always occurs at time of log rotation.

Below is a quick sampling of the notice.log creation date (^#open), and all instances of packet loss, covering today thus far. Is it normal that Bro drops packets during log rotation? Is there some kind of tuning I can/should be doing to address this? Or is this just a red herring?

#open 2014-09-23-00-02-10
2014-09-23T00:02:09+0000 PacketFilter::Dropped_Packets 2866 packets dropped after filtering, 143726 received, 143726 on link
2014-09-23T00:12:09+0000 PacketFilter::Dropped_Packets 94 packets dropped after filtering, 145724 received, 145724 on link

#open 2014-09-23-01-02-10
2014-09-23T01:02:09+0000 PacketFilter::Dropped_Packets 2803 packets dropped after filtering, 152045 received, 152045 on link

#open 2014-09-23-02-02-10
2014-09-23T02:02:09+0000 PacketFilter::Dropped_Packets 2772 packets dropped after filtering, 145405 received, 145405 on link

#open 2014-09-23-03-02-10
2014-09-23T03:02:09+0000 PacketFilter::Dropped_Packets 3197 packets dropped after filtering, 141184 received, 141184 on link
2014-09-23T03:57:09+0000 PacketFilter::Dropped_Packets 6 packets dropped after filtering, 140874 received, 140874 on link

#open 2014-09-23-04-02-10
2014-09-23T04:02:09+0000 PacketFilter::Dropped_Packets 2599 packets dropped after filtering, 136745 received, 136745 on link

#open 2014-09-23-05-02-10
2014-09-23T05:02:09+0000 PacketFilter::Dropped_Packets 2448 packets dropped after filtering, 134282 received, 134282 on link

#open 2014-09-23-06-02-10
2014-09-23T06:02:09+0000 PacketFilter::Dropped_Packets 2921 packets dropped after filtering, 131329 received, 131329 on link

#open 2014-09-23-07-02-10
2014-09-23T07:02:09+0000 PacketFilter::Dropped_Packets 3230 packets dropped after filtering, 139087 received, 139087 on link

#open 2014-09-23-08-00-07
2014-09-23T08:02:09+0000 PacketFilter::Dropped_Packets 44840 packets dropped after filtering, 179889 received, 179884 on link

#open 2014-09-23-09-02-10
2014-09-23T09:02:09+0000 PacketFilter::Dropped_Packets 3291 packets dropped after filtering, 135096 received, 135095 on link

#open 2014-09-23-10-02-10
2014-09-23T10:02:09+0000 PacketFilter::Dropped_Packets 2428 packets dropped after filtering, 134041 received, 134041 on link

#open 2014-09-23-11-02-10
2014-09-23T11:02:09+0000 PacketFilter::Dropped_Packets 2544 packets dropped after filtering, 131655 received, 131655 on link

#open 2014-09-23-12-02-10
2014-09-23T12:02:09+0000 PacketFilter::Dropped_Packets 2655 packets dropped after filtering, 136899 received, 136899 on link

#open 2014-09-23-13-02-10
2014-09-23T13:02:09+0000 PacketFilter::Dropped_Packets 2722 packets dropped after filtering, 142520 received, 142520 on link

2

Are you running in cluster mode or standalone? If you're running in standalone, it's very possible that something is blocking briefly when the logs are rotated which could cause a small back up of packets, leading to loss.

  .Seth

3

Standalone, as I slowly work towards cluster mode. Is there a single
thread handling both reading packets and disk I/O? Even at 5Mbps, I would
have expected a single thread to be able to keep up with everything, unless
it's waiting for compression.

4

Standalone, as I slowly work towards cluster mode.

Switching to cluster mode with a single worker process is easy. Just use the cluster config example and only configure a single worker. Things should work basically the same as before.

Is there a single thread handling both reading packets and disk I/O? Even at 5Mbps, I would have expected a single thread to be able to keep up with everything, unless it's waiting for compression.

Sort of. The actual file I/O is threaded, but I think that the way the external script is called that performs the rotation might accidentally block in some cases. Probably an area we should look into more closely some time.

.Seth

5

Beauty. It does. I was even able to run both configurations together for
a while, to confirm that everything was working as expected.

Thanks!

6

You aren't seeing the packet loss when files rotate anymore? I think we still need to look into the rotation issue, I think that a few other people have seen similar effects.

  .Seth

7

Correct. Granted, it's only been about three rotations with the cluster
configuration, but none of those rotations have resulted in packet loss,
whereas almost every rotation in 'standalone' does.

8

Great!

  .Seth