ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

Hi,

I am seeing this WARNING  event with iommu=off when booting a DL380 server with a  5.4.17 kernel.



[    7.292703] ehci-pci 0000:00:1a.0: swiotlb buffer is full (sz: 8 bytes), total 0 (slots), used 0 (slots)
[    7.309834] ehci-pci 0000:00:1a.0: overflow 0x0000000a1c8f9a60+8 of DMA mask ffffffff bus limit 0
[    7.325937] ------------[ cut here ]------------
[    7.326927] WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34 report_addr+0x7b/0x7f
[    7.326927] Modules linked in:
[    7.326927] CPU: 0 PID: 347 Comm: kworker/0:6 Not tainted 5.4.17-2013.el7uek.x86_64 #2
[    7.326927] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 10/21/2019
[    7.326927] Workqueue: usb_hub_wq hub_event
[    7.326927] RIP: 0010:report_addr+0x7b/0x7f
[    7.326927] Code: 59 be 4e 01 00 75 23 4c 8b 8f 78 02 00 00 48 89 d1 48 8d 55 f8 48 c7 c6 08 ff c3 b5 31 c0 c6 05 39 be 4e 01 01 e8 84 47 4d 00 <0f> 0b c9 c3 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 55
[    7.326927] RSP: 0000:ffffbcc186b179a8 EFLAGS: 00010246
[    7.326927] RAX: 0000000000000000 RBX: ffff936f1f9ef0b0 RCX: 0000000000000000
[    7.326927] RDX: 0000000000000001 RSI: 0000000000000086 RDI: 0000000000000246
[    7.326927] RBP: ffffbcc186b179b0 R08: 00000000000004b3 R09: 00000000000004b3
[    7.326927] R10: 0000000000000001 R11: 0000000000aaaaaa R12: 0000000000000008
[    7.326927] R13: 0000000000000c00 R14: ffff936f84430800 R15: ffff936f84434800
[    7.326927] FS:  0000000000000000(0000) GS:ffff936f57800000(0000) knlGS:0000000000000000
[    7.326927] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    7.326927] CR2: ffff937098201000 CR3: 0000000b96e0a001 CR4: 00000000003606f0
[    7.326927] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[    7.326927] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[    7.326927] Call Trace:
[    7.326927]  dma_direct_map_page+0xd7/0xe2
[    7.326927]  usb_hcd_map_urb_for_dma+0x506/0x64d
[    7.326927]  usb_hcd_submit_urb+0x364/0xbcc
[    7.326927]  ? dev_vprintk_emit+0x21c/0x242
[    7.326927]  usb_submit_urb.part.8+0x24c/0x564
[    7.326927]  usb_submit_urb+0x34/0x5e
[    7.326927]  usb_start_wait_urb+0x6e/0x16d
[    7.326927]  ? _cond_resched+0x19/0x2c
[    7.326927]  usb_control_msg+0xde/0x13f
[    7.326927]  hub_port_init+0x6fd/0xc61
[    7.326927]  hub_port_connect+0x16c/0xa04
[    7.326927]  port_event+0x208/0x7d4
[    7.326927]  ? __switch_to_asm+0x34/0x62
[    7.326927]  hub_event+0x234/0x3c3
[    7.326927]  ? __switch_to_asm+0x40/0x62
[    7.326927]  process_one_work+0x179/0x389
[    7.326927]  worker_thread+0x4f/0x3df
[    7.326927]  kthread+0x105/0x138
[    7.326927]  ? max_active_store+0x80/0x7c
[    7.326927]  ? kthread_bind+0x20/0x15
[    7.326927]  ret_from_fork+0x3e/0x49
[    7.326927] ---[ end trace 38bdc7707d62cfd7 ]—


The end result is this USB port is not configured when dma_direct_map_page() is called and it returns return DMA_MAPPING_ERROR;


When I boot the server with iommu=on I don’t see  this sequence :


[    7.245241] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    7.247303] ehci-pci: EHCI PCI platform driver
[    7.249348] ehci-pci 0000:00:1a.0: EHCI Host Controller
[    7.251175] ehci-pci 0000:00:1a.0: new USB bus registered, assigned bus number 1
[    7.253527] ehci-pci 0000:00:1a.0: debug port 2
[    7.258974] ehci-pci 0000:00:1a.0: cache line size of 64 is not supported
[    7.261222] ehci-pci 0000:00:1a.0: irq 18, io mem 0x9a501000
[    7.269345] ehci-pci 0000:00:1a.0: USB 2.0 started, EHCI 1.00
[    7.271297] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.06
[    7.273913] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    7.276300] usb usb1: Product: EHCI Host Controller
[    7.277854] usb usb1: Manufacturer: Linux 5.6.0-rc7.master.20200327.ol7.x86_64 ehci_hcd
[    7.280372] usb usb1: SerialNumber: 0000:00:1a.0
[    7.282019] hub 1-0:1.0: USB hub found
[    7.283339] hub 1-0:1.0: 2 ports detected
[    7.285464] ehci-pci 0000:00:1d.0: EHCI Host Controller
[    7.287229] ehci-pci 0000:00:1d.0: new USB bus registered, assigned bus number 2
[    7.289595] ehci-pci 0000:00:1d.0: debug port 2
[    7.294922] ehci-pci 0000:00:1d.0: cache line size of 64 is not supported
[    7.297113] ehci-pci 0000:00:1d.0: irq 18, io mem 0x9a500000
[    7.305345] ehci-pci 0000:00:1d.0: USB 2.0 started, EHCI 1.00
[    7.307273] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.06
[    7.309893] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    7.312172] usb usb2: Product: EHCI Host Controller
[    7.313721] usb usb2: Manufacturer: Linux 5.6.0-rc7.master.20200327.ol7.x86_64 ehci_hcd
[    7.316289] usb usb2: SerialNumber: 0000:00:1d.0
[    7.317913] hub 2-0:1.0: USB hub found
[    7.319219] hub 2-0:1.0: 2 ports detected


This is related to my previous question how the BCM devices export USB virtual keyboards and  mouse .

On an older kernel  5.3. flavor I am not seeing this behavior, and the usbhib devices  appear as expected :

lsusb -t
/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
    |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
    |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
    |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M


Has anyone seen this before ?

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Greg KH]

On Fri, Mar 27, 2020 at 11:11:33PM -0500, John Donnelly wrote:
> 
> Hi,
> 
> I am seeing this WARNING  event with iommu=off when booting a DL380 server with a  5.4.17 kernel.
> 
> 
> 
> [    7.292703] ehci-pci 0000:00:1a.0: swiotlb buffer is full (sz: 8 bytes), total 0 (slots), used 0 (slots)
> [    7.309834] ehci-pci 0000:00:1a.0: overflow 0x0000000a1c8f9a60+8 of DMA mask ffffffff bus limit 0
> [    7.325937] ------------[ cut here ]------------

So your system really wants the iommu enabled, I would stick with doing
that :)

thanks,

greg k-h

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Fri, 27 Mar 2020, John Donnelly wrote:

> Hi,
> 
> I am seeing this WARNING event with iommu=off when booting a DL380
> server with a 5.4.17 kernel.

> Has anyone seen this before ?

I suspect that the vast majority of users do not turn off their iommu.

Alan Stern

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Fri, 27 Mar 2020, John Donnelly wrote:

> Hi,
> 
> I am seeing this WARNING event with iommu=off when booting a DL380
> server with a 5.4.17 kernel.

...

> The end result is this USB port is not configured when
> dma_direct_map_page() is called and it returns return
> DMA_MAPPING_ERROR;
> 
> 
> When I boot the server with iommu=on I don’t see  this sequence :

...

> On an older kernel  5.3. flavor I am not seeing this behavior, and the usbhib devices  appear as expected :

I forgot to mention: Since you have one kernel where the WARNING occurs 
and one where it doesn't, you can use bisection to find the commit that 
was responsible for the change in behavior.  If you care to go to the 
trouble...

Alan Stern

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

On 3/28/20 10:37 AM, Alan Stern wrote:
> On Fri, 27 Mar 2020, John Donnelly wrote:
> 
>> Hi,
>>
>> I am seeing this WARNING event with iommu=off when booting a DL380
>> server with a 5.4.17 kernel.
> 
> ...
> 
>> The end result is this USB port is not configured when
>> dma_direct_map_page() is called and it returns return
>> DMA_MAPPING_ERROR;
>>
>>
>> When I boot the server with iommu=on I don’t see  this sequence :
> 
> ...
> 
>> On an older kernel  5.3. flavor I am not seeing this behavior, and the usbhib devices  appear as expected :
> 
> I forgot to mention: Since you have one kernel where the WARNING occurs
> and one where it doesn't, you can use bisection to find the commit that
> was responsible for the change in behavior.  If you care to go to the
> trouble...
> 
> Alan Stern
> 


Hi.


Yes that is the plan ! It may take awhile.




-- 
Thank You,
John

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

> On Mar 28, 2020, at 10:37 AM, Alan Stern <stern@rowland.harvard.edu> wrote:
> 
> On Fri, 27 Mar 2020, John Donnelly wrote:
> 
>> Hi,
>> 
>> I am seeing this WARNING event with iommu=off when booting a DL380
>> server with a 5.4.17 kernel.
> 
> ...
> 
>> The end result is this USB port is not configured when
>> dma_direct_map_page() is called and it returns return
>> DMA_MAPPING_ERROR;
>> 
>> 
>> When I boot the server with iommu=on I don’t see  this sequence :
> 
> ...
> 
>> On an older kernel  5.3. flavor I am not seeing this behavior, and the usbhib devices  appear as expected :
> 
> I forgot to mention: Since you have one kernel where the WARNING occurs 
> and one where it doesn't, you can use bisection to find the commit that 
> was responsible for the change in behavior.  If you care to go to the 
> trouble...
> 
> Alan Stern
> 

Hi,


I discovered this particular server doesn’t continue probing the ports behind BCM is due to iommu being on. 

With  “ iommu=on “  

USB Initialization stops after the  BCM "  3:1.0 hub with  2 ports detected” , but no additional probing is done to discover the other end-points behind 3:1.0 :


[    9.467008] hub 2-1:1.0: 8 ports detected
[    9.538361] usb 4-3: new high-speed USB device number 2 using xhci_hcd
[    9.564504] usb 4-3: New USB device found, idVendor=0424, idProduct=2660, bcdDevice= 8.01
[    9.580454] usb 4-3: New USB device strings: Mfr=0, Product=0,SerialNumber=0
[    9.596642] hub 4-3:1.0: USB hub found
[    9.611040] hub 4-3:1.0: 2 ports detected. 

   ** NO ADDITIONAL DISCOVERY ** 



2. With intel_iommu=off, the BCM ports are probed after " 3:1.0: 2 ports detected "  state: 

[    5.705072] usb 3-1: new full-speed USB device number 2 using uhci_hcd
[    5.772363] usb 4-3: new high-speed USB device number 2 using xhci_hcd
[    5.800528] usb 4-3: New USB device found, idVendor=0424, idProduct=2660,bcdDevice= 8.01
[    5.816439] usb 4-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    5.832298] hub 4-3:1.0: USB hub found
[    5.845786] hub 4-3:1.0: 2 ports detected. <----    AFTER THIS WE CONTINUE TO PROBE  
[    5.889503] usb 3-1: New USB device found, idVendor=03f0, idProduct=7029, bcdDevice= 0.02
[    5.905380] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    5.920997] usb 3-1: Product: Virtual Keyboard
[    5.934493] usb 3-1: Manufacturer: BMC


What prompts the discovery to look beyond : "hub 4-3:1.0: 2 ports detected. “  ? Could there some state that needs examined  before it continues ?  ( I’ve never dealt with USB before on Linux ) . 

The end result is the usbhid devices ( kdb and mouse ) are found :

/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
    |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
    |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
    |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M


Is there a way I can turn on debug messages for the usb driver(s) to increase verbosity during boot since these are build-in modules ?  

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Mon, 30 Mar 2020, John Donnelly wrote:

> Hi,
> 
> 
> I discovered this particular server doesn’t continue probing the
> ports behind BCM is due to iommu being on.
> 
> With  “ iommu=on “  
> 
> USB Initialization stops after the BCM "  3:1.0 hub with 2 ports
> detected” , but no additional probing is done to discover the other
> end-points behind 3:1.0 :
> 
> 
> [    9.467008] hub 2-1:1.0: 8 ports detected
> [    9.538361] usb 4-3: new high-speed USB device number 2 using xhci_hcd
> [    9.564504] usb 4-3: New USB device found, idVendor=0424, idProduct=2660, bcdDevice= 8.01
> [    9.580454] usb 4-3: New USB device strings: Mfr=0, Product=0,SerialNumber=0
> [    9.596642] hub 4-3:1.0: USB hub found
> [    9.611040] hub 4-3:1.0: 2 ports detected. 
> 
>    ** NO ADDITIONAL DISCOVERY ** 
> 
> 
> 
> 2. With intel_iommu=off, the BCM ports are probed after " 3:1.0: 2
> ports detected "  state:
> 
> [    5.705072] usb 3-1: new full-speed USB device number 2 using uhci_hcd
> [    5.772363] usb 4-3: new high-speed USB device number 2 using xhci_hcd
> [    5.800528] usb 4-3: New USB device found, idVendor=0424, idProduct=2660,bcdDevice= 8.01
> [    5.816439] usb 4-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> [    5.832298] hub 4-3:1.0: USB hub found
> [    5.845786] hub 4-3:1.0: 2 ports detected. <----    AFTER THIS WE CONTINUE TO PROBE  
> [    5.889503] usb 3-1: New USB device found, idVendor=03f0, idProduct=7029, bcdDevice= 0.02
> [    5.905380] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [    5.920997] usb 3-1: Product: Virtual Keyboard
> [    5.934493] usb 3-1: Manufacturer: BMC
> 
> 
> What prompts the discovery to look beyond : "hub 4-3:1.0: 2 ports
> detected. “ ? Could there some state that needs examined before it
> continues ?  ( I’ve never dealt with USB before on Linux ) .

Were there any differences between your two tests other than the iommu 
setting?

> The end result is the usbhid devices ( kdb and mouse ) are found :
> 
> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
>     |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
> 
> 
> Is there a way I can turn on debug messages for the usb driver(s) to
> increase verbosity during boot since these are build-in modules ?

You can turn on kernel debugging for USB during boot-up by manually
adding:

	dyndbg="module usbcore =p"

to the boot command line.  (See the file
Documentation/admin-guide/dynamic-debug-howto.rst in the kernel source
for an explanation.)  The debugging messages will then appear in the
output from the dmesg command.

It might be even more enlightening to collect a couple of usbmon
traces.  (See Documentation/usb/usbmon.rst.)  Here's what you should
do, first with iommu=on and then again with iommu=off.  After booting,
as root:

	echo 0 >/sys/bus/usb/devices/usb3/bConfigurationValue
	cat /sys/kernel/debug/usb/usbmon/3u >mon-on.txt &
	echo 1 >/sys/bus/usb/devices/usb3/bConfigurationValue
	fg
	... wait a few seconds ...
	^C

For the iommu=off test, replace the "mon-on.txt" with "mon-off.txt"
(this is the name of the file where the usbmon trace will be stored --
you can use other names if you want).  Then attach the two trace
files to your next email message.

Alan Stern

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

> On Mar 30, 2020, at 2:41 PM, Alan Stern <stern@rowland.harvard.edu> wrote:
> 
> On Mon, 30 Mar 2020, John Donnelly wrote:
> 
>> Hi,
>> 
>> 
>> I discovered this particular server doesn’t continue probing the
>> ports behind BCM is due to iommu being on.
>> 
>> With  “ iommu=on “  
>> 
>> USB Initialization stops after the BCM "  3:1.0 hub with 2 ports
>> detected” , but no additional probing is done to discover the other
>> end-points behind 3:1.0 :
>> 
>> 
>> [    9.467008] hub 2-1:1.0: 8 ports detected
>> [    9.538361] usb 4-3: new high-speed USB device number 2 using xhci_hcd
>> [    9.564504] usb 4-3: New USB device found, idVendor=0424, idProduct=2660, bcdDevice= 8.01
>> [    9.580454] usb 4-3: New USB device strings: Mfr=0, Product=0,SerialNumber=0
>> [    9.596642] hub 4-3:1.0: USB hub found
>> [    9.611040] hub 4-3:1.0: 2 ports detected. 
>> 
>>   ** NO ADDITIONAL DISCOVERY ** 
>> 
>> 
>> 
>> 2. With intel_iommu=off, the BCM ports are probed after " 3:1.0: 2
>> ports detected "  state:
>> 
>> [    5.705072] usb 3-1: new full-speed USB device number 2 using uhci_hcd
>> [    5.772363] usb 4-3: new high-speed USB device number 2 using xhci_hcd
>> [    5.800528] usb 4-3: New USB device found, idVendor=0424, idProduct=2660,bcdDevice= 8.01
>> [    5.816439] usb 4-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
>> [    5.832298] hub 4-3:1.0: USB hub found
>> [    5.845786] hub 4-3:1.0: 2 ports detected. <----    AFTER THIS WE CONTINUE TO PROBE  
>> [    5.889503] usb 3-1: New USB device found, idVendor=03f0, idProduct=7029, bcdDevice= 0.02
>> [    5.905380] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
>> [    5.920997] usb 3-1: Product: Virtual Keyboard
>> [    5.934493] usb 3-1: Manufacturer: BMC
>> 
>> 
>> What prompts the discovery to look beyond : "hub 4-3:1.0: 2 ports
>> detected. “ ? Could there some state that needs examined before it
>> continues ?  ( I’ve never dealt with USB before on Linux ) .
> 
> Were there any differences between your two tests other than the iommu 
> setting?

   No ! 


> 
>> The end result is the usbhid devices ( kdb and mouse ) are found :
>> 
>> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>    |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>>    |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
>>    |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M
>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>> 
>> 
>> Is there a way I can turn on debug messages for the usb driver(s) to
>> increase verbosity during boot since these are build-in modules ?
> 
> You can turn on kernel debugging for USB during boot-up by manually
> adding:
> 
> 	dyndbg="module usbcore =p"
> 
> to the boot command line.  (See the file
> Documentation/admin-guide/dynamic-debug-howto.rst in the kernel source
> for an explanation.)  The debugging messages will then appear in the
> output from the dmesg command.
> 
> It might be even more enlightening to collect a couple of usbmon
> traces.  (See Documentation/usb/usbmon.rst.)  Here's what you should
> do, first with iommu=on and then again with iommu=off.  After booting,
> as root:
> 
> 	echo 0 >/sys/bus/usb/devices/usb3/bConfigurationValue
> 	cat /sys/kernel/debug/usb/usbmon/3u >mon-on.txt &
> 	echo 1 >/sys/bus/usb/devices/usb3/bConfigurationValue
> 	fg
> 	... wait a few seconds ...
> 	^C
> 
> For the iommu=off test, replace the "mon-on.txt" with "mon-off.txt"
> (this is the name of the file where the usbmon trace will be stored --
> you can use other names if you want).  Then attach the two trace
> files to your next email message.
> 
> Alan Stern
> 

  Thanks for the hints !    I will probe around more !  

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

On 3/30/20 3:11 PM, John Donnelly wrote:

   See below
> 
> 
>> On Mar 30, 2020, at 2:41 PM, Alan Stern <stern@rowland.harvard.edu> wrote:
>>
>> On Mon, 30 Mar 2020, John Donnelly wrote:
>>
>>> Hi,
>>>
>>>
>>> I discovered this particular server doesn’t continue probing the
>>> ports behind BCM is due to iommu being on.
>>>
>>> With  “ iommu=on “
>>>
>>> USB Initialization stops after the BCM "  3:1.0 hub with 2 ports
>>> detected” , but no additional probing is done to discover the other
>>> end-points behind 3:1.0 :
>>>
>>>
>>> [    9.467008] hub 2-1:1.0: 8 ports detected
>>> [    9.538361] usb 4-3: new high-speed USB device number 2 using xhci_hcd
>>> [    9.564504] usb 4-3: New USB device found, idVendor=0424, idProduct=2660, bcdDevice= 8.01
>>> [    9.580454] usb 4-3: New USB device strings: Mfr=0, Product=0,SerialNumber=0
>>> [    9.596642] hub 4-3:1.0: USB hub found
>>> [    9.611040] hub 4-3:1.0: 2 ports detected.
>>>
>>>    ** NO ADDITIONAL DISCOVERY **
>>>
>>>
>>>
>>> 2. With intel_iommu=off, the BCM ports are probed after " 3:1.0: 2
>>> ports detected "  state:
>>>
>>> [    5.705072] usb 3-1: new full-speed USB device number 2 using uhci_hcd
>>> [    5.772363] usb 4-3: new high-speed USB device number 2 using xhci_hcd
>>> [    5.800528] usb 4-3: New USB device found, idVendor=0424, idProduct=2660,bcdDevice= 8.01
>>> [    5.816439] usb 4-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
>>> [    5.832298] hub 4-3:1.0: USB hub found
>>> [    5.845786] hub 4-3:1.0: 2 ports detected. <----    AFTER THIS WE CONTINUE TO PROBE
>>> [    5.889503] usb 3-1: New USB device found, idVendor=03f0, idProduct=7029, bcdDevice= 0.02
>>> [    5.905380] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
>>> [    5.920997] usb 3-1: Product: Virtual Keyboard
>>> [    5.934493] usb 3-1: Manufacturer: BMC
>>>
>>>
>>> What prompts the discovery to look beyond : "hub 4-3:1.0: 2 ports
>>> detected. “ ? Could there some state that needs examined before it
>>> continues ?  ( I’ve never dealt with USB before on Linux ) .
>>
>> Were there any differences between your two tests other than the iommu
>> setting?
> 
>     No !
> 
> 
>>
>>> The end result is the usbhid devices ( kdb and mouse ) are found :
>>>
>>> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>>>     |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
>>>     |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M
>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>
>>>
>>> Is there a way I can turn on debug messages for the usb driver(s) to
>>> increase verbosity during boot since these are build-in modules ?
>>
>> You can turn on kernel debugging for USB during boot-up by manually
>> adding:
>>
>> 	dyndbg="module usbcore =p"
>>
>> to the boot command line.  (See the file
>> Documentation/admin-guide/dynamic-debug-howto.rst in the kernel source
>> for an explanation.)  The debugging messages will then appear in the
>> output from the dmesg command.
>>
>> It might be even more enlightening to collect a couple of usbmon
>> traces.  (See Documentation/usb/usbmon.rst.)  Here's what you should
>> do, first with iommu=on and then again with iommu=off.  After booting,
>> as root:
>>
>> 	echo 0 >/sys/bus/usb/devices/usb3/bConfigurationValue
>> 	cat /sys/kernel/debug/usb/usbmon/3u >mon-on.txt &
>> 	echo 1 >/sys/bus/usb/devices/usb3/bConfigurationValue
>> 	fg
>> 	... wait a few seconds ...
>> 	^C
>>
>> For the iommu=off test, replace the "mon-on.txt" with "mon-off.txt"
>> (this is the name of the file where the usbmon trace will be stored --
>> you can use other names if you want).  Then attach the two trace
>> files to your next email message.
>>
>> Alan Stern
>>
> 
>    Thanks for the hints !    I will probe around more !
> 
> 

The debug method produces the following:

iommu=on  ( no BCM is discovered )

[    9.911027] hub 4-0:1.0: state 7 ports 6 chg 0000 evt 0000
[    9.923028] usb 3-3: new high-speed USB device number 2 using xhci_hcd
[    9.950106] In hub_port_connect .. init
[    9.963879] usb 3-3: udev 2, busnum 3, minor = 257
[    9.963882] usb 3-3: New USB device found, idVendor=0424, 
idProduct=2660, bcdDevice= 8.01
[    9.978980] usb 3-3: New USB device strings: Mfr=0, Product=0, 
SerialNumber=0
[    9.994524] usb 3-3: usb_probe_device
[    9.994527] usb 3-3: configuration #1 chosen from 1 choice
[    9.994790] usb 3-3: adding 3-3:1.0 (config #1, interface 0)
[    9.994826] hub 3-3:1.0: usb_probe_interface
[    9.994828] hub 3-3:1.0: usb_probe_interface - got id
[    9.994831] hub 3-3:1.0: USB hub found
[   10.008224] hub 3-3:1.0: 2 ports detected
[   10.021669] hub 3-3:1.0: compound device; port removable status: FR
[   10.021671] hub 3-3:1.0: individual port power switching
[   10.021672] hub 3-3:1.0: individual port over-current protection
[   10.021674] hub 3-3:1.0: Single TT
[   10.021676] hub 3-3:1.0: TT requires at most 8 FS bit times (666 ns)
[   10.021678] hub 3-3:1.0: power on to power good time: 100ms
[   10.021753] hub 3-3:1.0: local power source is good
[   10.021872] hub 3-3:1.0: enabling power on all ports
[   10.022120] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0000
[   10.127115] hub 3-3:1.0: state 7 ports 2 chg 0000 evt 0000
[   10.327902] i8042: Can't read CTR while initializing i8042


Produces this configuration without the BCM devices :


lsusb -t
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M



BCM is discovered  intel_iommu=off :


[    8.947539] usb 4-3: adding 4-3:1.0 (config #1, interface 0)
[    8.947569] hub 4-3:1.0: usb_probe_interface
[    8.947571] hub 4-3:1.0: usb_probe_interface - got id
[    8.947574] hub 4-3:1.0: USB hub found
[    8.960496] usb 3-1: skipped 1 descriptor after interface
[    8.960499] usb 3-1: skipped 1 descriptor after interface
[    8.960562] hub 4-3:1.0: 2 ports detected
[    8.974067] usb 3-1: default language 0x0409
[    8.974074] hub 4-3:1.0: compound device; port removable status: FR
[    8.974075] hub 4-3:1.0: individual port power switching
[    8.974077] hub 4-3:1.0: individual port over-current protection
[    8.974079] hub 4-3:1.0: Single TT
[    8.974081] hub 4-3:1.0: TT requires at most 8 FS bit times (666 ns)
[    8.974083] hub 4-3:1.0: power on to power good time: 100ms
[    8.974157] hub 4-3:1.0: local power source is good
[    8.974259] hub 4-3:1.0: enabling power on all ports
[    8.979469] usb 3-1: udev 2, busnum 3, minor = 257
[    8.979473] usb 3-1: New USB device found, idVendor=03f0, 
idProduct=7029, bcdDevice= 0.02
[    8.994797] usb 3-1: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
[    9.010633] usb 3-1: Product: Virtual Keyboard
[    9.024416] usb 3-1: Manufacturer: BMC
[    9.037858] usb 3-1: usb_probe_device
[    9.037860] usb 3-1: configuration #1 chosen from 1 choice
[    9.039418] usb 3-1: adding 3-1:1.0 (config #1, interface 0)
[    9.041507] usb 3-1: adding 3-1:1.1 (config #1, interface 1)
[    9.076272] hub 4-3:1.0: state 7 ports 2 chg 0000 evt 0000

I am not accustomed to looking the USB Bus.port.dev mappings , obviously 
with BCM discovered there are 05 Bus instead of 4 .

/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
     |__ Port 1: Dev 2, If 0, Class=Human Interface Device, 
Driver=usbhid, 12M
     |__ Port 1: Dev 2, If 1, Class=Human Interface Device, 
Driver=usbhid, 12M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M


Here are the pci mappings:

[    6.381615] input: BMC Virtual Keyboard  as 
/devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.0/0003:03F0:7029.0001/input/input1
[    6.463638] hid-generic 0003:03F0:7029.0001: input,hidraw0: USB HID 
v1.01 Keyboard [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input0
[    6.496589] input: BMC Virtual Keyboard  as 
/devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.1/0003:03F0:7029.0002/input/input2
[    6.529449] hid-generic 0003:03F0:7029.0002: input,hidraw1: USB HID 
v1.01 Mouse [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input1
[    6.563139] usbcore: registered new interface driver usbhid
[    6.580222] usbhid: USB HID core driver



The last activity done seen on both traces is :

     "  enabling power on all ports  "

Is this when the BCM discovery is suppose to  occur ? In the function 
example is when the udev appears:

    usb 3-1: udev 2, busnum 3, minor = 257


-- 
Thank You,
John

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Mon, 30 Mar 2020, John Donnelly wrote:

> The debug method produces the following:
> 
> iommu=on  ( no BCM is discovered )
> 
> [    9.911027] hub 4-0:1.0: state 7 ports 6 chg 0000 evt 0000
> [    9.923028] usb 3-3: new high-speed USB device number 2 using xhci_hcd
> [    9.950106] In hub_port_connect .. init
> [    9.963879] usb 3-3: udev 2, busnum 3, minor = 257
> [    9.963882] usb 3-3: New USB device found, idVendor=0424, 
> idProduct=2660, bcdDevice= 8.01
> [    9.978980] usb 3-3: New USB device strings: Mfr=0, Product=0, 
> SerialNumber=0
> [    9.994524] usb 3-3: usb_probe_device
> [    9.994527] usb 3-3: configuration #1 chosen from 1 choice
> [    9.994790] usb 3-3: adding 3-3:1.0 (config #1, interface 0)
> [    9.994826] hub 3-3:1.0: usb_probe_interface
> [    9.994828] hub 3-3:1.0: usb_probe_interface - got id
> [    9.994831] hub 3-3:1.0: USB hub found
> [   10.008224] hub 3-3:1.0: 2 ports detected
> [   10.021669] hub 3-3:1.0: compound device; port removable status: FR
> [   10.021671] hub 3-3:1.0: individual port power switching
> [   10.021672] hub 3-3:1.0: individual port over-current protection
> [   10.021674] hub 3-3:1.0: Single TT
> [   10.021676] hub 3-3:1.0: TT requires at most 8 FS bit times (666 ns)
> [   10.021678] hub 3-3:1.0: power on to power good time: 100ms
> [   10.021753] hub 3-3:1.0: local power source is good
> [   10.021872] hub 3-3:1.0: enabling power on all ports
> [   10.022120] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0000
> [   10.127115] hub 3-3:1.0: state 7 ports 2 chg 0000 evt 0000
> [   10.327902] i8042: Can't read CTR while initializing i8042
> 
> 
> Produces this configuration without the BCM devices :
> 
> 
> lsusb -t
> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>      |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>      |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>      |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
> 
> 
> 
> BCM is discovered  intel_iommu=off :
> 
> 
> [    8.947539] usb 4-3: adding 4-3:1.0 (config #1, interface 0)
> [    8.947569] hub 4-3:1.0: usb_probe_interface
> [    8.947571] hub 4-3:1.0: usb_probe_interface - got id
> [    8.947574] hub 4-3:1.0: USB hub found
> [    8.960496] usb 3-1: skipped 1 descriptor after interface
> [    8.960499] usb 3-1: skipped 1 descriptor after interface
> [    8.960562] hub 4-3:1.0: 2 ports detected
> [    8.974067] usb 3-1: default language 0x0409
> [    8.974074] hub 4-3:1.0: compound device; port removable status: FR
> [    8.974075] hub 4-3:1.0: individual port power switching
> [    8.974077] hub 4-3:1.0: individual port over-current protection
> [    8.974079] hub 4-3:1.0: Single TT
> [    8.974081] hub 4-3:1.0: TT requires at most 8 FS bit times (666 ns)
> [    8.974083] hub 4-3:1.0: power on to power good time: 100ms
> [    8.974157] hub 4-3:1.0: local power source is good
> [    8.974259] hub 4-3:1.0: enabling power on all ports
> [    8.979469] usb 3-1: udev 2, busnum 3, minor = 257
> [    8.979473] usb 3-1: New USB device found, idVendor=03f0, 
> idProduct=7029, bcdDevice= 0.02
> [    8.994797] usb 3-1: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=0
> [    9.010633] usb 3-1: Product: Virtual Keyboard
> [    9.024416] usb 3-1: Manufacturer: BMC
> [    9.037858] usb 3-1: usb_probe_device
> [    9.037860] usb 3-1: configuration #1 chosen from 1 choice
> [    9.039418] usb 3-1: adding 3-1:1.0 (config #1, interface 0)
> [    9.041507] usb 3-1: adding 3-1:1.1 (config #1, interface 1)
> [    9.076272] hub 4-3:1.0: state 7 ports 2 chg 0000 evt 0000
> 
> I am not accustomed to looking the USB Bus.port.dev mappings , obviously 
> with BCM discovered there are 05 Bus instead of 4 .
> 
> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>      |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>      |__ Port 1: Dev 2, If 0, Class=Human Interface Device, 
> Driver=usbhid, 12M
>      |__ Port 1: Dev 2, If 1, Class=Human Interface Device, 
> Driver=usbhid, 12M
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>      |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>      |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M

It seems pretty clear that your system (or at least the BMC part)  
doesn't work as intended when the iommu is turned on.

> Here are the pci mappings:
> 
> [    6.381615] input: BMC Virtual Keyboard  as 
> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.0/0003:03F0:7029.0001/input/input1
> [    6.463638] hid-generic 0003:03F0:7029.0001: input,hidraw0: USB HID 
> v1.01 Keyboard [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input0
> [    6.496589] input: BMC Virtual Keyboard  as 
> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.1/0003:03F0:7029.0002/input/input2
> [    6.529449] hid-generic 0003:03F0:7029.0002: input,hidraw1: USB HID 
> v1.01 Mouse [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input1
> [    6.563139] usbcore: registered new interface driver usbhid
> [    6.580222] usbhid: USB HID core driver

I don't know why you call these "pci mappings".  They have nothing to 
do with PCI, and the last two lines don't talk about mappings at all.

> The last activity done seen on both traces is :
> 
>      "  enabling power on all ports  "

Why do you say this is the last activity seen on both traces?  In both
of the log extracts you included above there are plenty of lines
following those "enabling power" messages.

> Is this when the BCM discovery is suppose to  occur ? In the function 
> example is when the udev appears:
> 
>     usb 3-1: udev 2, busnum 3, minor = 257

The BCM discovery is supposed to occur at the time you see it in the 
second log extract above.

One thing I didn't notice before: With iommu=off, you get an entire new 
USB host controller and bus.  It is called bus 3, and neither it nor 
the 3-1 device (mouse and keyboard) is present when iommu=on.  In 
fact, by comparing the listings you can see that buses 4 and 5 (with 
iommu=off) are really the same as buses 3 and 4 (with iommu=on).

I'd say that your BMC does not work with iommu=on, and it is that
failure which causes these extra devices not to be discovered.  In
fact, they appear not be real physical devices at all, but rather
virtual devices created by the BMC firmware.

If you want to find out why the BMC doesn't work with iommu=on, you 
should ask the company that manufactured your computer's motherboard.  
They are probably the only people who know the answer.

Alan Stern

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

> On Mar 31, 2020, at 9:17 AM, Alan Stern <stern@rowland.harvard.edu> wrote:
> 
> On Mon, 30 Mar 2020, John Donnelly wrote:
> 
>> The debug method produces the following:
>> 
>> iommu=on  ( no BCM is discovered )
>> 
>> [    9.911027] hub 4-0:1.0: state 7 ports 6 chg 0000 evt 0000
>> [    9.923028] usb 3-3: new high-speed USB device number 2 using xhci_hcd
>> [    9.950106] In hub_port_connect .. init
>> [    9.963879] usb 3-3: udev 2, busnum 3, minor = 257
>> [    9.963882] usb 3-3: New USB device found, idVendor=0424, 
>> idProduct=2660, bcdDevice= 8.01
>> [    9.978980] usb 3-3: New USB device strings: Mfr=0, Product=0, 
>> SerialNumber=0
>> [    9.994524] usb 3-3: usb_probe_device
>> [    9.994527] usb 3-3: configuration #1 chosen from 1 choice
>> [    9.994790] usb 3-3: adding 3-3:1.0 (config #1, interface 0)
>> [    9.994826] hub 3-3:1.0: usb_probe_interface
>> [    9.994828] hub 3-3:1.0: usb_probe_interface - got id
>> [    9.994831] hub 3-3:1.0: USB hub found
>> [   10.008224] hub 3-3:1.0: 2 ports detected
>> [   10.021669] hub 3-3:1.0: compound device; port removable status: FR
>> [   10.021671] hub 3-3:1.0: individual port power switching
>> [   10.021672] hub 3-3:1.0: individual port over-current protection
>> [   10.021674] hub 3-3:1.0: Single TT
>> [   10.021676] hub 3-3:1.0: TT requires at most 8 FS bit times (666 ns)
>> [   10.021678] hub 3-3:1.0: power on to power good time: 100ms
>> [   10.021753] hub 3-3:1.0: local power source is good
>> [   10.021872] hub 3-3:1.0: enabling power on all ports
>> [   10.022120] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0000
>> [   10.127115] hub 3-3:1.0: state 7 ports 2 chg 0000 evt 0000
>> [   10.327902] i8042: Can't read CTR while initializing i8042
>> 
>> 
>> Produces this configuration without the BCM devices :
>> 
>> 
>> lsusb -t
>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
>> 
>> 
>> 
>> BCM is discovered  intel_iommu=off :
>> 
>> 
>> [    8.947539] usb 4-3: adding 4-3:1.0 (config #1, interface 0)
>> [    8.947569] hub 4-3:1.0: usb_probe_interface
>> [    8.947571] hub 4-3:1.0: usb_probe_interface - got id
>> [    8.947574] hub 4-3:1.0: USB hub found
>> [    8.960496] usb 3-1: skipped 1 descriptor after interface
>> [    8.960499] usb 3-1: skipped 1 descriptor after interface
>> [    8.960562] hub 4-3:1.0: 2 ports detected
>> [    8.974067] usb 3-1: default language 0x0409
>> [    8.974074] hub 4-3:1.0: compound device; port removable status: FR
>> [    8.974075] hub 4-3:1.0: individual port power switching
>> [    8.974077] hub 4-3:1.0: individual port over-current protection
>> [    8.974079] hub 4-3:1.0: Single TT
>> [    8.974081] hub 4-3:1.0: TT requires at most 8 FS bit times (666 ns)
>> [    8.974083] hub 4-3:1.0: power on to power good time: 100ms
>> [    8.974157] hub 4-3:1.0: local power source is good
>> [    8.974259] hub 4-3:1.0: enabling power on all ports
>> [    8.979469] usb 3-1: udev 2, busnum 3, minor = 257
>> [    8.979473] usb 3-1: New USB device found, idVendor=03f0, 
>> idProduct=7029, bcdDevice= 0.02
>> [    8.994797] usb 3-1: New USB device strings: Mfr=1, Product=2, 
>> SerialNumber=0
>> [    9.010633] usb 3-1: Product: Virtual Keyboard
>> [    9.024416] usb 3-1: Manufacturer: BMC
>> [    9.037858] usb 3-1: usb_probe_device
>> [    9.037860] usb 3-1: configuration #1 chosen from 1 choice
>> [    9.039418] usb 3-1: adding 3-1:1.0 (config #1, interface 0)
>> [    9.041507] usb 3-1: adding 3-1:1.1 (config #1, interface 1)
>> [    9.076272] hub 4-3:1.0: state 7 ports 2 chg 0000 evt 0000
>> 
>> I am not accustomed to looking the USB Bus.port.dev mappings , obviously 
>> with BCM discovered there are 05 Bus instead of 4 .
>> 
>> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>>     |__ Port 1: Dev 2, If 0, Class=Human Interface Device, 
>> Driver=usbhid, 12M
>>     |__ Port 1: Dev 2, If 1, Class=Human Interface Device, 
>> Driver=usbhid, 12M
>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
> 
> It seems pretty clear that your system (or at least the BMC part)  
> doesn't work as intended when the iommu is turned on.
> 
>> Here are the pci mappings:
>> 
>> [    6.381615] input: BMC Virtual Keyboard  as 
>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.0/0003:03F0:7029.0001/input/input1
>> [    6.463638] hid-generic 0003:03F0:7029.0001: input,hidraw0: USB HID 
>> v1.01 Keyboard [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input0
>> [    6.496589] input: BMC Virtual Keyboard  as 
>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.1/0003:03F0:7029.0002/input/input2
>> [    6.529449] hid-generic 0003:03F0:7029.0002: input,hidraw1: USB HID 
>> v1.01 Mouse [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input1
>> [    6.563139] usbcore: registered new interface driver usbhid
>> [    6.580222] usbhid: USB HID core driver
> 
> I don't know why you call these "pci mappings".  They have nothing to 
> do with PCI, and the last two lines don't talk about mappings at all.
> 
>> The last activity done seen on both traces is :
>> 
>>     "  enabling power on all ports  "
> 
> Why do you say this is the last activity seen on both traces?  In both
> of the log extracts you included above there are plenty of lines
> following those "enabling power" messages.
> 
>> Is this when the BCM discovery is suppose to  occur ? In the function 
>> example is when the udev appears:
>> 
>>    usb 3-1: udev 2, busnum 3, minor = 257
> 
> The BCM discovery is supposed to occur at the time you see it in the 
> second log extract above.
> 
> One thing I didn't notice before: With iommu=off, you get an entire new 
> USB host controller and bus.  It is called bus 3, and neither it nor 
> the 3-1 device (mouse and keyboard) is present when iommu=on.  In 
> fact, by comparing the listings you can see that buses 4 and 5 (with 
> iommu=off) are really the same as buses 3 and 4 (with iommu=on).
> 
> I'd say that your BMC does not work with iommu=on, and it is that
> failure which causes these extra devices not to be discovered.  In
> fact, they appear not be real physical devices at all, but rather
> virtual devices created by the BMC firmware.
> 
> If you want to find out why the BMC doesn't work with iommu=on, you 
> should ask the company that manufactured your computer's motherboard.  
> They are probably the only people who know the answer.
> 
> Alan Stern
> 


  Hi Alan.

Thank you for your assistance and insight.   I’ve tried  older kernels  (4.14, and 4.18 ) with iommu=on
and the BMC is recognized . This is obviously a regression somewhere  along the way.


Let me do some more bisecting.

Thank you,
JD

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

> On Mar 31, 2020, at 11:07 AM, John Donnelly <john.p.donnelly@oracle.com> wrote:
> 
> 
> 
>> On Mar 31, 2020, at 9:17 AM, Alan Stern <stern@rowland.harvard.edu> wrote:
>> 
>> On Mon, 30 Mar 2020, John Donnelly wrote:
>> 
>>> The debug method produces the following:
>>> 
>>> iommu=on  ( no BCM is discovered )
>>> 
>>> [    9.911027] hub 4-0:1.0: state 7 ports 6 chg 0000 evt 0000
>>> [    9.923028] usb 3-3: new high-speed USB device number 2 using xhci_hcd
>>> [    9.950106] In hub_port_connect .. init
>>> [    9.963879] usb 3-3: udev 2, busnum 3, minor = 257
>>> [    9.963882] usb 3-3: New USB device found, idVendor=0424, 
>>> idProduct=2660, bcdDevice= 8.01
>>> [    9.978980] usb 3-3: New USB device strings: Mfr=0, Product=0, 
>>> SerialNumber=0
>>> [    9.994524] usb 3-3: usb_probe_device
>>> [    9.994527] usb 3-3: configuration #1 chosen from 1 choice
>>> [    9.994790] usb 3-3: adding 3-3:1.0 (config #1, interface 0)
>>> [    9.994826] hub 3-3:1.0: usb_probe_interface
>>> [    9.994828] hub 3-3:1.0: usb_probe_interface - got id
>>> [    9.994831] hub 3-3:1.0: USB hub found
>>> [   10.008224] hub 3-3:1.0: 2 ports detected
>>> [   10.021669] hub 3-3:1.0: compound device; port removable status: FR
>>> [   10.021671] hub 3-3:1.0: individual port power switching
>>> [   10.021672] hub 3-3:1.0: individual port over-current protection
>>> [   10.021674] hub 3-3:1.0: Single TT
>>> [   10.021676] hub 3-3:1.0: TT requires at most 8 FS bit times (666 ns)
>>> [   10.021678] hub 3-3:1.0: power on to power good time: 100ms
>>> [   10.021753] hub 3-3:1.0: local power source is good
>>> [   10.021872] hub 3-3:1.0: enabling power on all ports
>>> [   10.022120] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0000
>>> [   10.127115] hub 3-3:1.0: state 7 ports 2 chg 0000 evt 0000
>>> [   10.327902] i8042: Can't read CTR while initializing i8042
>>> 
>>> 
>>> Produces this configuration without the BCM devices :
>>> 
>>> 
>>> lsusb -t
>>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>>    |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
>>> 
>>> 
>>> 
>>> BCM is discovered  intel_iommu=off :
>>> 
>>> 
>>> [    8.947539] usb 4-3: adding 4-3:1.0 (config #1, interface 0)
>>> [    8.947569] hub 4-3:1.0: usb_probe_interface
>>> [    8.947571] hub 4-3:1.0: usb_probe_interface - got id
>>> [    8.947574] hub 4-3:1.0: USB hub found
>>> [    8.960496] usb 3-1: skipped 1 descriptor after interface
>>> [    8.960499] usb 3-1: skipped 1 descriptor after interface
>>> [    8.960562] hub 4-3:1.0: 2 ports detected
>>> [    8.974067] usb 3-1: default language 0x0409
>>> [    8.974074] hub 4-3:1.0: compound device; port removable status: FR
>>> [    8.974075] hub 4-3:1.0: individual port power switching
>>> [    8.974077] hub 4-3:1.0: individual port over-current protection
>>> [    8.974079] hub 4-3:1.0: Single TT
>>> [    8.974081] hub 4-3:1.0: TT requires at most 8 FS bit times (666 ns)
>>> [    8.974083] hub 4-3:1.0: power on to power good time: 100ms
>>> [    8.974157] hub 4-3:1.0: local power source is good
>>> [    8.974259] hub 4-3:1.0: enabling power on all ports
>>> [    8.979469] usb 3-1: udev 2, busnum 3, minor = 257
>>> [    8.979473] usb 3-1: New USB device found, idVendor=03f0, 
>>> idProduct=7029, bcdDevice= 0.02
>>> [    8.994797] usb 3-1: New USB device strings: Mfr=1, Product=2, 
>>> SerialNumber=0
>>> [    9.010633] usb 3-1: Product: Virtual Keyboard
>>> [    9.024416] usb 3-1: Manufacturer: BMC
>>> [    9.037858] usb 3-1: usb_probe_device
>>> [    9.037860] usb 3-1: configuration #1 chosen from 1 choice
>>> [    9.039418] usb 3-1: adding 3-1:1.0 (config #1, interface 0)
>>> [    9.041507] usb 3-1: adding 3-1:1.1 (config #1, interface 1)
>>> [    9.076272] hub 4-3:1.0: state 7 ports 2 chg 0000 evt 0000
>>> 
>>> I am not accustomed to looking the USB Bus.port.dev mappings , obviously 
>>> with BCM discovered there are 05 Bus instead of 4 .
>>> 
>>> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>>    |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>>>    |__ Port 1: Dev 2, If 0, Class=Human Interface Device, 
>>> Driver=usbhid, 12M
>>>    |__ Port 1: Dev 2, If 1, Class=Human Interface Device, 
>>> Driver=usbhid, 12M
>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>>    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
>> 
>> It seems pretty clear that your system (or at least the BMC part)  
>> doesn't work as intended when the iommu is turned on.
>> 
>>> Here are the pci mappings:
>>> 
>>> [    6.381615] input: BMC Virtual Keyboard  as 
>>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.0/0003:03F0:7029.0001/input/input1
>>> [    6.463638] hid-generic 0003:03F0:7029.0001: input,hidraw0: USB HID 
>>> v1.01 Keyboard [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input0
>>> [    6.496589] input: BMC Virtual Keyboard  as 
>>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.1/0003:03F0:7029.0002/input/input2
>>> [    6.529449] hid-generic 0003:03F0:7029.0002: input,hidraw1: USB HID 
>>> v1.01 Mouse [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input1
>>> [    6.563139] usbcore: registered new interface driver usbhid
>>> [    6.580222] usbhid: USB HID core driver
>> 
>> I don't know why you call these "pci mappings".  They have nothing to 
>> do with PCI, and the last two lines don't talk about mappings at all.
>> 
>>> The last activity done seen on both traces is :
>>> 
>>>    "  enabling power on all ports  "
>> 
>> Why do you say this is the last activity seen on both traces?  In both
>> of the log extracts you included above there are plenty of lines
>> following those "enabling power" messages.
>> 
>>> Is this when the BCM discovery is suppose to  occur ? In the function 
>>> example is when the udev appears:
>>> 
>>>   usb 3-1: udev 2, busnum 3, minor = 257
>> 
>> The BCM discovery is supposed to occur at the time you see it in the 
>> second log extract above.
>> 
>> One thing I didn't notice before: With iommu=off, you get an entire new 
>> USB host controller and bus.  It is called bus 3, and neither it nor 
>> the 3-1 device (mouse and keyboard) is present when iommu=on.  In 
>> fact, by comparing the listings you can see that buses 4 and 5 (with 
>> iommu=off) are really the same as buses 3 and 4 (with iommu=on).
>> 
>> I'd say that your BMC does not work with iommu=on, and it is that
>> failure which causes these extra devices not to be discovered.  In
>> fact, they appear not be real physical devices at all, but rather
>> virtual devices created by the BMC firmware.
>> 
>> If you want to find out why the BMC doesn't work with iommu=on, you 
>> should ask the company that manufactured your computer's motherboard.  
>> They are probably the only people who know the answer.
>> 
>> Alan Stern
>> 
> 
> 
>  Hi Alan.
> 
> Thank you for your assistance and insight.   I’ve tried  older kernels  (4.14, and 4.18 ) with iommu=on
> and the BMC is recognized . This is obviously a regression somewhere  along the way.
> 
> 
> Let me do some more bisecting.
> 
> Thank you,
> JD
> 

Hi ,

 One more follow up question.

How does a X86  kernel know where to look for USB buses/control registers ?  I am aware PowerPC has a device-tree that is passed by reference from UBoot that contains known devices.

For the BCM device :

   Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M

Is there a corresponding register set I can examine ?

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Tue, 31 Mar 2020, John Donnelly wrote:

> Hi ,
> 
>  One more follow up question.
> 
> How does a X86 kernel know where to look for USB buses/control
> registers ?  I am aware PowerPC has a device-tree that is passed by
> reference from UBoot that contains known devices.

Some of the information comes from ACPI tables in the BIOS.  Other
parts of it come from the components on the motherboard (for example,
devices attached to a PCI bus can be discovered directly by the
system).

> For the BCM device :
> 
>    Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> 
> Is there a corresponding register set I can examine ?

Yes.  For example, you can look at the files under 
/sys/kernel/debug/usb/uhci/.  You can also use lspci and other related 
PCI utilities.

Alan Stern

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[John Donnelly]

Issue resolved - see below .


> On Mar 31, 2020, at 9:17 AM, Alan Stern <stern@rowland.harvard.edu> wrote:
> 
> On Mon, 30 Mar 2020, John Donnelly wrote:
> 
>> The debug method produces the following:
>> 
>> iommu=on  ( no BCM is discovered )
>> 
>> [    9.911027] hub 4-0:1.0: state 7 ports 6 chg 0000 evt 0000
>> [    9.923028] usb 3-3: new high-speed USB device number 2 using xhci_hcd
>> [    9.950106] In hub_port_connect .. init
>> [    9.963879] usb 3-3: udev 2, busnum 3, minor = 257
>> [    9.963882] usb 3-3: New USB device found, idVendor=0424, 
>> idProduct=2660, bcdDevice= 8.01
>> [    9.978980] usb 3-3: New USB device strings: Mfr=0, Product=0, 
>> SerialNumber=0
>> [    9.994524] usb 3-3: usb_probe_device
>> [    9.994527] usb 3-3: configuration #1 chosen from 1 choice
>> [    9.994790] usb 3-3: adding 3-3:1.0 (config #1, interface 0)
>> [    9.994826] hub 3-3:1.0: usb_probe_interface
>> [    9.994828] hub 3-3:1.0: usb_probe_interface - got id
>> [    9.994831] hub 3-3:1.0: USB hub found
>> [   10.008224] hub 3-3:1.0: 2 ports detected
>> [   10.021669] hub 3-3:1.0: compound device; port removable status: FR
>> [   10.021671] hub 3-3:1.0: individual port power switching
>> [   10.021672] hub 3-3:1.0: individual port over-current protection
>> [   10.021674] hub 3-3:1.0: Single TT
>> [   10.021676] hub 3-3:1.0: TT requires at most 8 FS bit times (666 ns)
>> [   10.021678] hub 3-3:1.0: power on to power good time: 100ms
>> [   10.021753] hub 3-3:1.0: local power source is good
>> [   10.021872] hub 3-3:1.0: enabling power on all ports
>> [   10.022120] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0000
>> [   10.127115] hub 3-3:1.0: state 7 ports 2 chg 0000 evt 0000
>> [   10.327902] i8042: Can't read CTR while initializing i8042
>> 
>> 
>> Produces this configuration without the BCM devices :
>> 
>> 
>> lsusb -t
>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
>> 
>> 
>> 
>> BCM is discovered  intel_iommu=off :
>> 
>> 
>> [    8.947539] usb 4-3: adding 4-3:1.0 (config #1, interface 0)
>> [    8.947569] hub 4-3:1.0: usb_probe_interface
>> [    8.947571] hub 4-3:1.0: usb_probe_interface - got id
>> [    8.947574] hub 4-3:1.0: USB hub found
>> [    8.960496] usb 3-1: skipped 1 descriptor after interface
>> [    8.960499] usb 3-1: skipped 1 descriptor after interface
>> [    8.960562] hub 4-3:1.0: 2 ports detected
>> [    8.974067] usb 3-1: default language 0x0409
>> [    8.974074] hub 4-3:1.0: compound device; port removable status: FR
>> [    8.974075] hub 4-3:1.0: individual port power switching
>> [    8.974077] hub 4-3:1.0: individual port over-current protection
>> [    8.974079] hub 4-3:1.0: Single TT
>> [    8.974081] hub 4-3:1.0: TT requires at most 8 FS bit times (666 ns)
>> [    8.974083] hub 4-3:1.0: power on to power good time: 100ms
>> [    8.974157] hub 4-3:1.0: local power source is good
>> [    8.974259] hub 4-3:1.0: enabling power on all ports
>> [    8.979469] usb 3-1: udev 2, busnum 3, minor = 257
>> [    8.979473] usb 3-1: New USB device found, idVendor=03f0, 
>> idProduct=7029, bcdDevice= 0.02
>> [    8.994797] usb 3-1: New USB device strings: Mfr=1, Product=2, 
>> SerialNumber=0
>> [    9.010633] usb 3-1: Product: Virtual Keyboard
>> [    9.024416] usb 3-1: Manufacturer: BMC
>> [    9.037858] usb 3-1: usb_probe_device
>> [    9.037860] usb 3-1: configuration #1 chosen from 1 choice
>> [    9.039418] usb 3-1: adding 3-1:1.0 (config #1, interface 0)
>> [    9.041507] usb 3-1: adding 3-1:1.1 (config #1, interface 1)
>> [    9.076272] hub 4-3:1.0: state 7 ports 2 chg 0000 evt 0000
>> 
>> I am not accustomed to looking the USB Bus.port.dev mappings , obviously 
>> with BCM discovered there are 05 Bus instead of 4 .
>> 
>> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
>> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
>>     |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
>> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>>     |__ Port 1: Dev 2, If 0, Class=Human Interface Device, 
>> Driver=usbhid, 12M
>>     |__ Port 1: Dev 2, If 1, Class=Human Interface Device, 
>> Driver=usbhid, 12M
>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
>>     |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
> 
> It seems pretty clear that your system (or at least the BMC part)  
> doesn't work as intended when the iommu is turned on.
> 
>> Here are the pci mappings:
>> 
>> [    6.381615] input: BMC Virtual Keyboard  as 
>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.0/0003:03F0:7029.0001/input/input1
>> [    6.463638] hid-generic 0003:03F0:7029.0001: input,hidraw0: USB HID 
>> v1.01 Keyboard [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input0
>> [    6.496589] input: BMC Virtual Keyboard  as 
>> /devices/pci0000:00/0000:00:1c.2/0000:01:00.4/usb3/3-1/3-1:1.1/0003:03F0:7029.0002/input/input2
>> [    6.529449] hid-generic 0003:03F0:7029.0002: input,hidraw1: USB HID 
>> v1.01 Mouse [BMC Virtual Keyboard ] on usb-0000:01:00.4-1/input1
>> [    6.563139] usbcore: registered new interface driver usbhid
>> [    6.580222] usbhid: USB HID core driver
> 
> I don't know why you call these "pci mappings".  They have nothing to 
> do with PCI, and the last two lines don't talk about mappings at all.
> 
>> The last activity done seen on both traces is :
>> 
>>     "  enabling power on all ports  "
> 
> Why do you say this is the last activity seen on both traces?  In both
> of the log extracts you included above there are plenty of lines
> following those "enabling power" messages.
> 
>> Is this when the BCM discovery is suppose to  occur ? In the function 
>> example is when the udev appears:
>> 
>>    usb 3-1: udev 2, busnum 3, minor = 257
> 
> The BCM discovery is supposed to occur at the time you see it in the 
> second log extract above.
> 
> One thing I didn't notice before: With iommu=off, you get an entire new 
> USB host controller and bus.  It is called bus 3, and neither it nor 
> the 3-1 device (mouse and keyboard) is present when iommu=on.  In 
> fact, by comparing the listings you can see that buses 4 and 5 (with 
> iommu=off) are really the same as buses 3 and 4 (with iommu=on).
> 
> I'd say that your BMC does not work with iommu=on, and it is that
> failure which causes these extra devices not to be discovered.  In
> fact, they appear not be real physical devices at all, but rather
> virtual devices created by the BMC firmware.
> 
> If you want to find out why the BMC doesn't work with iommu=on, you 
> should ask the company that manufactured your computer's motherboard.  
> They are probably the only people who know the answer.
> 
> Alan Stern
> 

This issue has been resolved in 5.6.0.rc1 ( and 5.6.0.rc6 ) with commit :

9235cb13d7d1 iommu/vt-d: Allow devices with RMRRs to use identity domain

When I applied this to 5.4.17 release I get the iLO USB hub properly enumerated and
the corresponding keyboard and mouse  ( when iommu=pt ) 



[    8.798927] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    8.812350] ohci-pci: OHCI PCI platform driver
[    8.824135] uhci_hcd: USB Universal Host Controller Interface driver
[    8.837210] uhci_hcd 0000:01:00.4: UHCI Host Controller
[    8.850133] uhci_hcd 0000:01:00.4: new USB bus registered, assigned bus number 3
[    8.863092] uhci_hcd 0000:01:00.4: detected 8 ports
[    8.875997] uhci_hcd 0000:01:00.4: port count misdetected? forcing to 2 ports
[    8.889987] uhci_hcd 0000:01:00.4: supports USB remote wakeup
[    8.890014] uhci_hcd 0000:01:00.4: irq 19, io base 0x00001300
[    8.903367] uhci_hcd 0000:01:00.4: DMAR: Setting identity map [0x791dc000 - 0x791ddfff]
[    8.916824] uhci_hcd 0000:01:00.4: DMAR: Setting identity map [0x791cb000 - 0x791dbfff]
[    8.930057] uhci_hcd 0000:01:00.4: DMAR: Setting identity map [0x791de000 - 0x791f3fff]
[    8.943069] uhci_hcd 0000:01:00.4: DMAR: Setting identity map [0x791f4000 - 0x791f7fff]


lsusb -t
/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/6p, 5000M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/15p, 480M
   |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/2p, 480M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
   |__ Port 1: Dev 2, If 0, Class=Human Interface Device, Driver=usbhid, 12M
   |__ Port 1: Dev 2, If 1, Class=Human Interface Device, Driver=usbhid, 12M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
   |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
   |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M

In researching this regression, I identified another defect on the HP servers that exists in both 
5.4.17 and 5.6.0.rc6 that the USB hub is not functional when iommu=off .


https://bugzilla.kernel.org/show_bug.cgi?id=207147

Re: ehci-pci : WARNING: CPU: 0 PID: 347 at kernel/dma/direct.c:34

[Alan Stern]

On Tue, 7 Apr 2020, John Donnelly wrote:

> Issue resolved - see below .

> This issue has been resolved in 5.6.0.rc1 ( and 5.6.0.rc6 ) with commit :
> 
> 9235cb13d7d1 iommu/vt-d: Allow devices with RMRRs to use identity domain
> 
> When I applied this to 5.4.17 release I get the iLO USB hub properly enumerated and
> the corresponding keyboard and mouse  ( when iommu=pt ) 

Okay, congratulations!

Alan Stern