linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* kdump always hangs in rcu_barrier() -> wait_for_completion()
@ 2020-11-25  4:56 Dexuan Cui
  2020-11-26 15:46 ` Paul E. McKenney
  0 siblings, 1 reply; 8+ messages in thread
From: Dexuan Cui @ 2020-11-25  4:56 UTC (permalink / raw)
  To: Paul E. McKenney, boqun.feng, Ingo Molnar, rcu, vkuznets
  Cc: Michael Kelley, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 2559 bytes --]

Hi,
I happened to hit a kdump hang issue in a Linux VM running on some
Hyper-V host. Please see the attached log: the kdump kernel always hangs,
even if I configure only 1 virtual CPU to the VM.

I firstly hit the issue in RHEL 8.3's 4.18.x kernel, but later I found that 
the latest upstream v5.10-rc5 also has the same issue (at least the
symptom is exactly the same), so I dug into v5.10-rc5 and found that the
kdump kernel always hangs in kernel_init() -> mark_readonly() ->
rcu_barrier() -> wait_for_completion(&rcu_state.barrier_completion).

Let's take the 1-vCPU case for example (refer to the attached log): in the
below code, somehow rcu_segcblist_n_cbs() returns true, so the call
smp_call_function_single(cpu, rcu_barrier_func, (void *)cpu, 1) increases
the counter by 1, and hence later the counter is still 1 after the
atomic_sub_and_test(), and the complete() is not called.

static void rcu_barrier_func(void *cpu_in)
{
        ...
        if (rcu_segcblist_entrain(&rdp->cblist, &rdp->barrier_head)) {
                atomic_inc(&rcu_state.barrier_cpu_count);
        } else {
        ...
}

void rcu_barrier(void)
{
        ...
        atomic_set(&rcu_state.barrier_cpu_count, 2);
        ...
        for_each_possible_cpu(cpu) {
                rdp = per_cpu_ptr(&rcu_data, cpu);
                ...
                if (rcu_segcblist_n_cbs(&rdp->cblist) && cpu_online(cpu)) {
                        ...
                        smp_call_function_single(cpu, rcu_barrier_func, (void *)cpu, 1);
                        ...
                }
        }
        ...
        if (atomic_sub_and_test(2, &rcu_state.barrier_cpu_count))
                complete(&rcu_state.barrier_completion);

        ...
        wait_for_completion(&rcu_state.barrier_completion);

Sorry for my ignorance of RCU -- I'm not sure why the rcu_segcblist_n_cbs()
returns 1 here. In the normal kernel, it returns 0, so the normal kernel does not
hang.

Note: in the case of kdump kernel, if I remove the kernel parameter
console=ttyS0 OR if I build the kernel with CONFIG_HZ=250, the issue can
no longer reproduce. Currently my kernel uses CONFIG_HZ=1000 and I use
console=ttyS0, so I'm able to reproduce the isue every time.

Note: the same kernel binary can not reproduce the issue when the VM
runs on another Hyper-V host.

It looks there is some kind of race condition?

Looking forward to your insights!

I'm happy to test any patch or enable more tracing, if necessary. Thanks!

Thanks,
-- Dexuan

[-- Attachment #2: bad-hz-1000.log --]
[-- Type: application/octet-stream, Size: 78840 bytes --]

[    0.000000] Linux version 5.10.0-rc5+ (root@g2) (gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1 SMP Tue Nov 24 20:05:18 PST 2020
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-rc5+ root=UUID=b3930775-6a55-4cd0-99e7-971baa76a345 ro earlyprintk=ttyS0 ignore_loglevel sysrq_always_enabled unknown_nmi_panic console=ttyS0 crashkernel=2G cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 acpi_no_memhotplug transparent_hugepage=never nokaslr novmcoredd hest_disable disable_cpu_apicid=0 video=efifb:off=
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Hygon HygonGenuine
[    0.000000]   Centaur CentaurHauls
[    0.000000]   zhaoxin   Shanghai
[    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] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000c0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000009fff1fff] usable
[    0.000000] BIOS-e820: [mem 0x000000009fff2000-0x000000009fff2fff] reserved
[    0.000000] BIOS-e820: [mem 0x000000009fff3000-0x00000000f6d4afff] usable
[    0.000000] BIOS-e820: [mem 0x00000000f6d4b000-0x00000000f6d4bfff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f6d4c000-0x00000000f6e7afff] usable
[    0.000000] BIOS-e820: [mem 0x00000000f6e7b000-0x00000000f6e99fff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f6e9a000-0x00000000f6ef1fff] usable
[    0.000000] BIOS-e820: [mem 0x00000000f6ef2000-0x00000000f6f1afff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000f6f1b000-0x00000000f7f9afff] usable
[    0.000000] BIOS-e820: [mem 0x00000000f7f9b000-0x00000000f7ff2fff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000f7ff3000-0x00000000f7ffafff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f7ffb000-0x00000000f7ffefff] ACPI NVS
[    0.000000] BIOS-e820: [mem 0x00000000f7fff000-0x00000000f7ffffff] usable
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x0000000c87ffffff] usable
[    0.000000] printk: bootconsole [earlyser0] enabled
[    0.000000] printk: debug: ignoring loglevel setting.
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] efi: EFI v2.70 by Microsoft
[    0.000000] efi: ACPI=0xf7ffa000 ACPI 2.0=0xf7ffa014 SMBIOS=0xf7fd8000 SMBIOS 3.0=0xf7fd6000 MEMATTR=0xf7331798 RNG=0xf7fda818
[    0.000000] efi: seeding entropy pool
[    0.000000] random: fast init done
[    0.000000] SMBIOS 3.1.0 present.
[    0.000000] DMI: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 10/26/2020
[    0.000000] Hypervisor detected: Microsoft Hyper-V
[    0.000000] Hyper-V: features 0xae7f, hints 0xe0e24, misc 0xe0bed7b2
[    0.000000] Hyper-V Host Build:21261-10.0-1-0.1005
[    0.000000] Hyper-V: LAPIC Timer Frequency: 0x30d40
[    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.000002] tsc: Detected 2693.671 MHz processor
[    0.001784] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.004415] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.006681] last_pfn = 0xc88000 max_arch_pfn = 0x400000000
[    0.008929] MTRR default type: uncachable
[    0.010554] MTRR fixed ranges enabled:
[    0.012081]   00000-9FFFF write-back
[    0.013531]   A0000-FFFFF uncachable
[    0.014973] MTRR variable ranges enabled:
[    0.016583]   0 base 000000000000 mask 3FFF00000000 write-back
[    0.018951]   1 base 000100000000 mask 3FF000000000 write-back
[    0.021317]   2 disabled
[    0.022340]   3 disabled
[    0.023358]   4 disabled
[    0.024360]   5 disabled
[    0.025450]   6 disabled
[    0.026363]   7 disabled
[    0.027283] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT
[    0.029863] last_pfn = 0xf8000 max_arch_pfn = 0x400000000
[    0.044446] check: Scanning 1 areas for low memory corruption
[    0.048079] kexec: Reserving the low 1M of memory for crashkernel
[    0.051916] Using GB pages for direct mapping
[    0.055251] Secure boot disabled
[    0.057251] RAMDISK: [mem 0x122eb000-0x3fffdfff]
[    0.059915] ACPI: Early table checksum verification disabled
[    0.063000] ACPI: RSDP 0x00000000F7FFA014 000024 (v02 VRTUAL)
[    0.065393] ACPI: XSDT 0x00000000F7FF90E8 00005C (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.068943] ACPI: FACP 0x00000000F7FF8000 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.072481] ACPI: DSDT 0x00000000F6E7B000 01E184 (v02 MSFTVM DSDT01   00000001 MSFT 05000000)
[    0.076013] ACPI: FACS 0x00000000F7FFE000 000040
[    0.077927] ACPI: OEM0 0x00000000F7FF7000 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.081656] ACPI: WAET 0x00000000F7FF6000 000028 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.085231] ACPI: APIC 0x00000000F7FF5000 000050 (v04 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.088811] ACPI: SRAT 0x00000000F7FF4000 0002C0 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.091936] ACPI: BGRT 0x00000000F7FF3000 000038 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.095264] ACPI: FPDT 0x00000000F6D4B000 000034 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.098609] ACPI: Local APIC address 0xfee00000
[    0.101199] NUMA turned off
[    0.102924] Faking a node at [mem 0x0000000000000000-0x0000000c87ffffff]
[    0.106777] NODE_DATA(0) allocated [mem 0xc87fd3000-0xc87ffdfff]
[    0.109544] Reserving 256MB of low memory at 3680MB for crashkernel (low RAM limit: 4096MB)
[    0.113012] Reserving 2048MB of memory at 49264MB for crashkernel (System RAM: 51198MB)
[    0.117884] Zone ranges:
[    0.119448]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.123086]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.126887]   Normal   [mem 0x0000000100000000-0x0000000c87ffffff]
[    0.130742]   Device   empty
[    0.132530] Movable zone start for each node
[    0.134792] Early memory node ranges
[    0.136411]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.139050]   node   0: [mem 0x0000000000100000-0x000000009fff1fff]
[    0.141953]   node   0: [mem 0x000000009fff3000-0x00000000f6d4afff]
[    0.145854]   node   0: [mem 0x00000000f6d4c000-0x00000000f6e7afff]
[    0.149264]   node   0: [mem 0x00000000f6e9a000-0x00000000f6ef1fff]
[    0.151809]   node   0: [mem 0x00000000f6f1b000-0x00000000f7f9afff]
[    0.154117]   node   0: [mem 0x00000000f7fff000-0x00000000f7ffffff]
[    0.156497]   node   0: [mem 0x0000000100000000-0x0000000c87ffffff]
[    0.158931] Zeroed struct page in unavailable ranges: 271 pages
[    0.158932] Initmem setup node 0 [mem 0x0000000000001000-0x0000000c87ffffff]
[    0.164128] On node 0 totalpages: 13106929
[    0.165828]   DMA zone: 64 pages used for memmap
[    0.167887]   DMA zone: 1481 pages reserved
[    0.169650]   DMA zone: 3999 pages, LIFO batch:0
[    0.171629]   DMA32 zone: 16320 pages used for memmap
[    0.173831]   DMA32 zone: 1011538 pages, LIFO batch:63
[    0.183318]   Normal zone: 188928 pages used for memmap
[    0.186314]   Normal zone: 12091392 pages, LIFO batch:63
[    0.276124] ACPI: PM-Timer IO Port: 0x408
[    0.278642] ACPI: Local APIC address 0xfee00000
[    0.281462] ACPI: LAPIC_NMI (acpi_id[0x01] dfl dfl lint[0x1])
[    0.285307] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
[    0.288564] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.291267] ACPI: IRQ9 used by override.
[    0.292847] Using ACPI (MADT) for SMP configuration information
[    0.295195] TSC deadline timer available
[    0.296578] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.298443] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.301353] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000bffff]
[    0.304270] PM: hibernation: Registered nosave memory: [mem 0x000c0000-0x000fffff]
[    0.307339] PM: hibernation: Registered nosave memory: [mem 0x9fff2000-0x9fff2fff]
[    0.310439] PM: hibernation: Registered nosave memory: [mem 0xf6d4b000-0xf6d4bfff]
[    0.313506] PM: hibernation: Registered nosave memory: [mem 0xf6e7b000-0xf6e99fff]
[    0.316578] PM: hibernation: Registered nosave memory: [mem 0xf6ef2000-0xf6f1afff]
[    0.319649] PM: hibernation: Registered nosave memory: [mem 0xf7f9b000-0xf7ff2fff]
[    0.322714] PM: hibernation: Registered nosave memory: [mem 0xf7ff3000-0xf7ffafff]
[    0.325845] PM: hibernation: Registered nosave memory: [mem 0xf7ffb000-0xf7ffefff]
[    0.328523] PM: hibernation: Registered nosave memory: [mem 0xf8000000-0xffffffff]
[    0.331489] [mem 0xf8000000-0xffffffff] available for PCI devices
[    0.333817] Booting paravirtualized kernel on Hyper-V
[    0.335744] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.339958] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
[    0.343365] percpu: Embedded 54 pages/cpu s184320 r8192 d28672 u2097152
[    0.346050] pcpu-alloc: s184320 r8192 d28672 u2097152 alloc=1*2097152
[    0.348654] pcpu-alloc: [0] 0
[    0.349908] Hyper-V: PV spinlocks enabled
[    0.351532] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.354477] Built 1 zonelists, mobility grouping on.  Total pages: 12900136
[    0.357379] Policy zone: Normal
[    0.358489] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-rc5+ root=UUID=b3930775-6a55-4cd0-99e7-971baa76a345 ro earlyprintk=ttyS0 ignore_loglevel sysrq_always_enabled unknown_nmi_panic console=ttyS0 crashkernel=2G cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 acpi_no_memhotplug transparent_hugepage=never nokaslr novmcoredd hest_disable disable_cpu_apicid=0 video=efifb:off=
[    0.372245] sysrq: sysrq always enabled.
[    0.383142] Dentry cache hash table entries: 8388608 (order: 14, 67108864 bytes, linear)
[    0.393021] Inode-cache hash table entries: 4194304 (order: 13, 33554432 bytes, linear)
[    0.398151] mem auto-init: stack:off, heap alloc:on, heap free:off
[    0.514862] Memory: 48287208K/52427716K available (14346K kernel code, 3334K rwdata, 4776K rodata, 2376K init, 6440K bss, 4140252K reserved, 0K cma-reserved)
[    0.523617] random: get_random_u64 called from __kmem_cache_create+0x31/0x430 with crng_init=1
[    0.523699] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.531502] ftrace: allocating 44357 entries in 174 pages
[    0.547603] ftrace: allocated 174 pages with 5 groups
[    0.550877] rcu: Hierarchical RCU implementation.
[    0.553827] rcu:     RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=1.
[    0.558000]  Rude variant of Tasks RCU enabled.
[    0.560496]  Tracing variant of Tasks RCU enabled.
[    0.562459] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[    0.565281] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.570750] Using NULL legacy PIC
[    0.572135] NR_IRQS: 524544, nr_irqs: 256, preallocated irqs: 0
[    0.574834] random: crng done (trusting CPU's manufacturer)
[    0.577129] Console: colour dummy device 80x25
[    0.579278] printk: console [ttyS0] enabled
[    0.579278] printk: console [ttyS0] enabled
[    0.582811] printk: bootconsole [earlyser0] disabled
[    0.582811] printk: bootconsole [earlyser0] disabled
[    0.587009] ACPI: Core revision 20200925
[    0.588809] Failed to register legacy timer interrupt
[    0.590968] APIC: Switch to symmetric I/O mode setup
[    0.595467] x2apic enabled
[    0.596535] Switched APIC routing to physical x2apic.
[    0.598525] Hyper-V: Using IPI hypercalls
[    0.600240] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x26d3e3bf8bb, max_idle_ns: 440795220752 ns
[    0.605205] Calibrating delay loop (skipped), value calculated using timer frequency.. 5387.34 BogoMIPS (lpj=2693671)
[    0.606205] pid_max: default: 32768 minimum: 301
[    0.607720] LSM: Security Framework initializing
[    0.608214] Yama: becoming mindful.
[    0.609235] AppArmor: AppArmor initialized
[    0.610355] Mount-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.611332] Mountpoint-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.612402] Disabling memory control group subsystem
Poking KASLR using RDRAND RDTSC...
[    0.614372] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.615205] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.616211] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.617206] Spectre V2 : Mitigation: Enhanced IBRS
[    0.618204] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.619206] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.620207] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.621204] TAA: Mitigation: TSX disabled
[    0.625424] Freeing SMP alternatives memory: 40K
[    0.627099] smpboot: CPU0: Intel(R) Xeon(R) Platinum 8270 CPU @ 2.70GHz (family: 0x6, model: 0x55, stepping: 0x7)
[    0.627320] Performance Events: unsupported p6 CPU model 85 no PMU driver, software events only.
[    0.628235] rcu: Hierarchical SRCU implementation.
[    0.629484] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.630240] smp: Bringing up secondary CPUs ...
[    0.631206] smp: Brought up 1 node, 1 CPU
[    0.632205] smpboot: Max logical packages: 1
[    0.633206] smpboot: Total of 1 processors activated (5387.34 BogoMIPS)
[    0.635516] devtmpfs: initialized
[    0.636237] x86/mm: Memory block size: 128MB
[    0.639747] PM: Registering ACPI NVS region [mem 0xf7ffb000-0xf7ffefff] (16384 bytes)
[    0.640305] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.641211] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
[    0.642248] pinctrl core: initialized pinctrl subsystem
[    0.643638] PM: RTC time: 04:13:59, date: 2020-11-25
[    0.644305] NET: Registered protocol family 16
[    0.646097] DMA: preallocated 4096 KiB GFP_KERNEL pool for atomic allocations
[    0.647003] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.647978] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.648213] audit: initializing netlink subsys (disabled)
[    0.649310] thermal_sys: Registered thermal governor 'fair_share'
[    0.649311] thermal_sys: Registered thermal governor 'bang_bang'
[    0.650206] thermal_sys: Registered thermal governor 'step_wise'
[    0.651205] thermal_sys: Registered thermal governor 'user_space'
[    0.652214] EISA bus registered
[    0.654209] audit: type=2000 audit(1606277639.046:1): state=initialized audit_enabled=0 res=1
[    0.655208] cpuidle: using governor ladder
[    0.656205] cpuidle: using governor menu
[    0.657287] ACPI: bus type PCI registered
[    0.658205] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.660622] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.661208] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.662858] ACPI: Added _OSI(Module Device)
[    0.663211] ACPI: Added _OSI(Processor Device)
[    0.664205] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.665205] ACPI: Added _OSI(Processor Aggregator Device)
[    0.666213] ACPI: Added _OSI(Linux-Dell-Video)
[    0.667242] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.668209] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.673810] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.674974] ACPI: Interpreter enabled
[    0.675213] ACPI: (supports S0 S5)
[    0.676205] ACPI: Using IOAPIC for interrupt routing
[    0.677213] HEST: Table parsing disabled.
[    0.678206] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.679263] ACPI: Enabled 1 GPEs in block 00 to 0F
[    0.680750] iommu: Default domain type: Translated
[    0.681226] vgaarb: loaded
[    0.682281] SCSI subsystem initialized
[    0.683231] libata version 3.00 loaded.
[    0.684220] ACPI: bus type USB registered
[    0.685215] usbcore: registered new interface driver usbfs
[    0.686210] usbcore: registered new interface driver hub
[    0.687219] usbcore: registered new device driver usb
[    0.688215] pps_core: LinuxPPS API ver. 1 registered
[    0.689205] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.690207] PTP clock support registered
[    0.691239] EDAC MC: Ver: 3.0.0
[    0.692260] Registered efivars operations
[    0.693359] NetLabel: Initializing
[    0.694205] NetLabel:  domain hash size = 128
[    0.695205] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.696224] NetLabel:  unlabeled traffic allowed by default
[    0.697235] PCI: Using ACPI for IRQ routing
[    0.698205] PCI: System does not support PCI
[    0.699922] clocksource: Switched to clocksource tsc-early
[    0.711442] VFS: Disk quotas dquot_6.6.0
[    0.713909] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.718170] AppArmor: AppArmor Filesystem Enabled
[    0.720984] pnp: PnP ACPI init
[    0.722162] pnp 00:00: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.724620] pnp 00:01: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.727117] pnp 00:02: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.729621] pnp: PnP ACPI: found 3 devices
[    0.736362] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.740840] NET: Registered protocol family 2
[    0.742947] tcp_listen_portaddr_hash hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.747696] TCP established hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.753339] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[    0.756621] TCP: Hash tables configured (established 524288 bind 65536)
[    0.759582] UDP hash table entries: 32768 (order: 8, 1048576 bytes, linear)
[    0.763064] UDP-Lite hash table entries: 32768 (order: 8, 1048576 bytes, linear)
[    0.767904] NET: Registered protocol family 1
[    0.770160] NET: Registered protocol family 44
[    0.772025] PCI: CLS 0 bytes, default 64
[    0.773713] Trying to unpack rootfs image as initramfs...
[    2.118310] Initramfs unpacking failed: Decoding failed
[    2.257636] Freeing initrd memory: 750668K
[    2.260310] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    2.264330] software IO TLB: mapped [mem 0x00000000e2000000-0x00000000e6000000] (64MB)
[    2.269451] check: Scanning for low memory corruption every 60 seconds
[    2.272541] Initialise system trusted keyrings
[    2.274441] Key type blacklist registered
[    2.276165] workingset: timestamp_bits=36 max_order=24 bucket_order=0
[    2.279633] zbud: loaded
[    2.280926] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    2.283335] fuse: init (API version 7.32)
[    2.284974] integrity: Platform Keyring initialized
[    2.293521] Key type asymmetric registered
[    2.296087] Asymmetric key parser 'x509' registered
[    2.298425] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[    2.301441] io scheduler mq-deadline registered
[    2.303359] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    2.306129] intel_idle: Please enable MWAIT in BIOS SETUP
[    2.308475] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    2.311368] 00:00: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    2.314586] 00:01: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    2.317605] serial8250: ttyS2 at I/O 0x3e8 (irq = 4, base_baud = 115200) is a 16550A
[    2.320917] serial8250: ttyS3 at I/O 0x2e8 (irq = 3, base_baud = 115200) is a 16550A
[    2.324597] Linux agpgart interface v0.103
[    2.327462] loop: module loaded
[    2.329774] libphy: Fixed MDIO Bus: probed
[    2.332096] tun: Universal TUN/TAP device driver, 1.6
[    2.334231] PPP generic driver version 2.4.2
[    2.336037] VFIO - User Level meta-driver version: 0.3
[    2.338233] i8042: PNP: No PS/2 controller found.
[    2.340231] mousedev: PS/2 mouse device common for all mice
[    2.342667] rtc_cmos 00:02: RTC can wake from S4
[    2.366161] rtc_cmos 00:02: registered as rtc0
[    2.369262] rtc_cmos 00:02: setting system clock to 2020-11-25T04:14:01 UTC (1606277641)
[    2.373504] rtc_cmos 00:02: alarms up to one month, 114 bytes nvram
[    2.376085] device-mapper: uevent: version 1.0.3
[    2.377806] device-mapper: ioctl: 4.43.0-ioctl (2020-10-01) initialised: dm-devel@redhat.com
[    2.380985] platform eisa.0: Probing EISA bus 0
[    2.382750] platform eisa.0: EISA: Detected 0 cards
[    2.384636] intel_pstate: Intel P-state driver initializing
[    2.386928] EFI Variables Facility v0.08 2004-May-17
[    2.392489] drop_monitor: Initializing network drop monitor service
[    2.395184] NET: Registered protocol family 10
[    2.400852] Segment Routing with IPv6
[    2.402788] NET: Registered protocol family 17
[    2.404689] Key type dns_resolver registered
[    2.406572] mce: Unable to init MCE device (rc: -5)
[    2.408537] IPI shorthand broadcast: enabled
[    2.410191] sched_clock: Marking stable (2381777196, 28401800)->(2551395100, -141216104)
[    2.413440] registered taskstats version 1
[    2.415094] Loading compiled-in X.509 certificates
[    2.417633] Loaded X.509 cert 'Build time autogenerated kernel key: d2d6d33637fd863baea8e181dc8d2e48b9378be2'
[    2.421810] zswap: loaded using pool lzo/zbud
[    2.423722] Key type ._fscrypt registered
[    2.425831] Key type .fscrypt registered
[    2.428398] Key type fscrypt-provisioning registered
[    2.433177] Key type encrypted registered
[    2.434956] AppArmor: AppArmor sha1 policy hashing enabled
[    2.437701] integrity: Loading X.509 certificate: UEFI:db
[    2.439976] integrity: Loaded X.509 cert 'Microsoft Windows Production PCA 2011: a92902398e16c49778cd90f99e4f9ae17c55af53'
[    2.447360] integrity: Loading X.509 certificate: UEFI:MokListRT
[    2.451141] integrity: Loaded X.509 cert 'SomeOrg: shim: a01ee84e9b37ace407961cc468c5909447878469'
[    2.456862] integrity: Loading X.509 certificate: UEFI:MokListRT
[    2.460835] integrity: Loaded X.509 cert 'Canonical Ltd. Master Certificate Authority: ad91990bc22ab1f517048c23b6655a268e345a63'
[    2.468051] ima: No TPM chip found, activating TPM-bypass!
[    2.471435] ima: Allocated hash algorithm: sha1
[    2.474261] ima: No architecture policies found
[    2.477131] evm: Initialising EVM extended attributes:
[    2.480356] evm: security.selinux
[    2.482459] evm: security.SMACK64
[    2.484652] evm: security.SMACK64EXEC
[    2.486948] evm: security.SMACK64TRANSMUTE
[    2.488700] evm: security.SMACK64MMAP
[    2.490244] evm: security.apparmor
[    2.491674] evm: security.ima
[    2.492934] evm: security.capability
[    2.494442] evm: HMAC attrs: 0x1
[    2.495971] PM:   Magic number: 12:499:212
[    2.497805] RAS: Correctable Errors collector initialized.
[    2.501584] Freeing unused decrypted memory: 2036K
[    2.504292] Freeing unused kernel image (initmem) memory: 2376K
[    2.515676] Write protecting the kernel read-only data: 22528k
[    2.519115] Freeing unused kernel image (text/rodata gap) memory: 2036K
[    2.522195] Freeing unused kernel image (rodata/data gap) memory: 1368K
[    2.537579] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[    2.541596] Run /init as init process
[    2.543905]   with arguments:
[    2.545766]     /init
[    2.547268]     acpi_no_memhotplug
[    2.548675]     nokaslr
[    2.549696]     hest_disable
[    2.550894]   with environment:
[    2.552201]     HOME=/
[    2.553200]     TERM=linux
[    2.554340]     BOOT_IMAGE=/boot/vmlinuz-5.10.0-rc5+
[    2.556376]     crashkernel=2G
Loading, please wait...
Starting version 245.4-4ubuntu3.2
[    2.687339] hv_vmbus: Vmbus version:5.2
[    2.701220] cryptd: max_cpu_qlen set to 1000
[    2.715497] AVX2 version of gcm_enc/dec engaged.
[    2.718511] AES CTR mode by8 optimization enabled
[    2.904903] hv_vmbus: registering driver hyperv_keyboard
[    2.908860] input: AT Translated Set 2 keyboard as /devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/d34b2567-b9b6-42b9-8778-0a4ec0b955bf/serio0/input/input0
[    2.927029] hid: raw HID events driver (C) Jiri Kosina
[    2.932443] hv_vmbus: registering driver hid_hyperv
[    2.936263] hv_utils: Registering HyperV Utility Driver
[    2.939629] hv_vmbus: registering driver hv_utils
[    2.942866] input: Microsoft Vmbus HID-compliant Mouse as /devices/0006:045E:0621.0001/input/input1
[    2.948776] hid 0006:045E:0621.0001: input: <UNKNOWN> HID v0.01 Mouse [Microsoft Vmbus HID-compliant Mouse] on
[    2.953105] hv_utils: Heartbeat IC version 3.0
[    2.953111] hv_utils: Shutdown IC version 3.2
[    2.956908] hv_utils: TimeSync IC version 4.0
[    2.958701] hv_utils: VSS IC version 5.0
[    2.979534] hv_vmbus: registering driver hv_storvsc
[    2.983829] hv_vmbus: registering driver hv_netvsc
[    2.987301] scsi host0: storvsc_host_t
[    2.994495] scsi 0:0:0:0: Direct-Access     Msft     Virtual Disk     1.0  PQ: 0 ANSI: 5
[    3.006560] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    3.012682] sd 0:0:0:0: [sda] 266338304 512-byte logical blocks: (136 GB/127 GiB)
[    3.016674] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    3.018659] sd 0:0:0:0: [sda] Write Protect is off
[    3.020534] sd 0:0:0:0: [sda] Mode Sense: 0f 00 00 00
[    3.022582] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    3.028339]  sda: sda1 sda2
[    3.030099] sd 0:0:0:0: [sda] Attached SCSI disk
Begin: Loading essential drivers ... [    3.161208] raid6: avx512x4 gen() 18241 MB/s
[    3.181208] raid6: avx512x4 xor()  9124 MB/s
[    3.201208] raid6: avx512x2 gen() 18304 MB/s
[    3.220207] raid6: avx512x2 xor() 25244 MB/s
[    3.239207] raid6: avx512x1 gen() 18370 MB/s
[    3.259207] raid6: avx512x1 xor() 22401 MB/s
[    3.279207] raid6: avx2x4   gen() 18348 MB/s
[    3.299206] raid6: avx2x4   xor()  7810 MB/s
[    3.319209] raid6: avx2x2   gen() 18229 MB/s
[    3.339206] raid6: avx2x2   xor() 17106 MB/s
[    3.359210] raid6: avx2x1   gen() 13999 MB/s
[    3.379206] raid6: avx2x1   xor() 14610 MB/s
[    3.399207] raid6: sse2x4   gen() 10261 MB/s
[    3.419206] raid6: sse2x4   xor()  6375 MB/s
[    3.439208] raid6: sse2x2   gen() 11030 MB/s
[    3.459207] raid6: sse2x2   xor()  6531 MB/s
[    3.479207] raid6: sse2x1   gen()  9905 MB/s
[    3.498206] raid6: sse2x1   xor()  5326 MB/s
[    3.501322] raid6: using algorithm avx512x1 gen() 18370 MB/s
[    3.505299] raid6: .... xor() 22401 MB/s, rmw enabled
[    3.508854] raid6: using avx512x2 recovery algorithm
[    3.511485] tsc: Refined TSC clocksource calibration: 2693.673 MHz
[    3.514304] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x26d3e596aaf, max_idle_ns: 440795300987 ns
[    3.518684] clocksource: Switched to clocksource tsc
[    3.522549] xor: automatically using best checksumming function   avx
[    3.527575] async_tx: api initialized (async)
done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... [    3.797009] Btrfs loaded, crc32c=crc32c-intel
Scanning for Btrfs filesystems
done.
Warning: fsck not present, so skipping root file system
[    3.823835] EXT4-fs (sda2): INFO: recovery required on readonly filesystem
[    3.828123] EXT4-fs (sda2): write access will be enabled during recovery
[    3.851953] EXT4-fs (sda2): recovery complete
[    3.855160] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
done.
Begin: Running /scripts/local-bottom ... done.
Begin: Running /scripts/init-bottom ... done.
[    4.064715] systemd[1]: Inserted module 'autofs4'
[    4.096195] systemd[1]: systemd 245.4-4ubuntu3.2 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
[    4.107165] systemd[1]: Detected virtualization microsoft.
[    4.110615] systemd[1]: Detected architecture x86-64.

Welcome to Ubuntu 20.04.1 LTS!

[    4.118293] systemd[1]: Set hostname to <g2>.
[    4.254074] systemd[1]: /lib/systemd/system/dbus.socket:5: ListenStream= references a path below legacy directory /var/run/, updating /var/run/dbus/system_bus_socket ? /run/dbus/system_bus_socket; please update the unit file accordingly.
[    4.320595] systemd[1]: Unnecessary job for /sys/devices/virtual/misc/vmbus!hv_fcopy was removed.
[    4.326132] systemd[1]: Unnecessary job for /sys/devices/virtual/misc/vmbus!hv_vss was removed.
[    4.332120] systemd[1]: Created slice system-modprobe.slice.
[  OK  ] Created slice system-modprobe.slice.
[    4.339939] systemd[1]: Created slice system-serial\x2dgetty.slice.
[  OK  ] Created slice system-serial\x2dgetty.slice.
[    4.348050] systemd[1]: Created slice User and Session Slice.
[  OK  ] Created slice User and Session Slice.
[    4.355810] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[  OK  ] Started Forward Password R…uests to Wall Directory Watch.
[    4.365626] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[  OK  ] Set up automount Arbitrary…s File System Automount Point.
[    4.376283] systemd[1]: Reached target User and Group Name Lookups.
[  OK  ] Reached target User and Group Name Lookups.
[    4.384243] systemd[1]: Reached target Slices.
[  OK  ] Reached target Slices.
[    4.390793] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[  OK  ] Listening on Device-mapper event daemon FIFOs.
[    4.399278] systemd[1]: Listening on LVM2 poll daemon socket.
[  OK  ] Listening on LVM2 poll daemon socket.
[    4.407013] systemd[1]: Listening on multipathd control socket.
[  OK  ] Listening on multipathd control socket.
[    4.414700] systemd[1]: Listening on Syslog Socket.
[  OK  ] Listening on Syslog Socket.
[    4.421658] systemd[1]: Listening on initctl Compatibility Named Pipe.
[  OK  ] Listening on initctl Compatibility Named Pipe.
[    4.430192] systemd[1]: Listening on Journal Audit Socket.
[  OK  ] Listening on Journal Audit Socket.
[    4.437666] systemd[1]: Listening on Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket (/dev/log).
[    4.445289] systemd[1]: Listening on Journal Socket.
[  OK  ] Listening on Journal Socket.
[    4.452154] systemd[1]: Listening on Network Service Netlink Socket.
[  OK  ] Listening on Network Service Netlink Socket.
[    4.460682] systemd[1]: Listening on udev Control Socket.
[  OK  ] Listening on udev Control Socket.
[    4.467943] systemd[1]: Listening on udev Kernel Socket.
[  OK  ] Listening on udev Kernel Socket.
[    4.475458] systemd[1]: Mounting Huge Pages File System...
         Mounting Huge Pages File System...
[    4.483728] systemd[1]: Mounting POSIX Message Queue File System...
         Mounting POSIX Message Queue File System...
[    4.491541] systemd[1]: Mounting Kernel Debug File System...
         Mounting Kernel Debug File System...
[    4.498655] systemd[1]: Mounting Kernel Trace File System...
         Mounting Kernel Trace File System...
[    4.506258] systemd[1]: Starting Journal Service...
         Starting Journal Service...
[    4.515383] systemd[1]: Starting Set the console keyboard layout...
         Starting Set the console keyboard layout...
[    4.532671] systemd[1]: Starting Create list of static device nodes for the current kernel...
         Starting Create list of st…odes for the current kernel...
[    4.561303] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
         Starting Monitoring of LVM…meventd or progress polling...
[    4.599657] systemd[1]: Starting Load Kernel Module drm...
         Starting Load Kernel Module drm...
[    4.624761] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[    4.646901] systemd[1]: Starting Load Kernel Modules...
         Starting Load Kernel Modules...
[    4.669554] systemd[1]: Starting Remount Root and Kernel File Systems...
         Starting Remount Root and Kernel File Systems...
[    4.685882] systemd[1]: Starting udev Coldplug all Devices...
[    4.690128] EXT4-fs (sda2): re-mounted. Opts: (null)
         Starting udev Coldplug all Devices...
[    4.697291] systemd[1]: Starting Uncomplicated firewall...
         Starting Uncomplicated firewall...
[    4.710183] systemd[1]: Started Journal Service.
[  OK  ] Started Journal Service.
[  OK  ] Mounted Huge Pages File System.
[  OK  ] Mounted POSIX Message Queue File System.
[  OK  ] Mounted Kernel Debug File System.
[  OK  ] Mounted Kernel Trace File System.
[  OK  ] Finished Set the console keyboard layout.
[  OK  ] Finished Create list of st… nodes for the current kernel.
[  OK  ] Finished Monitoring of LVM… dmeventd or progress polling.
[  OK  ] Finished Load Kernel Modules.
[  OK  ] Finished Remount Root and Kernel File Systems.
[  OK  ] Finished Uncomplicated firewall.
         Activating swap /swap.img...
         Mounting FUSE Control File System...[    4.857616] Adding 4194300k swap on /swap.img.  Priority:-2 extents:6 across:4775932k FS

         Mounting Kernel Configuration File System...
         Starting Flush Journal to Persistent Storage...
[    4.889037] systemd-journald[310]: Received client request to flush runtime journal.
         Starting Load/Save Random Seed...
         Starting Apply Kernel Variables...
[    4.911988] systemd-journald[310]: File /var/log/journal/15cdc73075664108a5a3e06779c26a69/system.journal corrupted or uncleanly shut down, renaming and replacing.
         Starting Create System Users...
[  OK  ] Activated swap /swap.img.
[  OK  ] Finished Load Kernel Module drm.
[  OK  ] Finished udev Coldplug all Devices.
[  OK  ] Mounted FUSE Control File System.
[  OK  ] Mounted Kernel Configuration File System.
[  OK  ] Finished Load/Save Random Seed.
[  OK  ] Finished Apply Kernel Variables.
[  OK  ] Finished Create System Users.
[  OK  ] Reached target Swap.
         Starting Device-Mapper Multipath Device Controller...
         Starting Create Static Device Nodes in /dev...
[    4.990622] alua: device handler registered
[    4.999217] emc: device handler registered
[    5.006508] rdac: device handler registered
[  OK  ] Finished Create Static Device Nodes in /dev.
         Starting udev Kernel Device Manager...
[  OK  ] Started Device-Mapper Multipath Device Controller.
[  OK  ] Reached target Local File Systems (Pre).
         Mounting Mount unit for core18, revision 1885...
         Mounting Mount unit for core18, revision 1932...
         Mounting Mount unit for lxd, revision 16922...
         Mounting Mount unit for lxd, revision 18150...
         Mounting Mount unit for snapd, revision 9607...
         Mounting Mount unit for snapd, revision 9721...
[  OK  ] Mounted Mount unit for core18, revision 1885.
[  OK  ] Started udev Kernel Device Manager.
[  OK  ] Mounted Mount unit for core18, revision 1932.
[  OK  ] Mounted Mount unit for lxd, revision 16922.
[  OK  ] Mounted Mount unit for lxd, revision 18150.
[  OK  ] Mounted Mount unit for snapd, revision 9607.
[  OK  ] Mounted Mount unit for snapd, revision 9721.
[  OK  ] Started Dispatch Password …ts to Console Directory Watch.
[  OK  ] Reached target Local Encrypted Volumes.
[  OK  ] Finished Flush Journal to Persistent Storage.
[    5.285601] hv_vmbus: registering driver hv_balloon
[    5.292422] hv_balloon: Using Dynamic Memory protocol version 2.0
[    5.316655] hv_vmbus: registering driver hyperv_fb
[    5.322677] hyperv_fb: Synthvid Version major 3, minor 5
[    5.327219] hyperv_fb: Screen resolution: 1024x768, Color depth: 32
[    5.336301] Console: switching to colour frame buffer device 128x48
[    6.132663] pstore: Using crash dump compression: deflate
[    6.139125] pstore: Registered efi as persistent store backend
[  OK  ] Found device /dev/ttyS0.
[    6.541478] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer
[  OK  ] Found device Virtual_Disk 1.
         Mounting /boot/efi...
[    7.160489] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[  OK  ] Mounted /boot/efi.
[  OK  ] Reached target Local File Systems.
         Starting Load AppArmor profiles...
         Starting Set console font and keymap...
         Starting Create final runt…dir for shutdown pivot root...
         Starting Tell Plymouth To Write Out Runtime Data...
         Starting Create Volatile Files and Directories...
[  OK  ] Finished Set console font and keymap.[    7.257259] audit: type=1400 audit(1606277649.564:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=441 comm="apparmor_parser"

[  OK  ] Finished Create final runt…e dir for shutdown pivot root.[    7.277223] audit: type=1400 audit(1606277649.564:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=441 comm="apparmor_parser"

[  OK  ] Finished Tell Plymouth To Write Out Runtime Data.
[  OK  ] Finished Create Volatile Files and Directories.
[    7.322221] audit: type=1400 audit(1606277649.582:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=442 comm="apparmor_parser"
         Starting Network Time Synchronization...
         Starting Update UTMP about System Boot/Shutdown...
[  OK  [    7.359227] audit: type=1400 audit(1606277649.582:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=442 comm="apparmor_parser"
] Finished Load AppArmor profiles.
         Starting Load AppArmor pro…managed internally by snapd...
[  OK  ] Finished Update UTMP about System Boot/Shutdown.[    7.406668] audit: type=1400 audit(1606277649.614:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=443 comm="apparmor_parser"

[    7.444267] audit: type=1400 audit(1606277649.643:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=444 comm="apparmor_parser"
[    7.475285] audit: type=1400 audit(1606277649.643:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=444 comm="apparmor_parser"
[  OK  ] Finished Load AppArmor pro…s managed internally by snapd.
[    7.515224] audit: type=1400 audit(1606277649.643:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=444 comm="apparmor_parser"
[    7.537227] audit: type=1400 audit(1606277649.643:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/{,usr/}sbin/dhclient" pid=444 comm="apparmor_parser"
[    7.556509] audit: type=1400 audit(1606277649.649:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=447 comm="apparmor_parser"
[  OK  ] Started Network Time Synchronization.
[  OK  ] Reached target System Time Set.
[  OK  ] Reached target System Time Synchronized.
[  OK  ] Listening on Load/Save RF …itch Status /dev/rfkill Watch.
[  OK  ] Found device /sys/devices/virtual/misc/vmbus!hv_kvp.
[  OK  ] Started Hyper-V KVP Protocol Daemon.
         Starting Initial cloud-init job (pre-networking)...
         Starting Tell Plymouth To Write Out Runtime Data...
         Starting Platform Persistent Storage Archival...
[  OK  ] Finished Tell Plymouth To Write Out Runtime Data.
[  OK  ] Finished Platform Persistent Storage Archival.
[    9.452088] cloud-init[540]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~20.04.1 running 'init-local' at Wed, 25 Nov 2020 04:14:11 +0000. Up 9.41 seconds.
[  OK  ] Finished Initial cloud-init job (pre-networking).
[  OK  ] Reached target Network (Pre).
         Starting Network Service...
[  OK  ] Started Network Service.
         Starting Wait for Network to be Configured...[    9.589950] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

         Starting Network Name Resolution...
[  OK  ] Started Network Name Resolution.
[  OK  ] Reached target Network.
[  OK  ] Reached target Host and Network Name Lookups.
[  OK  ] Finished Wait for Network to be Configured.
         Starting Initial cloud-ini… (metadata service crawler)...
[   18.687455] cloud-init[553]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~20.04.1 running 'init' at Wed, 25 Nov 2020 04:14:20 +0000. Up 18.58 seconds.
[   18.697215] cloud-init[553]: ci-info: ++++++++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++++++++
[   18.701877] cloud-init[553]: ci-info: +--------+------+-----------------------------------------+---------------+--------+-------------------+
[   18.708709] cloud-init[553]: ci-info: | Device |  Up  |                 Address                 |      Mask     | Scope  |     Hw-Address    |
[   18.716535] cloud-init[553]: ci-info: +--------+------+-----------------------------------------+---------------+--------+-------------------+
[   18.720879] cloud-init[553]: ci-info: |  eth0  | True |              10.226.106.131             | 255.255.255.0 | global | 00:15:5d:6a:8a:0b |
[   18.729964] cloud-init[553]: ci-info: |  eth0  | True | 2001:4898:e0:f463:215:5dff:fe6a:8a0b/64 |       .       | global | 00:15:5d:6a:8a:0b |
[   18.740314] cloud-init[553]: ci-info: |  eth0  | True |       fe80::215:5dff:fe6a:8a0b/64       |       .       |  link  | 00:15:5d:6a:8a:0b |
[   18.747664] cloud-init[553]: ci-info: |   lo   | True |                127.0.0.1                |   255.0.0.0   |  host  |         .         |
[   18.755764] cloud-init[553]: ci-info: |   lo   | True |                 ::1/128                 |       .       |  host  |         .         |
[   18.767814] cloud-init[553]: ci-info: +--------+------+-----------------------------------------+---------------+--------+-------------------+
[   18.776706] cloud-init[553]: ci-info: +++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++
[   18.783593] cloud-init[553]: ci-info: +-------+--------------+--------------+-----------------+-----------+-------+
[   18.787914] cloud-init[553]: ci-info: | Route | Destination  |   Gateway    |     Genmask     | Interface | Flags |
[   18.792431] cloud-init[553]: ci-info: +-------+--------------+--------------+-----------------+-----------+-------+
[   18.800180] cloud-init[553]: ci-info: |   0   |   0.0.0.0    | 10.226.106.1 |     0.0.0.0     |    eth0   |   UG  |
[   18.803715] cloud-init[553]: ci-info: |   1   | 10.226.106.0 |   0.0.0.0    |  255.255.255.0  |    eth0   |   U   |
[   18.809278] cloud-init[553]: ci-info: |   2   | 10.226.106.1 |   0.0.0.0    | 255.255.255.255 |    eth0   |   UH  |
[   18.817104] cloud-init[553]: ci-info: +-------+--------------+--------------+-----------------+-----------+-------+
[   18.823221] cloud-init[553]: ci-info: +++++++++++++++++++++++++++++++++Route IPv6 info++++++++++++++++++++++++++++++++++
[   18.826968] cloud-init[553]: ci-info: +-------+------------------------+---------------------------+-----------+-------+
[   18.830817] cloud-init[553]: ci-info: | Route |      Destination       |          Gateway          | Interface | Flags |
[   18.834300] cloud-init[553]: ci-info: +-------+------------------------+---------------------------+-----------+-------+
[   18.838108] cloud-init[553]: ci-info: |   1   | 2001:4898:e0:f463::/64 |             ::            |    eth0   |   Ue  |
[   18.841896] cloud-init[553]: ci-info: |   2   |       fe80::/64        |             ::            |    eth0   |   U   |
[   18.845628] cloud-init[553]: ci-info: |   3   |          ::/0          | fe80::12f3:11ff:fe53:9669 |    eth0   |   UG  |
[   18.849996] cloud-init[553]: ci-info: |   5   |         local          |             ::            |    eth0   |   U   |
[   18.853704] cloud-init[553]: ci-info: |   6   |         local          |             ::            |    eth0   |   U   |
[   18.857413] cloud-init[553]: ci-info: |   7   |        ff00::/8        |             ::            |    eth0   |   U   |
[   18.861130] cloud-init[553]: ci-info: +-------+------------------------+---------------------------+-----------+-------+
[  OK  ] Finished Initial cloud-ini…ob (metadata service crawler).
[  OK  ] Reached target Cloud-config availability.
[  OK  ] Reached target Network is Online.
[  OK  ] Reached target System Initialization.
[  OK  ] Started Daily apt download activities.
[  OK  ] Started Daily apt upgrade and clean activities.
[  OK  ] Started Periodic ext4 Onli…ata Check for All Filesystems.
[  OK  ] Started Discard unused blocks once a week.
[  OK  ] Started Refresh fwupd metadata regularly.
[  OK  ] Started Daily rotation of log files.
[  OK  ] Started Daily man-db regeneration.
[  OK  ] Started Message of the Day.
[  OK  ] Started Daily Cleanup of Temporary Directories.
[  OK  ] Reached target Paths.
[  OK  ] Reached target Timers.
[  OK  ] Listening on D-Bus System Message Bus Socket.
[  OK  ] Listening on Open-iSCSI iscsid Socket.
[  OK  ] Listening on Socket unix for snap application lxd.daemon.
         Starting Socket activation for snappy daemon.
[  OK  ] Listening on UUID daemon activation socket.
[  OK  ] Reached target Remote File Systems (Pre).
[  OK  ] Reached target Remote File Systems.
         Starting Availability of block devices...
[  OK  ] Listening on Socket activation for snappy daemon.
[  OK  ] Finished Availability of block devices.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Basic System.
         Starting Accounts Service...
         Starting LSB: automatic crash report generation...
         Starting Deferred execution scheduler...
[  OK  ] Started Regular background program processing daemon.
[  OK  ] Started D-Bus System Message Bus.
[  OK  ] Started Save initial kernel messages after boot.
         Starting Remove Stale Onli…t4 Metadata Check Snapshots...
         Starting LSB: Record successful boot for GRUB...
         Starting GRUB failed boot detection...
[  OK  ] Started Hyper-V VSS Protocol Daemon.
         Starting Kernel crash dump capture service...
         Starting LSB: Execute the …-e command to reboot system...
         Starting Dispatcher daemon for systemd-networkd...
         Starting System Logging Service...
         Starting Secure Boot updates for DB and DBX...
         Starting Service for snap application lxd.activate...
         Starting Snap Daemon...
         Starting OpenBSD Secure Shell server...
         Starting Login Service...
         Starting Permit User Sessions...
         Starting Thermal Daemon Service...
[  OK  ] Started Deferred execution scheduler.
[  OK  ] Finished Remove Stale Onli…ext4 Metadata Check Snapshots.
[  OK  ] Finished Permit User Sessions.
[  OK  ] Started OpenBSD Secure Shell server.
[  OK  ] Finished GRUB failed boot detection.
[  OK  ] Started System Logging Service.
[  OK  ] Finished Secure Boot updates for DB and DBX.
[  OK  ] Started LSB: Record successful boot for GRUB.
Started LSB: Execute the k…c -e command to reboot system.
         Starting LSB: Load kernel image with kexec...
         Starting Hold until boot process finishes up...
         Starting Terminate Plymouth Boot Screen...[   19.689094] kdump-tools[581]: Starting kdump-tools:
[   19.700631] kdump-tools[632]:
[  OK   * Creating symlink /var/lib/kdump/vmlinuz] Finished Hold until boot process finishes up.
[   19.723744] kdump-tools
[632]: [  OK   * Creating symlink /var/lib/kdump/initrd.img] Finished Terminate Plymouth Boot Screen.

[  OK  ] Started Dispatcher daemon for systemd-networkd.
[  OK  ] Started Thermal Daemon Service.
[  OK  ] Started LSB: Load kernel image with kexec.
[  OK  ] Started Login Service.
[  OK  ] Started Serial Getty on ttyS0.
         Starting Set console scheme...
[  OK  ] Started Unattended Upgrades Shutdown.
[  OK  ] Finished Set console scheme.
[  OK  ] Created slice system-getty.slice.
[  OK  ] Started Getty on tty1.
[  OK  ] Reached target Login Prompts.
         Starting Authorization Manager...
[  OK  ] Started Authorization Manager.
[  OK  ] Started Accounts Service.
[  OK  ] Started LSB: automatic crash report generation.
[   24.987194] kdump-tools[632]:  * loaded kdump kernel

Ubuntu 20.04.1 LTS g2 ttyS0

g2 login: root
Password:
Welcome to Ubuntu 20.04.1 LTS (GNU/Linux 5.10.0-rc5+ x86_64)

 * Documentation:  https://help.ubuntu.com
 * Management:     https://landscape.canonical.com
 * Support:        https://ubuntu.com/advantage

 System information disabled due to load higher than 1.0

 * Introducing self-healing high availability clustering for MicroK8s!
   Super simple, hardened and opinionated Kubernetes for production.

     https://microk8s.io/high-availability

96 updates can be installed immediately.
7 of these updates are security updates.
To see these additional updates run: apt list --upgradable


Last login: Wed Nov 25 04:12:36 UTC 2020 on ttyS0
root@g2:~/dw#
root@g2:~/dw#
root@g2:~/dw# lscpu -e
CPU NODE SOCKET CORE L1d:L1i:L2:L3 ONLINE    MAXMHZ    MINMHZ
  0    0      0    0 0:0:0:0          yes 2700.0000 1000.0000
root@g2:~/dw#
root@g2:~/dw# grep CONFIG_HZ .config
# CONFIG_HZ_PERIODIC is not set
# CONFIG_HZ_100 is not set
# CONFIG_HZ_250 is not set
# CONFIG_HZ_300 is not set
CONFIG_HZ_1000=y
CONFIG_HZ=1000
root@g2:~/dw# grep NR_CPUS .config
CONFIG_NR_CPUS_RANGE_BEGIN=8192
CONFIG_NR_CPUS_RANGE_END=8192
CONFIG_NR_CPUS_DEFAULT=8192
CONFIG_NR_CPUS=8192
root@g2:~/dw# grep RCU  .config
# RCU Subsystem
CONFIG_TREE_RCU=y
# CONFIG_RCU_EXPERT is not set
CONFIG_SRCU=y
CONFIG_TREE_SRCU=y
CONFIG_TASKS_RCU_GENERIC=y
CONFIG_TASKS_RUDE_RCU=y
CONFIG_TASKS_TRACE_RCU=y
CONFIG_RCU_STALL_COMMON=y
CONFIG_RCU_NEED_SEGCBLIST=y
CONFIG_RCU_NOCB_CPU=y
# end of RCU Subsystem
CONFIG_MMU_GATHER_RCU_TABLE_FREE=y
# RCU Debugging
# CONFIG_RCU_SCALE_TEST is not set
# CONFIG_RCU_TORTURE_TEST is not set
# CONFIG_RCU_REF_SCALE_TEST is not set
CONFIG_RCU_CPU_STALL_TIMEOUT=60
# CONFIG_RCU_TRACE is not set
# CONFIG_RCU_EQS_DEBUG is not set
# end of RCU Debugging
root@g2:~/dw#
root@g2:~/dw# echo c > /proc/sysrq-trigger
[  107.732279] sysrq: Trigger a crash
[  107.734472] Kernel panic - not syncing: sysrq triggered crash
[  107.738023] CPU: 0 PID: 913 Comm: bash Kdump: loaded Not tainted 5.10.0-rc5+ #1
[  107.741968] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 10/26/2020
[  107.746403] Call Trace:
[  107.747441]  dump_stack+0x5e/0x74
[  107.748831]  panic+0xfb/0x2d7
[  107.750190]  sysrq_handle_crash+0x1a/0x20
[  107.751732]  __handle_sysrq.cold+0x48/0x120
[  107.753336]  write_sysrq_trigger+0x28/0x40
[  107.754961]  proc_reg_write+0x66/0x90
[  107.756835]  vfs_write+0xb9/0x250
[  107.759114]  ksys_write+0x67/0xe0
[  107.761482]  __x64_sys_write+0x1a/0x20
[  107.764047]  do_syscall_64+0x38/0x90
[  107.766638]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  107.770199] RIP: 0033:0x7f01ec96a1e7
[  107.772752] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[  107.784031] RSP: 002b:00007ffca6e28528 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  107.786983] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f01ec96a1e7
[  107.789805] RDX: 0000000000000002 RSI: 000055ee5d5c2450 RDI: 0000000000000001
[  107.792775] RBP: 000055ee5d5c2450 R08: 000000000000000a R09: 0000000000000001
[  107.795705] R10: 000055ee5cfc0017 R11: 0000000000000246 R12: 0000000000000002
[  107.798696] R13: 00007f01eca456a0 R14: 00007f01eca464a0 R15: 00007f01eca458a0
[  107.801680] Kernel Offset: disabled

[    0.000000] Linux version 5.10.0-rc5+ (root@g2) (gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1 SMP Tue Nov 24 20:05:18 PST 2020
[    0.000000] Command line: elfcorehdr=0xc07000000 BOOT_IMAGE=/boot/vmlinuz-5.10.0-rc5+ root=UUID=b3930775-6a55-4cd0-99e7-971baa76a345 ro earlyprintk=ttyS0 ignore_loglevel sysrq_always_enabled unknown_nmi_panic console=ttyS0 cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 acpi_no_memhotplug transparent_hugepage=never nokaslr novmcoredd hest_disable disable_cpu_apicid=0 video=efifb:off= reset_devices systemd.unit=kdump-tools-dump.service nr_cpus=1 irqpoll nousb ata_piix.prefer_ms_hyperv=0
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Hygon HygonGenuine
[    0.000000]   Centaur CentaurHauls
[    0.000000]   zhaoxin   Shanghai
[    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] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x0000000000000fff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000001000-0x000000000009ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000000c0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000e6000000-0x00000000f5ffffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000f6d4b000-0x00000000f6d4bfff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f6e7b000-0x00000000f6e99fff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f7ff3000-0x00000000f7ffafff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000f7ffb000-0x00000000f7ffefff] ACPI NVS
[    0.000000] BIOS-e820: [mem 0x0000000c07001000-0x0000000c86ffffff] usable
[    0.000000] printk: bootconsole [earlyser0] enabled
[    0.000000] printk: debug: ignoring loglevel setting.
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] e820: update [mem 0xc86ff82b0-0xc86ff831f] usable ==> usable
[    0.000000] extended physical RAM map:
[    0.000000] reserve setup_data: [mem 0x0000000000000000-0x0000000000000fff] reserved
[    0.000000] reserve setup_data: [mem 0x0000000000001000-0x000000000009ffff] usable
[    0.000000] reserve setup_data: [mem 0x00000000000c0000-0x00000000000fffff] reserved
[    0.000000] reserve setup_data: [mem 0x00000000e6000000-0x00000000f5ffffff] usable
[    0.000000] reserve setup_data: [mem 0x00000000f6d4b000-0x00000000f6d4bfff] ACPI data
[    0.000000] reserve setup_data: [mem 0x00000000f6e7b000-0x00000000f6e99fff] ACPI data
[    0.000000] reserve setup_data: [mem 0x00000000f7ff3000-0x00000000f7ffafff] ACPI data
[    0.000000] reserve setup_data: [mem 0x00000000f7ffb000-0x00000000f7ffefff] ACPI NVS
[    0.000000] reserve setup_data: [mem 0x0000000c07001000-0x0000000c86ff82af] usable
[    0.000000] reserve setup_data: [mem 0x0000000c86ff82b0-0x0000000c86ff831f] usable
[    0.000000] reserve setup_data: [mem 0x0000000c86ff8320-0x0000000c86ffffff] usable
[    0.000000] efi: EFI v2.70 by Microsoft
[    0.000000] efi: ACPI=0xf7ffa000 ACPI 2.0=0xf7ffa014 SMBIOS=0xf7fd8000 SMBIOS 3.0=0xf7fd6000 MEMATTR=0xf7331798 RNG=0xf7fda818
[    0.000000] efi: seeding entropy pool
[    0.000000] random: fast init done
[    0.000000] SMBIOS 3.1.0 present.
[    0.000000] DMI: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 10/26/2020
[    0.000000] Hypervisor detected: Microsoft Hyper-V
[    0.000000] Hyper-V: features 0xae7f, hints 0xe0e24, misc 0xe0bed7b2
[    0.000000] Hyper-V Host Build:21261-10.0-1-0.1005
[    0.000000] Hyper-V: LAPIC Timer Frequency: 0x30d40
[    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.000002] tsc: Detected 2693.671 MHz processor
[    0.001891] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.004620] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.006890] last_pfn = 0xc87000 max_arch_pfn = 0x400000000
[    0.009144] MTRR default type: uncachable
[    0.010772] MTRR fixed ranges enabled:
[    0.012290]   00000-9FFFF write-back
[    0.013743]   A0000-FFFFF uncachable
[    0.015189] MTRR variable ranges enabled:
[    0.016647]   0 base 000000000000 mask 3FFF00000000 write-back
[    0.018760]   1 base 000100000000 mask 3FF000000000 write-back
[    0.020978]   2 disabled
[    0.021946]   3 disabled
[    0.022909]   4 disabled
[    0.023874]   5 disabled
[    0.024847]   6 disabled
[    0.025815]   7 disabled
[    0.027149] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT
[    0.031558] x2apic: enabled by BIOS, switching to x2apic ops
[    0.035126] last_pfn = 0xf6000 max_arch_pfn = 0x400000000
[    0.051185] check: Scanning 1 areas for low memory corruption
[    0.054762] Using GB pages for direct mapping
[    0.057737] Secure boot disabled
[    0.059739] RAMDISK: [mem 0xc72dcb000-0xc841fffff]
[    0.062822] ACPI: Early table checksum verification disabled
[    0.066177] ACPI: RSDP 0x00000000F7FFA014 000024 (v02 VRTUAL)
[    0.068523] ACPI: XSDT 0x00000000F7FF90E8 00005C (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.071988] ACPI: FACP 0x00000000F7FF8000 000114 (v06 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.075490] ACPI: DSDT 0x00000000F6E7B000 01E184 (v02 MSFTVM DSDT01   00000001 MSFT 05000000)
[    0.078964] ACPI: FACS 0x00000000F7FFE000 000040
[    0.080642] ACPI: OEM0 0x00000000F7FF7000 000064 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.083942] ACPI: WAET 0x00000000F7FF6000 000028 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.087223] ACPI: APIC 0x00000000F7FF5000 000050 (v04 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.090669] ACPI: SRAT 0x00000000F7FF4000 0002C0 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.094273] ACPI: BGRT 0x00000000F7FF3000 000038 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.097781] ACPI: FPDT 0x00000000F6D4B000 000034 (v01 VRTUAL MICROSFT 00000001 MSFT 00000001)
[    0.101288] ACPI: Local APIC address 0xfee00000
[    0.103665] Setting APIC routing to physical x2apic.
[    0.106811] NUMA turned off
[    0.108553] Faking a node at [mem 0x0000000000000000-0x0000000c86ffffff]
[    0.112536] NODE_DATA(0) allocated [mem 0xc86fcd1c0-0xc86ff81bf]
[    0.116290] Zone ranges:
[    0.117863]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.121662]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.125533]   Normal   [mem 0x0000000100000000-0x0000000c86ffffff]
[    0.129288]   Device   empty
[    0.130464] Movable zone start for each node
[    0.132215] Early memory node ranges
[    0.133669]   node   0: [mem 0x0000000000001000-0x000000000009ffff]
[    0.136233]   node   0: [mem 0x00000000e6000000-0x00000000f5ffffff]
[    0.138795]   node   0: [mem 0x0000000c07001000-0x0000000c86ffffff]
[    0.142336] Zeroed struct page in unavailable ranges: 98146 pages
[    0.142337] Initmem setup node 0 [mem 0x0000000000001000-0x0000000c86ffffff]
[    0.147427] On node 0 totalpages: 589982
[    0.148966]   DMA zone: 3 pages used for memmap
[    0.150823]   DMA zone: 22 pages reserved
[    0.152463]   DMA zone: 159 pages, LIFO batch:0
[    0.154313]   DMA32 zone: 1024 pages used for memmap
[    0.156436]   DMA32 zone: 65536 pages, LIFO batch:15
[    0.158946]   Normal zone: 8192 pages used for memmap
[    0.161993]   Normal zone: 524287 pages, LIFO batch:63
[    0.167786] ACPI: PM-Timer IO Port: 0x408
[    0.169622] ACPI: Local APIC address 0xfee00000
[    0.171585] ACPI: LAPIC_NMI (acpi_id[0x01] dfl dfl lint[0x1])
[    0.173854] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
[    0.176417] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.179004] ACPI: IRQ9 used by override.
[    0.180526] Using ACPI (MADT) for SMP configuration information
[    0.182851] TSC deadline timer available
[    0.184461] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.186510] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.189734] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000bffff]
[    0.192824] PM: hibernation: Registered nosave memory: [mem 0x000c0000-0x000fffff]
[    0.195914] PM: hibernation: Registered nosave memory: [mem 0x00100000-0xe5ffffff]
[    0.199004] PM: hibernation: Registered nosave memory: [mem 0xf6000000-0xf6d4afff]
[    0.202091] PM: hibernation: Registered nosave memory: [mem 0xf6d4b000-0xf6d4bfff]
[    0.204927] PM: hibernation: Registered nosave memory: [mem 0xf6d4c000-0xf6e7afff]
[    0.207740] PM: hibernation: Registered nosave memory: [mem 0xf6e7b000-0xf6e99fff]
[    0.210639] PM: hibernation: Registered nosave memory: [mem 0xf6e9a000-0xf7ff2fff]
[    0.213563] PM: hibernation: Registered nosave memory: [mem 0xf7ff3000-0xf7ffafff]
[    0.216654] PM: hibernation: Registered nosave memory: [mem 0xf7ffb000-0xf7ffefff]
[    0.219907] PM: hibernation: Registered nosave memory: [mem 0xf7fff000-0xc07000fff]
[    0.222989] PM: hibernation: Registered nosave memory: [mem 0xc86ff8000-0xc86ff8fff]
[    0.225948] PM: hibernation: Registered nosave memory: [mem 0xc86ff8000-0xc86ff8fff]
[    0.228928] [mem 0x00100000-0xe5ffffff] available for PCI devices
[    0.231277] Booting paravirtualized kernel on Hyper-V
[    0.233241] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.237228] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
[    0.240361] percpu: Embedded 54 pages/cpu s184320 r8192 d28672 u2097152
[    0.242902] pcpu-alloc: s184320 r8192 d28672 u2097152 alloc=1*2097152
[    0.245380] pcpu-alloc: [0] 0
[    0.246570] Hyper-V: PV spinlocks enabled
[    0.248171] PV qspinlock hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.251296] Built 1 zonelists, mobility grouping on.  Total pages: 580741
[    0.254003] Policy zone: Normal
[    0.255194] Kernel command line: elfcorehdr=0xc07000000 BOOT_IMAGE=/boot/vmlinuz-5.10.0-rc5+ root=UUID=b3930775-6a55-4cd0-99e7-971baa76a345 ro earlyprintk=ttyS0 ignore_loglevel sysrq_always_enabled unknown_nmi_panic console=ttyS0 cgroup_disable=memory mce=off numa=off udev.children-max=2 panic=10 acpi_no_memhotplug transparent_hugepage=never nokaslr novmcoredd hest_disable disable_cpu_apicid=0 video=efifb:off= reset_devices systemd.unit=kdump-tools-dump.service nr_cpus=1 irqpoll nousb ata_piix.prefer_ms_hyperv=0
[    0.273745] sysrq: sysrq always enabled.
[    0.276361] Misrouted IRQ fixup and polling support enabled
[    0.279722] This may significantly impact system performance
[    0.283417] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.288547] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.293373] mem auto-init: stack:off, heap alloc:on, heap free:off
[    0.311218] Memory: 1926360K/2359928K available (14346K kernel code, 3334K rwdata, 4776K rodata, 2376K init, 6440K bss, 433312K reserved, 0K cma-reserved)
[    0.319892] random: get_random_u64 called from __kmem_cache_create+0x31/0x430 with crng_init=1
[    0.319971] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.328245] ftrace: allocating 44357 entries in 174 pages
[    0.344536] ftrace: allocated 174 pages with 5 groups
[    0.347702] rcu: Hierarchical RCU implementation.
[    0.350543] rcu:     RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=1.
[    0.354596]  Rude variant of Tasks RCU enabled.
[    0.357248]  Tracing variant of Tasks RCU enabled.
[    0.360177] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[    0.363181] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.368717] Using NULL legacy PIC
[    0.370772] NR_IRQS: 524544, nr_irqs: 256, preallocated irqs: 0
[    0.373683] random: crng done (trusting CPU's manufacturer)
[    0.376101] Console: colour dummy device 80x25
[    0.378009] printk: console [ttyS0] enabled
[    0.378009] printk: console [ttyS0] enabled
[    0.381471] printk: bootconsole [earlyser0] disabled
[    0.381471] printk: bootconsole [earlyser0] disabled
[    0.385597] ACPI: Core revision 20200925
[    0.387371] Failed to register legacy timer interrupt
[    0.389488] APIC: Switch to symmetric I/O mode setup
[    0.393001] Hyper-V: Using IPI hypercalls
[    0.394586] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x26d3e3bf8bb, max_idle_ns: 440795220752 ns
[    0.398801] Calibrating delay loop (skipped), value calculated using timer frequency.. 5387.34 BogoMIPS (lpj=2693671)
[    0.399798] pid_max: default: 32768 minimum: 301
[    0.399798] LSM: Security Framework initializing
[    0.399798] Yama: becoming mindful.
[    0.399798] AppArmor: AppArmor initialized
[    0.399798] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.399798] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.399798] Disabling memory control group subsystem
Poking KASLR using RDRAND RDTSC...
[    0.399798] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.399798] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.399798] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.399798] Spectre V2 : Mitigation: Enhanced IBRS
[    0.399798] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.399798] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.399798] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.399798] TAA: Mitigation: TSX disabled
[    0.399798] Freeing SMP alternatives memory: 40K
[    0.399798] smpboot: CPU0: Intel(R) Xeon(R) Platinum 8270 CPU @ 2.70GHz (family: 0x6, model: 0x55, stepping: 0x7)
[    0.399798] Performance Events: unsupported p6 CPU model 85 no PMU driver, software events only.
[    0.399798] rcu: Hierarchical SRCU implementation.
[    0.399798] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.399798] smp: Bringing up secondary CPUs ...
[    0.399798] smp: Brought up 1 node, 1 CPU
[    0.399798] smpboot: Max logical packages: 1
[    0.399798] smpboot: Total of 1 processors activated (5387.34 BogoMIPS)
[    0.399798] devtmpfs: initialized
[    0.399798] x86/mm: Memory block size: 128MB
[    0.399798] PM: Registering ACPI NVS region [mem 0xf7ffb000-0xf7ffefff] (16384 bytes)
[    0.399798] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.399798] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
[    0.399798] pinctrl core: initialized pinctrl subsystem
[    0.399798] PM: RTC time: 04:15:53, date: 2020-11-25
[    0.399798] NET: Registered protocol family 16
[    0.399798] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations
[    0.399798] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.399798] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.399798] audit: initializing netlink subsys (disabled)
[    0.399798] thermal_sys: Registered thermal governor 'fair_share'
[    0.399798] thermal_sys: Registered thermal governor 'bang_bang'
[    0.399798] thermal_sys: Registered thermal governor 'step_wise'
[    0.399798] thermal_sys: Registered thermal governor 'user_space'
[    0.399798] EISA bus registered
[    0.399798] cpuidle: using governor ladder
[    0.399798] cpuidle: using governor menu
[    0.399798] ACPI: bus type PCI registered
[    0.399798] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.399798] audit: type=2000 audit(1606277753.000:1): state=initialized audit_enabled=0 res=1
[    0.399798] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.399798] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.399798] ACPI: Added _OSI(Module Device)
[    0.399798] ACPI: Added _OSI(Processor Device)
[    0.399798] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.399798] ACPI: Added _OSI(Processor Aggregator Device)
[    0.399798] ACPI: Added _OSI(Linux-Dell-Video)
[    0.399798] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.399798] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.399798] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.399798] ACPI: Interpreter enabled
[    0.399798] ACPI: (supports S0 S5)
[    0.399798] ACPI: Using IOAPIC for interrupt routing
[    0.399798] HEST: Table parsing disabled.
[    0.399798] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.399798] ACPI: Enabled 1 GPEs in block 00 to 0F
[    0.399798] iommu: Default domain type: Translated
[    0.399798] vgaarb: loaded
[    0.399798] SCSI subsystem initialized
[    0.399798] libata version 3.00 loaded.
[    0.399798] ACPI: bus type USB registered
[    0.399798] usbcore: registered new interface driver usbfs
[    0.399798] usbcore: registered new interface driver hub
[    0.399798] usbcore: registered new device driver usb
[    0.399798] pps_core: LinuxPPS API ver. 1 registered
[    0.399798] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.399798] PTP clock support registered
[    0.399798] EDAC MC: Ver: 3.0.0
[    0.399798] Registered efivars operations
[    0.399798] NetLabel: Initializing
[    0.399798] NetLabel:  domain hash size = 128
[    0.399798] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.399798] NetLabel:  unlabeled traffic allowed by default
[    0.399798] PCI: Using ACPI for IRQ routing
[    0.399798] PCI: System does not support PCI
[    0.399798] clocksource: Switched to clocksource tsc-early
[    0.399798] VFS: Disk quotas dquot_6.6.0
[    0.399798] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.399798] AppArmor: AppArmor Filesystem Enabled
[    0.399798] pnp: PnP ACPI init
[    0.399798] pnp 00:00: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.399798] pnp 00:01: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.399798] pnp 00:02: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.399798] pnp: PnP ACPI: found 3 devices
[    0.399798] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.399798] NET: Registered protocol family 2
[    0.399798] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    0.399798] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.399798] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.399798] TCP: Hash tables configured (established 32768 bind 32768)
[    0.399798] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.399798] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.399798] NET: Registered protocol family 1
[    0.399798] NET: Registered protocol family 44
[    0.399798] PCI: CLS 0 bytes, default 64
[    0.399798] Trying to unpack rootfs image as initramfs...
[    0.399798] Freeing initrd memory: 282836K
[    0.399798] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.399798] software IO TLB: mapped [mem 0x00000000f2000000-0x00000000f6000000] (64MB)
[    0.399798] check: Scanning for low memory corruption every 60 seconds
[    0.399798] Initialise system trusted keyrings
[    0.399798] Key type blacklist registered
[    0.399798] workingset: timestamp_bits=36 max_order=20 bucket_order=0
[    0.399798] zbud: loaded
[    0.399798] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.399798] fuse: init (API version 7.32)
[    0.399798] integrity: Platform Keyring initialized
[    0.399798] Key type asymmetric registered
[    0.399798] Asymmetric key parser 'x509' registered
[    0.399798] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[    0.399798] io scheduler mq-deadline registered
[    0.399798] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    0.399798] intel_idle: Please enable MWAIT in BIOS SETUP
[    0.399798] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    0.399798] 00:00: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    0.399798] 00:01: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    0.399798] serial8250: ttyS2 at I/O 0x3e8 (irq = 4, base_baud = 115200) is a 16550A
[    0.399798] serial8250: ttyS3 at I/O 0x2e8 (irq = 3, base_baud = 115200) is a 16550A
[    0.399798] Linux agpgart interface v0.103
[    0.399798] loop: module loaded
[    0.399798] libphy: Fixed MDIO Bus: probed
[    0.399798] tun: Universal TUN/TAP device driver, 1.6
[    0.399798] PPP generic driver version 2.4.2
[    0.399798] VFIO - User Level meta-driver version: 0.3
[    0.399798] i8042: PNP: No PS/2 controller found.
[    0.399798] mousedev: PS/2 mouse device common for all mice
[    0.399798] rtc_cmos 00:02: RTC can wake from S4
[    0.399798] rtc_cmos 00:02: registered as rtc0
[    0.399798] rtc_cmos 00:02: setting system clock to 2020-11-25T04:15:54 UTC (1606277754)
[    0.399798] rtc_cmos 00:02: alarms up to one month, 114 bytes nvram
[    0.399798] device-mapper: uevent: version 1.0.3
[    0.399798] device-mapper: ioctl: 4.43.0-ioctl (2020-10-01) initialised: dm-devel@redhat.com
[    0.399798] platform eisa.0: Probing EISA bus 0
[    0.399798] platform eisa.0: EISA: Detected 0 cards
[    0.399798] intel_pstate: Intel P-state driver initializing
[    0.399798] EFI Variables Facility v0.08 2004-May-17
[    0.399798] drop_monitor: Initializing network drop monitor service
[    0.399798] NET: Registered protocol family 10
[    0.399798] Segment Routing with IPv6
[    0.399798] NET: Registered protocol family 17
[    0.399798] Key type dns_resolver registered
[    0.399798] mce: Unable to init MCE device (rc: -5)
[    0.399798] IPI shorthand broadcast: enabled
[    0.399798] sched_clock: Marking stable (373650700, 25147600)->(398798300, 0)
[    1.378932] registered taskstats version 1
[    1.380693] Loading compiled-in X.509 certificates
[    1.383229] Loaded X.509 cert 'Build time autogenerated kernel key: d2d6d33637fd863baea8e181dc8d2e48b9378be2'
[    1.387414] zswap: loaded using pool lzo/zbud
[    1.389323] Key type ._fscrypt registered
[    1.391079] Key type .fscrypt registered
[    1.392579] Key type fscrypt-provisioning registered
[    1.396165] Key type encrypted registered
[    1.397893] AppArmor: AppArmor sha1 policy hashing enabled
[    1.400972] integrity: Loading X.509 certificate: UEFI:db
[    1.403295] integrity: Loaded X.509 cert 'Microsoft Windows Production PCA 2011: a92902398e16c49778cd90f99e4f9ae17c55af53'
[    1.408495] integrity: Loading X.509 certificate: UEFI:MokListRT
[    1.411029] integrity: Loaded X.509 cert 'SomeOrg: shim: a01ee84e9b37ace407961cc468c5909447878469'
[    1.414749] integrity: Loading X.509 certificate: UEFI:MokListRT
[    1.417441] integrity: Loaded X.509 cert 'Canonical Ltd. Master Certificate Authority: ad91990bc22ab1f517048c23b6655a268e345a63'
[    1.422161] ima: No TPM chip found, activating TPM-bypass!
[    1.424206] ima: Allocated hash algorithm: sha1
[    1.425923] ima: No architecture policies found
[    1.427717] evm: Initialising EVM extended attributes:
[    1.429739] evm: security.selinux
[    1.431062] evm: security.SMACK64
[    1.432424] evm: security.SMACK64EXEC
[    1.433969] evm: security.SMACK64TRANSMUTE
[    1.435693] evm: security.SMACK64MMAP
[    1.437363] evm: security.apparmor
[    1.438833] evm: security.ima
[    1.440119] evm: security.capability
[    1.441658] evm: HMAC attrs: 0x1
[    1.443246] PM:   Magic number: 12:52:263
[    1.445028] RAS: Correctable Errors collector initialized.
[    1.448969] Freeing unused decrypted memory: 2036K
[    1.451517] Freeing unused kernel image (initmem) memory: 2376K


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-25  4:56 kdump always hangs in rcu_barrier() -> wait_for_completion() Dexuan Cui
@ 2020-11-26 15:46 ` Paul E. McKenney
  2020-11-26 21:25   ` Dexuan Cui
  0 siblings, 1 reply; 8+ messages in thread
From: Paul E. McKenney @ 2020-11-26 15:46 UTC (permalink / raw)
  To: Dexuan Cui
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

On Wed, Nov 25, 2020 at 04:56:33AM +0000, Dexuan Cui wrote:
> Hi,
> I happened to hit a kdump hang issue in a Linux VM running on some
> Hyper-V host. Please see the attached log: the kdump kernel always hangs,
> even if I configure only 1 virtual CPU to the VM.
> 
> I firstly hit the issue in RHEL 8.3's 4.18.x kernel, but later I found that 
> the latest upstream v5.10-rc5 also has the same issue (at least the
> symptom is exactly the same), so I dug into v5.10-rc5 and found that the
> kdump kernel always hangs in kernel_init() -> mark_readonly() ->
> rcu_barrier() -> wait_for_completion(&rcu_state.barrier_completion).
> 
> Let's take the 1-vCPU case for example (refer to the attached log): in the
> below code, somehow rcu_segcblist_n_cbs() returns true, so the call
> smp_call_function_single(cpu, rcu_barrier_func, (void *)cpu, 1) increases
> the counter by 1, and hence later the counter is still 1 after the
> atomic_sub_and_test(), and the complete() is not called.
> 
> static void rcu_barrier_func(void *cpu_in)
> {
>         ...
>         if (rcu_segcblist_entrain(&rdp->cblist, &rdp->barrier_head)) {
>                 atomic_inc(&rcu_state.barrier_cpu_count);
>         } else {
>         ...
> }
> 
> void rcu_barrier(void)
> {
>         ...
>         atomic_set(&rcu_state.barrier_cpu_count, 2);
>         ...
>         for_each_possible_cpu(cpu) {
>                 rdp = per_cpu_ptr(&rcu_data, cpu);
>                 ...
>                 if (rcu_segcblist_n_cbs(&rdp->cblist) && cpu_online(cpu)) {
>                         ...
>                         smp_call_function_single(cpu, rcu_barrier_func, (void *)cpu, 1);
>                         ...
>                 }
>         }
>         ...
>         if (atomic_sub_and_test(2, &rcu_state.barrier_cpu_count))
>                 complete(&rcu_state.barrier_completion);
> 
>         ...
>         wait_for_completion(&rcu_state.barrier_completion);
> 
> Sorry for my ignorance of RCU -- I'm not sure why the rcu_segcblist_n_cbs()
> returns 1 here. In the normal kernel, it returns 0, so the normal kernel does not
> hang.

The rcu_segcblist_n_cbs() function returns non-zero because something
invoked call_rcu() some time previously.  The ftrace facility (or just
a printk) should help you work out where that call_rcu() is located.

> Note: in the case of kdump kernel, if I remove the kernel parameter
> console=ttyS0 OR if I build the kernel with CONFIG_HZ=250, the issue can
> no longer reproduce. Currently my kernel uses CONFIG_HZ=1000 and I use
> console=ttyS0, so I'm able to reproduce the isue every time.
> 
> Note: the same kernel binary can not reproduce the issue when the VM
> runs on another Hyper-V host.
> 
> It looks there is some kind of race condition?

Quite possibly.  Perhaps there is some code somewhere in the kernel that
invokes call_rcu() after some number of jiffies, in which case reducing
CONFIG_HZ would delay that call_rcu() invocation until after this call
to rcu_barrier().  Perhaps that call_rcu() is also associated with the
console=ttyS0, so that it is delayed sufficiently with reduced CONFIG_HZ
and missing entirely without console=ttyS0.

> Looking forward to your insights!
> 
> I'm happy to test any patch or enable more tracing, if necessary. Thanks!

My best guess is that the underlying bug is that you are invoking
rcu_barrier() before the RCU grace-period kthread has been created.
This means that RCU grace periods cannot complete, which in turn means
that if there has been even one invocation of call_rcu() since boot,
rcu_barrier() cannot complete, which is what you are in fact seeing.
Please note that it is perfectly legal to invoke call_rcu() very early in
the boot process, as in even before the call to rcu_init().  Therefore,
if this is the case, the bug is the early call to rcu_barrier(), not
the early calls to call_rcu().

To check this, at the beginning of rcu_barrier(), check the value of
rcu_state.gp_kthread.  If my guess is correct, it will be NULL.

Another possibility is that rcu_state.gp_kthread is non-NULL, but that
something else is preventing RCU grace periods from completing, but in
that case you should see RCU CPU stall warnings.  Unless of course they
have been disabled.

Please let me know what you find!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 8+ messages in thread

* RE: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-26 15:46 ` Paul E. McKenney
@ 2020-11-26 21:25   ` Dexuan Cui
  2020-11-26 21:42     ` Paul E. McKenney
  0 siblings, 1 reply; 8+ messages in thread
From: Dexuan Cui @ 2020-11-26 21:25 UTC (permalink / raw)
  To: paulmck
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

> From: Paul E. McKenney <paulmck@kernel.org>
> Sent: Thursday, November 26, 2020 7:47 AM
>  ...
> The rcu_segcblist_n_cbs() function returns non-zero because something
> invoked call_rcu() some time previously.  The ftrace facility (or just
> a printk) should help you work out where that call_rcu() is located.

call_rcu() is indeed called multiple times, but as you said, this should
be normal.

> My best guess is that the underlying bug is that you are invoking
> rcu_barrier() before the RCU grace-period kthread has been created.
> This means that RCU grace periods cannot complete, which in turn means
> that if there has been even one invocation of call_rcu() since boot,
> rcu_barrier() cannot complete, which is what you are in fact seeing.
> Please note that it is perfectly legal to invoke call_rcu() very early in
> the boot process, as in even before the call to rcu_init().  Therefore,
> if this is the case, the bug is the early call to rcu_barrier(), not
> the early calls to call_rcu().
>
> To check this, at the beginning of rcu_barrier(), check the value of
> rcu_state.gp_kthread.  If my guess is correct, it will be NULL.

Unluckily, it's not NULL here. :-)

>
> Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> something else is preventing RCU grace periods from completing, but in

