RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Thomas Gleixner]

Dexuan,

On Sat, Aug 28 2021 at 01:53, Thomas Gleixner wrote:
> On Thu, Aug 19 2021 at 20:41, Dexuan Cui wrote:
>>> Sorry for the late response! I checked the below sys file, and the output is
>>> exactly the same in the good/bad cases -- in both cases, I use maxcpus=8;
>>> the only difference in the good case is that I online and then offline CPU 8~31:
>>> for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online; done
>>> for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online; done
>>> 
>>> # cat /sys/kernel/debug/irq/irqs/209

Yes, that looks correct.

>>
>> I tried the kernel parameter "intremap=nosid,no_x2apic_optout,nopost" but
>> it didn't help. Only "intremap=off" can work round the no interrupt issue.
>>
>> When the no interrupt issue happens, irq 209's effective_affinity_list is 5.
>> I modified modify_irte() to print the irte->low, irte->high, and I also printed
>> the irte_index for irq 209, and they were all normal to me, and they were
>> exactly the same in the bad case and the good case -- it looks like, with
>> "intremap=on maxcpus=8", MSI-X on CPU5 can't work for the NIC device
>> (MSI-X on CPU5 works for other devices like a NVMe controller) , and somehow
>> "onlining and then offlining CPU 8~31" can "fix" the issue, which is really weird.

Just for the record: maxcpus=N is a dangerous boot option as it leaves
the non brought up CPUs in a state where they can be hit by MCE
broadcasting without being able to act on it. Which means you're
operating the system out of spec.

According to your debug output the interrupt in question belongs to the
INTEL-IR-3 interrupt domain, which means it hangs of IOMMU3, aka DMAR
unit 3.

To which DMAR/remap unit are the other unaffected devices connected to?

Thanks,

        tglx

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

> From: Thomas Gleixner <tglx@linutronix.de>
> Sent: Saturday, August 28, 2021 1:44 PM
> >> I tried the kernel parameter "intremap=nosid,no_x2apic_optout,nopost"
> but
> >> it didn't help. Only "intremap=off" can work round the no interrupt issue.
> >>
> >> When the no interrupt issue happens, irq 209's effective_affinity_list is 5.
> >> I modified modify_irte() to print the irte->low, irte->high, and I also printed
> >> the irte_index for irq 209, and they were all normal to me, and they were
> >> exactly the same in the bad case and the good case -- it looks like, with
> >> "intremap=on maxcpus=8", MSI-X on CPU5 can't work for the NIC device
> >> (MSI-X on CPU5 works for other devices like a NVMe controller) , and
> somehow
> >> "onlining and then offlining CPU 8~31" can "fix" the issue, which is really
> weird.
> 
> Just for the record: maxcpus=N is a dangerous boot option as it leaves
> the non brought up CPUs in a state where they can be hit by MCE
> broadcasting without being able to act on it. Which means you're
> operating the system out of spec.

I didn't know about this. Thanks for the reply! 

> According to your debug output the interrupt in question belongs to the
> INTEL-IR-3 interrupt domain, which means it hangs of IOMMU3, aka DMAR
> unit 3.
>
> To which DMAR/remap unit are the other unaffected devices connected to?
> 
>         tglx

With maxcpus=8, on CPU 5, the NIC receives no interrupt, but a NVMe
interrupt ("INTEL-IR-6") on the CPU works, and two "IOAT" interrupts 
("INTEL-IR-7") also work.

Except the NIC, the only IRQs connected to the faulty IOMMU3 are
irq33 and irq34:

root@lsg-gen7-a:~# cat /sys/kernel/debug/irq/irqs/33
handler:  handle_fasteoi_irq
device:   (null)
status:   0x00004100
istate:   0x00000000
ddepth:   1
wdepth:   0
dstate:   0x3503a000
            IRQD_LEVEL
            IRQD_IRQ_DISABLED
            IRQD_IRQ_MASKED
            IRQD_SINGLE_TARGET
            IRQD_MOVE_PCNTXT
            IRQD_AFFINITY_ON_ACTIVATE
            IRQD_CAN_RESERVE
            IRQD_HANDLE_ENFORCE_IRQCTX
node:     1
affinity: 0-103
effectiv: 0
pending:
domain:  IO-APIC-18
 hwirq:   0x0
 chip:    IR-IO-APIC
  flags:   0x10
             IRQCHIP_SKIP_SET_WAKE
 parent:
    domain:  INTEL-IR-3
     hwirq:   0x0
     chip:    INTEL-IR
      flags:   0x0
     parent:
        domain:  VECTOR
         hwirq:   0x21
         chip:    APIC
          flags:   0x0
         Vector:     0
         Target:     0
         move_in_progress: 0
         is_managed:       0
         can_reserve:      1
         has_reserved:     1
         cleanup_pending:  0

root@lsg-gen7-a:~# cat /sys/kernel/debug/irq/irqs/34
handler:  handle_edge_irq
device:   0000:d7:00.0
status:   0x00004000
istate:   0x00000000
ddepth:   0
wdepth:   0
dstate:   0x37408200
            IRQD_ACTIVATED
            IRQD_IRQ_STARTED
            IRQD_SINGLE_TARGET
            IRQD_MOVE_PCNTXT
            IRQD_AFFINITY_ON_ACTIVATE
            IRQD_CAN_RESERVE
            IRQD_DEFAULT_TRIGGER_SET
            IRQD_HANDLE_ENFORCE_IRQCTX
node:     1
affinity: 0-7
effectiv: 1
pending:
domain:  INTEL-IR-MSI-3-3
 hwirq:   0x6b80000
 chip:    IR-PCI-MSI
  flags:   0x30
             IRQCHIP_SKIP_SET_WAKE
             IRQCHIP_ONESHOT_SAFE
 parent:
    domain:  INTEL-IR-3
     hwirq:   0x10000
     chip:    INTEL-IR
      flags:   0x0
     parent:
        domain:  VECTOR
         hwirq:   0x22
         chip:    APIC
          flags:   0x0
         Vector:    34
         Target:     1
         move_in_progress: 0
         is_managed:       0
         can_reserve:      1
         has_reserved:     0
         cleanup_pending:  0

root@lsg-gen7-a:~# lspci |grep d7:00.0
d7:00.0 PCI bridge: Intel Corporation Sky Lake-E PCI Express Root Port A (rev 07)

irq 33 doesn't appear in /proc/interupts.
irq 34 in /proc/interupts also receives no interrupts.

So it looks like IOMMU3 is somehow not working at all
with maxcpus=8. "onlining and offlining CPU 8~31" can
somehow "fix" it. :-) I'm not sure if this is a kernel issue
or firmware issue.

Thanks,
Dexuan

[5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

Hi all,
I'm seeing a strange "no MSI-X interrupt" issue with the Mellanox NIC
driver on a physical Linux host [1], if I only enable part of the CPUs.

The physical host has 104 logical processors (2 sockets, and each socket
has 26 cores with HT enabled). By default, the Mellanox driver works fine
when Linux boots up.

If I only use 1, 2, 32, 64, 96 processors by the Linux kernel parameter
"maxcpus=X" or "nr_cpus=X", everthing still works fine.

However, if the Linux host OS only uses 4, 8 or 16 processors, the
mlx5_core driver fails to load as it can not receive interrupt when
creating EQ (maxcpus=8 or 16), or the driver can load but it reports a
timeout error when I try to bring the NIC up (maxcpus=4). This issue is
a 100% repro.

For example, with "maxcpus=8", I get the below timeout error when trying
to load mlx5_core:

# modprobe mlx5_core
[ 1475.716688] mlx5_core 0000:d8:00.0: firmware version: 16.25.8352
[ 1475.722742] mlx5_core 0000:d8:00.0: 126.016 Gb/s available PCIe bandwidth (8.0 GT/s PCIe x16 link)
[ 1475.991398] mlx5_core 0000:d8:00.0: E-Switch: Total vports 2, per vport: max uc(1024) max mc(16384)

[ 1537.020001] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416): Recovered 1 EQEs on cmd_eq
[ 1537.028969] mlx5_core 0000:d8:00.0: wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301) recovered after timeout
[ 1598.460003] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416): Recovered 1 EQEs on cmd_eq
[ 1598.468978] mlx5_core 0000:d8:00.0: wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301) recovered after timeout
[ 1659.900010] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416): Recovered 1 EQEs on cmd_eq
[ 1659.908987] mlx5_core 0000:d8:00.0: wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301) recovered after timeout
[ 1721.340006] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416): Recovered 1 EQEs on cmd_eq
[ 1721.348989] mlx5_core 0000:d8:00.0: wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301) recovered after timeout

When this happens, the mlx5_core driver is stuck with the below
call-trace, waiting for some interrupt:

# ps aux |grep modprobe
root        1416  0.0  0.0  11024  1472 ttyS0    D+   08:08   0:00 modprobe mlx5_core
root        1480  0.0  0.0   6440   736 pts/0    S+   08:15   0:00 grep --color=auto modprobe

# cat /proc/1416/stack
[<0>] cmd_exec+0x8a7/0x9b0 [mlx5_core]
[<0>] mlx5_cmd_exec+0x24/0x50 [mlx5_core]
[<0>] create_map_eq+0x2a6/0x380 [mlx5_core]
[<0>] mlx5_eq_table_create+0x504/0x710 [mlx5_core]
[<0>] mlx5_load+0x52/0x130 [mlx5_core]
[<0>] mlx5_init_one+0x1cc/0x250 [mlx5_core]
[<0>] probe_one+0x1d3/0x2a0 [mlx5_core]
[<0>] local_pci_probe+0x45/0x80
[<0>] pci_device_probe+0x10f/0x1c0
[<0>] really_probe+0x1c1/0x3b0
[<0>] __driver_probe_device+0x109/0x180
[<0>] driver_probe_device+0x23/0xa0
[<0>] __driver_attach+0xbd/0x160
[<0>] bus_for_each_dev+0x7c/0xc0
[<0>] driver_attach+0x1e/0x20
[<0>] bus_add_driver+0x152/0x1f0
[<0>] driver_register+0x74/0xd0
[<0>] __pci_register_driver+0x68/0x70
[<0>] init+0x6b/0x1000 [mlx5_core]
[<0>] do_one_initcall+0x46/0x1d0
[<0>] do_init_module+0x62/0x250
[<0>] load_module+0x2503/0x2730
[<0>] __do_sys_finit_module+0xbf/0x120
[<0>] __x64_sys_finit_module+0x1a/0x20
[<0>] do_syscall_64+0x38/0xc0
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xae

To make the issue even weirder, when the issue happens (e.g. when Linux
only uses 8 processors), if I manually bring CPU #8~#31 online [2] and
then bring them offline [3], the Mellanox driver will work fine!

This is a x86-64 host. Is it possibe that the IOMMU Interrrupt Remapping
is not proprely set up with maxcpus=4, 8 and 16?

The above tests were done with the recent Linux v5.14-rc1 kernel. I also
tried Ubuntu 20.04's kernel "5.4.0-77-generic", and the Mellanox driver
exhibits exactly the same issue.

