Bug 237666 - repeated messages of "uhub_reattach_port: giving up port reset - device vanished"
Summary: repeated messages of "uhub_reattach_port: giving up port reset - device vanis...
Status: Open
Alias: None
Product: Base System
Classification: Unclassified
Component: usb (show other bugs)
Version: 12.0-RELEASE
Hardware: amd64 Any
: --- Affects Some People
Assignee: freebsd-usb mailing list
URL:
Keywords: needs-qa, regression
Depends on:
Blocks:
 
Reported: 2019-04-30 08:22 UTC by schmidt
Modified: 2019-09-21 01:25 UTC (History)
6 users (show)

See Also:
koobs: mfc-stable11?
koobs: mfc-stable12?


Attachments
dmesg.boot from the maschin (91.15 KB, text/plain)
2019-04-30 08:22 UTC, schmidt
no flags Details
dmesg.boot with stable kernel an verbose on (91.66 KB, text/plain)
2019-04-30 10:28 UTC, schmidt
no flags Details
dmesg.boot with stable kernel an verbose off (86.24 KB, text/plain)
2019-04-30 10:29 UTC, schmidt
no flags Details
dmesg.boot from the same machine running 11.2 (54.29 KB, text/plain)
2019-05-15 06:07 UTC, schmidt
no flags Details
dmesg.boot 11.2 with Lagacy USB Off an hw.usb.uhub.debug=17 set (93.10 KB, text/plain)
2019-05-15 09:27 UTC, schmidt
no flags Details
12.0 boot messages on Gigabyte motherboard (38.60 KB, text/plain)
2019-08-07 08:18 UTC, Mike Karels
no flags Details
Patch for XHCI (1.64 KB, patch)
2019-08-09 16:49 UTC, Hans Petter Selasky
no flags Details | Diff
devinfo -r (9.33 KB, text/plain)
2019-08-11 17:47 UTC, Mike Karels
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description schmidt 2019-04-30 08:22:45 UTC
Created attachment 204107 [details]
dmesg.boot from the maschin

I've just updated my System from FreeBSD 11.1-Release to FreeBSD 12.0-Release. 

After Booting i get every second the message 

uhub_reattach_port: giving up port reset - device vanished

I've disconnected all external usb devices (including mouse and keyboard) the messages continue. 

I've use the Hardware for at least 4 years now. No such problem in the past.
Comment 1 Hans Petter Selasky freebsd_committer 2019-04-30 09:06:54 UTC
Can you try a 12-stable based kernel?

I suspect APCI changes might have turned on something in the hardware which was off before. USB changes are down to a minimum.

The only relevant change I can think of is this one:
https://svnweb.freebsd.org/changeset/base/343134

--HPS
Comment 2 schmidt 2019-04-30 10:27:58 UTC
I've build a stable kernel and booted with it. 

The Problems are still there. 


If it's only the messages i could live with that but my keyboard and mouse behave strangely. 

I about 30 sec after boot mouse and keyboard are stuck and only disconnecting the keyboard revive keyboard and mouse.

X11 lags sometimes. I think it's the usb resets the freeze everything. 

I have the dmesg from the stable kernel attached. 

If anything under stable the problems with keyboard are more pronounced. Keys repeating or missing without reason.

So I'm back with the release kernel.

Regards 
  Estartu
Comment 3 schmidt 2019-04-30 10:28:51 UTC
Created attachment 204110 [details]
dmesg.boot with stable kernel an verbose on
Comment 4 schmidt 2019-04-30 10:29:24 UTC
Created attachment 204111 [details]
dmesg.boot with stable kernel an verbose off
Comment 5 srlemke 2019-05-14 14:43:37 UTC
Just to pump this thread a little more:

<slemke@besta>/home/slemke/dropbox # dmesg |grep vanished |wc -l
815

