Project

General

Profile

Actions

Bug #14623

closed

bhyve/xhci: Connecting device on port 1 failed

Added by Andy Fiddaman 4 months ago. Updated 4 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
bhyve
Start date:
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:

Description

When booting an illumos distribution under bhyve, and bhyve presents an emulated USB3 tablet device to the guest, the boot hangs, printing warning messages from the xhci driver. I confirmed this occurs with OmniOS, OpenIndiana, SmartOS and Tribblix guests.

The guest output is:

Loading unix...
Loading /platform/i86pc/amd64/boot_archive...
Loading /platform/i86pc/amd64/boot_archive.hash...
Booting...
OmniOS r151042 Version omnios-r151042-db746d6083 64-bit
Copyright (c) 2012-2017 OmniTI Computer Consulting, Inc.
Copyright (c) 2017-2022 OmniOS Community Edition (OmniOSce) Association.
WARNING: /pci@0,0/pci8086,1e31@1e,1 (xhci0): Connecting device on port 1 failed
WARNING: /pci@0,0/pci8086,1e31@1e,1 (xhci0): Connecting device on port 1 failed
WARNING: /pci@0,0/pci8086,1e31@1e,1 (xhci0): Connecting device on port 1 failed
WARNING: /pci@0,0/pci8086,1e31@1e,1 (xhci0): Connecting device on port 1 failed
WARNING: /pci@0,0/pci8086,1e31@1e,1 (xhci0): Connecting device on port 1 failed

and the warning message continues to be printed about once every two seconds.

The bhyve process outputs:

pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 2
pci_xhci: portregs_write to unpowered port 3
pci_xhci: portregs_write to unpowered port 4
pci_xhci: portregs_write to unpowered port 5
pci_xhci: portregs_write to unpowered port 6
pci_xhci: portregs_write to unpowered port 7
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 2
pci_xhci: portregs_write to unpowered port 2
pci_xhci: portregs_write to unpowered port 2
pci_xhci: portregs_write to unpowered port 2
pci_xhci: portregs_write to unpowered port 2
... elided ...
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs_write to unpowered port 1

and continues to print the last message over and over (port 1).

Here is the bhyve configuration I tested with. The relevant line is pci.0.30.1.slot.1.device=tablet

acpi_tables=false
memory.size=4G
x86.strictmsr=true
x86.vmexit_on_hlt=true
pci.0.0.0.device=hostbridge
pci.0.0.0.model=i440fx
pci.0.1.0.device=lpc
pci.0.4.0.device=nvme
pci.0.4.0.path=/dev/zvol/rdsk/rpool/test/root
pci.0.6.0.device=virtio-net-viona
pci.0.6.0.vnic=test0
pci.0.30.0.device=fbuf
pci.0.30.0.vga=off
pci.0.30.0.unix=/tmp/vm.vnc
pci.0.30.1.device=xhci
pci.0.30.1.slot.1.device=tablet
cpus=4
lpc.bootrom=/usr/share/bhyve/firmware/BHYVE.fd
lpc.com1.path=/dev/zconsole
name=test

Since other guests (Linux, Windows, FreeBSD) boot with this configuration, I'm assigning this issue to the driver category pending further analysis.

This appears similar to #8174 and may be a duplicate.


Related issues

Related to illumos gate - Bug #8174: VirtualBox xHCI: WARNING: /pci@0,0/pci8086,1e31@c (xhci0): Connecting device on port 1 failedNew2017-05-07

Actions
Actions #1

Updated by Andy Fiddaman 4 months ago

  • Related to Bug #8174: VirtualBox xHCI: WARNING: /pci@0,0/pci8086,1e31@c (xhci0): Connecting device on port 1 failed added
Actions #2

Updated by Andy Fiddaman 4 months ago

Putting bhyve's xhci emulation into debug mode produces lots of output, here is some edited content including showing the loop that we appear to drop into at the end:

pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: rtsregs read offset 0x18 -> 0xbf327328
pci_xhci: rtsregs read offset 0x1c -> 0x0
pci_xhci: runtime regs write offset 0x38: 0xbf327338
pci_xhci: runtime regs write offset 0x3c: 0x0
pci_xhci: erdp 0xbf327330, events cnt 0
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: doorbell write offset 0x0: 0x0
pci_xhci: cmd type 0x10, Trb0 x00000000bf329751 dwTrb2 x00000000 dwTrb3 x01014001, TRB_CYCLE 1/ccs 1
pci_xhci set_tr: new-tr x00000000bf329750, SCT 0 DCS 1
                 stream-id 0, slot 1, epid 1, C 1
pci_xhci set_tr first TRB:
pci_xhci: trb[@fffffc7f3f729750] type x00 RESERVED 0:x0000000000000000 2:x00000000 3:x00000000
pci_xhci: command 0x10 result: 0x1
pci_xhci: insert event 0[bf3262b0] 2[1000000] 3[1008401]
 erdp idx 15/seg 0, enq idx 15/seg 0, pcs 1
 (erdp=0xbf327330, erst=0xbf327240, tblsz=512, do_intr 1)
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: rtsregs read offset 0x18 -> 0xbf327338
pci_xhci: rtsregs read offset 0x1c -> 0x0
pci_xhci: runtime regs write offset 0x38: 0xbf327348
pci_xhci: runtime regs write offset 0x3c: 0x0
pci_xhci: erdp 0xbf327340, events cnt 0
pci_xhci: doorbell write offset 0x1: 0x1
pci_xhci doorbell slot 1 epid 1 stream 0
pci_xhci: get dev ctx, slot 1 devctx addr 00000000bf32a6c0
pci_xhci: device doorbell ep[1] 00000003 00400026 00000000bf329750 00000008
doorbell, ccs 0, trb ccs 0
pci_xhci: ring bf329750 trb[bf329750] EP 1 is RESERVED?
pci_xhci: portregs read offset 0x0 port 1 -> 0xe03
pci_xhci: portregs read offset 0x0 port 2 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 3 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 4 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 5 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 6 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 7 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 8 -> 0x2a0

>>> loader starts

Booting...
pci_xhci: hostop read offset 0x0 -> 0x1
pci_xhci: hostop write offset 0x0: 0x0
pci_xhci: hostop read offset 0x4 -> 0x9
OmniOS r151042 Version omnios-r151042-5b105d0fdc 64-bit
Copyright (c) 2012-2017 OmniTI Computer Consulting, Inc.
Copyright (c) 2017-2022 OmniOS Community Edition (OmniOSce) Association.
pci_xhci: hostcap read offset 0x0 -> 0x1000020
pci_xhci: hostcap read offset 0x18 -> 0xcc0
pci_xhci: hostcap read offset 0x14 -> 0x4a0
pci_xhci: hostcap read offset 0x0 -> 0x1000020
pci_xhci: hostcap read offset 0x4 -> 0x8000140
pci_xhci: hostcap read offset 0x8 -> 0x4
pci_xhci: hostcap read offset 0xc -> 0x0
pci_xhci: hostcap read offset 0x10 -> 0x3401281
pci_xhci: hostcap read offset 0x1c -> 0x11
pci_xhci: hostop read offset 0x8 -> 0x1
pci_xhci: xecp read offset 0x0 -> 0x2000402
pci_xhci: xecp read offset 0x0 -> 0x2000402
pci_xhci: xecp read offset 0x8 -> 0x405
pci_xhci: xecp read offset 0x0 -> 0x2000402
pci_xhci: xecp read offset 0x10 -> 0x3000002
pci_xhci: xecp read offset 0x10 -> 0x3000002
pci_xhci: xecp read offset 0x18 -> 0x401
pci_xhci: xecp read offset 0x0 -> 0x2000402
pci_xhci: xecp read offset 0x10 -> 0x3000002
pci_xhci: xecp read offset 0x0 -> 0x2000402
pci_xhci: xecp read offset 0x10 -> 0x3000002
pci_xhci: hostop read offset 0x0 -> 0x0
pci_xhci: hostop write offset 0x0: 0x0
pci_xhci: hostop read offset 0x4 -> 0x9
pci_xhci: hostop read offset 0x0 -> 0x0
pci_xhci: hostop write offset 0x0: 0x2
xhci reset unassigned slot (2)?
xhci reset unassigned slot (3)?
...
hci reset unassigned slot (64)?
pci_xhci: hostop read offset 0x0 -> 0x0
pci_xhci: hostop read offset 0x4 -> 0x9
pci_xhci: hostop read offset 0x38 -> 0x40
pci_xhci: hostop write offset 0x38: 0x40
pci_xhci: hostop write offset 0x30: 0x39c5d040
pci_xhci: hostop write offset 0x34: 0x1
pci_xhci: opregs dcbaap = 0x139c5d040 (vaddr 0xfffffc7fba05d040)
pci_xhci: hostop write offset 0x18: 0x39e1e001
pci_xhci: hostop write offset 0x1c: 0x1
pci_xhci: rtsregs read offset 0x8 -> 0x1
pci_xhci: runtime regs write offset 0x28: 0x1
pci_xhci: runtime regs write offset 0x38: 0x39e40000
pci_xhci: runtime regs write offset 0x3c: 0x1
pci_xhci: runtime regs write offset 0x30: 0x39c6ff40
pci_xhci: runtime regs write offset 0x34: 0x1
pci_xhci: wr erstba erst (fffffc7fba06ff40) ptr 0x139e40000, sz 256
pci_xhci: rtsregs read offset 0x0 -> 0x2
pci_xhci: runtime regs write offset 0x20: 0x2
pci_xhci: runtime regs write offset 0x24: 0x3f8
pci_xhci: hostop read offset 0x0 -> 0x0
pci_xhci: hostop write offset 0x0: 0x4
pci_xhci: hostop read offset 0x0 -> 0x4
pci_xhci: hostop write offset 0x0: 0x5
pci_xhci: insert event 0[1000000] 2[1000000] 3[8800]
 erdp idx 0/seg 0, enq idx 0/seg 0, pcs 1
 (erdp=0x139e40000, erst=0x139e40000, tblsz=256, do_intr 0)
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: rtsregs read offset 0x0 -> 0x3
pci_xhci: hostop read offset 0x3f0 -> 0x0
pci_xhci: portregs read offset 0x0 port 1 -> 0x20e03
pci_xhci: portregs read offset 0x0 port 2 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 3 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 4 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 5 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 6 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 7 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 8 -> 0x2a0
pci_xhci: runtime regs write offset 0x38: 0x39e40018
pci_xhci: runtime regs write offset 0x3c: 0x1
pci_xhci: erdp 0x139e40010, events cnt 0
pci_xhci: runtime regs write offset 0x20: 0x3
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: portregs read offset 0x0 port 1 -> 0x20e03
pci_xhci: portregs read offset 0x0 port 2 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 3 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 4 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 5 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 6 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 7 -> 0x2a0
pci_xhci: portregs read offset 0x0 port 1 -> 0x20e03
pci_xhci: portregs wr offset 0x0, port 1: 0xc00
pci_xhci: portregs read offset 0x0 port 2 -> 0x2a0
pci_xhci: portregs wr offset 0x0, port 2: 0x0
pci_xhci: portregs_write to unattached port 2
...
pci_xhci: portregs_write to unattached port 8
pci_xhci: portregs read offset 0x0 port 1 -> 0xc03
pci_xhci: portregs wr offset 0x0, port 1: 0xe00
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs read offset 0x0 port 2 -> 0xa0
pci_xhci: portregs wr offset 0x0, port 2: 0x200
pci_xhci: portregs_write to unattached port 2
pci_xhci: portregs_write to unpowered port 2
...
pci_xhci: portregs_write to unpowered port 8
pci_xhci: portregs read offset 0x0 port 1 -> 0xc03
pci_xhci: portregs read offset 0x0 port 1 -> 0xc03
pci_xhci: portregs wr offset 0x0, port 1: 0xe00
pci_xhci: portregs_write to unpowered port 1
...
pci_xhci: portregs read offset 0x0 port 1 -> 0xc03
pci_xhci: portregs read offset 0x0 port 2 -> 0xa0
pci_xhci: portregs read offset 0x0 port 3 -> 0xa0
pci_xhci: portregs read offset 0x0 port 4 -> 0xa0
pci_xhci: portregs read offset 0x0 port 5 -> 0xa0
pci_xhci: portregs read offset 0x0 port 6 -> 0xa0
pci_xhci: portregs read offset 0x0 port 7 -> 0xa0
pci_xhci: portregs read offset 0x0 port 8 -> 0xa0

>> then drop into this repeating reset loop

pci_xhci: portregs wr offset 0x0, port 1: 0xc10
xhci reset port 1
pci_xhci: insert event 0[1000000] 2[1000000] 3[8800]
 erdp idx 12/seg 0, enq idx 12/seg 0, pcs 1
 (erdp=0x139e400c0, erst=0x139e40000, tblsz=256, do_intr 1)
pci_xhci: hostop read offset 0x4 -> 0x18
pci_xhci: rtsregs read offset 0x0 -> 0x3
pci_xhci: hostop read offset 0x3f0 -> 0x0
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: hostop read offset 0x3f0 -> 0x0
pci_xhci: portregs read offset 0x0 port 2 -> 0xa0
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs read offset 0x0 port 3 -> 0xa0
pci_xhci: portregs read offset 0x0 port 2 -> 0xa0
pci_xhci: portregs read offset 0x0 port 4 -> 0xa0
pci_xhci: portregs read offset 0x0 port 3 -> 0xa0
pci_xhci: portregs read offset 0x0 port 5 -> 0xa0
pci_xhci: portregs read offset 0x0 port 4 -> 0xa0
pci_xhci: portregs read offset 0x0 port 6 -> 0xa0
pci_xhci: portregs read offset 0x0 port 5 -> 0xa0
pci_xhci: portregs read offset 0x0 port 7 -> 0xa0
pci_xhci: portregs read offset 0x0 port 6 -> 0xa0
pci_xhci: portregs read offset 0x0 port 8 -> 0xa0
pci_xhci: portregs read offset 0x0 port 7 -> 0xa0
pci_xhci: portregs read offset 0x0 port 8 -> 0xa0
pci_xhci: runtime regs write offset 0x38: 0x39e400d8
pci_xhci: runtime regs write offset 0x3c: 0x1
pci_xhci: erdp 0x139e400d0, events cnt 0
pci_xhci: runtime regs write offset 0x20: 0x3
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs wr offset 0x0, port 1: 0x200c00
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs wr offset 0x0, port 1: 0xc02
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs wr offset 0x0, port 1: 0x40c00
pci_xhci: portregs_write to unpowered port 1
pci_xhci: portregs read offset 0x0 port 1 -> 0x200c03
pci_xhci: portregs wr offset 0x0, port 1: 0xc10
xhci reset port 1
Actions #3

Updated by Andy Fiddaman 4 months ago

Fundamentally, the problem seems to be that the port is powered off by the driver, and bhyve does not allow it to be powered on again

pci_xhci: portregs wr offset 0x0, port 1: 0xc00
Power off port 1
pci_xhci: portregs wr offset 0x0, port 1: 0xe00
pci_xhci: portregs_write to unpowered port 1

and if I patch bhyve to allow the power on, then it works

root@bhyvetest:~# mdb -ke ::prtusb
INDEX   DRIVER      INST  NODE          GEN  VID.PID     PRODUCT
1       xhci        0     pci8086,1e31  3.0  0000.0000   No Product String
2       hid         0     mouse         3.0  fb5d.0001   HID Tablet

It's borne out by the usb debug messages from the kernel too

xusb0:  port1 status=0xc03, change=0x10
xusb0:  port1 connected
xusb0:  port1 enabled
xusb0:  port1 not suspended
xusb0:  port1 reset completed
xusb0:  port1 reset inactive
xusb0:  port1 power off
xusb0:  new port1 state 0x103
xusb0:  port 1 status (0xc03) not OK on retry 3
xusb0:  disabling port 1 again
xusb0:  hubd_disable_port: port=1

It doesn't look like the bhyve xhci sets the Port Power Control (PPC) flag in its capabilities register:

        sc->hccparams1 = XHCI_SET_HCCP1_AC64(1) |       /* 64-bit addrs */
                         XHCI_SET_HCCP1_NSS(1) |        /* no 2nd-streams */
                         XHCI_SET_HCCP1_SPC(1) |        /* short packet */
                         XHCI_SET_HCCP1_MAXPSA(XHCI_STREAMS_MAX);
Actions #4

Updated by Andy Fiddaman 4 months ago

  • Subject changed from xhci: Connecting device on port 1 failed to bhyve/xhci: Connecting device on port 1 failed
  • Category changed from driver - device drivers to bhyve
  • Status changed from New to In Progress
  • Assignee set to Andy Fiddaman
Actions #5

Updated by Electric Monk 4 months ago

  • Gerrit CR set to 2103
Actions #6

Updated by Andy Fiddaman 4 months ago

After reading the relevant parts of the XHCI specification (and with some help from Robert Mustacchi on how to interpret parts of it), it seems that there may be two separate issues here.

First, since the bhyve emulated XHCI hub does not advertise the Port Power Control (PPC) capability, then it should just ignore attempts to set a Port Power (PP) flag to 0. Even with PPC, the specification allows the effect of this flag to be delayed, so it a driver should not expect an immediate transition to 0. This is the fix in the attached Gerrit review which successfully resolves the issue and allows an illumos guest to attach the hid driver to the tablet device.

Secondly, illumos appears to be the only guest operating system that toggles the XHCI port power during initialisation, which is why the problem does not manifest with any of the other guests that I tested. When a hub does not advertise PPC, it's likely that the PP flag should not be toggled in this way.

Actions #7

Updated by Andy Fiddaman 4 months ago

Testing notes:

With this change in place, I have successfully booted Windows, FreeBSD, illumos and Linux guests within bhyve, and confirmed that the tablet device is successfully attached in each case. The mouse pointer in the RFB server behaves well - the same as before the change (by obversation).

Actions #8

Updated by Electric Monk 4 months ago

  • Status changed from In Progress to Closed
  • % Done changed from 0 to 100

git commit 104fd2955714fa4ea6ed431b6b5cf2eb0766ecad

commit  104fd2955714fa4ea6ed431b6b5cf2eb0766ecad
Author: Andy Fiddaman <omnios@citrus-it.co.uk>
Date:   2022-04-23T21:17:48.000Z

    14623 bhyve/xhci: Connecting device on port 1 failed
    Reviewed by: Robert Mustacchi <rm+illumos@fingolfin.org>
    Reviewed by: Toomas Soome <tsoome@me.com>
    Approved by: Rich Lowe <richlowe@richlowe.net>

Actions

Also available in: Atom PDF