I have Linux/Windows dual-boot on this physical machine, and Windows
doesn't have the issue when I let it only use 4, 8 and 16 processors.
So this looks like somehow the issue is specific to Linux.

Can someone please shed some light on this strange issue? I'm ready
to provide more logs if needed. Thanks!

PS, the physical machine has 4 NVMe controllers and 4 Broadcom NICs,
which are not affected by maxcpus=4, 8, and 16.

[1] This is the 'lspci' output of the Mellanox NIC:
d8:00.0 Ethernet controller: Mellanox Technologies MT27800 Family [ConnectX-5]
        Subsystem: Mellanox Technologies MT27800 Family [ConnectX-5]
        Flags: bus master, fast devsel, latency 0, IRQ 33, NUMA node 1
        Memory at f8000000 (64-bit, prefetchable) [size=32M]
        Expansion ROM at fbe00000 [disabled] [size=1M]
        Capabilities: [60] Express Endpoint, MSI 00
        Capabilities: [48] Vital Product Data
        Capabilities: [9c] MSI-X: Enable+ Count=64 Masked-
        Capabilities: [c0] Vendor Specific Information: Len=18 <?>
        Capabilities: [40] Power Management version 3
        Capabilities: [100] Advanced Error Reporting
        Capabilities: [150] Alternative Routing-ID Interpretation (ARI)
        Capabilities: [180] Single Root I/O Virtualization (SR-IOV)
        Capabilities: [1c0] Secondary PCI Express
        Kernel driver in use: mlx5_core
        Kernel modules: mlx5_core
00: b3 15 17 10 46 05 10 00 00 00 00 02 08 00 00 00
10: 0c 00 00 f8 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 b3 15 80 00
30: 00 00 e0 fb 60 00 00 00 00 00 00 00 ff 01 00 00

[2] for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online; done
[3] for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online; done

Thanks,
-- Dexuan

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

> From: Dexuan Cui
> Sent: Wednesday, July 14, 2021 5:39 PM
> To: netdev@vger.kernel.org; x86@kernel.org
> Cc: Haiyang Zhang <haiyangz@microsoft.com>; linux-kernel@vger.kernel.org
> Subject: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8
> 
> Hi all,
> I'm seeing a strange "no MSI-X interrupt" issue with the Mellanox NIC
> driver on a physical Linux host [1], if I only enable part of the CPUs.
> 
> The physical host has 104 logical processors (2 sockets, and each socket
> has 26 cores with HT enabled). By default, the Mellanox driver works fine
> when Linux boots up.
> 
> If I only use 1, 2, 32, 64, 96 processors by the Linux kernel parameter
> "maxcpus=X" or "nr_cpus=X", everthing still works fine.
> 
> However, if the Linux host OS only uses 4, 8 or 16 processors, the
> mlx5_core driver fails to load as it can not receive interrupt when
> creating EQ (maxcpus=8 or 16), or the driver can load but it reports a
> timeout error when I try to bring the NIC up (maxcpus=4). This issue is
> a 100% repro.
> 
> For example, with "maxcpus=8", I get the below timeout error when trying
> to load mlx5_core:
> 
> # modprobe mlx5_core
> [ 1475.716688] mlx5_core 0000:d8:00.0: firmware version: 16.25.8352
> [ 1475.722742] mlx5_core 0000:d8:00.0: 126.016 Gb/s available PCIe
> bandwidth (8.0 GT/s PCIe x16 link)
> [ 1475.991398] mlx5_core 0000:d8:00.0: E-Switch: Total vports 2, per vport:
> max uc(1024) max mc(16384)
> 
> [ 1537.020001] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> Recovered 1 EQEs on cmd_eq
> [ 1537.028969] mlx5_core 0000:d8:00.0:
> wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> recovered after timeout
> [ 1598.460003] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> Recovered 1 EQEs on cmd_eq
> [ 1598.468978] mlx5_core 0000:d8:00.0:
> wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> recovered after timeout
> [ 1659.900010] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> Recovered 1 EQEs on cmd_eq
> [ 1659.908987] mlx5_core 0000:d8:00.0:
> wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> recovered after timeout
> [ 1721.340006] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> Recovered 1 EQEs on cmd_eq
> [ 1721.348989] mlx5_core 0000:d8:00.0:
> wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> recovered after timeout
> 
> When this happens, the mlx5_core driver is stuck with the below
> call-trace, waiting for some interrupt:
> 
> # ps aux |grep modprobe
> root        1416  0.0  0.0  11024  1472 ttyS0    D+   08:08   0:00
> modprobe mlx5_core
> root        1480  0.0  0.0   6440   736 pts/0    S+   08:15   0:00
> grep --color=auto modprobe
> 
> # cat /proc/1416/stack
> [<0>] cmd_exec+0x8a7/0x9b0 [mlx5_core]
> [<0>] mlx5_cmd_exec+0x24/0x50 [mlx5_core]
> [<0>] create_map_eq+0x2a6/0x380 [mlx5_core]
> [<0>] mlx5_eq_table_create+0x504/0x710 [mlx5_core]
> [<0>] mlx5_load+0x52/0x130 [mlx5_core]
> [<0>] mlx5_init_one+0x1cc/0x250 [mlx5_core]
> [<0>] probe_one+0x1d3/0x2a0 [mlx5_core]
> [<0>] local_pci_probe+0x45/0x80
> [<0>] pci_device_probe+0x10f/0x1c0
> [<0>] really_probe+0x1c1/0x3b0
> [<0>] __driver_probe_device+0x109/0x180
> [<0>] driver_probe_device+0x23/0xa0
> [<0>] __driver_attach+0xbd/0x160
> [<0>] bus_for_each_dev+0x7c/0xc0
> [<0>] driver_attach+0x1e/0x20
> [<0>] bus_add_driver+0x152/0x1f0
> [<0>] driver_register+0x74/0xd0
> [<0>] __pci_register_driver+0x68/0x70
> [<0>] init+0x6b/0x1000 [mlx5_core]
> [<0>] do_one_initcall+0x46/0x1d0
> [<0>] do_init_module+0x62/0x250
> [<0>] load_module+0x2503/0x2730
> [<0>] __do_sys_finit_module+0xbf/0x120
> [<0>] __x64_sys_finit_module+0x1a/0x20
> [<0>] do_syscall_64+0x38/0xc0
> [<0>] entry_SYSCALL_64_after_hwframe+0x44/0xae
> 
> To make the issue even weirder, when the issue happens (e.g. when Linux
> only uses 8 processors), if I manually bring CPU #8~#31 online [2] and
> then bring them offline [3], the Mellanox driver will work fine!
> 
> This is a x86-64 host. Is it possibe that the IOMMU Interrrupt Remapping
> is not proprely set up with maxcpus=4, 8 and 16?
> 
> The above tests were done with the recent Linux v5.14-rc1 kernel. I also
> tried Ubuntu 20.04's kernel "5.4.0-77-generic", and the Mellanox driver
> exhibits exactly the same issue.
> 
> I have Linux/Windows dual-boot on this physical machine, and Windows
> doesn't have the issue when I let it only use 4, 8 and 16 processors.
> So this looks like somehow the issue is specific to Linux.
> 
> Can someone please shed some light on this strange issue? I'm ready
> to provide more logs if needed. Thanks!
> 
> PS, the physical machine has 4 NVMe controllers and 4 Broadcom NICs,
> which are not affected by maxcpus=4, 8, and 16.
> 
> [1] This is the 'lspci' output of the Mellanox NIC:
> d8:00.0 Ethernet controller: Mellanox Technologies MT27800 Family
> [ConnectX-5]
>         Subsystem: Mellanox Technologies MT27800 Family [ConnectX-5]
>         Flags: bus master, fast devsel, latency 0, IRQ 33, NUMA node 1
>         Memory at f8000000 (64-bit, prefetchable) [size=32M]
>         Expansion ROM at fbe00000 [disabled] [size=1M]
>         Capabilities: [60] Express Endpoint, MSI 00
>         Capabilities: [48] Vital Product Data
>         Capabilities: [9c] MSI-X: Enable+ Count=64 Masked-
>         Capabilities: [c0] Vendor Specific Information: Len=18 <?>
>         Capabilities: [40] Power Management version 3
>         Capabilities: [100] Advanced Error Reporting
>         Capabilities: [150] Alternative Routing-ID Interpretation (ARI)
>         Capabilities: [180] Single Root I/O Virtualization (SR-IOV)
>         Capabilities: [1c0] Secondary PCI Express
>         Kernel driver in use: mlx5_core
>         Kernel modules: mlx5_core
> 00: b3 15 17 10 46 05 10 00 00 00 00 02 08 00 00 00
> 10: 0c 00 00 f8 00 00 00 00 00 00 00 00 00 00 00 00
> 20: 00 00 00 00 00 00 00 00 00 00 00 00 b3 15 80 00
> 30: 00 00 e0 fb 60 00 00 00 00 00 00 00 ff 01 00 00
> 
> [2] for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online;
> done
> [3] for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online;
> done
> 
> Thanks,
> -- Dexuan