It looks like somehow the scheduling is not working here: in rcu_barrier()
, if I replace the wait_for_completion() with
wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ), the
issue persists.

> that case you should see RCU CPU stall warnings.  Unless of course they
> have been disabled.
> 							Thanx, Paul

I guess I didn't disable the wanrings (I don't even know how to do that :)

grep RCU .config
# RCU Subsystem
CONFIG_TREE_RCU=y
# CONFIG_RCU_EXPERT is not set
CONFIG_SRCU=y
CONFIG_TREE_SRCU=y
CONFIG_TASKS_RCU_GENERIC=y
CONFIG_TASKS_RUDE_RCU=y
CONFIG_TASKS_TRACE_RCU=y
CONFIG_RCU_STALL_COMMON=y
CONFIG_RCU_NEED_SEGCBLIST=y
CONFIG_RCU_NOCB_CPU=y
# end of RCU Subsystem
CONFIG_MMU_GATHER_RCU_TABLE_FREE=y
# RCU Debugging
# CONFIG_RCU_SCALE_TEST is not set
# CONFIG_RCU_TORTURE_TEST is not set
# CONFIG_RCU_REF_SCALE_TEST is not set
CONFIG_RCU_CPU_STALL_TIMEOUT=30
CONFIG_RCU_TRACE=y
CONFIG_RCU_EQS_DEBUG=y
# end of RCU Debugging

Thanks,
-- Dexuan


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-26 21:25   ` Dexuan Cui
@ 2020-11-26 21:42     ` Paul E. McKenney
  2020-11-26 22:59       ` Dexuan Cui
  0 siblings, 1 reply; 8+ messages in thread
From: Paul E. McKenney @ 2020-11-26 21:42 UTC (permalink / raw)
  To: Dexuan Cui
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

On Thu, Nov 26, 2020 at 09:25:28PM +0000, Dexuan Cui wrote:
> > From: Paul E. McKenney <paulmck@kernel.org>
> > Sent: Thursday, November 26, 2020 7:47 AM
> >  ...
> > The rcu_segcblist_n_cbs() function returns non-zero because something
> > invoked call_rcu() some time previously.  The ftrace facility (or just
> > a printk) should help you work out where that call_rcu() is located.
> 
> call_rcu() is indeed called multiple times, but as you said, this should
> be normal.

Good to know, thank you!

> > My best guess is that the underlying bug is that you are invoking
> > rcu_barrier() before the RCU grace-period kthread has been created.
> > This means that RCU grace periods cannot complete, which in turn means
> > that if there has been even one invocation of call_rcu() since boot,
> > rcu_barrier() cannot complete, which is what you are in fact seeing.
> > Please note that it is perfectly legal to invoke call_rcu() very early in
> > the boot process, as in even before the call to rcu_init().  Therefore,
> > if this is the case, the bug is the early call to rcu_barrier(), not
> > the early calls to call_rcu().
> >
> > To check this, at the beginning of rcu_barrier(), check the value of
> > rcu_state.gp_kthread.  If my guess is correct, it will be NULL.
> 
> Unluckily, it's not NULL here. :-)

You can't have everything!  ;-)

> > Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> > something else is preventing RCU grace periods from completing, but in
> 
> It looks like somehow the scheduling is not working here: in rcu_barrier()
> , if I replace the wait_for_completion() with
> wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ), the
> issue persists.

Have you tried using sysreq-t to see what the various tasks are doing?

One way that this can happen is if whatever task is currently running
has managed to enter long loop with interrupts disabled.

> > that case you should see RCU CPU stall warnings.  Unless of course they
> > have been disabled.
> > 							Thanx, Paul
> 
> I guess I didn't disable the wanrings (I don't even know how to do that :)

Having interrupts disabled on all CPUs would have the effect of disabling
the RCU CPU stall warnings.

The intended method is in Documentation/admin-guide/kernel-parameters.txt.
Search for rcu_cpu_stall_suppress.  Not that it seems important at this
point.

							Thanx, Paul

> grep RCU .config
> # RCU Subsystem
> CONFIG_TREE_RCU=y
> # CONFIG_RCU_EXPERT is not set
> CONFIG_SRCU=y
> CONFIG_TREE_SRCU=y
> CONFIG_TASKS_RCU_GENERIC=y
> CONFIG_TASKS_RUDE_RCU=y
> CONFIG_TASKS_TRACE_RCU=y
> CONFIG_RCU_STALL_COMMON=y
> CONFIG_RCU_NEED_SEGCBLIST=y
> CONFIG_RCU_NOCB_CPU=y
> # end of RCU Subsystem
> CONFIG_MMU_GATHER_RCU_TABLE_FREE=y
> # RCU Debugging
> # CONFIG_RCU_SCALE_TEST is not set
> # CONFIG_RCU_TORTURE_TEST is not set
> # CONFIG_RCU_REF_SCALE_TEST is not set
> CONFIG_RCU_CPU_STALL_TIMEOUT=30
> CONFIG_RCU_TRACE=y
> CONFIG_RCU_EQS_DEBUG=y
> # end of RCU Debugging
> 
> Thanks,
> -- Dexuan
> 

^ permalink raw reply	[flat|nested] 8+ messages in thread

* RE: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-26 21:42     ` Paul E. McKenney
@ 2020-11-26 22:59       ` Dexuan Cui
  2020-11-26 23:54         ` Paul E. McKenney
  0 siblings, 1 reply; 8+ messages in thread
