Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Slow startup #8751

Closed
1 of 2 tasks
Macmee opened this issue Aug 22, 2022 · 9 comments
Closed
1 of 2 tasks

Slow startup #8751

Macmee opened this issue Aug 22, 2022 · 9 comments

Comments

@Macmee
Copy link

Macmee commented Aug 22, 2022

Version

Microsoft Windows [Version 10.0.22622.575]

WSL Version

  • WSL 2
  • WSL 1

Kernel Version

No response

Distro Version

Debian Buster

Other Software

No response

Repro Steps

Launch wsl2

Expected Behavior

startup within one or two seconds

Actual Behavior

startup takes three to four seconds. I think possibly on the virtual disk line, so maybe with mounting the vhdx?

Im on a surface pro 8, so an nvme which should be speedy!

Diagnostic Logs

[ 0.000000] Linux version 5.15.57.1-microsoft-standard-WSL2 (oe-user@oe-host) (x86_64-msft-linux-gcc (GCC) 9.3.0, GNU ld (GNU Binutils) 2.34.0.20200220) #1 SMP Wed Jul 27 02:20:31 UTC 2022
[ 0.000000] Command line: initrd=\initrd.img WSL_ROOT_INIT=1 panic=-1 nr_cpus=8 swiotlb=force 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] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256'
[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
[ 0.000000] x86/fpu: xstate_offset[5]: 832, xstate_sizes[5]: 64
[ 0.000000] x86/fpu: xstate_offset[6]: 896, xstate_sizes[6]: 512
[ 0.000000] x86/fpu: xstate_offset[7]: 1408, xstate_sizes[7]: 1024
[ 0.000000] x86/fpu: Enabled xstate features 0xe7, context size is 2432 bytes, using 'compacted' format.
[ 0.000000] signal: max sigframe size: 3632
[ 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-0x0000000402bfffff] usable
[ 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 0xae7f, high 0x3b8030, hints 0xa4e24, misc 0xe4bed7b6
[ 0.000000] Hyper-V Host Build:22621-10.0-0-0.575
[ 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.000004] tsc: Detected 2995.211 MHz processor
[ 0.000023] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[ 0.000029] e820: remove [mem 0x000a0000-0x000fffff] usable
[ 0.000035] last_pfn = 0x402c00 max_arch_pfn = 0x400000000
[ 0.000079] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
[ 0.000096] last_pfn = 0xf8000 max_arch_pfn = 0x400000000
[ 0.000112] Using GB pages for direct mapping
[ 0.000733] RAMDISK: [mem 0x03a35000-0x03c05fff]
[ 0.000739] ACPI: Early table checksum verification disabled
[ 0.000762] ACPI: RSDP 0x00000000000E0000 000024 (v02 VRTUAL)
[ 0.000769] ACPI: XSDT 0x0000000000100000 000044 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[ 0.000786] ACPI: FACP 0x0000000000101000 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001)
[ 0.000795] ACPI: DSDT 0x00000000001011B8 01E191 (v02 MSFTVM DSDT01 00000001 MSFT 05000000)
[ 0.000801] ACPI: FACS 0x0000000000101114 000040
[ 0.000806] ACPI: OEM0 0x0000000000101154 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[ 0.000812] ACPI: SRAT 0x000000000011F349 000330 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001)
[ 0.000817] ACPI: APIC 0x000000000011F679 000088 (v04 VRTUAL MICROSFT 00000001 MSFT 00000001)
[ 0.000822] ACPI: Reserving FACP table memory at [mem 0x101000-0x101113]
[ 0.000825] ACPI: Reserving DSDT table memory at [mem 0x1011b8-0x11f348]
[ 0.000826] ACPI: Reserving FACS table memory at [mem 0x101114-0x101153]
[ 0.000828] ACPI: Reserving OEM0 table memory at [mem 0x101154-0x1011b7]
[ 0.000830] ACPI: Reserving SRAT table memory at [mem 0x11f349-0x11f678]
[ 0.000832] ACPI: Reserving APIC table memory at [mem 0x11f679-0x11f700]
[ 0.001144] Zone ranges:
[ 0.001147] DMA [mem 0x0000000000001000-0x0000000000ffffff]
[ 0.001150] DMA32 [mem 0x0000000001000000-0x00000000ffffffff]
[ 0.001153] Normal [mem 0x0000000100000000-0x0000000402bfffff]
[ 0.001155] Device empty
[ 0.001157] Movable zone start for each node
[ 0.001159] Early memory node ranges
[ 0.001160] node 0: [mem 0x0000000000001000-0x000000000009ffff]
[ 0.001192] node 0: [mem 0x0000000000200000-0x00000000f7ffffff]
[ 0.001196] node 0: [mem 0x0000000100000000-0x0000000402bfffff]
[ 0.001201] Initmem setup node 0 [mem 0x0000000000001000-0x0000000402bfffff]
[ 0.003862] On node 0, zone DMA: 1 pages in unavailable ranges
[ 0.004005] On node 0, zone DMA: 352 pages in unavailable ranges
[ 0.032098] On node 0, zone Normal: 21504 pages in unavailable ranges
[ 0.032154] ACPI: LAPIC_NMI (acpi_id[0x01] dfl dfl lint[0x1])
[ 0.032444] IOAPIC[0]: apic_id 8, version 17, address 0xfec00000, GSI 0-23
[ 0.032450] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.032455] ACPI: Using ACPI (MADT) for SMP configuration information
[ 0.032457] TSC deadline timer available
[ 0.032458] smpboot: Allowing 8 CPUs, 0 hotplug CPUs
[ 0.032469] [mem 0xf8000000-0xffffffff] available for PCI devices
[ 0.032470] Booting paravirtualized kernel on Hyper-V
[ 0.032472] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.039165] setup_percpu: NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:8 nr_node_ids:1
[ 0.039659] percpu: Embedded 53 pages/cpu s177432 r8192 d31464 u262144
[ 0.039668] pcpu-alloc: s177432 r8192 d31464 u262144 alloc=1*2097152
[ 0.039672] pcpu-alloc: [0] 0 1 2 3 4 5 6 7
[ 0.039692] Hyper-V: PV spinlocks enabled
[ 0.039695] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[ 0.039701] Built 1 zonelists, mobility grouping on. Total pages: 4106581
[ 0.039704] Kernel command line: initrd=\initrd.img WSL_ROOT_INIT=1 panic=-1 nr_cpus=8 swiotlb=force console=hvc0 debug pty.legacy_count=0
[ 0.039848] Unknown kernel command line parameters "WSL_ROOT_INIT=1", will be passed to user space.
[ 0.042468] Dentry cache hash table entries: 2097152 (order: 12, 16777216 bytes, linear)
[ 0.043982] Inode-cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[ 0.044166] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.071110] Memory: 4081540K/16689788K available (18454K kernel code, 2616K rwdata, 9556K rodata, 2000K init, 2048K bss, 400336K reserved, 0K cma-reserved)
[ 0.071151] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
[ 0.071158] ftrace: allocating 53430 entries in 209 pages
[ 0.106826] ftrace: allocated 209 pages with 4 groups
[ 0.107329] rcu: Hierarchical RCU implementation.
[ 0.107333] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=8.
[ 0.107337] Rude variant of Tasks RCU enabled.
[ 0.107338] Tracing variant of Tasks RCU enabled.
[ 0.107340] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.107342] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8
[ 0.112480] Using NULL legacy PIC
[ 0.112483] NR_IRQS: 16640, nr_irqs: 488, preallocated irqs: 0
[ 0.112847] random: crng init done
[ 0.112875] Console: colour dummy device 80x25
[ 0.112897] ACPI: Core revision 20210730
[ 0.112995] Failed to register legacy timer interrupt
[ 0.112996] APIC: Switch to symmetric I/O mode setup
[ 0.114979] x2apic enabled
[ 0.116853] Switched APIC routing to physical x2apic.
[ 0.116870] Hyper-V: Using IPI hypercalls
[ 0.116932] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x2b2c993ffe9, max_idle_ns: 440795229210 ns
[ 0.116941] Calibrating delay loop (skipped), value calculated using timer frequency.. 5990.42 BogoMIPS (lpj=29952110)
[ 0.116943] pid_max: default: 32768 minimum: 301
[ 0.116955] LSM: Security Framework initializing
[ 0.116960] landlock: Up and running.
[ 0.116998] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 0.117026] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 0.117306] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[ 0.117321] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.117322] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.117327] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[ 0.117329] Spectre V2 : Mitigation: Enhanced IBRS
[ 0.117330] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[ 0.117332] RETBleed: Mitigation: Enhanced IBRS
[ 0.117333] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[ 0.117335] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[ 0.126935] Freeing SMP alternatives memory: 56K
[ 0.126935] smpboot: CPU0: 11th Gen Intel(R) Core(TM) i7-1185G7 @ 3.00GHz (family: 0x6, model: 0x8c, stepping: 0x1)
[ 0.126935] Performance Events: AnyThread deprecated, Icelake events, 32-deep LBR, full-width counters, Intel PMU driver.
[ 0.126935] ... version: 5
[ 0.126935] ... bit width: 48
[ 0.126935] ... generic registers: 8
[ 0.126935] ... value mask: 0000ffffffffffff
[ 0.126935] ... max period: 00007fffffffffff
[ 0.126935] ... fixed-purpose events: 4
[ 0.126935] ... event mask: 0001000f000000ff
[ 0.126935] rcu: Hierarchical SRCU implementation.
[ 0.126935] smp: Bringing up secondary CPUs ...
[ 0.126935] x86: Booting SMP configuration:
[ 0.126935] .... node #0, CPUs: #1 #2 #3 #4 #5 #6 #7
[ 0.126935] smp: Brought up 1 node, 8 CPUs
[ 0.126935] smpboot: Max logical packages: 1
[ 0.126935] smpboot: Total of 8 processors activated (47923.37 BogoMIPS)
[ 0.146763] node 0 deferred pages initialised in 20ms
[ 0.147678] devtmpfs: initialized
[ 0.147678] x86/mm: Memory block size: 128MB
[ 0.147678] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.147678] futex hash table entries: 2048 (order: 5, 131072 bytes, linear)
[ 0.148031] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.148161] thermal_sys: Registered thermal governor 'step_wise'
[ 0.148194] cpuidle: using governor menu
[ 0.148194] ACPI: bus type PCI registered
[ 0.148194] PCI: Fatal: No config space access function found
[ 0.148614] Kprobes globally optimized
[ 0.148646] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[ 0.148646] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.156988] raid6: skip pq benchmark and using algorithm avx512x4
[ 0.156988] raid6: using avx512x2 recovery algorithm
[ 0.156988] ACPI: Added _OSI(Module Device)
[ 0.156988] ACPI: Added _OSI(Processor Device)
[ 0.156988] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 0.156989] ACPI: Added _OSI(Processor Aggregator Device)
[ 0.156991] ACPI: Added _OSI(Linux-Dell-Video)
[ 0.156992] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[ 0.156993] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[ 0.159600] ACPI: 1 ACPI AML tables successfully acquired and loaded
[ 0.160445] ACPI: Interpreter enabled
[ 0.160445] ACPI: PM: (supports S0 S5)
[ 0.160445] ACPI: Using IOAPIC for interrupt routing
[ 0.160445] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 0.160445] ACPI: Enabled 2 GPEs in block 00 to 0F
[ 0.160445] iommu: Default domain type: Translated
[ 0.160445] iommu: DMA domain TLB invalidation policy: lazy mode
[ 0.160445] SCSI subsystem initialized
[ 0.160445] ACPI: bus type USB registered
[ 0.160445] usbcore: registered new interface driver usbfs
[ 0.160445] usbcore: registered new interface driver hub
[ 0.160445] usbcore: registered new device driver usb
[ 0.160445] pps_core: LinuxPPS API ver. 1 registered
[ 0.160445] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it
[ 0.160445] PTP clock support registered
[ 0.166980] hv_vmbus: Vmbus version:5.3
[ 0.167144] PCI: Using ACPI for IRQ routing
[ 0.167147] PCI: System does not support PCI
[ 0.168446] clocksource: Switched to clocksource tsc-early
[ 0.168540] hv_vmbus: Unknown GUID: c376c1c3-d276-48d2-90a9-c04748072c60
[ 0.168597] hv_vmbus: Unknown GUID: 6e382d18-3336-4f4b-acc4-2b7703d4df4a
[ 0.168610] hv_vmbus: Unknown GUID: dde9cbc0-5060-4436-9448-ea1254a5d177
[ 0.180393] VFS: Disk quotas dquot_6.6.0
[ 0.180406] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.180424] FS-Cache: Loaded
[ 0.180449] pnp: PnP ACPI init
[ 0.180645] pnp: PnP ACPI: found 1 devices
[ 0.186242] NET: Registered PF_INET protocol family
[ 0.186665] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.187994] tcp_listen_portaddr_hash hash table entries: 8192 (order: 5, 131072 bytes, linear)
[ 0.188011] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[ 0.188015] TCP established hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.188350] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 0.188463] TCP: Hash tables configured (established 131072 bind 65536)
[ 0.188493] UDP hash table entries: 8192 (order: 6, 262144 bytes, linear)
[ 0.188523] UDP-Lite hash table entries: 8192 (order: 6, 262144 bytes, linear)
[ 0.188571] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.189268] RPC: Registered named UNIX socket transport module.
[ 0.189272] RPC: Registered udp transport module.
[ 0.189273] RPC: Registered tcp transport module.
[ 0.189274] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.189278] PCI: CLS 0 bytes, default 64
[ 0.189305] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 0.189307] software IO TLB: mapped [mem 0x00000000f4000000-0x00000000f8000000] (64MB)
[ 0.189339] Trying to unpack rootfs image as initramfs...
[ 0.189386] KVM: vmx: using Hyper-V Enlightened VMCS
[ 0.190328] Freeing initrd memory: 1860K
[ 0.463001] kvm: already loaded the other module
[ 0.466799] Initialise system trusted keyrings
[ 0.466997] workingset: timestamp_bits=46 max_order=22 bucket_order=0
[ 0.467855] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.468187] NFS: Registering the id_resolver key type
[ 0.468315] Key type id_resolver registered
[ 0.468316] Key type id_legacy registered
[ 0.468319] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.468322] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 0.468323] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[ 0.469293] Key type cifs.idmap registered
[ 0.469456] fuse: init (API version 7.34)
[ 0.469629] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, no debug enabled
[ 0.470182] 9p: Installing v9fs 9p2000 file system support
[ 0.470190] FS-Cache: Netfs '9p' registered for caching
[ 0.480394] NET: Registered PF_ALG protocol family
[ 0.480397] xor: automatically using best checksumming function avx
[ 0.480398] Key type asymmetric registered
[ 0.480400] Asymmetric key parser 'x509' registered
[ 0.480447] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[ 0.481041] hv_vmbus: registering driver hv_pci
[ 0.481712] hv_pci 870bc200-f828-4f53-89cf-46f9318bedf0: PCI VMBus probing: Using version 0x10004
[ 0.483156] hv_pci 870bc200-f828-4f53-89cf-46f9318bedf0: PCI host bridge to bus f828:00
[ 0.483159] pci_bus f828:00: root bus resource [mem 0x9ffe00000-0x9ffe02fff window]
[ 0.483162] pci_bus f828:00: No busn resource found for root bus, will use [bus 00-ff]
[ 0.483924] pci f828:00:00.0: [1af4:1043] type 00 class 0x010000
[ 0.484853] pci f828:00:00.0: reg 0x10: [mem 0x9ffe00000-0x9ffe00fff 64bit]
[ 0.485446] pci f828:00:00.0: reg 0x18: [mem 0x9ffe01000-0x9ffe01fff 64bit]
[ 0.486026] pci f828:00:00.0: reg 0x20: [mem 0x9ffe02000-0x9ffe02fff 64bit]
[ 0.489003] pci_bus f828:00: busn_res: [bus 00-ff] end is updated to 00
[ 0.489009] pci f828:00:00.0: BAR 0: assigned [mem 0x9ffe00000-0x9ffe00fff 64bit]
[ 0.489419] pci f828:00:00.0: BAR 2: assigned [mem 0x9ffe01000-0x9ffe01fff 64bit]
[ 0.489827] pci f828:00:00.0: BAR 4: assigned [mem 0x9ffe02000-0x9ffe02fff 64bit]
[ 0.490808] hv_pci 3533b7ab-edf6-4688-9e59-74652a3d7a0e: PCI VMBus probing: Using version 0x10004
[ 0.491784] hv_pci 3533b7ab-edf6-4688-9e59-74652a3d7a0e: PCI host bridge to bus edf6:00
[ 0.491788] pci_bus edf6:00: No busn resource found for root bus, will use [bus 00-ff]
[ 0.492247] pci edf6:00:00.0: [1414:008e] type 00 class 0x030200
[ 0.497289] pci_bus edf6:00: busn_res: [bus 00-ff] end is updated to 00
[ 0.498090] hv_pci 941b7727-f207-40ca-9848-4907e2ffb7b2: PCI VMBus probing: Using version 0x10004
[ 0.500064] hv_pci 941b7727-f207-40ca-9848-4907e2ffb7b2: PCI host bridge to bus f207:00
[ 0.500068] pci_bus f207:00: root bus resource [mem 0x9ffe04000-0x9ffe06fff window]
[ 0.500071] pci_bus f207:00: No busn resource found for root bus, will use [bus 00-ff]
[ 0.501302] pci f207:00:00.0: [1af4:1049] type 00 class 0x010000
[ 0.502585] pci f207:00:00.0: reg 0x10: [mem 0x9ffe04000-0x9ffe04fff 64bit]
[ 0.503468] pci f207:00:00.0: reg 0x18: [mem 0x9ffe05000-0x9ffe05fff 64bit]
[ 0.504353] pci f207:00:00.0: reg 0x20: [mem 0x9ffe06000-0x9ffe06fff 64bit]
[ 0.509676] pci_bus f207:00: busn_res: [bus 00-ff] end is updated to 00
[ 0.509684] pci f207:00:00.0: BAR 0: assigned [mem 0x9ffe04000-0x9ffe04fff 64bit]
[ 0.510338] pci f207:00:00.0: BAR 2: assigned [mem 0x9ffe05000-0x9ffe05fff 64bit]
[ 0.510946] pci f207:00:00.0: BAR 4: assigned [mem 0x9ffe06000-0x9ffe06fff 64bit]
[ 0.511736] ACPI: AC: AC Adapter [AC1] (off-line)
[ 0.512800] ACPI: battery: Slot [BAT1] (battery present)
[ 0.522180] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 0.560153] Non-volatile memory driver v1.3
[ 0.560378] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[ 0.562187] printk: console [hvc0] enabled
[ 0.565050] brd: module loaded
[ 0.567731] loop: module loaded
[ 0.568114] hv_vmbus: registering driver hv_storvsc
[ 0.569355] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[ 0.569953] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld Jason@zx2c4.com. All Rights Reserved.
[ 0.570283] scsi host0: storvsc_host_t
[ 0.570817] tun: Universal TUN/TAP device driver, 1.6
[ 0.571563] PPP generic driver version 2.4.2
[ 0.572084] PPP BSD Compression module registered
[ 0.572549] PPP Deflate Compression module registered
[ 0.572995] PPP MPPE Compression module registered
[ 0.573366] NET: Registered PF_PPPOX protocol family
[ 0.573741] usbcore: registered new interface driver cdc_ether
[ 0.574324] usbcore: registered new interface driver cdc_ncm
[ 0.574718] hv_vmbus: registering driver hv_netvsc
[ 0.575137] VFIO - User Level meta-driver version: 0.3
[ 0.575631] usbcore: registered new interface driver cdc_acm
[ 0.576144] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 0.576741] usbcore: registered new interface driver ch341
[ 0.577232] usbserial: USB Serial support registered for ch341-uart
[ 0.577712] usbcore: registered new interface driver cp210x
[ 0.578066] usbserial: USB Serial support registered for cp210x
[ 0.578645] usbcore: registered new interface driver ftdi_sio
[ 0.579145] usbserial: USB Serial support registered for FTDI USB Serial Device
[ 0.579937] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[ 0.580445] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 1
[ 0.580992] vhci_hcd: created sysfs vhci_hcd.0
[ 0.581772] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 0.582650] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.583447] usb usb1: Product: USB/IP Virtual Host Controller
[ 0.584023] usb usb1: Manufacturer: Linux 5.15.57.1-microsoft-standard-WSL2 vhci_hcd
[ 0.584818] usb usb1: SerialNumber: vhci_hcd.0
[ 0.585555] hub 1-0:1.0: USB hub found
[ 0.585850] hub 1-0:1.0: 8 ports detected
[ 0.586910] vhci_hcd vhci_hcd.0: USB/IP Virtual Host Controller
[ 0.587382] vhci_hcd vhci_hcd.0: new USB bus registered, assigned bus number 2
[ 0.588000] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[ 0.589056] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 0.589821] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.590711] usb usb2: Product: USB/IP Virtual Host Controller
[ 0.591363] usb usb2: Manufacturer: Linux 5.15.57.1-microsoft-standard-WSL2 vhci_hcd
[ 0.592084] usb usb2: SerialNumber: vhci_hcd.0
[ 0.592813] hub 2-0:1.0: USB hub found
[ 0.593107] hub 2-0:1.0: 8 ports detected
[ 0.593983] hv_vmbus: registering driver hyperv_keyboard
[ 0.594605] rtc_cmos 00:00: RTC can wake from S4
[ 0.596840] rtc_cmos 00:00: registered as rtc0
[ 0.597600] rtc_cmos 00:00: setting system clock to 2022-08-22T08:00:01 UTC (1661155201)
[ 0.598051] rtc_cmos 00:00: alarms up to one month, 114 bytes nvram
[ 0.599008] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: dm-devel@redhat.com
[ 0.599892] device-mapper: raid: Loading target version 1.15.1
[ 0.600321] usbcore: registered new interface driver usbhid
[ 0.600607] usbhid: USB HID core driver
[ 0.600905] hv_utils: Registering HyperV Utility Driver
[ 0.601212] hv_vmbus: registering driver hv_utils
[ 0.601529] hv_vmbus: registering driver hv_balloon
[ 0.601955] hv_utils: TimeSync IC version 4.0
[ 0.602070] hv_vmbus: registering driver dxgkrnl
[ 0.602695] hv_balloon: Using Dynamic Memory protocol version 2.0
[ 0.602966] (NULL device *): dxgk: dxg_drv_init Version: 2216
[ 0.604083] Free page reporting enabled
[ 0.604935] hv_balloon: Cold memory discard hint enabled
[ 0.605207] (NULL device *): dxgk: mmio allocated 9ffe10000 200000000 9ffe10000 bffe0ffff
[ 0.607204] drop_monitor: Initializing network drop monitor service
[ 0.607619] Mirror/redirect action on
[ 0.607838] u32 classifier
[ 0.607979] Performance counters on
[ 0.608191] input device check on
[ 0.608598] Actions configured
[ 0.610040] IPVS: Registered protocols (TCP, UDP)
[ 0.610782] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[ 0.611723] IPVS: ipvs loaded.
[ 0.612175] IPVS: [rr] scheduler registered.
[ 0.612726] IPVS: [wrr] scheduler registered.
[ 0.613128] IPVS: [sh] scheduler registered.
[ 0.613757] ipip: IPv4 and MPLS over IPv4 tunneling driver
[ 0.614282] ipt_CLUSTERIP: ClusterIP Version 0.8 loaded successfully
[ 0.615128] Initializing XFRM netlink socket
[ 0.615847] NET: Registered PF_INET6 protocol family
[ 0.616899] Segment Routing with IPv6
[ 0.617223] In-situ OAM (IOAM) with IPv6
[ 0.617495] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 0.617956] NET: Registered PF_PACKET protocol family
[ 0.618439] Bridge firewalling registered
[ 0.618981] 8021q: 802.1Q VLAN Support v1.8
[ 0.619413] sctp: Hash tables configured (bind 256/256)
[ 0.619964] 9pnet: Installing 9P2000 support
[ 0.638729] Key type dns_resolver registered
[ 0.639329] NET: Registered PF_VSOCK protocol family
[ 0.639679] hv_vmbus: registering driver hv_sock
[ 0.640044] IPI shorthand broadcast: enabled
[ 0.640353] sched_clock: Marking stable (635206231, 4103200)->(663903900, -24594469)
[ 0.641290] registered taskstats version 1
[ 0.642227] Loading compiled-in X.509 certificates
[ 0.643590] Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=no
[ 0.652165] Freeing unused kernel image (initmem) memory: 2000K
[ 0.677143] Write protecting the kernel read-only data: 30720k
[ 0.679320] Freeing unused kernel image (text/rodata gap) memory: 2024K
[ 0.680719] Freeing unused kernel image (rodata/data gap) memory: 684K
[ 0.681327] Run /init as init process
[ 0.681674] with arguments:
[ 0.682039] /init
[ 0.682297] with environment:
[ 0.682878] HOME=/
[ 0.683221] TERM=linux
[ 0.683490] WSL_ROOT_INIT=1
[ 0.711691] scsi 0:0:0:0: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5
[ 0.714190] sd 0:0:0:0: Attached scsi generic sg0 type 0
[ 0.718191] sd 0:0:0:0: [sda] 751192 512-byte logical blocks: (385 MB/367 MiB)
[ 0.720908] sd 0:0:0:0: [sda] Write Protect is on
[ 0.724487] sd 0:0:0:0: [sda] Mode Sense: 0f 00 80 00
[ 0.726716] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 1.309858] EXT4-fs (sda): mounted filesystem without journal. Opts: (null). Quota mode: none.
[ 1.467164] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2b2c993ffe9, max_idle_ns: 440795229210 ns
[ 1.468089] sd 0:0:0:0: [sda] Attached SCSI disk
[ 1.472928] clocksource: Switched to clocksource tsc
[ 1.493865] hv_pci cec6f92f-4430-41b5-bc11-a2ca4c7ec259: PCI VMBus probing: Using version 0x10004
[ 1.497033] hv_pci cec6f92f-4430-41b5-bc11-a2ca4c7ec259: PCI host bridge to bus 4430:00
[ 1.497562] pci_bus 4430:00: root bus resource [mem 0xc00000000-0xe00001fff window]
[ 1.498058] pci_bus 4430:00: No busn resource found for root bus, will use [bus 00-ff]
[ 1.500021] pci 4430:00:00.0: [1af4:105a] type 00 class 0x088000
[ 1.502845] pci 4430:00:00.0: reg 0x10: [mem 0xe00000000-0xe00000fff 64bit]
[ 1.505389] pci 4430:00:00.0: reg 0x18: [mem 0xe00001000-0xe00001fff 64bit]
[ 1.508715] pci 4430:00:00.0: reg 0x20: [mem 0xc00000000-0xdffffffff 64bit]
[ 1.514113] pci_bus 4430:00: busn_res: [bus 00-ff] end is updated to 00
[ 1.514540] pci 4430:00:00.0: BAR 4: assigned [mem 0xc00000000-0xdffffffff 64bit]
[ 1.517059] pci 4430:00:00.0: BAR 0: assigned [mem 0xe00000000-0xe00000fff 64bit]
[ 1.519942] pci 4430:00:00.0: BAR 2: assigned [mem 0xe00001000-0xe00001fff 64bit]
[ 1.536375] virtiofs virtio2: Cache len: 0x200000000 @ 0xc00000000
[ 1.577115] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 1.637472] memmap_init_zone_device initialised 2097152 pages in 60ms
[ 1.650338] FS-Cache: Duplicate cookie detected
[ 1.651103] FS-Cache: O-cookie c=00000004 [p=00000002 fl=222 nc=0 na=1]
[ 1.651935] FS-Cache: O-cookie d=000000002bd5225d{9P.session} n=0000000099698695
[ 1.653008] FS-Cache: O-key=[10] '34323934393337343530'
[ 1.653475] FS-Cache: N-cookie c=00000005 [p=00000002 fl=2 nc=0 na=1]
[ 1.653945] FS-Cache: N-cookie d=000000002bd5225d{9P.session} n=00000000982b3412
[ 1.654580] FS-Cache: N-key=[10] '34323934393337343530'
[ 2.487873] scsi 0:0:0:1: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5
[ 2.491248] sd 0:0:0:1: Attached scsi generic sg1 type 0
[ 2.493354] scsi 0:0:0:2: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5
[ 2.495934] sd 0:0:0:2: Attached scsi generic sg2 type 0
[ 2.497608] sd 0:0:0:1: [sdb] 8388616 512-byte logical blocks: (4.29 GB/4.00 GiB)
[ 2.500577] sd 0:0:0:2: [sdc] 536870912 512-byte logical blocks: (275 GB/256 GiB)
[ 2.500604] sd 0:0:0:1: [sdb] 4096-byte physical blocks
[ 2.502227] sd 0:0:0:2: [sdc] 4096-byte physical blocks
[ 2.503957] sd 0:0:0:2: [sdc] Write Protect is off
[ 2.505454] sd 0:0:0:1: [sdb] Write Protect is off
[ 2.512054] sd 0:0:0:2: [sdc] Mode Sense: 0f 00 00 00
[ 2.514400] sd 0:0:0:2: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 2.514742] sd 0:0:0:1: [sdb] Mode Sense: 0f 00 00 00
[ 2.516870] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 2.533731] sd 0:0:0:2: [sdc] Attached SCSI disk
[ 2.535827] sd 0:0:0:1: [sdb] Attached SCSI disk
[ 2.563522] EXT4-fs (sdc): recovery complete
[ 2.566284] EXT4-fs (sdc): mounted filesystem with ordered data mode. Opts: discard,errors=remount-ro,data=ordered. Quota mode: none.
[ 2.611540] Adding 4194304k swap on /dev/sdb. Priority:-2 extents:1 across:4194304k
[ 3.017178] hv_pci 3f065d71-13f6-4084-8acc-2ce36462f266: PCI VMBus probing: Using version 0x10004
[ 3.020163] hv_pci 3f065d71-13f6-4084-8acc-2ce36462f266: PCI host bridge to bus 13f6:00
[ 3.020873] pci_bus 13f6:00: root bus resource [mem 0x9ffe08000-0x9ffe0afff window]
[ 3.021440] pci_bus 13f6:00: No busn resource found for root bus, will use [bus 00-ff]
[ 3.022986] pci 13f6:00:00.0: [1af4:1049] type 00 class 0x010000
[ 3.024388] pci 13f6:00:00.0: reg 0x10: [mem 0x9ffe08000-0x9ffe08fff 64bit]
[ 3.025478] pci 13f6:00:00.0: reg 0x18: [mem 0x9ffe09000-0x9ffe09fff 64bit]
[ 3.026583] pci 13f6:00:00.0: reg 0x20: [mem 0x9ffe0a000-0x9ffe0afff 64bit]
[ 3.030711] pci_bus 13f6:00: busn_res: [bus 00-ff] end is updated to 00
[ 3.031192] pci 13f6:00:00.0: BAR 0: assigned [mem 0x9ffe08000-0x9ffe08fff 64bit]
[ 3.032238] pci 13f6:00:00.0: BAR 2: assigned [mem 0x9ffe09000-0x9ffe09fff 64bit]
[ 3.033232] pci 13f6:00:00.0: BAR 4: assigned [mem 0x9ffe0a000-0x9ffe0afff 64bit]
[ 3.266120] hv_pci e5cfe5d3-45fb-499d-8d56-9d683fba61a5: PCI VMBus probing: Using version 0x10004
[ 3.272238] hv_pci e5cfe5d3-45fb-499d-8d56-9d683fba61a5: PCI host bridge to bus 45fb:00
[ 3.272999] pci_bus 45fb:00: root bus resource [mem 0x9ffe0c000-0x9ffe0efff window]
[ 3.273835] pci_bus 45fb:00: No busn resource found for root bus, will use [bus 00-ff]
[ 3.276681] pci 45fb:00:00.0: [1af4:1049] type 00 class 0x010000
[ 3.279754] pci 45fb:00:00.0: reg 0x10: [mem 0x9ffe0c000-0x9ffe0cfff 64bit]
[ 3.281567] pci 45fb:00:00.0: reg 0x18: [mem 0x9ffe0d000-0x9ffe0dfff 64bit]
[ 3.283275] pci 45fb:00:00.0: reg 0x20: [mem 0x9ffe0e000-0x9ffe0efff 64bit]
[ 3.291837] pci_bus 45fb:00: busn_res: [bus 00-ff] end is updated to 00
[ 3.293380] pci 45fb:00:00.0: BAR 0: assigned [mem 0x9ffe0c000-0x9ffe0cfff 64bit]
[ 3.296121] pci 45fb:00:00.0: BAR 2: assigned [mem 0x9ffe0d000-0x9ffe0dfff 64bit]
[ 3.298857] pci 45fb:00:00.0: BAR 4: assigned [mem 0x9ffe0e000-0x9ffe0efff 64bit]
[ 49.429818] hv_balloon: Max. dynamic memory size: 16300 MB