(+ the linux-pci list)

It turns out that adding "intremap=off" can work around the issue!

The root cause is still not clear yet. I don't know why Windows is good here.

Thanks,
Dexuan

Re: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Leon Romanovsky]

On Thu, Jul 15, 2021 at 01:11:55AM +0000, Dexuan Cui wrote:
> > From: Dexuan Cui
> > Sent: Wednesday, July 14, 2021 5:39 PM
> > To: netdev@vger.kernel.org; x86@kernel.org
> > Cc: Haiyang Zhang <haiyangz@microsoft.com>; linux-kernel@vger.kernel.org
> > Subject: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8
> > 
> > Hi all,
> > I'm seeing a strange "no MSI-X interrupt" issue with the Mellanox NIC
> > driver on a physical Linux host [1], if I only enable part of the CPUs.
> > 
> > The physical host has 104 logical processors (2 sockets, and each socket
> > has 26 cores with HT enabled). By default, the Mellanox driver works fine
> > when Linux boots up.
> > 
> > If I only use 1, 2, 32, 64, 96 processors by the Linux kernel parameter
> > "maxcpus=X" or "nr_cpus=X", everthing still works fine.
> > 
> > However, if the Linux host OS only uses 4, 8 or 16 processors, the
> > mlx5_core driver fails to load as it can not receive interrupt when
> > creating EQ (maxcpus=8 or 16), or the driver can load but it reports a
> > timeout error when I try to bring the NIC up (maxcpus=4). This issue is
> > a 100% repro.
> > 
> > For example, with "maxcpus=8", I get the below timeout error when trying
> > to load mlx5_core:
> > 
> > # modprobe mlx5_core
> > [ 1475.716688] mlx5_core 0000:d8:00.0: firmware version: 16.25.8352
> > [ 1475.722742] mlx5_core 0000:d8:00.0: 126.016 Gb/s available PCIe
> > bandwidth (8.0 GT/s PCIe x16 link)
> > [ 1475.991398] mlx5_core 0000:d8:00.0: E-Switch: Total vports 2, per vport:
> > max uc(1024) max mc(16384)
> > 
> > [ 1537.020001] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> > Recovered 1 EQEs on cmd_eq
> > [ 1537.028969] mlx5_core 0000:d8:00.0:
> > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> > recovered after timeout
> > [ 1598.460003] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> > Recovered 1 EQEs on cmd_eq
> > [ 1598.468978] mlx5_core 0000:d8:00.0:
> > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> > recovered after timeout
> > [ 1659.900010] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> > Recovered 1 EQEs on cmd_eq
> > [ 1659.908987] mlx5_core 0000:d8:00.0:
> > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> > recovered after timeout
> > [ 1721.340006] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid 1416):
> > Recovered 1 EQEs on cmd_eq
> > [ 1721.348989] mlx5_core 0000:d8:00.0:
> > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]: CREATE_EQ(0x301)
> > recovered after timeout
> > 
> > When this happens, the mlx5_core driver is stuck with the below
> > call-trace, waiting for some interrupt:
> > 
> > # ps aux |grep modprobe
> > root        1416  0.0  0.0  11024  1472 ttyS0    D+   08:08   0:00
> > modprobe mlx5_core
> > root        1480  0.0  0.0   6440   736 pts/0    S+   08:15   0:00
> > grep --color=auto modprobe
> > 
> > # cat /proc/1416/stack
> > [<0>] cmd_exec+0x8a7/0x9b0 [mlx5_core]
> > [<0>] mlx5_cmd_exec+0x24/0x50 [mlx5_core]
> > [<0>] create_map_eq+0x2a6/0x380 [mlx5_core]
> > [<0>] mlx5_eq_table_create+0x504/0x710 [mlx5_core]
> > [<0>] mlx5_load+0x52/0x130 [mlx5_core]
> > [<0>] mlx5_init_one+0x1cc/0x250 [mlx5_core]
> > [<0>] probe_one+0x1d3/0x2a0 [mlx5_core]
> > [<0>] local_pci_probe+0x45/0x80
> > [<0>] pci_device_probe+0x10f/0x1c0
> > [<0>] really_probe+0x1c1/0x3b0
> > [<0>] __driver_probe_device+0x109/0x180
> > [<0>] driver_probe_device+0x23/0xa0
> > [<0>] __driver_attach+0xbd/0x160
> > [<0>] bus_for_each_dev+0x7c/0xc0
> > [<0>] driver_attach+0x1e/0x20
> > [<0>] bus_add_driver+0x152/0x1f0
> > [<0>] driver_register+0x74/0xd0
> > [<0>] __pci_register_driver+0x68/0x70
> > [<0>] init+0x6b/0x1000 [mlx5_core]
> > [<0>] do_one_initcall+0x46/0x1d0
> > [<0>] do_init_module+0x62/0x250
> > [<0>] load_module+0x2503/0x2730
> > [<0>] __do_sys_finit_module+0xbf/0x120
> > [<0>] __x64_sys_finit_module+0x1a/0x20
> > [<0>] do_syscall_64+0x38/0xc0
> > [<0>] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > 
> > To make the issue even weirder, when the issue happens (e.g. when Linux
> > only uses 8 processors), if I manually bring CPU #8~#31 online [2] and
> > then bring them offline [3], the Mellanox driver will work fine!
> > 
> > This is a x86-64 host. Is it possibe that the IOMMU Interrrupt Remapping
> > is not proprely set up with maxcpus=4, 8 and 16?
> > 
> > The above tests were done with the recent Linux v5.14-rc1 kernel. I also
> > tried Ubuntu 20.04's kernel "5.4.0-77-generic", and the Mellanox driver
> > exhibits exactly the same issue.
> > 
> > I have Linux/Windows dual-boot on this physical machine, and Windows
> > doesn't have the issue when I let it only use 4, 8 and 16 processors.
> > So this looks like somehow the issue is specific to Linux.
> > 
> > Can someone please shed some light on this strange issue? I'm ready
> > to provide more logs if needed. Thanks!
> > 
> > PS, the physical machine has 4 NVMe controllers and 4 Broadcom NICs,
> > which are not affected by maxcpus=4, 8, and 16.
> > 
> > [1] This is the 'lspci' output of the Mellanox NIC:
> > d8:00.0 Ethernet controller: Mellanox Technologies MT27800 Family
> > [ConnectX-5]
> >         Subsystem: Mellanox Technologies MT27800 Family [ConnectX-5]
> >         Flags: bus master, fast devsel, latency 0, IRQ 33, NUMA node 1
> >         Memory at f8000000 (64-bit, prefetchable) [size=32M]
> >         Expansion ROM at fbe00000 [disabled] [size=1M]
> >         Capabilities: [60] Express Endpoint, MSI 00
> >         Capabilities: [48] Vital Product Data
> >         Capabilities: [9c] MSI-X: Enable+ Count=64 Masked-
> >         Capabilities: [c0] Vendor Specific Information: Len=18 <?>
> >         Capabilities: [40] Power Management version 3
> >         Capabilities: [100] Advanced Error Reporting
> >         Capabilities: [150] Alternative Routing-ID Interpretation (ARI)
> >         Capabilities: [180] Single Root I/O Virtualization (SR-IOV)
> >         Capabilities: [1c0] Secondary PCI Express
> >         Kernel driver in use: mlx5_core
> >         Kernel modules: mlx5_core
> > 00: b3 15 17 10 46 05 10 00 00 00 00 02 08 00 00 00
> > 10: 0c 00 00 f8 00 00 00 00 00 00 00 00 00 00 00 00
> > 20: 00 00 00 00 00 00 00 00 00 00 00 00 b3 15 80 00
> > 30: 00 00 e0 fb 60 00 00 00 00 00 00 00 ff 01 00 00
> > 
> > [2] for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online;
> > done
> > [3] for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online;
> > done
> > 
> > Thanks,
> > -- Dexuan
> 
> (+ the linux-pci list)
> 
> It turns out that adding "intremap=off" can work around the issue!
> 
> The root cause is still not clear yet. I don't know why Windows is good here.

The card is stuck in the FW, maybe Saeed knows why. I tried your
scenario and it worked for me.

Thanks

> 
> Thanks,
> Dexuan
> 

Re: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Saeed Mahameed]

On Sun, 2021-07-18 at 12:12 +0300, Leon Romanovsky wrote:
> On Thu, Jul 15, 2021 at 01:11:55AM +0000, Dexuan Cui wrote:
> > > From: Dexuan Cui
> > > Sent: Wednesday, July 14, 2021 5:39 PM
> > > To: netdev@vger.kernel.org; x86@kernel.org
> > > Cc: Haiyang Zhang <haiyangz@microsoft.com>;
> > > linux-kernel@vger.kernel.org
> > > Subject: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8
> > > 
> > > Hi all,
> > > I'm seeing a strange "no MSI-X interrupt" issue with the Mellanox
> > > NIC
> > > driver on a physical Linux host [1], if I only enable part of the
> > > CPUs.
> > > 
> > > The physical host has 104 logical processors (2 sockets, and each
> > > socket
> > > has 26 cores with HT enabled). By default, the Mellanox driver
> > > works fine
> > > when Linux boots up.
> > > 
> > > If I only use 1, 2, 32, 64, 96 processors by the Linux kernel
> > > parameter
> > > "maxcpus=X" or "nr_cpus=X", everthing still works fine.
> > > 
> > > However, if the Linux host OS only uses 4, 8 or 16 processors, the
> > > mlx5_core driver fails to load as it can not receive interrupt when
> > > creating EQ (maxcpus=8 or 16), or the driver can load but it
> > > reports a
> > > timeout error when I try to bring the NIC up (maxcpus=4). This
> > > issue is
> > > a 100% repro.
> > > 
> > > For example, with "maxcpus=8", I get the below timeout error when
> > > trying
> > > to load mlx5_core:
> > > 
> > > # modprobe mlx5_core
> > > [ 1475.716688] mlx5_core 0000:d8:00.0: firmware version: 16.25.8352
> > > [ 1475.722742] mlx5_core 0000:d8:00.0: 126.016 Gb/s available PCIe
> > > bandwidth (8.0 GT/s PCIe x16 link)
> > > [ 1475.991398] mlx5_core 0000:d8:00.0: E-Switch: Total vports 2,
> > > per vport:
> > > max uc(1024) max mc(16384)
> > > 
> > > [ 1537.020001] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid
> > > 1416):
> > > Recovered 1 EQEs on cmd_eq
> > > [ 1537.028969] mlx5_core 0000:d8:00.0:
> > > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
> > > CREATE_EQ(0x301)
> > > recovered after timeout
> > > [ 1598.460003] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid
> > > 1416):
> > > Recovered 1 EQEs on cmd_eq
> > > [ 1598.468978] mlx5_core 0000:d8:00.0:
> > > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
> > > CREATE_EQ(0x301)
> > > recovered after timeout
> > > [ 1659.900010] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid
> > > 1416):
> > > Recovered 1 EQEs on cmd_eq
> > > [ 1659.908987] mlx5_core 0000:d8:00.0:
> > > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
> > > CREATE_EQ(0x301)
> > > recovered after timeout
> > > [ 1721.340006] mlx5_core 0000:d8:00.0: mlx5_cmd_eq_recover:245:(pid
> > > 1416):
> > > Recovered 1 EQEs on cmd_eq
> > > [ 1721.348989] mlx5_core 0000:d8:00.0:
> > > wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
> > > CREATE_EQ(0x301)
> > > recovered after timeout
> > > 
> > > When this happens, the mlx5_core driver is stuck with the below
> > > call-trace, waiting for some interrupt:
> > > 
> > > # ps aux |grep modprobe
> > > root        1416  0.0  0.0  11024  1472 ttyS0    D+   08:08   0:00
> > > modprobe mlx5_core
> > > root        1480  0.0  0.0   6440   736 pts/0    S+   08:15   0:00
> > > grep --color=auto modprobe
> > > 
> > > # cat /proc/1416/stack
> > > [<0>] cmd_exec+0x8a7/0x9b0 [mlx5_core]
> > > [<0>] mlx5_cmd_exec+0x24/0x50 [mlx5_core]
> > > [<0>] create_map_eq+0x2a6/0x380 [mlx5_core]
> > > [<0>] mlx5_eq_table_create+0x504/0x710 [mlx5_core]
> > > [<0>] mlx5_load+0x52/0x130 [mlx5_core]
> > > [<0>] mlx5_init_one+0x1cc/0x250 [mlx5_core]
> > > [<0>] probe_one+0x1d3/0x2a0 [mlx5_core]
> > > [<0>] local_pci_probe+0x45/0x80
> > > [<0>] pci_device_probe+0x10f/0x1c0
> > > [<0>] really_probe+0x1c1/0x3b0
> > > [<0>] __driver_probe_device+0x109/0x180
> > > [<0>] driver_probe_device+0x23/0xa0
> > > [<0>] __driver_attach+0xbd/0x160
> > > [<0>] bus_for_each_dev+0x7c/0xc0
> > > [<0>] driver_attach+0x1e/0x20
> > > [<0>] bus_add_driver+0x152/0x1f0
> > > [<0>] driver_register+0x74/0xd0
> > > [<0>] __pci_register_driver+0x68/0x70
> > > [<0>] init+0x6b/0x1000 [mlx5_core]
> > > [<0>] do_one_initcall+0x46/0x1d0
> > > [<0>] do_init_module+0x62/0x250
> > > [<0>] load_module+0x2503/0x2730
> > > [<0>] __do_sys_finit_module+0xbf/0x120
> > > [<0>] __x64_sys_finit_module+0x1a/0x20
> > > [<0>] do_syscall_64+0x38/0xc0
> > > [<0>] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > > 
> > > To make the issue even weirder, when the issue happens (e.g. when
> > > Linux
> > > only uses 8 processors), if I manually bring CPU #8~#31 online [2]
> > > and
> > > then bring them offline [3], the Mellanox driver will work fine!
> > > 
> > > This is a x86-64 host. Is it possibe that the IOMMU Interrrupt
> > > Remapping
> > > is not proprely set up with maxcpus=4, 8 and 16?
> > > 
> > > The above tests were done with the recent Linux v5.14-rc1 kernel. I
> > > also
> > > tried Ubuntu 20.04's kernel "5.4.0-77-generic", and the Mellanox
> > > driver
> > > exhibits exactly the same issue.
> > > 
> > > I have Linux/Windows dual-boot on this physical machine, and
> > > Windows
> > > doesn't have the issue when I let it only use 4, 8 and 16
> > > processors.
> > > So this looks like somehow the issue is specific to Linux.
> > > 
> > > Can someone please shed some light on this strange issue? I'm ready
> > > to provide more logs if needed. Thanks!
> > > 
> > > PS, the physical machine has 4 NVMe controllers and 4 Broadcom
> > > NICs,
> > > which are not affected by maxcpus=4, 8, and 16.
> > > 
> > > [1] This is the 'lspci' output of the Mellanox NIC:
> > > d8:00.0 Ethernet controller: Mellanox Technologies MT27800 Family
> > > [ConnectX-5]
> > >         Subsystem: Mellanox Technologies MT27800 Family [ConnectX-
> > > 5]
> > >         Flags: bus master, fast devsel, latency 0, IRQ 33, NUMA
> > > node 1
> > >         Memory at f8000000 (64-bit, prefetchable) [size=32M]
> > >         Expansion ROM at fbe00000 [disabled] [size=1M]
> > >         Capabilities: [60] Express Endpoint, MSI 00
> > >         Capabilities: [48] Vital Product Data
> > >         Capabilities: [9c] MSI-X: Enable+ Count=64 Masked-
> > >         Capabilities: [c0] Vendor Specific Information: Len=18 <?>
> > >         Capabilities: [40] Power Management version 3
> > >         Capabilities: [100] Advanced Error Reporting
> > >         Capabilities: [150] Alternative Routing-ID Interpretation
> > > (ARI)
> > >         Capabilities: [180] Single Root I/O Virtualization (SR-IOV)
> > >         Capabilities: [1c0] Secondary PCI Express
> > >         Kernel driver in use: mlx5_core
> > >         Kernel modules: mlx5_core
> > > 00: b3 15 17 10 46 05 10 00 00 00 00 02 08 00 00 00
> > > 10: 0c 00 00 f8 00 00 00 00 00 00 00 00 00 00 00 00
> > > 20: 00 00 00 00 00 00 00 00 00 00 00 00 b3 15 80 00
> > > 30: 00 00 e0 fb 60 00 00 00 00 00 00 00 ff 01 00 00
> > > 
> > > [2] for i in `seq 8 31`;  do echo 1 > 
> > > /sys/devices/system/cpu/cpu$i/online;
> > > done
> > > [3] for i in `seq 8 31`;  do echo 0 > 
> > > /sys/devices/system/cpu/cpu$i/online;
> > > done
> > > 
> > > Thanks,
> > > -- Dexuan
> > 
> > (+ the linux-pci list)
> > 
> > It turns out that adding "intremap=off" can work around the issue!
> > 
> > The root cause is still not clear yet. I don't know why Windows is
> > good here.
> 
> The card is stuck in the FW, maybe Saeed knows why. I tried your
> scenario and it worked for me.
> 
> Thanks

I don't think the FW is stuck since we see the cmd completion after
timeout, this means that the 1st interrupt from the device got lost.

"wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
CREATE_EQ(0x301) recovered after timeout"

the fact that this happens on  5.14 and 5.4 kernels and the issue is
worked around via bringing the cpus online, or disabling intremap,
means that there is something wrong with the interrupt remapping
mechanism, maybe the interrupt is being delivered on an offline cpu ? 
is this a qemu/VM guest or a bare metal host ?

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

> From: Saeed Mahameed <saeed@kernel.org>
> Sent: Monday, July 19, 2021 1:18 PM
> > > ...
> > > It turns out that adding "intremap=off" can work around the issue!
> > >
> > > The root cause is still not clear yet. I don't know why Windows is
> > > good here.
> >
> > The card is stuck in the FW, maybe Saeed knows why. I tried your
> > scenario and it worked for me.
> >
> > Thanks
> 
> I don't think the FW is stuck since we see the cmd completion after
> timeout, this means that the 1st interrupt from the device got lost.
> 
> "wait_func_handle_exec_timeout:1062:(pid 1416): cmd[0]:
> CREATE_EQ(0x301) recovered after timeout"
> 
> the fact that this happens on  5.14 and 5.4 kernels and the issue is
> worked around via bringing the cpus online, or disabling intremap,
> means that there is something wrong with the interrupt remapping
> mechanism, maybe the interrupt is being delivered on an offline cpu ?
> is this a qemu/VM guest or a bare metal host ?

Thanks for the replies! 

This is a bare metal x86-64 host with Intel CPUs. Yes, I believe the
issue is in the IOMMU Interrupt Remapping mechanism rather in the
NIC driver. I just don't understand why bringing the CPUs online and
offline can work around the issue. I'm trying to dump the IOMMU IR
table entries to look for any error. 

Thanks,
Dexuan

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Thomas Gleixner]

Dexuan,

On Mon, Jul 19 2021 at 20:33, Dexuan Cui wrote:
> This is a bare metal x86-64 host with Intel CPUs. Yes, I believe the
> issue is in the IOMMU Interrupt Remapping mechanism rather in the
> NIC driver. I just don't understand why bringing the CPUs online and
> offline can work around the issue. I'm trying to dump the IOMMU IR
> table entries to look for any error. 

can you please enable GENERIC_IRQ_DEBUGFS and provide the output of

cat /sys/kernel/debug/irq/irqs/$THENICIRQS

Thanks,

        tglx

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

> From: Thomas Gleixner <tglx@linutronix.de>
> Sent: Wednesday, July 21, 2021 2:17 PM
> To: Dexuan Cui <decui@microsoft.com>; Saeed Mahameed
> 
> On Mon, Jul 19 2021 at 20:33, Dexuan Cui wrote:
> > This is a bare metal x86-64 host with Intel CPUs. Yes, I believe the
> > issue is in the IOMMU Interrupt Remapping mechanism rather in the
> > NIC driver. I just don't understand why bringing the CPUs online and
> > offline can work around the issue. I'm trying to dump the IOMMU IR
> > table entries to look for any error.
> 
> can you please enable GENERIC_IRQ_DEBUGFS and provide the output of
> 
> cat /sys/kernel/debug/irq/irqs/$THENICIRQS
> 
> Thanks,
> 
>         tglx

Sorry for the late response! I checked the below sys file, and the output is
exactly the same in the good/bad cases -- in both cases, I use maxcpus=8;
the only difference in the good case is that I online and then offline CPU 8~31:
for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online; done
for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online; done

# cat /sys/kernel/debug/irq/irqs/209
handler:  handle_edge_irq
device:   0000:d8:00.0
status:   0x00004000
istate:   0x00000000
ddepth:   0
wdepth:   0
dstate:   0x35409200
            IRQD_ACTIVATED
            IRQD_IRQ_STARTED
            IRQD_SINGLE_TARGET
            IRQD_MOVE_PCNTXT
            IRQD_AFFINITY_SET
            IRQD_AFFINITY_ON_ACTIVATE
            IRQD_CAN_RESERVE
            IRQD_HANDLE_ENFORCE_IRQCTX
node:     1
affinity: 0-7
effectiv: 5
pending:
domain:  INTEL-IR-MSI-3-3
 hwirq:   0x6c00000
 chip:    IR-PCI-MSI
  flags:   0x30
             IRQCHIP_SKIP_SET_WAKE
             IRQCHIP_ONESHOT_SAFE
 parent:
    domain:  INTEL-IR-3
     hwirq:   0x20000
     chip:    INTEL-IR
      flags:   0x0
     parent:
        domain:  VECTOR
         hwirq:   0xd1
         chip:    APIC
          flags:   0x0
         Vector:    42
         Target:     5
         move_in_progress: 0
         is_managed:       0
         can_reserve:      1
         has_reserved:     0
         cleanup_pending:  0

Thanks,
Dexuan

RE: [5.14-rc1] mlx5_core receives no interrupts with maxcpus=8

[Dexuan Cui]

> From: Dexuan Cui
> Sent: Wednesday, August 18, 2021 2:08 PM
> 
> > From: Thomas Gleixner <tglx@linutronix.de>
> > Sent: Wednesday, July 21, 2021 2:17 PM
> > To: Dexuan Cui <decui@microsoft.com>; Saeed Mahameed
> >
> > On Mon, Jul 19 2021 at 20:33, Dexuan Cui wrote:
> > > This is a bare metal x86-64 host with Intel CPUs. Yes, I believe the
> > > issue is in the IOMMU Interrupt Remapping mechanism rather in the
> > > NIC driver. I just don't understand why bringing the CPUs online and
> > > offline can work around the issue. I'm trying to dump the IOMMU IR
> > > table entries to look for any error.
> >
> > can you please enable GENERIC_IRQ_DEBUGFS and provide the output of
> >
> > cat /sys/kernel/debug/irq/irqs/$THENICIRQS
> >
> > Thanks,
> >
> >         tglx
> 
> Sorry for the late response! I checked the below sys file, and the output is
> exactly the same in the good/bad cases -- in both cases, I use maxcpus=8;
> the only difference in the good case is that I online and then offline CPU 8~31:
> for i in `seq 8 31`;  do echo 1 >  /sys/devices/system/cpu/cpu$i/online; done
> for i in `seq 8 31`;  do echo 0 >  /sys/devices/system/cpu/cpu$i/online; done
> 
> # cat /sys/kernel/debug/irq/irqs/209
> ...

I tried the kernel parameter "intremap=nosid,no_x2apic_optout,nopost" but
it didn't help. Only "intremap=off" can work round the no interrupt issue.

When the no interrupt issue happens, irq 209's effective_affinity_list is 5.
I modified modify_irte() to print the irte->low, irte->high, and I also printed
the irte_index for irq 209, and they were all normal to me, and they were
exactly the same in the bad case and the good case -- it looks like, with
"intremap=on maxcpus=8", MSI-X on CPU5 can't work for the NIC device
(MSI-X on CPU5 works for other devices like a NVMe controller) , and somehow
"onlining and then offlining CPU 8~31" can "fix" the issue, which is really weird.

Thanks,
Dexuan