kern/56291: XEN3_DOM0 nvme abysmal performance - very slow boot

[kardel%netbsd.org@localhost]

>Number:         56291
>Category:       kern
>Synopsis:       XEN3_DOM0 nvme abysmal performance - very slow boot
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu Jul 01 17:20:00 +0000 2021
>Originator:     kardel%netbsd.org@localhost
>Release:        NetBSD 9.99.85
>Organization:
	
>Environment:
	
	
System: NetBSD kebne-new 9.99.85 NetBSD 9.99.85 (GENERIC) #4: Tue Jun 29 11:47:28 CEST 2021  kardel@pip:/src/NetBSD/cur/src/obj.amd64/sys/arch/amd64/compile/GENERIC amd64
Architecture: x86_64
Machine: amd64
>Description:
	On a Dell R740 9.99.85 GENERIC boots normally and can access ld0@nvme0.
	The XEN3_DOM0 kernel under XEN 4.15 boots very slowly when nvme is enabled.
	Disabling nvme allows the kernel to boot normally.
	A similar issue was observed in PR kern/55667 initially before the
	hypervisor problems started there.

NVME attachment (plain boot):
nvme0 at pci7 dev 0 function 0: Samsung Electronics (3rd vendor ID) NVMe SSD Controller 172Xa/172Xb (rev. 0x01)
nvme0: NVMe 1.2
nvme0: for admin queue interrupting at msix5 vec 0
nvme0: Dell Express Flash PM1725a 1.6TB AIC, firmware 1.0.3, serial S39WNA0J701058
nvme0: for io queue 1 interrupting at msix5 vec 1 affinity to cpu0
nvme0: for io queue 2 interrupting at msix5 vec 2 affinity to cpu1
nvme0: for io queue 3 interrupting at msix5 vec 3 affinity to cpu2
nvme0: for io queue 4 interrupting at msix5 vec 4 affinity to cpu3
nvme0: for io queue 5 interrupting at msix5 vec 5 affinity to cpu4
nvme0: for io queue 6 interrupting at msix5 vec 6 affinity to cpu5
nvme0: for io queue 7 interrupting at msix5 vec 7 affinity to cpu6
nvme0: for io queue 8 interrupting at msix5 vec 8 affinity to cpu7
nvme0: for io queue 9 interrupting at msix5 vec 9 affinity to cpu8
nvme0: for io queue 10 interrupting at msix5 vec 10 affinity to cpu9
nvme0: for io queue 11 interrupting at msix5 vec 11 affinity to cpu10
nvme0: for io queue 12 interrupting at msix5 vec 12 affinity to cpu11
ld0 at nvme0 nsid 1
ld0: 1490 GB, 194561 cyl, 255 head, 63 sec, 512 bytes/sect x 3125627568 sectors

Boot dmesg fragment (DEBUG_AUTOCONF enabled):
...
[   8.2649101] ipmi0: holding up boot
[   8.2649590] usb1: holding up boot
[   8.2650032] ld0: holding up boot
[   8.2727850] config_pending_decr: usb1 0
[   8.2728872] ipmi0: holding up boot
[   8.2729371] ld0: holding up boot
### DELAY
[  54.7952753] ipmi0: version 2.0 interface KCS iobase 0xca8/0x8 spacing 4
[  54.7954282] ipmi0:  irq 10
[  54.7954650] ipmi0: ID 32.1 IPMI 2.0 Available +SDRs
[  54.7955304] ipmi0: Additional Chassis Bridge IPMBRcv FRU SEL SDR Sensor
[  54.7956175] ipmi0: Manufacturer 002a2 Product 01a2
[  54.7956805] ipmi0: Firmware 3.2
[  54.7957271] config_pending_decr: ipmi0 0
[  54.7957843] ld0: holding up boot
### DELAY
[ 216.0106481] config_pending_incr: dk3 1
[ 216.0107207] config_pending_decr: dk3 0
[ 216.0108237] ld0: holding up boot
[ 216.0108758] dk3 at ld0: "primary", 3125624832 blocks at 2048, type: ntfs
[ 216.0109770] config_pending_decr: ld0 0
[ 216.0112442] config_pending_incr: swcrypto0 1
[ 216.0113031] crypto: assign driver 0, flags 2
[ 216.0113598] crypto: driver 0 registers alg 1 flags 0 maxoplen 0
[ 216.0114375] crypto: driver 0 registers alg 2 flags 0 maxoplen 0
[ 216.0115144] crypto: driver 0 registers alg 3 flags 0 maxoplen 0
[ 216.0115911] crypto: driver 0 registers alg 4 flags 0 maxoplen 0
[ 216.0116680] crypto: driver 0 registers alg 5 flags 0 maxoplen 0
[ 216.0117445] crypto: driver 0 registers alg 26 flags 0 maxoplen 0
[ 216.0118228] crypto: driver 0 registers alg 27 flags 0 maxoplen 0
[ 216.0119010] crypto: driver 0 registers alg 29 flags 0 maxoplen 0
[ 216.0119788] crypto: driver 0 registers alg 33 flags 0 maxoplen 0
[ 216.0120568] crypto: driver 0 registers alg 17 flags 0 maxoplen 0
[ 216.0121790] crypto: driver 0 registers alg 6 flags 0 maxoplen 0
[ 216.0122560] crypto: driver 0 registers alg 19 flags 0 maxoplen 0
[ 216.0123341] crypto: driver 0 registers alg 7 flags 0 maxoplen 0
[ 216.0124108] crypto: driver 0 registers alg 20 flags 0 maxoplen 0
[ 216.0124892] crypto: driver 0 registers alg 15 flags 0 maxoplen 0
[ 216.0125677] crypto: driver 0 registers alg 24 flags 0 maxoplen 0
[ 216.0126461] crypto: driver 0 registers alg 25 flags 0 maxoplen 0
[ 216.0127242] crypto: driver 0 registers alg 8 flags 0 maxoplen 0
[ 216.0128013] crypto: driver 0 registers alg 21 flags 0 maxoplen 0
[ 216.0128792] crypto: driver 0 registers alg 16 flags 0 maxoplen 0
[ 216.0129578] crypto: driver 0 registers alg 9 flags 0 maxoplen 0
[ 216.0130348] crypto: driver 0 registers alg 10 flags 0 maxoplen 0
[ 216.0131133] crypto: driver 0 registers alg 13 flags 0 maxoplen 0
[ 216.0131915] crypto: driver 0 registers alg 14 flags 0 maxoplen 0
[ 216.0132695] crypto: driver 0 registers alg 28 flags 0 maxoplen 0
[ 216.0133476] crypto: driver 0 registers alg 30 flags 0 maxoplen 0
[ 216.0134259] crypto: driver 0 registers alg 31 flags 0 maxoplen 0
[ 216.0135041] crypto: driver 0 registers alg 32 flags 0 maxoplen 0
[ 216.0136265] crypto: driver 0 registers alg 11 flags 0 maxoplen 0
[ 216.0137046] crypto: driver 0 registers alg 18 flags 0 maxoplen 0
[ 216.0137829] crypto: driver 0 registers alg 23 flags 0 maxoplen 0
[ 216.0138611] crypto: driver 0 registers alg 22 flags 0 maxoplen 0
[ 216.0139399] config_pending_decr: swcrypto0 0
[ 216.0140149] cgd: self-test aes-xts-256
[ 216.0141513] cgd: self-test aes-xts-512
[ 216.0142216] cgd: self-test aes-cbc-128
[ 216.0142903] cgd: self-test aes-cbc-256
[ 216.0143573] cgd: self-test 3des-cbc-192
[ 216.0144272] cgd: self-test blowfish-cbc-448
[ 216.0146578] cgd: self-test aes-cbc-128 (encblkno8)
[ 216.0147597] cgd: self-tests passed
[ 216.0149507] Searching for RAID components...
[ 216.0150100] dk0: scanning for RAID component (additional printf in rf_netbsdkintf.c)
[ 216.0181774] dk1: scanning for RAID component
[ 216.0221832] dk2: scanning for RAID component
[ 216.0262053] dk3: scanning for RAID component
### DELAY (dk3 is on ld0@nvme)
[ 638.0406144] ld0: scanning for RAID component
### DELAY (ld0 is nvme)
[ 3514.2205637] sd0: scanning for RAID component
[ 3514.2288368] boot device: dk0
[ 3514.2328566] root on dk0 dumps on dk2

>How-To-Repeat:
	Attempt to boot a XEN3_DOM0 kernel with xen 4.15 on a Dell R740. 
	Observe extremely slow nvme interactions.
	Boot without xen does not exhibit the issue and nvme performs
	with data rate > 1.8GB/s.
>Fix:
	?

>Unformatted: