On 27/02/2018 19:35, Marc Zyngier wrote: > On 27/02/18 18:11, Gustavo Pimentel wrote: >> On 27/02/2018 13:25, Marc Zyngier wrote: >>> Hi Gustavo, >>> >>> On 27/02/18 12:42, Gustavo Pimentel wrote: >>>> Hi Marc, >>>> >>>> I'm having some problems in my setup related to MSI-X, maybe you could help me >>>> debugging where could be the problem. >>>> >>>> Currently I have a RC (bridge) with 1 MSI-X interrupt and a commercial USB 3.0 >>>> EP capable of 8 MSI-X interrupts, however the xhci driver only uses 2 interrupts. >>>> >>>> I have posted below some debug info gathered during my tests. >>>> >>>> >>>> # cat /proc/interrupts >>>> CPU0 >>>> 3: 10014 ARC In-core Intc 3 Timer0 (per-cpu-tick) >>>> 4: 0 dw-apb-ictl 4 eth0 >>>> 8: 1 dw-apb-ictl 8 ehci_hcd:usb1, ohci_hcd:usb2 >>>> 9: 38 dw-apb-ictl 7 dw-mci >>>> 14: 0 dw-apb-ictl 14 e001d000.i2c >>>> 16: 0 dw-apb-ictl 16 e001f000.i2c >>>> 19: 4065 dw-apb-ictl 19 ttyS3 >>>> 46: 0 PCI-MSI 0 aerdrv >>>> 47: 1 PCI-MSI 524288 xhci_hcd >>>> 48: 0 PCI-MSI 524289 xhci_hcd >>>> # >>>> # >>>> # find /sys/ | grep msi >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/msi_bus >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/msi_irqs >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/msi_irqs/46 >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/msi_bus >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/msi_irqs >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/msi_irqs/48 >>>> /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/msi_irqs/47 >>>> # >>>> # >>>> # cat /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/ms >>>> i_bus >>>> 1 >>>> # >>>> # >>>> # cat /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/ms >>>> i_irqs/46 >>>> msix >>>> # >>>> # cat /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/00 >>>> 00:01:00.0/msi_bus >>>> 1 >>>> # >>>> # cat /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/00 >>>> 00:01:00.0/msi_irqs/48 >>>> msix >>>> # >>>> # >>>> # cat /sys/devices/platform/haps_tunnel/dfc00000.pcie/pci0000:00/0000:00:00.0/00 >>>> 00:01:00.0/msi_irqs/47 >>>> msix >>>> >>>> >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:dw_pcie_host_init:449) pp->num_vectors = 64 >>>> (GP:dw_pcie_host_init:453) dw_pcie_allocate_domains >>>> (GP:dw_pcie_allocate_domains:277) pp->num_vectors = 64 >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:pci_alloc_irq_vectors_affinity:1214) MSI-X >>>> (GP:__pci_enable_msix_range:1132) min=1, max=32 >>>> (GP:__pci_enable_msix:975) >>>> (GP:__pci_enable_msix:981) nr_entries = 1, nvec = 32 >>>> (GP:__pci_enable_msix_range:1145) rc=1 >>>> (GP:__pci_enable_msix:975) >>>> (GP:__pci_enable_msix:981) nr_entries = 1, nvec = 1 >>>> (GP:__pci_enable_msix:987) >>>> (GP:msix_capability_init:773) >>>> (GP:msix_capability_init:777) Disable MSI-X >>>> (GP:msix_capability_init:780) Control register 0x00000000 >>>> (GP:msix_map_region:682) Table offset = 0x00000000, bir = 0) >>>> (GP:msix_map_region:685) phys_addr = 0xD0500000, nr_entries = 1, ENTRY_SIZE = 16 >>>> bytes, table size = 16 bytes) >>>> (GP:msix_setup_entries:701) Allocate MSI entries 0/1 >>>> (GP:msix_setup_entries:719) >>>> (GP:msix_setup_entries:725) dev->irq = 45, base = d0500000, >>>> entry->msi_attrib.entry_nr = 0 >>>> (GP:pci_msi_setup_msi_irqs:53) msi_domain_alloc_irqs >>>> (GP:dw_pcie_irq_domain_alloc:231) nr_irqs = 1 >>>> (GP:dw_pcie_irq_domain_alloc:232) pp->num_vectors = 64 >>>> (GP:dw_pcie_irq_domain_alloc:233) order_base_2(nr_irqs) = 0 >>>> (GP:dw_pcie_irq_domain_alloc:245) virq + 0 = 46, bit + 0 = 0 >>>> (GP:msi_domain_alloc_irqs:399) IRQ_DOMAIN_ACTIVATE_IRQ >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:__irq_domain_activate_irq:1521) >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:msi_domain_activate:107) >>>> (GP:dw_pci_setup_msi_msg:142) msg_lo = 0x00000000, msg->address_hi = 0x9A228000, >>>> msg->data = 0x00000000, hwirq = 0 >>>> (GP:__pci_write_msi_msg:320) msg->address_lo = 0x9A228000, msg->address_hi = >>>> 0x00000000, msg->data = 0x00000000 >>>> (GP:msix_capability_init:804) Mask all MSI-X and enable MSI-X >>>> (GP:msix_program_entries:743) >>>> (GP:msix_capability_init:810) Populating MSI sysfs >>>> (GP:msix_capability_init:818) Unmask all MSI-X >>>> (GP:__pci_enable_msix_range:1145) rc=0 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1556) ALREADY ACTIVATED >> (GP:dw_pci_bottom_unmask:187) >> (GP:dw_pci_bottom_unmask:197) ctrl = 0, res = 0, bit = 0 >> (GP:dw_pci_bottom_unmask:198) Before, pp->irq_status[0] = 0x0 >> (GP:dw_pci_bottom_unmask:200) After, pp->irq_status[0] = 0x1 >> (GP:request_threaded_irq:1769) retval = 0 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516)(GP:request_threaded_irq:1769) retval = 0 >> (GP:request_threaded_irq:1694) >> (GP:request_threaded_irq:1769) retval = 0 >>>> (GP:xhci_setup_msix:264) >>>> (GP:pci_alloc_irq_vectors_affinity:1214) MSI-X >>>> (GP:__pci_enable_msix_range:1132) min=2, max=2 >>>> (GP:__pci_enable_msix:975) >>>> (GP:__pci_enable_msix:981) nr_entries = 8, nvec = 2 >>>> (GP:__pci_enable_msix:987) >>>> (GP:msix_capability_init:773) >>>> (GP:msix_capability_init:777) Disable MSI-X >>>> (GP:msix_capability_init:780) Control register 0x00000007 >>>> (GP:msix_map_region:682) Table offset = 0x00002000, bir = 0) >>>> (GP:msix_map_region:685) phys_addr = 0xD0402000, nr_entries = 8, ENTRY_SIZE = 16 >>>> bytes, table size = 128 bytes) >>>> (GP:msix_setup_entries:701) Allocate MSI entries 0/2 >>>> (GP:msix_setup_entries:719) >>>> (GP:msix_setup_entries:725) dev->irq = 45, base = d0402000, >>>> entry->msi_attrib.entry_nr = 0 >>>> (GP:msix_setup_entries:701) Allocate MSI entries 1/2 >>>> (GP:msix_setup_entries:719) >>>> (GP:msix_setup_entries:725) dev->irq = 45, base = d0402000, >>>> entry->msi_attrib.entry_nr = 1 >>>> (GP:pci_msi_setup_msi_irqs:53) msi_domain_alloc_irqs >>>> (GP:dw_pcie_irq_domain_alloc:231) nr_irqs = 1 >>>> (GP:dw_pcie_irq_domain_alloc:232) pp->num_vectors = 64 >>>> (GP:dw_pcie_irq_domain_alloc:233) order_base_2(nr_irqs) = 0 >>>> (GP:dw_pcie_irq_domain_alloc:245) virq + 0 = 47, bit + 0 = 1 >>>> (GP:dw_pcie_irq_domain_alloc:231) nr_irqs = 1 >>>> (GP:dw_pcie_irq_domain_alloc:232) pp->num_vectors = 64 >>>> (GP:dw_pcie_irq_domain_alloc:233) order_base_2(nr_irqs) = 0 >>>> (GP:dw_pcie_irq_domain_alloc:245) virq + 0 = 48, bit + 0 = 2 >>>> (GP:msi_domain_alloc_irqs:399) IRQ_DOMAIN_ACTIVATE_IRQ >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:__irq_domain_activate_irq:1521) >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:msi_domain_activate:107) >>>> (GP:dw_pci_setup_msi_msg:142) msg_lo = 0x00000001, msg->address_hi = 0x9A228000, >>>> msg->data = 0x00000000, hwirq = 1 >>>> (GP:__pci_write_msi_msg:320) msg->address_lo = 0x9A228000, msg->address_hi = >>>> 0x00000000, msg->data = 0x00000001 >>>> (GP:msi_domain_alloc_irqs:399) IRQ_DOMAIN_ACTIVATE_IRQ >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:__irq_domain_activate_irq:1521) >>>> (GP:__irq_domain_activate_irq:1516) >>>> (GP:msi_domain_activate:107) >>>> (GP:dw_pci_setup_msi_msg:142) msg_lo = 0x00000002, msg->address_hi = 0x9A228000, >>>> msg->data = 0x00000000, hwirq = 2 >>>> (GP:__pci_write_msi_msg:320) msg->address_lo = 0x9A228000, msg->address_hi = >>>> 0x00000000, msg->data = 0x00000002 >>>> (GP:msix_capability_init:804) Mask all MSI-X and enable MSI-X >>>> (GP:msix_program_entries:743) >>>> (GP:msix_capability_init:810) Populating MSI sysfs >>>> (GP:msix_capability_init:818) Unmask all MSI-X >>>> (GP:__pci_enable_msix_range:1145) rc=0 >>>> (GP:xhci_setup_msix:285) 0/2 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1556) ALREADY ACTIVATED >> (GP:dw_pci_bottom_unmask:187) >> (GP:dw_pci_bottom_unmask:197) ctrl = 0, res = 0, bit = 1 >> (GP:dw_pci_bottom_unmask:198) Before, pp->irq_status[0] = 0x1 >> (GP:dw_pci_bottom_unmask:200) After, pp->irq_status[0] = 0x3 >> (GP:request_threaded_irq:1769) retval = 0 >> (GP:xhci_setup_msix:289) ret = 0 >>>> (GP:xhci_setup_msix:285) 1/2 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1556) ALREADY ACTIVATED >> (GP:dw_pci_bottom_unmask:187) >> (GP:dw_pci_bottom_unmask:197) ctrl = 0, res = 0, bit = 2 >> (GP:dw_pci_bottom_unmask:198) Before, pp->irq_status[0] = 0x3 >> (GP:dw_pci_bottom_unmask:200) After, pp->irq_status[0] = 0x7 >> (GP:request_threaded_irq:1769) retval = 0 >> (GP:xhci_setup_msix:289) ret = 0 >> (GP:xhci_setup_msix:293) msix_enabled >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >> (GP:request_threaded_irq:1769) retval = 0 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >> (GP:request_threaded_irq:1769) retval = 0 >> (GP:request_threaded_irq:1694) >>>> (GP:irq_domain_activate_irq:1552) NOT ACTIVATED >>>> (GP:__irq_domain_activate_irq:1516) >> (GP:__irq_domain_activate_irq:1516) >> (GP:request_threaded_irq:1769) retval = 0 >>>> >>>> Me and João have looked to the sequence and this seems to be correct, however we >>>> are not receiving any interrupts and that originates the xhci to abort... >>>> >>>> xhci_hcd 0000:01:00.0: Abort failed to stop command ring: -110 >>>> xhci_hcd 0000:01:00.0: xHCI host controller not responding, assume dead >>>> xhci_hcd 0000:01:00.0: HC died; cleaning up >>>> xhci_hcd 0000:01:00.0: Error while assigning device slot ID >>>> xhci_hcd 0000:01:00.0: Max number of devices this xHCI host supports is 64. >>>> usb usb3-port1: couldn't allocate usb_device >>>> >>>> Any clue? Thanks in advance. >>> It is hard to dig in such a trace. One thing that strikes me is that I >>> don't see any trace that suggest that the interrupts get unmasked. That >>> should happen when the driver issues a request_irq. >> >> I have completed the above trace. As you can see the interrupts are being unmasked. > > How about the PCI domain itself? you only show things being unmasked at > the MSI controller level, but it could well be that they are still > masked at the endpoint level. I'm really poking in the dark here, so > bear with me. It was false alarm Marc (it was HW configuration problem). Anyway thanks very much for your help, it help me to understand better the internal implementation. > >> This modification has worked before with just one device with MSI-X capability, >> I assume the problem exists now because I have now 2 devices (Bridge + EP) the >> MSI-X capability (that's my currently theory). > > I'd find it odd. MSI-X allocation is per-device, and they really > shouldn't step on each other's toes...> > M. Gustavo
