DMA stops working; needs a reboot

[lukego]

Problem: DMA stops working for the Intel NIC. Cause unknown. Reboot is only known cure.

The basic symptom is a lack of any values in the NIC counters:

selftest: intel device 0000:00:04.0
NIC transmit test
intel selftest: pciaddr=0000:00:04.0 secs=1
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:
NIC transmit+receive loopback test
intel selftest: pciaddr=0000:00:04.0 secs=1 receive=true loopback=true
Waiting for linkup............... ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:

For full back story see discussion on commit e5d463e.

[rahul-mr]

I hope the NIC firmware is up-to-date.

Have you tried testing it with ethtool (after the e1000e driver is loaded)?

[lukego]

Here is what I see on bern.snabb.co:

• This problem is happening on the host.
• This problem is not happening within a KVM using pcipassthrough.

I have tried stopping the KVM, restarting the KVM, and running on the host both with and without the KVM running. In these tests it has always worked in the KVM and never on the host.

Could be that the DMA-enable code in pci.lua works for QEMU's PCI bridge but not physical ones?

[lukego]

The issue seems to be that the PCI card is not able to do DMA with the HugeTLB memory that snabbswitch has allocated. I see these messages repeatedly in dmesg:

[709668.764714] DRHD: handling fault status reg 3
[709668.764741] DMAR:[DMA Read] Request device [05:00.0] fault addr d8800000 
[709668.764743] DMAR:[fault reason 06] PTE Read access is not set

Looks like this memory needs to be enabled for DMA (in the IOMMU?) somehow. I'm looking for a straightforward way to do this from userspace.

[lukego]

Booting with intel_iommu=off does not help.

[rahul-mr]

On 01/15/2013 10:28 PM, Luke Gorrie wrote:

Booting with intel_iommu=off does not help.

dunno if this helps, but can u try booting kernel with
iommu=force,memaper=3 (taken from here:
http://whiteboard.ping.se/Linux/IOMMU)

check this also:
http://www.mjmwired.net/kernel/Documentation/x86/x86_64/boot-options.txt#230

[lukego]

Dinner time here! Will investigate more tomorrow. Hope we can find a
solution that doesn't need reboot and hacking grub (but that would be good
enough to start with).

On 15 January 2013 18:01, rahul-mr notifications@github.com wrote:

On 01/15/2013 10:28 PM, Luke Gorrie wrote:

Booting with intel_iommu=off does not help.

dunno if this helps, but can u try booting kernel with
iommu=force,memaper=3 (taken from here:
http://whiteboard.ping.se/Linux/IOMMU)

check this also:

http://www.mjmwired.net/kernel/Documentation/x86/x86_64/boot-options.txt#230

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/39#issuecomment-12277488.

[lukego]

The problem seems to be that the HugeTLB allocated memory doesn't reliably work for DMA. The situation is better when using the old mmap() of /dev/mem memory allocation scheme.

I will create a workaround based on ye olde memmap=16M\$0x10000000 Grub parameter and then look for a way to make the HugeTLB memory work. I cross my fingers that we can find a reliable solution that needs neither a boot parameter nor a helper kernel module.

[lukego]

The workaround is done now: the commit above (+ the one after). This works on bern.snabb.co.

Going to look more into why HugeTLB pages are not working next. One more theory to explore is that memory.map() is not finding the right physical address for them and so we would pass the wrong addresses to the NIC.

[lukego]

I am continuing to look into this. There are plenty of exciting /proc files to check and cross-check on the hunt for where memory really is.

[pkazmier]

I made a comment on one of the commits about how the rx and tx descriptor base addresses are set. Might this be something in your chase for the odd hugetbl behavior?

f5a3431#commitcomment-2465756

[rahul-mr]

Hmm, it seems the latest commit f23d5cb doesn't fix this issue. It is interesting to note that during testing with the current master, the 'high' 32 bits of the rx/tx descriptor base addresses always remained 0x00000000

[lukego]

Interesting. This fix is working for me on bern.snabb.co. I see 0x00000003
in the TDBAH/RDBAH registers suggesting that the huge pages have been
allocated from the high part of the 16GB of ram.

Can you help me reproduce a failure with that commit applied?

On 20 January 2013 13:19, rahul-mr notifications@github.com wrote:

Hmm, it seems the latest commit f23d5cbhttps://github.com/SnabbCo/snabbswitch/commit/f23d5cb464ec46cb7de5c423b89c4ec491ec633edoesn't fix this issue. It is interesting to note that during testing with
the current master, the 'high' 32 bits of the rx/tx descriptor base
addresses always remained 0x00000000

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/39#issuecomment-12469851.

[pkazmier]

It's stopped working on arbon at the moment:

pkazmier@snabbdev:~/snabbswitch/src$ sudo flock -x /tmp/snabb.lock ./snabbswitch
[sudo] password for pkazmier: 
selftest: memory
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
  Allocating a 2MB HugeTLB: Got 2MB at 0x32200000
  Allocating a 2MB HugeTLB: Got 2MB at 0x31c00000
  Allocating a 2MB HugeTLB: Got 2MB at 0x24c00000
  Allocating a 2MB HugeTLB: Got 2MB at 0x20a00000
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
HugeTLB page allocation OK.
selftest: pci
Scanning PCI devices:
pciaddr         vendor  device  iface   status
0000:00:00.0    0x8086  0x1237  -       -
0000:00:01.0    0x8086  0x7000  -       -
0000:00:01.1    0x8086  0x7010  -       -
0000:00:01.3    0x8086  0x7113  -       -
0000:00:02.0    0x1013  0x00b8  -       -
0000:00:03.0    0x10ec  0x8139  eth0    up
0000:00:04.0    0x8086  0x10d3  -       -
0000:00:05.0    0x1af4  0x1001  -       -
Suitable devices: 
  0000:00:04.0
selftest: intel device 0000:00:04.0
NIC transmit test
intel selftest: pciaddr=0000:00:04.0 secs=1
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:
NIC transmit+receive loopback test
intel selftest: pciaddr=0000:00:04.0 secs=1 receive=true loopback=true
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:

[pkazmier]

FWIW: Ever since I got my Intel controller working, I've yet to stumble across a case where it stops working (i.e., no packet statistics are displayed). I've got the day off from work for today, so I hope to do some more investigation. In the meantime, I fired up this loop on my box to see if it's stops working:

root@world:/home/kaz# while /bin/true
> do
> echo -n "TIMESTAMP: "
> date
> ./snabbswitch 
> done >> /tmp/debug.txt

In another window, I'm just tailing the log file tail -f /tmp/debug.txt | egrep 'TIMESTAMP|TPT'. I'll keep an eye on this to see if it ever stops working like it has on arbon. Like bern, my host is not running in a VM, but rather the host directly.

(and yes, I've disabled my call to memory.install so that I'm using HugeTLB pages instead)

[pkazmier]

Re: my last comment, the loop has been running for quite some time now (1,621 runs to be exact), and it still runs successful. I cannot seem to reproduce the issue where the stats stop printing out when I run snabb in my environment. I'll let in run overnight though.

[rahul-mr]

Sample run in arbon:

selftest: memory
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
  Allocating a 2MB HugeTLB: Got 2MB at 0x3aa00000
  Allocating a 2MB HugeTLB: Got 2MB at 0x32000000
  Allocating a 2MB HugeTLB: Got 2MB at 0x20800000
  Allocating a 2MB HugeTLB: Got 2MB at 0x20200000
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
HugeTLB page allocation OK.
selftest: pci
Scanning PCI devices:
pciaddr         vendor  device  iface   status
0000:00:00.0    0x8086  0x1237  -       -
0000:00:01.0    0x8086  0x7000  -       -
0000:00:01.1    0x8086  0x7010  -       -
0000:00:01.3    0x8086  0x7113  -       -
0000:00:02.0    0x1013  0x00b8  -       -
0000:00:03.0    0x10ec  0x8139  eth0    up
0000:00:04.0    0x8086  0x10d3  -       -
0000:00:05.0    0x1af4  0x1001  -       -
Suitable devices: 
  0000:00:04.0
selftest: intel device 0000:00:04.0
NIC transmit test
intel selftest: pciaddr=0000:00:04.0 secs=1
Waiting for linkup............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:
NIC transmit+receive loopback test
intel selftest: pciaddr=0000:00:04.0 secs=1 receive=true loopback=true
Waiting for linkup............ ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:00:04.0:

While it is working in Bern:

selftest: memory
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 8
  Allocating a 2MB HugeTLB: Got 2MB at 0xfb200000
  Allocating a 2MB HugeTLB: Got 2MB at 0xfb400000
  Allocating a 2MB HugeTLB: Got 2MB at 0xfba00000
  Allocating a 2MB HugeTLB: Got 2MB at 0xdb400000
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 8
HugeTLB page allocation OK.
selftest: pci
Scanning PCI devices:
pciaddr         vendor  device  iface   status
0000:00:00.0    0x8086  0x0158  -       -
0000:00:01.0    0x8086  0x0151  -       -
0000:00:02.0    0x8086  0x016a  -       -
0000:00:06.0    0x8086  0x015d  -       -
0000:00:16.0    0x8086  0x1c3a  -       -
0000:00:1a.0    0x8086  0x1c2d  -       -
0000:00:1c.0    0x8086  0x1c10  -       -
0000:00:1c.5    0x8086  0x1c1a  -       -
0000:00:1c.6    0x8086  0x1c1c  -       -
0000:00:1c.7    0x8086  0x1c1e  -       -
0000:00:1d.0    0x8086  0x1c26  -       -
0000:00:1e.0    0x8086  0x244e  -       -
0000:00:1f.0    0x8086  0x1c56  -       -
0000:00:1f.2    0x8086  0x1c02  -       -
0000:00:1f.3    0x8086  0x1c22  -       -
0000:04:00.0    0x8086  0x10d3  eth0    up
0000:05:00.0    0x8086  0x10d3  -       -
0000:06:00.0    0x1b21  0x1042  -       -
Suitable devices: 
  0000:05:00.0
selftest: intel device 0000:05:00.0
NIC transmit test
intel selftest: pciaddr=0000:05:00.0 secs=1
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:05:00.0:
           1,207,447 GPTC       Good Packets Transmitted Count
          77,277,376 GOTCL      Good Octets Transmitted Count
          77,280,320 TOTL       Total Octets Transmitted (Low)
           1,207,517 TPT        Total Packets Transmitted
           1,207,520 PTC64      Packets Transmitted [64 Bytes] Count
NIC transmit+receive loopback test
intel selftest: pciaddr=0000:05:00.0 secs=1 receive=true loopback=true
Waiting for linkup............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:05:00.0:
             179,933 MPC        Missed Packets Count
             868,259 PRC64      Packets Received [64 Bytes] Count
             868,276 GPRC       Good Packets Received Count
           1,048,224 GPTC       Good Packets Transmitted Count
          55,570,176 GORCL      Good Octets Received Count
          67,087,040 GOTCL      Good Octets Transmitted Count
                  39 RNBC       Receive No Buffers Count
          67,088,960 TORL       Total Octets Received (Low)
          67,089,408 TOTL       Total Octets Transmitted (Low)
           1,048,275 TPR        Total Packets Received
           1,048,280 TPT        Total Packets Transmitted
           1,048,282 PTC64      Packets Transmitted [64 Bytes] Count

Note that I've been running the tests only in arbon till now. So, maybe this issue happens only when running under KVM ?

[rahul-mr]

Update: the issue is now showing up in bern:

selftest: memory
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
  Allocating a 2MB HugeTLB: Got 2MB at 0xfb600000
  Allocating a 2MB HugeTLB: Got 2MB at 0xfb800000
  Allocating a 2MB HugeTLB: Got 2MB at 0xdb400000
  Allocating a 2MB HugeTLB: Got 2MB at 0xfba00000
Kernel HugeTLB pages (/proc/sys/vm/nr_hugepages): 10
HugeTLB page allocation OK.
selftest: pci
Scanning PCI devices:
pciaddr         vendor  device  iface   status
0000:00:00.0    0x8086  0x0158  -       -
0000:00:01.0    0x8086  0x0151  -       -
0000:00:02.0    0x8086  0x016a  -       -
0000:00:06.0    0x8086  0x015d  -       -
0000:00:16.0    0x8086  0x1c3a  -       -
0000:00:1a.0    0x8086  0x1c2d  -       -
0000:00:1c.0    0x8086  0x1c10  -       -
0000:00:1c.5    0x8086  0x1c1a  -       -
0000:00:1c.6    0x8086  0x1c1c  -       -
0000:00:1c.7    0x8086  0x1c1e  -       -
0000:00:1d.0    0x8086  0x1c26  -       -
0000:00:1e.0    0x8086  0x244e  -       -
0000:00:1f.0    0x8086  0x1c56  -       -
0000:00:1f.2    0x8086  0x1c02  -       -
0000:00:1f.3    0x8086  0x1c22  -       -
0000:04:00.0    0x8086  0x10d3  eth0    up
0000:05:00.0    0x8086  0x10d3  -       -
0000:06:00.0    0x1b21  0x1042  -       -
Suitable devices: 
  0000:05:00.0
selftest: intel device 0000:05:00.0
NIC transmit test
intel selftest: pciaddr=0000:05:00.0 secs=1
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:05:00.0:
NIC transmit+receive loopback test
intel selftest: pciaddr=0000:05:00.0 secs=1 receive=true loopback=true
Waiting for linkup.............. ok
Generating traffic for 1 second(s)...
Statistics for PCI device 0000:05:00.0:

[rahul-mr]

Update (on bern):

1. I have tried using memory.install() to use the memmap-ed address space for the {rx,tx}desc/buffers but still couldn't get the NIC to print statistics.
2. Tried to bind the pci device (0000:05:00.0) to the e1000e device driver:

# echo -n "0000:05:00.0" > /sys/bus/pci/drivers/e1000e/bind
# dmesg | tail -n 10
[503057.724204] e1000e 0000:05:00.0: Disabling ASPM L0s L1
[503057.724224] e1000e 0000:05:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[503057.724249] e1000e 0000:05:00.0: setting latency timer to 64
[503057.724533] e1000e 0000:05:00.0: irq 56 for MSI/MSI-X
[503057.724540] e1000e 0000:05:00.0: irq 57 for MSI/MSI-X
[503057.724546] e1000e 0000:05:00.0: irq 58 for MSI/MSI-X
[503057.999025] e1000e 0000:05:00.0: eth1: (PCI Express:2.5GT/s:Width x1) 30:85:a9:a3:c5:38
[503057.999030] e1000e 0000:05:00.0: eth1: Intel(R) PRO/1000 Network Connection
[503057.999109] e1000e 0000:05:00.0: eth1: MAC: 3, PHY: 8, PBA No: FFFFFF-0FF

3. Ran the ethtool on eth1:

root@bern:~# ethtool -t eth1
The test result is FAIL
The test extra info:
Register test  (offline)         0
Eeprom test    (offline)         0
Interrupt test (offline)         0
Loopback test  (offline)         13
Link test   (on/offline)         0

root@bern:~# ethtool -t eth1 online
The test result is PASS
The test extra info:
Register test  (offline)         0
Eeprom test    (offline)         0
Interrupt test (offline)         0
Loopback test  (offline)         0
Link test   (on/offline)         0

4. Unbind the device:

# echo -n "0000:05:00.0" > /sys/bus/pci/drivers/e1000e/unbind

5. Ran selftest again and still couldn't get the NIC to print any statistic.

[lukego]

I wonder if there are some new tools we could add to our toolbox for this
situation?

I saw an old LWN article about tracing MMIO operations at the PCI level:
http://lwn.net/Articles/270939/

Could it be that new Linux tracing infrastructure can give us more
visibility into what's going on?

I once had a similar problem while writing a driver for a USB device and
discovered to my delight that tcpdump could record USB traffic (
http://lukego.livejournal.com/22799.html)

On 22 January 2013 10:51, rahul-mr notifications@github.com wrote:

Update (on bern):

1. I have tried using memory.install() to use the memmap-ed address space
   for the {rx,tx}desc/buffers but still couldn't get the NIC to print
   statistics.
2. Tried to bind the pci device (0000:05:00.0) to the e1000e device driver:

echo -n "0000:05:00.0" > /sys/bus/pci/drivers/e1000e/bind

dmesg | tail -n 10

[503057.724204] e1000e 0000:05:00.0: Disabling ASPM L0s L1
[503057.724224] e1000e 0000:05:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[503057.724249] e1000e 0000:05:00.0: setting latency timer to 64
[503057.724533] e1000e 0000:05:00.0: irq 56 for MSI/MSI-X
[503057.724540] e1000e 0000:05:00.0: irq 57 for MSI/MSI-X
[503057.724546] e1000e 0000:05:00.0: irq 58 for MSI/MSI-X
[503057.999025] e1000e 0000:05:00.0: eth1: (PCI Express:2.5GT/s:Width x1) 30:85:a9:a3:c5:38
[503057.999030] e1000e 0000:05:00.0: eth1: Intel(R) PRO/1000 Network Connection
[503057.999109] e1000e 0000:05:00.0: eth1: MAC: 3, PHY: 8, PBA No: FFFFFF-0FF

3. Ran the ethtool on eth1:

root@bern:~# ethtool -t eth1
The test result is FAIL
The test extra info:
Register test (offline) 0
Eeprom test (offline) 0
Interrupt test (offline) 0
Loopback test (offline) 13
Link test (on/offline) 0

root@bern:~# ethtool -t eth1 online
The test result is PASS
The test extra info:
Register test (offline) 0
Eeprom test (offline) 0
Interrupt test (offline) 0
Loopback test (offline) 0
Link test (on/offline) 0

4. Unbind the device:

echo -n "0000:05:00.0" > /sys/bus/pci/drivers/e1000e/unbind

5. Ran selftest again and still couldn't get the NIC to print any
   statistic.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/39#issuecomment-12537140.

[pkazmier]

Weird, I still don't see it on my machine. I ran the selftest 2,997 times over night and it's still working. Rahul, are you executing a different part of the code than I am? I'm only running the selftest as defined in selftest.lua. I'll leave my loop going all day long while I'm off at work to see if I can get it to happen.

[rahul-mr]

@pkazmier:

Weird, I still don't see it on my machine. I ran the selftest 2,997 times over night and it's still working. Rahul, are you executing a different part of the code than I am? I'm only running the selftest as defined in selftest.lua. I'll leave my loop going all day long while I'm off at work to see if I can get it to happen.

I'm working on issue #33 ATM (branch I'm working on: https://github.com/rahul-mr/snabbswitch/commits/mem_high_issue33 ). The selftest.lua I'm using includes selftest_tso() which ends up calling add_txbuf_tso(). I'm reviewing the code I've written to see if I ended up doing something stupid. Will you be able to test it in your hardware (disclaimer: alpha quality code ;-) ) to see if that triggers this issue? But IIRC the issue got triggered y'day in arbon while running the master branch.

My concern is that whatever triggered the DMA access problem, we should still be able to get the NIC to work without a reboot.

@lukego:

I wonder if there are some new tools we could add to our toolbox for this situation?

Though it isn't much, I've added the definitions of the rx/tx diagnostics registers to help with the debugging.

[lukego]

I have also written some code (uncommitted) to decode the kpageflags file
to see information about physical pages (e.g. does the kernel agree that
they are part of Huge pages, etc). I put this code down for the moment when
it seemed like everything was working :-)

One idea with Arbon: Can we have broken the VM by running something (e.g.
snabbswitch or e1000e bind) on the host? I don't think I have done that
since the last reboot but I can imagine it may mess up the IOMMU trickery
that makes PCIe bypass work.

More tomorrow!

On 22 January 2013 19:29, rahul-mr notifications@github.com wrote:

@pkazmier https://github.com/pkazmier:

Weird, I still don't see it on my machine. I ran the selftest 2,997 times
over night and it's still working. Rahul, are you executing a different
part of the code than I am? I'm only running the selftest as defined in
selftest.lua. I'll leave my loop going all day long while I'm off at work
to see if I can get it to happen.

I'm working on issue #33https://github.com/SnabbCo/snabbswitch/issues/33ATM (branch I'm working on:
https://github.com/rahul-mr/snabbswitch/commits/mem_high_issue33 ). The
selftest.lua I'm using includes selftest_tso() which ends up calling
add_txbuf_tso(). I'm reviewing the code I've written to see if I ended up
doing something stupid. Will you be able to test it in your hardware
(disclaimer: alpha quality code ;-) ) to see if that triggers this issue?
But IIRC the issue got triggered y'day in arbon while running the master
branch.

My concern is that whatever triggered the DMA access problem, we should
still be able to get the NIC to work without a reboot.

@lukego https://github.com/lukego:

I wonder if there are some new tools we could add to our toolbox for this
situation?

Though it isn't much, I've added the definitions of the rx/tx diagnostics
registers to help with the debugging.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/39#issuecomment-12558650.

[rahul-mr]

Update:
FWIW segfaults shown in kernel log messages:
Arbon:

$ dmesg | grep -i snabb
[231898.115174] snabbswitch[18548]: segfault at 20200004 ip 000000000043f279 sp 00007fffff752e90 error 4 in snabbswitch[400000+77000]
[276311.218457] snabbswitch[9178]: segfault at 20a65a89 ip 000000000043f279 sp 00007fff568091c0 error 4 in snabbswitch[400000+76000]
[276375.002616] snabbswitch[9245]: segfault at 20865a89 ip 000000000043f279 sp 00007fff367a2a20 error 4 in snabbswitch[400000+76000]

$ addr2line -e src/snabbswitch 000000000043f279
lj_crecord.c:0

Bern:

$ dmesg | grep -i snabb
[ 1220.493591] snabbswitch[2266]: segfault at 0 ip 000000000043f2f1 sp 00007fff359b8100 error 6 in snabbswitch[400000+76000]
[ 1252.896728] snabbswitch[2280]: segfault at 0 ip 000000000043f2f1 sp 00007fffee7b97c0 error 6 in snabbswitch[400000+76000]
[ 1765.469630] snabbswitch[2300]: segfault at 0 ip 000000000043f2f1 sp 00007ffffdc87a40 error 6 in snabbswitch[400000+76000]
[ 1783.146961] snabbswitch[2312]: segfault at 0 ip 000000000043f2f1 sp 00007fff16c8eaa0 error 6 in snabbswitch[400000+76000]
[ 1803.573392] snabbswitch[2324]: segfault at 0 ip 000000000043f2f1 sp 00007fff9c046890 error 6 in snabbswitch[400000+76000]

$ addr2line -e ~/prog/snabbswitch/src/snabbswitch 000000000043f2f1
lj_crecord.c:0

Now I'm using gdb to run snabbswitch (using a debug build of luajit and snabbswitch) - no segfaults yet.

[rahul-mr]

On 01/23/2013 01:10 AM, Luke Gorrie wrote:

I have also written some code (uncommitted) to decode the kpageflags file
to see information about physical pages (e.g. does the kernel agree that
they are part of Huge pages, etc). I put this code down for the moment when
it seemed like everything was working:-)
Interesting!
One idea with Arbon: Can we have broken the VM by running something (e.g.
snabbswitch or e1000e bind) on the host? I don't_think_ I have done that
since the last reboot but I can imagine it may mess up the IOMMU trickery
that makes PCIe bypass work.
Hmm, I've used the e1000e bind only on Bern. But I agree that I/we might
have inadvertently broken the PCI passthrough functionality ;-)

[pkazmier]

Just got home from work, it's still running fine on my machine (5,729 runs now) and no segfaults in my dmesg. Nice find Rahul.

[rahul-mr]

Just got home from work, it's still running fine on my machine (5,729 runs now) and no segfaults in my dmesg. Nice find Rahul.

Thanks, Pete :-)

BTW did you find any significant change in the MPC (Missed Packets Count) and RNBC (Receive No Buffers Count) in the NIC transmit+receive loopback test with the current master?

[pkazmier]

The MPC and RNBC counts are roughly 700,000 and 22,000 respectively. I don't run the current master as it doesn't support my NIC, but other than a few changes for PHY access, it's more or less the same. Because I recently got this working, I have no other baseline to make comparisons as to whether or not there were significant differences in results.

Need to head out for a bit. Good luck!

[rahul-mr]

Update: I would like to start with an apology - it seems the issue is triggered only when I run add_txbuf_tso. So the earlier report that the issue was triggered with the @snabbco master branch seems to be incorrect (It seems I may have mixed up branches while testing. To avoid the possibility of mixing up branches and getting incorrect findings, from now onwards I'll make a fresh git clone of @snabbco snabbswitch master and test with that). sorry for the incorrect findings :-(

Now on to the good news: The issue is not in accessing DMA memory, but the reset function doesn't set the GIO Master Disable bit (of CTRL register) and wait for GIO Master Enable Status bit to be cleared (in STATUS register).

This is the updated reset():

  function reset ()
      regs[IMC] = 0xffffffff                 -- Disable interrupts
      regs[CTRL] = bit.bor(regs[CTRL], bits({GMD=2})) -- GIO Master Disable
      --local deadline = C.get_time_ns() + 
      C.usleep(10)
      assert( not bitset(regs[STATUS], 19) ) -- GIO Master Enable Status 
      regs[CTRL] = bits({FD=0,SLU=6,RST=26,PHY_RST=31}) -- Global reset
      C.usleep(10); assert( not bitset(regs[CTRL],26) )
      regs[IMC] = 0xffffffff                 -- Disable interrupts
   end

Now the add_txbuf_tso works as expected (multiple runs without any errors) :-)

waiting for packet transmission...
Statistics for PCI device 0000:05:00.0:
                   1 GPTC       Good Packets Transmitted Count
                  64 GOTCL      Good Octets Transmitted Count
                  64 TOTL       Total Octets Transmitted (Low)
                   1 TPT        Total Packets Transmitted
                   1 PTC64      Packets Transmitted [64 Bytes] Count
size    mss     txtcp   txeth   txhw
4       1500    1       1       1

So one possible explanation for the previously observed behaviour is that since a Device Reset (RST) will not clear the NIC's internal Packet Buffer Allocation register (and possibly other undocumented internal registers?) and since we haven't issued a GIO Master Disable, the NIC will not clear all the pending requests (Page 35, Page 295 of 82574L DS)

Edit: 82574L not 83574L ; grammar fix

[rahul-mr]

Update: A new issue has cropped up now: assert( not bitset(regs[STATUS], 19) ) fails sometimes. Investigating...

Update2: It seems calling M.init() at the end of selftest_tso() fixes the assertion issue.

Update3: Page63 of DS - types of reset

[rahul-mr]

Update: the following reset() seems to work:

   function reset ()
      regs[IMC] = 0xffffffff                 -- Disable interrupts
      regs[CTRL] = bit.bor(regs[CTRL], bits({GMD=2})) -- Set GIO Master Disable
      C.usleep(1000) -- wait 1ms to clear all pending requests
      print("DBG: reset: GIO Master Enable Status: "..tostring(bitset(regs[STATUS], 19)) ) --GIO Master Enable Status 
      regs[CTRL] = bits({FD=0,SLU=6,RST=26,PHY_RST=31}) -- Global reset [ will (hopefully!) clear GIO Master Disable ]
      C.usleep(10); assert( not bitset(regs[CTRL],26) )
      regs[IMC] = 0xffffffff                 -- Disable interrupts
   end

