* v6.12-rc workqueue lockups
@ 2024-10-23 10:19 John Garry
2024-10-23 20:13 ` Jan Kara
2024-10-23 20:39 ` Jan Kara
0 siblings, 2 replies; 8+ messages in thread
From: John Garry @ 2024-10-23 10:19 UTC (permalink / raw)
To: linux-kernel, viro, brauner, jack, linux-fsdevel
Hi All,
I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
master branch:
Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221
at Oct 22 09:07:15 ...
kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221
at Oct 22 09:08:07 ...
kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0
stuck for 44s!
Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221
at Oct 22 09:08:07 ...
kernel:BUG: workqueue lockup - pool cpus=4 node=0 flags=0x0 nice=0
stuck for 35s!
Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221
at Oct 22 09:08:07 ...
kernel:BUG: workqueue lockup - pool cpus=10 node=0 flags=0x0 nice=0
stuck for 33s!
This is while doing some server MySQL performance testing. v6.11 has no
such issue.
I added some debug, and we seem to be spending a lot of time in FS
writeback, specifically wb_workfn() -> wb_do_writeback() - ring any bells?
My config:
https://pastebin.com/Y7DXnMG2
early (available) dmesg is below.
Cheers,
John
[root@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 opc]# dmesg
[ 0.000000] Linux version 6.12.0-rc4-ge8f994e752e1
(opc@jgarry-atomic-write-exp-e4-8-instance-20231214-1221) (gcc (GCC)
8.5.0 20210514 (Red Hat 8.5.0-20.0.1), GNU ld version 2.30-123.0.1.el8)
#32 SMP PREEMPT_DYNAMIC Mon Oct 21 09:44:56 GMT 2024
[ 0.000000] Command line:
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-6.12.0-rc4-ge8f994e752e1
root=/dev/mapper/ocivolume-root ro crashkernel=auto LANG=en_US.UTF-8
console=tty0 console=ttyS0,115200 rd.luks=0 rd.md=0 rd.dm=0
rd.lvm.vg=ocivolume rd.lvm.lv=ocivolume/root rd.net.timeout.carrier=5
netroot=iscsi:169.254.0.2:::1:iqn.2015-02.oracle.boot:uefi
rd.iscsi.param=node.session.timeo.replacement_timeout=6000 net.ifnames=1
nvme_core.shutdown_timeout=10 ipmi_si.tryacpi=0 ipmi_si.trydmi=0
libiscsi.debug_libiscsi_eh=1 loglevel=4 ip=dhcp,dhcp6
rd.net.timeout.dhcp=10 crash_kexec_post_notifiers
[ 0.000000] BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000007fffff] usable
[ 0.000000] BIOS-e820: [mem 0x0000000000800000-0x0000000000807fff]
ACPI NVS
[ 0.000000] BIOS-e820: [mem 0x0000000000808000-0x000000000080ffff] usable
[ 0.000000] BIOS-e820: [mem 0x0000000000810000-0x00000000008fffff]
ACPI NVS
[ 0.000000] BIOS-e820: [mem 0x0000000000900000-0x00000000bf6eefff] usable
[ 0.000000] BIOS-e820: [mem 0x00000000bf6ef000-0x00000000bf96efff]
reserved
[ 0.000000] BIOS-e820: [mem 0x00000000bf96f000-0x00000000bf97efff]
ACPI data
[ 0.000000] BIOS-e820: [mem 0x00000000bf97f000-0x00000000bf9fefff]
ACPI NVS
[ 0.000000] BIOS-e820: [mem 0x00000000bf9ff000-0x00000000bfe7bfff] usable
[ 0.000000] BIOS-e820: [mem 0x00000000bfe7c000-0x00000000bfefffff]
reserved
[ 0.000000] BIOS-e820: [mem 0x00000000bff00000-0x00000000bfffffff]
ACPI NVS
[ 0.000000] BIOS-e820: [mem 0x00000000ffc00000-0x00000000ffffffff]
reserved
[ 0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000203fffffff] usable
[ 0.000000] NX (Execute Disable) protection: active
[ 0.000000] APIC: Static calls initialized
[ 0.000000] e820: update [mem 0xbe1fa018-0xbe203457] usable ==> usable
[ 0.000000] extended physical RAM map:
[ 0.000000] reserve setup_data: [mem
0x0000000000000000-0x000000000009ffff] usable
[ 0.000000] reserve setup_data: [mem
0x0000000000100000-0x00000000007fffff] usable
[ 0.000000] reserve setup_data: [mem
0x0000000000800000-0x0000000000807fff] ACPI NVS
[ 0.000000] reserve setup_data: [mem
0x0000000000808000-0x000000000080ffff] usable
[ 0.000000] reserve setup_data: [mem
0x0000000000810000-0x00000000008fffff] ACPI NVS
[ 0.000000] reserve setup_data: [mem
0x0000000000900000-0x00000000be1fa017] usable
[ 0.000000] reserve setup_data: [mem
0x00000000be1fa018-0x00000000be203457] usable
[ 0.000000] reserve setup_data: [mem
0x00000000be203458-0x00000000bf6eefff] usable
[ 0.000000] reserve setup_data: [mem
0x00000000bf6ef000-0x00000000bf96efff] reserved
[ 0.000000] reserve setup_data: [mem
0x00000000bf96f000-0x00000000bf97efff] ACPI data
[ 0.000000] reserve setup_data: [mem
0x00000000bf97f000-0x00000000bf9fefff] ACPI NVS
[ 0.000000] reserve setup_data: [mem
0x00000000bf9ff000-0x00000000bfe7bfff] usable
[ 0.000000] reserve setup_data: [mem
0x00000000bfe7c000-0x00000000bfefffff] reserved
[ 0.000000] reserve setup_data: [mem
0x00000000bff00000-0x00000000bfffffff] ACPI NVS
[ 0.000000] reserve setup_data: [mem
0x00000000ffc00000-0x00000000ffffffff] reserved
[ 0.000000] reserve setup_data: [mem
0x0000000100000000-0x000000203fffffff] usable
[ 0.000000] efi: EFI v2.7 by EDK II
[ 0.000000] efi: SMBIOS=0xbf741000 ACPI=0xbf97e000 ACPI
2.0=0xbf97e014 MEMATTR=0xbe7dc698 MOKvar=0xbf73c000
[ 0.000000] efi: Remove mem100: MMIO range=[0xffc00000-0xffffffff]
(4MB) from e820 map
[ 0.000000] e820: remove [mem 0xffc00000-0xffffffff] reserved
[ 0.000000] SMBIOS 2.8 present.
[ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.5.1
06/16/2021
[ 0.000000] DMI: Memory slots populated: 8/8
[ 0.000000] Hypervisor detected: KVM
[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[ 0.000000] kvm-clock: using sched offset of 6371798537501154 cycles
[ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff
max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[ 0.000004] tsc: Detected 2445.322 MHz processor
[ 0.000100] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[ 0.000102] e820: remove [mem 0x000a0000-0x000fffff] usable
[ 0.000108] last_pfn = 0x2040000 max_arch_pfn = 0x400000000
[ 0.000136] MTRR map: 4 entries (2 fixed + 2 variable; max 18), built
from 8 variable MTRRs
[ 0.000138] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
[ 0.000189] last_pfn = 0xbfe7c max_arch_pfn = 0x400000000
[ 0.004285] Using GB pages for direct mapping
[ 0.004770] Secure boot disabled
[ 0.004771] RAMDISK: [mem 0x57dbf000-0x5c573fff]
[ 0.004775] ACPI: Early table checksum verification disabled
[ 0.004777] ACPI: RSDP 0x00000000BF97E014 000024 (v02 BOCHS )
[ 0.004781] ACPI: XSDT 0x00000000BF97D0E8 000044 (v01 BOCHS BXPCFACP
00000001 01000013)
[ 0.004785] ACPI: FACP 0x00000000BF979000 000074 (v01 BOCHS BXPCFACP
00000001 BXPC 00000001)
[ 0.004789] ACPI: DSDT 0x00000000BF97A000 002862 (v01 BOCHS BXPCDSDT
00000001 BXPC 00000001)
[ 0.004792] ACPI: FACS 0x00000000BF9DD000 000040
[ 0.004794] ACPI: APIC 0x00000000BF978000 0000F0 (v01 BOCHS BXPCAPIC
00000001 BXPC 00000001)
[ 0.004796] ACPI: HPET 0x00000000BF977000 000038 (v01 BOCHS BXPCHPET
00000001 BXPC 00000001)
[ 0.004798] ACPI: BGRT 0x00000000BF976000 000038 (v01 INTEL EDK2
00000002 01000013)
[ 0.004799] ACPI: Reserving FACP table memory at [mem
0xbf979000-0xbf979073]
[ 0.004800] ACPI: Reserving DSDT table memory at [mem
0xbf97a000-0xbf97c861]
[ 0.004801] ACPI: Reserving FACS table memory at [mem
0xbf9dd000-0xbf9dd03f]
[ 0.004802] ACPI: Reserving APIC table memory at [mem
0xbf978000-0xbf9780ef]
[ 0.004803] ACPI: Reserving HPET table memory at [mem
0xbf977000-0xbf977037]
[ 0.004803] ACPI: Reserving BGRT table memory at [mem
0xbf976000-0xbf976037]
[ 0.005076] No NUMA configuration found
[ 0.005076] Faking a node at [mem 0x0000000000000000-0x000000203fffffff]
[ 0.005084] NODE_DATA(0) allocated [mem 0x203ffd5a00-0x203fffffff]
[ 0.005313] crashkernel: memory value expected
[ 0.005433] Zone ranges:
[ 0.005434] DMA [mem 0x0000000000001000-0x0000000000ffffff]
[ 0.005435] DMA32 [mem 0x0000000001000000-0x00000000ffffffff]
[ 0.005436] Normal [mem 0x0000000100000000-0x000000203fffffff]
[ 0.005437] Device empty
[ 0.005438] Movable zone start for each node
[ 0.005440] Early memory node ranges
[ 0.005440] node 0: [mem 0x0000000000001000-0x000000000009ffff]
[ 0.005441] node 0: [mem 0x0000000000100000-0x00000000007fffff]
[ 0.005442] node 0: [mem 0x0000000000808000-0x000000000080ffff]
[ 0.005443] node 0: [mem 0x0000000000900000-0x00000000bf6eefff]
[ 0.005444] node 0: [mem 0x00000000bf9ff000-0x00000000bfe7bfff]
[ 0.005444] node 0: [mem 0x0000000100000000-0x000000203fffffff]
[ 0.005455] Initmem setup node 0 [mem
0x0000000000001000-0x000000203fffffff]
[ 0.005464] On node 0, zone DMA: 1 pages in unavailable ranges
[ 0.005475] On node 0, zone DMA: 96 pages in unavailable ranges
[ 0.005476] On node 0, zone DMA: 8 pages in unavailable ranges
[ 0.005487] On node 0, zone DMA: 240 pages in unavailable ranges
[ 0.009255] On node 0, zone DMA32: 784 pages in unavailable ranges
[ 0.009460] On node 0, zone Normal: 388 pages in unavailable ranges
[ 0.010254] ACPI: PM-Timer IO Port: 0xb008
[ 0.010265] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.010286] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI
0-23
[ 0.010288] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.010290] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.010291] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.010292] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.010293] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.010296] ACPI: Using ACPI (MADT) for SMP configuration information
[ 0.010297] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.010305] e820: update [mem 0xbe204000-0xbe20cfff] usable ==> reserved
[ 0.010313] TSC deadline timer available
[ 0.010317] CPU topo: Max. logical packages: 1
[ 0.010318] CPU topo: Max. logical dies: 1
[ 0.010319] CPU topo: Max. dies per package: 1
[ 0.010323] CPU topo: Max. threads per core: 2
[ 0.010324] CPU topo: Num. cores per package: 8
[ 0.010324] CPU topo: Num. threads per package: 16
[ 0.010325] CPU topo: Allowing 16 present CPUs plus 0 hotplug CPUs
[ 0.010341] kvm-guest: APIC: eoi() replaced with
kvm_guest_apic_eoi_write()
[ 0.010349] kvm-guest: KVM setup pv remote TLB flush
[ 0.010351] kvm-guest: setup PV sched yield
[ 0.010362] PM: hibernation: Registered nosave memory: [mem
0x00000000-0x00000fff]
[ 0.010364] PM: hibernation: Registered nosave memory: [mem
0x000a0000-0x000fffff]
[ 0.010365] PM: hibernation: Registered nosave memory: [mem
0x00800000-0x00807fff]
[ 0.010366] PM: hibernation: Registered nosave memory: [mem
0x00810000-0x008fffff]
[ 0.010368] PM: hibernation: Registered nosave memory: [mem
0xbe1fa000-0xbe1fafff]
[ 0.010369] PM: hibernation: Registered nosave memory: [mem
0xbe203000-0xbe203fff]
[ 0.010369] PM: hibernation: Registered nosave memory: [mem
0xbe204000-0xbe20cfff]
[ 0.010371] PM: hibernation: Registered nosave memory: [mem
0xbf6ef000-0xbf96efff]
[ 0.010371] PM: hibernation: Registered nosave memory: [mem
0xbf96f000-0xbf97efff]
[ 0.010372] PM: hibernation: Registered nosave memory: [mem
0xbf97f000-0xbf9fefff]
[ 0.010373] PM: hibernation: Registered nosave memory: [mem
0xbfe7c000-0xbfefffff]
[ 0.010373] PM: hibernation: Registered nosave memory: [mem
0xbff00000-0xbfffffff]
[ 0.010374] PM: hibernation: Registered nosave memory: [mem
0xc0000000-0xffffffff]
[ 0.010376] [mem 0xc0000000-0xffffffff] available for PCI devices
[ 0.010377] Booting paravirtualized kernel on KVM
[ 0.010379] clocksource: refined-jiffies: mask: 0xffffffff
max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[ 0.015938] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:16
nr_cpu_ids:16 nr_node_ids:1
[ 0.016565] percpu: Embedded 66 pages/cpu s233472 r8192 d28672 u524288
[ 0.016571] pcpu-alloc: s233472 r8192 d28672 u524288 alloc=1*2097152
[ 0.016573] pcpu-alloc: [0] 00 01 02 03 [0] 04 05 06 07
[ 0.016577] pcpu-alloc: [0] 08 09 10 11 [0] 12 13 14 15
[ 0.016602] kvm-guest: PV spinlocks enabled
[ 0.016604] PV qspinlock hash table entries: 256 (order: 0, 4096
bytes, linear)
[ 0.016607] Kernel command line:
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-6.12.0-rc4-ge8f994e752e1
root=/dev/mapper/ocivolume-root ro crashkernel=auto LANG=en_US.UTF-8
console=tty0 console=ttyS0,115200 rd.luks=0 rd.md=0 rd.dm=0
rd.lvm.vg=ocivolume rd.lvm.lv=ocivolume/root rd.net.timeout.carrier=5
netroot=iscsi:169.254.0.2:::1:iqn.2015-02.oracle.boot:uefi
rd.iscsi.param=node.session.timeo.replacement_timeout=6000 net.ifnames=1
nvme_core.shutdown_timeout=10 ipmi_si.tryacpi=0 ipmi_si.trydmi=0
libiscsi.debug_libiscsi_eh=1 loglevel=4 ip=dhcp,dhcp6
rd.net.timeout.dhcp=10 crash_kexec_post_notifiers
[ 0.016877] Unknown kernel command line parameters
"BOOT_IMAGE=(hd0,gpt2)/vmlinuz-6.12.0-rc4-ge8f994e752e1 LANG=en_US.UTF-8
netroot=iscsi:169.254.0.2:::1:iqn.2015-02.oracle.boot:uefi
ip=dhcp,dhcp6", will be passed to user space.
[ 0.016897] random: crng init done
[ 0.020224] Dentry cache hash table entries: 8388608 (order: 14,
67108864 bytes, linear)
[ 0.021894] Inode-cache hash table entries: 4194304 (order: 13,
33554432 bytes, linear)
[ 0.021997] Fallback order for Node 0: 0
[ 0.022001] Built 1 zonelists, mobility grouping on. Total pages:
33552915
[ 0.022002] Policy zone: Normal
[ 0.022004] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.022009] software IO TLB: area num 16.
[ 0.043364] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
[ 0.043396] ftrace: allocating 54211 entries in 212 pages
[ 0.054792] ftrace: allocated 212 pages with 4 groups
[ 0.055553] Dynamic Preempt: voluntary
[ 0.055620] rcu: Preemptible hierarchical RCU implementation.
[ 0.055621] rcu: RCU restricting CPUs from NR_CPUS=8192 to
nr_cpu_ids=16.
[ 0.055622] Trampoline variant of Tasks RCU enabled.
[ 0.055623] Rude variant of Tasks RCU enabled.
[ 0.055623] Tracing variant of Tasks RCU enabled.
[ 0.055623] rcu: RCU calculated value of scheduler-enlistment delay
is 100 jiffies.
[ 0.055624] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=16
[ 0.055634] RCU Tasks: Setting shift to 4 and lim to 1
rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[ 0.055636] RCU Tasks Rude: Setting shift to 4 and lim to 1
rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[ 0.055638] RCU Tasks Trace: Setting shift to 4 and lim to 1
rcu_task_cb_adjust=1 rcu_task_cpu_ids=16.
[ 0.058342] NR_IRQS: 524544, nr_irqs: 552, preallocated irqs: 16
[ 0.058536] rcu: srcu_init: Setting srcu_struct sizes based on
contention.
[ 0.058593] Console: colour dummy device 80x25
[ 0.058595] printk: legacy console [tty0] enabled
[ 0.058669] printk: legacy console [ttyS0] enabled
[ 0.058708] ACPI: Core revision 20240827
[ 0.058825] clocksource: hpet: mask: 0xffffffff max_cycles:
0xffffffff, max_idle_ns: 19112604467 ns
[ 0.058914] APIC: Switch to symmetric I/O mode setup
[ 0.059050] x2apic enabled
[ 0.059241] APIC: Switched APIC routing to: physical x2apic
[ 0.059245] kvm-guest: APIC: send_IPI_mask() replaced with
kvm_send_ipi_mask()
[ 0.059248] kvm-guest: APIC: send_IPI_mask_allbutself() replaced with
kvm_send_ipi_mask_allbutself()
[ 0.059250] kvm-guest: setup PV IPIs
[ 0.059932] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.059948] clocksource: tsc-early: mask: 0xffffffffffffffff
max_cycles: 0x233f75bfd04, max_idle_ns: 440795297075 ns
[ 0.059953] Calibrating delay loop (skipped) preset value.. 4890.64
BogoMIPS (lpj=2445322)
[ 0.060034] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[ 0.060091] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
[ 0.060092] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
[ 0.060098] Spectre V1 : Mitigation: usercopy/swapgs barriers and
__user pointer sanitization
[ 0.060101] Spectre V2 : Mitigation: Retpolines
[ 0.060102] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling
RSB on context switch
[ 0.060103] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
[ 0.060104] Spectre V2 : Enabling Restricted Speculation for firmware
calls
[ 0.060106] Spectre V2 : mitigation: Enabling conditional Indirect
Branch Prediction Barrier
[ 0.060107] Spectre V2 : User space: Mitigation: STIBP via prctl
[ 0.060110] Speculative Store Bypass: Mitigation: Speculative Store
Bypass disabled via prctl
[ 0.060111] Speculative Return Stack Overflow: IBPB-extending
microcode not applied!
[ 0.060112] Speculative Return Stack Overflow: WARNING: See
https://kernel.org/doc/html/latest/admin-guide/hw-vuln/srso.html for
mitigation options.
[ 0.060113] Speculative Return Stack Overflow: Vulnerable: Safe RET,
no microcode
[ 0.060126] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating
point registers'
[ 0.060128] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[ 0.060128] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[ 0.060129] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys
User registers'
[ 0.060131] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
[ 0.060132] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
[ 0.060133] x86/fpu: Enabled xstate features 0x207, context size is
840 bytes, using 'compacted' format.
[ 0.089741] Freeing SMP alternatives memory: 44K
[ 0.089745] pid_max: default: 32768 minimum: 301
[ 0.092531] LSM: initializing
lsm=lockdown,capability,yama,selinux,ima,evm
[ 0.092582] Yama: becoming mindful.
[ 0.092591] SELinux: Initializing.
[ 0.092964] Mount-cache hash table entries: 131072 (order: 8, 1048576
bytes, linear)
[ 0.093025] Mountpoint-cache hash table entries: 131072 (order: 8,
1048576 bytes, linear)
[ 0.093346] smpboot: CPU0: AMD EPYC 7J13 64-Core Processor (family:
0x19, model: 0x1, stepping: 0x1)
[ 0.094118] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
[ 0.094151] ... version: 0
[ 0.094153] ... bit width: 48
[ 0.094154] ... generic registers: 6
[ 0.094156] ... value mask: 0000ffffffffffff
[ 0.094158] ... max period: 00007fffffffffff
[ 0.094160] ... fixed-purpose events: 0
[ 0.094161] ... event mask: 000000000000003f
[ 0.094267] signal: max sigframe size: 3376
[ 0.094304] rcu: Hierarchical SRCU implementation.
[ 0.094306] rcu: Max phase no-delay instances is 400.
[ 0.094361] Timer migration: 2 hierarchy levels; 8 children per
group; 2 crossnode level
[ 0.098965] smp: Bringing up secondary CPUs ...
[ 0.099114] smpboot: x86: Booting SMP configuration:
[ 0.099116] .... node #0, CPUs: #2 #4 #6 #8 #10 #12 #14 #1
#3 #5 #7 #9 #11 #13 #15
[ 0.108037] smp: Brought up 1 node, 16 CPUs
[ 0.108043] smpboot: Total of 16 processors activated (78250.30 BogoMIPS)
[ 0.159990] node 0 deferred pages initialised in 51ms
[ 0.160046] Memory: 131807404K/134211660K available (18432K kernel
code, 5906K rwdata, 8816K rodata, 4636K init, 6600K bss, 2391816K
reserved, 0K cma-reserved)
[ 0.163026] devtmpfs: initialized
[ 0.163026] x86/mm: Memory block size: 1024MB
[ 0.166139] ACPI: PM: Registering ACPI NVS region [mem
0x00800000-0x00807fff] (32768 bytes)
[ 0.166139] ACPI: PM: Registering ACPI NVS region [mem
0x00810000-0x008fffff] (983040 bytes)
[ 0.166139] ACPI: PM: Registering ACPI NVS region [mem
0xbf97f000-0xbf9fefff] (524288 bytes)
[ 0.166139] ACPI: PM: Registering ACPI NVS region [mem
0xbff00000-0xbfffffff] (1048576 bytes)
[ 0.166139] clocksource: jiffies: mask: 0xffffffff max_cycles:
0xffffffff, max_idle_ns: 1911260446275000 ns
[ 0.166139] futex hash table entries: 4096 (order: 6, 262144 bytes,
linear)
[ 0.166203] pinctrl core: initialized pinctrl subsystem
[ 0.166930] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.167265] DMA: preallocated 4096 KiB GFP_KERNEL pool for atomic
allocations
[ 0.167271] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA pool for
atomic allocations
[ 0.167275] DMA: preallocated 4096 KiB GFP_KERNEL|GFP_DMA32 pool for
atomic allocations
[ 0.167285] audit: initializing netlink subsys (disabled)
[ 0.167298] audit: type=2000 audit(1729591723.425:1):
state=initialized audit_enabled=0 res=1
[ 0.167298] thermal_sys: Registered thermal governor 'fair_share'
[ 0.167298] thermal_sys: Registered thermal governor 'bang_bang'
[ 0.167298] thermal_sys: Registered thermal governor 'step_wise'
[ 0.167298] thermal_sys: Registered thermal governor 'user_space'
[ 0.167298] cpuidle: using governor menu
[ 0.168318] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[ 0.168477] PCI: Using configuration type 1 for base access
[ 0.168479] PCI: Using configuration type 1 for extended access
[ 0.169170] kprobes: kprobe jump-optimization is enabled. All kprobes
are optimized if possible.
[ 0.169170] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[ 0.169170] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
[ 0.169170] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.169170] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
[ 0.170111] ACPI: Added _OSI(Module Device)
[ 0.170111] ACPI: Added _OSI(Processor Device)
[ 0.170111] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 0.170111] ACPI: Added _OSI(Processor Aggregator Device)
[ 0.172032] ACPI: 1 ACPI AML tables successfully acquired and loaded
[ 0.173301] ACPI: Interpreter enabled
[ 0.173301] ACPI: PM: (supports S0 S3 S4 S5)
[ 0.173301] ACPI: Using IOAPIC for interrupt routing
[ 0.173301] PCI: Using host bridge windows from ACPI; if necessary,
use "pci=nocrs" and report a bug
[ 0.173301] PCI: Using E820 reservations for host bridge windows
[ 0.173301] ACPI: Enabled 2 GPEs in block 00 to 0F
[ 0.180029] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 0.180036] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM
ClockPM Segments MSI EDR HPX-Type3]
[ 0.180744] acpiphp: Slot [3] registered
[ 0.180777] acpiphp: Slot [4] registered
[ 0.180798] acpiphp: Slot [5] registered
[ 0.180820] acpiphp: Slot [6] registered
[ 0.180843] acpiphp: Slot [7] registered
[ 0.180861] acpiphp: Slot [8] registered
[ 0.180878] acpiphp: Slot [9] registered
[ 0.180895] acpiphp: Slot [10] registered
[ 0.180912] acpiphp: Slot [11] registered
[ 0.180929] acpiphp: Slot [12] registered
[ 0.180973] acpiphp: Slot [15] registered
[ 0.180989] acpiphp: Slot [16] registered
[ 0.181006] acpiphp: Slot [17] registered
[ 0.181022] acpiphp: Slot [18] registered
[ 0.181040] acpiphp: Slot [19] registered
[ 0.181056] acpiphp: Slot [20] registered
[ 0.181072] acpiphp: Slot [21] registered
[ 0.181089] acpiphp: Slot [22] registered
[ 0.181105] acpiphp: Slot [23] registered
[ 0.181121] acpiphp: Slot [24] registered
[ 0.181137] acpiphp: Slot [25] registered
[ 0.181154] acpiphp: Slot [26] registered
[ 0.181171] acpiphp: Slot [27] registered
[ 0.181187] acpiphp: Slot [28] registered
[ 0.181205] acpiphp: Slot [29] registered
[ 0.181221] acpiphp: Slot [30] registered
[ 0.181237] acpiphp: Slot [31] registered
[ 0.181247] PCI host bridge to bus 0000:00
[ 0.181252] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
[ 0.181255] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
[ 0.181258] pci_bus 0000:00: root bus resource [mem
0x000a0000-0x000bffff window]
[ 0.181260] pci_bus 0000:00: root bus resource [mem
0xc0000000-0xfebfffff window]
[ 0.181262] pci_bus 0000:00: root bus resource [mem
0x2800000000-0x287fffffff window]
[ 0.181265] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.181389] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
conventional PCI endpoint
[ 0.181762] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
conventional PCI endpoint
[ 0.182209] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
conventional PCI endpoint
[ 0.185434] pci 0000:00:01.1: BAR 4 [io 0xe020-0xe02f]
[ 0.186229] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
[ 0.186232] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
[ 0.186234] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
[ 0.186236] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
[ 0.186357] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300
conventional PCI endpoint
[ 0.188399] pci 0000:00:01.2: BAR 4 [io 0xe000-0xe01f]
[ 0.189321] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
conventional PCI endpoint
[ 0.189644] pci 0000:00:01.3: quirk: [io 0xb000-0xb03f] claimed by
PIIX4 ACPI
[ 0.189653] pci 0000:00:01.3: quirk: [io 0xb100-0xb10f] claimed by
PIIX4 SMB
[ 0.189851] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
conventional PCI endpoint
[ 0.192958] pci 0000:00:02.0: BAR 0 [mem 0xc0000000-0xc0ffffff pref]
[ 0.196725] pci 0000:00:02.0: BAR 2 [mem 0xc1410000-0xc1410fff]
[ 0.201736] pci 0000:00:02.0: ROM [mem 0xffff0000-0xffffffff pref]
[ 0.201788] pci 0000:00:02.0: Video device with shadowed ROM at [mem
0x000c0000-0x000dffff]
[ 0.202164] pci 0000:00:03.0: [15b3:101e] type 00 class 0x020000 PCIe
Endpoint
[ 0.203427] pci 0000:00:03.0: BAR 0 [mem 0x2800000000-0x28001fffff
64bit pref]
[ 0.209424] pci 0000:00:03.0: enabling Extended Tags
[ 0.210042] pci 0000:00:03.0: 0.000 Gb/s available PCIe bandwidth,
limited by Unknown x0 link at 0000:00:03.0 (capable of 126.024 Gb/s with
16.0 GT/s PCIe x8 link)
[ 0.210318] pci 0000:00:0d.0: [1b36:0001] type 01 class 0x060400
conventional PCI bridge
[ 0.211303] pci 0000:00:0d.0: BAR 0 [mem 0x2800401000-0x28004010ff 64bit]
[ 0.211964] pci 0000:00:0d.0: PCI bridge to [bus 01]
[ 0.211983] pci 0000:00:0d.0: bridge window [io 0xd000-0xdfff]
[ 0.211996] pci 0000:00:0d.0: bridge window [mem 0xc1200000-0xc13fffff]
[ 0.212368] pci 0000:00:0d.0: bridge window [mem
0x2800200000-0x28002fffff 64bit pref]
[ 0.213036] pci 0000:00:0e.0: [1b36:0001] type 01 class 0x060400
conventional PCI bridge
[ 0.213955] pci 0000:00:0e.0: BAR 0 [mem 0x2800400000-0x28004000ff 64bit]
[ 0.214631] pci 0000:00:0e.0: PCI bridge to [bus 02]
[ 0.214650] pci 0000:00:0e.0: bridge window [io 0xc000-0xcfff]
[ 0.214663] pci 0000:00:0e.0: bridge window [mem 0xc1000000-0xc11fffff]
[ 0.214978] pci 0000:00:0e.0: bridge window [mem
0x2800300000-0x28003fffff 64bit pref]
[ 0.217732] pci_bus 0000:01: extended config space not accessible
[ 0.218041] acpiphp: Slot [0] registered
[ 0.218070] acpiphp: Slot [1] registered
[ 0.218087] acpiphp: Slot [2] registered
[ 0.218108] acpiphp: Slot [3-2] registered
[ 0.218129] acpiphp: Slot [4-2] registered
[ 0.218149] acpiphp: Slot [5-2] registered
[ 0.218179] acpiphp: Slot [6-2] registered
[ 0.218200] acpiphp: Slot [7-2] registered
[ 0.218221] acpiphp: Slot [8-2] registered
[ 0.218241] acpiphp: Slot [9-2] registered
[ 0.218261] acpiphp: Slot [10-2] registered
[ 0.218282] acpiphp: Slot [11-2] registered
[ 0.218304] acpiphp: Slot [12-2] registered
[ 0.218321] acpiphp: Slot [13] registered
[ 0.218338] acpiphp: Slot [14] registered
[ 0.218358] acpiphp: Slot [15-2] registered
[ 0.218380] acpiphp: Slot [16-2] registered
[ 0.218400] acpiphp: Slot [17-2] registered
[ 0.218421] acpiphp: Slot [18-2] registered
[ 0.218441] acpiphp: Slot [19-2] registered
[ 0.218461] acpiphp: Slot [20-2] registered
[ 0.218482] acpiphp: Slot [21-2] registered
[ 0.218503] acpiphp: Slot [22-2] registered
[ 0.218524] acpiphp: Slot [23-2] registered
[ 0.218544] acpiphp: Slot [24-2] registered
[ 0.218565] acpiphp: Slot [25-2] registered
[ 0.218585] acpiphp: Slot [26-2] registered
[ 0.218605] acpiphp: Slot [27-2] registered
[ 0.218625] acpiphp: Slot [28-2] registered
[ 0.218648] acpiphp: Slot [29-2] registered
[ 0.218668] acpiphp: Slot [30-2] registered
[ 0.218690] acpiphp: Slot [31-2] registered
[ 0.218763] pci 0000:01:00.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.219367] pci 0000:01:00.0: BAR 0 [io 0xd000-0xd03f]
[ 0.219955] pci 0000:01:00.0: BAR 1 [mem 0xc1200000-0xc1200fff]
[ 0.222955] pci 0000:01:00.0: BAR 4 [mem 0x2800200000-0x2800203fff
64bit pref]
[ 0.224516] pci 0000:00:0d.0: PCI bridge to [bus 01]
[ 0.225060] pci_bus 0000:02: extended config space not accessible
[ 0.225375] acpiphp: Slot [0-2] registered
[ 0.225398] acpiphp: Slot [1-2] registered
[ 0.225422] acpiphp: Slot [2-2] registered
[ 0.225443] acpiphp: Slot [3-3] registered
[ 0.225465] acpiphp: Slot [4-3] registered
[ 0.225486] acpiphp: Slot [5-3] registered
[ 0.225507] acpiphp: Slot [6-3] registered
[ 0.225528] acpiphp: Slot [7-3] registered
[ 0.225549] acpiphp: Slot [8-3] registered
[ 0.225571] acpiphp: Slot [9-3] registered
[ 0.225593] acpiphp: Slot [10-3] registered
[ 0.225618] acpiphp: Slot [11-3] registered
[ 0.225646] acpiphp: Slot [12-3] registered
[ 0.225670] acpiphp: Slot [13-2] registered
[ 0.225690] acpiphp: Slot [14-2] registered
[ 0.225712] acpiphp: Slot [15-3] registered
[ 0.225733] acpiphp: Slot [16-3] registered
[ 0.225756] acpiphp: Slot [17-3] registered
[ 0.225777] acpiphp: Slot [18-3] registered
[ 0.225799] acpiphp: Slot [19-3] registered
[ 0.225834] acpiphp: Slot [20-3] registered
[ 0.225856] acpiphp: Slot [21-3] registered
[ 0.225878] acpiphp: Slot [22-3] registered
[ 0.225899] acpiphp: Slot [23-3] registered
[ 0.225923] acpiphp: Slot [24-3] registered
[ 0.225945] acpiphp: Slot [25-3] registered
[ 0.225969] acpiphp: Slot [26-3] registered
[ 0.225991] acpiphp: Slot [27-3] registered
[ 0.226013] acpiphp: Slot [28-3] registered
[ 0.226034] acpiphp: Slot [29-3] registered
[ 0.226056] acpiphp: Slot [30-3] registered
[ 0.226078] acpiphp: Slot [31-3] registered
[ 0.226153] pci 0000:02:00.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.228394] pci 0000:02:00.0: BAR 0 [io 0xc140-0xc17f]
[ 0.228956] pci 0000:02:00.0: BAR 1 [mem 0xc1005000-0xc1005fff]
[ 0.231955] pci 0000:02:00.0: BAR 4 [mem 0x2800314000-0x2800317fff
64bit pref]
[ 0.233232] pci 0000:02:01.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.233958] pci 0000:02:01.0: BAR 0 [io 0xc100-0xc13f]
[ 0.234955] pci 0000:02:01.0: BAR 1 [mem 0xc1004000-0xc1004fff]
[ 0.240454] pci 0000:02:01.0: BAR 4 [mem 0x2800310000-0x2800313fff
64bit pref]
[ 0.241425] pci 0000:02:02.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.242585] pci 0000:02:02.0: BAR 0 [io 0xc0c0-0xc0ff]
[ 0.243592] pci 0000:02:02.0: BAR 1 [mem 0xc1003000-0xc1003fff]
[ 0.247599] pci 0000:02:02.0: BAR 4 [mem 0x280030c000-0x280030ffff
64bit pref]
[ 0.249045] pci 0000:02:03.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.251490] pci 0000:02:03.0: BAR 0 [io 0xc080-0xc0bf]
[ 0.252436] pci 0000:02:03.0: BAR 1 [mem 0xc1002000-0xc1002fff]
[ 0.255443] pci 0000:02:03.0: BAR 4 [mem 0x2800308000-0x280030bfff
64bit pref]
[ 0.257432] pci 0000:02:04.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.258575] pci 0000:02:04.0: BAR 0 [io 0xc040-0xc07f]
[ 0.259572] pci 0000:02:04.0: BAR 1 [mem 0xc1001000-0xc1001fff]
[ 0.263835] pci 0000:02:04.0: BAR 4 [mem 0x2800304000-0x2800307fff
64bit pref]
[ 0.265839] pci 0000:02:05.0: [1af4:1004] type 00 class 0x010000
conventional PCI endpoint
[ 0.266385] pci 0000:02:05.0: BAR 0 [io 0xc000-0xc03f]
[ 0.266955] pci 0000:02:05.0: BAR 1 [mem 0xc1000000-0xc1000fff]
[ 0.269955] pci 0000:02:05.0: BAR 4 [mem 0x2800300000-0x2800303fff
64bit pref]
[ 0.271486] pci 0000:00:0e.0: PCI bridge to [bus 02]
[ 0.275010] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
[ 0.275112] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
[ 0.275205] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
[ 0.275296] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
[ 0.275344] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
[ 0.276299] iommu: Default domain type: Passthrough
[ 0.276299] SCSI subsystem initialized
[ 0.276299] ACPI: bus type USB registered
[ 0.276299] usbcore: registered new interface driver usbfs
[ 0.276299] usbcore: registered new interface driver hub
[ 0.276299] usbcore: registered new device driver usb
[ 0.276299] pps_core: LinuxPPS API ver. 1 registered
[ 0.276299] pps_core: Software ver. 5.3.6 - Copyright 2005-2007
Rodolfo Giometti <giometti@linux.it>
[ 0.276299] PTP clock support registered
[ 0.276977] EDAC MC: Ver: 3.0.0
[ 0.277122] efivars: Registered efivars operations
[ 0.277241] NetLabel: Initializing
[ 0.277243] NetLabel: domain hash size = 128
[ 0.277245] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
[ 0.277265] NetLabel: unlabeled traffic allowed by default
[ 0.277267] PCI: Using ACPI for IRQ routing
[ 0.277269] PCI: pci_cache_line_size set to 64 bytes
[ 0.277471] e820: reserve RAM buffer [mem 0x00810000-0x008fffff]
[ 0.277474] e820: reserve RAM buffer [mem 0xbe1fa018-0xbfffffff]
[ 0.277476] e820: reserve RAM buffer [mem 0xbe204000-0xbfffffff]
[ 0.277478] e820: reserve RAM buffer [mem 0xbf6ef000-0xbfffffff]
[ 0.277480] e820: reserve RAM buffer [mem 0xbfe7c000-0xbfffffff]
[ 0.278004] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[ 0.278004] pci 0000:00:02.0: vgaarb: bridge control possible
[ 0.278004] pci 0000:00:02.0: vgaarb: VGA device added:
decodes=io+mem,owns=io+mem,locks=none
[ 0.278004] vgaarb: loaded
[ 0.278177] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 0.278185] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[ 0.282053] clocksource: Switched to clocksource kvm-clock
[ 0.282381] VFS: Disk quotas dquot_6.6.0
[ 0.282393] VFS: Dquot-cache hash table entries: 512 (order 0, 4096
bytes)
[ 0.282461] pnp: PnP ACPI init
[ 0.282580] pnp 00:03: [dma 2]
[ 0.282936] pnp: PnP ACPI: found 5 devices
[ 0.290539] clocksource: acpi_pm: mask: 0xffffff max_cycles:
0xffffff, max_idle_ns: 2085701024 ns
[ 0.290610] NET: Registered PF_INET protocol family
[ 0.290745] IP idents hash table entries: 262144 (order: 9, 2097152
bytes, linear)
[ 0.293435] tcp_listen_portaddr_hash hash table entries: 65536
(order: 8, 1048576 bytes, linear)
[ 0.293512] Table-perturb hash table entries: 65536 (order: 6, 262144
bytes, linear)
[ 0.293520] TCP established hash table entries: 524288 (order: 10,
4194304 bytes, linear)
[ 0.293876] TCP bind hash table entries: 65536 (order: 9, 2097152
bytes, linear)
[ 0.294012] TCP: Hash tables configured (established 524288 bind 65536)
[ 0.294196] MPTCP token hash table entries: 65536 (order: 8, 1572864
bytes, linear)
[ 0.294259] UDP hash table entries: 65536 (order: 9, 2097152 bytes,
linear)
[ 0.294455] UDP-Lite hash table entries: 65536 (order: 9, 2097152
bytes, linear)
[ 0.294684] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.294692] NET: Registered PF_XDP protocol family
[ 0.294701] pci 0000:00:0d.0: PCI bridge to [bus 01]
[ 0.294717] pci 0000:00:0d.0: bridge window [io 0xd000-0xdfff]
[ 0.295517] pci 0000:00:0d.0: bridge window [mem 0xc1200000-0xc13fffff]
[ 0.296000] pci 0000:00:0d.0: bridge window [mem
0x2800200000-0x28002fffff 64bit pref]
[ 0.296922] pci 0000:00:0e.0: PCI bridge to [bus 02]
[ 0.296946] pci 0000:00:0e.0: bridge window [io 0xc000-0xcfff]
[ 0.297640] pci 0000:00:0e.0: bridge window [mem 0xc1000000-0xc11fffff]
[ 0.298105] pci 0000:00:0e.0: bridge window [mem
0x2800300000-0x28003fffff 64bit pref]
[ 0.299021] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 0.299025] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 0.299027] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff
window]
[ 0.299030] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfffff
window]
[ 0.299032] pci_bus 0000:00: resource 8 [mem
0x2800000000-0x287fffffff window]
[ 0.299035] pci_bus 0000:01: resource 0 [io 0xd000-0xdfff]
[ 0.299037] pci_bus 0000:01: resource 1 [mem 0xc1200000-0xc13fffff]
[ 0.299040] pci_bus 0000:01: resource 2 [mem
0x2800200000-0x28002fffff 64bit pref]
[ 0.299042] pci_bus 0000:02: resource 0 [io 0xc000-0xcfff]
[ 0.299044] pci_bus 0000:02: resource 1 [mem 0xc1000000-0xc11fffff]
[ 0.299047] pci_bus 0000:02: resource 2 [mem
0x2800300000-0x28003fffff 64bit pref]
[ 0.299181] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 0.299194] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 0.330370] ACPI: \_SB_.LNKD: Enabled at IRQ 11
[ 0.361660] pci 0000:00:01.2: quirk_usb_early_handoff+0x0/0x6c0 took
60970 usecs
[ 0.361776] PCI: CLS 0 bytes, default 64
[ 0.361816] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 0.361818] software IO TLB: mapped [mem
0x00000000b7dfe000-0x00000000bbdfe000] (64MB)
[ 0.361884] Trying to unpack rootfs image as initramfs...
[ 0.366339] clocksource: tsc: mask: 0xffffffffffffffff max_cycles:
0x233f75bfd04, max_idle_ns: 440795297075 ns
[ 0.370487] Initialise system trusted keyrings
[ 0.370503] Key type blacklist registered
[ 0.370580] workingset: timestamp_bits=36 max_order=25 bucket_order=0
[ 0.370590] zbud: loaded
[ 0.371461] integrity: Platform Keyring initialized
[ 0.371467] integrity: Machine keyring initialized
[ 0.371469] Allocating IMA blacklist keyring.
[ 0.383287] NET: Registered PF_ALG protocol family
[ 0.383292] Key type asymmetric registered
[ 0.383294] Asymmetric key parser 'x509' registered
[ 0.383296] Key type pkcs7_test registered
[ 1.184057] Freeing initrd memory: 73428K
[ 1.188531] Block layer SCSI generic (bsg) driver version 0.4 loaded
(major 246)
[ 1.188605] io scheduler mq-deadline registered
[ 1.188608] io scheduler kyber registered
[ 1.188625] io scheduler bfq registered
[ 1.190588] atomic64_test: passed for x86-64 platform with CX8 and
with SSE
[ 1.191032] shpchp 0000:00:0d.0: Requesting control of SHPC hotplug
via OSHP (\_SB_.PCI0.S68_)
[ 1.191042] shpchp 0000:00:0d.0: Requesting control of SHPC hotplug
via OSHP (\_SB_.PCI0)
[ 1.191050] shpchp 0000:00:0d.0: Cannot get control of SHPC hotplug
[ 1.191087] shpchp 0000:00:0e.0: Requesting control of SHPC hotplug
via OSHP (\_SB_.PCI0.S70_)
[ 1.191094] shpchp 0000:00:0e.0: Requesting control of SHPC hotplug
via OSHP (\_SB_.PCI0)
[ 1.191098] shpchp 0000:00:0e.0: Cannot get control of SHPC hotplug
[ 1.191108] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[ 1.191262] input: Power Button as
/devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 1.191358] ACPI: button: Power Button [PWRF]
[ 1.191401] input: Sleep Button as
/devices/LNXSYSTM:00/LNXSLPBN:00/input/input1
[ 1.191461] ACPI: button: Sleep Button [SLPF]
[ 1.192870] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 1.193046] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200)
is a 16550A
[ 1.193688] Non-volatile memory driver v1.3
[ 1.193691] Linux agpgart interface v0.103
[ 1.195189] rdac: device handler registered
[ 1.195253] hp_sw: device handler registered
[ 1.195256] emc: device handler registered
[ 1.195306] alua: device handler registered
[ 1.195560] VFIO - User Level meta-driver version: 0.3
[ 1.227222] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 1.227304] uhci_hcd 0000:00:01.2: new USB bus registered, assigned
bus number 1
[ 1.227321] uhci_hcd 0000:00:01.2: detected 2 ports
[ 1.227410] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000e000
[ 1.227524] usb usb1: New USB device found, idVendor=1d6b,
idProduct=0001, bcdDevice= 6.12
[ 1.227528] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 1.227530] usb usb1: Product: UHCI Host Controller
[ 1.227532] usb usb1: Manufacturer: Linux 6.12.0-rc4-ge8f994e752e1
uhci_hcd
[ 1.227535] usb usb1: SerialNumber: 0000:00:01.2
[ 1.227677] hub 1-0:1.0: USB hub found
[ 1.227687] hub 1-0:1.0: 2 ports detected
[ 1.227867] usbcore: registered new interface driver usbserial_generic
[ 1.227874] usbserial: USB Serial support registered for generic
[ 1.227913] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at
0x60,0x64 irq 1,12
[ 1.228538] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 1.228545] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 1.228666] mousedev: PS/2 mouse device common for all mice
[ 1.228977] input: AT Translated Set 2 keyboard as
/devices/platform/i8042/serio0/input/input2
[ 1.229107] rtc_cmos 00:00: RTC can wake from S4
[ 1.229881] input: VirtualPS/2 VMware VMMouse as
/devices/platform/i8042/serio1/input/input5
[ 1.230218] input: VirtualPS/2 VMware VMMouse as
/devices/platform/i8042/serio1/input/input4
[ 1.230314] rtc_cmos 00:00: registered as rtc0
[ 1.230379] rtc_cmos 00:00: setting system clock to
2024-10-22T10:08:44 UTC (1729591724)
[ 1.230445] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram
[ 1.230674] amd_pstate: the _CPC object is not present in SBIOS or
ACPI disabled
[ 1.230802] efifb: probing for efifb
[ 1.230826] efifb: showing boot graphics
[ 1.231517] efifb: framebuffer at 0xc0000000, using 1876k, total 1875k
[ 1.231519] efifb: mode is 800x600x32, linelength=3200, pages=1
[ 1.231522] efifb: scrolling: redraw
[ 1.231523] efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0
[ 1.231584] fbcon: Deferring console take-over
[ 1.231586] fb0: EFI VGA frame buffer device
[ 1.231611] hid: raw HID events driver (C) Jiri Kosina
[ 1.231732] usbcore: registered new interface driver usbhid
[ 1.231734] usbhid: USB HID core driver
[ 1.231800] drop_monitor: Initializing network drop monitor service
[ 1.231891] Initializing XFRM netlink socket
[ 1.231921] NET: Registered PF_INET6 protocol family
[ 1.232303] Segment Routing with IPv6
[ 1.232314] In-situ OAM (IOAM) with IPv6
[ 1.232336] NET: Registered PF_PACKET protocol family
[ 1.232345] bridge: filtering via arp/ip/ip6tables is no longer
available by default. Update your scripts to load br_netfilter if you
need this.
[ 1.232472] sctp: Hash tables configured (bind 2048/2048)
[ 1.232508] tipc: Activated (version 2.0.0)
[ 1.232530] NET: Registered PF_TIPC protocol family
[ 1.232566] tipc: Started in single node mode
[ 1.233858] IPI shorthand broadcast: enabled
[ 1.236388] sched_clock: Marking stable (1235002986,
409682)->(1238644994, -3232326)
[ 1.236687] registered taskstats version 1
[ 1.237696] Loading compiled-in X.509 certificates
[ 1.245277] Loaded X.509 cert 'Build time autogenerated kernel key:
0ec1ef2cc4b8a3e8d8d68ea1e6a2a1b1fa52a0e7'
[ 1.248603] Demotion targets for Node 0: null
[ 1.248612] page_owner is disabled
[ 1.248816] Key type .fscrypt registered
[ 1.248819] Key type fscrypt-provisioning registered
[ 1.254132] cryptd: max_cpu_qlen set to 1000
[ 1.257270] AES CTR mode by8 optimization enabled
[ 1.271994] Key type encrypted registered
[ 1.272087] ima: No TPM chip found, activating TPM-bypass!
[ 1.272091] Loading compiled-in module X.509 certificates
[ 1.272520] Loaded X.509 cert 'Build time autogenerated kernel key:
0ec1ef2cc4b8a3e8d8d68ea1e6a2a1b1fa52a0e7'
[ 1.272524] ima: Allocated hash algorithm: sha256
[ 1.272535] ima: No architecture policies found
[ 1.272555] evm: Initialising EVM extended attributes:
[ 1.272556] evm: security.selinux
[ 1.272558] evm: security.SMACK64 (disabled)
[ 1.272560] evm: security.SMACK64EXEC (disabled)
[ 1.272562] evm: security.SMACK64TRANSMUTE (disabled)
[ 1.272563] evm: security.SMACK64MMAP (disabled)
[ 1.272565] evm: security.apparmor (disabled)
[ 1.272566] evm: security.ima
[ 1.272568] evm: security.capability
[ 1.272569] evm: HMAC attrs: 0x1
[ 1.278150] RAS: Correctable Errors collector initialized.
[ 1.278221] clk: Disabling unused clocks
[ 1.278601] integrity: Unable to open file: /etc/keys/x509_ima.der (-2)
[ 1.280221] Freeing unused decrypted memory: 2028K
[ 1.280768] fbcon: Taking over console
[ 1.281428] Freeing unused kernel image (initmem) memory: 4636K
[ 1.281441] Write protecting the kernel read-only data: 28672k
[ 1.282052] Freeing unused kernel image (rodata/data gap) memory: 1424K
[ 1.282057] rodata_test: all tests were successful
[ 1.282065] Run /init as init process
[ 1.282066] with arguments:
[ 1.282068] /init
[ 1.282070] with environment:
[ 1.282072] HOME=/
[ 1.282074] TERM=linux
[ 1.282076] BOOT_IMAGE=(hd0,gpt2)/vmlinuz-6.12.0-rc4-ge8f994e752e1
[ 1.282078] LANG=en_US.UTF-8
[ 1.282079] netroot=iscsi:169.254.0.2:::1:iqn.2015-02.oracle.boot:uefi
[ 1.282081] ip=dhcp,dhcp6
[ 1.282175] Console: switching to colour frame buffer device 100x37
[ 1.292802] systemd[1]: systemd 239 (239-78.0.3.el8) 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=legacy)
[ 1.292847] systemd[1]: Detected virtualization kvm.
[ 1.292851] systemd[1]: Detected architecture x86-64.
[ 1.292854] systemd[1]: Running in initial RAM disk.
[ 1.306900] systemd[1]: No hostname configured.
[ 1.306906] systemd[1]: Set hostname to <localhost>.
[ 1.306967] systemd[1]: Initializing machine ID from KVM UUID.
[ 1.366385] systemd[1]: Listening on Journal Socket (/dev/log).
[ 1.367054] systemd[1]: Listening on Open-iSCSI iscsid Socket.
[ 1.367792] systemd[1]: Reached target Swap.
[ 1.411190] Loading iSCSI transport class v2.0-870.
[ 1.456433] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 1.608667] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is
disabled. Duplicate IMA measurements will not be recorded in the IMA log.
[ 1.608708] device-mapper: uevent: version 1.0.3
[ 1.608810] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01)
initialised: dm-devel@lists.linux.dev
[ 1.622063] usb 1-1: New USB device found, idVendor=0627,
idProduct=0001, bcdDevice= 0.00
[ 1.622069] usb 1-1: New USB device strings: Mfr=1, Product=3,
SerialNumber=10
[ 1.622072] usb 1-1: Product: QEMU USB Tablet
[ 1.622074] usb 1-1: Manufacturer: QEMU
[ 1.622077] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
[ 1.630374] input: QEMU QEMU USB Tablet as
/devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input6
[ 1.630546] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID
v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[ 1.670213] RPC: Registered named UNIX socket transport module.
[ 1.670217] RPC: Registered udp transport module.
[ 1.670219] RPC: Registered tcp transport module.
[ 1.670220] RPC: Registered tcp-with-tls transport module.
[ 1.670222] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 1.912115] libata version 3.00 loaded.
[ 1.914119] ata_piix 0000:00:01.1: version 2.13
[ 1.915467] scsi host0: scsi_eh_0: sleeping
[ 1.915623] scsi host0: ata_piix
[ 1.915803] scsi host1: scsi_eh_1: sleeping
[ 1.915872] scsi host1: ata_piix
[ 1.915930] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xe020
irq 14 lpm-pol 0
[ 1.915934] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xe028
irq 15 lpm-pol 0
[ 1.915978] scsi host0: scsi_eh_0: waking up 1/0/0
[ 1.915987] scsi host1: scsi_eh_1: waking up 1/0/0
[ 1.916066] scsi host0: waking up host to restart
[ 1.916071] scsi host0: scsi_eh_0: sleeping
[ 1.916135] scsi host1: waking up host to restart
[ 1.916140] scsi host1: scsi_eh_1: sleeping
[ 1.936504] ACPI: \_SB_.LNKA: Enabled at IRQ 10
[ 2.003188] ACPI: \_SB_.LNKB: Enabled at IRQ 10
[ 2.066454] ACPI: \_SB_.LNKC: Enabled at IRQ 11
[ 2.132878] mlx5_core 0000:00:03.0: PTM is not supported by PCIe
[ 2.132920] mlx5_core 0000:00:03.0: firmware version: 22.31.1660
[ 2.200058] scsi host2: scsi_eh_2: sleeping
[ 2.200149] virtio_scsi virtio0: 1/0/0 default/read/poll queues
[ 2.200807] scsi host2: Virtio SCSI HBA
[ 2.203783] scsi host3: scsi_eh_3: sleeping
[ 2.203871] virtio_scsi virtio1: 1/0/0 default/read/poll queues
[ 2.204196] scsi 2:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.204520] scsi host3: Virtio SCSI HBA
[ 2.207209] scsi host4: scsi_eh_4: sleeping
[ 2.207345] virtio_scsi virtio2: 1/0/0 default/read/poll queues
[ 2.207439] scsi 3:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.208011] scsi host4: Virtio SCSI HBA
[ 2.210543] scsi host5: scsi_eh_5: sleeping
[ 2.210636] virtio_scsi virtio3: 1/0/0 default/read/poll queues
[ 2.210856] scsi 4:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.211564] scsi host5: Virtio SCSI HBA
[ 2.214638] scsi host6: scsi_eh_6: sleeping
[ 2.214752] virtio_scsi virtio4: 1/0/0 default/read/poll queues
[ 2.214846] scsi 5:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.215637] scsi host6: Virtio SCSI HBA
[ 2.215838] scsi 2:0:1:1: alua: supports implicit and explicit TPGS
[ 2.215846] scsi 2:0:1:1: alua: device
naa.600140516a734e90bb1003022747ab09 port group 0 rel port 1
[ 2.218762] scsi host7: scsi_eh_7: sleeping
[ 2.218900] virtio_scsi virtio5: 1/0/0 default/read/poll queues
[ 2.218931] scsi 6:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.219711] scsi 3:0:1:1: alua: supports implicit and explicit TPGS
[ 2.219718] scsi 3:0:1:1: alua: device
naa.6001405bcbd343a198f2444be1e421e3 port group 0 rel port 1
[ 2.219943] scsi host7: Virtio SCSI HBA
[ 2.223079] scsi host8: scsi_eh_8: sleeping
[ 2.223251] virtio_scsi virtio6: 1/0/0 default/read/poll queues
[ 2.223328] scsi 7:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.224139] scsi host8: Virtio SCSI HBA
[ 2.225772] scsi 4:0:1:1: alua: supports implicit and explicit TPGS
[ 2.225779] scsi 4:0:1:1: alua: device
naa.6001405e745a4a428e2051af8471bcfc port group 0 rel port 1
[ 2.227439] scsi 8:0:1:1: Direct-Access ORACLE BlockVolume 1.0
PQ: 0 ANSI: 5
[ 2.228198] scsi 5:0:1:1: alua: supports implicit and explicit TPGS
[ 2.228205] scsi 5:0:1:1: alua: device
naa.600140541ab847d580575aaa275fba74 port group 0 rel port 1
[ 2.232192] scsi 6:0:1:1: alua: supports implicit and explicit TPGS
[ 2.232199] scsi 6:0:1:1: alua: device
naa.6001405e527541efa8f364650591481c port group 0 rel port 1
[ 2.235143] scsi 7:0:1:1: alua: supports implicit and explicit TPGS
[ 2.235148] scsi 7:0:1:1: alua: device
naa.60014059e21a4073a4b86c0926e500df port group 0 rel port 1
[ 2.238873] scsi 8:0:1:1: alua: supports implicit and explicit TPGS
[ 2.238879] scsi 8:0:1:1: alua: device
naa.600140513a73428e9ccd548ba60a71c5 port group 0 rel port 1
[ 2.244256] scsi 2:0:1:1: Attached scsi generic sg0 type 0
[ 2.244307] scsi 3:0:1:1: Attached scsi generic sg1 type 0
[ 2.244352] scsi 4:0:1:1: Attached scsi generic sg2 type 0
[ 2.244391] scsi 5:0:1:1: Attached scsi generic sg3 type 0
[ 2.244505] scsi 6:0:1:1: Attached scsi generic sg4 type 0
[ 2.244561] scsi 7:0:1:1: Attached scsi generic sg5 type 0
[ 2.244605] scsi 8:0:1:1: Attached scsi generic sg6 type 0
[ 2.247768] sd 4:0:1:1: [sdb] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247775] sd 4:0:1:1: [sdb] 4096-byte physical blocks
[ 2.247812] sd 8:0:1:1: [sdf] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247814] sd 4:0:1:1: [sdb] Write Protect is off
[ 2.247817] sd 4:0:1:1: [sdb] Mode Sense: 43 00 00 08
[ 2.247818] sd 8:0:1:1: [sdf] 4096-byte physical blocks
[ 2.247822] sd 2:0:1:1: [sda] 97677312 512-byte logical blocks: (50.0
GB/46.6 GiB)
[ 2.247828] sd 2:0:1:1: [sda] 4096-byte physical blocks
[ 2.247884] sd 2:0:1:1: [sda] Write Protect is off
[ 2.247885] sd 8:0:1:1: [sdf] Write Protect is off
[ 2.247889] sd 8:0:1:1: [sdf] Mode Sense: 43 00 00 08
[ 2.247889] sd 2:0:1:1: [sda] Mode Sense: 43 00 00 08
[ 2.247915] sd 4:0:1:1: [sdb] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.247931] sd 5:0:1:1: [sdd] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247937] sd 5:0:1:1: [sdd] 4096-byte physical blocks
[ 2.247937] sd 6:0:1:1: [sde] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247941] sd 6:0:1:1: [sde] 4096-byte physical blocks
[ 2.247955] sd 2:0:1:1: [sda] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.247956] sd 3:0:1:1: [sdc] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247971] sd 3:0:1:1: [sdc] 4096-byte physical blocks
[ 2.247980] sd 8:0:1:1: [sdf] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.247995] sd 7:0:1:1: [sdg] 2147483648 512-byte logical blocks:
(1.10 TB/1.00 TiB)
[ 2.247998] sd 5:0:1:1: [sdd] Write Protect is off
[ 2.247999] sd 7:0:1:1: [sdg] 4096-byte physical blocks
[ 2.248003] sd 5:0:1:1: [sdd] Mode Sense: 43 00 00 08
[ 2.248028] sd 7:0:1:1: [sdg] Write Protect is off
[ 2.248032] sd 7:0:1:1: [sdg] Mode Sense: 43 00 00 08
[ 2.248066] sd 8:0:1:1: [sdf] Preferred minimum I/O size 4096 bytes
[ 2.248067] sd 5:0:1:1: [sdd] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.248070] sd 8:0:1:1: [sdf] Optimal transfer size 1048576 bytes
[ 2.248088] sd 7:0:1:1: [sdg] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.248127] sd 5:0:1:1: [sdd] Preferred minimum I/O size 4096 bytes
[ 2.248130] sd 5:0:1:1: [sdd] Optimal transfer size 1048576 bytes
[ 2.248146] sd 7:0:1:1: [sdg] Preferred minimum I/O size 4096 bytes
[ 2.248150] sd 7:0:1:1: [sdg] Optimal transfer size 1048576 bytes
[ 2.261489] sd 3:0:1:1: [sdc] Write Protect is off
[ 2.261494] sd 3:0:1:1: [sdc] Mode Sense: 43 00 00 08
[ 2.261505] sd 6:0:1:1: [sde] Write Protect is off
[ 2.261510] sd 6:0:1:1: [sde] Mode Sense: 43 00 00 08
[ 2.261593] sd 3:0:1:1: [sdc] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.261624] sd 6:0:1:1: [sde] Write cache: disabled, read cache:
enabled, doesn't support DPO or FUA
[ 2.261648] sd 3:0:1:1: [sdc] Preferred minimum I/O size 4096 bytes
[ 2.261651] sd 3:0:1:1: [sdc] Optimal transfer size 1048576 bytes
[ 2.261690] sd 6:0:1:1: [sde] Preferred minimum I/O size 4096 bytes
[ 2.261693] sd 6:0:1:1: [sde] Optimal transfer size 1048576 bytes
[ 2.263621] sd 5:0:1:1: [sdd] Attached SCSI disk
[ 2.265605] sd 7:0:1:1: [sdg] Attached SCSI disk
[ 2.307864] mlx5_core 0000:00:03.0: Rate limit: 127 rates are
supported, range: 0Mbps to 48828Mbps
[ 2.397844] sd 2:0:1:1: [sda] Preferred minimum I/O size 4096 bytes
[ 2.397848] sd 2:0:1:1: [sda] Optimal transfer size 1048576 bytes
[ 2.397876] sd 4:0:1:1: [sdb] Preferred minimum I/O size 4096 bytes
[ 2.397882] sd 4:0:1:1: [sdb] Optimal transfer size 1048576 bytes
[ 2.404886] sd 3:0:1:1: [sdc] Attached SCSI disk
[ 2.405607] sd 8:0:1:1: [sdf] Attached SCSI disk
[ 2.413331] sd 6:0:1:1: [sde] Attached SCSI disk
[ 2.432677] sd 4:0:1:1: [sdb] Attached SCSI disk
[ 2.436518] sda: sda1 sda2 sda3
[ 2.436726] sd 2:0:1:1: [sda] Attached SCSI disk
[ 2.495972] mlx5_core 0000:00:03.0: MLX5E: StrdRq(1) RqSz(8)
StrdSz(2048) RxCqeCmprss(0 basic)
[ 2.498736] mlx5_core 0000:00:03.0 ens3: renamed from eth0
[ 2.785798] mlx5_core 0000:00:03.0 ens3: Link up
[ 7.197671] iscsi: registered transport (tcp)
[ 12.708818] SGI XFS with ACLs, security attributes, realtime, scrub,
repair, quota, no debug enabled
[ 12.711995] XFS (dm-0): Mounting V5 Filesystem
8b8d3b19-9faa-4dee-b3ba-765c3515b283
[ 12.768728] XFS (dm-0): Starting recovery (logdev: internal)
[ 12.791358] XFS (dm-0): Ending recovery (logdev: internal)
[ 13.281956] printk: systemd: 30 output lines suppressed due to
ratelimiting
[ 13.320686] audit: type=1404 audit(1729591736.590:2): enforcing=1
old_enforcing=0 auid=4294967295 ses=4294967295 enabled=1 old-enabled=1
lsm=selinux res=1
[ 13.449726] SELinux: Permission watch in class filesystem not
defined in policy.
[ 13.449733] SELinux: Permission watch in class file not defined in
policy.
[ 13.449735] SELinux: Permission watch_mount in class file not
defined in policy.
[ 13.449737] SELinux: Permission watch_sb in class file not defined
in policy.
[ 13.449738] SELinux: Permission watch_with_perm in class file not
defined in policy.
[ 13.449740] SELinux: Permission watch_reads in class file not
defined in policy.
[ 13.449743] SELinux: Permission watch in class dir not defined in
policy.
[ 13.449745] SELinux: Permission watch_mount in class dir not defined
in policy.
[ 13.449747] SELinux: Permission watch_sb in class dir not defined in
policy.
[ 13.449749] SELinux: Permission watch_with_perm in class dir not
defined in policy.
[ 13.449750] SELinux: Permission watch_reads in class dir not defined
in policy.
[ 13.449755] SELinux: Permission watch in class lnk_file not defined
in policy.
[ 13.449756] SELinux: Permission watch_mount in class lnk_file not
defined in policy.
[ 13.449758] SELinux: Permission watch_sb in class lnk_file not
defined in policy.
[ 13.449760] SELinux: Permission watch_with_perm in class lnk_file
not defined in policy.
[ 13.449761] SELinux: Permission watch_reads in class lnk_file not
defined in policy.
[ 13.449764] SELinux: Permission watch in class chr_file not defined
in policy.
[ 13.449766] SELinux: Permission watch_mount in class chr_file not
defined in policy.
[ 13.449767] SELinux: Permission watch_sb in class chr_file not
defined in policy.
[ 13.449769] SELinux: Permission watch_with_perm in class chr_file
not defined in policy.
[ 13.449771] SELinux: Permission watch_reads in class chr_file not
defined in policy.
[ 13.449773] SELinux: Permission watch in class blk_file not defined
in policy.
[ 13.449775] SELinux: Permission watch_mount in class blk_file not
defined in policy.
[ 13.449776] SELinux: Permission watch_sb in class blk_file not
defined in policy.
[ 13.449778] SELinux: Permission watch_with_perm in class blk_file
not defined in policy.
[ 13.449780] SELinux: Permission watch_reads in class blk_file not
defined in policy.
[ 13.449782] SELinux: Permission watch in class sock_file not defined
in policy.
[ 13.449784] SELinux: Permission watch_mount in class sock_file not
defined in policy.
[ 13.449786] SELinux: Permission watch_sb in class sock_file not
defined in policy.
[ 13.449787] SELinux: Permission watch_with_perm in class sock_file
not defined in policy.
[ 13.449789] SELinux: Permission watch_reads in class sock_file not
defined in policy.
[ 13.449792] SELinux: Permission watch in class fifo_file not defined
in policy.
[ 13.449793] SELinux: Permission watch_mount in class fifo_file not
defined in policy.
[ 13.449795] SELinux: Permission watch_sb in class fifo_file not
defined in policy.
[ 13.449796] SELinux: Permission watch_with_perm in class fifo_file
not defined in policy.
[ 13.449798] SELinux: Permission watch_reads in class fifo_file not
defined in policy.
[ 13.449842] SELinux: Permission perfmon in class capability2 not
defined in policy.
[ 13.449843] SELinux: Permission bpf in class capability2 not defined
in policy.
[ 13.449850] SELinux: Permission perfmon in class cap2_userns not
defined in policy.
[ 13.449851] SELinux: Permission bpf in class cap2_userns not defined
in policy.
[ 13.449884] SELinux: Class mctp_socket not defined in policy.
[ 13.449886] SELinux: Class anon_inode not defined in policy.
[ 13.449888] SELinux: Class io_uring not defined in policy.
[ 13.449890] SELinux: Class user_namespace not defined in policy.
[ 13.449891] SELinux: the above unknown classes and permissions will
be allowed
[ 13.452920] SELinux: policy capability network_peer_controls=1
[ 13.452923] SELinux: policy capability open_perms=1
[ 13.452924] SELinux: policy capability extended_socket_class=1
[ 13.452926] SELinux: policy capability always_check_network=0
[ 13.452927] SELinux: policy capability cgroup_seclabel=1
[ 13.452929] SELinux: policy capability nnp_nosuid_transition=1
[ 13.452930] SELinux: policy capability genfs_seclabel_symlinks=0
[ 13.452932] SELinux: policy capability ioctl_skip_cloexec=0
[ 13.452933] SELinux: policy capability userspace_initial_context=0
[ 13.495918] audit: type=1403 audit(1729591736.765:3): auid=4294967295
ses=4294967295 lsm=selinux res=1
[ 13.497553] systemd[1]: Successfully loaded SELinux policy in 177.640ms.
[ 13.537137] systemd[1]: Relabelled /dev, /run and /sys/fs/cgroup in
25.294ms.
[ 13.539979] systemd[1]: systemd 239 (239-78.0.3.el8) 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=legacy)
[ 13.540014] systemd[1]: Detected virtualization kvm.
[ 13.540019] systemd[1]: Detected architecture x86-64.
[ 13.543914] systemd[1]: Set hostname to
<jgarry-atomic-write-exp-e4-8-instance-20231214-1221>.
[ 13.920513] systemd[1]: Configuration file
/usr/lib/systemd/system/wlp-agent-osqueryd.service is marked executable.
Please remove executable permission bits. Proceeding anyway.
[ 13.920519] systemd[1]: Configuration file
/usr/lib/systemd/system/wlp-agent-osqueryd.service is marked
world-inaccessible. This has no effect as configuration data is
accessible via APIs without restrictions. Proceeding anyway.
[ 14.050676] systemd[1]: initrd-switch-root.service: Succeeded.
[ 14.051194] systemd[1]: Stopped Switch Root.
[ 14.052258] systemd[1]: systemd-journald.service: Service has no
hold-off time (RestartSec=0), scheduling restart.
[ 14.052311] systemd[1]: systemd-journald.service: Scheduled restart
job, restart counter is at 1.
[ 14.088998] xfs filesystem being remounted at / supports timestamps
until 2038-01-19 (0x7fffffff)
[ 14.136047] Adding 8132604k swap on /.swapfile. Priority:-2
extents:2 across:35280552k
[ 14.547999] piix4_smbus 0000:00:01.3: SMBus Host Controller at
0xb100, revision 0
[ 14.548040] i2c i2c-0: Memory type 0x07 not supported yet, not
instantiating SPD
[ 14.577631] input: PC Speaker as /devices/platform/pcspkr/input/input7
[ 14.582701] ACPI: bus type drm_connector registered
[ 14.702381] Console: switching to colour dummy device 80x25
[ 14.702434] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
[ 14.702546] [drm] Found bochs VGA, ID 0xb0c5.
[ 14.702550] [drm] Framebuffer size 16384 kB @ 0xc0000000, mmio @
0xc1410000.
[ 14.704103] [drm] Found EDID data blob.
[ 14.704367] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
[ 14.705273] fbcon: bochs-drmdrmfb (fb0) is primary device
[ 14.717166] kvm_amd: Nested Virtualization enabled
[ 14.717169] kvm_amd: Nested Paging enabled
[ 14.754315] Console: switching to colour frame buffer device 128x48
[ 14.756440] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame
buffer device
[ 14.798565] md127: detected capacity change from 0 to 8588877824
[ 15.020099] XFS (dm-1): Mounting V5 Filesystem
21d53c77-7876-4a1c-b4e1-a8cd74d1938c
[ 15.020499] XFS (sdf): Mounting V5 Filesystem
d9dc5ab6-ac4f-4994-8a72-33d087459466
[ 15.021945] XFS (sda2): Mounting V5 Filesystem
f7cf63bd-4975-44bb-ba99-b81e037be7e1
[ 15.024276] XFS (sdc): EXPERIMENTAL: V5 Filesystem with Large Block
Size (16384 bytes) enabled.
[ 15.024890] XFS (sdc): Mounting V5 Filesystem
714d73f3-408e-4b1a-b21d-6505fbf27bc6
[ 15.079368] XFS (sda2): Ending clean mount
[ 15.086230] XFS (sdc): Ending clean mount
[ 15.088004] xfs filesystem being mounted at /boot supports timestamps
until 2038-01-19 (0x7fffffff)
[ 15.094004] xfs filesystem being mounted at /home/opc/mnt_16k
supports timestamps until 2038-01-19 (0x7fffffff)
[ 15.137815] XFS (sdf): Starting recovery (logdev: internal)
[ 15.192601] XFS (sdf): Ending recovery (logdev: internal)
[ 15.194230] XFS (dm-1): Starting recovery (logdev: internal)
[ 15.199394] xfs filesystem being mounted at /home/opc/mnt_4k supports
timestamps until 2038-01-19 (0x7fffffff)
[ 15.216710] XFS (dm-1): Ending recovery (logdev: internal)
[ 15.223689] xfs filesystem being mounted at /var/oled supports
timestamps until 2038-01-19 (0x7fffffff)
[ 15.536223] fuse: init (API version 7.41)
[root@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 opc]#
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-23 10:19 v6.12-rc workqueue lockups John Garry
@ 2024-10-23 20:13 ` Jan Kara
2024-10-24 3:18 ` Dave Chinner
2024-10-23 20:39 ` Jan Kara
1 sibling, 1 reply; 8+ messages in thread
From: Jan Kara @ 2024-10-23 20:13 UTC (permalink / raw)
To: John Garry; +Cc: linux-kernel, viro, brauner, jack, linux-fsdevel
Hi!
On Wed 23-10-24 11:19:24, John Garry wrote:
> I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
> master branch:
>
> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> Oct 22 09:07:15 ...
> kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
>
> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> Oct 22 09:08:07 ...
> kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck
> for 44s!
>
> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> Oct 22 09:08:07 ...
> kernel:BUG: workqueue lockup - pool cpus=4 node=0 flags=0x0 nice=0 stuck
> for 35s!
>
> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> Oct 22 09:08:07 ...
> kernel:BUG: workqueue lockup - pool cpus=10 node=0 flags=0x0 nice=0 stuck
> for 33s!
>
> This is while doing some server MySQL performance testing. v6.11 has no such
> issue.
>
> I added some debug, and we seem to be spending a lot of time in FS
> writeback, specifically wb_workfn() -> wb_do_writeback() - ring any bells?
Thanks for report. This doesn't remind me of anything but checking the
writeback changes we have merged 532980cb1bf ("inode: port __I_SYNC to var
event") which could have odd consequences if we made mistake somewhere...
It probably won't be easy to revert but you could try whether the problem
reproduces before / after this commit.
Honza
--
Jan Kara <jack@suse.com>
SUSE Labs, CR
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-23 10:19 v6.12-rc workqueue lockups John Garry
2024-10-23 20:13 ` Jan Kara
@ 2024-10-23 20:39 ` Jan Kara
2024-10-24 9:35 ` John Garry
1 sibling, 1 reply; 8+ messages in thread
From: Jan Kara @ 2024-10-23 20:39 UTC (permalink / raw)
To: John Garry; +Cc: linux-kernel, viro, brauner, jack, linux-fsdevel
On Wed 23-10-24 11:19:24, John Garry wrote:
> Hi All,
>
> I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
> master branch:
>
> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> Oct 22 09:07:15 ...
> kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
BTW, can you please share logs which would contain full stacktraces that
this softlockup reports produce? The attached dmesg is just from fresh
boot... Thanks!
Honza
--
Jan Kara <jack@suse.com>
SUSE Labs, CR
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-23 20:13 ` Jan Kara
@ 2024-10-24 3:18 ` Dave Chinner
0 siblings, 0 replies; 8+ messages in thread
From: Dave Chinner @ 2024-10-24 3:18 UTC (permalink / raw)
To: Jan Kara; +Cc: John Garry, linux-kernel, viro, brauner, linux-fsdevel
On Wed, Oct 23, 2024 at 10:13:14PM +0200, Jan Kara wrote:
>
> Hi!
>
> On Wed 23-10-24 11:19:24, John Garry wrote:
> > I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
> > master branch:
> >
> > Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> > Oct 22 09:07:15 ...
> > kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
> >
> > Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> > Oct 22 09:08:07 ...
> > kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck
> > for 44s!
> >
> > Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> > Oct 22 09:08:07 ...
> > kernel:BUG: workqueue lockup - pool cpus=4 node=0 flags=0x0 nice=0 stuck
> > for 35s!
> >
> > Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> > Oct 22 09:08:07 ...
> > kernel:BUG: workqueue lockup - pool cpus=10 node=0 flags=0x0 nice=0 stuck
> > for 33s!
> >
> > This is while doing some server MySQL performance testing. v6.11 has no such
> > issue.
> >
> > I added some debug, and we seem to be spending a lot of time in FS
> > writeback, specifically wb_workfn() -> wb_do_writeback() - ring any bells?
>
> Thanks for report. This doesn't remind me of anything but checking the
> writeback changes we have merged 532980cb1bf ("inode: port __I_SYNC to var
> event") which could have odd consequences if we made mistake somewhere...
> It probably won't be easy to revert but you could try whether the problem
> reproduces before / after this commit.
I haven't seen the above hangs, but I just got this scheduler
warning a few minutes ago waiting for writeback:
[12886.406341] WARNING: CPU: 19 PID: 504037 at kernel/sched/fair.c:5629 pick_task_fair+0xb6/0x1b0
[12886.412600] Modules linked in:
[12886.414325] CPU: 19 UID: 0 PID: 504037 Comm: fsstress Not tainted 6.12.0-rc4-dgc+ #268
[12886.418822] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-debian-1.16.3-2 04/01/2014
[12886.424280] RIP: 0010:pick_task_fair+0xb6/0x1b0
[12886.426885] Code: 40 f3 d3 03 01 74 2a 41 80 7f 50 00 74 96 f6 05 31 f3 d3 03 01 75 8d c6 05 28 f3 d3 03 01 48 c7 c7 f7 22 c4 82 e8 ea d7 fa ff <0f> 0b e9 73 ff ff ff c6 05 0d f3 d3 03 01 48 c7 c7 e5 22 c4 82 e8
[12886.437460] RSP: 0018:ffffc9001e703c88 EFLAGS: 00010046
[12886.440448] RAX: 02f256539620ed00 RBX: 0000000000000000 RCX: 0000000000000027
[12886.444542] RDX: 0000000000000000 RSI: 00000000ffdfffff RDI: ffff88901fadc9c8
[12886.448601] RBP: ffffc9001e703cb0 R08: 00000000001fffff R09: ffff88a018a00000
[12886.452655] R10: 00000000005ffffd R11: 0000000000000004 R12: ffff888861406400
[12886.456585] R13: ffff88901faf0140 R14: ffff88901faf00c0 R15: ffff889079412900
[12886.460679] FS: 00007f65469d8740(0000) GS:ffff88901fac0000(0000) knlGS:0000000000000000
[12886.465309] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[12886.468469] CR2: 00007f9de8006248 CR3: 00000009b7c16000 CR4: 0000000000350ef0
[12886.472382] Call Trace:
[12886.473751] <TASK>
[12886.474947] ? show_regs+0x5e/0x70
[12886.476829] ? __warn+0xd0/0x1d0
[12886.478634] ? pick_task_fair+0xb6/0x1b0
[12886.480794] ? report_bug+0x145/0x1f0
[12886.482875] ? handle_bug+0x67/0x90
[12886.484804] ? exc_invalid_op+0x1b/0x50
[12886.486932] ? asm_exc_invalid_op+0x1b/0x20
[12886.489230] ? pick_task_fair+0xb6/0x1b0
[12886.491389] ? pick_task_fair+0xb6/0x1b0
[12886.493538] pick_next_task_fair+0x27/0x330
[12886.495836] __schedule+0x2ad/0xb10
[12886.497756] schedule+0x6d/0xf0
[12886.499511] wb_wait_for_completion+0x56/0x90
[12886.501972] ? __pfx_autoremove_wake_function+0x10/0x10
[12886.504832] ? __pfx_sync_inodes_one_sb+0x10/0x10
[12886.507432] sync_inodes_sb+0xb0/0x2b0
[12886.509500] ? __pfx_sync_inodes_one_sb+0x10/0x10
[12886.512094] sync_inodes_one_sb+0x14/0x20
[12886.514314] iterate_supers+0x7a/0xd0
[12886.516338] ksys_sync+0x40/0xa0
[12886.518132] __ia32_sys_sync+0xe/0x20
[12886.520141] x64_sys_call+0x2a59/0x2ee0
[12886.522258] do_syscall_64+0x68/0x130
[12886.524275] ? exc_nmi+0xbd/0x110
[12886.526116] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[12886.528883] RIP: 0033:0x7f6546ae97c7
[12886.530862] Code: 73 01 c3 48 8b 0d 59 86 0d 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 a2 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 29 86 0d 00 f7 d8 64 89 01 48
[12886.540989] RSP: 002b:00007ffdf43f4178 EFLAGS: 00000206 ORIG_RAX: 00000000000000a2
[12886.545125] RAX: ffffffffffffffda RBX: 0000000000000247 RCX: 00007f6546ae97c7
[12886.549029] RDX: 00000000ffffffff RSI: 000000000a8ca705 RDI: 0000000000000247
[12886.552926] RBP: 00000000000001f4 R08: 000000000000004c R09: 0000000000000006
[12886.556823] R10: 0000000000000007 R11: 0000000000000206 R12: 000055f5884d45a0
[12886.560725] R13: 028f5c28f5c28f5c R14: 8f5c28f5c28f5c29 R15: 000055f5884c16c0
[12886.564659] </TASK
Which is from a wait_event() call and ends up warning here:
static struct sched_entity *
pick_next_entity(struct rq *rq, struct cfs_rq *cfs_rq)
{
/*
* Enabling NEXT_BUDDY will affect latency but not fairness.
*/
if (sched_feat(NEXT_BUDDY) &&
cfs_rq->next && entity_eligible(cfs_rq, cfs_rq->next)) {
/* ->next will never be delayed */
SCHED_WARN_ON(cfs_rq->next->sched_delayed);
return cfs_rq->next;
}
struct sched_entity *se = pick_eevdf(cfs_rq);
if (se->sched_delayed) {
dequeue_entities(rq, se, DEQUEUE_SLEEP | DEQUEUE_DELAYED);
SCHED_WARN_ON(se->sched_delayed);
>>>>>>>>> SCHED_WARN_ON(se->on_rq);
return NULL;
}
return se;
}
Possibly a scheduler bug?
-Dave.
--
Dave Chinner
david@fromorbit.com
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-23 20:39 ` Jan Kara
@ 2024-10-24 9:35 ` John Garry
2024-10-24 21:13 ` Dave Chinner
0 siblings, 1 reply; 8+ messages in thread
From: John Garry @ 2024-10-24 9:35 UTC (permalink / raw)
To: Jan Kara; +Cc: linux-kernel, viro, brauner, linux-fsdevel
On 23/10/2024 21:39, Jan Kara wrote:
> On Wed 23-10-24 11:19:24, John Garry wrote:
>> Hi All,
>>
>> I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
>> master branch:
>>
>> Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
>> Oct 22 09:07:15 ...
>> kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
>
> BTW, can you please share logs which would contain full stacktraces that
> this softlockup reports produce? The attached dmesg is just from fresh
> boot... Thanks!
>
thanks for getting back to me.
So I think that enabling /proc/sys/kernel/softlockup_all_cpu_backtrace
is required there. Unfortunately my VM often just locks up without any
sign of life.
But I'll continue to try. And I'll also try reverting that commit you
mentioned.
Cheers,
John
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-24 9:35 ` John Garry
@ 2024-10-24 21:13 ` Dave Chinner
2024-10-24 22:23 ` John Garry
0 siblings, 1 reply; 8+ messages in thread
From: Dave Chinner @ 2024-10-24 21:13 UTC (permalink / raw)
To: John Garry; +Cc: Jan Kara, linux-kernel, viro, brauner, linux-fsdevel
On Thu, Oct 24, 2024 at 10:35:29AM +0100, John Garry wrote:
> On 23/10/2024 21:39, Jan Kara wrote:
> > On Wed 23-10-24 11:19:24, John Garry wrote:
> > > Hi All,
> > >
> > > I have been seeing lockups reliably occur on v6.12-rc1, 3, 4 and linus'
> > > master branch:
> > >
> > > Message from syslogd@jgarry-atomic-write-exp-e4-8-instance-20231214-1221 at
> > > Oct 22 09:07:15 ...
> > > kernel:watchdog: BUG: soft lockup - CPU#12 stuck for 26s! [khugepaged:154]
> >
> > BTW, can you please share logs which would contain full stacktraces that
> > this softlockup reports produce? The attached dmesg is just from fresh
> > boot... Thanks!
> >
>
> thanks for getting back to me.
>
> So I think that enabling /proc/sys/kernel/softlockup_all_cpu_backtrace is
> required there. Unfortunately my VM often just locks up without any sign of
> life.
Attach a "serial" console to the vm - add "console=ttyS0,115600" to
the kernel command line and add "-serial pty" to the qemu command
line. You can then attach something like minicom to the /dev/pts/X
device that qemu creates for the console output and capture
everything from initial boot right through to the softlockup traces
that are emitted...
-Dave.
--
Dave Chinner
david@fromorbit.com
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-24 21:13 ` Dave Chinner
@ 2024-10-24 22:23 ` John Garry
2024-10-28 5:35 ` Dave Chinner
0 siblings, 1 reply; 8+ messages in thread
From: John Garry @ 2024-10-24 22:23 UTC (permalink / raw)
To: Dave Chinner; +Cc: Jan Kara, linux-kernel, viro, brauner, linux-fsdevel
On 24/10/2024 22:13, Dave Chinner wrote:
>>> BTW, can you please share logs which would contain full stacktraces that
>>> this softlockup reports produce? The attached dmesg is just from fresh
>>> boot... Thanks!
>>>
>> thanks for getting back to me.
>>
>> So I think that enabling /proc/sys/kernel/softlockup_all_cpu_backtrace is
>> required there. Unfortunately my VM often just locks up without any sign of
>> life.
> Attach a "serial" console to the vm - add "console=ttyS0,115600" to
> the kernel command line and add "-serial pty" to the qemu command
> line. You can then attach something like minicom to the /dev/pts/X
> device that qemu creates for the console output and capture
> everything from initial boot right through to the softlockup traces
> that are emitted...
I am using an OCI instance, so I can't change the qemu command line (as
far as I know).
For this issue, the Cloud Shell locks up also. There are other console
connection methods, which I can try.
BTW, earlier today I got this once when trying to recreate this issue:
[ 1549.241972] ------------[ cut here ]------------
[ 1609.240236] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 1609.240243] rcu: 5-...!: (0 ticks this GP)
idle=a8f4/1/0x4000000000000000 softirq=71287/71287 fqs=1
[ 1609.240249] rcu: (detected by 2, t=60004 jiffies, g=168077,
q=10823 ncpus=16)
[ 1609.240252] Sending NMI from CPU 2 to CPUs 5:
[ 1609.240277] NMI backtrace for cpu 5
[ 1609.240281] CPU: 5 UID: 1002 PID: 8250 Comm: mysqld Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1609.240286] Tainted: [W]=WARN
[ 1609.240288] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1609.240289] RIP: 0010:native_halt+0xe/0x20
[ 1609.240296] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1609.240298] RSP: 0018:ffffc0c8c71dbd20 EFLAGS: 00000046
[ 1609.240301] RAX: 0000000000000003 RBX: ffff9ff73fab6580 RCX:
0000000000000008
[ 1609.240303] RDX: ffff9ff7bffaf740 RSI: 0000000000000003 RDI:
ffff9ff73fab6580
[ 1609.240304] RBP: ffff9ff73f8b7440 R08: 0000000000000008 R09:
0000000000000074
[ 1609.240306] R10: 0000000000000002 R11: 0000000000000000 R12:
0000000000000000
[ 1609.240307] R13: 0000000000000001 R14: 0000000000000100 R15:
0000000000180000
[ 1609.240311] FS: 00007f9e12600700(0000) GS:ffff9ff73f880000(0000)
knlGS:0000000000000000
[ 1609.240313] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1609.240315] CR2: 00007f9d63e00004 CR3: 0000001a0bc04005 CR4:
0000000000770ef0
[ 1609.240319] PKRU: 55555554
[ 1609.240320] Call Trace:
[ 1609.240322] <NMI>
[ 1609.240325] ? nmi_cpu_backtrace+0x98/0x110
[ 1609.240330] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1609.240334] ? nmi_handle+0x5c/0x150
[ 1609.240339] ? default_do_nmi+0x4e/0x120
[ 1609.240343] ? exc_nmi+0x137/0x1d0
[ 1609.240347] ? end_repeat_nmi+0xf/0x53
[ 1609.240354] ? native_halt+0xe/0x20
[ 1609.240357] ? native_halt+0xe/0x20
[ 1609.240360] ? native_halt+0xe/0x20
[ 1609.240363] </NMI>
[ 1609.240364] <TASK>
[ 1609.240366] kvm_wait+0x47/0x60
[ 1609.240368] __pv_queued_spin_lock_slowpath+0x255/0x370
[ 1609.240373] _raw_spin_lock+0x29/0x30
[ 1609.240376] raw_spin_rq_lock_nested+0x1c/0x80
[ 1609.240381] __task_rq_lock+0x3f/0xe0
[ 1609.240384] try_to_wake_up+0x3cf/0x640
[ 1609.240387] ? plist_del+0x63/0xc0
[ 1609.240391] wake_up_q+0x4d/0x90
[ 1609.240394] futex_wake+0x154/0x180
[ 1609.240400] do_futex+0xf8/0x1d0
[ 1609.240404] __x64_sys_futex+0x68/0x1c0
[ 1609.240407] ? restore_fpregs_from_fpstate+0x3c/0xa0
[ 1609.240411] do_syscall_64+0x62/0x170
[ 1609.240416] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1609.240419] RIP: 0033:0x7fa6a961191a
[ 1609.240422] Code: 00 00 b8 ca 00 00 00 0f 05 5a 5e c3 0f 1f 40 00 56
52 c7 07 00 00 00 00 81 f6 81 00 00 00 ba 01 00 00 00 b8 ca 00 00 00 0f
05 <5a> 5e c3 0f 1f 00 41 54 41 55 49 89 fc 49 89 f5 48 83 ec 18 48 89
[ 1609.240424] RSP: 002b:00007f9e125feee0 EFLAGS: 00000206 ORIG_RAX:
00000000000000ca
[ 1609.240426] RAX: ffffffffffffffda RBX: 00007fa6a02ccb50 RCX:
00007fa6a961191a
[ 1609.240428] RDX: 0000000000000001 RSI: 0000000000000081 RDI:
00007fa6a02ccb50
[ 1609.240429] RBP: 00007f9e125ff1a0 R08: 0000000000000000 R09:
00007fa6a9d0c000
[ 1609.240431] R10: 00007fa6a9d0b080 R11: 0000000000000206 R12:
00007fa6a9852830
[ 1609.240432] R13: 0f83e0f83e0f83e1 R14: 0000000000000008 R15:
0000000000000100
[ 1609.240437] </TASK>
[ 1609.241262] rcu: rcu_preempt kthread timer wakeup didn't happen for
59997 jiffies! g168077 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
[ 1609.241265] rcu: Possible timer handling issue on cpu=5
timer-softirq=15698
[ 1609.241267] rcu: rcu_preempt kthread starved for 60000 jiffies!
g168077 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=5
[ 1609.241269] rcu: Unless rcu_preempt kthread gets sufficient CPU
time, OOM is now expected behavior.
[ 1609.241270] rcu: RCU grace-period kthread stack dump:
[ 1609.241271] task:rcu_preempt state:I stack:0 pid:17
tgid:17 ppid:2 flags:0x00004000
[ 1609.241275] Call Trace:
[ 1609.241277] <TASK>
[ 1609.241279] __schedule+0x334/0xba0
[ 1609.241286] schedule+0x36/0xc0
[ 1609.241290] schedule_timeout+0x1e0/0x2c0
[ 1609.241293] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1609.241296] ? __pfx_process_timeout+0x10/0x10
[ 1609.241300] rcu_gp_fqs_loop+0x336/0x500
[ 1609.241306] ? __pfx_rcu_gp_kthread+0x10/0x10
[ 1609.241308] rcu_gp_kthread+0xdf/0x190
[ 1609.241311] kthread+0xd2/0x100
[ 1609.241315] ? __pfx_kthread+0x10/0x10
[ 1609.241318] ret_from_fork+0x34/0x40
[ 1609.241321] ? __pfx_kthread+0x10/0x10
[ 1609.241324] ret_from_fork_asm+0x1a/0x30
[ 1609.241331] </TASK>
[ 1669.246372] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 1669.246379] rcu: 0-...0: (1 GPs behind) idle=dff4/0/0x1
softirq=83650/83651 fqs=6001
[ 1669.246385] rcu: 1-...0: (1 GPs behind) idle=eb2c/0/0x1
softirq=74528/74529 fqs=6001
[ 1669.246388] rcu: 4-...0: (1 GPs behind) idle=4b84/0/0x1
softirq=78302/78303 fqs=6001
[ 1669.246391] rcu: 5-...0: (1 GPs behind)
idle=a8f4/1/0x4000000000000000 softirq=71287/71287 fqs=6001
[ 1669.246394] rcu: 7-...0: (1 GPs behind)
idle=1a3c/1/0x4000000000000000 softirq=71163/71164 fqs=6001
[ 1669.246396] rcu: 8-...0: (1 GPs behind)
idle=a654/1/0x4000000000000000 softirq=78387/78388 fqs=6001
[ 1669.246398] rcu: 9-...0: (1 GPs behind)
idle=8b0c/1/0x4000000000000000 softirq=91122/91123 fqs=6001
[ 1669.246401] rcu: (detected by 13, t=60005 jiffies, g=168081,
q=14788 ncpus=16)
[ 1669.246404] Sending NMI from CPU 13 to CPUs 0:
[ 1669.246431] NMI backtrace for cpu 0
[ 1669.246439] CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1669.246445] Tainted: [W]=WARN
[ 1669.246446] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.246448] RIP: 0010:native_halt+0xe/0x20
[ 1669.246455] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.246458] RSP: 0018:ffffc0c8c0003d58 EFLAGS: 00000046
[ 1669.246461] RAX: 0000000000000001 RBX: ffff9ff73fab6580 RCX:
0000000000000001
[ 1669.246463] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
ffff9ff73f637454
[ 1669.246464] RBP: ffff9ff73f637440 R08: 0000000000000001 R09:
0000000000000200
[ 1669.246466] R10: 0000000000000000 R11: 0000000000000000 R12:
ffff9ff73f6b7440
[ 1669.246467] R13: ffff9ff73f637454 R14: 0000000000000001 R15:
0000000000040000
[ 1669.246471] FS: 0000000000000000(0000) GS:ffff9ff73f600000(0000)
knlGS:0000000000000000
[ 1669.246474] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.246476] CR2: 00007f8f73400004 CR3: 0000001a0bc04005 CR4:
0000000000770ef0
[ 1669.246479] PKRU: 55555554
[ 1669.246481] Call Trace:
[ 1669.246484] <NMI>
[ 1669.246487] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.246492] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.246496] ? nmi_handle+0x5c/0x150
[ 1669.246501] ? default_do_nmi+0x4e/0x120
[ 1669.246505] ? exc_nmi+0x137/0x1d0
[ 1669.246509] ? end_repeat_nmi+0xf/0x53
[ 1669.246516] ? native_halt+0xe/0x20
[ 1669.246520] ? native_halt+0xe/0x20
[ 1669.246523] ? native_halt+0xe/0x20
[ 1669.246526] </NMI>
[ 1669.246527] <IRQ>
[ 1669.246528] kvm_wait+0x47/0x60
[ 1669.246531] __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.246536] _raw_spin_lock+0x29/0x30
[ 1669.246540] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.246544] _raw_spin_rq_lock_irqsave+0x17/0x20
[ 1669.246548] sched_balance_rq+0xa4e/0xd70
[ 1669.246557] sched_balance_domains+0x277/0x390
[ 1669.246561] _nohz_idle_balance.isra.146+0x2bb/0x3a0
[ 1669.246566] handle_softirqs+0xca/0x2c0
[ 1669.246572] irq_exit_rcu+0xb0/0xd0
[ 1669.246575] sysvec_call_function_single+0x71/0x90
[ 1669.246579] </IRQ>
[ 1669.246580] <TASK>
[ 1669.246581] asm_sysvec_call_function_single+0x1a/0x20
[ 1669.246585] RIP: 0010:pv_native_safe_halt+0xf/0x20
[ 1669.246587] Code: 22 d7 e9 6f 48 2d 00 0f 1f 40 00 90 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 43 76 3f 00 fb
f4 <e9> 47 48 2d 00 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90
[ 1669.246589] RSP: 0018:ffffffff95803e68 EFLAGS: 00000212
[ 1669.246591] RAX: 0000000000000000 RBX: ffffffff95810940 RCX:
0000000000000000
[ 1669.246593] RDX: 4000000000000000 RSI: 0000000000000087 RDI:
000000000129dfec
[ 1669.246594] RBP: 0000000000000000 R08: 0000000000000001 R09:
ffff9ff7bfffffc0
[ 1669.246596] R10: 000000000003c540 R11: 0000000000000000 R12:
ffffffff95db8be0
[ 1669.246597] R13: ffffffff95810940 R14: 0000000000000000 R15:
0000000000000000
[ 1669.246603] default_idle+0x9/0x20
[ 1669.246606] default_idle_call+0x34/0xf0
[ 1669.246608] do_idle+0x1f8/0x270
[ 1669.246613] cpu_startup_entry+0x29/0x30
[ 1669.246616] rest_init+0xcc/0xd0
[ 1669.246619] start_kernel+0x459/0x6a0
[ 1669.246626] x86_64_start_reservations+0x21/0x40
[ 1669.246631] x86_64_start_kernel+0x91/0xa0
[ 1669.246635] common_startup_64+0x13e/0x141
[ 1669.246641] </TASK>
[ 1669.247412] Sending NMI from CPU 13 to CPUs 1:
[ 1669.247431] NMI backtrace for cpu 1
[ 1669.247435] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1669.247438] Tainted: [W]=WARN
[ 1669.247439] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.247440] RIP: 0010:native_halt+0xe/0x20
[ 1669.247442] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.247444] RSP: 0018:ffffc0c8c02dcd58 EFLAGS: 00000046
[ 1669.247446] RAX: 0000000000000001 RBX: ffff9ff73fab6580 RCX:
0000000000000001
[ 1669.247447] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
ffff9ff73f6b7454
[ 1669.247448] RBP: ffff9ff73f6b7440 R08: 0000000000000001 R09:
0000000000000200
[ 1669.247449] R10: 0000000000000000 R11: 0000000000000000 R12:
ffff9ff73f8b7440
[ 1669.247450] R13: ffff9ff73f6b7454 R14: 0000000000000001 R15:
0000000000080000
[ 1669.247452] FS: 0000000000000000(0000) GS:ffff9ff73f680000(0000)
knlGS:0000000000000000
[ 1669.247454] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.247455] CR2: 00007f9d22800004 CR3: 00000001095f2001 CR4:
0000000000770ef0
[ 1669.247457] PKRU: 55555554
[ 1669.247458] Call Trace:
[ 1669.247459] <NMI>
[ 1669.247460] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.247463] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.247465] ? nmi_handle+0x5c/0x150
[ 1669.247469] ? default_do_nmi+0x4e/0x120
[ 1669.247471] ? exc_nmi+0x137/0x1d0
[ 1669.247474] ? end_repeat_nmi+0xf/0x53
[ 1669.247479] ? native_halt+0xe/0x20
[ 1669.247482] ? native_halt+0xe/0x20
[ 1669.247485] ? native_halt+0xe/0x20
[ 1669.247487] </NMI>
[ 1669.247488] <IRQ>
[ 1669.247489] kvm_wait+0x47/0x60
[ 1669.247490] __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.247493] _raw_spin_lock+0x29/0x30
[ 1669.247496] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.247498] _raw_spin_rq_lock_irqsave+0x17/0x20
[ 1669.247500] sched_balance_rq+0xa4e/0xd70
[ 1669.247507] sched_balance_domains+0x277/0x390
[ 1669.247511] _nohz_idle_balance.isra.146+0x2bb/0x3a0
[ 1669.247514] handle_softirqs+0xca/0x2c0
[ 1669.247518] irq_exit_rcu+0xb0/0xd0
[ 1669.247520] sysvec_call_function_single+0x71/0x90
[ 1669.247523] </IRQ>
[ 1669.247524] <TASK>
[ 1669.247525] asm_sysvec_call_function_single+0x1a/0x20
[ 1669.247528] RIP: 0010:pv_native_safe_halt+0xf/0x20
[ 1669.247529] Code: 22 d7 e9 6f 48 2d 00 0f 1f 40 00 90 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 43 76 3f 00 fb
f4 <e9> 47 48 2d 00 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90
[ 1669.247530] RSP: 0018:ffffc0c8c00c3ec8 EFLAGS: 00000202
[ 1669.247532] RAX: 0000000000000001 RBX: ffff9fd8809c8000 RCX:
0000000000000001
[ 1669.247533] RDX: 4000000000000000 RSI: 0000000000000087 RDI:
0000000000d4eb24
[ 1669.247534] RBP: 0000000000000001 R08: 0000000000000001 R09:
0101010101010101
[ 1669.247535] R10: 00000000ffffffff R11: 0000000000000001 R12:
ffffffff95db8be0
[ 1669.247536] R13: ffff9fd8809c8000 R14: 0000000000000000 R15:
0000000000000000
[ 1669.247541] default_idle+0x9/0x20
[ 1669.247543] default_idle_call+0x34/0xf0
[ 1669.247545] do_idle+0x1f8/0x270
[ 1669.247548] cpu_startup_entry+0x29/0x30
[ 1669.247550] start_secondary+0x11e/0x140
[ 1669.247554] common_startup_64+0x13e/0x141
[ 1669.247559] </TASK>
[ 1669.248416] Sending NMI from CPU 13 to CPUs 4:
[ 1669.248428] NMI backtrace for cpu 4
[ 1669.248431] CPU: 4 UID: 0 PID: 0 Comm: swapper/4 Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1669.248434] Tainted: [W]=WARN
[ 1669.248435] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.248436] RIP: 0010:vprintk_emit+0x3a0/0x430
[ 1669.248440] Code: 6c 74 76 48 c7 c7 a8 0c 7f 96 c6 05 74 64 a8 02 01
e8 a4 32 cd 00 0f b6 05 68 64 a8 02 48 c7 c2 9b 0c 7f 96 84 c0 74 09 f3
90 <0f> b6 02 84 c0 75 f7 e8 04 1e 00 00 80 e7 02 74 06 fb 0f 1f 44 00
[ 1669.248442] RSP: 0018:ffffc0c8c01a4e18 EFLAGS: 00000002
[ 1669.248444] RAX: 0000000000000001 RBX: 0000000000000246 RCX:
0000000000000000
[ 1669.248445] RDX: ffffffff967f0c9b RSI: 0000000000000002 RDI:
ffffffff967f0ca8
[ 1669.248446] RBP: 0000000000000027 R08: 0000000000000000 R09:
c0000000ffff7fff
[ 1669.248448] R10: 0000000000000001 R11: ffffc0c8c01a4c48 R12:
0000000000000000
[ 1669.248449] R13: 0000000000000000 R14: ffffffff954639d9 R15:
ffffc0c8c01a4e70
[ 1669.248451] FS: 0000000000000000(0000) GS:ffff9ff73f800000(0000)
knlGS:0000000000000000
[ 1669.248453] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.248454] CR2: 00007fa3de41be6c CR3: 0000000109516004 CR4:
0000000000770ef0
[ 1669.248457] PKRU: 55555554
[ 1669.248458] Call Trace:
[ 1669.248459] <NMI>
[ 1669.248461] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.248464] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.248466] ? nmi_handle+0x5c/0x150
[ 1669.248470] ? default_do_nmi+0x4e/0x120
[ 1669.248472] ? exc_nmi+0x137/0x1d0
[ 1669.248475] ? end_repeat_nmi+0xf/0x53
[ 1669.248480] ? vprintk_emit+0x3a0/0x430
[ 1669.248482] ? vprintk_emit+0x3a0/0x430
[ 1669.248485] ? vprintk_emit+0x3a0/0x430
[ 1669.248487] </NMI>
[ 1669.248488] <IRQ>
[ 1669.248489] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248491] ? __pfx_workqueue_timedout+0x10/0x10
[ 1669.248494] ? __pfx_workqueue_timedout+0x10/0x10
[ 1669.248496] _printk+0x5c/0x80
[ 1669.248500] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248502] workqueue_timedout+0x23/0x60
[ 1669.248505] call_timer_fn+0x27/0x130
[ 1669.248509] __run_timer_base.part.35+0x1fe/0x230
[ 1669.248512] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248513] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248515] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248516] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248518] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.248519] ? sched_clock_cpu+0x11/0x190
[ 1669.248524] run_timer_softirq+0x51/0x90
[ 1669.248526] handle_softirqs+0xca/0x2c0
[ 1669.248530] irq_exit_rcu+0xb0/0xd0
[ 1669.248532] sysvec_apic_timer_interrupt+0x71/0x90
[ 1669.248536] </IRQ>
[ 1669.248537] <TASK>
[ 1669.248538] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 1669.248540] RIP: 0010:pv_native_safe_halt+0xf/0x20
[ 1669.248542] Code: 22 d7 e9 6f 48 2d 00 0f 1f 40 00 90 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 43 76 3f 00 fb
f4 <e9> 47 48 2d 00 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90
[ 1669.248544] RSP: 0018:ffffc0c8c00dbec8 EFLAGS: 00000216
[ 1669.248545] RAX: 0000000000000004 RBX: ffff9fd8809e0000 RCX:
ffff9fd884428e38
[ 1669.248546] RDX: 4000000000000000 RSI: 0000000000000004 RDI:
0000000000b34b7c
[ 1669.248547] RBP: 0000000000000004 R08: 0000000000000001 R09:
0000000000000004
[ 1669.248548] R10: 0000000000000000 R11: 0000000000000001 R12:
ffffffff95db8be0
[ 1669.248549] R13: ffff9fd8809e0000 R14: 0000000000000000 R15:
0000000000000000
[ 1669.248554] default_idle+0x9/0x20
[ 1669.248556] default_idle_call+0x34/0xf0
[ 1669.248558] do_idle+0x1f8/0x270
[ 1669.248561] cpu_startup_entry+0x29/0x30
[ 1669.248564] start_secondary+0x11e/0x140
[ 1669.248566] common_startup_64+0x13e/0x141
[ 1669.248571] </TASK>
[ 1669.249421] Sending NMI from CPU 13 to CPUs 5:
[ 1669.249444] NMI backtrace for cpu 5
[ 1669.249446] CPU: 5 UID: 1002 PID: 8250 Comm: mysqld Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1669.249450] Tainted: [W]=WARN
[ 1669.249451] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.249453] RIP: 0010:native_halt+0xe/0x20
[ 1669.249456] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.249458] RSP: 0018:ffffc0c8c71dbd20 EFLAGS: 00000046
[ 1669.249460] RAX: 0000000000000003 RBX: ffff9ff73fab6580 RCX:
0000000000000008
[ 1669.249462] RDX: 0000000000000000 RSI: 0000000000000003 RDI:
ffff9ff73fab6580
[ 1669.249463] RBP: ffff9ff73f8b7440 R08: 0000000000000008 R09:
0000000000000074
[ 1669.249464] R10: 0000000000000002 R11: 0000000000000000 R12:
0000000000000000
[ 1669.249466] R13: 0000000000000001 R14: 0000000000000100 R15:
0000000000180000
[ 1669.249468] FS: 00007f9e12600700(0000) GS:ffff9ff73f880000(0000)
knlGS:0000000000000000
[ 1669.249470] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.249472] CR2: 00007f9d63e00004 CR3: 0000001a0bc04005 CR4:
0000000000770ef0
[ 1669.249475] PKRU: 55555554
[ 1669.249476] Call Trace:
[ 1669.249477] <NMI>
[ 1669.249479] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.249482] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.249484] ? nmi_handle+0x5c/0x150
[ 1669.249488] ? default_do_nmi+0x4e/0x120
[ 1669.249491] ? exc_nmi+0x137/0x1d0
[ 1669.249495] ? end_repeat_nmi+0xf/0x53
[ 1669.249501] ? native_halt+0xe/0x20
[ 1669.249504] ? native_halt+0xe/0x20
[ 1669.249507] ? native_halt+0xe/0x20
[ 1669.249511] </NMI>
[ 1669.249511] <TASK>
[ 1669.249512] kvm_wait+0x47/0x60
[ 1669.249515] __pv_queued_spin_lock_slowpath+0x255/0x370
[ 1669.249518] _raw_spin_lock+0x29/0x30
[ 1669.249521] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.249524] __task_rq_lock+0x3f/0xe0
[ 1669.249528] try_to_wake_up+0x3cf/0x640
[ 1669.249531] ? plist_del+0x63/0xc0
[ 1669.249534] wake_up_q+0x4d/0x90
[ 1669.249537] futex_wake+0x154/0x180
[ 1669.249544] do_futex+0xf8/0x1d0
[ 1669.249547] __x64_sys_futex+0x68/0x1c0
[ 1669.249550] ? restore_fpregs_from_fpstate+0x3c/0xa0
[ 1669.249554] do_syscall_64+0x62/0x170
[ 1669.249558] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1669.249561] RIP: 0033:0x7fa6a961191a
[ 1669.249564] Code: 00 00 b8 ca 00 00 00 0f 05 5a 5e c3 0f 1f 40 00 56
52 c7 07 00 00 00 00 81 f6 81 00 00 00 ba 01 00 00 00 b8 ca 00 00 00 0f
05 <5a> 5e c3 0f 1f 00 41 54 41 55 49 89 fc 49 89 f5 48 83 ec 18 48 89
[ 1669.249566] RSP: 002b:00007f9e125feee0 EFLAGS: 00000206 ORIG_RAX:
00000000000000ca
[ 1669.249568] RAX: ffffffffffffffda RBX: 00007fa6a02ccb50 RCX:
00007fa6a961191a
[ 1669.249570] RDX: 0000000000000001 RSI: 0000000000000081 RDI:
00007fa6a02ccb50
[ 1669.249571] RBP: 00007f9e125ff1a0 R08: 0000000000000000 R09:
00007fa6a9d0c000
[ 1669.249572] R10: 00007fa6a9d0b080 R11: 0000000000000206 R12:
00007fa6a9852830
[ 1669.249574] R13: 0f83e0f83e0f83e1 R14: 0000000000000008 R15:
0000000000000100
[ 1669.249579] </TASK>
[ 1669.250426] Sending NMI from CPU 13 to CPUs 7:
[ 1669.250443] NMI backtrace for cpu 7
[ 1669.250446] CPU: 7 UID: 0 PID: 9912 Comm: pidstat Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1669.250450] Tainted: [W]=WARN
[ 1669.250451] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.250452] RIP: 0010:native_halt+0xe/0x20
[ 1669.250456] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.250458] RSP: 0018:ffffc0c8c8a4bb18 EFLAGS: 00000046
[ 1669.250460] RAX: 0000000000000003 RBX: ffff9ff73fab58c0 RCX:
0000000000000008
[ 1669.250461] RDX: ffff9ff7bffafb40 RSI: 0000000000000003 RDI:
ffff9ff73fab58c0
[ 1669.250462] RBP: ffff9ff73f9b7440 R08: 0000000000000008 R09:
00000000000000b4
[ 1669.250464] R10: ffffc0c8c8a4bbe0 R11: 0000000000000000 R12:
0000000000000000
[ 1669.250465] R13: 0000000000000001 R14: 0000000000000100 R15:
0000000000200000
[ 1669.250467] FS: 00007f461edcb580(0000) GS:ffff9ff73f980000(0000)
knlGS:0000000000000000
[ 1669.250469] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.250470] CR2: 000055b6651fe000 CR3: 00000001082de002 CR4:
0000000000770ef0
[ 1669.250473] PKRU: 55555554
[ 1669.250474] Call Trace:
[ 1669.250475] <NMI>
[ 1669.250477] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.250481] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.250483] ? nmi_handle+0x5c/0x150
[ 1669.250486] ? default_do_nmi+0x4e/0x120
[ 1669.250489] ? exc_nmi+0x137/0x1d0
[ 1669.250492] ? end_repeat_nmi+0xf/0x53
[ 1669.250497] ? native_halt+0xe/0x20
[ 1669.250499] ? native_halt+0xe/0x20
[ 1669.250502] ? native_halt+0xe/0x20
[ 1669.250505] </NMI>
[ 1669.250506] <TASK>
[ 1669.250506] kvm_wait+0x47/0x60
[ 1669.250508] __pv_queued_spin_lock_slowpath+0x255/0x370
[ 1669.250512] _raw_spin_lock_irq+0x2f/0x40
[ 1669.250513] wq_worker_comm+0xbb/0x120
[ 1669.250517] proc_task_name+0xbb/0xf0
[ 1669.250522] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.250525] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.250527] do_task_stat+0x47f/0xec0
[ 1669.250535] proc_single_show+0x59/0xd0
[ 1669.250539] seq_read_iter+0x19f/0x410
[ 1669.250544] seq_read+0x109/0x150
[ 1669.250549] vfs_read+0xc2/0x350
[ 1669.250552] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.250554] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.250557] ksys_read+0x63/0xe0
[ 1669.250560] do_syscall_64+0x62/0x170
[ 1669.250563] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1669.250566] RIP: 0033:0x7f461e71fdf5
[ 1669.250568] Code: fe ff ff 50 48 8d 3d a2 8d 06 00 e8 35 ee 01 00 0f
1f 44 00 00 f3 0f 1e fa 48 8d 05 45 49 2a 00 8b 00 85 c0 75 0f 31 c0 0f
05 <48> 3d 00 f0 ff ff 77 53 c3 66 90 41 54 49 89 d4 55 48 89 f5 53 89
[ 1669.250570] RSP: 002b:00007ffc727410d8 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[ 1669.250572] RAX: ffffffffffffffda RBX: 00007f461e3559b0 RCX:
00007f461e71fdf5
[ 1669.250573] RDX: 0000000000000400 RSI: 000055b64c60f5c0 RDI:
0000000000000004
[ 1669.250574] RBP: 0000000000000004 R08: 0000000000000000 R09:
0000000000000000
[ 1669.250575] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000000
[ 1669.250576] R13: 00000000000002a7 R14: 00007ffc727411f4 R15:
000055b64c60f130
[ 1669.250580] </TASK>
[ 1669.251430] Sending NMI from CPU 13 to CPUs 8:
[ 1669.251457] NMI backtrace for cpu 8
[ 1669.251461] CPU: 8 UID: 1002 PID: 8288 Comm: mysqld Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1669.251467] Tainted: [W]=WARN
[ 1669.251468] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.251470] RIP: 0010:native_halt+0xe/0x20
[ 1669.251478] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.251480] RSP: 0018:ffffc0c8c72cba20 EFLAGS: 00000046
[ 1669.251483] RAX: 0000000000000001 RBX: ffff9ff73fab6580 RCX:
0000000000000001
[ 1669.251485] RDX: 0000000000000001 RSI: 0000000000000001 RDI:
ffff9ff73fa37454
[ 1669.251487] RBP: ffff9ff73fa37440 R08: 0000000000000001 R09:
0000000000000200
[ 1669.251488] R10: 0000000000000000 R11: 0000000000000000 R12:
ffff9ff73f637440
[ 1669.251489] R13: ffff9ff73fa37454 R14: 0000000000000001 R15:
0000000000240000
[ 1669.251494] FS: 00007f9187200700(0000) GS:ffff9ff73fa00000(0000)
knlGS:0000000000000000
[ 1669.251496] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.251498] CR2: 00007f8ff7800004 CR3: 0000001a0bc04002 CR4:
0000000000770ef0
[ 1669.251501] PKRU: 55555554
[ 1669.251502] Call Trace:
[ 1669.251505] <NMI>
[ 1669.251508] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.251514] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.251518] ? nmi_handle+0x5c/0x150
[ 1669.251523] ? default_do_nmi+0x4e/0x120
[ 1669.251527] ? exc_nmi+0x137/0x1d0
[ 1669.251531] ? end_repeat_nmi+0xf/0x53
[ 1669.251540] ? native_halt+0xe/0x20
[ 1669.251543] ? native_halt+0xe/0x20
[ 1669.251547] ? native_halt+0xe/0x20
[ 1669.251550] </NMI>
[ 1669.251551] <TASK>
[ 1669.251552] kvm_wait+0x47/0x60
[ 1669.251555] __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.251560] _raw_spin_lock+0x29/0x30
[ 1669.251564] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.251568] _raw_spin_rq_lock_irqsave+0x17/0x20
[ 1669.251572] sched_balance_rq+0xa4e/0xd70
[ 1669.251581] sched_balance_newidle+0x1c3/0x430
[ 1669.251585] pick_next_task_fair+0x36/0x370
[ 1669.251588] ? dl_server_stop+0x2c/0x40
[ 1669.251592] pick_next_task+0x6b/0xc00
[ 1669.251595] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.251597] ? dequeue_task_fair+0xa1/0x2b0
[ 1669.251601] __schedule+0x155/0xba0
[ 1669.251606] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.251609] schedule+0x36/0xc0
[ 1669.251613] futex_wait_queue+0x66/0xa0
[ 1669.251619] __futex_wait+0x13d/0x1b0
[ 1669.251623] ? __pfx_futex_wake_mark+0x10/0x10
[ 1669.251629] futex_wait+0x6e/0x110
[ 1669.251632] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.251634] ? futex_wake+0x85/0x180
[ 1669.251639] do_futex+0x11a/0x1d0
[ 1669.251642] __x64_sys_futex+0x68/0x1c0
[ 1669.251645] ? restore_fpregs_from_fpstate+0x3c/0xa0
[ 1669.251650] do_syscall_64+0x62/0x170
[ 1669.251655] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1669.251658] RIP: 0033:0x7fa6a960e4ac
[ 1669.251662] Code: 68 4c 89 64 24 70 89 6c 24 78 e8 ef 2e 00 00 e8 da
32 00 00 45 31 d2 31 d2 8b 74 24 34 41 89 c0 4c 89 ff b8 ca 00 00 00 0f
05 <48> 3d 00 f0 ff ff 77 54 44 89 c7 e8 14 33 00 00 48 8b 7c 24 10 31
[ 1669.251664] RSP: 002b:00007f91871ff9f0 EFLAGS: 00000246 ORIG_RAX:
00000000000000ca
[ 1669.251667] RAX: ffffffffffffffda RBX: 00007fa6a001d518 RCX:
00007fa6a960e4ac
[ 1669.251668] RDX: 0000000000000000 RSI: 0000000000000080 RDI:
00007fa6a001d540
[ 1669.251669] RBP: 0000000000000000 R08: 0000000000000000 R09:
00007fa6a9d0c000
[ 1669.251671] R10: 0000000000000000 R11: 0000000000000246 R12:
00007fa6a001d4f0
[ 1669.251672] R13: 0000000000001eec R14: 0000000000000000 R15:
00007fa6a001d540
[ 1669.251677] </TASK>
[ 1669.252438] Sending NMI from CPU 13 to CPUs 9:
[ 1669.252457] NMI backtrace for cpu 9
[ 1669.252459] CPU: 9 UID: 1002 PID: 8255 Comm: mysqld Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1669.252462] Tainted: [W]=WARN
[ 1669.252462] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.252463] RIP: 0010:native_halt+0xe/0x20
[ 1669.252466] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.252468] RSP: 0018:ffffc0c8c7203718 EFLAGS: 00000046
[ 1669.252469] RAX: 0000000000000001 RBX: ffff9ff73fab6580 RCX:
0000000000000001
[ 1669.252470] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
ffff9ff73fab7454
[ 1669.252471] RBP: ffff9ff73fab7440 R08: ffff9ff73fab58e8 R09:
ffff9fd880401ff0
[ 1669.252473] R10: 0000000000000000 R11: ffffffff95869448 R12:
ffff9ff73fa37440
[ 1669.252474] R13: ffff9ff73fab7454 R14: 0000000000000001 R15:
0000000000280000
[ 1669.252476] FS: 00007f9e0a600700(0000) GS:ffff9ff73fa80000(0000)
knlGS:0000000000000000
[ 1669.252478] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.252479] CR2: 00007f8fb5e00004 CR3: 0000001a0bc04004 CR4:
0000000000770ef0
[ 1669.252481] PKRU: 55555554
[ 1669.252482] Call Trace:
[ 1669.252483] <NMI>
[ 1669.252484] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.252487] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.252489] ? nmi_handle+0x5c/0x150
[ 1669.252493] ? default_do_nmi+0x4e/0x120
[ 1669.252495] ? exc_nmi+0x137/0x1d0
[ 1669.252498] ? end_repeat_nmi+0xf/0x53
[ 1669.252503] ? native_halt+0xe/0x20
[ 1669.252506] ? native_halt+0xe/0x20
[ 1669.252509] ? native_halt+0xe/0x20
[ 1669.252511] </NMI>
[ 1669.252512] <TASK>
[ 1669.252513] kvm_wait+0x47/0x60
[ 1669.252514] __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.252518] _raw_spin_lock+0x29/0x30
[ 1669.252520] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.252523] try_to_wake_up+0x187/0x640
[ 1669.252526] kick_pool+0x65/0x140
[ 1669.252531] __queue_work+0x1ae/0x400
[ 1669.252535] queue_work_on+0x66/0x70
[ 1669.252538] soft_cursor+0x198/0x230
[ 1669.252542] bit_cursor+0x355/0x610
[ 1669.252546] ? __entry_text_end+0x101ec6/0x101ec9
[ 1669.252548] ? get_color+0x26/0x120
[ 1669.252552] ? __pfx_bit_cursor+0x10/0x10
[ 1669.252553] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.252556] hide_cursor+0x27/0x90
[ 1669.252559] vt_console_print+0x3e9/0x400
[ 1669.252564] console_flush_all+0x2df/0x500
[ 1669.252569] console_unlock+0x10b/0x1f0
[ 1669.252572] vprintk_emit+0x3c6/0x430
[ 1669.252575] _printk+0x5c/0x80
[ 1669.252580] __warn_printk+0xe3/0x120
[ 1669.252583] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.252587] pick_task_fair+0x103/0x160
[ 1669.252590] pick_next_task_fair+0x4c/0x370
[ 1669.252593] pick_next_task+0x6b/0xc00
[ 1669.252595] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.252597] ? dequeue_task_fair+0x4b/0x2b0
[ 1669.252599] __schedule+0x155/0xba0
[ 1669.252603] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.252605] schedule+0x36/0xc0
[ 1669.252608] futex_wait_queue+0x66/0xa0
[ 1669.252611] __futex_wait+0x13d/0x1b0
[ 1669.252615] ? __pfx_futex_wake_mark+0x10/0x10
[ 1669.252619] futex_wait+0x6e/0x110
[ 1669.252622] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.252623] ? futex_wake+0x85/0x180
[ 1669.252627] do_futex+0x11a/0x1d0
[ 1669.252630] __x64_sys_futex+0x68/0x1c0
[ 1669.252632] ? restore_fpregs_from_fpstate+0x3c/0xa0
[ 1669.252635] do_syscall_64+0x62/0x170
[ 1669.252638] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1669.252641] RIP: 0033:0x7fa6a961187d
[ 1669.252643] Code: f0 5a 41 5a c3 0f 1f 84 00 00 00 00 00 41 52 52 4d
31 d2 ba 02 00 00 00 81 f6 80 00 00 00 39 d0 75 08 90 b8 ca 00 00 00 0f
05 <89> d0 87 07 85 c0 75 f0 5a 41 5a c3 0f 1f 80 00 00 00 00 48 83 3a
[ 1669.252644] RSP: 002b:00007f9e0a5fee88 EFLAGS: 00000202 ORIG_RAX:
00000000000000ca
[ 1669.252646] RAX: ffffffffffffffda RBX: 00007fa6a02ccb50 RCX:
00007fa6a961187d
[ 1669.252647] RDX: 0000000000000002 RSI: 0000000000000080 RDI:
00007fa6a02ccb50
[ 1669.252648] RBP: 00007f9e0a5fef70 R08: 00007fa6a02ccb50 R09:
0000000000000028
[ 1669.252649] R10: 0000000000000000 R11: 0000000000000202 R12:
00007fa6a988c010
[ 1669.252650] R13: 0f83e0f83e0f83e1 R14: 0000000000000004 R15:
00007fa6a984a010
[ 1669.252654] </TASK>
[ 1669.253446] rcu: rcu_preempt kthread starved for 30005 jiffies!
g168081 f0x0 RCU_GP_DOING_FQS(6) ->state=0x0 ->cpu=2
[ 1669.253449] rcu: Unless rcu_preempt kthread gets sufficient CPU
time, OOM is now expected behavior.
[ 1669.253451] rcu: RCU grace-period kthread stack dump:
[ 1669.253452] task:rcu_preempt state:R running task stack:0
pid:17 tgid:17 ppid:2 flags:0x00004008
[ 1669.253457] Call Trace:
[ 1669.253458] <TASK>
[ 1669.253461] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.253464] ? sysvec_call_function_single+0xe/0x90
[ 1669.253467] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1669.253469] ? asm_sysvec_call_function_single+0x1a/0x20
[ 1669.253473] ? kvm_wait+0x47/0x60
[ 1669.253475] ? __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.253478] ? _raw_spin_lock+0x29/0x30
[ 1669.253481] ? raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.253484] ? resched_cpu+0x3e/0x80
[ 1669.253486] ? force_qs_rnp+0x239/0x2c0
[ 1669.253490] ? __pfx_rcu_watching_snap_recheck+0x10/0x10
[ 1669.253493] ? rcu_gp_fqs_loop+0x384/0x500
[ 1669.253497] ? __pfx_rcu_gp_kthread+0x10/0x10
[ 1669.253499] ? rcu_gp_kthread+0xdf/0x190
[ 1669.253502] ? kthread+0xd2/0x100
[ 1669.253506] ? __pfx_kthread+0x10/0x10
[ 1669.253509] ? ret_from_fork+0x34/0x40
[ 1669.253512] ? __pfx_kthread+0x10/0x10
[ 1669.253515] ? ret_from_fork_asm+0x1a/0x30
[ 1669.253521] </TASK>
[ 1669.253522] rcu: Stack dump where RCU GP kthread last ran:
[ 1669.253523] Sending NMI from CPU 13 to CPUs 2:
[ 1669.253539] NMI backtrace for cpu 2
[ 1669.253542] CPU: 2 UID: 0 PID: 17 Comm: rcu_preempt Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1669.253546] Tainted: [W]=WARN
[ 1669.253547] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1669.253548] RIP: 0010:native_halt+0xe/0x20
[ 1669.253553] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90
90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01
f4 <e9> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
[ 1669.253555] RSP: 0018:ffffc0c8c009bd88 EFLAGS: 00000046
[ 1669.253557] RAX: 0000000000000001 RBX: ffff9ff73fab6580 RCX:
0000000000000001
[ 1669.253559] RDX: 0000000000000001 RSI: 0000000000000001 RDI:
ffff9ff73f737454
[ 1669.253560] RBP: ffff9ff73f737440 R08: ffff9ff73f7370f0 R09:
0000000000000377
[ 1669.253562] R10: 0000000000000001 R11: 0000000000000001 R12:
ffff9ff73fab7440
[ 1669.253563] R13: ffff9ff73f737454 R14: 0000000000000001 R15:
00000000000c0000
[ 1669.253566] FS: 0000000000000000(0000) GS:ffff9ff73f700000(0000)
knlGS:0000000000000000
[ 1669.253567] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1669.253569] CR2: 00007f6d7d6f9890 CR3: 0000001a0bc04005 CR4:
0000000000770ef0
[ 1669.253572] PKRU: 55555554
[ 1669.253572] Call Trace:
[ 1669.253574] <NMI>
[ 1669.253575] ? nmi_cpu_backtrace+0x98/0x110
[ 1669.253579] ? nmi_cpu_backtrace_handler+0x11/0x20
[ 1669.253581] ? nmi_handle+0x5c/0x150
[ 1669.253585] ? default_do_nmi+0x4e/0x120
[ 1669.253587] ? exc_nmi+0x137/0x1d0
[ 1669.253590] ? end_repeat_nmi+0xf/0x53
[ 1669.253595] ? native_halt+0xe/0x20
[ 1669.253598] ? native_halt+0xe/0x20
[ 1669.253601] ? native_halt+0xe/0x20
[ 1669.253603] </NMI>
[ 1669.253604] <TASK>
[ 1669.253605] kvm_wait+0x47/0x60
[ 1669.253607] __pv_queued_spin_lock_slowpath+0x307/0x370
[ 1669.253610] _raw_spin_lock+0x29/0x30
[ 1669.253612] raw_spin_rq_lock_nested+0x1c/0x80
[ 1669.253615] resched_cpu+0x3e/0x80
[ 1669.253618] force_qs_rnp+0x239/0x2c0
[ 1669.253621] ? __pfx_rcu_watching_snap_recheck+0x10/0x10
[ 1669.253624] rcu_gp_fqs_loop+0x384/0x500
[ 1669.253628] ? __pfx_rcu_gp_kthread+0x10/0x10
[ 1669.253631] rcu_gp_kthread+0xdf/0x190
[ 1669.253633] kthread+0xd2/0x100
[ 1669.253637] ? __pfx_kthread+0x10/0x10
[ 1669.253640] ret_from_fork+0x34/0x40
[ 1669.253643] ? __pfx_kthread+0x10/0x10
[ 1669.253646] ret_from_fork_asm+0x1a/0x30
[ 1669.253652] </TASK>
[ 1721.537374] INFO: task kworker/u66:13:128 blocked for more than 122
seconds.
[ 1721.537380] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.537382] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.537383] task:kworker/u66:13 state:D stack:0 pid:128
tgid:128 ppid:2 flags:0x00004000
[ 1721.537388] Workqueue: events_unbound idle_cull_fn
[ 1721.537395] Call Trace:
[ 1721.537397] <TASK>
[ 1721.537401] __schedule+0x334/0xba0
[ 1721.537409] schedule+0x36/0xc0
[ 1721.537412] schedule_preempt_disabled+0x15/0x30
[ 1721.537415] __mutex_lock.isra.14+0x431/0x690
[ 1721.537418] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537421] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537424] idle_cull_fn+0x3b/0xe0
[ 1721.537428] process_scheduled_works+0x109/0x4e0
[ 1721.537431] ? __pfx_workqueue_timedout+0x10/0x10
[ 1721.537434] ? __pfx_idle_cull_fn+0x10/0x10
[ 1721.537437] worker_thread+0x117/0x240
[ 1721.537440] ? __pfx_worker_thread+0x10/0x10
[ 1721.537442] kthread+0xd2/0x100
[ 1721.537446] ? __pfx_kthread+0x10/0x10
[ 1721.537449] ret_from_fork+0x34/0x40
[ 1721.537453] ? __pfx_kthread+0x10/0x10
[ 1721.537456] ret_from_fork_asm+0x1a/0x30
[ 1721.537462] </TASK>
[ 1721.537469] INFO: task kworker/u65:4:229 blocked for more than 122
seconds.
[ 1721.537471] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.537472] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.537473] task:kworker/u65:4 state:D stack:0 pid:229
tgid:229 ppid:2 flags:0x00004000
[ 1721.537477] Workqueue: events_unbound idle_cull_fn
[ 1721.537479] Call Trace:
[ 1721.537481] <TASK>
[ 1721.537483] __schedule+0x334/0xba0
[ 1721.537488] schedule+0x36/0xc0
[ 1721.537491] schedule_preempt_disabled+0x15/0x30
[ 1721.537493] __mutex_lock.isra.14+0x431/0x690
[ 1721.537496] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537498] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537501] idle_cull_fn+0x3b/0xe0
[ 1721.537504] process_scheduled_works+0x109/0x4e0
[ 1721.537507] ? __pfx_workqueue_timedout+0x10/0x10
[ 1721.537509] ? __pfx_idle_cull_fn+0x10/0x10
[ 1721.537512] worker_thread+0x117/0x240
[ 1721.537515] ? __pfx_worker_thread+0x10/0x10
[ 1721.537517] kthread+0xd2/0x100
[ 1721.537520] ? __pfx_kthread+0x10/0x10
[ 1721.537523] ret_from_fork+0x34/0x40
[ 1721.537525] ? __pfx_kthread+0x10/0x10
[ 1721.537528] ret_from_fork_asm+0x1a/0x30
[ 1721.537533] </TASK>
[ 1721.537538] INFO: task kworker/11:1H:659 blocked for more than 122
seconds.
[ 1721.537540] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.537541] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.537542] task:kworker/11:1H state:D stack:0 pid:659
tgid:659 ppid:2 flags:0x00004000
[ 1721.537546] Workqueue: kblockd blk_mq_timeout_work
[ 1721.537550] Call Trace:
[ 1721.537552] <TASK>
[ 1721.537554] __schedule+0x334/0xba0
[ 1721.537559] schedule+0x36/0xc0
[ 1721.537562] schedule_timeout+0x283/0x2c0
[ 1721.537565] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537567] ? scsi_queue_rq+0x2b6/0xbe0
[ 1721.537571] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537573] ? __prepare_to_swait+0x52/0x80
[ 1721.537577] wait_for_completion_state+0x173/0x1d0
[ 1721.537581] __wait_rcu_gp+0x121/0x150
[ 1721.537585] synchronize_rcu_normal.part.63+0x3a/0x60
[ 1721.537589] ? __pfx_call_rcu_hurry+0x10/0x10
[ 1721.537592] ? __pfx_wakeme_after_rcu+0x10/0x10
[ 1721.537594] synchronize_rcu_normal+0x9a/0xb0
[ 1721.537597] ? __pfx_blk_mq_check_expired+0x10/0x10
[ 1721.537601] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537603] blk_mq_timeout_work+0x142/0x1a0
[ 1721.537605] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.537608] process_scheduled_works+0x109/0x4e0
[ 1721.537611] ? __pfx_workqueue_timedout+0x10/0x10
[ 1721.537614] ? __pfx_blk_mq_timeout_work+0x10/0x10
[ 1721.537617] worker_thread+0x117/0x240
[ 1721.537619] ? __pfx_worker_thread+0x10/0x10
[ 1721.537622] kthread+0xd2/0x100
[ 1721.537624] ? __pfx_kthread+0x10/0x10
[ 1721.537627] ret_from_fork+0x34/0x40
[ 1721.537630] ? __pfx_kthread+0x10/0x10
[ 1721.537633] ret_from_fork_asm+0x1a/0x30
[ 1721.537638] </TASK>
[ 1721.537697] INFO: task mysqld:8329 blocked for more than 122 seconds.
[ 1721.537699] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.537700] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.537701] task:mysqld state:D stack:0 pid:8329
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.537704] Call Trace:
[ 1721.537705] <TASK>
[ 1721.537707] __schedule+0x334/0xba0
[ 1721.537712] schedule+0x36/0xc0
[ 1721.537716] inode_dio_wait+0x7b/0xb0
[ 1721.537720] ? __pfx_var_wake_function+0x10/0x10
[ 1721.537726] xfs_file_fallocate+0xca/0x440 [xfs]
[ 1721.537873] vfs_fallocate+0x124/0x310
[ 1721.537878] ksys_fallocate+0x40/0x80
[ 1721.537881] __x64_sys_fallocate+0x1e/0x30
[ 1721.537884] do_syscall_64+0x62/0x170
[ 1721.537889] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.537892] RIP: 0033:0x7fa6a6d2499a
[ 1721.537895] RSP: 002b:00007fa6a43f5bd0 EFLAGS: 00000246 ORIG_RAX:
000000000000011d
[ 1721.537898] RAX: ffffffffffffffda RBX: 0000000004000000 RCX:
00007fa6a6d2499a
[ 1721.537899] RDX: 0000000250000000 RSI: 0000000000000000 RDI:
0000000000000029
[ 1721.537901] RBP: 00007fa6a43f6120 R08: 0000000000001000 R09:
0000000250000000
[ 1721.537902] R10: 0000000004000000 R11: 0000000000000246 R12:
00007fa6a02c1e10
[ 1721.537904] R13: 00007fa6a02c1ed8 R14: 00007f8bd8012f70 R15:
00007f8bd809a0d0
[ 1721.537908] </TASK>
[ 1721.537910] INFO: task mysqld:8331 blocked for more than 122 seconds.
[ 1721.537911] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.537913] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.537914] task:mysqld state:D stack:0 pid:8331
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.537916] Call Trace:
[ 1721.537926] <TASK>
[ 1721.537928] __schedule+0x334/0xba0
[ 1721.537933] schedule+0x36/0xc0
[ 1721.537937] inode_dio_wait+0x7b/0xb0
[ 1721.537940] ? __pfx_var_wake_function+0x10/0x10
[ 1721.537943] xfs_file_fallocate+0xca/0x440 [xfs]
[ 1721.538078] vfs_fallocate+0x124/0x310
[ 1721.538081] ksys_fallocate+0x40/0x80
[ 1721.538085] __x64_sys_fallocate+0x1e/0x30
[ 1721.538087] do_syscall_64+0x62/0x170
[ 1721.538091] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.538093] RIP: 0033:0x7fa6a6d2499a
[ 1721.538095] RSP: 002b:00007fa6a41f1bd0 EFLAGS: 00000246 ORIG_RAX:
000000000000011d
[ 1721.538097] RAX: ffffffffffffffda RBX: 0000000004000000 RCX:
00007fa6a6d2499a
[ 1721.538099] RDX: 000000024c000000 RSI: 0000000000000000 RDI:
0000000000000027
[ 1721.538100] RBP: 00007fa6a41f2120 R08: 0000000000001000 R09:
000000024c000000
[ 1721.538101] R10: 0000000004000000 R11: 0000000000000246 R12:
00007fa6a02c1fe0
[ 1721.538103] R13: 00007fa6a02c20a8 R14: 00007f8bcc012f80 R15:
00007f8bcc099f80
[ 1721.538107] </TASK>
[ 1721.538108] INFO: task mysqld:8332 blocked for more than 122 seconds.
[ 1721.538110] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.538111] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.538112] task:mysqld state:D stack:0 pid:8332
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.538115] Call Trace:
[ 1721.538116] <TASK>
[ 1721.538118] __schedule+0x334/0xba0
[ 1721.538122] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.538125] schedule+0x36/0xc0
[ 1721.538129] schedule_timeout+0x1e0/0x2c0
[ 1721.538132] ? __pfx_process_timeout+0x10/0x10
[ 1721.538137] io_schedule_timeout+0x51/0x70
[ 1721.538140] __iomap_dio_rw+0x5ca/0x840
[ 1721.538145] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.538152] iomap_dio_rw+0x12/0x40
[ 1721.538155] xfs_file_dio_write_aligned+0xa6/0x130 [xfs]
[ 1721.538283] xfs_file_write_iter+0xcc/0x120 [xfs]
[ 1721.538427] vfs_write+0x2fc/0x430
[ 1721.538433] ksys_pwrite64+0x69/0xa0
[ 1721.538436] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.538439] do_syscall_64+0x62/0x170
[ 1721.538442] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.538445] RIP: 0033:0x7fa6a96124d7
[ 1721.538447] RSP: 002b:00007fa69fff65a0 EFLAGS: 00000293 ORIG_RAX:
0000000000000012
[ 1721.538449] RAX: ffffffffffffffda RBX: 000000000000002b RCX:
00007fa6a96124d7
[ 1721.538450] RDX: 0000000000100000 RSI: 00007f8bc491c000 RDI:
000000000000002b
[ 1721.538452] RBP: 00007f8bc491c000 R08: 0000000000000000 R09:
00007fa69fff88ec
[ 1721.538453] R10: 0000000248400000 R11: 0000000000000293 R12:
0000000000100000
[ 1721.538454] R13: 0000000248400000 R14: 00000000042ae5f8 R15:
00007f8bc409a270
[ 1721.538459] </TASK>
[ 1721.538460] INFO: task mysqld:8333 blocked for more than 122 seconds.
[ 1721.538462] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.538463] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.538464] task:mysqld state:D stack:0 pid:8333
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.538467] Call Trace:
[ 1721.538468] <TASK>
[ 1721.538470] __schedule+0x334/0xba0
[ 1721.538475] schedule+0x36/0xc0
[ 1721.538478] inode_dio_wait+0x7b/0xb0
[ 1721.538482] ? __pfx_var_wake_function+0x10/0x10
[ 1721.538485] xfs_file_fallocate+0xca/0x440 [xfs]
[ 1721.538610] vfs_fallocate+0x124/0x310
[ 1721.538613] ksys_fallocate+0x40/0x80
[ 1721.538616] __x64_sys_fallocate+0x1e/0x30
[ 1721.538618] do_syscall_64+0x62/0x170
[ 1721.538622] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.538625] RIP: 0033:0x7fa6a6d2499a
[ 1721.538626] RSP: 002b:00007fa69f9f8bd0 EFLAGS: 00000246 ORIG_RAX:
000000000000011d
[ 1721.538628] RAX: ffffffffffffffda RBX: 0000000004000000 RCX:
00007fa6a6d2499a
[ 1721.538630] RDX: 0000000250000000 RSI: 0000000000000000 RDI:
0000000000000028
[ 1721.538631] RBP: 00007fa69f9f9120 R08: 0000000000001000 R09:
0000000250000000
[ 1721.538632] R10: 0000000004000000 R11: 0000000000000246 R12:
00007fa6a02c1bf0
[ 1721.538634] R13: 00007fa6a02c1cb8 R14: 00007f8bc0076090 R15:
00007f8bc009a880
[ 1721.538638] </TASK>
[ 1721.538639] INFO: task mysqld:8335 blocked for more than 122 seconds.
[ 1721.538641] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.538642] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.538643] task:mysqld state:D stack:0 pid:8335
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.538645] Call Trace:
[ 1721.538647] <TASK>
[ 1721.538649] __schedule+0x334/0xba0
[ 1721.538654] schedule+0x36/0xc0
[ 1721.538657] inode_dio_wait+0x7b/0xb0
[ 1721.538660] ? __pfx_var_wake_function+0x10/0x10
[ 1721.538664] xfs_file_fallocate+0xca/0x440 [xfs]
[ 1721.538788] vfs_fallocate+0x124/0x310
[ 1721.538792] ksys_fallocate+0x40/0x80
[ 1721.538795] __x64_sys_fallocate+0x1e/0x30
[ 1721.538797] do_syscall_64+0x62/0x170
[ 1721.538801] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.538803] RIP: 0033:0x7fa6a6d2499a
[ 1721.538805] RSP: 002b:00007fa69e9f8bd0 EFLAGS: 00000246 ORIG_RAX:
000000000000011d
[ 1721.538807] RAX: ffffffffffffffda RBX: 0000000004000000 RCX:
00007fa6a6d2499a
[ 1721.538808] RDX: 0000000250000000 RSI: 0000000000000000 RDI:
0000000000000026
[ 1721.538810] RBP: 00007fa69e9f9120 R08: 0000000000001000 R09:
0000000250000000
[ 1721.538811] R10: 0000000004000000 R11: 0000000000000246 R12:
00007fa6a02c21b0
[ 1721.538812] R13: 00007fa6a02c2278 R14: 00007f8bb4056cb0 R15:
00007f8bb4099de0
[ 1721.538817] </TASK>
[ 1721.538819] INFO: task mysqld:8341 blocked for more than 122 seconds.
[ 1721.538820] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.538821] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.538822] task:mysqld state:D stack:0 pid:8341
tgid:8190 ppid:8021 flags:0x00000000
[ 1721.538825] Call Trace:
[ 1721.538827] <TASK>
[ 1721.538829] __schedule+0x334/0xba0
[ 1721.538833] schedule+0x36/0xc0
[ 1721.538837] inode_dio_wait+0x7b/0xb0
[ 1721.538840] ? __pfx_var_wake_function+0x10/0x10
[ 1721.538843] xfs_file_fallocate+0xca/0x440 [xfs]
[ 1721.538974] vfs_fallocate+0x124/0x310
[ 1721.538977] ksys_fallocate+0x40/0x80
[ 1721.538980] __x64_sys_fallocate+0x1e/0x30
[ 1721.538983] do_syscall_64+0x62/0x170
[ 1721.538986] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.538989] RIP: 0033:0x7fa6a6d2499a
[ 1721.538991] RSP: 002b:00007fa697ff8bd0 EFLAGS: 00000246 ORIG_RAX:
000000000000011d
[ 1721.538993] RAX: ffffffffffffffda RBX: 0000000004000000 RCX:
00007fa6a6d2499a
[ 1721.538994] RDX: 000000024c000000 RSI: 0000000000000000 RDI:
000000000000002c
[ 1721.538995] RBP: 00007fa697ff9120 R08: 0000000000001000 R09:
000000024c000000
[ 1721.538997] R10: 0000000004000000 R11: 0000000000000246 R12:
00007fa6a02c1850
[ 1721.538998] R13: 00007fa6a02c1918 R14: 00007f8b9001a950 R15:
00007f8b9003b5b0
[ 1721.539002] </TASK>
[ 1721.539006] INFO: task top:9931 blocked for more than 122 seconds.
[ 1721.539008] Tainted: G W
6.12.0-rc4-g556c97f2ecbf #40
[ 1721.539009] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 1721.539010] task:top state:D stack:0 pid:9931
tgid:9931 ppid:9915 flags:0x00004002
[ 1721.539013] Call Trace:
[ 1721.539015] <TASK>
[ 1721.539017] __schedule+0x334/0xba0
[ 1721.539022] schedule+0x36/0xc0
[ 1721.539025] schedule_preempt_disabled+0x15/0x30
[ 1721.539027] __mutex_lock.isra.14+0x431/0x690
[ 1721.539029] ? prep_new_page+0x1b/0x50
[ 1721.539033] ? get_page_from_freelist+0x11b2/0x22a0
[ 1721.539037] wq_worker_comm+0x26/0x120
[ 1721.539041] proc_task_name+0xbb/0xf0
[ 1721.539045] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.539047] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.539050] do_task_stat+0x47f/0xec0
[ 1721.539058] proc_single_show+0x59/0xd0
[ 1721.539063] seq_read_iter+0x19f/0x410
[ 1721.539068] seq_read+0x109/0x150
[ 1721.539073] vfs_read+0xc2/0x350
[ 1721.539075] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.539077] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1721.539081] ksys_read+0x63/0xe0
[ 1721.539084] do_syscall_64+0x62/0x170
[ 1721.539088] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1721.539090] RIP: 0033:0x7f2fc4d1fdf5
[ 1721.539092] RSP: 002b:00007ffc726f6dc8 EFLAGS: 00000246 ORIG_RAX:
0000000000000000
[ 1721.539094] RAX: ffffffffffffffda RBX: 00007f2fc6213678 RCX:
00007f2fc4d1fdf5
[ 1721.539095] RDX: 0000000000000400 RSI: 000055955b781a10 RDI:
0000000000000007
[ 1721.539096] RBP: 00007f2fc6213670 R08: 0000000000000000 R09:
00007f2fc4d80060
[ 1721.539098] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000007
[ 1721.539099] R13: 0000000000000000 R14: 0000000000000000 R15:
0000000000000000
[ 1721.539103] </TASK>
[ 1721.539104] Future hung task reports are suppressed, see sysctl
kernel.hung_task_warnings
[ 1776.268834] watchdog: BUG: soft lockup - CPU#10 stuck for 23s!
[osms-agent:3184]
[ 1776.268839] Modules linked in: binfmt_misc ip6t_REJECT ipt_REJECT
xt_comment xt_owner nft_compat nft_fib_inet nft_fib_ipv4 nft_fib_ipv6
nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct
rfkill nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
ip_set cuse fuse vfat fat intel_rapl_msr intel_rapl_common raid0 kvm_amd
mlx5_ib bochs ccp drm_vram_helper drm_ttm_helper ib_uverbs mlx5_vdpa ttm
vringh drm_kms_helper kvm vhost_iotlb ib_core vdpa drm joydev pcspkr
i2c_piix4 pvpanic_mmio pvpanic i2c_smbus xfs iscsi_tcp libiscsi_tcp
libiscsi nvme_tcp nvme_fabrics nvme nvme_core sd_mod sg virtio_scsi
mlx5_core ata_generic pata_acpi crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel sha512_ssse3 ata_piix mlxfw sha256_ssse3 sha1_ssse3
psample libata virtio_pci tls serio_raw virtio_pci_legacy_dev
virtio_pci_modern_dev pci_hyperv_intf qemu_fw_cfg dm_multipath sunrpc
dm_mirror dm_region_hash dm_log dm_mod scsi_transport_iscsi aesni_intel
crypto_simd cryptd
[ 1776.268933] CPU: 10 UID: 0 PID: 3184 Comm: osms-agent Tainted: G
W 6.12.0-rc4-g556c97f2ecbf #40
[ 1776.268937] Tainted: [W]=WARN
[ 1776.268939] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1776.268940] RIP: 0010:smp_call_function_many_cond+0x312/0x4e0
[ 1776.268947] Code: 48 00 39 05 f0 74 fe 01 48 89 c5 0f 86 79 ff ff ff
48 63 c5 48 8b 3b 48 03 3c c5 00 8e 5a 95 66 90 8b 47 08 a8 01 74 09 f3
90 <8b> 47 08 a8 01 75 f7 83 c5 01 eb ba e8 cd f6 ff ff eb f4 83 7c 24
[ 1776.268949] RSP: 0018:ffffc0c8c2d9fc38 EFLAGS: 00000202
[ 1776.268951] RAX: 0000000000000011 RBX: ffff9ff73fb37900 RCX:
0000000000000000
[ 1776.268953] RDX: 0000000000000001 RSI: 0000000000000010 RDI:
ffff9ff73f6bd340
[ 1776.268954] RBP: 0000000000000001 R08: 0000000000000001 R09:
ffff9ff73f6bd340
[ 1776.268956] R10: 0000000000000002 R11: 0000000000000000 R12:
0000000000000001
[ 1776.268957] R13: 0000000000000001 R14: 0000000000000010 R15:
ffff9ff73f6bd340
[ 1776.268969] FS: 00007fdbcd600700(0000) GS:ffff9ff73fb00000(0000)
knlGS:0000000000000000
[ 1776.268971] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1776.268973] CR2: 00007fdbea983560 CR3: 00000001095f2005 CR4:
0000000000770ef0
[ 1776.268976] PKRU: 55555554
[ 1776.268977] Call Trace:
[ 1776.268980] <IRQ>
[ 1776.268982] ? watchdog_timer_fn+0x1e2/0x260
[ 1776.268987] ? __pfx_watchdog_timer_fn+0x10/0x10
[ 1776.268989] ? __hrtimer_run_queues+0x10c/0x270
[ 1776.268995] ? hrtimer_interrupt+0x109/0x250
[ 1776.268997] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1776.269002] ? __sysvec_apic_timer_interrupt+0x55/0x120
[ 1776.269006] ? sysvec_apic_timer_interrupt+0x6c/0x90
[ 1776.269010] </IRQ>
[ 1776.269012] <TASK>
[ 1776.269013] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 1776.269019] ? smp_call_function_many_cond+0x312/0x4e0
[ 1776.269021] ? smp_call_function_many_cond+0x2ea/0x4e0
[ 1776.269023] ? __pfx_flush_tlb_func+0x10/0x10
[ 1776.269029] on_each_cpu_cond_mask+0x29/0x50
[ 1776.269031] flush_tlb_mm_range+0x13f/0x160
[ 1776.269035] dup_mmap+0x2ea/0x740
[ 1776.269042] copy_process+0x12b2/0x1d20
[ 1776.269047] kernel_clone+0x9e/0x390
[ 1776.269050] __do_sys_clone+0x66/0x90
[ 1776.269055] do_syscall_64+0x62/0x170
[ 1776.269059] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1776.269063] RIP: 0033:0x7fdbeb4f9a73
[ 1776.269066] Code: db 0f 85 28 01 00 00 64 4c 8b 0c 25 10 00 00 00 45
31 c0 4d 8d 91 d0 02 00 00 31 d2 31 f6 bf 11 00 20 01 b8 38 00 00 00 0f
05 <48> 3d 00 f0 ff ff 0f 87 b9 00 00 00 41 89 c5 85 c0 0f 85 c6 00 00
[ 1776.269067] RSP: 002b:00007fdbcd5fe660 EFLAGS: 00000246 ORIG_RAX:
0000000000000038
[ 1776.269070] RAX: ffffffffffffffda RBX: 0000000000000001 RCX:
00007fdbeb4f9a73
[ 1776.269071] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
0000000001200011
[ 1776.269072] RBP: 0000000000000001 R08: 0000000000000000 R09:
00007fdbcd600700
[ 1776.269074] R10: 00007fdbcd6009d0 R11: 0000000000000246 R12:
0000000000000004
[ 1776.269075] R13: 00007fdbeb309b70 R14: 00007fdbcd5fe768 R15:
00007fdbd7cad2e8
[ 1776.269079] </TASK>
[ 1776.269081] Kernel panic - not syncing: softlockup: hung tasks
[ 1776.269083] CPU: 10 UID: 0 PID: 3184 Comm: osms-agent Tainted: G
W L 6.12.0-rc4-g556c97f2ecbf #40
[ 1776.269086] Tainted: [W]=WARN, [L]=SOFTLOCKUP
[ 1776.269087] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.5.1 06/16/2021
[ 1776.269088] Call Trace:
[ 1776.269090] <IRQ>
[ 1776.269091] panic+0x34f/0x380
[ 1776.269095] watchdog_timer_fn+0x220/0x260
[ 1776.269098] ? __pfx_watchdog_timer_fn+0x10/0x10
[ 1776.269100] __hrtimer_run_queues+0x10c/0x270
[ 1776.269104] hrtimer_interrupt+0x109/0x250
[ 1776.269106] ? srso_alias_return_thunk+0x5/0xfbef5
[ 1776.269109] __sysvec_apic_timer_interrupt+0x55/0x120
[ 1776.269112] sysvec_apic_timer_interrupt+0x6c/0x90
[ 1776.269115] </IRQ>
[ 1776.269116] <TASK>
[ 1776.269118] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 1776.269120] RIP: 0010:smp_call_function_many_cond+0x312/0x4e0
[ 1776.269122] Code: 48 00 39 05 f0 74 fe 01 48 89 c5 0f 86 79 ff ff ff
48 63 c5 48 8b 3b 48 03 3c c5 00 8e 5a 95 66 90 8b 47 08 a8 01 74 09 f3
90 <8b> 47 08 a8 01 75 f7 83 c5 01 eb ba e8 cd f6 ff ff eb f4 83 7c 24
[ 1776.269124] RSP: 0018:ffffc0c8c2d9fc38 EFLAGS: 00000202
[ 1776.269126] RAX: 0000000000000011 RBX: ffff9ff73fb37900 RCX:
0000000000000000
[ 1776.269127] RDX: 0000000000000001 RSI: 0000000000000010 RDI:
ffff9ff73f6bd340
[ 1776.269128] RBP: 0000000000000001 R08: 0000000000000001 R09:
ffff9ff73f6bd340
[ 1776.269129] R10: 0000000000000002 R11: 0000000000000000 R12:
0000000000000001
[ 1776.269130] R13: 0000000000000001 R14: 0000000000000010 R15:
ffff9ff73f6bd340
[ 1776.269135] ? smp_call_function_many_cond+0x2ea/0x4e0
[ 1776.269137] ? __pfx_flush_tlb_func+0x10/0x10
[ 1776.269141] on_each_cpu_cond_mask+0x29/0x50
[ 1776.269143] flush_tlb_mm_range+0x13f/0x160
[ 1776.269146] dup_mmap+0x2ea/0x740
[ 1776.269152] copy_process+0x12b2/0x1d20
[ 1776.269156] kernel_clone+0x9e/0x390
[ 1776.269160] __do_sys_clone+0x66/0x90
[ 1776.269164] do_syscall_64+0x62/0x170
[ 1776.269167] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 1776.269169] RIP: 0033:0x7fdbeb4f9a73
[ 1776.269171] Code: db 0f 85 28 01 00 00 64 4c 8b 0c 25 10 00 00 00 45
31 c0 4d 8d 91 d0 02 00 00 31 d2 31 f6 bf 11 00 20 01 b8 38 00 00 00 0f
05 <48> 3d 00 f0 ff ff 0f 87 b9 00 00 00 41 89 c5 85 c0 0f 85 c6 00 00
[ 1776.269172] RSP: 002b:00007fdbcd5fe660 EFLAGS: 00000246 ORIG_RAX:
0000000000000038
[ 1776.269174] RAX: ffffffffffffffda RBX: 0000000000000001 RCX:
00007fdbeb4f9a73
[ 1776.269175] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
0000000001200011
[ 1776.269177] RBP: 0000000000000001 R08: 0000000000000000 R09:
00007fdbcd600700
[ 1776.269178] R10: 00007fdbcd6009d0 R11: 0000000000000246 R12:
0000000000000004
[ 1776.269179] R13: 00007fdbeb309b70 R14: 00007fdbcd5fe768 R15:
00007fdbd7cad2e8
[ 1776.269183] </TASK>
[ 1776.272383] Kernel Offset: 0x12c00000 from 0xffffffff81000000
(relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[ 1776.712795] ---[ end Kernel panic - not syncing: softlockup: hung
tasks ]---
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: v6.12-rc workqueue lockups
2024-10-24 22:23 ` John Garry
@ 2024-10-28 5:35 ` Dave Chinner
0 siblings, 0 replies; 8+ messages in thread
From: Dave Chinner @ 2024-10-28 5:35 UTC (permalink / raw)
To: John Garry; +Cc: Jan Kara, linux-kernel, viro, brauner, linux-fsdevel
On Thu, Oct 24, 2024 at 11:23:17PM +0100, John Garry wrote:
> On 24/10/2024 22:13, Dave Chinner wrote:
> > > > BTW, can you please share logs which would contain full stacktraces that
> > > > this softlockup reports produce? The attached dmesg is just from fresh
> > > > boot... Thanks!
> > > >
> > > thanks for getting back to me.
> > >
> > > So I think that enabling /proc/sys/kernel/softlockup_all_cpu_backtrace is
> > > required there. Unfortunately my VM often just locks up without any sign of
> > > life.
> > Attach a "serial" console to the vm - add "console=ttyS0,115600" to
> > the kernel command line and add "-serial pty" to the qemu command
> > line. You can then attach something like minicom to the /dev/pts/X
> > device that qemu creates for the console output and capture
> > everything from initial boot right through to the softlockup traces
> > that are emitted...
>
> I am using an OCI instance, so I can't change the qemu command line (as far
> as I know).
>
> For this issue, the Cloud Shell locks up also. There are other console
> connection methods, which I can try.
>
> BTW, earlier today I got this once when trying to recreate this issue:
>
> [ 1549.241972] ------------[ cut here ]------------
> [ 1609.240236] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> [ 1609.240243] rcu: 5-...!: (0 ticks this GP)
> idle=a8f4/1/0x4000000000000000 softirq=71287/71287 fqs=1
> [ 1609.240249] rcu: (detected by 2, t=60004 jiffies, g=168077, q=10823
> ncpus=16)
> [ 1609.240252] Sending NMI from CPU 2 to CPUs 5:
> [ 1609.240277] NMI backtrace for cpu 5
> [ 1609.240281] CPU: 5 UID: 1002 PID: 8250 Comm: mysqld Tainted: G W
> 6.12.0-rc4-g556c97f2ecbf #40
> [ 1609.240286] Tainted: [W]=WARN
> [ 1609.240288] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.5.1 06/16/2021
> [ 1609.240289] RIP: 0010:native_halt+0xe/0x20
> [ 1609.240296] Code: 0f 1f 84 00 00 00 00 00 0f 1f 40 00 90 90 90 90 90 90
> 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa eb 07 0f 00 2d 23 f1 17 01 f4 <e9>
> 28 c3 05 01 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90
> [ 1609.240298] RSP: 0018:ffffc0c8c71dbd20 EFLAGS: 00000046
> [ 1609.240301] RAX: 0000000000000003 RBX: ffff9ff73fab6580 RCX:
> 0000000000000008
> [ 1609.240303] RDX: ffff9ff7bffaf740 RSI: 0000000000000003 RDI:
> ffff9ff73fab6580
> [ 1609.240304] RBP: ffff9ff73f8b7440 R08: 0000000000000008 R09:
> 0000000000000074
> [ 1609.240306] R10: 0000000000000002 R11: 0000000000000000 R12:
> 0000000000000000
> [ 1609.240307] R13: 0000000000000001 R14: 0000000000000100 R15:
> 0000000000180000
> [ 1609.240311] FS: 00007f9e12600700(0000) GS:ffff9ff73f880000(0000)
> knlGS:0000000000000000
> [ 1609.240313] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1609.240315] CR2: 00007f9d63e00004 CR3: 0000001a0bc04005 CR4:
> 0000000000770ef0
> [ 1609.240319] PKRU: 55555554
> [ 1609.240320] Call Trace:
> [ 1609.240322] <NMI>
> [ 1609.240325] ? nmi_cpu_backtrace+0x98/0x110
> [ 1609.240330] ? nmi_cpu_backtrace_handler+0x11/0x20
> [ 1609.240334] ? nmi_handle+0x5c/0x150
> [ 1609.240339] ? default_do_nmi+0x4e/0x120
> [ 1609.240343] ? exc_nmi+0x137/0x1d0
> [ 1609.240347] ? end_repeat_nmi+0xf/0x53
> [ 1609.240354] ? native_halt+0xe/0x20
> [ 1609.240357] ? native_halt+0xe/0x20
> [ 1609.240360] ? native_halt+0xe/0x20
> [ 1609.240363] </NMI>
> [ 1609.240364] <TASK>
> [ 1609.240366] kvm_wait+0x47/0x60
> [ 1609.240368] __pv_queued_spin_lock_slowpath+0x255/0x370
> [ 1609.240373] _raw_spin_lock+0x29/0x30
> [ 1609.240376] raw_spin_rq_lock_nested+0x1c/0x80
> [ 1609.240381] __task_rq_lock+0x3f/0xe0
> [ 1609.240384] try_to_wake_up+0x3cf/0x640
> [ 1609.240387] ? plist_del+0x63/0xc0
> [ 1609.240391] wake_up_q+0x4d/0x90
> [ 1609.240394] futex_wake+0x154/0x180
> [ 1609.240400] do_futex+0xf8/0x1d0
> [ 1609.240404] __x64_sys_futex+0x68/0x1c0
> [ 1609.240407] ? restore_fpregs_from_fpstate+0x3c/0xa0
> [ 1609.240411] do_syscall_64+0x62/0x170
> [ 1609.240416] entry_SYSCALL_64_after_hwframe+0x76/0x7e
Yup, I'm seeing random RCU stalls as well when running a 64p
VM under hard concurrent fstests load. The serial console output is
occasionally tripping RCU stall warnings, too.
-Dave.
--
Dave Chinner
david@fromorbit.com
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2024-10-28 5:35 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-10-23 10:19 v6.12-rc workqueue lockups John Garry
2024-10-23 20:13 ` Jan Kara
2024-10-24 3:18 ` Dave Chinner
2024-10-23 20:39 ` Jan Kara
2024-10-24 9:35 ` John Garry
2024-10-24 21:13 ` Dave Chinner
2024-10-24 22:23 ` John Garry
2024-10-28 5:35 ` Dave Chinner
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox