microsoft / WSL

Issues found on WSL
https://docs.microsoft.com/windows/wsl
MIT License
17.23k stars 811 forks source link

Failed to acquire global channel lock #9033

Closed Sarisan closed 2 months ago

Sarisan commented 1 year ago

Windows Version

Microsoft Windows [Version 10.0.22631.3593]

WSL Version

2.1.5.0

Are you using WSL 1 or WSL 2?

Kernel Version

5.15.146.1-2

Distro Version

Debian GNU/Linux trixie/sid

Other Software

No response

Repro Steps

Just run WSL like usual

Expected Behavior

To see no errors

Actual Behavior

Spam of "Failed to acquire global channel lock" messages

Diagnostic Logs

[    0.000000] Linux version 6.9.2-microsoft-quark-WSL2 (sarisan@GrayFox) (x86_64-linux-gnu-gcc (Debian 13.2.0-25) 13.2.0, GNU ld (GNU Binutils for Debian) 2.42) #1 SMP Mon May 27 12:22:03 MSK 2024
[    0.000000] Command line: initrd=\initrd.img WSL_ROOT_INIT=1 panic=-1 nr_cpus=16 hv_utils.timesync_implicit=1 console=hvc0 debug pty.legacy_count=0
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Centaur CentaurHauls
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000e0000-0x00000000000e0fff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000001fffff] ACPI data
[    0.000000] BIOS-e820: [mem 0x0000000000200000-0x00000000f7ffffff] usable
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x00000001ff5fffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] APIC: Static calls initialized
[    0.000000] DMI not present or invalid.
[    0.000000] Hypervisor detected: Microsoft Hyper-V
[    0.000000] Hyper-V: privilege flags low 0xae7f, high 0x3b8030, hints 0xa4e24, misc 0xe0bed7b2
[    0.000000] Hyper-V: Nested features: 0x3e0101
[    0.000000] Hyper-V: LAPIC Timer Frequency: 0x1e8480
[    0.000000] Hyper-V: Using hypercall for remote TLB flush
[    0.000000] clocksource: hyperv_clocksource_tsc_page: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns
[    0.000000] clocksource: hyperv_clocksource_msr: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns
[    0.000000] tsc: Detected 2112.007 MHz processor
[    0.000006] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000008] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000011] last_pfn = 0x1ff600 max_arch_pfn = 0x400000000
[    0.000028] MTRR map: 5 entries (4 fixed + 1 variable; max 20), built from 8 variable MTRRs
[    0.000030] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT
[    0.000058] last_pfn = 0xf8000 max_arch_pfn = 0x400000000
[    0.000067] Using GB pages for direct mapping
[    0.000068] Incomplete global flushes, disabling PCID
[    0.000464] RAMDISK: [mem 0x04235000-0x0440bfff]
[    0.000468] ACPI: Early table checksum verification disabled
[    0.000484] ACPI: RSDP 0x00000000000E0000 000024 (v02 VRTUAL)
[    0.000488] ACPI: XSDT 0x0000000000100000 000044 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.000493] ACPI: FACP 0x0000000000101000 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.000498] ACPI: DSDT 0x00000000001011B8 01E191 (v02 MSFTVM DSDT01   00000001 MSFT 05000000)
[    0.000501] ACPI: FACS 0x0000000000101114 000040
[    0.000504] ACPI: OEM0 0x0000000000101154 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.000506] ACPI: SRAT 0x000000000011F349 0003B0 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.000509] ACPI: APIC 0x000000000011F6F9 0000C8 (v04 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.000511] ACPI: Reserving FACP table memory at [mem 0x101000-0x101113]
[    0.000512] ACPI: Reserving DSDT table memory at [mem 0x1011b8-0x11f348]
[    0.000513] ACPI: Reserving FACS table memory at [mem 0x101114-0x101153]
[    0.000513] ACPI: Reserving OEM0 table memory at [mem 0x101154-0x1011b7]
[    0.000514] ACPI: Reserving SRAT table memory at [mem 0x11f349-0x11f6f8]
[    0.000514] ACPI: Reserving APIC table memory at [mem 0x11f6f9-0x11f7c0]
[    0.000685] Zone ranges:
[    0.000686]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000687]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.000688]   Normal   [mem 0x0000000100000000-0x00000001ff5fffff]
[    0.000689]   Device   empty
[    0.000690] Movable zone start for each node
[    0.000690] Early memory node ranges
[    0.000690]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.000692]   node   0: [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.000692]   node   0: [mem 0x0000000100000000-0x00000001ff5fffff]
[    0.000693] Initmem setup node 0 [mem 0x0000000000001000-0x00000001ff5fffff]
[    0.000819] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.000839] On node 0, zone DMA: 352 pages in unavailable ranges
[    0.011830] On node 0, zone Normal: 2560 pages in unavailable ranges
[    0.011880] ACPI: LAPIC_NMI (acpi_id[0x01] dfl dfl lint[0x1])
[    0.012086] IOAPIC[0]: apic_id 16, version 17, address 0xfec00000, GSI 0-23
[    0.012090] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.012095] ACPI: Using ACPI (MADT) for SMP configuration information
[    0.012096] TSC deadline timer available
[    0.012100] CPU topo: Max. logical packages:   1
[    0.012100] CPU topo: Max. logical dies:       1
[    0.012101] CPU topo: Max. dies per package:   1
[    0.012104] CPU topo: Max. threads per core:   2
[    0.012105] CPU topo: Num. cores per package:     8
[    0.012105] CPU topo: Num. threads per package:  16
[    0.012106] CPU topo: Allowing 16 present CPUs plus 0 hotplug CPUs
[    0.012117] random: crng init done
[    0.012122] [mem 0xf8000000-0xffffffff] available for PCI devices
[    0.012124] Booting paravirtualized kernel on Hyper-V
[    0.012126] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.018689] setup_percpu: NR_CPUS:256 nr_cpumask_bits:16 nr_cpu_ids:16 nr_node_ids:1
[    0.019576] percpu: Embedded 58 pages/cpu s198056 r8192 d31320 u262144
[    0.019582] pcpu-alloc: s198056 r8192 d31320 u262144 alloc=1*2097152
[    0.019585] pcpu-alloc: [0] 00 01 02 03 04 05 06 07 [0] 08 09 10 11 12 13 14 15
[    0.019598] Hyper-V: PV spinlocks enabled
[    0.019600] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.019602] Kernel command line: initrd=\initrd.img WSL_ROOT_INIT=1 panic=-1 nr_cpus=16 hv_utils.timesync_implicit=1 console=hvc0 debug pty.legacy_count=0
[    0.019661] Unknown kernel command line parameters "WSL_ROOT_INIT=1", will be passed to user space.
[    0.020902] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[    0.021520] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.021729] Built 1 zonelists, mobility grouping on.  Total pages: 2028589
[    0.021732] mem auto-init: stack:all(zero), heap alloc:off, heap free:off
[    0.021736] software IO TLB: area num 16.
[    0.043434] Memory: 4073328K/8245884K available (22528K kernel code, 2924K rwdata, 12768K rodata, 3708K init, 1148K bss, 265176K reserved, 0K cma-reserved)
[    0.043480] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
[    0.043507] ftrace: allocating 61179 entries in 239 pages
[    0.052783] ftrace: allocated 239 pages with 7 groups
[    0.053094] rcu: Hierarchical RCU implementation.
[    0.053095] rcu:     RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=16.
[    0.053097]  Rude variant of Tasks RCU enabled.
[    0.053097]  Tracing variant of Tasks RCU enabled.
[    0.053098] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.053098] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=16
[    0.053104] RCU Tasks Rude: Setting shift to 4 and lim to 1 rcu_task_cb_adjust=1.
[    0.053106] RCU Tasks Trace: Setting shift to 4 and lim to 1 rcu_task_cb_adjust=1.
[    0.055970] Using NULL legacy PIC
[    0.055972] NR_IRQS: 16640, nr_irqs: 552, preallocated irqs: 0
[    0.056015] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.056549] Console: colour dummy device 80x25
[    0.056562] ACPI: Core revision 20230628
[    0.056636] Failed to register legacy timer interrupt
[    0.056636] APIC: Switch to symmetric I/O mode setup
[    0.057942] x2apic enabled
[    0.060311] APIC: Switched APIC routing to: physical x2apic
[    0.060318] Hyper-V: Host Build 10.0.22621.3593-3-0
[    0.060321] Hyper-V: enabling crash_kexec_post_notifiers
[    0.060388] Hyper-V: Using IPI hypercalls
[    0.060391] APIC: send_IPI() replaced with hv_send_ipi()
[    0.060397] APIC: send_IPI_mask() replaced with hv_send_ipi_mask()
[    0.060399] APIC: send_IPI_mask_allbutself() replaced with hv_send_ipi_mask_allbutself()
[    0.060401] APIC: send_IPI_allbutself() replaced with hv_send_ipi_allbutself()
[    0.060402] APIC: send_IPI_all() replaced with hv_send_ipi_all()
[    0.060404] APIC: send_IPI_self() replaced with hv_send_ipi_self()
[    0.060492] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1e717f281b0, max_idle_ns: 440795248185 ns
[    0.060500] Calibrating delay loop (skipped), value calculated using timer frequency.. 4224.01 BogoMIPS (lpj=21120070)
[    0.060689] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[    0.060717] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.060718] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.060725] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.060726] Spectre V2 : Mitigation: Enhanced / Automatic IBRS
[    0.060727] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.060727] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT
[    0.060728] RETBleed: Mitigation: Enhanced IBRS
[    0.060729] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.060730] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[    0.060731] Register File Data Sampling: Vulnerable: No microcode
[    0.060747] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.060748] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.060749] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.060749] x86/fpu: Supporting XSAVE feature 0x800: 'Control-flow User registers'
[    0.060750] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.060751] x86/fpu: xstate_offset[11]:  832, xstate_sizes[11]:   16
[    0.060752] x86/fpu: Enabled xstate features 0x807, context size is 848 bytes, using 'compacted' format.
[    0.070497] Freeing SMP alternatives memory: 64K
[    0.070497] pid_max: default: 32768 minimum: 301
[    0.070497] LSM: initializing lsm=capability,landlock
[    0.070497] landlock: Up and running.
[    0.070497] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.070497] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.070497] smpboot: CPU0: 12th Gen Intel(R) Core(TM) i5-1240P (family: 0x6, model: 0x9a, stepping: 0x3)
[    0.070497] Performance Events: unsupported p6 CPU model 154 no PMU driver, software events only.
[    0.070497] signal: max sigframe size: 1776
[    0.070497] rcu: Hierarchical SRCU implementation.
[    0.070497] rcu:     Max phase no-delay instances is 1000.
[    0.070497] smp: Bringing up secondary CPUs ...
[    0.070497] smpboot: x86: Booting SMP configuration:
[    0.070497] .... node  #0, CPUs:        #2  #4  #6  #8 #10 #12 #14  #1  #3  #5  #7  #9 #11 #13 #15
[    0.070724] smp: Brought up 1 node, 16 CPUs
[    0.070729] smpboot: Total of 16 processors activated (67584.22 BogoMIPS)
[    0.074211] node 0 deferred pages initialised in 0ms
[    0.074211] devtmpfs: initialized
[    0.074211] x86/mm: Memory block size: 128MB
[    0.074211] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.074211] futex hash table entries: 4096 (order: 6, 262144 bytes, linear)
[    0.074211] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.074211] audit: initializing netlink subsys (disabled)
[    0.074211] audit: type=2000 audit(1716839381.010:1): state=initialized audit_enabled=0 res=1
[    0.074211] thermal_sys: Registered thermal governor 'step_wise'
[    0.074211] cpuidle: using governor menu
[    0.074211] PCI: Fatal: No config space access function found
[    0.080650] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
[    0.080809] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[    0.080811] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
[    0.080813] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[    0.080813] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
[    0.080865] raid6: skipped pq benchmark and selected avx2x4
[    0.080865] raid6: using avx2x2 recovery algorithm
[    0.080865] ACPI: Added _OSI(Module Device)
[    0.080865] ACPI: Added _OSI(Processor Device)
[    0.080865] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.080865] ACPI: Added _OSI(Processor Aggregator Device)
[    0.083494] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.083761] ACPI: _OSC evaluation for CPUs failed, trying _PDC
[    0.083761] ACPI: Interpreter enabled
[    0.083761] ACPI: PM: (supports S0 S5)
[    0.083761] ACPI: Using IOAPIC for interrupt routing
[    0.083761] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.083761] PCI: Using E820 reservations for host bridge windows
[    0.083761] ACPI: Enabled 2 GPEs in block 00 to 0F
[    0.083761] iommu: Default domain type: Translated
[    0.083761] iommu: DMA domain TLB invalidation policy: lazy mode
[    0.083761] SCSI subsystem initialized
[    0.083761] ACPI: bus type USB registered
[    0.083761] usbcore: registered new interface driver usbfs
[    0.083761] usbcore: registered new interface driver hub
[    0.083761] usbcore: registered new device driver usb
[    0.083761] pps_core: LinuxPPS API ver. 1 registered
[    0.083761] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.083761] PTP clock support registered
[    0.110505] hv_vmbus: Vmbus version:5.3
[    0.111249] PCI: Using ACPI for IRQ routing
[    0.111252] PCI: System does not support PCI
[    0.112760] clocksource: Switched to clocksource tsc-early
[    0.112853] hv_vmbus: Unknown GUID: 6e382d18-3336-4f4b-acc4-2b7703d4df4a
[    0.112862] hv_vmbus: Unknown GUID: dde9cbc0-5060-4436-9448-ea1254a5d177
[    0.112760] VFS: Disk quotas dquot_6.6.0
[    0.112760] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.112760] netfs: FS-Cache loaded
[    0.112760] pnp: PnP ACPI init
[    0.112760] pnp: PnP ACPI: found 1 devices
[    0.117137] NET: Registered PF_INET protocol family
[    0.117237] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.129622] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear)
[    0.129632] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.129635] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.129696] TCP bind hash table entries: 65536 (order: 9, 2097152 bytes, linear)
[    0.130061] TCP: Hash tables configured (established 65536 bind 65536)
[    0.130096] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    0.130108] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    0.130140] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.130816] RPC: Registered named UNIX socket transport module.
[    0.130818] RPC: Registered udp transport module.
[    0.130818] RPC: Registered tcp transport module.
[    0.130819] RPC: Registered tcp-with-tls transport module.
[    0.130819] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.130826] PCI: CLS 0 bytes, default 64
[    0.130847] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.130848] software IO TLB: mapped [mem 0x00000000f4000000-0x00000000f8000000] (64MB)
[    0.130896] kvm_intel: Using Hyper-V Enlightened VMCS
[    0.130976] Trying to unpack rootfs image as initramfs...
[    0.131802] Freeing initrd memory: 1884K
[    0.250784] kvm_amd: CPU 8 isn't AMD or Hygon
[    0.252634] Initialise system trusted keyrings
[    0.252736] workingset: timestamp_bits=46 max_order=21 bucket_order=0
[    0.252857] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.252958] NFS: Registering the id_resolver key type
[    0.252963] Key type id_resolver registered
[    0.252963] Key type id_legacy registered
[    0.252965] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.252967] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    0.253676] Key type cifs.idmap registered
[    0.253731] fuse: init (API version 7.40)
[    0.253850] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, no debug enabled
[    0.254183] 9p: Installing v9fs 9p2000 file system support
[    0.254193] ceph: loaded (mds proto 32)
[    0.260550] NET: Registered PF_ALG protocol family
[    0.260552] xor: automatically using best checksumming function   avx
[    0.260554] Key type asymmetric registered
[    0.260555] Asymmetric key parser 'x509' registered
[    0.260566] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[    0.261242] hv_vmbus: registering driver hv_pci
[    0.261512] hv_pci 79df1521-7961-466a-af16-cae756a79020: PCI VMBus probing: Using version 0x10004
[    0.262134] hv_pci 79df1521-7961-466a-af16-cae756a79020: PCI host bridge to bus 7961:00
[    0.262136] pci_bus 7961:00: root bus resource [mem 0x9ffe00000-0x9ffe02fff window]
[    0.262138] pci_bus 7961:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.262605] pci 7961:00:00.0: [1af4:1043] type 00 class 0x010000 conventional PCI endpoint
[    0.263046] pci 7961:00:00.0: BAR 0 [mem 0x9ffe00000-0x9ffe00fff 64bit]
[    0.263291] pci 7961:00:00.0: BAR 2 [mem 0x9ffe01000-0x9ffe01fff 64bit]
[    0.263592] pci 7961:00:00.0: BAR 4 [mem 0x9ffe02000-0x9ffe02fff 64bit]
[    0.265359] pci_bus 7961:00: busn_res: [bus 00-ff] end is updated to 00
[    0.265364] pci 7961:00:00.0: BAR 0 [mem 0x9ffe00000-0x9ffe00fff 64bit]: assigned
[    0.265565] pci 7961:00:00.0: BAR 2 [mem 0x9ffe01000-0x9ffe01fff 64bit]: assigned
[    0.265776] pci 7961:00:00.0: BAR 4 [mem 0x9ffe02000-0x9ffe02fff 64bit]: assigned
[    0.266285] hv_pci 0244d3b6-fe5b-4c56-9c48-69ebbbca57fa: PCI VMBus probing: Using version 0x10004
[    0.266703] hv_pci 0244d3b6-fe5b-4c56-9c48-69ebbbca57fa: PCI host bridge to bus fe5b:00
[    0.266705] pci_bus fe5b:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.266913] pci fe5b:00:00.0: [1414:008e] type 00 class 0x030200 conventional PCI endpoint
[    0.269384] pci_bus fe5b:00: busn_res: [bus 00-ff] end is updated to 00
[    0.269523] ACPI: AC: AC Adapter [AC1] (on-line)
[    0.269985] virtio-pci 7961:00:00.0: enabling device (0000 -> 0002)
[    0.270174] ACPI: battery: Slot [BAT1] (battery present)
[    0.272258] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.294075] Non-volatile memory driver v1.3
[    0.294084] ACPI: bus type drm_connector registered
[    0.294274] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[    0.295537] printk: legacy console [hvc0] enabled
[    0.297869] brd: module loaded
[    0.299487] loop: module loaded
[    0.302993] zram: Added device: zram0
[    0.303316] hv_vmbus: registering driver hv_storvsc
[    0.303820] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[    0.304799] scsi host0: storvsc_host_t
[    0.304937] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
[    0.305925] tun: Universal TUN/TAP device driver, 1.6
[    0.306679] PPP generic driver version 2.4.2
[    0.307177] PPP BSD Compression module registered
[    0.307413] PPP Deflate Compression module registered
[    0.307648] PPP MPPE Compression module registered
[    0.307822] NET: Registered PF_PPPOX protocol family
[    0.308055] usbcore: registered new interface driver cdc_ether
[    0.308467] usbcore: registered new interface driver cdc_ncm
[    0.308729] usbcore: registered new interface driver r8153_ecm
[    0.309294] hv_vmbus: registering driver hv_netvsc
[    0.309820] VFIO - User Level meta-driver version: 0.3
[    0.310130] usbcore: registered new interface driver cdc_acm
[    0.310398] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    0.310827] usbcore: registered new interface driver uas
[    0.311063] usbcore: registered new interface driver usb-storage
[    0.311413] usbcore: registered new interface driver ch341
[    0.311617] usbserial: USB Serial support registered for ch341-uart
[    0.311906] usbcore: registered new interface driver cp210x
[    0.312152] usbserial: USB Serial support registered for cp210x
[    0.312449] usbcore: registered new interface driver ftdi_sio
[    0.312759] usbserial: USB Serial support registered for FTDI USB Serial Device
[    0.313234] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[    0.313538] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 1
[    0.314400] vhci_hcd: created sysfs vhci_hcd.0
[    0.314888] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.09
[    0.315312] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.315670] usb usb1: Product: USB/IP Virtual Host Controller
[    0.316090] usb usb1: Manufacturer: Linux 6.9.2-microsoft-quark-WSL2 vhci_hcd
[    0.316643] usb usb1: SerialNumber: vhci_hcd.0
[    0.317119] hub 1-0:1.0: USB hub found
[    0.317349] hub 1-0:1.0: 8 ports detected
[    0.317756] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[    0.318224] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 2
[    0.318594] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    0.319095] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.09
[    0.319403] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.319679] usb usb2: Product: USB/IP Virtual Host Controller
[    0.319911] usb usb2: Manufacturer: Linux 6.9.2-microsoft-quark-WSL2 vhci_hcd
[    0.320187] usb usb2: SerialNumber: vhci_hcd.0
[    0.320482] hub 2-0:1.0: USB hub found
[    0.320646] hub 2-0:1.0: 8 ports detected
[    0.321025] hv_vmbus: registering driver hyperv_keyboard
[    0.321229] rtc_cmos 00:00: RTC can wake from S4
[    0.322683] rtc_cmos 00:00: registered as rtc0
[    0.323129] rtc_cmos 00:00: setting system clock to 2024-05-27T19:49:41 UTC (1716839381)
[    0.323498] rtc_cmos 00:00: alarms up to one month, 114 bytes nvram
[    0.323866] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
[    0.324305] hid: raw HID events driver (C) Jiri Kosina
[    0.324721] usbcore: registered new interface driver usbhid
[    0.324892] usbhid: USB HID core driver
[    0.325073] hv_utils: Registering HyperV Utility Driver
[    0.325279] hv_vmbus: registering driver hv_utils
[    0.325471] hv_vmbus: registering driver hv_balloon
[    0.325788] hv_utils: TimeSync IC version 4.0
[    0.326047] hv_vmbus: registering driver dxgkrnl
[    0.326188] hv_balloon: Using Dynamic Memory protocol version 2.0
[    0.327443] drop_monitor: Initializing network drop monitor service
[    0.327893] Mirror/redirect action on
[    0.328032] Free page reporting enabled
[    0.328178] u32 classifier
[    0.328363] hv_balloon: Cold memory discard hint enabled with order 9
[    0.328484]     Performance counters on
[    0.329000]     input device check on
[    0.329194]     Actions configured
[    0.330789] IPVS: Registered protocols (TCP, UDP)
[    0.331176] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[    0.331591] IPVS: ipvs loaded.
[    0.331765] IPVS: [rr] scheduler registered.
[    0.331984] IPVS: [wrr] scheduler registered.
[    0.332206] IPVS: [sh] scheduler registered.
[    0.332606] ipip: IPv4 and MPLS over IPv4 tunneling driver
[    0.332951] Initializing XFRM netlink socket
[    0.333226] NET: Registered PF_INET6 protocol family
[    0.333730] Segment Routing with IPv6
[    0.333890] In-situ OAM (IOAM) with IPv6
[    0.334069] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.334391] NET: Registered PF_PACKET protocol family
[    0.334582] Bridge firewalling registered
[    0.334723] 8021q: 802.1Q VLAN Support v1.8
[    0.334853] sctp: Hash tables configured (bind 256/256)
[    0.335053] 9pnet: Installing 9P2000 support
[    0.335285] Key type dns_resolver registered
[    0.335473] Key type ceph registered
[    0.335727] libceph: loaded (mon/osd proto 15/24)
[    0.336027] NET: Registered PF_VSOCK protocol family
[    0.336305] hv_vmbus: registering driver hv_sock
[    0.337673] IPI shorthand broadcast: enabled
[    0.339102] sched_clock: Marking stable (333600936, 4031648)->(361152006, -23519422)
[    0.339992] Timer migration: 2 hierarchy levels; 8 children per group; 2 crossnode level
[    0.341031] registered taskstats version 1
[    0.341878] Loading compiled-in X.509 certificates
[    0.343714] Btrfs loaded, zoned=no, fsverity=no
[    0.344074] Running certificate verification selftests
[    0.344883] Loaded X.509 cert 'Certificate verification self-testing key: f58703bb33ce1b73ee02eccdee5b8817518fe3db'
[    0.357250] clk: Disabling unused clocks
[    0.359426] Freeing unused kernel image (initmem) memory: 3708K
[    0.360108] Write protecting the kernel read-only data: 36864k
[    0.361742] Freeing unused kernel image (rodata/data gap) memory: 1568K
[    0.362353] Run /init as init process
[    0.362645]   with arguments:
[    0.362874]     /init
[    0.363013]   with environment:
[    0.363301]     HOME=/
[    0.363541]     TERM=linux
[    0.363800]     WSL_ROOT_INIT=1
[    0.368399] scsi 0:0:0:0: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    0.370310] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    0.370353] sd 0:0:0:0: [sda] 795664 512-byte logical blocks: (407 MB/389 MiB)
[    0.371404] sd 0:0:0:0: [sda] Write Protect is on
[    0.371855] sd 0:0:0:0: [sda] Mode Sense: 0f 00 80 00
[    0.372469] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    0.373070] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#1093 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    0.634562] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#1100 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    0.699520] sd 0:0:0:0: [sda] Attached SCSI disk
[    1.056216] EXT4-fs (sda): mounted filesystem 00000000-0000-0000-0000-000000000000 ro without journal. Quota mode: none.
[    1.254327] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e717f281b0, max_idle_ns: 440795248185 ns
[    1.258220] clocksource: Switched to clocksource tsc
[    1.433688] hv_pci f8216462-f1c5-4187-89c6-731d07528ddb: PCI VMBus probing: Using version 0x10004
[    1.435276] hv_pci f8216462-f1c5-4187-89c6-731d07528ddb: PCI host bridge to bus f1c5:00
[    1.435699] pci_bus f1c5:00: root bus resource [mem 0xa00000000-0xc00001fff window]
[    1.435981] pci_bus f1c5:00: No busn resource found for root bus, will use [bus 00-ff]
[    1.436834] pci f1c5:00:00.0: [1af4:105a] type 00 class 0x088000 conventional PCI endpoint
[    1.437633] pci f1c5:00:00.0: BAR 0 [mem 0xc00000000-0xc00000fff 64bit]
[    1.438223] pci f1c5:00:00.0: BAR 2 [mem 0xc00001000-0xc00001fff 64bit]
[    1.438722] pci f1c5:00:00.0: BAR 4 [mem 0xa00000000-0xbffffffff 64bit]
[    1.441201] pci_bus f1c5:00: busn_res: [bus 00-ff] end is updated to 00
[    1.441701] pci f1c5:00:00.0: BAR 4 [mem 0xa00000000-0xbffffffff 64bit]: assigned
[    1.442204] pci f1c5:00:00.0: BAR 0 [mem 0xc00000000-0xc00000fff 64bit]: assigned
[    1.442696] pci f1c5:00:00.0: BAR 2 [mem 0xc00001000-0xc00001fff 64bit]: assigned
[    1.443212] virtio-pci f1c5:00:00.0: enabling device (0000 -> 0002)
[    1.452449] virtiofs virtio1: Cache len: 0x200000000 @ 0xa00000000
[    3.014767] scsi 0:0:0:1: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    3.020235] sd 0:0:0:1: Attached scsi generic sg1 type 0
[    3.020637] sd 0:0:0:1: [sdb] 16777224 512-byte logical blocks: (8.59 GB/8.00 GiB)
[    3.021552] scsi 0:0:0:2: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    3.021801] sd 0:0:0:1: [sdb] 4096-byte physical blocks
[    3.021990] sd 0:0:0:1: [sdb] Write Protect is off
[    3.022983] sd 0:0:0:1: [sdb] Mode Sense: 0f 00 00 00
[    3.023648] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    3.023873] sd 0:0:0:2: Attached scsi generic sg2 type 0
[    3.024283] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#1258 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    3.024409] sd 0:0:0:2: [sdc] 536870912 512-byte logical blocks: (275 GB/256 GiB)
[    3.025412] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#6 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    3.025906] sd 0:0:0:2: [sdc] 4096-byte physical blocks
[    3.026886] sd 0:0:0:1: [sdb] Attached SCSI disk
[    3.027250] sd 0:0:0:2: [sdc] Write Protect is off
[    3.027886] sd 0:0:0:2: [sdc] Mode Sense: 0f 00 00 00
[    3.028346] sd 0:0:0:2: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    3.028993] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#1107 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    3.030267] hv_storvsc fd1d2cbd-ce7c-535c-966b-eb5f811c95f0: tag#1114 cmd 0x5a status: scsi 0x2 srb 0x86 hv 0xc0000001
[    3.031487] sd 0:0:0:2: [sdc] Attached SCSI disk
[    3.138987] Adding 8388608k swap on /dev/sdb.  Priority:-2 extents:1 across:8388608k
[    3.170330] EXT4-fs (sdc): mounted filesystem 80f569ab-03a9-44cb-b9d6-8520798d2b4c r/w with ordered data mode. Quota mode: none.
[    3.802480] misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock
[   38.994322] TCP: eth0: Driver has suspect GRO implementation, TCP performance may be compromised.
[   49.149120] hv_balloon: Max. dynamic memory size: 8054 MB
[  268.813437] misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock
[ 1379.662008] misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock

I see the same behavior with the default kernel version either

benhillis commented 1 year ago

I think the dxg print may not be related to why the PCI devices cannot be accessed. Would need to look at logs of what's happening on the host:

/logs

ghost commented 1 year ago

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

Thank you!

Sarisan commented 1 year ago

WslLogs-2022-10-19_01-12-22.zip

dfisk commented 1 year ago

I am getting the same dmesg dgx print error on Windows Server 2022, version 21H2 build 203487.1364. It is the last entry after Ubuntu install and occurs after every invocation of nvidia-smi (post installing CUDA 12 with a GPU). The nvidia-smi command returns: Failed to initialize NVML: GPU access blocked by the operating system Failed to properly shut down NVML: GPU access blocked by the operating system

dfisk commented 1 year ago

This Event looks relevant: Failed to map guest I/O buffer for read access with status 0xC00000A1. Device name = C:\Users\Administrator\AppData\Local\Packages\CanonicalGroupLimited.UbuntuonWindows_79rhkp1fndgsc\LocalState\ext4.vhdx

Log Name:      Microsoft-Windows-Hyper-V-StorageVSP-Admin
Source:        Microsoft-Windows-Hyper-V-StorageVSP
Date:          12/22/2022 9:36:05 AM
Event ID:      7
Task Category: None
Level:         Error
Keywords:      
User:          NT VIRTUAL MACHINE\B1BEBEFC-AB0B-403F-82C4-96968F5306CB
Computer:      WIN-3UDMJ4TFN2C
Description:
Failed to map guest I/O buffer for read access with status 0xC00000A1. Device name = C:\Users\Administrator\AppData\Local\Packages\CanonicalGroupLimited.UbuntuonWindows_79rhkp1fndgsc\LocalState\ext4.vhdx
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Microsoft-Windows-Hyper-V-StorageVSP" Guid="{10b3d268-9782-49a4-aacc-a93c5482cb6f}" />
    <EventID>7</EventID>
    <Version>0</Version>
    <Level>2</Level>
    <Task>0</Task>
    <Opcode>0</Opcode>
    <Keywords>0x8000000000000000</Keywords>
    <TimeCreated SystemTime="2022-12-22T17:36:05.1060509Z" />
    <EventRecordID>3</EventRecordID>
    <Correlation />
    <Execution ProcessID="11204" ThreadID="10076" />
    <Channel>Microsoft-Windows-Hyper-V-StorageVSP-Admin</Channel>
    <Computer>WIN-3UDMJ4TFN2C</Computer>
    <Security UserID="S-1-5-83-1-2982067964-1077914379-2526463106-3406189455" />
  </System>
  <EventData>
    <Data Name="DeviceName">C:\Users\Administrator\AppData\Local\Packages\CanonicalGroupLimited.UbuntuonWindows_79rhkp1fndgsc\LocalState\ext4.vhdx</Data>
    <Data Name="Status">3221225633</Data>
  </EventData>
</Event> 
geole commented 1 year ago

Hello, i have probably the same problem This is my wsl collect WslLogs-2023-03-07_19-11-24.zip

i have also a Journal.txt ubuntu journalog I can do another test.

geole commented 1 year ago

Hello Last Errors journalctl -p err -n 5 Mar 10 13:43:38 DESKTOP-71NRFPV kernel: misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock Mar 10 13:55:40 DESKTOP-71NRFPV kernel: misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock Mar 10 13:55:41 DESKTOP-71NRFPV gnome-session-binary[11450]: Unrecoverable failure in required component org.gnome.Shell.desktop Mar 10 14:00:14 DESKTOP-71NRFPV kernel: misc dxg: dxgk: dxgglobal_acquire_channel_lock: Failed to acquire global channel lock Mar 10 14:00:14 DESKTOP-71NRFPV gnome-session-binary[11843]: Unrecoverable failure in required component org.gnome.Shell.desktop a@DESKTOP-71NRFPV:~$

Journal trace of last connexion Trace.txt

wizpresso-steve-cy-fan commented 1 year ago

We also saw this issue popping off for #10357. Consider the relevant parts of kernel driver:

    down_read(&dxgglobal->channel_lock);
    if (dxgglobal->channel.channel == NULL) {
        DXG_ERR("Failed to acquire global channel lock");
        return -ENODEV;
    } else {
        return 0;
    }

https://github.com/microsoft/WSL2-Linux-Kernel/blob/12802bc3d28e15a13881c8edaef28238fd44c90d/drivers/hv/dxgkrnl/dxgmodule.c#L49C2-L55

It seems like dxgglobal->channel.channel. This means we don't even have a dxgkrnl IPC channel from Hyper-V.

But it actually makes sense, here's why: image

And so there is no VMBus communication whatsoever without the virtual PCIE device. We also observed the same thing with @dfisk.

Sarisan commented 2 months ago

https://github.com/microsoft/WSL2-Linux-Kernel/commit/423e5044c57566f8267bbb20cf7cf57d1aefb040