[Bro-Dev] netmap lb issues - not forwarding packets after a few min

[Scott Campbell]

Currently running bro current (2.5-372) on a Scientific Linux release 
6.9 kernel 2.6.32-696.13.2.el6.x86_64 .  The bro netmap module was added 
per directions:

bro at xdev-m ~/bin> ./bro -N Bro::Netmap
Bro::Netmap - Packet acquisition via Netmap (dynamic, version 1.0)

I downloaded and installed the current git netmap ( 
MODULE_INFO(srcversion, "70F039B58865AAE47076678") ) without issue, and 
there are no messages when the modules load besides what you would 
expect to see.

What I am seeing is when I run the lb application it runs as expected 
for a few minutes, then stops forwarding packets and continues logging 
the same line regardless of how long you wait.  Sample logs follow.

lb starts:

> [root at xdev-w1 lb]# ./lb -i eth5 -o 10 -p8 -B 1024
> 933.751533 main [600] interface is eth5
> 933.751614 main [621] requested 1024 extra buffers
> 934.080683 main [714] successfully opened netmap:eth5 (tx rings: 512)
> 934.080699 main [725] obtained 1024 extra buffers
> 934.081586 main [784] opening pipe named netmap:eth5{0/xT at 1
> 934.081627 nm_mmap [987] do not mmap, inherit from parent
> 934.081639 main [799] successfully opened pipe #1 netmap:eth5{0/xT at 1 (tx slots: 512)
> 934.081646 main [803] zerocopy enabled
> 934.081671 main [784] opening pipe named netmap:eth5{1/xT at 1
> 934.081692 nm_mmap [987] do not mmap, inherit from parent
> 934.081700 main [799] successfully opened pipe #2 netmap:eth5{1/xT at 1 (tx slots: 512)
> 934.081706 main [803] zerocopy enabled
> 934.081729 main [784] opening pipe named netmap:eth5{2/xT at 1
> 934.081746 nm_mmap [987] do not mmap, inherit from parent
> 934.081754 main [799] successfully opened pipe #3 netmap:eth5{2/xT at 1 (tx slots: 512)
> 934.081760 main [803] zerocopy enabled
> 934.081786 main [784] opening pipe named netmap:eth5{3/xT at 1
> 934.081803 nm_mmap [987] do not mmap, inherit from parent
> 934.081813 main [799] successfully opened pipe #4 netmap:eth5{3/xT at 1 (tx slots: 512)
> 934.081819 main [803] zerocopy enabled
> 934.081842 main [784] opening pipe named netmap:eth5{4/xT at 1
> 934.081862 nm_mmap [987] do not mmap, inherit from parent
> 934.081870 main [799] successfully opened pipe #5 netmap:eth5{4/xT at 1 (tx slots: 512)
> 934.081876 main [803] zerocopy enabled
> 934.081899 main [784] opening pipe named netmap:eth5{5/xT at 1
> 934.081916 nm_mmap [987] do not mmap, inherit from parent
> 934.081923 main [799] successfully opened pipe #6 netmap:eth5{5/xT at 1 (tx slots: 512)
> 934.081929 main [803] zerocopy enabled
> 934.081954 main [784] opening pipe named netmap:eth5{6/xT at 1
> 934.081972 nm_mmap [987] do not mmap, inherit from parent
> 934.081980 main [799] successfully opened pipe #7 netmap:eth5{6/xT at 1 (tx slots: 512)
> 934.081986 main [803] zerocopy enabled
> 934.082013 main [784] opening pipe named netmap:eth5{7/xT at 1
> 934.082031 nm_mmap [987] do not mmap, inherit from parent
> 934.082041 main [799] successfully opened pipe #8 netmap:eth5{7/xT at 1 (tx slots: 512)
> 934.082046 main [803] zerocopy enabled
> {"ts":1513728945.082923,"interface":"netmap:eth5{0/xT at 1","output_ring":0,"packets_forwarded":85397,"packets_dropped":0,"data_forward_rate_Mbps":160.3504,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":19.4110,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{1/xT at 1","output_ring":1,"packets_forwarded":65319,"packets_dropped":0,"data_forward_rate_Mbps":29.0976,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":8.5940,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{2/xT at 1","output_ring":2,"packets_forwarded":317351,"packets_dropped":1300,"data_forward_rate_Mbps":395.4482,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":35.4900,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{3/xT at 1","output_ring":3,"packets_forwarded":100570,"packets_dropped":0,"data_forward_rate_Mbps":148.8784,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":16.3190,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{4/xT at 1","output_ring":4,"packets_forwarded":75111,"packets_dropped":0,"data_forward_rate_Mbps":91.5148,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":11.4440,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{5/xT at 1","output_ring":5,"packets_forwarded":66920,"packets_dropped":0,"data_forward_rate_Mbps":66.1700,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":8.0000,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{6/xT at 1","output_ring":6,"packets_forwarded":143992,"packets_dropped":0,"data_forward_rate_Mbps":170.3500,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":17.5980,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5{7/xT at 1","output_ring":7,"packets_forwarded":67032,"packets_dropped":0,"data_forward_rate_Mbps":29.2870,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":5.2020,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728945.082923,"interface":"netmap:eth5","output_ring":null,"packets_received":1035728,"packets_forwarded":921692,"packets_dropped":1300,"non_ip_packets":18,"data_forward_rate_Mbps":1091.0964,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":122.0570,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}
> {"ts":1513728955.083739,"interface":"netmap:eth5{0/xT at 1","output_ring":0,"packets_forwarded":517056,"packets_dropped":31870,"data_forward_rate_Mbps":583.9244,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":46.9350,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{1/xT at 1","output_ring":1,"packets_forwarded":415852,"packets_dropped":0,"data_forward_rate_Mbps":583.7359,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":48.9310,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{2/xT at 1","output_ring":2,"packets_forwarded":998058,"packets_dropped":1300,"data_forward_rate_Mbps":925.2677,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":106.8910,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{3/xT at 1","output_ring":3,"packets_forwarded":836948,"packets_dropped":14154,"data_forward_rate_Mbps":1321.3131,"data_drop_rate_Mbps":15.6000,"packet_forward_rate_kpps":91.2690,"packet_drop_rate_kpps":1.0790,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{4/xT at 1","output_ring":4,"packets_forwarded":409670,"packets_dropped":0,"data_forward_rate_Mbps":519.5414,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":40.8310,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{5/xT at 1","output_ring":5,"packets_forwarded":395510,"packets_dropped":0,"data_forward_rate_Mbps":545.0672,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":42.6580,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{6/xT at 1","output_ring":6,"packets_forwarded":555556,"packets_dropped":0,"data_forward_rate_Mbps":592.1166,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":47.5850,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5{7/xT at 1","output_ring":7,"packets_forwarded":393490,"packets_dropped":0,"data_forward_rate_Mbps":515.1810,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":41.6850,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513728955.083739,"interface":"netmap:eth5","output_ring":null,"packets_received":5323612,"packets_forwarded":4522140,"packets_dropped":47324,"non_ip_packets":18,"data_forward_rate_Mbps":5586.1473,"data_drop_rate_Mbps":15.6000,"packet_forward_rate_kpps":466.7870,"packet_drop_rate_kpps":1.0790,"free_buffer_slots":1024}

this continues for some time then :

> {"ts":1513729195.106307,"interface":"netmap:eth5{0/xT at 1","output_ring":0,"packets_forwarded":4920687,"packets_dropped":33825,"data_forward_rate_Mbps":10.7695,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":2.0180,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{1/xT at 1","output_ring":1,"packets_forwarded":5930891,"packets_dropped":3760,"data_forward_rate_Mbps":47.3625,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":9.5640,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{2/xT at 1","output_ring":2,"packets_forwarded":16009392,"packets_dropped":130519,"data_forward_rate_Mbps":849.3118,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":77.2920,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{3/xT at 1","output_ring":3,"packets_forwarded":7001918,"packets_dropped":1337878,"data_forward_rate_Mbps":36.4586,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":5.6990,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{4/xT at 1","output_ring":4,"packets_forwarded":5250042,"packets_dropped":1403,"data_forward_rate_Mbps":161.3338,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":17.7030,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{5/xT at 1","output_ring":5,"packets_forwarded":5426001,"packets_dropped":0,"data_forward_rate_Mbps":67.0789,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":7.9150,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{6/xT at 1","output_ring":6,"packets_forwarded":5991695,"packets_dropped":0,"data_forward_rate_Mbps":58.6742,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":7.5420,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5{7/xT at 1","output_ring":7,"packets_forwarded":5094833,"packets_dropped":0,"data_forward_rate_Mbps":152.4217,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":15.5730,"packet_drop_rate_kpps":0.0000,"overflow_queue_size":0}
> {"ts":1513729195.106307,"interface":"netmap:eth5","output_ring":null,"packets_received":62232503,"packets_forwarded":55625459,"packets_dropped":1507385,"non_ip_packets":413,"data_forward_rate_Mbps":1383.4110,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":143.3050,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}
> {"ts":1513729195.106307,"interface":"netmap:eth5","output_ring":null,"packets_received":62232503,"packets_forwarded":55625459,"packets_dropped":1507385,"non_ip_packets":413,"data_forward_rate_Mbps":1383.4110,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":143.3050,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}
> {"ts":1513729195.106307,"interface":"netmap:eth5","output_ring":null,"packets_received":62232503,"packets_forwarded":55625459,"packets_dropped":1507385,"non_ip_packets":413,"data_forward_rate_Mbps":1383.4110,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":143.3050,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}
> {"ts":1513729195.106307,"interface":"netmap:eth5","output_ring":null,"packets_received":62232503,"packets_forwarded":55625459,"packets_dropped":1507385,"non_ip_packets":413,"data_forward_rate_Mbps":1383.4110,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":143.3050,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}
> {"ts":1513729195.106307,"interface":"netmap:eth5","output_ring":null,"packets_received":62232503,"packets_forwarded":55625459,"packets_dropped":1507385,"non_ip_packets":413,"data_forward_rate_Mbps":1383.4110,"data_drop_rate_Mbps":0.0000,"packet_forward_rate_kpps":143.3050,"packet_drop_rate_kpps":0.0000,"free_buffer_slots":1024}

The individual sub interfaces created by lb no longer report, but every 
10 seconds (as configured) 9 identical lines (8 from -p 8 , and one from 
eth5) print out with the numbers no longer changing.

Interface counters on eth5 continue to move so the interface is still 
seeing data.  As well the time it takes for this to happen seems to 
vary.  I have reloaded the modules, run lb as a user or root, changed 
the configuration parameters, rebooted the system all to no avail.

Any thoughts?

scott