[Linuxptp-users] "poll tx timestamp timeout", igb on i210, vanilla kernel (was: "poll tx timestamp timeout", problem since v1.2, igb, stmmac)

[Jean-Baptiste M. <jea...@pa...>]

On 10/25/2013 06:12 PM, Vick, Matthew wrote:
...
> I210 should definitely be working in the upstream Linux kernel. Please let
> me know if it is not.

I think there is a problem.
ptp4l "poll tx timestamp timeout" 100%
igb driver on i210 "Detected Tx Unit Hang" 100%

Tested here with a freshly built 3.10.2 fetched from kernel.org.
# uname -a
Linux sumo 3.10.2-vanilla-686-pae #2 SMP Mon Oct 28 11:21:13 CET 2013 i686 GNU/Linux
# modinfo /lib/modules/3.10.2-vanilla-686-pae/kernel/drivers/net/ethernet/intel/igb/igb.ko
filename:       /lib/modules/3.10.2-vanilla-686-pae/kernel/drivers/net/ethernet/intel/igb/igb.ko
version:        5.0.3-k
license:        GPL
description:    Intel(R) Gigabit Ethernet Network Driver
author:         Intel Corporation, <e10...@li...>
srcversion:     8251E5B658798814C71FD34
...
For ptp4l:
# git log -n 1 --pretty=oneline
52c5e0cfc972c3e2b65ca492eecbff6edb8b2aaf Don't calculate delay with old master's sync time stamp.

Setup:

# rmmod igb
# dmesg -c
# dmesg -n 7
# modprobe igb
(for the braves out here, contact me for the "debug=16" dmesg output bellow)
# ifconfig eth2-igb 192.168.100.2 up

Then:

# ./ptp4l -i eth2-igb -m -l 7
ptp4l[12963.591]: selected /dev/ptp0 as PTP clock
ptp4l[12963.592]: PI servo: sync interval 1.000 kp 0.700 ki 0.300000
ptp4l[12963.592]: driver changed our HWTSTAMP options
ptp4l[12963.593]: tx_type   1 not 1
ptp4l[12963.593]: rx_filter 1 not 12
ptp4l[12963.593]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[12963.593]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[12969.593]: port 1: announce timeout
ptp4l[12969.593]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[12969.593]: selected best master clock a0369f.fffe.1c38a8
ptp4l[12969.593]: assuming the grand master role
ptp4l[12969.594]: port 1: master tx announce timeout
ptp4l[12969.594]: port 1: setting asCapable
ptp4l[12970.593]: port 1: master sync timeout
ptp4l[12970.594]: poll tx timestamp timeout
ptp4l[12970.594]: port 1: send sync failed
ptp4l[12970.594]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[12970.594]: waiting 2^{4} seconds to clear fault on port 1
^Cptp4l[12972.061]: caught signal 2

# dmesg
[12955.198501] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.0.3-k
[12955.198511] igb: Copyright (c) 2007-2013 Intel Corporation.
[12955.199411] igb 0000:03:00.0: irq 43 for MSI/MSI-X
[12955.199432] igb 0000:03:00.0: irq 44 for MSI/MSI-X
[12955.199450] igb 0000:03:00.0: irq 45 for MSI/MSI-X
[12955.199467] igb 0000:03:00.0: irq 46 for MSI/MSI-X
[12955.199487] igb 0000:03:00.0: irq 47 for MSI/MSI-X
[12955.284305] igb 0000:03:00.0: added PHC on eth0
[12955.284317] igb 0000:03:00.0: Intel(R) Gigabit Ethernet Network Connection
[12955.284326] igb 0000:03:00.0: eth0: (PCIe:2.5Gb/s:Width x1) a0:36:9f:1c:38:a8
[12955.284532] igb 0000:03:00.0: eth0: PBA No: G69016-001
[12955.284539] igb 0000:03:00.0: Using MSI-X interrupts. 4 rx queue(s), 4 tx queue(s)
[12955.311533] systemd-udevd[11676]: renamed network interface eth0 to eth2-igb
[12962.123669] IPv6: ADDRCONF(NETDEV_UP): eth2-igb: link is not ready
[12964.333099] igb: eth2-igb NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[12964.333533] IPv6: ADDRCONF(NETDEV_CHANGE): eth2-igb: link becomes ready
[12966.207446] igb 0000:03:00.0: Detected Tx Unit Hang
[12966.207446]   Tx Queue             <2>
[12966.207446]   TDH                  <0>
[12966.207446]   TDT                  <1>
[12966.207446]   next_to_use          <1>
[12966.207446]   next_to_clean        <0>
[12966.207446] buffer_info[next_to_clean]
[12966.207446]   time_stamp           <30429e>
[12966.207446]   next_to_watch        <eedcc000>
[12966.207446]   jiffies              <304470>
[12966.207446]   desc.status          <168000>
[12968.208531] igb 0000:03:00.0: Detected Tx Unit Hang
[12968.208531]   Tx Queue             <2>
[12968.208531]   TDH                  <0>
[12968.208531]   TDT                  <1>
[12968.208531]   next_to_use          <1>
[12968.208531]   next_to_clean        <0>
[12968.208531] buffer_info[next_to_clean]
[12968.208531]   time_stamp           <30429e>
[12968.208531]   next_to_watch        <eedcc000>
[12968.208531]   jiffies              <304664>
[12968.208531]   desc.status          <168000>
[12970.210527] igb 0000:03:00.0: Detected Tx Unit Hang
[12970.210527]   Tx Queue             <2>
[12970.210527]   TDH                  <0>
[12970.210527]   TDT                  <1>
[12970.210527]   next_to_use          <1>
[12970.210527]   next_to_clean        <0>
[12970.210527] buffer_info[next_to_clean]
[12970.210527]   time_stamp           <30429e>
[12970.210527]   next_to_watch        <eedcc000>
[12970.210527]   jiffies              <304858>
[12970.210527]   desc.status          <168000>
[12972.212578] igb 0000:03:00.0: Detected Tx Unit Hang
[12972.212578]   Tx Queue             <1>
[12972.212578]   TDH                  <0>
[12972.212578]   TDT                  <1>
[12972.212578]   next_to_use          <1>
[12972.212578]   next_to_clean        <0>
[12972.212578] buffer_info[next_to_clean]
[12972.212578]   time_stamp           <304790>
[12972.212578]   next_to_watch        <eec1d000>
[12972.212578]   jiffies              <304a4c>
[12972.212578]   desc.status          <d8000>
[12972.212594] igb 0000:03:00.0: Detected Tx Unit Hang
[12972.212594]   Tx Queue             <2>
[12972.212594]   TDH                  <0>
[12972.212594]   TDT                  <1>
[12972.212594]   next_to_use          <1>
[12972.212594]   next_to_clean        <0>
[12972.212594] buffer_info[next_to_clean]
[12972.212594]   time_stamp           <30429e>
[12972.212594]   next_to_watch        <eedcc000>
[12972.212594]   jiffies              <304a4c>
[12972.212594]   desc.status          <168000>
[12974.214274] igb 0000:03:00.0 eth2-igb: Reset adapter
[12978.014992] igb: eth2-igb NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[12982.234731] igb 0000:03:00.0: Detected Tx Unit Hang
[12982.234731]   Tx Queue             <2>
[12982.234731]   TDH                  <0>
[12982.234731]   TDT                  <1>
[12982.234731]   next_to_use          <1>
[12982.234731]   next_to_clean        <0>
[12982.234731] buffer_info[next_to_clean]
[12982.234731]   time_stamp           <3052a1>
[12982.234731]   next_to_watch        <eedcc000>
[12982.234731]   jiffies              <305413>
[12982.234731]   desc.status          <1ac000>
[12984.236804] igb 0000:03:00.0: Detected Tx Unit Hang
[12984.236804]   Tx Queue             <2>
[12984.236804]   TDH                  <0>
[12984.236804]   TDT                  <1>
[12984.236804]   next_to_use          <1>
[12984.236804]   next_to_clean        <0>
[12984.236804] buffer_info[next_to_clean]
[12984.236804]   time_stamp           <3052a1>
[12984.236804]   next_to_watch        <eedcc000>
[12984.236804]   jiffies              <305607>
[12984.236804]   desc.status          <1ac000>
[12986.238813] igb 0000:03:00.0: Detected Tx Unit Hang
[12986.238813]   Tx Queue             <3>
[12986.238813]   TDH                  <0>
[12986.238813]   TDT                  <2>
[12986.238813]   next_to_use          <2>
[12986.238813]   next_to_clean        <0>
[12986.238813] buffer_info[next_to_clean]
[12986.238813]   time_stamp           <3055a0>
[12986.238813]   next_to_watch        <ef523010>
[12986.238813]   jiffies              <3057fb>
[12986.238813]   desc.status          <158200>
[12986.238828] igb 0000:03:00.0: Detected Tx Unit Hang
[12986.238828]   Tx Queue             <2>
[12986.238828]   TDH                  <0>
[12986.238828]   TDT                  <1>
[12986.238828]   next_to_use          <1>
[12986.238828]   next_to_clean        <0>
[12986.238828] buffer_info[next_to_clean]
[12986.238828]   time_stamp           <3052a1>
[12986.238828]   next_to_watch        <eedcc000>
[12986.238828]   jiffies              <3057fb>
[12986.238828]   desc.status          <1ac000>
[12986.238843] igb 0000:03:00.0: Detected Tx Unit Hang
[12986.238843]   Tx Queue             <1>
[12986.238843]   TDH                  <0>
[12986.238843]   TDT                  <1>
[12986.238843]   next_to_use          <1>
[12986.238843]   next_to_clean        <0>
[12986.238843] buffer_info[next_to_clean]
[12986.238843]   time_stamp           <3055a2>
[12986.238843]   next_to_watch        <eec1d000>
[12986.238843]   jiffies              <3057fb>
[12986.238843]   desc.status          <f8000>
[12988.240845] igb 0000:03:00.0: Detected Tx Unit Hang
[12988.240845]   Tx Queue             <2>
[12988.240845]   TDH                  <0>
[12988.240845]   TDT                  <1>
[12988.240845]   next_to_use          <1>
[12988.240845]   next_to_clean        <0>
[12988.240845] buffer_info[next_to_clean]
[12988.240845]   time_stamp           <3052a1>
[12988.240845]   next_to_watch        <eedcc000>
[12988.240845]   jiffies              <3059ef>
[12988.240845]   desc.status          <1ac000>
[12988.240860] igb 0000:03:00.0: Detected Tx Unit Hang
[12988.240860]   Tx Queue             <3>
[12988.240860]   TDH                  <0>
[12988.240860]   TDT                  <2>
[12988.240860]   next_to_use          <2>
[12988.240860]   next_to_clean        <0>
[12988.240860] buffer_info[next_to_clean]
[12988.240860]   time_stamp           <3055a0>
[12988.240860]   next_to_watch        <ef523010>
[12988.240860]   jiffies              <3059ef>
[12988.240860]   desc.status          <158200>
[12988.240875] igb 0000:03:00.0: Detected Tx Unit Hang
[12988.240875]   Tx Queue             <1>
[12988.240875]   TDH                  <0>
[12988.240875]   TDT                  <1>
[12988.240875]   next_to_use          <1>
[12988.240875]   next_to_clean        <0>
[12988.240875] buffer_info[next_to_clean]
[12988.240875]   time_stamp           <3055a2>
[12988.240875]   next_to_watch        <eec1d000>
[12988.240875]   jiffies              <3059ef>
[12988.240875]   desc.status          <f8000>
[12988.244531] igb 0000:03:00.0 eth2-igb: Reset adapter

> I'm uncertain what the Debian kernel version of igb looks like. It's
> possible some critical patch is missing. You can try the latest version
> (5.0.6) from e1000.sf.net and compiling with CFLAGS_EXTRA=-DIGB_PTP to see
> if that driver works for you.

Will do.
-- 
JB