Wednesday, October 31, 2012

how to fix that PCI(e) memspace?

That was a curious problem : a customer wanted hotplug functionality work with
our MIPS based board. Although we support native hotplug (by virtue of the
controller supporting native hotplug), the board did not have any hot-plug
support infrastructure : no attention button, no power control to slots ..etc.
So, we had to resort to a PLX chipset -- PEX 8624 and RDK board.

Thus, I started with an intel eepro (PCI ID - 8086:10d3) pcie single lane 1G ethernet
card. The driver has been available with linux and it is rock stable. After
compiling it as a module, (e1000e.ko) Linux was booted on the board.

Here is the topology

MIPS -> PCIe controller -> PEX 8624 -> eepro card

There are four 8x pcie controllers (yeah.. it can do 160Gbps sustained). Our
boot loader initializes the controllers and sets up BARs..etc. Linux is told not
to reconfigure (re-enumerate) devices and accept the values set in BARS and
other resources.

Now, I load the driver and .... Wham!

# modprobe e1000e
  0:<6>e1000e: Intel(R) PRO/1000 Network Driver - 1.3.10-k2
  0:<6>e1000e: Copyright(c) 1999 - 2011 Intel Corporation.
  0:<6>e1000e 0000:04:00.0: Disabling ASPM  L1
  0:<7>PCI: Setting latency timer of device 0000:04:00.0 to 64
  0:<3>e1000e 0000:04:00.0: MSI hi = 0x0, lo = 0xfcdc0000, data = 0x6
*******************************************************************************************
cpu_0 received a bus/cache error(warning)
*******************************************************************************************
CPU (XXX specific) registers dump: Node=0
    COP2: TxMsgStatus = 0x00000000, MsgStatus1 = 0x0f0f0000
     ICU: log0 = 0x00000000, log1 = 0x00000000, log2 = 0x00000000
     LSU: log0 = 0x00000000, log1 = 0x0000003c88f64500
     SCU: log0 = 0x00000000, log1 = 0x00000000, log2 = 0x00000000
     TCU: reg0 = 0x00000000, reg1 = 0x00000000, reg2 = 0x00000000
     NBU: reg0 = 0x00000000, reg1 = 0x00000000, reg2 = 0x00000000
  DRAM_A: reg1 = 0x00000000, reg2 = 0x00000000
  DRAM_B: reg1 = 0x00000000, reg2 = 0x00000000
  DRAM_C: reg1 = 0x00000000, reg2 = 0x00000000
  DRAM_D: reg1 = 0x00000000, reg2 = 0x00000000

     CPU: epc = 0xffffffffc127e3fc, errorepc = 0xffffffffe00580c4, cacheerr = 0x00000000
*******************************************************************************************
LSU Cache Warning:
   log0=0x0000000000000000, phyaddr=0x3c88f64500

Now that is a real problem.

After a couple of debug attempts, I could figure out that the first access
to PCI Mem configured in BAR0 is the culprit.

Obviously, we need to check whether BARs are setup correctly or not.
lspci comes to rescue here
lspci | grep 8086    /* This works because I am not on an intel system */
04:00.0 0200: 8086:10d3

~ # lspci -xxx -s 4:0.0
04:00.0 0200: 8086:10d3
00: 86 80 d3 10 07 00 10 00 00 00 00 02 08 00 00 00
10: 00 00 10 d0 00 00 20 d0 01 00 00 14 00 00 30 d0
20: 00 00 00 00 00 00 00 00 00 00 00 00 86 80 1f a0
30: 00 00 00 00 c8 00 00 00 00 00 00 00 58 01 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 11 00 04 00 03 00 00 00 03 20 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 01 d0 22 c8 00 20 00 14
d0: 05 e0 80 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 10 a0 01 00 c1 8c 00 00 10 28 10 00 11 1c 03 05
f0: 00 00 11 10 00 00 00 00 00 00 00 00 00 00 00 00

The highlighted area are the two BARs configured. The reason for crash is caused
by an access (otherwise legitimate -- not a bug in the driver) to one of these
areas (actually 0xd0100000 -- from the driver code). How do I know this? You look through the driver and you can make it out.

Why should we get a kernel crash while trying to access a memspace register? It can be explained like this. When an address is to be accessed, that address is put on the bus. Either DRAM controller should claim it (if it is within the DRAM range) or some other device controller should claim it, thus resolving the address. In this case, there were none to claim the address. Thus the NBU(North Bridge Unit) threw up an error.

Obviously that means this address' access is not set up correctly. We have to see how, when and why?
(I had set the PCI controller address range in the boot loader. Thus, I know 0xd0000000 is the base of PCI memspace and its size is 32M. And I had setup the NBU registers to redirect this memory range to PCI controllers. So, I don't have to worry about that part )

Armed with this knowledge, we need to figure out how access to this address is routed through PCIe switch from controller to the device.

lspci comes to rescue again.

~ # lspci -t -v #In tree structure, verbose
-[0000:00]-+-00.0  XXXX:1001
           +-00.1  XXXX:1002
           +-00.2  XXXX:1002
           +-00.3  XXXX:1002
           +-00.4  XXXX:1003
           +-01.0-[0000:01-05]----00.0-[0000:02-05]--+-04.0-[0000:03]--
           |                                         +-05.0-[0000:04]----00.0  8 086:10d3
           |                                         \-08.0-[0000:05]--
       +-01.1-[0000:06]--
           +-01.2-[0000:07]--
           +-01.3-[0000:08]--

What should we make out from this terse runic inscriptions?
The relevant facts here are that,
1. bus0,dev1,func0 is a pcie switch, so are d0f1, d0f2, and d0f3
2. b0d1f0 has a secondary bus (bus 1) and a subordinate bus(bus5).
    why? because that is what 01.0-[0000:01-05] means
    if you need raw config space data, try
    ~ # lspci -x -s 0:1.0
    00:01.0 0604: XXXX:1004 (rev 10)
    00: 4e 18 04 10 07 04 10 00 10 00 04 06 08 00 81 00
    10: 00 00 00 00 00 00 00 00 00 01 05 00 01 f1 00 00
    20: 00 10 30 d0 00 10 00 00 00 00 00 00 00 00 00 00
    30: 00 14 0f 14 40 00 00 00 00 00 00 00 58 01 00 00

3. Following the above points, we can see that the memory access path is,
controller (0:1.0) -> switch(primary/upstream) (1:0.0) ->
switch (secondary/downstream) (2:5.0) -> device (4:0.0) for 0xd0100000 address.

Also, note that bus 2 is internally consumed by the switch.

This makes our task easy, we need to check only the above path to figure out
whether memory access works at all.

Again, back to lspci to check whether memspace is set correctly throughout this
path.
~ # lspci -xx -s 04:00.0
04:00.0 0200: 8086:10d3
00: 86 80 d3 10 07 00 10 00 00 00 00 02 08 00 00 00
10: 00 00 10 d0 00 00 20 d0 01 00 00 14 00 00 30 d0
20: 00 00 00 00 00 00 00 00 00 00 00 00 86 80 1f a0
30: 00 00 00 00 c8 00 00 00 00 00 00 00 58 01 00 00

Shows the device has two regions : one starting @ 0xd0100000 , another starting
@ 0xd0200000. We don't know the sizes of these regions, but for the time being
it does not matter.

For any access to these regions to pass through the switch, switch has to be
configured to claim these accesses. A switch can be programmed to do this by
filling in the correct range in memspace/mem limit registers at offset 0x20-0x23

~ # lspci -xx -s 01:00.0
01:00.0 0604: 10b5:8624 (rev bb)
00: b5 10 24 86 07 04 10 00 bb 00 04 06 08 00 01 00
10: 00 00 00 d0 00 00 00 00 01 02 05 00 f1 f1 00 00
20: 00 10 30 d0 01 10 01 00 00 00 00 00 00 00 00 00
30: 00 00 0f 14 40 00 00 00 00 00 00 00 58 01 00 00

Does not look good. Why? Pay attention to the highlighted area. This means that the range 0xd0300000 - 0x1000ffff is the memspace. Or is it ? No. according to the spec, if the mem limit is lower than base, then it should be considered disabled. So, effectively we have disabled the memspace behind the switch. No wonder we got a kernel crash.

Lets check if this behavior is consistent across all switch ports and controller (controller is also a switch, called root switch). Lets start with the controller.

~ # lspci -x -s 0:1.0
00:01.0 0604: XXXX:1004 (rev 10)
00: 4e 18 04 10 07 04 10 00 10 00 04 06 08 00 81 00
10: 00 00 00 00 00 00 00 00 00 01 05 00 01 f1 00 00
20: 00 d0 30 d0 00 10 00 00 00 00 00 00 00 00 00 00
30: 00 14 0f 14 40 00 00 00 00 00 00 00 58 01 00 00

Hmm... I guess you can see the discrepancy.

Now, to make sure the error has percolated all the way through,
~ # lspci -x -s 2:5.0
02:05.0 0604: 10b5:8624 (rev bb)
00: b5 10 24 86 07 04 10 00 bb 00 04 06 08 00 01 00
10: 00 00 00 00 00 00 00 00 02 04 04 00 f1 f1 00 00
20: 00 10 30 d0 01 10 01 00 00 00 00 00 00 00 00 00
30: 00 00 0f 14 40 00 00 00 00 00 00 00 58 01 00 00

~ # lspci -x -s 4:0.0
04:00.0 0200: 8086:10d3
00: 86 80 d3 10 07 00 10 00 00 00 00 02 08 00 00 00
10: 00 00 10 d0 00 00 20 d0 01 00 00 14 00 00 30 d0
20: 00 00 00 00 00 00 00 00 00 00 00 00 86 80 1f a0
30: 00 00 00 00 c8 00 00 00 00 00 00 00 58 01 00 00

This is completely weired. No wonder we had such a bad experience. Looks like
boot loader screwed up big time. So, lets drop to boot loader (in our case, it
is u-boot)

The correct minimum memory space access range should be as follows

0:1.0 : regiter at offset 0x20 (membase/memlimit) should contain something like
0xd010d020. Thus defining an address range on the secondary side of the root
switch to be 0xd0100000 - 0xd02fffff (at least)

1:0.0 : If this switch has not implemented a BAR for its internal PCI memory,
range 0xd0100000 - 0xd02fffff will solely be for seconday side of the switch.

2:5.0 : Requires 0xd0100000 - 0xd02fffff assigned to this device.

Now, lets drop to u-boot and manually overwrite the range
u-boot# pci write.l 0x20 0xd010d020 1.0.0
u-boot# pci write.l 0x20 0xd010d020 2.5.0
u-boot# pci write.l 0x20 0xd000d010 2.8.0


Boot up linux and load the driver.
~ # modprobe e1000e
  0:<6>e1000e: Intel(R) PRO/1000 Network Driver - 1.3.10-k2
  0:<6>e1000e: Copyright(c) 1999 - 2011 Intel Corporation.
  0:<6>e1000e 0000:04:00.0: Disabling ASPM L0s
  0:<7>PCI: Setting latency timer of device 0000:04:00.0 to 64

~ # ifconfig eth0 1.1.1.1 up

~ # ifconfig eth0 10.67.70.5 up
~ # ping 10.67.70.61
PING 10.67.70.61 (10.67.70.61): 56 data bytes
64 bytes from 10.67.70.61: seq=0 ttl=64 time=1.187 ms
64 bytes from 10.67.70.61: seq=1 ttl=64 time=0.137 ms
64 bytes from 10.67.70.61: seq=2 ttl=64 time=0.129 ms


That was a great experience to figure out the root cause of the crash. Now
update bootloader code to handle PCIe switch resource allocations correctly.

Thus, a problem manifested with reference to PCIe native hot-plug pointed to a PCI resource allocation issue which had to be eventually fixed in the boot loader in embedded system. Maybe, if we had used linux to re-initialize all PCI resources and re-enumerate it, this problem would have never occurred.

Anyway, now you, the reader, should be slightly more comfortable using lspci to troubleshoot some intricate PCI resource allocation issues :-)

No comments:

Post a Comment