From: Dexuan Cui @ 2020-11-26 22:59 UTC (permalink / raw)
  To: paulmck
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

> From: Paul E. McKenney <paulmck@kernel.org>
> Sent: Thursday, November 26, 2020 1:42 PM
> 
> > > Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> > > something else is preventing RCU grace periods from completing, but in
> >
> > It looks like somehow the scheduling is not working here: in rcu_barrier()
> > , if I replace the wait_for_completion() with
> > wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ), the
> > issue persists.
> 
> Have you tried using sysreq-t to see what the various tasks are doing?

Will try it.

BTW, this is a "Generation 2" VM on Hyper-V, meaning sysrq only starts to
work after the Hyper-V para-virtualized keyboard driver loads... So, at this
early point, sysrq is not working. :-( I'll have to hack the code and use a 
virtual NMI interrupt to force the sysrq handler to be called.
 
> Having interrupts disabled on all CPUs would have the effect of disabling
> the RCU CPU stall warnings.
> 							Thanx, Paul

I'm sure the interrupts are not disabled. Here the VM only has 1 virtual CPU,
and when the hang issue happens the virtual serial console is still responding
when I press Enter (it prints a new line) or Ctrl+C (it prints ^C).

Here the VM does not use the "legacy timers" (PIT, Local APIC timer, etc.) at all.
Instead, the VM uses the Hyper-V para-virtualized timers. It looks the Hyper-V
timer never fires in the kdump kernel when the hang issue happens. I'm 
looking into this... I suspect this hang issue may only be specific to Hyper-V.

Thanks,
-- Dexuan

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-26 22:59       ` Dexuan Cui
@ 2020-11-26 23:54         ` Paul E. McKenney
  2021-01-28  7:28           ` Dexuan Cui
  0 siblings, 1 reply; 8+ messages in thread
From: Paul E. McKenney @ 2020-11-26 23:54 UTC (permalink / raw)
  To: Dexuan Cui
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

On Thu, Nov 26, 2020 at 10:59:19PM +0000, Dexuan Cui wrote:
> > From: Paul E. McKenney <paulmck@kernel.org>
> > Sent: Thursday, November 26, 2020 1:42 PM
> > 
> > > > Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> > > > something else is preventing RCU grace periods from completing, but in
> > >
> > > It looks like somehow the scheduling is not working here: in rcu_barrier()
> > > , if I replace the wait_for_completion() with
> > > wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ), the
> > > issue persists.
> > 
> > Have you tried using sysreq-t to see what the various tasks are doing?
> 
> Will try it.
> 
> BTW, this is a "Generation 2" VM on Hyper-V, meaning sysrq only starts to
> work after the Hyper-V para-virtualized keyboard driver loads... So, at this
> early point, sysrq is not working. :-( I'll have to hack the code and use a 
> virtual NMI interrupt to force the sysrq handler to be called.

Whatever works!

> > Having interrupts disabled on all CPUs would have the effect of disabling
> > the RCU CPU stall warnings.
> > 							Thanx, Paul
> 
> I'm sure the interrupts are not disabled. Here the VM only has 1 virtual CPU,
> and when the hang issue happens the virtual serial console is still responding
> when I press Enter (it prints a new line) or Ctrl+C (it prints ^C).
> 
> Here the VM does not use the "legacy timers" (PIT, Local APIC timer, etc.) at all.
> Instead, the VM uses the Hyper-V para-virtualized timers. It looks the Hyper-V
> timer never fires in the kdump kernel when the hang issue happens. I'm 
> looking into this... I suspect this hang issue may only be specific to Hyper-V.

Fair enough, given that timers not working can also suppress RCU CPU
stall warnings.  ;-)

							Thanx, Paul

^ permalink raw reply	[flat|nested] 8+ messages in thread

* RE: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2020-11-26 23:54         ` Paul E. McKenney
@ 2021-01-28  7:28           ` Dexuan Cui
  2021-01-28 14:58             ` Paul E. McKenney
  0 siblings, 1 reply; 8+ messages in thread
From: Dexuan Cui @ 2021-01-28  7:28 UTC (permalink / raw)
  To: paulmck, Neeraj Upadhyay
  Cc: boqun.feng, Ingo Molnar, rcu, vkuznets, Michael Kelley, linux-kernel

> From: Paul E. McKenney <paulmck@kernel.org>
> Sent: Thursday, November 26, 2020 3:55 PM
> To: Dexuan Cui <decui@microsoft.com>
> Cc: boqun.feng@gmail.com; Ingo Molnar <mingo@redhat.com>;
> rcu@vger.kernel.org; vkuznets <vkuznets@redhat.com>; Michael Kelley
> <mikelley@microsoft.com>; linux-kernel@vger.kernel.org
> Subject: Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
> 
> On Thu, Nov 26, 2020 at 10:59:19PM +0000, Dexuan Cui wrote:
> > > From: Paul E. McKenney <paulmck@kernel.org>
> > > Sent: Thursday, November 26, 2020 1:42 PM
> > >
> > > > > Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> > > > > something else is preventing RCU grace periods from completing, but in
> > > >
> > > > It looks like somehow the scheduling is not working here: in rcu_barrier()
> > > > , if I replace the wait_for_completion() with
> > > > wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ),
> the
> > > > issue persists.
> > >
> > > Have you tried using sysreq-t to see what the various tasks are doing?
> >
> > Will try it.
> >
> > BTW, this is a "Generation 2" VM on Hyper-V, meaning sysrq only starts to
> > work after the Hyper-V para-virtualized keyboard driver loads... So, at this
> > early point, sysrq is not working. :-( I'll have to hack the code and use a
> > virtual NMI interrupt to force the sysrq handler to be called.
> 
> Whatever works!
> 
> > > Having interrupts disabled on all CPUs would have the effect of disabling
> > > the RCU CPU stall warnings.
> > > 							Thanx, Paul
> >
> > I'm sure the interrupts are not disabled. Here the VM only has 1 virtual CPU,
> > and when the hang issue happens the virtual serial console is still responding
> > when I press Enter (it prints a new line) or Ctrl+C (it prints ^C).
> >
> > Here the VM does not use the "legacy timers" (PIT, Local APIC timer, etc.) at
> all.
> > Instead, the VM uses the Hyper-V para-virtualized timers. It looks the
> Hyper-V
> > timer never fires in the kdump kernel when the hang issue happens. I'm
> > looking into this... I suspect this hang issue may only be specific to Hyper-V.
> 
> Fair enough, given that timers not working can also suppress RCU CPU
> stall warnings.  ;-)
> 
> 							Thanx, Paul

FYI: the issue has been fixed by this fix:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=fff7b5e6ee63c5d20406a131b260c619cdd24fd1

Thanks,
-- Dexuan

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
  2021-01-28  7:28           ` Dexuan Cui
@ 2021-01-28 14:58             ` Paul E. McKenney
  0 siblings, 0 replies; 8+ messages in thread
From: Paul E. McKenney @ 2021-01-28 14:58 UTC (permalink / raw)
  To: Dexuan Cui
  Cc: Neeraj Upadhyay, boqun.feng, Ingo Molnar, rcu, vkuznets,
	Michael Kelley, linux-kernel

On Thu, Jan 28, 2021 at 07:28:20AM +0000, Dexuan Cui wrote:
> > From: Paul E. McKenney <paulmck@kernel.org>
> > Sent: Thursday, November 26, 2020 3:55 PM
> > To: Dexuan Cui <decui@microsoft.com>
> > Cc: boqun.feng@gmail.com; Ingo Molnar <mingo@redhat.com>;
> > rcu@vger.kernel.org; vkuznets <vkuznets@redhat.com>; Michael Kelley
> > <mikelley@microsoft.com>; linux-kernel@vger.kernel.org
> > Subject: Re: kdump always hangs in rcu_barrier() -> wait_for_completion()
> > 
> > On Thu, Nov 26, 2020 at 10:59:19PM +0000, Dexuan Cui wrote:
> > > > From: Paul E. McKenney <paulmck@kernel.org>
> > > > Sent: Thursday, November 26, 2020 1:42 PM
> > > >
> > > > > > Another possibility is that rcu_state.gp_kthread is non-NULL, but that
> > > > > > something else is preventing RCU grace periods from completing, but in
> > > > >
> > > > > It looks like somehow the scheduling is not working here: in rcu_barrier()
> > > > > , if I replace the wait_for_completion() with
> > > > > wait_for_completion_timeout(&rcu_state.barrier_completion, 30*HZ),
> > the
> > > > > issue persists.
> > > >
> > > > Have you tried using sysreq-t to see what the various tasks are doing?
> > >
> > > Will try it.
> > >
> > > BTW, this is a "Generation 2" VM on Hyper-V, meaning sysrq only starts to
> > > work after the Hyper-V para-virtualized keyboard driver loads... So, at this
> > > early point, sysrq is not working. :-( I'll have to hack the code and use a
> > > virtual NMI interrupt to force the sysrq handler to be called.
> > 
> > Whatever works!
> > 
> > > > Having interrupts disabled on all CPUs would have the effect of disabling
> > > > the RCU CPU stall warnings.
> > > > 							Thanx, Paul
> > >
> > > I'm sure the interrupts are not disabled. Here the VM only has 1 virtual CPU,
> > > and when the hang issue happens the virtual serial console is still responding
> > > when I press Enter (it prints a new line) or Ctrl+C (it prints ^C).
> > >
> > > Here the VM does not use the "legacy timers" (PIT, Local APIC timer, etc.) at
> > all.
> > > Instead, the VM uses the Hyper-V para-virtualized timers. It looks the
> > Hyper-V
> > > timer never fires in the kdump kernel when the hang issue happens. I'm
> > > looking into this... I suspect this hang issue may only be specific to Hyper-V.
> > 
> > Fair enough, given that timers not working can also suppress RCU CPU
> > stall warnings.  ;-)
> > 
> > 							Thanx, Paul
> 
> FYI: the issue has been fixed by this fix:
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=fff7b5e6ee63c5d20406a131b260c619cdd24fd1

Thank you for the update!

							Thanx, Paul

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2021-01-28 14:59 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-11-25  4:56 kdump always hangs in rcu_barrier() -> wait_for_completion() Dexuan Cui
2020-11-26 15:46 ` Paul E. McKenney
2020-11-26 21:25   ` Dexuan Cui
2020-11-26 21:42     ` Paul E. McKenney
2020-11-26 22:59       ` Dexuan Cui
2020-11-26 23:54         ` Paul E. McKenney
2021-01-28  7:28           ` Dexuan Cui
2021-01-28 14:58             ` Paul E. McKenney

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).