[Zeek] Capture packet loss discrepancy
Michał Purzyński
michalpurzynski1 at gmail.com
Fri Mar 6 02:39:07 PST 2020
You either drop data before it reaches Zeek sensors or you have an
offloading missconfiguration on the card or you have a load-balancing
problem. That might be a good news.
The capture.log file is based on heuristics "I have seen some ACKs without
matching data packets" - but won't tell you where the problem is. Justin
calls it a "check engine light".
You don't seem to have drops in stats.log and in ethtool stats. That's
great. Stats.log meaning is different for each capture method and it's
never enough without some ethtool stats.
Can you tell us more about your setup?
- how are you feeding your sensor (taps, span ports, etc)
- what's your capture mechanism?
- can you share all commands for interface's configuration?
- can you share the node.cfg
- output of
ethtool -c <interface>
ethtool -l <interface>
ethtool -x <interface>
ethtool -a <interface>
ethtool -g <interface>
On Fri, Mar 6, 2020 at 2:19 AM Federico Foschini <undicizeri at gmail.com>
wrote:
> Hello,
> I’m using Zeek 3.0.1 and I’m seeing very high zeek capture loss even if
> the system load is very low (I’m analyzing 50-100mbps of traffic with a
> Xeon 8C-16T and 32GiB of ram, the system load is barely rearching 1).
>
> This is what
> https://docs.zeek.org/en/stable/scripts/policy/misc/capture-loss.zeek.html
> is reporting:
>
> {"_path":"capture_loss","_write_ts":"2020-03-06T10:00:28.080623Z","ts":"2020-03-06T10:00:28.080623Z","ts_delta":900.0000138282776,"peer":"worker-1-1","gaps":980763,"acks":3451717,"percent_lost":28.4137720444
> 6367}
> {"_path":"capture_loss","_write_ts":"2020-03-06T09:45:28.080609Z","ts":"2020-03-06T09:45:28.080609Z","ts_delta":900.0000011920929,"peer":"worker-1-1","gaps":775832,"acks":3944662,"percent_lost":19.6678955002
> 98886}
>
> But in Zeek stats logs I cannot see any drops:
>
> {"_path":"stats","_write_ts":"2020-03-06T10:00:25.184307Z","ts":"2020-03-06T10:00:25.184307Z","peer":"manager","mem":99,"pkts_proc":0,"bytes_recv":0,"events_proc":2171,"events_queued":2175,"active_tcp_conns"
> :0,"active_udp_conns":0,"active_icmp_conns":0,"tcp_conns":0,"udp_conns":0,"icmp_conns":0,"timers":1097,"active_timers":77,"files":0,"active_files":0,"dns_requests":0,"active_dns_requests":0,"reassem_tcp_size
> ":0,"reassem_file_size":0,"reassem_frag_size":0,"reassem_unknown_size":0}
> {"_path":"stats","_write_ts":"2020-03-06T10:00:26.676726Z","ts":"2020-03-06T10:00:26.676726Z","peer":"proxy-1","mem":95,"pkts_proc":0,"bytes_recv":0,"events_proc":1579,"events_queued":1579,"active_tcp_conns"
> :0,"active_udp_conns":0,"active_icmp_conns":0,"tcp_conns":0,"udp_conns":0,"icmp_conns":0,"timers":939,"active_timers":39,"files":0,"active_files":0,"dns_requests":0,"active_dns_requests":0,"reassem_tcp_size"
> :0,"reassem_file_size":0,"reassem_frag_size":0,"reassem_unknown_size":0}
> {"_path":"stats","_write_ts":"2020-03-06T10:00:28.087807Z","ts":"2020-03-06T10:00:28.087807Z","peer":"worker-1-1","mem":494,"pkts_proc":4342283,"bytes_recv":3395272841,"pkts_dropped":0,"pkts_link":4347989,"p
> kt_lag":0.010818004608154297,"events_proc":894955,"events_queued":894955,"active_tcp_conns":2944,"active_udp_conns":473,"active_icmp_conns":70,"tcp_conns":9036,"udp_conns":7376,"icmp_conns":383,"timers":2168
> 06,"active_timers":11468,"files":10693,"active_files":10,"dns_requests":2,"active_dns_requests":0,"reassem_tcp_size":500680,"reassem_file_size":451064,"reassem_frag_size":0,"reassem_unknown_size":0}
> {"_path":"stats","_write_ts":"2020-03-06T10:05:25.185129Z","ts":"2020-03-06T10:05:25.185129Z","peer":"manager","mem":99,"pkts_proc":0,"bytes_recv":0,"events_proc":3573,"events_queued":3569,"active_tcp_conns"
> :0,"active_udp_conns":0,"active_icmp_conns":0,"tcp_conns":0,"udp_conns":0,"icmp_conns":0,"timers":1063,"active_timers":77,"files":0,"active_files":0,"dns_requests":0,"active_dns_requests":0,"reassem_tcp_size
> ":0,"reassem_file_size":0,"reassem_frag_size":0,"reassem_unknown_size":0}
> {"_path":"stats","_write_ts":"2020-03-06T10:05:26.677296Z","ts":"2020-03-06T10:05:26.677296Z","peer":"proxy-1","mem":95,"pkts_proc":0,"bytes_recv":0,"events_proc":2101,"events_queued":2101,"active_tcp_conns"
> :0,"active_udp_conns":0,"active_icmp_conns":0,"tcp_conns":0,"udp_conns":0,"icmp_conns":0,"timers":933,"active_timers":39,"files":0,"active_files":0,"dns_requests":0,"active_dns_requests":0,"reassem_tcp_size"
> :0,"reassem_file_size":0,"reassem_frag_size":0,"reassem_unknown_size":0}
> {"_path":"stats","_write_ts":"2020-03-06T10:05:28.087831Z","ts":"2020-03-06T10:05:28.087831Z","peer":"worker-1-1","mem":494,"pkts_proc":4024429,"bytes_recv":3075761558,"pkts_dropped":0,"pkts_link":4029762,"p
> kt_lag":0.012360095977783203,"events_proc":860917,"events_queued":860919,"active_tcp_conns":3043,"active_udp_conns":505,"active_icmp_conns":149,"tcp_conns":10006,"udp_conns":7298,"icmp_conns":483,"timers":23
> 2394,"active_timers":12492,"files":11763,"active_files":13,"dns_requests":0,"active_dns_requests":0,"reassem_tcp_size":60920,"reassem_file_size":955592,"reassem_frag_size":0,"reassem_unknown_size":0}
>
> My network interface reports 0 drops:
>
> NIC statistics:
> rx_packets: 57185146109
> tx_packets: 118236
> rx_bytes: 51106679706383
> tx_bytes: 12060072
> rx_broadcast: 28116614
> tx_broadcast: 0
> rx_multicast: 430062675
> tx_multicast: 0
> multicast: 430062675
> collisions: 0
> rx_crc_errors: 0
> rx_no_buffer_count: 0
> rx_missed_errors: 0
> tx_aborted_errors: 0
> tx_carrier_errors: 0
> tx_window_errors: 0
> tx_abort_late_coll: 0
> tx_deferred_ok: 0
> tx_single_coll_ok: 0
> tx_multi_coll_ok: 0
> tx_timeout_count: 0
> rx_long_length_errors: 0
> rx_short_length_errors: 0
> rx_align_errors: 0
> tx_tcp_seg_good: 0
> tx_tcp_seg_failed: 0
> rx_flow_control_xon: 0
> rx_flow_control_xoff: 0
> tx_flow_control_xon: 0
> tx_flow_control_xoff: 0
> rx_long_byte_count: 51106679706383
> tx_dma_out_of_sync: 0
> tx_smbus: 0
> rx_smbus: 0
> dropped_smbus: 0
> os2bmc_rx_by_bmc: 0
> os2bmc_tx_by_bmc: 0
> os2bmc_tx_by_host: 0
> os2bmc_rx_by_host: 0
> tx_hwtstamp_timeouts: 0
> rx_hwtstamp_cleared: 0
> rx_errors: 0
> tx_errors: 0
> tx_dropped: 0
> rx_length_errors: 0
> rx_over_errors: 0
> rx_frame_errors: 0
> rx_fifo_errors: 0
> tx_fifo_errors: 0
> tx_heartbeat_errors: 0
> tx_queue_0_packets: 0
> tx_queue_0_restart: 0
> tx_queue_1_packets: 118236
> tx_queue_1_bytes: 11587128
> tx_queue_1_restart: 0
> tx_queue_2_packets: 0
> tx_queue_2_bytes: 0
> tx_queue_2_restart: 0
> tx_queue_3_packets: 0
> tx_queue_3_bytes: 0
> tx_queue_3_restart: 0
> tx_queue_4_packets: 0
> tx_queue_4_bytes: 0
> tx_queue_4_restart: 0
> tx_queue_5_packets: 0
> tx_queue_5_bytes: 0
> tx_queue_5_restart: 0
> tx_queue_6_packets: 0
> tx_queue_6_bytes: 0
> tx_queue_6_restart: 0
> tx_queue_7_packets: 0
> tx_queue_7_bytes: 0
> tx_queue_7_restart: 0
> rx_queue_0_packets: 7309311690
> rx_queue_0_bytes: 6672057827542
> rx_queue_0_drops: 0
> rx_queue_0_csum_err: 0
> rx_queue_0_alloc_failed: 0
> rx_queue_1_packets: 7067404359
> rx_queue_1_bytes: 5978548722708
> rx_queue_1_drops: 0
> rx_queue_1_csum_err: 0
> rx_queue_1_alloc_failed: 0
> rx_queue_2_packets: 6936589456
> rx_queue_2_bytes: 5816850955623
> rx_queue_2_drops: 0
> rx_queue_2_csum_err: 0
> rx_queue_2_alloc_failed: 0
> rx_queue_3_packets: 7560820836
> rx_queue_3_bytes: 7177372551363
> rx_queue_3_drops: 0
> rx_queue_3_csum_err: 0
> rx_queue_3_alloc_failed: 0
> rx_queue_4_packets: 6665690657
> rx_queue_4_bytes: 5815406197188
> rx_queue_4_drops: 0
> rx_queue_4_csum_err: 0
> rx_queue_4_alloc_failed: 0
> rx_queue_5_packets: 7245905157
> rx_queue_5_bytes: 6640952714842
> rx_queue_5_drops: 0
> rx_queue_5_csum_err: 0
> tx_queue_5_restart: 0
> tx_queue_6_packets: 0
> tx_queue_6_bytes: 0
> tx_queue_6_restart: 0
> tx_queue_7_packets: 0
> tx_queue_7_bytes: 0
> tx_queue_7_restart: 0
> rx_queue_0_packets: 7309311690
> rx_queue_0_bytes: 6672057827542
> rx_queue_0_drops: 0
> rx_queue_0_csum_err: 0
> rx_queue_0_alloc_failed: 0
> rx_queue_1_packets: 7067404359
> rx_queue_1_bytes: 5978548722708
> rx_queue_1_drops: 0
> rx_queue_1_csum_err: 0
> rx_queue_1_alloc_failed: 0
> rx_queue_2_packets: 6936589456
> rx_queue_2_bytes: 5816850955623
> rx_queue_2_drops: 0
> rx_queue_2_csum_err: 0
> rx_queue_2_alloc_failed: 0
> rx_queue_3_packets: 7560820836
> rx_queue_3_bytes: 7177372551363
> rx_queue_3_drops: 0
> rx_queue_3_csum_err: 0
> rx_queue_3_alloc_failed: 0
> rx_queue_4_packets: 6665690657
> rx_queue_4_bytes: 5815406197188
> rx_queue_4_drops: 0
> rx_queue_4_csum_err: 0
> rx_queue_4_alloc_failed: 0
> rx_queue_5_packets: 7245905157
> rx_queue_5_bytes: 6640952714842
> rx_queue_5_drops: 0
> rx_queue_5_csum_err: 0
> rx_queue_5_alloc_failed: 0
> rx_queue_6_packets: 7693400503
> rx_queue_6_bytes: 6803443308105
> rx_queue_6_drops: 0
> rx_queue_6_csum_err: 0
> rx_queue_6_alloc_failed: 0
> rx_queue_7_packets: 6706023451
> rx_queue_7_bytes: 5768995611822
> rx_queue_7_drops: 0
> rx_queue_7_csum_err: 0
> rx_queue_7_alloc_failed: 0
>
> Is there something am I missing? Is it a way to further analyze the
> problem? By looking in zeek logs everything looks fine.
> --
> Federico Foschini.
> _______________________________________________
> Zeek mailing list
> zeek at zeek.org
> http://mailman.ICSI.Berkeley.EDU/mailman/listinfo/zeek
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mailman.ICSI.Berkeley.EDU/pipermail/zeek/attachments/20200306/2cbaa6be/attachment-0001.html
More information about the Zeek
mailing list