NetBSD Problem Report #57266

From www@netbsd.org  Sat Mar 11 22:26:32 2023
Return-Path: <www@netbsd.org>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id EF2BE1A9239
	for <gnats-bugs@gnats.NetBSD.org>; Sat, 11 Mar 2023 22:26:31 +0000 (UTC)
Message-Id: <20230311222630.41A2A1A923A@mollari.NetBSD.org>
Date: Sat, 11 Mar 2023 22:26:30 +0000 (UTC)
From: bbartlomiej@gmail.com
Reply-To: bbartlomiej@gmail.com
To: gnats-bugs@NetBSD.org
Subject: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
X-Send-Pr-Version: www-1.0

>Number:         57266
>Category:       port-amd64
>Synopsis:       Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
>Confidential:   no
>Severity:       non-critical
>Priority:       high
>Responsible:    port-amd64-maintainer
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sat Mar 11 22:30:00 +0000 2023
>Last-Modified:  Tue Mar 14 07:40:01 +0000 2023
>Originator:     Bartek Krawczyk
>Release:        10.0_BETA
>Organization:
>Environment:
NetBSD netbsd.sol 10.0_BETA NetBSD 10.0_BETA (GENERIC) #0: Tue Mar  7 19:57:47 UTC 2023  mkrepro@mkrepro.NetBSD.org:/usr/src/sys/arch/amd64/compile/GENERIC amd64
>Description:
During the installation on VirtualBox 7.0 and using virtio-scsi in it (identified as vioscsi0 in NetBSD) the disk performance is abysmal. During installation downloading, extracting packages took ages. Unpacking pkgsrc in the installer took more than 30 minutes.

After installation and during compiling of devel/git, I get a lot of 

[  4197.011371] sd0(vioscsi0:0:0:0): adapter resource shortage
[  5134.201736] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)
[  5134.212605] sd0(vioscsi0:0:0:0): adapter resource shortage
[  5135.277596] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)
[  5135.277596] sd0(vioscsi0:0:0:0): adapter resource shortage
[  5136.340777] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)
[  5136.362106] sd0(vioscsi0:0:0:0): adapter resource shortage
[  5137.406205] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)
[  5137.406205] sd0(vioscsi0:0:0:0): adapter resource shortage

in the logs. This seems to resemble kern/52199 symptoms but supposedly that was already fixed?
>How-To-Repeat:
1. Try to install NetBSD 10.0_BETA in VirtualBox 7.0
2. Use virtio-scsi driver that gets recognized as vioscsi0 in NetBSD
3. Try to write to disk, for instance unpack pkgsrc distribution
>Fix:

>Audit-Trail:
From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
Date: Sat, 11 Mar 2023 23:08:44 -0000 (UTC)

 bbartlomiej@gmail.com writes:

 >[  4197.011371] sd0(vioscsi0:0:0:0): adapter resource shortage
 >[  5134.201736] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)

 vioscsi seems to allocate a too small queue, so it's "natural" to
 overflow it, and then that case isn't handled correctly by the
 driver.

 You should see a message like

   "cmd_per_lun %u qsize %d seg_max %u max_target %hu max_lun %u\n"

 The values come from VirtualBox. Can you please dump the values here?

From: =?UTF-8?B?SmFyb23DrXIgRG9sZcSNZWs=?= <jaromir.dolecek@gmail.com>
To: gnats-bugs@netbsd.org
Cc: port-amd64-maintainer@netbsd.org, gnats-admin@netbsd.org, 
	netbsd-bugs@netbsd.org
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 08:28:00 +0100

 Can you please post the full dmesg of the virtual machine?

 Can you also confirm what is the block size you used for the
 filesystem on the sd device?

 It's pretty odd that the incoming request from the SCSI subsystem
 passes a 128k I/O, that shouldn't really happen.
 The SCSI subsystem should enforce 64k minphys, but that might be done
 only for raw I/O, not block I/O as used for the actual filesystem
 operations with a buffer cache.

 Jaromir

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 11:18:44 +0100

 On 12/03/2023 00:10, Michael van Elst wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: mlelstv@serpens.de (Michael van Elst)
 > To: gnats-bugs@netbsd.org
 > Cc:
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
 > Date: Sat, 11 Mar 2023 23:08:44 -0000 (UTC)
 > 
 >   bbartlomiej@gmail.com writes:
 >   
 >   >[  4197.011371] sd0(vioscsi0:0:0:0): adapter resource shortage
 >   >[  5134.201736] vioscsi0: autoconfiguration error: error reserving 35 (nsegs 18)
 >   
 >   vioscsi seems to allocate a too small queue, so it's "natural" to
 >   overflow it, and then that case isn't handled correctly by the
 >   driver.
 >   
 >   You should see a message like
 >   
 >     "cmd_per_lun %u qsize %d seg_max %u max_target %hu max_lun %u\n"
 >   
 >   The values come from VirtualBox. Can you please dump the values here?
 >   

 It shows:
 messages:Mar 12 11:06:11 netbsd /netbsd: [   1.0546101] vioscsi0: 
 cmd_per_lun 128 qsize 1024 seg_max 126 max_target 2 max_lun 1

 I haven't changed anything in default VirtualBox configuration except 
 for picking the virtio drivers for network and storage since I noticed 
 they're available. Today I tested with PIIX4 instead of virtio-scsi and 
 logs didn't show any errors but unpacking pkgsrc also took ~30min. The 
 VM has 12 vCPUs (Ryzen 9 3900x) and ~16GB of RAM assigned.

 -- 
 Regards
 Bartek Krawczyk

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 11:31:54 +0100

 On 12/03/2023 08:30, Jaromír Doleček wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: =?UTF-8?B?SmFyb23DrXIgRG9sZcSNZWs=?= <jaromir.dolecek@gmail.com>
 > To: gnats-bugs@netbsd.org
 > Cc: port-amd64-maintainer@netbsd.org, gnats-admin@netbsd.org,
 > 	netbsd-bugs@netbsd.org
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 >   and NetBSD 10.0_BETA
 > Date: Sun, 12 Mar 2023 08:28:00 +0100
 > 
 >   Can you please post the full dmesg of the virtual machine?
 >   
 >   Can you also confirm what is the block size you used for the
 >   filesystem on the sd device?
 >   
 >   It's pretty odd that the incoming request from the SCSI subsystem
 >   passes a 128k I/O, that shouldn't really happen.
 >   The SCSI subsystem should enforce 64k minphys, but that might be done
 >   only for raw I/O, not block I/O as used for the actual filesystem
 >   operations with a buffer cache.

 In general this is purely default NetBSD 10.0_BETA installation. The 
 only options I changed is adding log, async and noatime to / mount in 
 the installer.

 I assume bsize = 16384 would mean it's 16k? Sorry I can't read dumpfs well.

 netbsd# dumpfs -s dk0
 file system: /dev/rdk0
 format  FFSv2
 endian  little-endian
 location 65536  (-b 128)
 magic   19540119        time    Sun Mar 12 11:23:05 2023
 superblock location     65536   id      [ 640cb8fc 1f74db7 ]
 nbfree  5132249 ndir    84014   nifree  10222212        nffree  7034
 ncg     466     size    44040160        blocks  42698036
 bsize   16384   shift   14      mask    0xffffc000
 fsize   2048    shift   11      mask    0xfffff800
 frag    8       shift   3       fsbtodb 2
 bpg     11814   fpg     94512   ipg     22912
 minfree 5%      optim   time    maxcontig 4     maxbpg  2048
 symlinklen 120  contigsumsize 4
 maxfilesize 0x000080100202ffff
 nindir  2048    inopb   64
 avgfilesize 16384       avgfpdir 64
 sblkno  40      cblkno  48      iblkno  56      dblkno  2920
 sbsize  2048    cgsize  16384
 csaddr  2920    cssize  8192
 cgrotor 0       fmod    0       ronly   0       clean   0x02
 wapbl version 0x1       location 2      flags 0x0
 wapbl loc0 88096960     loc1 131072     loc2 512        loc3 3
 usrquota 0      grpquota 0
 flags   wapbl
 fsmnt   /
 volname         swuid   0

 pkgsrc untar is taking 20min so far and it's not done yet.

 netbsd# iostat
         tty |______ sd0 _____| |______ dk0 _____| |______ dk1 _____| 
 |______ cd0 _____|              CPU
   tin  tout    t/s  KB/t  MB/s    t/s  KB/t  MB/s    t/s  KB/t  MB/s 
 t/s  KB/t  MB/s  us ni sy in  id
     1   672    272 2.702 0.717    272 2.702 0.717      0 1.571 0.000 
   0 0.000 0.000   0  0  8  2  90

 netbsd# mount
 /dev/dk0 on / type ffs (asynchronous, log, noatime, local)
 tmpfs on /tmp type tmpfs (local)
 kernfs on /kern type kernfs (local)
 ptyfs on /dev/pts type ptyfs (local)
 procfs on /proc type procfs (local)
 tmpfs on /var/shm type tmpfs (local)

 dmesg below after boot and some file operations (unpacking pkgsrc). :

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

 [     1.000000] NetBSD 10.0_BETA (GENERIC) #0: Tue Mar  7 19:57:47 UTC 2023
 [     1.000000] 
 mkrepro@mkrepro.NetBSD.org:/usr/src/sys/arch/amd64/compile/GENERIC
 [     1.000000] total memory = 16383 MB
 [     1.000000] avail memory = 15826 MB
 [     1.000000] timecounter: Timecounters tick every 10.000 msec
 [     1.000000] Kernelized RAIDframe activated
 [     1.000000] timecounter: Timecounter "i8254" frequency 1193182 Hz 
 quality 100
 [     1.000004] mainbus0 (root)
 [     1.000004] ACPI: RSDP 0x00000000000E0000 000024 (v02 VBOX  )
 [     1.000004] ACPI: XSDT 0x00000000DFFF0030 00003C (v01 VBOX 
 VBOXXSDT 00000001 ASL  00000061)
 [     1.000004] ACPI: FACP 0x00000000DFFF00F0 0000F4 (v04 VBOX 
 VBOXFACP 00000001 ASL  00000061)
 [     1.000004] ACPI: DSDT 0x00000000DFFF0660 002353 (v02 VBOX 
 VBOXBIOS 00000002 INTL 20100528)
 [     1.000004] ACPI: FACS 0x00000000DFFF0200 000040
 [     1.000004] ACPI: APIC 0x00000000DFFF0240 0000AC (v02 VBOX 
 VBOXAPIC 00000001 ASL  00000061)
 [     1.000004] ACPI: SSDT 0x00000000DFFF02F0 00036C (v01 VBOX 
 VBOXCPUT 00000002 INTL 20100528)
 [     1.000004] ACPI: 2 ACPI AML tables successfully acquired and loaded
 [     1.000004] ioapic0 at mainbus0 apid 12: pa 0xfec00000, version 
 0x20, 24 pins
 [     1.000004] cpu0 at mainbus0 apid 0
 [     1.000004] cpu0: Use mfence to serialize rdtsc
 [     1.000004] cpu0: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu0: node 0, package 0, core 0, smt 0
 [     1.000004] cpu1 at mainbus0 apid 1
 [     1.000004] cpu1: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu1: node 0, package 0, core 0, smt 1
 [     1.000004] cpu2 at mainbus0 apid 2
 [     1.000004] cpu2: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu2: node 0, package 0, core 0, smt 2
 [     1.000004] cpu3 at mainbus0 apid 3
 [     1.000004] cpu3: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu3: node 0, package 0, core 0, smt 3
 [     1.000004] cpu4 at mainbus0 apid 4
 [     1.000004] cpu4: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu4: node 0, package 0, core 0, smt 4
 [     1.000004] cpu5 at mainbus0 apid 5
 [     1.000004] cpu5: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu5: node 0, package 0, core 0, smt 5
 [     1.000004] cpu6 at mainbus0 apid 6
 [     1.000004] cpu6: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu6: node 0, package 0, core 0, smt 6
 [     1.000004] cpu7 at mainbus0 apid 7
 [     1.000004] cpu7: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu7: node 0, package 0, core 0, smt 7
 [     1.000004] cpu8 at mainbus0 apid 8
 [     1.000004] cpu8: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu8: node 0, package 0, core 1, smt 0
 [     1.000004] cpu9 at mainbus0 apid 9
 [     1.000004] cpu9: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu9: node 0, package 0, core 1, smt 1
 [     1.000004] cpu10 at mainbus0 apid 10
 [     1.000004] cpu10: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu10: node 0, package 0, core 1, smt 2
 [     1.000004] cpu11 at mainbus0 apid 11
 [     1.000004] cpu11: AMD Ryzen 9 3900X 12-Core Processor            , 
 id 0x870f10
 [     1.000004] cpu11: node 0, package 0, core 1, smt 3
 [     1.000004] acpi0 at mainbus0: Intel ACPICA 20221020
 [     1.000004] acpi0: X/RSDT: OemId <VBOX  ,VBOXXSDT,00000001>, AslId 
 <ASL ,00000061>
 [     1.000004] acpi0: SCI interrupting at int 9
 [     1.000004] acpi0: fixed power button present
 [     1.000004] acpi0: fixed sleep button present
 [     1.000004] timecounter: Timecounter "ACPI-Safe" frequency 3579545 
 Hz quality 900
 [     1.054610] pckbc1 at acpi0 (PS2K, PNP0303) (kbd port): io 0x60,0x64 
 irq 1
 [     1.054610] pckbc2 at acpi0 (PS2M, PNP0F03) (aux port): irq 12
 [     1.054610] attimer1 at acpi0 (TIMR, PNP0100): io 0x40-0x43,0x50-0x53
 [     1.054610] acpivga0 at acpi0 (GFX0): ACPI Display Adapter
 [     1.054610] acpiout0 at acpivga0 (VGA, 0x0100): ACPI Display Output 
 Device
 [     1.054610] acpivga0: connected output devices:
 [     1.054610] acpivga0:   0x0100 (acpiout0): VGA Analog Monitor, index 
 0, port 0, head 0
 [     1.054610] acpiacad0 at acpi0 (AC, ACPI0003-0): ACPI AC Adapter
 [     1.054610] ACPI: Enabled 2 GPEs in block 00 to 07
 [     1.054610] pckbd0 at pckbc1 (kbd slot)
 [     1.054610] pckbc1: using irq 1 for kbd slot
 [     1.054610] wskbd0 at pckbd0: console keyboard
 [     1.054610] pms0 at pckbc1 (aux slot)
 [     1.054610] pckbc1: using irq 12 for aux slot
 [     1.054610] wsmouse0 at pms0 mux 0
 [     1.054610] pci0 at mainbus0 bus 0: configuration mode 1
 [     1.054610] pci0: This pci host supports neither MSI nor MSI-X.
 [     1.054610] pci0: i/o space, memory space enabled, rd/line, rd/mult, 
 wr/inv ok
 [     1.054610] pchb0 at pci0 dev 0 function 0: Intel 82441FX (PMC) PCI 
 and Memory Controller (rev. 0x02)
 [     1.054610] pcib0 at pci0 dev 1 function 0: Intel 82371SB (PIIX3) 
 PCI-ISA Bridge (rev. 0x00)
 [     1.054610] vga0 at pci0 dev 2 function 0: VMware Virtual SVGA II 
 (rev. 0x00)
 [     1.054610] wsdisplay0 at vga0 kbdmux 1: console (80x25, vt100 
 emulation), using wskbd0
 [     1.054610] wsmux1: connecting to wsdisplay0
 [     1.054610] drm at vga0 not configured
 [     1.054610] virtio0 at pci0 dev 3 function 0
 [     1.054610] virtio0: network device (id 1, rev. 0x00)
 [     1.054610] vioif0 at virtio0: features: 
 0x70020<CTRL_RX,CTRL_VQ,STATUS,MAC>
 [     1.054610] vioif0: Ethernet address 08:00:27:f0:f4:01
 [     1.054610] virtio0: allocated 32768 byte for virtqueue 0 for rx0, 
 size 1024
 [     1.054610] virtio0: allocated 32768 byte for virtqueue 1 for tx0, 
 size 1024
 [     1.054610] virtio0: allocated 32768 byte for virtqueue 2 for 
 control, size 1024
 [     1.054610] virtio0: interrupting at ioapic0 pin 19
 [     1.054610] VirtualBox Guest Service (miscellaneous system) at pci0 
 dev 4 function 0 not configured
 [     1.054610] auich0 at pci0 dev 5 function 0: i82801AA (ICH) AC-97 Audio
 [     1.054610] auich0: interrupting at ioapic0 pin 21
 [     1.054610] auich0: ac97: SigmaTel STAC9700 codec; no 3D stereo
 [     1.054610] auich0: ac97: ext id 0x809<AC97_23,VRM,VRA>
 [     1.054610] ohci0 at pci0 dev 6 function 0: Apple Computer Intrepid 
 USB Controller (rev. 0x00)
 [     1.054610] ohci0: interrupting at ioapic0 pin 22
 [     1.054610] ohci0: OHCI version 1.0
 [     1.054610] usb0 at ohci0: USB revision 1.0
 [     1.054610] piixpm0 at pci0 dev 7 function 0: Intel 82371AB (PIIX4) 
 Power Management Controller (rev. 0x08)
 [     1.054610] piixpm0: interrupting at ioapic0 pin 23
 [     1.054610] iic0 at piixpm0 port 0: I2C bus
 [     1.054610] ehci0 at pci0 dev 11 function 0: Intel 82801FB/FR USB 
 EHCI Controller (rev. 0x00)
 [     1.054610] ehci0: 32-bit DMA
 [     1.054610] ehci0: interrupting at ioapic0 pin 19
 [     1.054610] ehci0: EHCI version 1.0
 [     1.054610] ehci0: Using DMA subregion for control data structures
 [     1.054610] usb1 at ehci0: USB revision 2.0
 [     1.054610] virtio1 at pci0 dev 15 function 0
 [     1.054610] virtio1: SCSI device (id 8, rev. 0x01)
 [     1.054610] vioscsi0 at virtio1: features: 0x100000000<V1>
 [     1.054610] virtio1: allocated 32768 byte for virtqueue 0 for 
 control, size 1024
 [     1.054610] virtio1: allocated 32768 byte for virtqueue 1 for event, 
 size 1024
 [     1.054610] virtio1: allocated 32768 byte for virtqueue 2 for 
 request, size 1024
 [     1.054610] vioscsi0: cmd_per_lun 128 qsize 1024 seg_max 126 
 max_target 2 max_lun 1
 [     1.054610] virtio1: interrupting at ioapic0 pin 23
 [     1.054610] scsibus0 at vioscsi0: 3 targets, 2 luns per target
 [     1.054610] isa0 at pcib0
 [     1.054610] pcppi0 at isa0 port 0x61
 [     1.054610] spkr0 at pcppi0: PC Speaker
 [     1.054610] wsbell at spkr0 not configured
 [     1.054610] midi0 at pcppi0: PC speaker
 [     1.054610] sysbeep0 at pcppi0
 [     1.054610] attimer1: attached to pcppi0
 [     1.054610] acpicpu0 at cpu0: ACPI CPU
 [     1.054610] acpicpu0: C1: HLT, lat   0 us, pow     0 mW
 [     1.054610] acpicpu1 at cpu1: ACPI CPU
 [     1.054610] acpicpu2 at cpu2: ACPI CPU
 [     1.054610] acpicpu3 at cpu3: ACPI CPU
 [     1.054610] acpicpu4 at cpu4: ACPI CPU
 [     1.054610] acpicpu5 at cpu5: ACPI CPU
 [     1.054610] acpicpu6 at cpu6: ACPI CPU
 [     1.054610] acpicpu7 at cpu7: ACPI CPU
 [     1.054610] acpicpu8 at cpu8: ACPI CPU
 [     1.054610] acpicpu9 at cpu9: ACPI CPU
 [     1.054610] acpicpu10 at cpu10: ACPI CPU
 [     1.054610] acpicpu11 at cpu11: ACPI CPU
 [     1.054610] timecounter: Timecounter "clockinterrupt" frequency 100 
 Hz quality 0
 [     1.707485] autoconfiguration error: ERROR: 245897 cycle TSC drift 
 observed
 [     1.717170] acpiacad0: AC adapter online.
 [     2.043085] auich0: measured ac97 link rate at 47956 Hz, will use 
 48000 Hz
 [     2.043085] audio0 at auich0: playback, capture, full duplex, 
 independent
 [     2.055215] audio0: slinear_le:16 2ch 48000Hz, blk 1920 bytes (10ms) 
 for playback
 [     2.055215] audio0: slinear_le:16 2ch 48000Hz, blk 1920 bytes (10ms) 
 for recording
 [     2.055215] spkr1 at audio0: PC Speaker (synthesized)
 [     2.055215] wsbell at spkr1 not configured
 [     2.068926] uhub0 at usb1: NetBSD (0x0000) EHCI root hub (0x0000), 
 class 9/0, rev 2.00/1.00, addr 1
 [     2.140225] uhub0: 12 ports with 12 removable, self powered
 [     2.167187] uhub1 at usb0: NetBSD (0x0000) OHCI root hub (0x0000), 
 class 9/0, rev 1.00/1.00, addr 1
 [     2.175684] uhub1: 12 ports with 12 removable, self powered
 [     2.188596] probe(vioscsi0:0:0:0): generic HBA error
 [     2.216483] sd0 at scsibus0 target 0 lun 0: <VBOX, HARDDISK, 1.0> 
 disk fixed
 [     2.238856] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.287573] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.309000] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.328392] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.349159] sd0: fabricating a geometry
 [     2.359268] sd0: 100 GB, 102400 cyl, 64 head, 32 sec, 512 bytes/sect 
 x 209715200 sectors
 [     2.392056] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.420403] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.471043] sd0(vioscsi0:0:0:0): IPsec: Initialized Security 
 Association Processing.
 [     2.522192] generic HBA error
 [     2.532429] sd0(vioscsi0:0:0:0): generic HBA error
 [     2.543512] sd0: fabricating a geometry
 [     2.573694] sd0: GPT GUID: f52cb2c3-30bf-42b6-9c35-128692d85b63
 [     2.583969] dk0 at sd0: "18f309b9-7f18-4803-b287-d5fad297777c", 
 176160640 blocks at 64, type: ffs
 [     2.593321] dk1 at sd0: "df82d37c-cb09-44bf-a91e-ed2ec2008d7d", 
 33554432 blocks at 176160704, type: swap
 [     2.613878] sd0: async, 8-bit transfers, tagged queueing
 [     2.634279] cd0 at scsibus0 target 1 lun 0: <VBOX, CD-ROM, 1.0> 
 cdrom removable
 [     2.655233] cd0: async, 8-bit transfers, tagged queueing
 [     2.664590] cd0(vioscsi0:0:1:0): generic HBA error
 [     2.797814] swwdog0: software watchdog initialized
 [     2.837489] WARNING: 1 error while detecting hardware; check system log.
 [     2.837489] boot device: sd0
 [     2.849541] root on dk0 dumps on dk1
 [     3.092213] /: replaying log to memory
 [     3.104665] root file system type: ffs
 [     3.104665] kern.module.path=/stand/amd64/10.0/modules
 [     3.123264] WARNING: NVRAM century is 12 but RTC year is 2023
 [     3.937373] /: replaying log to disk
 [    50.979056] cd0(vioscsi0:0:1:0): generic HBA error
 [    50.989299] cd0(vioscsi0:0:1:0): generic HBA error
 [    62.569283] wsdisplay0: screen 1 added (80x25, vt100 emulation)
 [    62.569283] wsdisplay0: screen 2 added (80x25, vt100 emulation)
 [    62.569283] wsdisplay0: screen 3 added (80x25, vt100 emulation)
 [    62.569283] wsdisplay0: screen 4 added (80x25, vt100 emulation)
 [   146.753100] cd0(vioscsi0:0:1:0): generic HBA error
 [   146.763761] cd0(vioscsi0:0:1:0): generic HBA error

 -- 
 Regards
 Bartek Krawczyk

From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 11:02:08 -0000 (UTC)

 bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:

 >It shows:
 >messages:Mar 12 11:06:11 netbsd /netbsd: [   1.0546101] vioscsi0: 
 >cmd_per_lun 128 qsize 1024 seg_max 126 max_target 2 max_lun 1

 If the possible 128 commands get queued, each should take at most 8
 queue entries (but with 64k blocks and 4k pages it can take 18 (or 17?)).

 >logs didn't show any errors but unpacking pkgsrc also took ~30min. The 
 >VM has 12 vCPUs (Ryzen 9 3900x) and ~16GB of RAM assigned.

 Unpacking pkgsrc can vary in time, I get natively:

 - 42s to a journaled ffs on NVME.
 - 10m to a not-journaled ffs on SATA HDD.

 So 30m is slower, but on a virtualized disk maybe not that much.
 A slow disk also makes the queue larger (and the risk to overflow it)
 which makes it even slower.

 I tried on qemu with vioscsi, but the queue was never large and unpacking
 pgksrc never overflowed it.

 [   1.0000070] vioscsi0: cmd_per_lun 128 qsize 256 seg_max 254 max_target 255 max_lun 16383


 To get some information on how fast your emulated disk is, you could
 compare the unpacking (lots of transactions) with reading the raw
 disk sequentially (bandwidth matters) using e.g.:

 dd if=/dev/rdk0 of=/dev/null bs=1024k count=10240

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 12:47:12 +0100

 On 12/03/2023 12:05, Michael van Elst wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: mlelstv@serpens.de (Michael van Elst)
 > To: gnats-bugs@netbsd.org
 > Cc:
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
 > Date: Sun, 12 Mar 2023 11:02:08 -0000 (UTC)
 > 
 >   bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:
 >   
 >   >It shows:
 >   >messages:Mar 12 11:06:11 netbsd /netbsd: [   1.0546101] vioscsi0:
 >   >cmd_per_lun 128 qsize 1024 seg_max 126 max_target 2 max_lun 1
 >   
 >   If the possible 128 commands get queued, each should take at most 8
 >   queue entries (but with 64k blocks and 4k pages it can take 18 (or 17?)).
 >   
 >   >logs didn't show any errors but unpacking pkgsrc also took ~30min. The
 >   >VM has 12 vCPUs (Ryzen 9 3900x) and ~16GB of RAM assigned.
 >   
 >   Unpacking pkgsrc can vary in time, I get natively:
 >   
 >   - 42s to a journaled ffs on NVME.
 >   - 10m to a not-journaled ffs on SATA HDD.
 >   
 >   So 30m is slower, but on a virtualized disk maybe not that much.
 >   A slow disk also makes the queue larger (and the risk to overflow it)
 >   which makes it even slower.
 >   
 >   I tried on qemu with vioscsi, but the queue was never large and unpacking
 >   pgksrc never overflowed it.
 >   
 >   [   1.0000070] vioscsi0: cmd_per_lun 128 qsize 256 seg_max 254 max_target 255 max_lun 16383
 >   
 >   
 >   To get some information on how fast your emulated disk is, you could
 >   compare the unpacking (lots of transactions) with reading the raw
 >   disk sequentially (bandwidth matters) using e.g.:
 >   
 >   dd if=/dev/rdk0 of=/dev/null bs=1024k count=10240
 >   

 The host (Windows) has a NVME disk WDC WDS100T2B0C-00PXH0 which in 
 general performs very well.

 netbsd# dd if=/dev/rdk0 of=/dev/null bs=1024k count=10240
 10240+0 records in
 10240+0 records out
 10737418240 bytes transferred in 58.141 secs (184678939 bytes/sec)

 -- 
 Regards
 Bartek Krawczyk