@benhillis
Copy link
Member

3-4 seconds is about standard. I'll sync up with the vhdx team to see if there's any way to speed things up more than that.

@senlinding
Copy link

After today's update, I also encountered the problem of slow startup.

@senlinding
Copy link

image

@stanmart
Copy link

stanmart commented Jan 20, 2023

I have the exact same issue and similar logs to @senlinding with hv_balloon and hv_pci taking a long time. It is a relatively new phenomenon. Startup used to take 4-5 seconds a few months ago, and now it is around a minute. There has been no major changes to my system either on the Windows or Linux side apart from regular Windows Updates and apt upgrades.

I have also noticed that starting Ubuntu as administrator is quick as expected (~4s), but starting it normally leads to a long start-up time.

@logularjason
Copy link

[ 4.225021] pci a0fc:00:00.0: BAR 4: assigned [mem 0xbffe16000-0xbffe16fff 64bit]
[ 49.732478] hv_balloon: Max. dynamic memory size: 8060 MB

Same with me. 45s startup. Fresh install of ubunu under windows 11 and everything up to date with patches.

@stanmart
Copy link

stanmart commented Feb 3, 2023

@logularjason, could you perhaps check if the startup is also slow when you start Ubuntu in an admin terminal window?

@logularjason
Copy link

@logularjason, could you perhaps check if the startup is also slow when you start Ubuntu in an admin terminal window?

Hi @stanmart - thanks for the suggestion. I can confirm it starts in around 3s-4s when I run "wsl.exe" from cmd as admin.

What are implications for this? i.e. are you trying to confirm/identify a bug? I guess this is a work-around until a fix is available, or are you implying startup of ubuntu a different way?

@stanmart
Copy link

stanmart commented Feb 6, 2023

Thanks for checking! I'm just hoping that it might be useful info for WSL maintainers for figuring out what the issue is. Seems peculiar so it might narrow things down a bit.

Copy link
Contributor

This issue has been automatically closed since it has not had any activity for the past year. If you're still experiencing this issue please re-file this as a new issue or feature request.

Thank you!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants