WSL slow startup: PCI VMBus probing: Using version 0x10003

[joehays]

All,

After following the technique from @sryio in issue #5548

I get a new error that is still taking a long time. Here is a subset of the dmesg output right after startup.

[    0.287156] Run /init as init process
[    0.287467]   with arguments:
[    0.287758]     /init
[    0.287948]   with environment:
[    0.288333]     HOME=/
[    0.288740]     TERM=linux
[    0.288984]     WSL_ROOT_INIT=1
[    0.294590] scsi 0:0:0:0: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    0.305790] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    0.306271] scsi 0:0:0:1: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    0.306336] sd 0:0:0:0: [sda] 798352 512-byte logical blocks: (409 MB/390 MiB)
[    0.307616] sd 0:0:0:0: [sda] Write Protect is on
[    0.307841] sd 0:0:0:0: [sda] Mode Sense: 0f 00 80 00
[    0.308038] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    0.309651] sd 0:0:0:0: [sda] Attached SCSI disk
[    0.310093] EXT4-fs (sda): mounted filesystem without journal. Opts: (null). Quota mode: none.
[    0.314780] sd 0:0:0:1: Attached scsi generic sg1 type 0
[    0.315292] sd 0:0:0:1: [sdb] 16777224 512-byte logical blocks: (8.59 GB/8.00 GiB)
[    0.315547] sd 0:0:0:1: [sdb] 4096-byte physical blocks
[    0.315784] sd 0:0:0:1: [sdb] Write Protect is off
[    0.316127] sd 0:0:0:1: [sdb] Mode Sense: 0f 00 00 00
[    0.316654] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    0.318172] sd 0:0:0:1: [sdb] Attached SCSI disk
[    0.337014] Adding 8388608k swap on /dev/sdb.  Priority:-2 extents:1 across:8388608k
[    0.421459] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    0.493087] hv_pci f8075d2f-6e9e-4a13-ae8b-5553ecd73cd7: PCI VMBus probing: Using version 0x10003
[    0.494353] hv_pci f8075d2f-6e9e-4a13-ae8b-5553ecd73cd7: PCI host bridge to bus 6e9e:00
[    0.494639] pci_bus 6e9e:00: root bus resource [mem 0xc00000000-0xe00001fff window]
[    0.494814] pci_bus 6e9e:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.495319] pci 6e9e:00:00.0: [1af4:105a] type 00 class 0x088000
[    0.496799] pci 6e9e:00:00.0: reg 0x10: [mem 0xe00000000-0xe00000fff 64bit]
[    0.498294] pci 6e9e:00:00.0: reg 0x18: [mem 0xe00001000-0xe00001fff 64bit]
[    0.499626] pci 6e9e:00:00.0: reg 0x20: [mem 0xc00000000-0xdffffffff 64bit]
[    0.501916] pci_bus 6e9e:00: busn_res: [bus 00-ff] end is updated to 00
[    0.502185] pci 6e9e:00:00.0: BAR 4: assigned [mem 0xc00000000-0xdffffffff 64bit]
[    0.503253] pci 6e9e:00:00.0: BAR 0: assigned [mem 0xe00000000-0xe00000fff 64bit]
[    0.504436] pci 6e9e:00:00.0: BAR 2: assigned [mem 0xe00001000-0xe00001fff 64bit]
[    0.511130] virtiofs virtio2: Cache len: 0x200000000 @ 0xc00000000
[    0.594861] memmap_init_zone_device initialised 2097152 pages in 20ms
[    0.599305] FS-Cache: Duplicate cookie detected
[    0.599653] FS-Cache: O-cookie c=00000004 [p=00000002 fl=222 nc=0 na=1]
[    0.599842] FS-Cache: O-cookie d=00000000429fd3de{9P.session} n=00000000c9ff751e
[    0.600110] FS-Cache: O-key=[10] '34323934393337333530'
[    0.600252] FS-Cache: N-cookie c=00000005 [p=00000002 fl=2 nc=0 na=1]
[    0.605215] FS-Cache: N-cookie d=00000000429fd3de{9P.session} n=00000000a5e9f1e0
[    0.605417] FS-Cache: N-key=[10] '34323934393337333530'
[    0.626246] scsi 0:0:0:2: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    0.633268] sd 0:0:0:2: Attached scsi generic sg2 type 0
[    0.633606] sd 0:0:0:2: [sdc] 2147483648 512-byte logical blocks: (1.10 TB/1.00 TiB)
[    0.633802] sd 0:0:0:2: [sdc] 4096-byte physical blocks
[    0.633952] sd 0:0:0:2: [sdc] Write Protect is off
[    0.634092] sd 0:0:0:2: [sdc] Mode Sense: 0f 00 00 00
[    0.634285] sd 0:0:0:2: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    0.636199] sd 0:0:0:2: [sdc] Attached SCSI disk
[    0.644792] EXT4-fs (sdc): mounted filesystem with ordered data mode. Opts: discard,errors=remount-ro,data=ordered. Quota mode: none.
[    1.170371] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2b2c8e53fc7, max_idle_ns: 440795296122 ns
[    1.174965] clocksource: Switched to clocksource tsc
[   45.211733] hv_pci beb0d606-f148-4343-b159-8f0239691cf7: PCI VMBus probing: Using version 0x10003
[   45.213543] hv_pci beb0d606-f148-4343-b159-8f0239691cf7: PCI host bridge to bus f148:00
[   45.214541] pci_bus f148:00: root bus resource [mem 0x9ffe08000-0x9ffe0afff window]
[   45.214971] pci_bus f148:00: No busn resource found for root bus, will use [bus 00-ff]
[   45.215967] pci f148:00:00.0: [1af4:1049] type 00 class 0x010000
[   45.216884] pci f148:00:00.0: reg 0x10: [mem 0x9ffe08000-0x9ffe08fff 64bit]
[   45.217591] pci f148:00:00.0: reg 0x18: [mem 0x9ffe09000-0x9ffe09fff 64bit]
[   45.218542] pci f148:00:00.0: reg 0x20: [mem 0x9ffe0a000-0x9ffe0afff 64bit]
[   45.221451] pci_bus f148:00: busn_res: [bus 00-ff] end is updated to 00
[   45.221838] pci f148:00:00.0: BAR 0: assigned [mem 0x9ffe08000-0x9ffe08fff 64bit]
[   45.222604] pci f148:00:00.0: BAR 2: assigned [mem 0x9ffe09000-0x9ffe09fff 64bit]
[   45.223302] pci f148:00:00.0: BAR 4: assigned [mem 0x9ffe0a000-0x9ffe0afff 64bit]
[   45.340969] hv_pci a4d6480e-ce9a-429d-8b20-7abbc2968375: PCI VMBus probing: Using version 0x10003
[   45.342152] hv_pci a4d6480e-ce9a-429d-8b20-7abbc2968375: PCI host bridge to bus ce9a:00
[   45.342530] pci_bus ce9a:00: root bus resource [mem 0x9ffe0c000-0x9ffe0efff window]
[   45.342806] pci_bus ce9a:00: No busn resource found for root bus, will use [bus 00-ff]
[   45.343691] pci ce9a:00:00.0: [1af4:1049] type 00 class 0x010000
[   45.344501] pci ce9a:00:00.0: reg 0x10: [mem 0x9ffe0c000-0x9ffe0cfff 64bit]
[   45.345041] pci ce9a:00:00.0: reg 0x18: [mem 0x9ffe0d000-0x9ffe0dfff 64bit]
[   45.345625] pci ce9a:00:00.0: reg 0x20: [mem 0x9ffe0e000-0x9ffe0efff 64bit]
[   45.347737] pci_bus ce9a:00: busn_res: [bus 00-ff] end is updated to 00
[   45.348004] pci ce9a:00:00.0: BAR 0: assigned [mem 0x9ffe0c000-0x9ffe0cfff 64bit]
[   45.348517] pci ce9a:00:00.0: BAR 2: assigned [mem 0x9ffe0d000-0x9ffe0dfff 64bit]
[   45.349072] pci ce9a:00:00.0: BAR 4: assigned [mem 0x9ffe0e000-0x9ffe0efff 64bit]
[   45.610444] systemd-journald[58]: Received client request to flush runtime journal.
[   45.615311] systemd-journald[58]: File /var/log/journal/c4033985b6a04f41b11f4fc45ddc40b5/system.journal corrupted or uncleanly shut down, renaming and replacing.
[   47.378922] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.379537] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.379946] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.380369] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -2
[   47.381424] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.381812] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.382185] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -22
[   47.382656] misc dxg: dxgk: dxgkio_query_adapter_info: Ioctl failed: -2
[   48.913577] WSL (2): Creating login session for joehays
[   49.059293] hv_balloon: Max. dynamic memory size: 32610 MB
[   49.323373] systemd-journald[58]: File /var/log/journal/c4033985b6a04f41b11f4fc45ddc40b5/user-1000.journal corrupted or uncleanly shut down, renaming and replacing.

Zooming in you can see that the major chunk of time for startup was here,

[    1.174965] clocksource: Switched to clocksource tsc
[   45.211733] hv_pci beb0d606-f148-4343-b159-8f0239691cf7: PCI VMBus probing: Using version 0x10003

Googling around for wsl PCI VMBus probing did not shed much light... the closest where:

• https://bugs.launchpad.net/ubuntuwsl/+bug/1939235
• https://bathindahelper.com/t/finally-solved-ubuntu-linux-error-on-windows-11-or-win10/3613/2

but don't appear to be this issue...

Thoughts?

System Description:
WSL version: 2.0.9.0
Kernel version: 5.15.133.1-1
WSLg version: 1.0.59
MSRDC version: 1.2.4677
Direct3D version: 1.611.1-81528511
DXCore version: 10.0.25131.1002-220531-1700.rs-onecore-base2-hyp
Windows version: 10.0.19045.3930

Device name astrocyte
Processor 13th Gen Intel(R) Core(TM) i9-13900H 2.60 GHz
Installed RAM 64.0 GB (63.7 GB usable)
Device ID 93CDF4AC-164A-42B5-B0B8-019666C58CEC
Product ID 00329-00000-00003-AA350
System type 64-bit operating system, x64-based processor
Pen and touch Touch support with 10 touch points