From: Robert Elz <kre@munnari.OZ.AU>
To: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
Cc: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
        netbsd-bugs@netbsd.org
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 20:00:16 +0700

     Date:        Sun, 12 Mar 2023 11:31:54 +0100
     From:        Bartek Krawczyk <bbartlomiej.mail@gmail.com>
     Message-ID:  <1326a107-6fbd-27df-c0d6-b7dd69fceddb@gmail.com>

   | In general this is purely default NetBSD 10.0_BETA installation. The 
   | only options I changed is adding log, async and noatime to / mount in 
   | the installer.

 That's a combination that makes no sense, and I thought had been made
 impossible, but you seem to have achieved it.

 "async" says "just do all I/O to buffers, in any order, write to the
 disc when necessary, in any order, filesystem consistency if the system
 shoukd crash before umount is not guaranteed, and is often a complete
 disaster".  I use that a lot for trash fikesystems I can just newfs if
 needed, but want to run as fast as possible - like /usr/obj.  I also use
 it for src/pkgsrc while unpacking as I can always newfs and start again
 if something goes wrong.   I'd never recommend it for root though.

 "log" delays meta-data writes, but keeps track of what should be done
 and in what order so the filesystem can be made consistent after a crash.

 Using neither causes meta-data to be written synchronously, and in order,
 so the filesystem should never become inconsistent.  Safe, but slow,
 particularly for things like unpacking pkgsrc, which is almost all meta-data
 operations (allocating inodes, making new directory entries, ...)

 Async and log are almost opposites in intent, both make the filesystem
 do meta-data ops faster than the default, but in dramatically different
 ways.  It is possible the system is simply ignoring both of them, and
 operating in safe slow mode.   If not, then almost anything might be
 happening internally.   Just don't do that.

 For root just use log.  Not async.   If you use a separate filesystem
 for pkgsrc, you can mount that async while unpacking.  That is then lots
 faster.  After the unpack is done, umount and mount again without async
 (you can use log, or not, as you like - once unpacked, pkgsrc should
 get few future changes, just perhaps occasional updates, so it doesn't
 make a lot of difference - put the work directories elsewhere.)

 kre

 ps: the noatime option is immaterial to all of this.

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: Robert Elz <kre@munnari.OZ.AU>
Cc: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 netbsd-bugs@netbsd.org
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Sun, 12 Mar 2023 19:06:31 +0100

 On 12/03/2023 14:00, Robert Elz wrote:
 >    | In general this is purely default NetBSD 10.0_BETA installation. The
 >    | only options I changed is adding log, async and noatime to / mount in
 >    | the installer.
 > 
 > That's a combination that makes no sense, and I thought had been made
 > impossible, but you seem to have achieved it.
 > 
 > "async" says "just do all I/O to buffers, in any order, write to the
 > disc when necessary, in any order, filesystem consistency if the system
 > shoukd crash before umount is not guaranteed, and is often a complete
 > disaster".  I use that a lot for trash fikesystems I can just newfs if
 > needed, but want to run as fast as possible - like /usr/obj.  I also use
 > it for src/pkgsrc while unpacking as I can always newfs and start again
 > if something goes wrong.   I'd never recommend it for root though.
 > 
 > "log" delays meta-data writes, but keeps track of what should be done
 > and in what order so the filesystem can be made consistent after a crash.
 > 
 > Using neither causes meta-data to be written synchronously, and in order,
 > so the filesystem should never become inconsistent.  Safe, but slow,
 > particularly for things like unpacking pkgsrc, which is almost all meta-data
 > operations (allocating inodes, making new directory entries, ...)
 > 
 > Async and log are almost opposites in intent, both make the filesystem
 > do meta-data ops faster than the default, but in dramatically different
 > ways.  It is possible the system is simply ignoring both of them, and
 > operating in safe slow mode.   If not, then almost anything might be
 > happening internally.   Just don't do that.
 > 
 > For root just use log.  Not async.   If you use a separate filesystem
 > for pkgsrc, you can mount that async while unpacking.  That is then lots
 > faster.  After the unpack is done, umount and mount again without async
 > (you can use log, or not, as you like - once unpacked, pkgsrc should
 > get few future changes, just perhaps occasional updates, so it doesn't
 > make a lot of difference - put the work directories elsewhere.)

 Thanks Robert for the insight.
 I tested with only "log" option added to /, and it takes:

 netbsd# time tar xf pkgsrc.tar.xz
       1594.28 real         5.69 user      1528.69 sys

 so 26 minutes.

 PS. the man page for mount says if both log and async are provided, 
 async is simply disregarded so it shouldn't have impacted my results.

 Is anybody else running a NetBSD 10.0_BETA VM and can confirm my 
 numbers? Default install, just "log" added on / mount point.

 -- 
 Regards
 Bartek Krawczyk

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org, bbartlomiej@gmail.com
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Mon, 13 Mar 2023 08:49:13 +0100

 On 12/03/2023 19:10, Bartek Krawczyk wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
 > To: Robert Elz <kre@munnari.OZ.AU>
 > Cc: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 >   netbsd-bugs@netbsd.org
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 >   and NetBSD 10.0_BETA
 > Date: Sun, 12 Mar 2023 19:06:31 +0100

 >   I tested with only "log" option added to /, and it takes:
 >   
 >   netbsd# time tar xf pkgsrc.tar.xz
 >         1594.28 real         5.69 user      1528.69 sys
 >   
 >   so 26 minutes.
 >   
 >   PS. the man page for mount says if both log and async are provided,
 >   async is simply disregarded so it shouldn't have impacted my results.
 >   
 >   Is anybody else running a NetBSD 10.0_BETA VM and can confirm my
 >   numbers? Default install, just "log" added on / mount point.

 I also created a Rocky 9 VM (RHEL 9) running on the same host (Windows + 
 VirtualBox 7.0) with the same virtio-scsi drivers in the hypervisor. 
 Default installation:

 [bartek@localhost ~]$ uname -a
 Linux localhost.localdomain 5.14.0-162.18.1.el9_1.x86_64 #1 SMP 
 PREEMPT_DYNAMIC Wed Mar 1 22:02:24 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

 [bartek@localhost ~]$ time tar xf pkgsrc.tar.xz

 real    0m54.657s
 user    0m12.333s
 sys     0m34.845s

 Also even downloading (virtio net driver) is much faster: 7MB/s vs 
 0,5MB/s on NetBSD but that is aprobably again constrained by slow disk I/O.

 Another VM on the same host using Windows WSL2 - Debian VM: 10s to 
 unpack pkgsrc.tar.zx

 -- 
 Regards
 Bartek Krawczyk

From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
Date: Mon, 13 Mar 2023 19:34:14 -0000 (UTC)

 bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:

 >Also even downloading (virtio net driver) is much faster: 7MB/s vs 
 >0,5MB/s on NetBSD but that is aprobably again constrained by slow disk I/O.

 I get about 7MB/s download, 25MB/s write to disk and finishing the untar
 task in 960 seconds. That's not virtualbox but qemu emulating
 an aarch64 CPU and which is completely CPU bound on the host (a 8 years
 old Xeon with SSD).

 N.B. the guest filesystem is mounted only with noatime option.

 So there must be something special with virtualbox.

From: Bartek Krawczyk <bbartlomiej.mail@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Tue, 14 Mar 2023 00:13:26 +0100

 On 13/03/2023 20:40, Michael van Elst wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: mlelstv@serpens.de (Michael van Elst)
 > To: gnats-bugs@netbsd.org
 > Cc:
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
 > Date: Mon, 13 Mar 2023 19:34:14 -0000 (UTC)
 > 
 >   bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:
 >   
 >   >Also even downloading (virtio net driver) is much faster: 7MB/s vs
 >   >0,5MB/s on NetBSD but that is aprobably again constrained by slow disk I/O.
 >   
 >   I get about 7MB/s download, 25MB/s write to disk and finishing the untar
 >   task in 960 seconds. That's not virtualbox but qemu emulating
 >   an aarch64 CPU and which is completely CPU bound on the host (a 8 years
 >   old Xeon with SSD).
 >   
 >   N.B. the guest filesystem is mounted only with noatime option.
 >   
 >   So there must be something special with virtualbox.
 >   

 Indeed there was, but not with VirtualBox but with Windows 11.
 Windows has Hyper-V tightly integrated nowadays and a lot of security 
 features are based on that.

 For others trying to run a NetBSD VM in Windows 10/11:
 1. Remove WSL2
 2. If you're using Pro or Enterprise edition, remove Hyper-V (Home 
 edition doesn't have it as a separate feature).
 3. In system Settings > Device Security > Core Isolation disable Memory 
 Integrity.
 These steps should disable or limit Hyper-V influence.

 This will allow VirtualBox and other hypervisors to fully utilize your 
 hardware. With Hyper-V running in the background, your other hypervisor 
 will fallback to slower mode (for instance a turtle icon in VirtualBox).

 Now unpacking pkgsrc takes 3,5 minutes instead of 25-30 and "iostat dk0" 
 shows more than 1.5MB/s while doing that.

 Thanks all for help!
 -- 
 Regards
 Bartek Krawczyk

From: mlelstv@serpens.de (Michael van Elst)
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
Date: Tue, 14 Mar 2023 04:00:00 -0000 (UTC)

 bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:

 >Indeed there was, but not with VirtualBox but with Windows 11.
 >Windows has Hyper-V tightly integrated nowadays and a lot of security 
 >features are based on that.

 But the question remains why this didn't affect other guests.

From: =?UTF-8?Q?Bart=c5=82omiej_Krawczyk?= <bbartlomiej@gmail.com>
To: gnats-bugs@netbsd.org, port-amd64-maintainer@netbsd.org,
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0
 and NetBSD 10.0_BETA
Date: Tue, 14 Mar 2023 08:38:23 +0100

 On 14/03/2023 05:05, Michael van Elst wrote:
 > The following reply was made to PR port-amd64/57266; it has been noted by GNATS.
 > 
 > From: mlelstv@serpens.de (Michael van Elst)
 > To: gnats-bugs@netbsd.org
 > Cc:
 > Subject: Re: port-amd64/57266: Poor disk performance on VirtualBox vioscsi0 and NetBSD 10.0_BETA
 > Date: Tue, 14 Mar 2023 04:00:00 -0000 (UTC)
 > 
 >   bbartlomiej.mail@gmail.com (Bartek Krawczyk) writes:
 >   
 >   >Indeed there was, but not with VirtualBox but with Windows 11.
 >   >Windows has Hyper-V tightly integrated nowadays and a lot of security
 >   >features are based on that.
 >   
 >   But the question remains why this didn't affect other guests.
 >   

 That's what threw me off. It impacted Linux guests much less with the 
 same VirtIO driver on the VirtualBox side. If I find anything else I'll 
 raise a bug upstream.
 Unless anybody has any idea what logs to gather from NetBSD?

 -- 
 Pozdrawiam
 Bartłomiej Krawczyk

NetBSD Home
NetBSD PR Database Search

(Contact us) $NetBSD: query-full-pr,v 1.47 2022/09/11 19:34:41 kim Exp $
$NetBSD: gnats_config.sh,v 1.9 2014/08/02 14:16:04 spz Exp $
Copyright © 1994-2023 The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.