[pkazmier]

Hi Rahul, where did you find the recommendation to disable the GIO master? I'm trying to learn what this is as its not documented well in my DS (or more likely I don't understand what's going on). How was this causing the issue? I assume I'll need to add to my code as well, but I'm not having any issues so I'm unsure what this is doing. Is this related to enabling bus mastering in init_pci?

[rahul-mr]

Hi Rahul, where did you find the recommendation to disable the GIO master? I'm trying to learn what this is as its not documented well in my DS (or more likely I don't understand what's going on). How was this causing the issue? I assume I'll need to add to my code as well, but I'm not having any issues so I'm unsure what this is doing. Is this related to enabling bus mastering in init_pci?

Hi Pete, as mentioned in an earlier post, please check: Page 295 and Page 35 of 82574L DS

[pkazmier]

Thanks! I completely missed that last paragraph in that post! I think I was too focused on the code. I'll read up and if I have any more questions I'll ask later.

[rahul-mr]

On 01/25/2013 07:40 AM, pkazmier wrote:

Thanks! I completely missed that last paragraph in that post! I think I was too focused on the code. I'll read up and if I have any more questions I'll ask later.
No worries ! :-)

[pkazmier]

To cross check, I went through the code for the igb and e1000e linux drivers. Guess what is the very first thing they do in their reset functions - disable master polling (see the comment about sticking). The igb_disable_pcie_master function below sets the CTRL.GMB bit, so it looks like you nailed this! I notice they set this prior to masking the interrupts, should we do the same?

static s32 igb_reset_hw_82575(struct e1000_hw *hw)
{
    u32 ctrl, icr;
    s32 ret_val;

    /*
     * Prevent the PCI-E bus from sticking if there is no TLP connection
     * on the last TLP read/write transaction when MAC is reset.
     */
    ret_val = igb_disable_pcie_master(hw);
    if (ret_val)
        hw_dbg("PCI-E Master disable polling has failed.\n");

    /* set the completion timeout for interface */
    ret_val = igb_set_pcie_completion_timeout(hw);
    if (ret_val) {
        hw_dbg("PCI-E Set completion timeout has failed.\n");
    }

    hw_dbg("Masking off all interrupts\n");
    wr32(E1000_IMC, 0xffffffff);
...

[rahul-mr]

On 01/25/2013 08:10 AM, pkazmier wrote:

To cross check, I went through the code for the igb and e1000e linux drivers. Guess what is the very first thing they do in their reset functions - disable master polling (see the comment about sticking). The igb_disable_pcie_master function below sets the CTRL.GMB bit, so it looks like you nailed this! I notice they set this prior to masking the interrupts, should we do the same?
Page 78 of 82574L DS says:

4.6.1  Interrupts During Initialization
Most drivers disable interrupts during initialization to prevent 
re-entrancy. Interrupts
are disabled by writing to the IMC register. Note that the interrupts 
need to be disabled
also after issuing a global reset, so a typical driver initialization 
flow is:
1. Disable interrupts
2. Issue a global reset
3. Disable interrupts (again)
4. …
After the initialization completes, a typical driver enables the desired 
interrupts by
writing to the IMS register.

I think the way we are doing it is safe :-)

[rahul-mr]

Update: In addition to the updated reset(), it seems it is important to do the following (in selftest_tso()) to avoid NIC lockups:

print "waiting for old traffic to die out ..."
--C.usleep(100000) -- Wait for old traffic from previous tests to die out

regs[CTRL] = bit.bor(regs[CTRL], bits({GMD=2})) -- Set GIO Master Disable
C.usleep(10000) -- wait 10ms
print("DBG: selftest_tso: GIO Master Enable Status: "..tostring(bitset(regs[STATUS], 19)) ) --GIO Master Enable Status
regs[CTRL] = bit.band(regs[CTRL], bit.bnot(bits({GMD=2})) ) -- Clear GIO Master Disable

[rahul-mr]

Update: This is the current setup that seems to work (for multiple runs):

   local function clear_rx()
      rdt = 0
      regs[RDT] = 0
      regs[RDH] = 0
   end M.clear_rx = clear_rx

   local function clear_tx()
      tdt = 0
      regs[TDT] = 0
      regs[TDH] = 0
   end M.clear_tx = clear_tx

  function M.selftest_tso (options):

      -- blah blah blah

      print "waiting for old traffic to die out ..."

      regs[CTRL] = bit.bor(regs[CTRL], bits({GMD=2})) -- Set GIO Master Disable
      C.usleep(10000) -- wait 10ms
      print("DBG: selftest_tso: GIO Master Enable Status: "..tostring(bitset(regs[STATUS], 19)) ) --GIO Master Enable Status
      regs[CTRL] = bit.band(regs[CTRL], bit.bnot(bits({GMD=2})) ) -- Clear GIO Master Disable

      --  blah blah blah

      print "waiting for packet transmission..."
      C.usleep(1000000) -- wait for 1s transmit
      M.clear_tx()
      C.usleep(1000) -- wait for 1 ms
      M.clear_rx()
      C.usleep(1000) -- wait for 1 ms

      -- blah blah blah

      regs[CTRL] = bit.bor(regs[CTRL], bits({GMD=2})) -- Set GIO Master Disable
      C.usleep(1000) -- wait 1ms
      print("DBG: selftest_tso: GIO Master Enable Status: "..tostring(bitset(regs[STATUS], 19)) ) --GIO Master Enable Status
      regs[CTRL] = bit.band(regs[CTRL], bit.bnot(bits({GMD=2})) ) -- Clear GIO Master Disable

  end

[lukego]

arbon-VM seems in the DMA-stuck state. Do you know a "cure" for this that doesn't require a reboot? I tried a replacement reset() above and your @rahul-mr/issue33 branch but can't get the counters moving.

[rahul-mr]

On 01/25/2013 01:45 PM, Luke Gorrie wrote:

arbon-VM seems in the DMA-stuck state. Do you know a "cure" for this that doesn't require a reboot? I tried a replacement reset() above and your @rahul-mr/issue33 branch but can't get the counters moving.

As far as I can see, the reset() doesn't bring the NIC out of its
locked-up state - only a hardware reboot works once the NIC enters the
locked-up state (the PCIe master disable/enable can prevent but not
cure).

I'm thinking of trying to directly write to the PCIe Power Management
Control/Status Register (PMCSR) [page 266, 82574L DS] to do a D0 -> D3
-> D0 power state transition and see if that helps.

[rahul-mr]

I'm thinking of trying to directly write to the PCIe Power Management Control/Status Register (PMCSR) [page 266, 82574L DS] to do a D0 -> D3 -> D0 power state transition and see if that helps.

Tried it - doesn't seem to fix the problem. arbon needs a reboot.

[lukego]

I did a reboot on arbon.

Here's the procedure I use after reboot to get the devel VM back up, in
case you want to do it yourself any time:

echo 0000:05:00.0 > /sys/bus/pci/devices/0000\:05\:00.0/driver/unbind
screen -S kvm # create a stable screen session
/root/kvm.sh

On 27 January 2013 12:44, rahul-mr notifications@github.com wrote:

I'm thinking of trying to directly write to the PCIe Power Management
Control/Status Register (PMCSR) [page 266, 82574L DS] to do a D0 -> D3 ->
D0 power state transition and see if that helps.

Tried it - doesn't seem to fix the problem. arbon needs a reboot.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/39#issuecomment-12753040.

[rahul-mr]

I did a reboot on arbon.

Here's the procedure I use after reboot to get the devel VM back up, in case you want to do it yourself any time:

Thanks, Luke :-)

[lukego]

I believe this was an issue with truncating 64-bit pointers to 32-bits so that we would give mangled pointers to the NIC.