kern/54771: nvme(4) fails to attach

[martin%NetBSD.org@localhost]

>Number:         54771
>Category:       kern
>Synopsis:       nvme(4) fails to attach
>Confidential:   no
>Severity:       critical
>Priority:       high
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Mon Dec 16 12:40:00 +0000 2019
>Originator:     Martin Husemann
>Release:        NetBSD 9.0_RC1
>Organization:
The NetBSD Foundation, Inc.
>Environment:
System: NetBSD emmas.aprisoft.de 8.1_STABLE NetBSD 8.1_STABLE (EMMAS) #9: Mon Nov 4 09:15:39 CET 2019 martin%emmas.aprisoft.de@localhost:/var/nbsd/src-8/sys/arch/amd64/compile/EMMAS amd64
Architecture: x86_64
Machine: amd64
(not this machine, see dmesg below)

>Description:

Trying to test PR 54761 I created a VirtualBox installation with two NVME 
drives. Unofurtunately the drives do not attach:

nvme0 at pci0 dev 14 function 0: vendor 80ee product 4e56 (rev. 0x00)
nvme0: NVMe 1.2
nvme0: interrupting at ioapic0 pin 22
nvme0: autoconfiguration error: polled command timed out
nvme0: autoconfiguration error: unable to identify controller


Full dmesg:

Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017,
2018, 2019 The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California.  All rights reserved.

NetBSD 9.0_RC1 (GENERIC) #0: Sat Dec 14 12:36:33 UTC 2019
	mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/amd64/compile/GENERIC
total memory = 16383 MB
avail memory = 15880 MB
cpu_rng: RDSEED
rnd: seeded with 256 bits
timecounter: Timecounters tick every 10.000 msec
Kernelized RAIDframe activated
running cgd selftest aes-xts-256 aes-xts-512 done
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
efi: systbl at pa dff29f18
innotek GmbH VirtualBox (1.2)
mainbus0 (root)
ACPI: RSDP 0x00000000DFF35014 000024 (v02 VBOX  )
ACPI: XSDT 0x00000000DFF340E8 000044 (v01 VBOX   VBOXFACP 00000001      01000013)
ACPI: FACP 0x00000000DFF32000 0000F4 (v04 VBOX   VBOXFACP 00000001 ASL  00000061)
ACPI: DSDT 0x00000000DFF2F000 0022EA (v02 VBOX   VBOXBIOS 00000002 INTL 20100528)
ACPI: FACS 0x00000000DFF39000 000040
ACPI: APIC 0x00000000DFF33000 00008C (v02 VBOX   VBOXAPIC 00000001 ASL  00000061)
ACPI: SSDT 0x00000000DFF2E000 0001CC (v01 VBOX   VBOXCPUT 00000002 INTL 20100528)
ACPI: BGRT 0x00000000DE9D4000 000038 (v01 INTEL  EDK2     00000002      01000013)
ACPI: 2 ACPI AML tables successfully acquired and loaded
ioapic0 at mainbus0 apid 8: pa 0xfec00000, version 0x20, 24 pins
cpu0 at mainbus0 apid 0
cpu0: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu0: package 0, core 0, smt 0
cpu1 at mainbus0 apid 1
cpu1: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu1: package 0, core 0, smt 1
cpu2 at mainbus0 apid 2
cpu2: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu2: package 0, core 0, smt 2
cpu3 at mainbus0 apid 3
cpu3: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu3: package 0, core 0, smt 3
cpu4 at mainbus0 apid 4
cpu4: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu4: package 0, core 0, smt 4
cpu5 at mainbus0 apid 5
cpu5: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu5: package 0, core 0, smt 5
cpu6 at mainbus0 apid 6
cpu6: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu6: package 0, core 0, smt 6
cpu7 at mainbus0 apid 7
cpu7: AMD Ryzen 9 3900X 12-Core Processor            , id 0x870f10
cpu7: package 0, core 0, smt 7
acpi0 at mainbus0: Intel ACPICA 20190405
acpi0: X/RSDT: OemId <VBOX  ,VBOXFACP,00000001>, AslId <    ,01000013>
acpi0: SCI interrupting at int 9
acpi0: fixed power button present
acpi0: fixed sleep button present
timecounter: Timecounter "ACPI-Safe" frequency 3579545 Hz quality 900
pckbc1 at acpi0 (PS2K, PNP0303) (kbd port): io 0x60,0x64 irq 1
pckbc2 at acpi0 (PS2M, PNP0F03) (aux port): irq 12
attimer1 at acpi0 (TIMR, PNP0100): io 0x40-0x43,0x50-0x53
acpivga0 at acpi0 (GFX0): ACPI Display Adapter
acpiout0 at acpivga0 (VGA, 0x0100): ACPI Display Output Device
acpivga0: connected output devices:
acpivga0:   0x0100 (acpiout0): VGA Analog Monitor, index 0, port 0, head 0
acpiacad0 at acpi0 (AC, ACPI0003-0): ACPI AC Adapter
ACPI: Enabled 2 GPEs in block 00 to 07
pckbd0 at pckbc1 (kbd slot)
pckbc1: using irq 1 for kbd slot
wskbd0 at pckbd0: console keyboard
pms0 at pckbc1 (aux slot)
pckbc1: using irq 12 for aux slot
wsmouse0 at pms0 mux 0
pci0 at mainbus0 bus 0: configuration mode 1
pci0: This pci host supports neither MSI nor MSI-X.
pci0: i/o space, memory space enabled, rd/line, rd/mult, wr/inv ok
pchb0 at pci0 dev 0 function 0: vendor 8086 product 1237 (rev. 0x02)
pcib0 at pci0 dev 1 function 0: vendor 8086 product 7000 (rev. 0x00)
piixide0 at pci0 dev 1 function 1: Intel 631xESB/632xESB IDE Controller (rev. 0x00)
piixide0: bus-master DMA support present
piixide0: primary channel configured to compatibility mode
piixide0: primary channel interrupting at ioapic0 pin 14
atabus0 at piixide0 channel 0
piixide0: secondary channel configured to compatibility mode
piixide0: secondary channel interrupting at ioapic0 pin 15
atabus1 at piixide0 channel 1
genfb0 at pci0 dev 2 function 0: vendor 80ee product beef (rev. 0x00)
genfb0: framebuffer at 0xe0000000, size 1024x768, depth 32, stride 4096
genfb0: shadow framebuffer enabled, size 3072 KB
wsdisplay0 at genfb0 kbdmux 1: console (default, vt100 emulation), using wskbd0
wsmux1: connecting to wsdisplay0
drm at genfb0 not configured
wm0 at pci0 dev 3 function 0: Intel i82540EM 1000BASE-T Ethernet (rev. 0x02)
wm0: interrupting at ioapic0 pin 19
wm0: 32-bit 33MHz PCI bus
wm0: 64 words (6 address bits) MicroWire EEPROM
wm0: Ethernet address 08:00:27:bc:f9:2e
wm0: 0x402<LOCK_EECD,IOH_VALID>
makphy0 at wm0 phy 1: Marvell 88E1011 Gigabit PHY, rev. 4
makphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
wm0: Clear PME# now
vendor 80ee product cafe (miscellaneous system) at pci0 dev 4 function 0 not configured
auich0 at pci0 dev 5 function 0: i82801AA (ICH) AC-97 Audio
auich0: interrupting at ioapic0 pin 21
auich0: ac97: SigmaTel STAC9700 codec; no 3D stereo
auich0: ac97: ext id 0x809<AC97_23,VRM,VRA>
piixpm0 at pci0 dev 7 function 0: vendor 8086 product 7113 (rev. 0x08)
timecounter: Timecounter "piixpm0" frequency 3579545 Hz quality 1000
piixpm0: 24-bit timer
piixpm0: interrupting at ioapic0 pin 23
iic0 at piixpm0 port 0: I2C bus
xhci0 at pci0 dev 12 function 0: vendor 8086 product 1e31 (rev. 0x00)
xhci0: interrupting at ioapic0 pin 20
xhci0: autoconfiguration error: Unknown revision (20). Set to 3.0.
xhci0: xHCI version 1.0
usb0 at xhci0: USB revision 3.0
usb1 at xhci0: USB revision 2.0
ahcisata0 at pci0 dev 13 function 0: vendor 8086 product 2829 (rev. 0x02)
ahcisata0: 64-bit DMA
ahcisata0: AHCI revision 1.10, 4 ports, 32 slots, CAP 0xc8241f83<CCCS,SAM,ISS=0x2=Gen2,SSS,SNCQ,S64A>
ahcisata0: interrupting at ioapic0 pin 21
atabus2 at ahcisata0 channel 0
atabus3 at ahcisata0 channel 1
atabus4 at ahcisata0 channel 2
atabus5 at ahcisata0 channel 3
ahcisata0: Clear PME# now
nvme0 at pci0 dev 14 function 0: vendor 80ee product 4e56 (rev. 0x00)
nvme0: NVMe 1.2
nvme0: interrupting at ioapic0 pin 22
nvme0: autoconfiguration error: polled command timed out
nvme0: autoconfiguration error: unable to identify controller
isa0 at pcib0
pcppi0 at isa0 port 0x61
spkr0 at pcppi0: PC Speaker
wsbell at spkr0 not configured
midi0 at pcppi0: PC speaker
sysbeep0 at pcppi0
attimer1: attached to pcppi0
acpicpu0 at cpu0: ACPI CPU
acpicpu0: C1: HLT, lat   0 us, pow     0 mW
acpicpu1 at cpu1: ACPI CPU
acpicpu2 at cpu2: ACPI CPU
acpicpu3 at cpu3: ACPI CPU
acpicpu4 at cpu4: ACPI CPU
acpicpu5 at cpu5: ACPI CPU
acpicpu6 at cpu6: ACPI CPU
acpicpu7 at cpu7: ACPI CPU
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
autoconfiguration error: ERROR: 2367 cycle TSC drift observed
acpiacad0: AC adapter online.
auich0: autoconfiguration error: ac97 link rate calibration timed out after 1150519 us
audio0 at auich0: playback, capture, full duplex, independent
audio0: slinear_le:16 2ch 48000Hz, blk 40ms for playback
audio0: slinear_le:16 2ch 48000Hz, blk 40ms for recording
spkr1 at audio0: PC Speaker (synthesized)
wsbell at spkr1 not configured
uhub0 at usb0: NetBSD (0000) xHCI root hub (0000), class 9/0, rev 3.00/1.00, addr 0
uhub0: 6 ports with 6 removable, self powered
uhub1 at usb1: NetBSD (0000) xHCI root hub (0000), class 9/0, rev 2.00/1.00, addr 0
uhub1: 8 ports with 8 removable, self powered
atapibus0 at atabus1: 2 targets
cd0 at atapibus0 drive 0: <VBOX CD-ROM, VB2-01700376, 1.0> cdrom removable
cd0: 32-bit data port
cd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133)
cd0(piixide0:1:0): using PIO mode 4, DMA mode 2 (using DMA)
IPsec: Initialized Security Association Processing.
ahcisata0 port 1: device present, speed: 3.0Gb/s
ahcisata0 port 0: device present, speed: 3.0Gb/s
wd0 at atabus2 drive 0
wd0: <VBOX HARDDISK>
wd0: drive supports 128-sector PIO transfers, LBA48 addressing
wd0: 30720 MB, 62415 cyl, 16 head, 63 sec, 512 bytes/sect x 62914560 sectors
wd0: GPT GUID: 8bc9aef0-1204-4c9a-9b14-53cf81c30a35
dk0 at wd0: "e4c1b47a-0e33-4800-acd5-8755f42eeabd", 262144 blocks at 64, type: ntfs
dk1 at wd0: "7878519c-4b35-427a-9e89-7b68cfd96920", 45875133 blocks at 262272, type: ffs
dk2 at wd0: "6173740a-d903-4c13-84a3-ad7b516bd5ce", 16777119 blocks at 46137408, type: swap
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133), NCQ (32 tags)
wd0(ahcisata0:0:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133) (using DMA), NCQ (31 tags)
wd1 at atabus3 drive 0
wd1: <VBOX HARDDISK>
wd1: drive supports 128-sector PIO transfers, LBA48 addressing
wd1: 1550 MB, 3149 cyl, 16 head, 63 sec, 512 bytes/sect x 3174400 sectors
wd1: GPT GUID: 84a6fef3-46c8-48a4-954c-00f32da83fa3
dk3 at wd1: "EFI system", 262144 blocks at 2048, type: msdos
dk4 at wd1: "5f6a5e82-78be-4a19-abc4-230376a8feaa", 2908160 blocks at 264192, type: ffs
wd1: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133), NCQ (32 tags)
wd1(ahcisata0:1:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133) (using DMA), NCQ (31 tags)
WARNING: 5 errors while detecting hardware; check system log.
boot device: wd0
root on dk1 dumps on dk2
root file system type: ffs
kern.module.path=/stand/amd64/9.0/modules
wsdisplay0: screen 1 added (default, vt100 emulation)
wsdisplay0: screen 2 added (default, vt100 emulation)
wsdisplay0: screen 3 added (default, vt100 emulation)
wsdisplay0: screen 4 added (default, vt100 emulation)

>How-To-Repeat:
s/a

>Fix:
n/a