microsoft / WSL

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

import tar fails Unspecified error E_FAIL bsdtar oom-kill #9669

Closed msci-madager closed 1 year ago

msci-madager commented 1 year ago

Version

10.0.19044.2604

WSL Version

Kernel Version

5.15.79.1

Distro Version

Ubuntu 20.04.5 LTS

Other Software

No response

Repro Steps

wsl --shutdown wsl --import test .\ .\dev-machine-wsl.tar --version 2

Expected Behavior

Completion successfully. A vhdx image gets created.

Actual Behavior

Failure reported. Out of 10 import command 6-7 times below failure occurs, the remaining 3-4 times completes successfully.

Import in progress, this may take a few minutes.
Unspecified error
Error code: Wsl/Service/E_FAIL

Diagnostic Logs

wsl -v
WSL version: 1.0.3.0
Kernel version: 5.15.79.1
WSLg version: 1.0.47
MSRDC version: 1.2.3575
Direct3D version: 1.606.4
DXCore version: 10.0.25131.1002-220531-1700.rs-onecore-base2-hyp
Windows version: 10.0.19044.2604

tar has size of 5.6G, can be reproduced other similar sized file

Mode                 LastWriteTime         Length Name
----                 -------------         ------ ----
-a----        11/21/2022   4:08 PM     5621934592 dev-machine-wsl.tar
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] Hypervisor detected: Microsoft Hyper-V
[    0.000000] Hyper-V: privilege flags low 0x2e7f, high 0x3b8030, hints 0x20e24, misc 0x20bed7b6
[    0.000000] Hyper-V Host Build:19041-10.0-2-0.2604
[    0.000000] Hyper-V: Nested features: 0x0
[    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.000003] tsc: Marking TSC unstable due to running on Hyper-V
[    0.002840] tsc: Detected 2712.000 MHz processor
[    0.005108] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.008263] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.010883] last_pfn = 0x1288200 max_arch_pfn = 0x400000000
[    0.013345] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT
[    0.016747] last_pfn = 0xf8000 max_arch_pfn = 0x400000000
[    0.019934] Using GB pages for direct mapping
[    0.022487] RAMDISK: [mem 0x03a35000-0x03c0efff]
[    0.024678] ACPI: Early table checksum verification disabled
[    0.027341] ACPI: RSDP 0x00000000000E0000 000024 (v02 VRTUAL)
[    0.030132] ACPI: XSDT 0x0000000000100000 000044 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.034697] ACPI: FACP 0x0000000000101000 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.039108] ACPI: DSDT 0x00000000001011B8 01E184 (v02 MSFTVM DSDT01   00000001 MSFT 05000000)
[    0.043227] ACPI: FACS 0x0000000000101114 000040
[    0.045544] ACPI: OEM0 0x0000000000101154 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.049726] ACPI: SRAT 0x000000000011F33C 000270 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.054267] ACPI: APIC 0x000000000011F5AC 000078 (v04 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.058203] ACPI: Reserving FACP table memory at [mem 0x101000-0x101113]
[    0.061448] ACPI: Reserving DSDT table memory at [mem 0x1011b8-0x11f33b]
[    0.065012] ACPI: Reserving FACS table memory at [mem 0x101114-0x101153]
[    0.068330] ACPI: Reserving OEM0 table memory at [mem 0x101154-0x1011b7]
[    0.071405] ACPI: Reserving SRAT table memory at [mem 0x11f33c-0x11f5ab]
[    0.074579] ACPI: Reserving APIC table memory at [mem 0x11f5ac-0x11f623]
[    0.078251] Zone ranges:
[    0.079436]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.082805]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.085573]   Normal   [mem 0x0000000100000000-0x00000012881fffff]
[    0.088296]   Device   empty
[    0.089589] Movable zone start for each node
[    0.091611] Early memory node ranges
[    0.093238]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.096370]   node   0: [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.099470]   node   0: [mem 0x0000000100000000-0x00000009ffdfffff]
[    0.102438]   node   0: [mem 0x0000001000000000-0x00000012881fffff]
[    0.105219] Initmem setup node 0 [mem 0x0000000000001000-0x00000012881fffff]
[    0.108871] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.108902] On node 0, zone DMA: 352 pages in unavailable ranges
[    0.125502] On node 0, zone Normal: 512 pages in unavailable ranges
[    0.128816] On node 0, zone Normal: 32256 pages in unavailable ranges
[    0.132107] ACPI: LAPIC_NMI (acpi_id[0x01] dfl dfl lint[0x1])
[    0.137725] IOAPIC[0]: apic_id 6, version 17, address 0xfec00000, GSI 0-23
[    0.141050] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.143951] ACPI: Using ACPI (MADT) for SMP configuration information
[    0.146969] smpboot: Allowing 6 CPUs, 0 hotplug CPUs
[    0.149194] [mem 0xf8000000-0xffffffff] available for PCI devices
[    0.151945] Booting paravirtualized kernel on Hyper-V
[    0.154154] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.164936] setup_percpu: NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:6 nr_node_ids:1
[    0.168665] percpu: Embedded 53 pages/cpu s177496 r8192 d31400 u262144
[    0.171570] pcpu-alloc: s177496 r8192 d31400 u262144 alloc=1*2097152
[    0.174462] pcpu-alloc: [0] 0 1 2 3 4 5 - -
[    0.176888] Hyper-V: PV spinlocks enabled
[    0.179324] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.182960] Built 1 zonelists, mobility grouping on.  Total pages: 12901381
[    0.186373] Kernel command line: initrd=\initrd.img WSL_ROOT_INIT=1 panic=-1 nr_cpus=6 swiotlb=force earlycon=uart8250,io,0x3f8,115200 console=hvc0 debug pty.legacy_count=0
[    0.193673] Unknown kernel command line parameters "WSL_ROOT_INIT=1", will be passed to user space.
[    0.211902] Dentry cache hash table entries: 8388608 (order: 14, 67108864 bytes, linear)
[    0.221037] Inode-cache hash table entries: 4194304 (order: 13, 33554432 bytes, linear)
[    0.225289] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.258373] Memory: 4081496K/52427388K available (18452K kernel code, 2627K rwdata, 9760K rodata, 2028K init, 1876K bss, 1032800K reserved, 0K cma-reserved)
[    0.264869] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=6, Nodes=1
[    0.267746] ftrace: allocating 54585 entries in 214 pages
[    0.294571] ftrace: allocated 214 pages with 5 groups
[    0.297150] rcu: Hierarchical RCU implementation.
[    0.299386] rcu:     RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=6.
[    0.302475]  Rude variant of Tasks RCU enabled.
[    0.304498]  Tracing variant of Tasks RCU enabled.
[    0.306684] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.310127] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=6
[    0.317758] Using NULL legacy PIC
[    0.319129] NR_IRQS: 16640, nr_irqs: 472, preallocated irqs: 0
[    0.321830] random: crng init done
[    0.323222] Console: colour dummy device 80x25
[    0.325313] ACPI: Core revision 20210730
[    0.327204] Failed to register legacy timer interrupt
[    0.329597] APIC: Switch to symmetric I/O mode setup
[    0.332022] Hyper-V: Using IPI hypercalls
[    0.333934] Calibrating delay loop (skipped), value calculated using timer frequency.. 5424.00 BogoMIPS (lpj=27120000)
[    0.338702] pid_max: default: 32768 minimum: 301
[    0.340741] LSM: Security Framework initializing
[    0.342975] landlock: Up and running.
[    0.343930] Mount-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.343930] Mountpoint-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.343930] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.343930] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.343930] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.343930] Spectre V2 : Mitigation: Enhanced IBRS
[    0.343930] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.343930] Spectre V2 : Spectre v2 / PBRSB-eIBRS: Retire a single CALL on VMEXIT
[    0.343930] RETBleed: Mitigation: Enhanced IBRS
[    0.343930] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.343930] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.343930] MMIO Stale Data: Vulnerable: Clear CPU buffers attempted, no microcode
[    0.343930] SRBDS: Unknown: Dependent on hypervisor status
[    0.343930] Freeing SMP alternatives memory: 60K
[    0.343930] smpboot: CPU0: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz (family: 0x6, model: 0xa5, stepping: 0x2)
[    0.343930] Performance Events: Skylake events, full-width counters, Intel PMU driver.
[    0.343930] ... version:                4
[    0.343930] ... bit width:              48
[    0.343935] ... generic registers:      4
[    0.345639] ... value mask:             0000ffffffffffff
[    0.347838] ... max period:             00007fffffffffff
[    0.350017] ... fixed-purpose events:   3
[    0.351649] ... event mask:             000000070000000f
[    0.353868] rcu: Hierarchical SRCU implementation.
[    0.354412] smp: Bringing up secondary CPUs ...
[    0.356566] x86: Booting SMP configuration:
[    0.358480] .... node  #0, CPUs:      #1
[    0.358828] MMIO Stale Data CPU bug present and SMT on, data leak possible. See https://www.kernel.org/doc/html/latest/admin-guide/hw-vuln/processor_mmio_stale_data.html for more details.
[    0.364004]  #2 #3 #4 #5
[    0.364808] smp: Brought up 1 node, 6 CPUs
[    0.367003] smpboot: Max logical packages: 1
[    0.368809] smpboot: Total of 6 processors activated (32544.00 BogoMIPS)
[    0.446283] node 0 deferred pages initialised in 70ms
[    0.447206] devtmpfs: initialized
[    0.453974] x86/mm: Memory block size: 128MB
[    0.457088] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.457856] futex hash table entries: 2048 (order: 5, 131072 bytes, linear)
[    0.464207] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.466974] thermal_sys: Registered thermal governor 'step_wise'
[    0.467003] cpuidle: using governor menu
[    0.468042] ACPI: bus type PCI registered
[    0.469851] PCI: Fatal: No config space access function found
[    0.475175] Kprobes globally optimized
[    0.476801] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.476970] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.483989] raid6: skip pq benchmark and using algorithm avx2x4
[    0.486338] raid6: using avx2x2 recovery algorithm
[    0.488348] ACPI: Added _OSI(Module Device)
[    0.490160] ACPI: Added _OSI(Processor Device)
[    0.493936] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.496032] ACPI: Added _OSI(Processor Aggregator Device)
[    0.498290] ACPI: Added _OSI(Linux-Dell-Video)
[    0.500200] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.502543] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.507819] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.511144] ACPI: Interpreter enabled
[    0.512966] ACPI: PM: (supports S0 S5)
[    0.513968] ACPI: Using IOAPIC for interrupt routing
[    0.516499] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.521090] ACPI: Enabled 2 GPEs in block 00 to 0F
[    0.524671] iommu: Default domain type: Translated
[    0.526832] iommu: DMA domain TLB invalidation policy: lazy mode
[    0.530063] SCSI subsystem initialized
[    0.531799] ACPI: bus type USB registered
[    0.533626] usbcore: registered new interface driver usbfs
[    0.533942] usbcore: registered new interface driver hub
[    0.536153] usbcore: registered new device driver usb
[    0.538340] pps_core: LinuxPPS API ver. 1 registered
[    0.540722] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.543948] PTP clock support registered
[    0.545733] hv_vmbus: Vmbus version:5.2
[    0.545733] PCI: Using ACPI for IRQ routing
[    0.547490] PCI: System does not support PCI
[    0.549389] clocksource: Switched to clocksource hyperv_clocksource_tsc_page
[    0.549477] hv_vmbus: Unknown GUID: c376c1c3-d276-48d2-90a9-c04748072c60
[    0.550658] hv_vmbus: Unknown GUID: 6e382d18-3336-4f4b-acc4-2b7703d4df4a
[    0.553642] hv_vmbus: Unknown GUID: dde9cbc0-5060-4436-9448-ea1254a5d177
[    0.558211] VFS: Disk quotas dquot_6.6.0
[    0.559822] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.563384] FS-Cache: Loaded
[    0.564943] pnp: PnP ACPI init
[    0.566559] pnp: PnP ACPI: found 3 devices
[    0.572258] NET: Registered PF_INET protocol family
[    0.575016] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.579888] tcp_listen_portaddr_hash hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.584281] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.587759] TCP established hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.592476] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[    0.596305] TCP: Hash tables configured (established 524288 bind 65536)
[    0.599859] UDP hash table entries: 32768 (order: 8, 1048576 bytes, linear)
[    0.603233] UDP-Lite hash table entries: 32768 (order: 8, 1048576 bytes, linear)
[    0.606988] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.609813] RPC: Registered named UNIX socket transport module.
[    0.612554] RPC: Registered udp transport module.
[    0.614599] RPC: Registered tcp transport module.
[    0.616713] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.619454] PCI: CLS 0 bytes, default 64
[    0.621235] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.621540] Trying to unpack rootfs image as initramfs...
[    0.624090] software IO TLB: mapped [mem 0x00000000f4000000-0x00000000f8000000] (64MB)
[    0.629944] kvm: no hardware support
[    0.630013] Freeing initrd memory: 1896K
[    0.631679] has_svm: not amd or hygon
[    0.635257] kvm: no hardware support
[    0.637980] Initialise system trusted keyrings
[    0.640102] workingset: timestamp_bits=46 max_order=24 bucket_order=0
[    0.643412] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.645979] NFS: Registering the id_resolver key type
[    0.648331] Key type id_resolver registered
[    0.650323] Key type id_legacy registered
[    0.652116] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.654900] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    0.657959] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[    0.661719] Key type cifs.idmap registered
[    0.663525] fuse: init (API version 7.34)
[    0.665837] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, no debug enabled
[    0.670276] 9p: Installing v9fs 9p2000 file system support
[    0.672628] FS-Cache: Netfs '9p' registered for caching
[    0.674831] FS-Cache: Netfs 'ceph' registered for caching
[    0.677075] ceph: loaded (mds proto 32)
[    0.685900] NET: Registered PF_ALG protocol family
[    0.688427] xor: automatically using best checksumming function   avx
[    0.691502] Key type asymmetric registered
[    0.693363] Asymmetric key parser 'x509' registered
[    0.695575] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[    0.699447] hv_vmbus: registering driver hv_pci
[    0.702714] hv_pci c62c35c4-b61e-4e82-bd4d-403ee18e0f63: PCI VMBus probing: Using version 0x10003
[    0.707866] hv_pci c62c35c4-b61e-4e82-bd4d-403ee18e0f63: PCI host bridge to bus b61e:00
[    0.711541] pci_bus b61e:00: root bus resource [mem 0x9ffe00000-0x9ffe02fff window]
[    0.715064] pci_bus b61e:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.719807] pci b61e:00:00.0: [1af4:1043] type 00 class 0x010000
[    0.723346] pci b61e:00:00.0: reg 0x10: [mem 0x9ffe00000-0x9ffe00fff 64bit]
[    0.727347] pci b61e:00:00.0: reg 0x18: [mem 0x9ffe01000-0x9ffe01fff 64bit]
[    0.731205] pci b61e:00:00.0: reg 0x20: [mem 0x9ffe02000-0x9ffe02fff 64bit]
[    0.737585] pci_bus b61e:00: busn_res: [bus 00-ff] end is updated to 00
[    0.740239] pci b61e:00:00.0: BAR 0: assigned [mem 0x9ffe00000-0x9ffe00fff 64bit]
[    0.743758] pci b61e:00:00.0: BAR 2: assigned [mem 0x9ffe01000-0x9ffe01fff 64bit]
[    0.747373] pci b61e:00:00.0: BAR 4: assigned [mem 0x9ffe02000-0x9ffe02fff 64bit]
[    0.751592] hv_pci 87fe8344-8fda-4f7b-9a7e-bb64c490be66: PCI VMBus probing: Using version 0x10003
[    0.756286] hv_pci 87fe8344-8fda-4f7b-9a7e-bb64c490be66: PCI host bridge to bus 8fda:00
[    0.759644] pci_bus 8fda:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.763364] pci 8fda:00:00.0: [1414:008e] type 00 class 0x030200
[    0.770370] pci_bus 8fda:00: busn_res: [bus 00-ff] end is updated to 00
[    0.773780] hv_pci f04754a0-b751-4573-a957-ce9c3f6fb79d: PCI VMBus probing: Using version 0x10003
[    0.778525] hv_pci f04754a0-b751-4573-a957-ce9c3f6fb79d: PCI host bridge to bus b751:00
[    0.782064] pci_bus b751:00: root bus resource [mem 0x9ffe04000-0x9ffe06fff window]
[    0.785301] pci_bus b751:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.789700] pci b751:00:00.0: [1af4:1049] type 00 class 0x010000
[    0.793661] pci b751:00:00.0: reg 0x10: [mem 0x9ffe04000-0x9ffe04fff 64bit]
[    0.797307] pci b751:00:00.0: reg 0x18: [mem 0x9ffe05000-0x9ffe05fff 64bit]
[    0.801328] pci b751:00:00.0: reg 0x20: [mem 0x9ffe06000-0x9ffe06fff 64bit]
[    0.808199] pci_bus b751:00: busn_res: [bus 00-ff] end is updated to 00
[    0.811076] pci b751:00:00.0: BAR 0: assigned [mem 0x9ffe04000-0x9ffe04fff 64bit]
[    0.814527] pci b751:00:00.0: BAR 2: assigned [mem 0x9ffe05000-0x9ffe05fff 64bit]
[    0.818684] pci b751:00:00.0: BAR 4: assigned [mem 0x9ffe06000-0x9ffe06fff 64bit]
[    0.822823] ACPI: AC: AC Adapter [AC1] (on-line)
[    0.825967] ACPI: battery: Slot [BAT1] (battery present)
[    0.833205] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.836463] 00:00: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    0.839954] 00:01: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    0.874255] Non-volatile memory driver v1.3
[    0.876310] printk: console [hvc0] enabled
[    0.876470] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[    0.878186] printk: bootconsole [uart8250] disabled
[    0.886787] brd: module loaded
[    0.888086] loop: module loaded
[    0.888396] hv_vmbus: registering driver hv_storvsc
[    0.889093] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[    0.889460] scsi host0: storvsc_host_t
[    0.889474] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
[    0.890204] tun: Universal TUN/TAP device driver, 1.6
[    0.890565] PPP generic driver version 2.4.2
[    0.890995] PPP BSD Compression module registered
[    0.891281] PPP Deflate Compression module registered
[    0.891572] PPP MPPE Compression module registered
[    0.891832] NET: Registered PF_PPPOX protocol family
[    0.892126] usbcore: registered new interface driver cdc_ether
[    0.892457] usbcore: registered new interface driver cdc_ncm
[    0.892819] usbcore: registered new interface driver r8153_ecm
[    0.893168] hv_vmbus: registering driver hv_netvsc
[    0.893566] VFIO - User Level meta-driver version: 0.3
[    0.893986] usbcore: registered new interface driver cdc_acm
[    0.894384] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    0.894829] usbcore: registered new interface driver ch341
[    0.895091] usbserial: USB Serial support registered for ch341-uart
[    0.895403] usbcore: registered new interface driver cp210x
[    0.895680] usbserial: USB Serial support registered for cp210x
[    0.896003] usbcore: registered new interface driver ftdi_sio
[    0.896319] usbserial: USB Serial support registered for FTDI USB Serial Device
[    0.896886] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[    0.897220] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 1
[    0.897623] vhci_hcd: created sysfs vhci_hcd.0
[    0.898142] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[    0.898622] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.899144] usb usb1: Product: USB/IP Virtual Host Controller
[    0.899643] usb usb1: Manufacturer: Linux 5.15.79.1-microsoft-standard-WSL2 vhci_hcd
[    0.900250] usb usb1: SerialNumber: vhci_hcd.0
[    0.900660] hub 1-0:1.0: USB hub found
[    0.900877] hub 1-0:1.0: 8 ports detected
[    0.901530] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[    0.901866] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 2
[    0.902420] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    0.903107] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[    0.903515] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.903876] usb usb2: Product: USB/IP Virtual Host Controller
[    0.904236] usb usb2: Manufacturer: Linux 5.15.79.1-microsoft-standard-WSL2 vhci_hcd
[    0.904653] usb usb2: SerialNumber: vhci_hcd.0
[    0.905094] hub 2-0:1.0: USB hub found
[    0.905315] hub 2-0:1.0: 8 ports detected
[    0.905956] hv_vmbus: registering driver hyperv_keyboard
[    0.906353] rtc_cmos 00:02: RTC can wake from S4
[    0.908134] rtc_cmos 00:02: registered as rtc0
[    0.908721] rtc_cmos 00:02: setting system clock to 2023-02-21T13:41:32 UTC (1676986892)
[    0.909121] rtc_cmos 00:02: alarms up to one month, 114 bytes nvram
[    0.909682] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: dm-devel@redhat.com
[    0.910279] device-mapper: raid: Loading target version 1.15.1
[    0.910624] usbcore: registered new interface driver usbhid
[    0.910896] usbhid: USB HID core driver
[    0.911175] hv_utils: Registering HyperV Utility Driver
[    0.911433] hv_vmbus: registering driver hv_utils
[    0.911704] hv_vmbus: registering driver hv_balloon
[    0.912177] hv_vmbus: registering driver dxgkrnl
[    0.912190] hv_utils: TimeSync IC version 4.0
[    0.912947] hv_balloon: Using Dynamic Memory protocol version 2.0
[    0.913066] drop_monitor: Initializing network drop monitor service
[    0.913824] Mirror/redirect action on
[    0.914159] Free page reporting enabled
[    0.914160] hv_balloon: Cold memory discard hint enabled with order 9
[    0.915196] u32 classifier
[    0.915438]     Performance counters on
[    0.915706]     input device check on
[    0.915969]     Actions configured
[    0.917188] IPVS: Registered protocols (TCP, UDP)
[    0.917746] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[    0.918253] IPVS: ipvs loaded.
[    0.918566] IPVS: [rr] scheduler registered.
[    0.918894] IPVS: [wrr] scheduler registered.
[    0.919153] IPVS: [sh] scheduler registered.
[    0.919399] ipip: IPv4 and MPLS over IPv4 tunneling driver
[    0.919691] ipt_CLUSTERIP: ClusterIP Version 0.8 loaded successfully
[    0.920000] Initializing XFRM netlink socket
[    0.920303] NET: Registered PF_INET6 protocol family
[    0.921107] Segment Routing with IPv6
[    0.921396] In-situ OAM (IOAM) with IPv6
[    0.921713] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.922201] NET: Registered PF_PACKET protocol family
[    0.922479] Bridge firewalling registered
[    0.922691] 8021q: 802.1Q VLAN Support v1.8
[    0.922914] sctp: Hash tables configured (bind 1024/1024)
[    0.923203] 9pnet: Installing 9P2000 support
[    0.939035] Key type dns_resolver registered
[    0.939469] Key type ceph registered
[    0.939916] libceph: loaded (mon/osd proto 15/24)
[    0.940363] NET: Registered PF_VSOCK protocol family
[    0.940690] hv_vmbus: registering driver hv_sock
[    0.941076] IPI shorthand broadcast: enabled
[    0.941440] sched_clock: Marking stable (928241300, 12108400)->(1037347600, -96997900)
[    0.942088] registered taskstats version 1
[    0.942508] Loading compiled-in X.509 certificates
[    0.943225] Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=no
[    0.944375] Freeing unused kernel image (initmem) memory: 2028K
[    1.004045] Write protecting the kernel read-only data: 30720k
[    1.005690] Freeing unused kernel image (text/rodata gap) memory: 2024K
[    1.006500] Freeing unused kernel image (rodata/data gap) memory: 480K
[    1.006889] Run /init as init process
[    1.007097]   with arguments:
[    1.007299]     /init
[    1.007441]   with environment:
[    1.007637]     HOME=/
[    1.007764]     TERM=linux
[    1.007889]     WSL_ROOT_INIT=1
[    1.011806] scsi 0:0:0:0: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    1.012677] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    1.013420] sd 0:0:0:0: [sda] 743696 512-byte logical blocks: (381 MB/363 MiB)
[    1.013982] sd 0:0:0:0: [sda] Write Protect is on
[    1.014326] sd 0:0:0:0: [sda] Mode Sense: 0f 00 80 00
[    1.014942] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    1.564578] EXT4-fs (sda): mounted filesystem without journal. Opts: (null). Quota mode: none.
GNS: Processing Next Message
Processing LX_GNS_MESSAGE_TYPE LxGnsMessageInterfaceConfiguration
OpenAdapterImpl: Found an interface matching the GUID ED124FC7-FA85-4647-9D7F-4E1073E696CA, with name eth0
LxGnsMessageInterfaceConfiguration: no-op - the endpoint ID ED124FC7-FA85-4647-9D7F-4E1073E696CA PortFriendlyName is blank
SetAdapterConfiguration setting the IPv4 address on endpointID (ED124FC7-FA85-4647-9D7F-4E1073E696CA) to 172.25.72.173/20 on interfaceName eth0
SetInterfaceState: setting interface state to Up on interfaceName eth0
Returning LxGnsMessageResult [0 - ]
GNS: Processing Next Message
Processing LX_GNS_MESSAGE_TYPE LxGnsMessageNotification
OpenAdapterImpl: Found an interface matching the GUID ED124FC7-FA85-4647-9D7F-4E1073E696CA, with name eth0
Processing Notification LxGnsMessageNotification GuestEndpointResourceType::Route for interfaceName eth0
ProcessRouteChange: Add route default  via 172.25.64.1/0 dev 6 metric 0 on interfaceName eth0
ModifyDefaultRouteImpl - SendMessage Route (to [empty], via 172.25.64.1), operation (RTM_NEWROUTE ), netLinkflags (NLM_F_CREATE )
ModifyDefaultRouteImpl - InitializeAddressAttribute RTA_DST ([not set]) RTA_GATEWAY ([empty]), RTA_PRIORITY (0)
Returning LxGnsMessageResult [0 - ]
GNS: Processing Next Message
Processing LX_GNS_MESSAGE_TYPE LxGnsMessageNotification
OpenAdapterImpl: Found an interface matching the GUID ED124FC7-FA85-4647-9D7F-4E1073E696CA, with name eth0
Processing Notification LxGnsMessageNotification GuestEndpointResourceType::DNS for interfaceName eth0
ProcessDNSChange: setting DNS server domain to : # This file was automatically generated by WSL. To stop automatic generation of this file, add the following entry to /etc/wsl.conf:
# [network]
# generateResolvConf = false
nameserver 172.25.64.1
 on interfaceName eth0