<root@besta>/root # pciconf -lv |grep -i usb
    device     = '100 Series/C230 Series Chipset Family USB 3.0 xHCI Controller'
    subclass   = USB
    device     = 'DSL6340 USB 3.1 Controller [Alpine Ridge]'
    subclass   = USB
<root@besta>/root # 

So this is a very interesting scenario and will probably very difficult to debug and solve:

I have one of these portable docking station(works fine on linux):
https://www.czc.cz/dell-dokovaci-stanice-wd15-130w/187601/produkt - its and usb-c docking station.

On system boot it boot-locks with the message:
"uhub_reattach_port: giving up port reset - device vanished" - if I quickly unplug and replug the usb-c the boot proceeds and images appears on the 2 screens attached to the docking station. No regular USB2 are working on the docking station (only the 2 monitors) - Only the screns are correctly detected.

<root@besta>/home/slemke # uname -a
FreeBSD besta 12.0-RELEASE-p3 FreeBSD 12.0-RELEASE-p3 GENERIC  amd64
<root@besta>/home/slemke #
Comment 6 schmidt 2019-05-15 06:07:46 UTC
Created attachment 204382 [details]
dmesg.boot from the same machine running 11.2

There was no working with 12.0 and this bug. So i downgraded back to 11.2. 

There are some USB errors there as well but no repeated errors and no ill effects.
Comment 7 schmidt 2019-05-15 06:17:09 UTC
I've the same USB Controller chip as srlemke@protonmail.com but mine is on the Mainboard, because the error is still there when all USB devices are disconnected. 

xhci0@pci0:6:0:0:       class=0x0c0330 card=0x11112222 chip=0x15b68086 rev=0x00 hdr=0x00
    vendor     = 'Intel Corporation'
    device     = 'DSL6540 USB 3.1 Controller [Alpine Ridge]'
    class      = serial bus
    subclass   = USB
Comment 8 Hans Petter Selasky freebsd_committer 2019-05-15 07:43:11 UTC
Can you try to figure out if anything is connected to the failing port?
Comment 9 schmidt 2019-05-15 08:00:11 UTC
The error is there even if nothing is connected to any USB-Port.
Comment 10 Hans Petter Selasky freebsd_committer 2019-05-15 08:20:11 UTC
And you're sure this is no internal USB device?

--HPS
Comment 11 schmidt 2019-05-15 08:37:44 UTC
I have tested is without any device connected. No keyboard, no mouse, no external HUB. Nothing and the error is still there.
Comment 12 Hans Petter Selasky freebsd_committer 2019-05-15 08:47:45 UTC
I understand, but sometimes the vendor wire internal devices to the USB ports, like bluetooth and BIOS related features.

BTW: Have you tried playing with BIOS legacy USB support ON/OFF?
Comment 13 Hans Petter Selasky freebsd_committer 2019-05-15 09:12:18 UTC
You might want to set:
sysctl hw.usb.uhub.debug=17

When collecting dmesg from the failing case.
Comment 14 schmidt 2019-05-15 09:27:49 UTC
Created attachment 204388 [details]
dmesg.boot 11.2 with Lagacy USB Off an hw.usb.uhub.debug=17 set

Disabling Legacy USB support didn't change anything. Therefore i booted with hw.usb.uhub.debug=17 set. The Buffer for dmesg isn't large enough for the whole kernel messages. so only the last part are here but the USB Errors are in the file.
Comment 15 Mike Karels freebsd_committer 2019-08-07 08:18:33 UTC
Created attachment 206324 [details]
12.0 boot messages on Gigabyte motherboard

I just switched from 11.3 to 12.0, and also have this problem since upgrade on a system with a Gigabyte motherboard.  I attached a dmesg.  I note that I am also losing communication with a UPS (via USB) every 10 minutes, which is also new.  I have lots of USB devices attached; I have not attempted to remove them, etc, but can do so. I can also provide 11.3 dmesgs.
Comment 16 Hans Petter Selasky freebsd_committer 2019-08-07 08:52:49 UTC
Does it help to set:

sysctl hw.usb.disable_enumeration=1

After boot. Does the UPS still work?

I suspect the issue has nothing to do with USB, but likely early AP startup (timing issue, can be disabled in kernel build) or ACPI's recent USB support.

1) Try removing this option from kernel config:
sys/amd64/conf/GENERIC:options 	EARLY_AP_STARTUP

2) Try booting with the following line added to /boot/loader.conf:

debug.acpi.disabled="usb"

--HPS
Comment 17 Mike Karels freebsd_committer 2019-08-07 12:21:49 UTC
Setting sysctl hw.usb.disable_enumeration=1 makes the messages stop. The UPS does not appear to work; I stopped apcupsd, and apctest cannot open the device. Clearing the sysctl makes the messages start again, but apctest does not work. Unfortunately, I did not try apctest before setting the sysctl.

Booting with debug.acpi.disabled="usb" did not seem to change anything: the messages continued, apcupsd complained about losing communication, and apctest didn't work.  hw.usb.disable_enumeration=1 still stopped the messages, but apcupsd still complains about lost communiction.  I can test the rest this evening.
Comment 18 Mike Karels freebsd_committer 2019-08-08 05:00:37 UTC
Commenting out EARLY_AP_STARTUP from the kernel config did not seem to change anything: the error message still repeats, and apcupsd loses contact with the UPS (probably never has it). I forgot to change the ident, but the APs were not started until nearly the end of autoconfiguration, just before attaching cd0 and mounting root.  The error messages start after that, after finding several more USB devices.  From messages:

Aug  7 21:43:31 pughole kernel: Launching APs: 1 10 3 8 9 11 5 7 4 2 6
Aug  7 21:43:31 pughole kernel: cd0 at ahcich1 bus 0 scbus0 target 0 lun 0
Aug  7 21:43:31 pughole kernel: cd0: <HL-DT-ST BD-RE  WH14NS40 1.00> Removable C
D-ROM SCSI device
Aug  7 21:43:31 pughole kernel: cd0: Serial Number SIK9IFALJ462
Aug  7 21:43:31 pughole kernel: cd0: 150.000MB/s transfers (SATA 1.x, UDMA6, ATA
PI 12bytes, PIO 8192bytes)
Aug  7 21:43:31 pughole kernel: cd0: Attempt to query device size failed: NOT RE
ADY, Medium not present - tray closed
Aug  7 21:43:31 pughole kernel: Trying to mount root from ufs:/dev/nvd0p5 [rw]..
.
Aug  7 21:43:31 pughole kernel: uhub0: 4 ports with 4 removable, self powered
Aug  7 21:43:31 pughole kernel: ZFS filesystem version: 5
Aug  7 21:43:31 pughole kernel: ZFS storage pool version: features support (5000
)
Aug  7 21:43:31 pughole kernel: uhub2: 2 ports with 2 removable, self powered
Aug  7 21:43:31 pughole kernel: uhub3: 2 ports with 2 removable, self powered
Aug  7 21:43:31 pughole kernel: uhub1: 21 ports with 21 removable, self powered
Aug  7 21:43:31 pughole kernel: uhub_reattach_port: giving up port reset - device vanished
Aug  7 21:43:31 pughole kernel: ugen1.2: <vendor 0x045b product 0x0209> at usbus1
Aug  7 21:43:31 pughole kernel: uhub4 numa-domain 0 on uhub1
Aug  7 21:43:31 pughole kernel: uhub4: <vendor 0x045b product 0x0209, class 9/0, rev 2.10/1.00, addr 1> on usbus1

Any reason to try these in combination?
Comment 19 Hans Petter Selasky freebsd_committer 2019-08-08 06:33:40 UTC
Hi,

Can you collect logs from FreeBSD 12 with:

sysctl hw.usb.uhub.debug=17

Just let it run for 12 minutes. According to your logs it takes around 10 minutes for the cycle before UPS detaches.

--HPS
Comment 20 Hans Petter Selasky freebsd_committer 2019-08-08 06:37:06 UTC
Aug  6 18:07:20 pughole kernel: usbus0 numa-domain 0 on xhci0
Aug  6 18:07:20 pughole kernel: usbus0: 5.0Gbps Super Speed USB v3.0

I'm a little surprised that your xhci has 21 ports on the root-HUB. That seems a lot. Maybe 5 is more correct. Can you check this?

--HPS
Comment 21 Mike Karels freebsd_committer 2019-08-08 07:11:51 UTC
I'll collect the logs tomorrow.  About the 21 ports: 11.3 reported the same thing, but I agree that the number sounds suspicious.  Does a verbose boot provide any information about that?
Comment 22 Hans Petter Selasky freebsd_committer 2019-08-08 07:20:13 UTC
Hi,

I think bootverbose won't help.

hw.usb.uhub.debug will reveal more information about which ports are active and which are causing problems. Currently xhci.debug is a last resort, because it is very verbose.

Thanks for testing. Lets try to figure out the reason for this "giving up port reset" failure, which also happens on 11.x - right.

--HPS
Comment 23 Mike Karels freebsd_committer 2019-08-08 23:39:20 UTC
The output from the time with debug enabled is too big to attach. ftp://ftp.karels.net/outgoing/messages.usb_debug should work (normal anonymous access).
Comment 24 Hans Petter Selasky freebsd_committer 2019-08-09 07:29:20 UTC
Can you repeat with hw.usb.xhci.debug=17. It looks like the XHCI port status register is returning all ones, which is strange.
Comment 25 Mike Karels freebsd_committer 2019-08-09 13:26:50 UTC
I wasn't sure about hub_debug, so I did both.  ftp://ftp.karels.net/outgoing/messages.xhci_debug.gz (it's 14M without compression).
Comment 26 Hans Petter Selasky freebsd_committer 2019-08-09 16:38:52 UTC
Aug  9 07:47:30 pughole kernel: xhci_roothub_exec: port status=0x000802a0
Aug  9 07:47:30 pughole kernel: uhub_read_port_status: port 21, wPortStatus=0x07a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Aug  9 07:47:31 pughole kernel: xhci_roothub_exec: type=0xa3 request=0x00 wLen=0x0004 wValue=0x0000 wIndex=0x0003
Aug  9 07:47:31 pughole kernel: xhci_roothub_exec: UR_GET_STATUS i=3
Aug  9 07:47:31 pughole kernel: xhci_roothub_exec: port status=0xffffffff
Aug  9 07:47:31 pughole kernel: uhub_read_port_status: port 3, wPortStatus=0x07fb, wPortChange=0x00fb, err=USB_ERR_NORMAL_COMPLETION
Aug  9 07:47:31 pughole kernel: uhub_reattach_port: giving up port reset - device vanished
Aug  9 07:47:31 pughole kernel: xhci_roothub_exec: type=0x23 request=0x01 wLen=0x0000 wValue=0x0001 wIndex=0x0003
Aug  9 07:47:31 pughole kernel: xhci_roothub_exec: UR_CLEAR_PORT_FEATURE


Here it is "port status=0xffffffff" which is a totally off-track XHCI PCI read value.

I'll try to make a patch you can try. This looks like a low-level hardware PCI issue.
Comment 27 Hans Petter Selasky freebsd_committer 2019-08-09 16:49:00 UTC
Created attachment 206399 [details]
Patch for XHCI

Can you repeat XHCI logging with this patch?
Comment 28 Mike Karels freebsd_committer 2019-08-10 16:55:14 UTC
ftp://ftp.karels.net/outgoing/messages.xhci_retry.gz.  Oddly, port status is still sometimes -1, sometimes a more reasonable value, and they are in clusters.
Comment 29 Mike Karels freebsd_committer 2019-08-10 17:16:27 UTC
Hmm, I see that there are two xhci controllers.  One is on pci7, and I see this:

pcib7: <PCI-PCI bridge> at device 2.0 numa-domain 0 on pci4
pcib7: failed to allocate initial I/O port window: 0-0xfff
pcib7: failed to allocate initial memory window: 0-0xfffff
pcib7: failed to allocate initial prefetch window: 0-0xfffff
pci7: <PCI bus> numa-domain 0 on pcib7
xhci0: <XHCI (generic) USB 3.0 controller> mem 0xd8000000-0xd800ffff at device 0
.0 numa-domain 0 on pci7
xhci0: 32 bytes context size, 64-bit DMA
usbus0 numa-domain 0 on xhci0

and

pcib1: <ACPI Host-PCI bridge> port 0xcf8-0xcff numa-domain 0 on acpi0
pci1: <ACPI PCI bus> numa-domain 0 on pcib1
...
pci1: <unknown> at device 17.0 (no driver attached)
xhci1: <Intel Wellsburg USB 3.0 controller> mem 0xf6120000-0xf612ffff irq 19 at device 20.0 numa-domain 0 on pci1
xhci1: 32 bytes context size, 64-bit DMA
usbus1 numa-domain 0 on xhci1
pci1: <simple comms> at device 22.0 (no driver attached)

I'm also not using any USB3 device regularly, so I don't know if the misbehaving controller is functioning at all.

The messages above are similar with 11.3.
Comment 30 Hans Petter Selasky freebsd_committer 2019-08-10 17:46:21 UTC
Hi Konstatin,

We are seeing a 32-bit PCI read resulting in -1U. This is a regression issue in more recent versions of FreeBSD. Can you comment on these failure messages:

--HPS

> Hmm, I see that there are two xhci controllers.  One is on pci7, and I see this:
> 
> pcib7: <PCI-PCI bridge> at device 2.0 numa-domain 0 on pci4
> pcib7: failed to allocate initial I/O port window: 0-0xfff
> pcib7: failed to allocate initial memory window: 0-0xfffff
> pcib7: failed to allocate initial prefetch window: 0-0xfffff
> pci7: <PCI bus> numa-domain 0 on pcib7
> xhci0: <XHCI (generic) USB 3.0 controller> mem 0xd8000000-0xd800ffff at device 0
> .0 numa-domain 0 on pci7
> xhci0: 32 bytes context size, 64-bit DMA
> usbus0 numa-domain 0 on xhci0
> 
> and
> 
> pcib1: <ACPI Host-PCI bridge> port 0xcf8-0xcff numa-domain 0 on acpi0
> pci1: <ACPI PCI bus> numa-domain 0 on pcib1
> ...
> pci1: <unknown> at device 17.0 (no driver attached)
> xhci1: <Intel Wellsburg USB 3.0 controller> mem 0xf6120000-0xf612ffff irq 19 at device 20.0 numa-domain 0 on pci1
> xhci1: 32 bytes context size, 64-bit DMA
> usbus1 numa-domain 0 on xhci1
> pci1: <simple comms> at device 22.0 (no driver attached)
> 
> I'm also not using any USB3 device regularly, so I don't know if the misbehaving controller is functioning at all.
> 
> The messages above are similar with 11.3.
Comment 31 Hans Petter Selasky freebsd_committer 2019-08-10 17:47:10 UTC
Mike, can you repeat when you started seeing this bug?
Comment 32 Mike Karels freebsd_committer 2019-08-10 18:27:49 UTC
Yes, I started seeing these when I upgraded from FreeBSD 11.3 (RELEASE) to 12.0-RELEASE-p9 about a week ago.  I have /var/log/messages from 11.3 for comparison. btw, I added your xhci patch to the system with no EARLY_AP_STARTUP, although it probably doesn't matter.  I'll note that 12.0 is older than 11.3 in various ways; I should probably try 12-stable.

fwiw, this is a Gigabyte GA-X99P-SLI motherboard (rev. 1.0) with Intel Core i7-5820K, 6 cores plus hyperthreading, several years old, and has run many versions of FreeBSD.  I believe the chipset is an Intel X99; I could research the details.  I might be able to reboot 11.3 if it mattered (it's on an alternate partition, but I don't know how to boot it using UEFI).

Thanks for looking into this!
Comment 33 Mike Karels freebsd_committer 2019-08-10 20:21:48 UTC
An up-to-date GENERIC 12-stable kernel has the problem also.
Comment 34 Konstantin Belousov freebsd_committer 2019-08-11 08:52:45 UTC
(In reply to Hans Petter Selasky from comment #30)
Minus one reads mean that there is no more a device to respond at the address read.  I have no idea why, and there seems to be the mix of several scenarios of failure.  At least I would not be suprised to see that if the docking station was detached, assuming the controller is inside it.
Comment 35 Mike Karels freebsd_committer 2019-08-11 13:51:32 UTC
This is not a laptop; it's a tower computer.  Also, note that the messages start even before autoconfiguration is complete.
Comment 36 Hans Petter Selasky freebsd_committer 2019-08-11 14:58:06 UTC
@kib: What about these PCI errors?

> pcib7: failed to allocate initial I/O port window: 0-0xfff
> pcib7: failed to allocate initial memory window: 0-0xfffff
> pcib7: failed to allocate initial prefetch window: 0-0xfffff
Comment 37 Hans Petter Selasky freebsd_committer 2019-08-11 15:13:44 UTC
Hi,

Can you attach output from:

devinfo -r

and

acpidump -dt

--HPS
Comment 38 Hans Petter Selasky freebsd_committer 2019-08-11 15:15:27 UTC
Adding John Baldwin aswell after searching for similar issues.
Comment 39 Konstantin Belousov freebsd_committer 2019-08-11 15:37:14 UTC
(In reply to Hans Petter Selasky from comment #36)
These 'failed to allocate' messages are the secondary effects of reading all ones.  Values of the bridge' registers to specify io and memory window to forward to subordinary buses are all ones (AKA 0xfff...), and that range conflicts with already allocated resources.

So the question is how it comes that bridges were enumerated, but accessing their PCI config space reads failing.  I am curious if manually reading e.g. pci vendor or device id using pciconf would show sane values or 1111...s.
Comment 40 Mike Karels freebsd_committer 2019-08-11 17:47:57 UTC
Created attachment 206443 [details]
devinfo -r

devinfo -r is attached; acpdidump -dt is ftp://ftp.karels.net/outgoing/acpidump-dt.
Comment 41 John Baldwin freebsd_committer freebsd_triage 2019-08-12 16:47:54 UTC
If PCI messed up you would get -1 constantly, not sporadically.  FWIW, I have the exact same problem on my desktop since I upgraded it to 12.0.  I also use apcupsd and usually get a couple of e-mails a day due to "losing communications", but apcupsd is able to reattach when the device comes back so it still works overall aside from sending spammy e-mails.

Mine is also not a laptop, it's an Ivy Bridge desktop motherboard:

smbios.planar.maker="MSI"
smbios.planar.product="Z77A-G45 (MS-7752)"

xhci0: <Intel Panther Point USB 3.0 controller> mem 0xf7100000-0xf710ffff irq 16 at device 20.0 on pci0
xhci0: 32 bytes context size, 64-bit DMA
usbus0: waiting for BIOS to give up control
xhci0: Port routing mask set to 0xffffffff
usbus0 on xhci0
usbus0: 5.0Gbps Super Speed USB v3.0
ehci0: <Intel Panther Point USB 2.0 controller> mem 0xf7118000-0xf71183ff irq 16 at device 26.0 on pci0
usbus1: EHCI version 1.0
usbus1 on ehci0
usbus1: 480Mbps High Speed USB v2.0
...
ehci1: <Intel Panther Point USB 2.0 controller> mem 0xf7117000-0xf71173ff irq 23 at device 29.0 on pci0
usbus2: EHCI version 1.0
usbus2 on ehci1
usbus2: 480Mbps High Speed USB v2.0
...
ugen1.1: <Intel EHCI root HUB> at usbus1
ugen2.1: <Intel EHCI root HUB> at usbus2
ugen0.1: <0x8086 XHCI root HUB> at usbus0
...
uhub0: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
uhub1: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus2
uhub2: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
uhub2: 8 ports with 8 removable, self powered
uhub0: 2 ports with 2 removable, self powered
uhub1: 2 ports with 2 removable, self powered
ugen1.2: <vendor 0x8087 product 0x0024> at usbus1
uhub3 on uhub0
uhub3: <vendor 0x8087 product 0x0024, class 9/0, rev 2.00/0.00, addr 2> on usbus1
ugen2.2: <vendor 0x8087 product 0x0024> at usbus2
uhub4 on uhub1
uhub4: <vendor 0x8087 product 0x0024, class 9/0, rev 2.00/0.00, addr 2> on usbus2
uhub3: 6 ports with 6 removable, self powered
uhub4: 8 ports with 8 removable, self powered
ugen1.3: <American Power Conversion Back-UPS RS 1000G FW:868.L3 .D USB FW:L3> at usbus1
ugen1.4: <vendor 0x0451 product 0x8043> at usbus1
uhub5 on uhub3
uhub5: <vendor 0x0451 product 0x8043, class 9/0, rev 2.10/1.00, addr 4> on usbus1
uhub5: MTT enabled
uhub5: 4 ports with 4 removable, self powered
ugen1.5: <Logitech Trackball> at usbus1
ums0 on uhub5
ums0: <Logitech Trackball, class 0/0, rev 1.10/2.20, addr 5> on usbus1
ums0: 3 buttons and [XYZ] coordinates ID=0
ugen1.6: <LITE-ON Technology USB NetVista Full Width Keyboard.> at usbus1
ukbd0 on uhub5
ukbd0: <EP1 Interrupt> on usbus1
kbd2 at ukbd0

This is a typical set of logs from /var/log/messages when the UPS bounces:

Aug  9 17:35:01 ralph kernel: ugen1.3: <American Power Conversion Back-UPS RS 10
00G FW:868.L3 .D USB FW:L3> at usbus1 (disconnected)
Aug  9 17:35:01 ralph kernel: ugen1.3: <American Power Conversion Back-UPS RS 10
00G FW:868.L3 .D USB FW:L3> at usbus1
Aug  9 17:35:01 ralph kernel: interface uhid.1 already present in the KLD 'kerne
l'!
Aug  9 17:35:01 ralph kernel: linker_load_file: /boot/kernel/uhid.ko - unsupport
ed file type
Aug  9 17:35:07 ralph apcupsd[1967]: Communications with UPS restored.
Comment 42 John Baldwin freebsd_committer freebsd_triage 2019-08-12 16:50:06 UTC
(In reply to Hans Petter Selasky from comment #36)
Those are a red herring.  The next few lines down in dmesg show that a child device allocated resources ok which meant that pcib7 allocated fresh resources for its I/O windows.  You could verify this with 'pciconf -lB pcib7' and see that it has valid ranges for I/O and memory decoding, but the child device (xhci0) would not be able to attach successfully if we hadn't allocated valid windows in the parent bridge.
Comment 43 Konstantin Belousov freebsd_committer 2019-08-12 17:46:16 UTC
(In reply to John Baldwin from comment #42)
apcupsd loosing ugen's is nothing new.  I have this since 9.x times on very different machines, from old cedarview atoms up to the Skylake-X.  I do not think it is related.
Comment 44 John Baldwin freebsd_committer freebsd_triage 2019-08-12 18:02:11 UTC
(In reply to Konstantin Belousov from comment #43)
Yes, but I never had a single instance while running 10.x and 11.x on this desktop.  The day I upgraded to 12.0 I started getting multiple alerts a day.
Comment 45 Mike Karels freebsd_committer 2019-09-08 20:09:40 UTC
Any additional thoughts on this?  I rebooted with my UPS disconnected, and I still get constant messages about device vanished.  Then I rebooted with *no* external USB devices connected, and I *still* get these messages immediately and constantly.  I never saw this with 11.3, and I may have to revert to it.  I'm happy to run experiments to test any theories.
Comment 46 Hans Petter Selasky freebsd_committer 2019-09-09 07:14:34 UTC
Maybe you could try to do some bisecting with the FreeBSD master branch? To find the offending commit?

--HPS
Comment 47 Hans Petter Selasky freebsd_committer 2019-09-09 07:31:16 UTC
Start with r308158 of FreeBSD head branch.

Then build kernels and add revision steps like 1 2 4 8 16 32 and so on until the issue appears. Then repeat like in binary search to find the exact revision.

--HPS
Comment 48 Mike Karels freebsd_committer 2019-09-10 01:13:49 UTC
I'll give it a try soon.
Comment 49 Hans Petter Selasky freebsd_committer 2019-09-17 14:06:27 UTC
Ping - any progress?
Comment 50 Mike Karels freebsd_committer 2019-09-17 23:21:05 UTC
I've been working on this off and on.  It looks like the repeated messages started with r330957, an ACPI update.  However, the problem with the UPS started much earlier.  I haven't bracketed that, as lots of the early systems won't boot, at least multi-user, which makes it hard to test.  It seems to be before r315272.
Comment 51 Hans Petter Selasky freebsd_committer 2019-09-18 07:17:14 UTC
You should be able to identify the ACPI update in the stable/12 branch aswell. Then use that to bisect, because head might be a bit unstable as you see :-)

--HPS
Comment 52 Hans Petter Selasky freebsd_committer 2019-09-18 09:18:56 UTC
commit 48286dea101b3aad1e566952e372a646c87a8970
Author: jkim <jkim@FreeBSD.org>
Date:   Wed Mar 14 23:45:48 2018 +0000

    Merge ACPICA 20180313.


HEAD r330957 appears to be before 12.0 was released and was never MFC'ed to FreeBSD 11. I'm adding jkim, in case he has any input on this.

--HPS
Comment 53 Hans Petter Selasky freebsd_committer 2019-09-18 09:23:39 UTC
jkim: What is the right way to add ACPI debugging?
Comment 54 Mike Karels freebsd_committer 2019-09-19 03:31:01 UTC
(In reply to Hans Petter Selasky from comment #52)
In an "svn log" that goes far enough back to see this ACPI update on stable/12, I see the same revision number as on head.  "svn update -r330957" in that tree deletes most of the kernel.  I'm not sure what this means, but I know I can't compile it.
Comment 55 Jung-uk Kim freebsd_committer 2019-09-20 20:12:40 UTC
(In reply to Hans Petter Selasky from comment #53)
Add "options ACPI_DEBUG" to kernel configuration and set debug.acpi.layer and debug.acpi.level as described in acpi(4).

https://www.freebsd.org/cgi/man.cgi?query=acpi&format=html#DEBUGGING_OUTPUT
Comment 56 Jung-uk Kim freebsd_committer 2019-09-20 22:13:35 UTC
(In reply to Mike Karels from comment #54)
I just updated stable/12 to ACPICA 20190703 (r352566).

https://svnweb.freebsd.org/changeset/base/352566
Comment 57 Mike Karels freebsd_committer 2019-09-21 01:25:38 UTC
(In reply to Jung-uk Kim from comment #56)
I built a kernel at r352566.  It still prints this error message once per second.  However, I did not get the messages from apcupsd about losing contact.  I don't know if that means if it is working better or worse.  As I am running 12.0 userland, I went back to my previous kernel.

btw, I had to add "device iflib" to GENERIC.  I'll check whether anyone has commented on that.