Bug 200221

Created attachment 156797 [details]
dmesg.boot and pciconf -lv outputs for machine2 (2x Xeon)

(In reply to anthony from comment #0)
I should have added - neither machine experienced these problems until they were upgraded to 10.1-RELEASE.

Can you try to disable tso4 on em interfaces?

Disabled tso4 on em0, not had any problems so far over two backup runs. I'll keep monitoring it, as it doesn't happen every time.

It's now been a week, disabling tso4 does seem to have resolved this. What could be the reason for this now being required? As mentioned, I don't recall this happening before it was upgraded to 10.1-RELEASE (previously 10.0-RELEASE).

I think it's some bug due to em(4) upgrade in 10.1

https://svnweb.freebsd.org/base?view=revision&revision=269196

I've now built a 10.1-RELEASE-p10 kernel with sys/dev/e1000 rolled back to before 269196. tso4 is enabled, I'll test this out over a few days and see what happens.

Now had two weeks under the 10.1-RELEASE-p10 kernel with e1000 rolled back to 269196 and I've not seen any timeouts. I'll try moving e1000 forwards to try and find the problem commit that is the cause.

The are some updates of em(4) driver in CURRENT, which are already MFC'd to 10-STABLE. It has some fixes, which may be related to your issue. So you can try it.

https://svnweb.freebsd.org/base/head/sys/dev/e1000/if_em.c?revision=283959&view=markup&sortby=date

Now using sys/dev/e1000@283959 from 10-STABLE (rest of the kernel 10.1-RELEASE as before), I'm seeing watchdog timeouts again, with tso4 enabled. Again, this only seems to happen at a point of high network load (nightly backup over NFS). I'll try disabling tso4 on this revision but failing that, will go back to e1000@269196.

There is slightly more detail in messages now, though: 

Jul  8 07:31:58 urybsod kernel: em0: Watchdog timeout Queue[0]-- resetting
Jul  8 07:31:58 urybsod kernel: Interface is RUNNING and ACTIVE
Jul  8 07:31:58 urybsod kernel: em0: TX Queue 0 ------
Jul  8 07:31:58 urybsod kernel: em0: hw tdh = 909, hw tdt = 1015
Jul  8 07:31:58 urybsod kernel: em0: Tx Queue Status = -2147483648
Jul  8 07:31:58 urybsod kernel: em0: TX descriptors avail = 914
Jul  8 07:31:58 urybsod kernel: em0: Tx Descriptors avail failure = 114
Jul  8 07:31:58 urybsod kernel: em0: RX Queue 0 ------
Jul  8 07:31:58 urybsod kernel: em0: hw rdh = 959, hw rdt = 958
Jul  8 07:31:58 urybsod kernel: em0: RX discarded packets = 0
Jul  8 07:31:58 urybsod kernel: em0: RX Next to Check = 959
Jul  8 07:31:58 urybsod kernel: em0: RX Next to Refresh = 958
Jul  8 07:31:58 urybsod kernel: em0: Link is Down
Jul  8 07:31:58 urybsod kernel: em0: link state changed to DOWN
Jul  8 07:32:01 urybsod kernel: em0: Link is up 1000 Mbps Full Duplex
Jul  8 07:32:01 urybsod kernel: em0: link state changed to UP
Jul  8 07:32:01 urybsod devd: Executing '/etc/rc.d/dhclient quietstart em0'

Comment 11 Sean Bruno 2015-07-15 16:19:23 UTC

Can you try the following patch to if_em.c and see if it helps?  I'm trying to diagnose this here.

Index: dev/e1000/if_em.c
===================================================================
--- dev/e1000/if_em.c	(revision 285481)
+++ dev/e1000/if_em.c	(working copy)
@@ -3034,6 +3034,9 @@
 	if_setflags(ifp, IFF_BROADCAST | IFF_SIMPLEX | IFF_MULTICAST);
 	if_setioctlfn(ifp, em_ioctl);
 	if_setgetcounterfn(ifp, em_get_counter);
+	ifp->if_hw_tsomax = 65518; /* 32*MCLBYTES - max_mac_hdr_len*/
+	ifp->if_hw_tsomaxsegcount = EM_MAX_SCATTER;
+	ifp->if_hw_tsomaxsegsize = 65536;
 #ifdef EM_MULTIQUEUE
 	/* Multiqueue stack interface */
 	if_settransmitfn(ifp, em_mq_start);

Had to make a couple of changes to get that patch into a 10.1-RELEASE kernel:

-- Brought sys/dev/e1000 up to 10-STABLE (as previous)
-- Merged r274043 and r274704 from 10-STABLE

Unfortunately, it hasn't resolved the issue - see below. TSO4 is enabled.

Jul 21 07:36:56 urybsod kernel: em0: Watchdog timeout Queue[0]-- resetting
Jul 21 07:36:56 urybsod kernel: Interface is RUNNING and ACTIVE
Jul 21 07:36:56 urybsod kernel: em0: TX Queue 0 ------
Jul 21 07:36:56 urybsod kernel: em0: hw tdh = 271, hw tdt = 814
Jul 21 07:36:56 urybsod kernel: em0: Tx Queue Status = -2147483648
Jul 21 07:36:56 urybsod kernel: em0: TX descriptors avail = 477
Jul 21 07:36:56 urybsod kernel: em0: Tx Descriptors avail failure = 0
Jul 21 07:36:56 urybsod kernel: em0: RX Queue 0 ------
Jul 21 07:36:56 urybsod kernel: em0: hw rdh = 9, hw rdt = 8
Jul 21 07:36:56 urybsod kernel: em0: RX discarded packets = 0
Jul 21 07:36:56 urybsod kernel: em0: RX Next to Check = 9
Jul 21 07:36:56 urybsod kernel: em0: RX Next to Refresh = 8
Jul 21 07:36:56 urybsod kernel: em0: Link is Down
Jul 21 07:36:56 urybsod kernel: em0: link state changed to DOWN
Jul 21 07:37:00 urybsod kernel: em0: Link is up 1000 Mbps Full Duplex
Jul 21 07:37:00 urybsod kernel: em0: link state changed to UP
Jul 21 07:37:00 urybsod devd: Executing '/etc/rc.d/dhclient quietstart em0'

Comment 13 Sean Bruno 2015-08-03 16:44:05 UTC

(In reply to anthony from comment #12)
Ok, I think I've got this bug cornered.  Can you test the patch at https://reviews.freebsd.org/D3192 to see if it fixes your testcase?

Comment 14 commit-hook 2015-08-16 19:44:24 UTC

A commit references this bug:

Author: sbruno
Date: Sun Aug 16 19:43:45 UTC 2015
New revision: 286831
URL: https://svnweb.freebsd.org/changeset/base/286831

Log:
  Increase EM_MAX_SCATTER to 64 such that the size of em_xmit()::segs[EM_MAX_SCATTER]
  doesn't get overrun by things like NFS that can and do shove more than 32 segs when
  being used with em(4) and TSO4.

  Update tso handling code in em_xmit() with update from jhb@ in email thread:
  https://lists.freebsd.org/pipermail/freebsd-net/2014-July/039306.html

  set ifp->if_hw_tsomax, ifp->if_hw_tsomaxsegcount & ifp->if_hw_tsomaxsegsize
  to appropriate values.

  Define a TSO workaround "magic" number  of 4 that is used to avoid an
  alignment issue in hardware.

  Change a couple of integer values that were used as booleans to actual
  bool types.

  Ensure that em_enable_intr() enables the appropriate mask of interrupts
  and not just a hardcoded define of values.

  PR:		200221 199174 195078
  Differential Revision:	https://reviews.freebsd.org/D3192
  Reviewed by:	erj jhb hiren
  MFC after:	2 weeks
  Sponsored by:	Limelight Networks

Changes:
  head/sys/dev/e1000/if_em.c
  head/sys/dev/e1000/if_em.h

Apologies for the delay in updating - I had to wait for a period where I could reboot the server into a new kernel.

I've patched CURRENT@286381 (and also CURRENT@285879) onto the changes from 10.1-RELEASE as described in Comment 12. After about a week in use, I've seen no watchdog timeout issues, so this patch seems to have solved the issue - thanks! I'll now try the patch onto the other server which uses the e1000 driver - although that one occurs rarely.

Comment 16 Sean Bruno 2015-09-02 16:33:58 UTC

You'll need this one as well to avoid a panic:

https://svnweb.freebsd.org/base?view=revision&revision=287330

Created attachment 160662 [details]
svn di svn://svn0.eu.freebsd.org/base/stable/10/sys/dev/e1000 sys/dev/e1000

Unfortunately, the server experienced a watchdog timeout this morning :

Sep  2 07:39:49 urybsod kernel: em0: Watchdog timeout Queue[0]-- resetting
Sep  2 07:39:49 urybsod kernel: Interface is RUNNING and ACTIVE
Sep  2 07:39:49 urybsod kernel: em0: TX Queue 0 ------
Sep  2 07:39:49 urybsod kernel: em0: hw tdh = 247, hw tdt = 495
Sep  2 07:39:49 urybsod kernel: em0: Tx Queue Status = -2147483648
Sep  2 07:39:49 urybsod kernel: em0: TX descriptors avail = 771
Sep  2 07:39:49 urybsod kernel: em0: Tx Descriptors avail failure = 237
Sep  2 07:39:49 urybsod kernel: em0: RX Queue 0 ------
Sep  2 07:39:49 urybsod kernel: em0: hw rdh = 344, hw rdt = 343
Sep  2 07:39:49 urybsod kernel: em0: RX discarded packets = 0
Sep  2 07:39:49 urybsod kernel: em0: RX Next to Check = 344
Sep  2 07:39:49 urybsod kernel: em0: RX Next to Refresh = 343
Sep  2 07:39:49 urybsod kernel: em0: Link is Down
Sep  2 07:39:49 urybsod kernel: em0: link state changed to DOWN
Sep  2 07:39:53 urybsod kernel: em0: Link is up 1000 Mbps Full Duplex
Sep  2 07:39:53 urybsod kernel: em0: link state changed to UP
Sep  2 07:39:53 urybsod devd: Executing '/etc/rc.d/dhclient quietstart em0'

So these patches appear to be improving stability, as this is the only occurrence in 13 days of uptime, compared to nearly every day previously.

I should reiterate what state this kernel is in :
sys/dev/e1000 is at 10-STABLE@HEAD with CURRENT@286381, CURRENT@285879 patched. This required some manual patching. Diff of e1000 to 10-STABLE attached.
Merged r274043 and r274704 from 10-STABLE.

I've not yet encountered a panic, but I'll apply 287330 to be on the safe side.

It would be great to have these MFC'd to 10-STABLE, thanks. :)

Hello,

I'm running 10.2-RELEASE on a HP Proliant Microserver with the following network interface:

em0@pci0:2:0:0: class=0x020000 card=0xa01f8086 chip=0x10d38086 rev=0x00 hdr=0x00
    vendor     = 'Intel Corporation'
    device     = '82574L Gigabit Network Connection'
    class      = network
    subclass   = ethernet

The machine run an NFS server and unless I mount the shared folder with a rsize/wsize of 32768 I'm experiencing watchdog timeouts after a few minutes under load (for ex streaming a movie):

Nov  7 23:25:26 mordor kernel: em0: Watchdog timeout Queue[0]-- resetting
Nov  7 23:25:26 mordor kernel: Interface is RUNNING and ACTIVE
Nov  7 23:25:26 mordor kernel: em0: TX Queue 0 ------
Nov  7 23:25:26 mordor kernel: em0: hw tdh = 508, hw tdt = 402
Nov  7 23:25:26 mordor kernel: em0: Tx Queue Status = -2147483648
Nov  7 23:25:26 mordor kernel: em0: TX descriptors avail = 93
Nov  7 23:25:26 mordor kernel: em0: Tx Descriptors avail failure = 0
Nov  7 23:25:26 mordor kernel: em0: RX Queue 0 ------
Nov  7 23:25:26 mordor kernel: em0: hw rdh = 206, hw rdt = 205
Nov  7 23:25:26 mordor kernel: em0: RX discarded packets = 0
Nov  7 23:25:26 mordor kernel: em0: RX Next to Check = 206
Nov  7 23:25:26 mordor kernel: em0: RX Next to Refresh = 205
Nov  7 23:25:26 mordor kernel: em0: link state changed to DOWN
Nov  7 23:25:30 mordor kernel: em0: link state changed to UP

... and I have to do an "hard" reboot

Note that this is with TSO enabled:

em0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=4219b<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM,TSO4,WOL_MAGIC,VLAN_HWTSO>
        ether 68:05:ca:xx:xx:xx
        inet 192.168.0.254 netmask 0xffffff00 broadcast 192.168.0.255 
        inet 192.168.0.21 netmask 0xffffffff broadcast 192.168.0.21 
        inet 192.168.0.20 netmask 0xffffffff broadcast 192.168.0.20 
        nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active

I'll try to disable TSO and see if it fixes the problem ..

Comment 22 Kubilay Kocak 2015-11-10 12:18:30 UTC

I believe this still needs MFC? (commit log specified two weeks)

Assign to committer who originally resolved in HEAD

I'm seeing the same issue on the very same hardware as Julien on current releng/10.2.

Currently using this /etc/rc.conf workaround:
ifconfig_em0="DHCP -tso -vlanhwtso"

Comment 24 commit-hook 2016-01-27 22:32:13 UTC

A commit references this bug:

Author: marius
Date: Wed Jan 27 22:31:10 UTC 2016
New revision: 294958
URL: https://svnweb.freebsd.org/changeset/base/294958

Log:
  Sync the e1000 drivers with what's in head as of r294327, modulo parts
  that don't apply to stable/10 (driver API, if_inc_counter(), RSS changes
  etc.) and modulo r287465 (which reportedly breaks igb(4)), i. e. assorted
  fixes and improvements only:

  o MFC r267385 (partial):
    - Don't compare bus_dma map pointers for static DMA allocations against
      NULL to determine if bus_dmamap_unload() or bus_dmamem_free() should be
      called. Instead, check the associated bus and virtual addresses.
    - Don't clear static DMA maps to NULL.
  o MFC r284933:
    Delete the refernce to VLAN handling being disabled by default. This is
    no longer the case. [1]
  o MFC r285639:
    Add an adapter CORE lock in the DDB hook em_dump_queue to avoid WITNESS
    panic in em_init_locked() while debugging.
  o MFC r285879:
    - Remove unused txd_saved.
    - Intialize txd_upper, txd_lower and txd_used at declaration.
  o MFC r286162:
    Free mbufs when busdma loading fails.
  o MFC r286829:
    Add capability to disable CRC stripping as it breaks IPMI/BMC capabilities
    on certain adatpers. [2]
  o MFC r286831: [3]
    - Increase EM_MAX_SCATTER to 64 such that the size of em_xmit()::
      segs[EM_MAX_SCATTER] doesn't get overrun by things like NFS that can
      and do shove more than 32 segs when being used with em(4) and TSO4.
    - Update tso handling code in em_xmit() with update from jhb@
    - Set if_hw_tsomax, if_hw_tsomaxsegcount and if_hw_tsomaxsegsize to
      appropriate values.
    - Define a TSO workaround "magic" number of 4 that is used to avoid an
      alignment issue in hardware.
    - Change a couple of integer values that were used as booleans to actual
      bool types.
    - Ensure that em_enable_intr() enables the appropriate mask of interrupts
      and not just a hardcoded define of values.
  o MFC r286832:
    e1000/if_lem.c bump to 1.1.0
  o MFC r286833:
    Bump all copywrite dates to 2015.
  o MFC r287112:
    Style/whitespace cleanup in shared/common code.
  o MFC r293331:
    - Switch em(4) to the extended RX descriptor format.
    - Split rxbuffer and txbuffer apart to support the new RX descriptor
      format structures. Move rxbuffer manipulation to em_setup_rxdesc() to
      unify the new behavior changes.
    - Add a RSSKEYLEN macro for help in generating the RSSKEY data structures
      in the card.
    - Change em_receive_checksum() to process the new rxdescriptor format
      status bit.
  o MFC r293332:
    Disable the reuse of checksum offload context descriptors in the case
    of multiple queues in em(4). Document errata in the code.
  o MFC r293854:
    Given that em(4), lem(4) and igb(4) hardware doesn't require the
    alignment guarantees provided by m_defrag(9), use m_collapse(9)
    instead for performance reasons.
    While at it, sanitize the statistics softc members, i. e. retire
    unused ones and add SYSCTL nodes missing for actually used ones.

  PR:	118693 [1], 161277 [2], 195078 [3], 199174 [3], 200221 [3]

Changes:
_U  stable/10/
  stable/10/share/man/man4/em.4
  stable/10/sys/dev/e1000/e1000_80003es2lan.c
  stable/10/sys/dev/e1000/e1000_80003es2lan.h
  stable/10/sys/dev/e1000/e1000_82540.c
  stable/10/sys/dev/e1000/e1000_82541.c
  stable/10/sys/dev/e1000/e1000_82541.h
  stable/10/sys/dev/e1000/e1000_82542.c
  stable/10/sys/dev/e1000/e1000_82543.c
  stable/10/sys/dev/e1000/e1000_82543.h
  stable/10/sys/dev/e1000/e1000_82571.c
  stable/10/sys/dev/e1000/e1000_82571.h
  stable/10/sys/dev/e1000/e1000_82575.c
  stable/10/sys/dev/e1000/e1000_82575.h
  stable/10/sys/dev/e1000/e1000_api.c
  stable/10/sys/dev/e1000/e1000_api.h
  stable/10/sys/dev/e1000/e1000_defines.h
  stable/10/sys/dev/e1000/e1000_hw.h
  stable/10/sys/dev/e1000/e1000_i210.c
  stable/10/sys/dev/e1000/e1000_i210.h
  stable/10/sys/dev/e1000/e1000_ich8lan.c
  stable/10/sys/dev/e1000/e1000_ich8lan.h
  stable/10/sys/dev/e1000/e1000_mac.c
  stable/10/sys/dev/e1000/e1000_mac.h
  stable/10/sys/dev/e1000/e1000_manage.c
  stable/10/sys/dev/e1000/e1000_manage.h
  stable/10/sys/dev/e1000/e1000_mbx.c
  stable/10/sys/dev/e1000/e1000_mbx.h
  stable/10/sys/dev/e1000/e1000_nvm.c
  stable/10/sys/dev/e1000/e1000_nvm.h
  stable/10/sys/dev/e1000/e1000_osdep.c
  stable/10/sys/dev/e1000/e1000_osdep.h
  stable/10/sys/dev/e1000/e1000_phy.c
  stable/10/sys/dev/e1000/e1000_phy.h
  stable/10/sys/dev/e1000/e1000_regs.h
  stable/10/sys/dev/e1000/e1000_vf.c
  stable/10/sys/dev/e1000/e1000_vf.h
  stable/10/sys/dev/e1000/if_em.c
  stable/10/sys/dev/e1000/if_em.h
  stable/10/sys/dev/e1000/if_igb.c
  stable/10/sys/dev/e1000/if_igb.h
  stable/10/sys/dev/e1000/if_lem.c
  stable/10/sys/dev/e1000/if_lem.h
  stable/10/sys/dev/ixgb/if_ixgb.c
  stable/10/sys/dev/netmap/if_em_netmap.h

Comment 25 Kubilay Kocak 2017-04-14 09:43:04 UTC

Merged to stable/10, record appropriately.