Returning LxGnsMessageResult [0 - ]
GNS: Processing Next Message
[    1.734140] sd 0:0:0:0: [sda] Attached SCSI disk
Processing LX_GNS_MESSAGE_TYPE LxGnsMessageNotification
OpenAdapterImpl: Found an interface matching the GUID ED124FC7-FA85-4647-9D7F-4E1073E696CA, with name eth0
Processing Notification LxGnsMessageNotification GuestEndpointResourceType::Interface for interfaceName eth0
ProcessLinkChange: setting link state to InterfaceState::Up on interfaceName eth0
SetInterfaceState: setting interface state to Up on interfaceName eth0
ProcessLinkChange: Setting MTU to 1400 on interfaceName eth0
Returning LxGnsMessageResult [0 - ]
GNS: Processing Next Message
[    1.821919] hv_pci f2d59d34-c8ab-4ad4-b0b3-00474f2cd3cb: PCI VMBus probing: Using version 0x10003
[    1.824165] hv_pci f2d59d34-c8ab-4ad4-b0b3-00474f2cd3cb: PCI host bridge to bus c8ab:00
[    1.824587] pci_bus c8ab:00: root bus resource [mem 0xc00000000-0xe00001fff window]
[    1.824924] pci_bus c8ab:00: No busn resource found for root bus, will use [bus 00-ff]
[    1.826062] pci c8ab:00:00.0: [1af4:105a] type 00 class 0x088000
[    1.828218] pci c8ab:00:00.0: reg 0x10: [mem 0xe00000000-0xe00000fff 64bit]
[    1.830242] pci c8ab:00:00.0: reg 0x18: [mem 0xe00001000-0xe00001fff 64bit]
[    1.832405] pci c8ab:00:00.0: reg 0x20: [mem 0xc00000000-0xdffffffff 64bit]
[    1.837544] pci_bus c8ab:00: busn_res: [bus 00-ff] end is updated to 00
[    1.837898] pci c8ab:00:00.0: BAR 4: assigned [mem 0xc00000000-0xdffffffff 64bit]
[    1.839801] pci c8ab:00:00.0: BAR 0: assigned [mem 0xe00000000-0xe00000fff 64bit]
[    1.841662] pci c8ab:00:00.0: BAR 2: assigned [mem 0xe00001000-0xe00001fff 64bit]
[    1.854945] virtiofs virtio2: Cache len: 0x200000000 @ 0xc00000000
[    1.894072] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    1.949857] memmap_init_zone_device initialised 2097152 pages in 20ms
[    1.959181] FS-Cache: Duplicate cookie detected
[    1.959698] FS-Cache: O-cookie c=00000004 [p=00000002 fl=222 nc=0 na=1]
[    1.960186] FS-Cache: O-cookie d=00000000703106f0{9P.session} n=00000000c7a4eabe
[    1.960892] FS-Cache: O-key=[10] '34323934393337343538'
[    1.961313] FS-Cache: N-cookie c=00000005 [p=00000002 fl=2 nc=0 na=1]
[    1.961625] FS-Cache: N-cookie d=00000000703106f0{9P.session} n=00000000e667d650
[    1.962049] FS-Cache: N-key=[10] '34323934393337343538'
[    1.963672] FS-Cache: Duplicate cookie detected
[    1.964007] FS-Cache: O-cookie c=00000004 [p=00000002 fl=222 nc=0 na=1]
[    1.964365] FS-Cache: O-cookie d=00000000703106f0{9P.session} n=00000000c7a4eabe
[    1.964826] FS-Cache: O-key=[10] '34323934393337343538'
[    1.965138] FS-Cache: N-cookie c=00000006 [p=00000002 fl=2 nc=0 na=1]
[    1.965533] FS-Cache: N-cookie d=00000000703106f0{9P.session} n=0000000089f2d423
[    1.965995] FS-Cache: N-key=[10] '34323934393337343538'
[    2.564263] scsi 0:0:0:1: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    2.566323] sd 0:0:0:1: Attached scsi generic sg1 type 0
[    2.567326] scsi 0:0:0:2: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    2.567610] sd 0:0:0:1: [sdb] 27262984 512-byte logical blocks: (14.0 GB/13.0 GiB)
[    2.568654] sd 0:0:0:2: Attached scsi generic sg2 type 0
[    2.568679] sd 0:0:0:1: [sdb] 4096-byte physical blocks
[    2.569271] sd 0:0:0:2: [sdc] 2147483648 512-byte logical blocks: (1.10 TB/1.00 TiB)
[    2.569646] sd 0:0:0:1: [sdb] Write Protect is off
[    2.569784] sd 0:0:0:2: [sdc] 4096-byte physical blocks
[    2.570089] sd 0:0:0:1: [sdb] Mode Sense: 0f 00 00 00
[    2.570528] sd 0:0:0:2: [sdc] Write Protect is off
[    2.571085] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.571243] sd 0:0:0:2: [sdc] Mode Sense: 0f 00 00 00
[    2.572507] sd 0:0:0:2: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.574326] sd 0:0:0:1: [sdb] Attached SCSI disk
[    2.575257] sd 0:0:0:2: [sdc] Attached SCSI disk
mke2fs 1.46.5 (30-Dec-2021)
Setting up swapspace version 1, size = 13 GiB (13958643712 bytes)
no label, UUID=3aca589f-6716-468a-bf73-809f480195f7
[    2.614389] Adding 13631488k swap on /dev/sdb.  Priority:-2 extents:1 across:13631488k
Discarding device blocks: done
Creating filesystem with 268435456 4k blocks and 67108864 inodes
Filesystem UUID: f81a5e25-4e36-43b5-844e-b4f64572b53a
Superblock backups stored on blocks:
        32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
        4096000, 7962624, 11239424, 20480000, 23887872, 71663616, 78675968,
        102400000, 214990848

Allocating group tables: done
Writing inode tables: done
Creating journal (262144 blocks): done
Writing superblocks and filesystem accounting information: done

[    2.838346] EXT4-fs (sdc): mounted filesystem with ordered data mode. Opts: discard,errors=remount-ro,data=ordered. Quota mode: none.
[   42.336494] bsdtar invoked oom-killer: gfp_mask=0x108c40(GFP_NOFS|__GFP_NOFAIL|__GFP_HARDWALL), order=0, oom_score_adj=0
[   42.337119] CPU: 0 PID: 153 Comm: bsdtar Not tainted 5.15.79.1-microsoft-standard-WSL2 #1
[   42.337466] Call Trace:
[   42.337577]  <TASK>
[   42.337700]  dump_stack_lvl+0x34/0x48
[   42.337909]  dump_header+0x4a/0x19a
[   42.338104]  oom_kill_process.cold+0xb/0x10
[   42.338315]  out_of_memory+0x1fb/0x2a0
[   42.338521]  mem_cgroup_out_of_memory+0xe5/0x100
[   42.338744]  try_charge_memcg+0x66e/0x730
[   42.338929]  charge_memcg+0x3f/0x90
[   42.339091]  __mem_cgroup_charge+0x2c/0x90
[   42.339310]  __add_to_page_cache_locked+0x2eb/0x360
[   42.339591]  ? scan_shadow_nodes+0x30/0x30
[   42.339778]  add_to_page_cache_lru+0x48/0xd0
[   42.339992]  pagecache_get_page+0x18e/0x4a0
[   42.340153]  __getblk_gfp+0xe0/0x270
[   42.340312]  ? submit_bh_wbc+0x160/0x190
[   42.340508]  ext4_sb_breadahead_unmovable+0x18/0x50
[   42.340756]  __ext4_get_inode_loc+0x392/0x420
[   42.340975]  ? kmem_cache_alloc+0x108/0x370
[   42.341156]  __ext4_get_inode_loc_noinmem+0x3d/0xa0
[   42.341390]  __ext4_iget+0x149/0xdb0
[   42.341552]  ? d_alloc_parallel+0x232/0x4b0
[   42.341713]  ext4_lookup+0x11f/0x1e0
[   42.341880]  __lookup_slow+0x85/0x150
[   42.342047]  walk_component+0x13f/0x1b0
[   42.342273]  link_path_walk.part.0+0x236/0x3a0
[   42.342512]  ? __alloc_file+0x98/0x110
[   42.342678]  path_openat+0xb5/0x1090
[   42.342841]  ? handle_mm_fault+0xc2/0x2a0
[   42.343056]  ? do_user_addr_fault+0x1c4/0x630
[   42.343337]  do_filp_open+0xb2/0x120
[   42.343530]  ? 0xffffffff81000000
[   42.343697]  ? strncpy_from_user+0xbc/0x150
[   42.343863]  do_sys_openat2+0x24a/0x320
[   42.344046]  do_sys_open+0x44/0x80
[   42.344221]  do_syscall_64+0x38/0xc0
[   42.344451]  entry_SYSCALL_64_after_hwframe+0x61/0xcb
[   42.344728] RIP: 0033:0x7fb6011e298b
[   42.344898] Code: 25 00 00 41 00 3d 00 00 41 00 74 33 64 8b 04 25 18 00 00 00 85 c0 75 57 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 81 00 00 00 48 83 c4 68 5d 41 5c c3 90 48
[   42.345763] RSP: 002b:00007fffe30a7430 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
[   42.346093] RAX: ffffffffffffffda RBX: 0000558866fcf070 RCX: 00007fb6011e298b
[   42.346491] RDX: 00000000000b0000 RSI: 00005588671c99f0 RDI: 00000000ffffff9c
[   42.346823] RBP: 00005588671c99f0 R08: 00005588671ca950 R09: 0000000000000000
[   42.347153] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000b0000
[   42.347486] R13: 00005588671cb320 R14: 00005588671cb328 R15: 00005588671cb320
[   42.347814]  </TASK>
[   42.347953] memory: usage 65536kB, limit 65536kB, failcnt 570487
[   42.348232] memory+swap: usage 70988kB, limit 9007199254740988kB, failcnt 0
[   42.348601] kmem: usage 8756kB, limit 9007199254740988kB, failcnt 0
[   42.348940] Memory cgroup stats for /64M:
[   42.348954] anon 0
[   42.348954] file 58085376
[   42.348954] kernel_stack 16384
[   42.348954] pagetables 61440
[   42.348954] percpu 0
[   42.348954] sock 0
[   42.348954] shmem 0
[   42.348954] file_mapped 0
[   42.348954] file_dirty 0
[   42.348954] file_writeback 0
[   42.348954] swapcached 44724224
[   42.348954] anon_thp 0
[   42.348954] file_thp 0
[   42.348954] shmem_thp 0
[   42.348954] inactive_anon 57344
[   42.348954] active_anon 0
[   42.348954] inactive_file 29044736
[   42.348954] active_file 29040640
[   42.348954] unevictable 0
[   42.348954] slab_reclaimable 8830144
[   42.348954] slab_unreclaimable 38232
[   42.348954] slab 8868376
[   42.348954] workingset_refault_anon 9111
[   42.348954] workingset_refault_file 65380
[   42.348954] workingset_activate_anon 2689
[   42.348954] workingset_activate_file 8976
[   42.348954] workingset_restore_anon 1749
[   42.348954] workingset_restore_file 6005
[   42.348954] workingset_nodereclaim 9984
[   42.348954] pgfault 32960
[   42.353046] Tasks state (memory values in pages):
[   42.353261] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[   42.353644] [    144]     0   144      573      258    40960        5             0 init
[   42.354048] [    153]     0   153     4338      504    69632     1383             0 bsdtar
[   42.354439] oom-kill:constraint=CONSTRAINT_MEMCG,nodemask=(null),cpuset=/,mems_allowed=0,oom_memcg=/64M,task_memcg=/64M,task=bsdtar,pid=153,uid=0
[   42.355018] Memory cgroup out of memory: Killed process 153 (bsdtar) total-vm:17352kB, anon-rss:0kB, file-rss:2016kB, shmem-rss:0kB, UID:0 pgtables:68kB oom_score_adj:0
[   42.633446] WSL (1) ERROR: UtilProcessChildExitCode:2056: /usr/bin/bsdtar killed by signal
[   42.633449] 9
[   42.634796] WSL (1) ERROR: ProcessMessage:2869: import failed
[   42.774403] sd 0:0:0:2: [sdc] Synchronizing SCSI cache
[   49.745020] hv_balloon: Max. dynamic memory size: 51200 MB
The connection with the virtual machine or container was closed.

.wslconfig

[wsl2]
memory=50G
processors=6
debugConsole=true
[interop]
enabled=true

Actually setting swap (even disable) or setting memory to various value did not change end result. oom-kill reproducible in about 60-70% of the cases. Otherwise wsl images run smoothly on the same machine . Possibly related: #9424 #9382

benhillis commented 1 year ago

Thanks for reporting, I have a fix for this in the works.

marysue commented 1 year ago

Has there been a fix? 3/21/2023 I'm getting the same error. My import has taken the .vhdx file and created some temporary directories which are empty.

kapsner commented 1 year ago

+1 I am getting the same error. Is there already a fix / workaround available?

benhillis commented 1 year ago

Yes - this should be fixed in https://github.com/microsoft/WSL/releases/tag/1.1.5.