Edition Windows 10 Enterprise
Version 22H2
Installed on ‎12/‎6/‎2023
OS build 19045.3930
Experience Windows Feature Experience Pack 1000.19053.1000.0

Name NVIDIA GeForce RTX 4080 Laptop GPU
PNP Device ID PCI\VEN_10DE&DEV_27A0&SUBSYS_0BDB1028&REV_A1\4&32DCE9B4&0&0008
Adapter Type NVIDIA GeForce RTX 4080 Laptop GPU, NVIDIA compatible
Adapter Description NVIDIA GeForce RTX 4080 Laptop GPU
Adapter RAM (1,048,576) bytes
Installed Drivers C:\windows\System32\DriverStore\FileRepository\nvdmsig.inf_amd64_58416624598bf658\nvldumdx.dll,C:\windows\System32\DriverStore\FileRepository\nvdmsig.inf_amd64_58416624598bf658\nvldumdx.dll,C:\windows\System32\DriverStore\FileRepository\nvdmsig.inf_amd64_58416624598bf658\nvldumdx.dll,C:\windows\System32\DriverStore\FileRepository\nvdmsig.inf_amd64_58416624598bf658\nvldumdx.dll
Driver Version 31.0.15.4633

[github-actions]

Hi I'm an AI powered bot that finds similar issues based off the issue title.

Please view the issues below to see if they solve your problem, and if the issue describes your problem please consider closing this one and thumbs upping the other issue to help us prioritize it. Thank you!

Open similar issues:

• wsl2 kernel not probing scsi disks asynchronously cause a slow booting (#6594), similarity score: 0.72
• WSL 2 slow startup (~10s from cold start) (#6765), similarity score: 0.71

Closed similar issues:

• WSL not being usable after computer startup when Fast Startup enabled (#6244), similarity score: 0.71

Note: You can give me feedback by thumbs upping or thumbs downing this comment.

[OneBlue]

/logs

[microsoft-github-policy-service]

Hello! Could you please provide more logs to help us better diagnose your issue?

To collect WSL logs, download and execute collect-wsl-logs.ps1 in an administrative powershell prompt:

Invoke-WebRequest -UseBasicParsing "https://raw.githubusercontent.com/microsoft/WSL/master/diagnostics/collect-wsl-logs.ps1" -OutFile collect-wsl-logs.ps1
Set-ExecutionPolicy Bypass -Scope Process -Force
.\collect-wsl-logs.ps1

The scipt will output the path of the log file once done.

Once completed please upload the output files to this Github issue.

Click here for more info on logging

If you choose to email these logs instead of attaching to the bug, please send them to wsl-gh-logs@microsoft.com with the number of the github issue in the subject, and in the message a link to your comment in the github issue.

Thank you!

[microsoft-github-policy-service]

This issue has been automatically closed since it has not had any author activity for the past 7 days. If you're still experiencing this issue please re-open it.

Thank you!