Bug 222744 - Issues with Intel EM(4) drivers and iflib updates working with netmap
Summary: Issues with Intel EM(4) drivers and iflib updates working with netmap
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: CURRENT
Hardware: amd64 Any
: --- Affects Only Me
Assignee: Stephen Hurd
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-10-02 23:46 UTC by Shirkdog
Modified: 2017-10-30 21:15 UTC (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Shirkdog 2017-10-02 23:46:44 UTC
Tested on 12-CURRENT 

pciconf
em0@pci0:1:0:0: class=0x020000 card=0x115e8086 chip=0x105e8086 rev=0x06 hdr=0x00
 vendor  = 'Intel Corporation'  
 device  = '82571EB Gigabit Ethernet Controller'  
 class= network  
 subclass= ethernet

I wanted to document this issue as things are being updated for the "iflib" improvements in CURRENT. Up until the following commits, doing things with netmap would cause a kernel panic on this intel nic.

https://reviews.freebsd.org/D12140

After this commit, it appeared that I could put this Intel 82571EB NIC into netmap mode with something like tcpdump and see packet data:

tcpdump -i netmap:em0 -nns 0

However, tcpdump only logs 1024 packets, and then just stops logging packets. I tested with another application that puts the interface in netmap mode (lb from the netmap github repo) and it also load balances until it forwards 1024 packets and stops forwarding. In fact, when running the lb app again, and hitting <Ctrl>+C the box panicked. 90% of the time I get a kernel panic, especially if I output the packet data to STDOUT. If I do something like the following, tcpdump will never finish as the count will never reach 1025. 

tcpdump -i netmap:em0 -n -c 1025 

truss output from the pid for tcpdump:
poll({ 3/POLLIN },1,1000)                        = 0 (0x0)
...

Run the same thing again, there are also these interesting NULL frames inserted, this second run lead to a panic:

poll({ 3/POLLIN },1,1000)= 1 (0x1) 
write(1,"23:41:37.192324 00:00:00:00:00:0"...,122) = 122 (0x7a)  
write(1,"\t0x0000:  0000 0000 0000 0000 0"...,68) = 68 (0x44) 
write(1,"\t0x0010:  0000 0000 0000 0000 0"...,68) = 68 (0x44) 
write(1,"\t0x0020:  0000 0000 0000 0000 0"...,68) = 68 (0x44) 
write(1,"\t0x0030:  0000 0000 0000 0000 0"...,68) = 68 (0x44) 
write(1,"\t0x0040:  0000 0000 0000 0000 0"...,68) = 68 (0x44) 
write(1,"\t0x0050:  0000  "...,54) = 54 (0x36) 
poll({ 3/POLLIN },1,1000)= 1 (0x1) 
write(1,"23:41:37.218808 IP xx.xxx.xxx.xx"...,119) = 119 (0x77)  
poll({ 3/POLLIN },1,1000)= 1 (0x1)


I am working on getting a textdump of the panic, but the backtrace was the following:

em_isc_rxd_pkt_get() at em_isc_rxd_pkt_get+0xf1
iflib_netmap_rxsysnc() at iflib_netmap_rxsync+0x235
netmap_poll() at netmap_poll+0x79c
freebsd_netmap_poll() at freebsd_netmap_poll+0x32
devfs_poll_f() at devfs_poll_f+0x7f


systl for hw.em and dev.em.0

hw.em.max_interrupt_rate: 8000  
hw.em.eee_setting: 1
hw.em.rx_process_limit: -1
hw.em.sbp: 1  
hw.em.smart_pwr_down: 0
hw.em.rx_abs_int_delay: 66
hw.em.tx_abs_int_delay: 66
hw.em.rx_int_delay: 0  
hw.em.tx_int_delay: 66 
hw.em.disable_crc_stripping: 0 
dev.em.0.wake: 0 
dev.em.0.interrupts.rx_overrun: 0  
dev.em.0.interrupts.rx_desc_min_thresh: 0
dev.em.0.interrupts.tx_queue_min_thresh: 0  
dev.em.0.interrupts.tx_queue_empty: 0 
dev.em.0.interrupts.tx_abs_timer: 0
dev.em.0.interrupts.tx_pkt_timer: 0
dev.em.0.interrupts.rx_abs_timer: 0
dev.em.0.interrupts.rx_pkt_timer: 23343  
dev.em.0.interrupts.asserts: 71321923 
dev.em.0.mac_stats.tso_ctx_fail: 0 
dev.em.0.mac_stats.tso_txd: 0
dev.em.0.mac_stats.tx_frames_1024_1522: 0
dev.em.0.mac_stats.tx_frames_512_1023: 0 
dev.em.0.mac_stats.tx_frames_256_511: 0  
dev.em.0.mac_stats.tx_frames_128_255: 0  
dev.em.0.mac_stats.tx_frames_65_127: 0
dev.em.0.mac_stats.tx_frames_64: 0 
dev.em.0.mac_stats.mcast_pkts_txd: 0  
dev.em.0.mac_stats.bcast_pkts_txd: 0  
dev.em.0.mac_stats.good_pkts_txd: 0
dev.em.0.mac_stats.total_pkts_txd: 0  
dev.em.0.mac_stats.good_octets_txd: 0 
dev.em.0.mac_stats.good_octets_recvd: 175021103382
dev.em.0.mac_stats.rx_frames_1024_1522: 110020952 
dev.em.0.mac_stats.rx_frames_512_1023: 3556274 
dev.em.0.mac_stats.rx_frames_256_511: 4759999  
dev.em.0.mac_stats.rx_frames_128_255: 9906052  
dev.em.0.mac_stats.rx_frames_65_127: 20994339  
dev.em.0.mac_stats.rx_frames_64: 32014796
dev.em.0.mac_stats.mcast_pkts_recvd: 7805
dev.em.0.mac_stats.bcast_pkts_recvd: 10  
dev.em.0.mac_stats.good_pkts_recvd: 181252412  
dev.em.0.mac_stats.total_pkts_recvd: 181878781 
dev.em.0.mac_stats.xoff_txd: 0  
dev.em.0.mac_stats.xoff_recvd: 0
dev.em.0.mac_stats.xon_txd: 0
dev.em.0.mac_stats.xon_recvd: 0 
dev.em.0.mac_stats.coll_ext_errs: 0
dev.em.0.mac_stats.alignment_errs: 0  
dev.em.0.mac_stats.crc_errs: 0  
dev.em.0.mac_stats.recv_errs: 0 
dev.em.0.mac_stats.recv_jabber: 0  
dev.em.0.mac_stats.recv_oversize: 0
dev.em.0.mac_stats.recv_fragmented: 0 
dev.em.0.mac_stats.recv_undersize: 0  
dev.em.0.mac_stats.recv_no_buff: 126  
dev.em.0.mac_stats.missed_packets: 626369
dev.em.0.mac_stats.defer_count: 0  
dev.em.0.mac_stats.sequence_errors: 0 
dev.em.0.mac_stats.symbol_errors: 0
dev.em.0.mac_stats.collision_count: 0 
dev.em.0.mac_stats.late_coll: 0 
dev.em.0.mac_stats.multiple_coll: 0
dev.em.0.mac_stats.single_coll: 0  
dev.em.0.mac_stats.excess_coll: 0  
dev.em.0.queue_rx_0.rx_irq: 0
dev.em.0.queue_rx_0.rxd_tail: 650  
dev.em.0.queue_rx_0.rxd_head: 652  
dev.em.0.queue_tx_0.tx_irq: 0
dev.em.0.queue_tx_0.txd_tail: 0 
dev.em.0.queue_tx_0.txd_head: 0 
dev.em.0.fc_low_water: 21028 
dev.em.0.fc_high_water: 22528
dev.em.0.rx_control: 100892734  
dev.em.0.device_control: 787009 
dev.em.0.watchdog_timeouts: 0
dev.em.0.rx_overruns: 0
dev.em.0.tx_dma_fail: 0
dev.em.0.mbuf_defrag_fail: 0 
dev.em.0.link_irq: 0
dev.em.0.dropped: 0 
dev.em.0.eee_control: 1
dev.em.0.itr: 488
dev.em.0.tx_abs_int_delay: 66
dev.em.0.rx_abs_int_delay: 66
dev.em.0.tx_int_delay: 66 
dev.em.0.rx_int_delay: 0  
dev.em.0.rs_dump: 0 
dev.em.0.reg_dump: General Registers  
  CTRL  000c0241 
  STATUS00080383 
  CTRL_EXIT  101400c0  
  
Interrupt Registers 
  ICR00000000 
  
RX Registers  
  RCTL  0603803e 
  RDLEN 00004000 
  RDH0000028c 
  RDT0000028a 
  RXDCTL00010000 
  RDBAL 029a8000 
  RDBAH 00000000 
  
TX Registers  
  TCTL  3103f0fa 
  TDBAL 056dc000 
  TDBAH 00000000 
  TDLEN 00004000 
  TDH00000000 
  TDT00000000 
  TXDCTL0341011f 
  TDFH  00001000 
  TDFT  00001000 
  TDFHS 00001000 
  TDFPC 00000000 
  
  
dev.em.0.fc: 3
dev.em.0.debug: -1  
dev.em.0.nvm: -1 
dev.em.0.iflib.rxq0.rxq_fl0.credits: 1023
dev.em.0.iflib.rxq0.rxq_fl0.cidx: 652 
dev.em.0.iflib.rxq0.rxq_fl0.pidx: 651 
dev.em.0.iflib.txq0.r_abdications: 0  
dev.em.0.iflib.txq0.r_restarts: 0  
dev.em.0.iflib.txq0.r_stalls: 0 
dev.em.0.iflib.txq0.r_starts: 0 
dev.em.0.iflib.txq0.r_drops: 0  
dev.em.0.iflib.txq0.r_enqueues: 0  
dev.em.0.iflib.txq0.ring_state: pidx_head: 0000 pidx_tail: 0000 cidx: 0000 state: IDLE
dev.em.0.iflib.txq0.txq_cleaned: 0 
dev.em.0.iflib.txq0.txq_processed: 0  
dev.em.0.iflib.txq0.txq_in_use: 0  
dev.em.0.iflib.txq0.txq_cidx_processed: 0
dev.em.0.iflib.txq0.txq_cidx: 0 
dev.em.0.iflib.txq0.txq_pidx: 0 
dev.em.0.iflib.txq0.no_tx_dma_setup: 0
dev.em.0.iflib.txq0.txd_encap_efbig: 0
dev.em.0.iflib.txq0.tx_map_failed: 0  
dev.em.0.iflib.txq0.no_desc_avail: 0  
dev.em.0.iflib.txq0.mbuf_defrag_failed: 0
dev.em.0.iflib.txq0.m_pullups: 0
dev.em.0.iflib.txq0.mbuf_defrag: 0 
dev.em.0.iflib.override_nrxds: 0
dev.em.0.iflib.override_ntxds: 0
dev.em.0.iflib.disable_msix: 0  
dev.em.0.iflib.override_qs_enable: 0  
dev.em.0.iflib.override_nrxqs: 0
dev.em.0.iflib.override_ntxqs: 0
dev.em.0.iflib.driver_version: 7.6.1-k
dev.em.0.%parent: pci1 
dev.em.0.%pnpinfo: vendor=0x8086 device=0x105e subvendor=0x8086 subdevice=0x115e class=0x020000
dev.em.0.%location: slot=0 function=0 dbsf=pci0:1:0:0 handle=\_SB_.PCI0.PEG0.PEGP  
dev.em.0.%driver: em
dev.em.0.%desc: Intel(R) PRO/1000 Network Connection


dmesg:
[1] em0: <Intel(R) PRO/1000 Network Connection> port 0xe020-0xe03f mem 0xf7da0000-0xf7dbffff,0xf7d80000-0xf7d9ffff irq 16 at device 0.0 on pci1
[1] em0: attach_pre capping queues at 1  
[1] em0: using 1024 tx descriptors and 1024 rx descriptors 
[1] em0: msix_init qsets capped at 1  
[1] em0: PCIY_MSIX capability not found; or rid 0 == 0. 
[1] em0: Using an MSI interrupt 
[1] em0: allocated for 1 tx_queues 
[1] em0: allocated for 1 rx_queues 
[1] taskqgroup_attach: setaffinity failed: 3
[1] taskqgroup_attach: setaffinity failed: 3
[1] em0: Ethernet address: 68:05:ca:33:42:f0
[1] em0: netmap queues/slots: TX 1/1024, RX 1/1024
Comment 1 Stephen Hurd freebsd_committer freebsd_triage 2017-10-23 16:48:54 UTC
Please test https://reviews.freebsd.org/D12769
Comment 2 commit-hook freebsd_committer freebsd_triage 2017-10-30 21:14:38 UTC
A commit references this bug:

Author: shurd
Date: Mon Oct 30 21:14:31 UTC 2017
New revision: 325167
URL: https://svnweb.freebsd.org/changeset/base/325167

Log:
  Fix PR222744 - netmap errors with iflib em driver

  Fix error when refilling netmap buffers that resulted in the first
  buffer of the successive passes through ifl_bus_addrs[] leaving the
  first value unset (tmp_pidx started at 1, not zero after the first time
  through the loop).

  Leave the one unused buffer required by some NICs visible in the netmap
  ring rather than hidden. There will always be a buffer in use by the
  kernel now when an iflib driver is used via netmap.

  Always get the netmap slot index via netmap_idx_n2k() to account for
  nkr_hwofs in a consistent way.

  Split shared functionality into new functions.
  iru_init(): shared by _iflib_fl_refill() and netmap_fl_refill()
  netmap_fl_refill(): shared by iflib_netmap_rxsync() and
  iflib_netmap_rxq_init()

  PR:		222744
  Reported by:	Shirkdog <mshirk@daemon-security.com>
  Reviewed by:	sbruno
  Approved by:	sbruno (mentor)
  Sponsored by:	Limelight Networks
  Differential Revision:	https://reviews.freebsd.org/D12769

Changes:
  head/sys/net/iflib.c