lkrg-org / lkrg

Linux Kernel Runtime Guard
https://lkrg.org
Other
404 stars 72 forks source link

watchdog: BUG: soft lockup - CPU#0 stuck for 30s! [systemd-udevd:444] for mkosi-mainline with 5.19.0-051900rc6daily20220716-generic #209

Open solardiz opened 1 year ago

solardiz commented 1 year ago

Hopefully, this is not LKRG-related, but it is nevertheless an issue seen on our CI today (for mkosi-mainline), so recording it in here in case it repeats:

https://github.com/lkrg-org/lkrg/runs/7427152212?check_suite_focus=true

Ubuntu Kinetic Kudu (development branch) localhost ttyS0
localhost login: root (automatic login)
Welcome to Ubuntu Kinetic Kudu (development branch) (GNU/Linux 5.19.0-051900rc6daily20220716-generic x86_64)
 * Documentation:  https://help.ubuntu.com/
 * Management:     https://landscape.canonical.com/
 * Support:        https://ubuntu.com/advantage
Last login: Wed Jul 20 10:36:16 UTC 2022 on tty1
[  106.832779] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
root@localhost:~# /lkrg/.github/workflows/run-boot-tests.sh
+ '[' '!' -d /sys/module/p_lkrg ']'
+ mknod /dev/test c 10 241
+ true
[  110.619571] NET: Registered PF_VSOCK protocol family
+ dmesg -T
+ grep 'Registered.*protocol family'
+ grep -w -e PF_VSOCK -e 40
[  127.433547] [drm] pci: virtio-vga detected at 0000:00:01.0
[  127.462871] virtio-pci 0000:00:01.0: vgaarb: deactivate vga console
[  127.488917] Console: switching to colour dummy device 80x25
[  127.509747] [drm] features: -virgl +edid -resource_blob -host_visible
[  127.509842] [drm] features: -context_init
[  127.536641] [drm] number of scanouts: 1
[  127.536931] [drm] number of cap sets: 0
[Wed Jul 20 10:36:33 2022] NET: Registered PF_VSOCK protocol family
+ sleep 21
[  127.666625] [drm] Initialized virtio_gpu 0.1.0 0 for virtio0 on minor 0
[  161.321462] watchdog: BUG: soft lockup - CPU#0 stuck for 30s! [systemd-udevd:444]
[  161.322032] Modules linked in: virtio_gpu(+) virtio_dma_buf drm_shmem_helper vhost_vsock vmw_vsock_virtio_transport_common drm_kms_helper vhost vhost_iotlb vsock fb_sys_fops psmouse syscopyarea input_leds i2c_i801 sysfillrect mac_hid i2c_smbus lpc_ich sysimgblt ramoops pstore_blk reed_solomon pstore_zone mtd drm efi_pstore ip_tables x_tables crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd ahci cryptd serio_raw libahci virtio_scsi p_lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4
[  161.325394] CPU: 0 PID: 444 Comm: systemd-udevd Tainted: G           OE     5.19.0-051900rc6daily20220716-generic #202207152219
[  161.326214] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014
[  161.326951] RIP: 0010:__alloc_pages_bulk+0x4f1/0x6d0
[  161.327575] Code: ff 0f 85 a8 fd ff ff 4c 63 6d b0 44 89 db 4d 89 d4 45 85 ed 0f 84 d3 00 00 00 48 f7 45 88 00 02 00 00 74 06 fb 0f 1f 44 00 00 <4c> 89 e0 49 2b 44 24 60 48 c1 f8 09 69 c0 ab aa aa aa 44 8d 70 04
[  161.328565] RSP: 0018:ff367afd0188f6b8 EFLAGS: 00000206
[  161.328861] RAX: 0000000000000000 RBX: 0000000000000064 RCX: 0000000000000000
[  161.329263] RDX: ffed366bc02cda80 RSI: 0000000000000001 RDI: ff28c7eecb36b000
[  161.329669] RBP: ff367afd0188f750 R08: 0000000000000064 R09: 000000000000367c
[  161.330025] R10: ff28c7eefffb2600 R11: 0000000000000064 R12: ff28c7eefffb2600
[  161.330432] R13: 0000000000000064 R14: ff28c7eefec37448 R15: 0000000000000065
[  161.330963] FS:  00007fd6e28338c0(0000) GS:ff28c7eefec00000(0000) knlGS:0000000000000000
[  161.331436] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  161.331788] CR2: 00007f16fd254d60 CR3: 00000000027ec000 CR4: 00000000007516f0
[  161.332348] PKRU: 55555554
[  161.332604] Call Trace:
[  161.333461]  <TASK>
[  161.333711]  ? psi_task_switch+0xc6/0x220
[  161.334027]  alloc_pages_bulk_array_mempolicy+0xa3/0x290
[  161.334490]  vm_area_alloc_pages+0x90/0x180
[  161.334782]  __vmalloc_area_node+0xf1/0x380
[  161.335054]  __vmalloc_node_range+0xce/0x230
[  161.335348]  __vmalloc_node+0x4e/0x70
[  161.335557]  ? drm_fb_helper_generic_probe+0x10d/0x1c0 [drm_kms_helper]
[  161.336212]  vzalloc+0x21/0x30
[  161.336435]  drm_fb_helper_generic_probe+0x10d/0x1c0 [drm_kms_helper]
[  161.337166]  drm_fb_helper_single_fb_probe+0x2cd/0x470 [drm_kms_helper]
[  161.337614]  __drm_fb_helper_initial_config_and_unlock+0x41/0xd0 [drm_kms_helper]
[  161.338072]  drm_fbdev_client_hotplug+0x1d3/0x200 [drm_kms_helper]
[  161.338598]  ? drm_client_init+0x120/0x170 [drm]
[  161.339038]  drm_fbdev_generic_setup+0xd0/0x1a0 [drm_kms_helper]
[  161.339486]  virtio_gpu_probe+0xeb/0x110 [virtio_gpu]
[  161.339805]  virtio_dev_probe+0x1b6/0x2b0
[  161.340047]  really_probe+0x1d6/0x3b0
[  161.340258]  __driver_probe_device+0x119/0x190
[  161.340524]  driver_probe_device+0x23/0xc0
[  161.340812]  __driver_attach+0xbd/0x1e0
[  161.341133]  ? __device_attach_driver+0x120/0x120
[  161.341442]  bus_for_each_dev+0x7f/0xd0
[  161.341681]  driver_attach+0x1e/0x30
[  161.341889]  bus_add_driver+0x178/0x220
[  161.342143]  driver_register+0x95/0x100
[  161.342456]  ? 0xffffffffc066c000
[  161.342994]  register_virtio_driver+0x20/0x40
[  161.343261]  virtio_gpu_driver_init+0x15/0x1000 [virtio_gpu]
[  161.343587]  do_one_initcall+0x49/0x210
[  161.343827]  ? kmem_cache_alloc_trace+0x1a6/0x320
[  161.344104]  do_init_module+0x52/0x220
[  161.344326]  load_module+0xb42/0xd30
[  161.344570]  ? kernel_read_file+0x230/0x290
[  161.344861]  __do_sys_finit_module+0xc8/0x140
[  161.345158]  ? __do_sys_finit_module+0xc8/0x140
[  161.345484]  __x64_sys_finit_module+0x18/0x20
[  161.345720]  do_syscall_64+0x5c/0x90
[  161.345938]  ? do_syscall_64+0x69/0x90
[  161.346235]  ? common_interrupt+0x55/0xa0
[  161.346517]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  161.347105] RIP: 0033:0x7fd6e271ea3d
[  161.347517] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
[  161.348691] RSP: 002b:00007ffde3c98db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  161.349201] RAX: ffffffffffffffda RBX: 0000555dda3dfd40 RCX: 00007fd6e271ea3d
[  161.349647] RDX: 0000000000000000 RSI: 00007fd6e29a5441 RDI: 0000000000000015
[  161.350224] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000002
[  161.350723] R10: 0000000000000015 R11: 0000000000000246 R12: 00007fd6e29a5441
[  161.351205] R13: 0000555dda3a6420 R14: 0000555dda3e02a0 R15: 0000555dda3e1f90
[  161.351754]  </TASK>
[  161.352278] Kernel panic - not syncing: softlockup: hung tasks
[  161.352843] CPU: 0 PID: 444 Comm: systemd-udevd Tainted: G           OEL    5.19.0-051900rc6daily20220716-generic #202207152219
[  161.353492] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014
[  161.354017] Call Trace:
[  161.354329]  <IRQ>
[  161.354486]  show_stack+0x52/0x5c
[  161.354731]  dump_stack_lvl+0x49/0x63
[  161.355074]  dump_stack+0x10/0x16
[  161.355361]  panic+0x162/0x2fb
[  161.355550]  watchdog_timer_fn.cold+0xc/0x16
[  161.355833]  ? lockup_detector_update_enable+0x60/0x60
[  161.356300]  __hrtimer_run_queues+0x109/0x260
[  161.356826]  ? clockevents_program_event+0xad/0x130
[  161.357325]  hrtimer_interrupt+0x101/0x220
[  161.357657]  __sysvec_apic_timer_interrupt+0x64/0x110
[  161.358049]  sysvec_apic_timer_interrupt+0x7b/0x90
[  161.358480]  </IRQ>
[  161.358677]  <TASK>
[  161.358856]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  161.359279] RIP: 0010:__alloc_pages_bulk+0x4f1/0x6d0
[  161.359633] Code: ff 0f 85 a8 fd ff ff 4c 63 6d b0 44 89 db 4d 89 d4 45 85 ed 0f 84 d3 00 00 00 48 f7 45 88 00 02 00 00 74 06 fb 0f 1f 44 00 00 <4c> 89 e0 49 2b 44 24 60 48 c1 f8 09 69 c0 ab aa aa aa 44 8d 70 04
[  161.360937] RSP: 0018:ff367afd0188f6b8 EFLAGS: 00000206
[  161.361320] RAX: 0000000000000000 RBX: 0000000000000064 RCX: 0000000000000000
[  161.361934] RDX: ffed366bc02cda80 RSI: 0000000000000001 RDI: ff28c7eecb36b000
[  161.362445] RBP: ff367afd0188f750 R08: 0000000000000064 R09: 000000000000367c
[  161.362911] R10: ff28c7eefffb2600 R11: 0000000000000064 R12: ff28c7eefffb2600
[  161.363398] R13: 0000000000000064 R14: ff28c7eefec37448 R15: 0000000000000065
[  161.364020]  ? __alloc_pages_bulk+0x2f6/0x6d0
[  161.364343]  ? psi_task_switch+0xc6/0x220
[  161.364746]  alloc_pages_bulk_array_mempolicy+0xa3/0x290
[  161.365186]  vm_area_alloc_pages+0x90/0x180
[  161.365487]  __vmalloc_area_node+0xf1/0x380
[  161.365908]  __vmalloc_node_range+0xce/0x230
[  161.366253]  __vmalloc_node+0x4e/0x70
[  161.366518]  ? drm_fb_helper_generic_probe+0x10d/0x1c0 [drm_kms_helper]
[  161.367111]  vzalloc+0x21/0x30
[  161.367366]  drm_fb_helper_generic_probe+0x10d/0x1c0 [drm_kms_helper]
[  161.367846]  drm_fb_helper_single_fb_probe+0x2cd/0x470 [drm_kms_helper]
[  161.368390]  __drm_fb_helper_initial_config_and_unlock+0x41/0xd0 [drm_kms_helper]
[  161.369005]  drm_fbdev_client_hotplug+0x1d3/0x200 [drm_kms_helper]
[  161.369499]  ? drm_client_init+0x120/0x170 [drm]
[  161.370013]  drm_fbdev_generic_setup+0xd0/0x1a0 [drm_kms_helper]
[  161.370535]  virtio_gpu_probe+0xeb/0x110 [virtio_gpu]
[  161.370975]  virtio_dev_probe+0x1b6/0x2b0
[  161.371354]  really_probe+0x1d6/0x3b0
[  161.371618]  __driver_probe_device+0x119/0x190
[  161.371939]  driver_probe_device+0x23/0xc0
[  161.372228]  __driver_attach+0xbd/0x1e0
[  161.373028]  ? __device_attach_driver+0x120/0x120
[  161.373327]  bus_for_each_dev+0x7f/0xd0
[  161.373576]  driver_attach+0x1e/0x30
[  161.373797]  bus_add_driver+0x178/0x220
[  161.374156]  driver_register+0x95/0x100
[  161.374437]  ? 0xffffffffc066c000
[  161.374662]  register_virtio_driver+0x20/0x40
[  161.374922]  virtio_gpu_driver_init+0x15/0x1000 [virtio_gpu]
[  161.375245]  do_one_initcall+0x49/0x210
[  161.375481]  ? kmem_cache_alloc_trace+0x1a6/0x320
[  161.375755]  do_init_module+0x52/0x220
[  161.375971]  load_module+0xb42/0xd30
[  161.376192]  ? kernel_read_file+0x230/0x290
ABORT
[  161.376598]  __do_sys_finit_module+0xc8/0x140
[  161.377153]  ? __do_sys_finit_module+0xc8/0x140
[  161.377472]  __x64_sys_finit_module+0x18/0x20
[  161.377883]  do_syscall_64+0x5c/0x90
[  161.378148]  ? do_syscall_64+0x69/0x90
[  161.378369]  ? common_interrupt+0x55/0xa0
[  161.378611]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  161.378920] RIP: 0033:0x7fd6e271ea3d
[  161.379189] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
[  161.380081] RSP: 002b:00007ffde3c98db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  161.380401] RAX: ffffffffffffffda RBX: 0000555dda3dfd40 RCX: 00007fd6e271ea3d
[  161.380856] RDX: 0000000000000000 RSI: 00007fd6e29a5441 RDI: 0000000000000015
[  161.381308] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000002
[  161.381705] R10: 0000000000000015 R11: 0000000000000246 R12: 00007fd6e29a5441
[  161.382213] R13: 0000555dda3a6420 R14: 0000555dda3e02a0 R15: 0000555dda3e1f90
[  161.382733]  </TASK>
[  161.383716] Kernel Offset: 0x31200000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
solardiz commented 1 year ago

Here's another, also for mainline with slightly newer kernel: https://github.com/solardiz/lkrg/runs/7568173574?check_suite_focus=true

Ubuntu Kinetic Kudu (development branch) localhost ttyS0

localhost login: root (automatic login)

Welcome to Ubuntu Kinetic Kudu (development branch) (GNU/Linux 5.19.0-051900rc8daily20220727-generic x86_64)

 * Documentation:  https://help.ubuntu.com/
 * Management:     https://landscape.canonical.com/
 * Support:        https://ubuntu.com/advantage
Last login: Thu Jul 28 20:45:39 UTC 2022 on tty1
[  102.621423] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
root@localhost:~# /lkrg/.github/workflows/run-boot-tests.sh
+ '[' '!' -d /sys/module/lkrg ']'
+ mknod /dev/test c 10 241
+ true
[  104.614838] NET: Registered PF_VSOCK protocol family
+ dmesg -T
+ grep 'Registered.*protocol family'
+ grep -w -e PF_VSOCK -e 40
[Thu Jul 28 20:45:55 2022] NET: Registered PF_VSOCK protocol family
+ sleep 21
[  120.010711] [drm] pci: virtio-vga detected at 0000:00:01.0
[  120.022843] virtio-pci 0000:00:01.0: vgaarb: deactivate vga console
[  120.040852] Console: switching to colour dummy device 80x25
[  120.059741] [drm] features: -virgl +edid -resource_blob -host_visible
[  120.059846] [drm] features: -context_init
[  120.079201] [drm] number of scanouts: 1
[  120.079522] [drm] number of cap sets: 0
[  120.126672] [drm] Initialized virtio_gpu 0.1.0 0 for virtio0 on minor 0
[  150.873167] watchdog: BUG: soft lockup - CPU#0 stuck for 27s! [systemd-udevd:447]
[  150.873660] Modules linked in: virtio_gpu(+) virtio_dma_buf drm_shmem_helper drm_kms_helper vhost_vsock vmw_vsock_virtio_transport_common vhost vhost_iotlb vsock fb_sys_fops psmouse syscopyarea input_leds i2c_i801 sysfillrect mac_hid lpc_ich i2c_smbus sysimgblt ramoops pstore_blk reed_solomon pstore_zone mtd drm efi_pstore ip_tables x_tables crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd ahci cryptd libahci serio_raw virtio_scsi lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4
[  150.876390] CPU: 0 PID: 447 Comm: systemd-udevd Tainted: G           OE     5.19.0-051900rc8daily20220727-generic #202207262221
[  150.877046] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014
[  150.877607] RIP: 0010:__alloc_pages_bulk+0x4f1/0x6d0
[  150.878231] Code: ff 0f 85 a8 fd ff ff 4c 63 6d b0 44 89 db 4d 89 d4 45 85 ed 0f 84 d3 00 00 00 48 f7 45 88 00 02 00 00 74 06 fb 0f 1f 44 00 00 <4c> 89 e0 49 2b 44 24 60 48 c1 f8 09 69 c0 ab aa aa aa 44 8d 70 04
[  150.879157] RSP: 0018:ff7e853701897a80 EFLAGS: 00000206
[  150.879458] RAX: 0000000000000000 RBX: 0000000000000046 RCX: 0000000000000000
[  150.879812] RDX: fff211ccc0303580 RSI: 0000000000000001 RDI: ff4f652b4c0d7000
[  150.880144] RBP: ff7e853701897b18 R08: 0000000000000046 R09: 000000000000365b
[  150.880475] R10: ff4f652b7ffb2600 R11: 0000000000000046 R12: ff4f652b7ffb2600
[  150.880824] R13: 0000000000000046 R14: ff4f652b7ec37448 R15: 0000000000000047
[  150.881355] FS:  00007fcb3ea9c8c0(0000) GS:ff4f652b7ec00000(0000) knlGS:0000000000000000
[  150.881826] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  150.882142] CR2: 00007f990d6bcf20 CR3: 00000000071be000 CR4: 00000000007516f0
[  150.882644] PKRU: 55555554
[  150.882887] Call Trace:
[  150.883549]  <TASK>
[  150.883812]  ? psi_task_switch+0xc6/0x220
[  150.884126]  alloc_pages_bulk_array_mempolicy+0xa3/0x290
[  150.884550]  vm_area_alloc_pages+0x90/0x180
[  150.884791]  ? __kmalloc_node+0x1c4/0x3e0
[  150.885055]  __vmalloc_area_node+0xf1/0x380
[  150.885286]  __vmalloc_node_range+0xce/0x230
[  150.885488]  ? 0xffffffffc02bb000
[  150.885925]  ? move_module+0x23/0x170
[  150.886127]  module_alloc+0x82/0xe0
[  150.886320]  ? move_module+0x23/0x170
[  150.886511]  move_module+0x23/0x170
[  150.886702]  layout_and_allocate+0xde/0x120
[  150.886926]  load_module+0x2d6/0xd30
[  150.887115]  ? kernel_read_file+0x230/0x290
[  150.887373]  __do_sys_finit_module+0xc8/0x140
[  150.887603]  ? __do_sys_finit_module+0xc8/0x140
[  150.887864]  __x64_sys_finit_module+0x18/0x20
[  150.888089]  do_syscall_64+0x5c/0x90
[  150.888289]  ? syscall_exit_to_user_mode+0x26/0x50
[  150.888529]  ? __x64_sys_lseek+0x18/0x20
[  150.888735]  ? do_syscall_64+0x69/0x90
[  150.888936]  ? irqentry_exit+0x3b/0x50
[  150.889156]  ? exc_page_fault+0x87/0x180
[  150.889365]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  150.889753] RIP: 0033:0x7fcb3e91ea3d
[  150.890097] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
[  150.890685] RSP: 002b:00007ffd90466c98 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  150.891090] RAX: ffffffffffffffda RBX: 000055a54123b9b0 RCX: 00007fcb3e91ea3d
[  150.891567] RDX: 0000000000000000 RSI: 00007fcb3eb5f441 RDI: 0000000000000006
[  150.891877] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000002
ABORT
[  150.892190] R10: 0000000000000006 R11: 0000000000000246 R12: 00007fcb3eb5f441
[  150.892459] R13: 000055a54123ad80 R14: 000055a54123a4c0 R15: 000055a54123bc60
[  150.892856]  </TASK>
[  150.893317] Kernel panic - not syncing: softlockup: hung tasks
[  150.893773] CPU: 0 PID: 447 Comm: systemd-udevd Tainted: G           OEL    5.19.0-051900rc8daily20220727-generic #202207262221
[  150.894325] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1 04/01/2014
[  150.894811] Call Trace:
[  150.895089]  <IRQ>
[  150.895222]  show_stack+0x52/0x5c
[  150.895425]  dump_stack_lvl+0x49/0x63
[  150.895666]  dump_stack+0x10/0x16
[  150.895846]  panic+0x162/0x2fb
[  150.896036]  watchdog_timer_fn.cold+0xc/0x16
[  150.896261]  ? lockup_detector_update_enable+0x60/0x60
[  150.896524]  __hrtimer_run_queues+0x109/0x260
[  150.896751]  ? clockevents_program_event+0xad/0x130
[  150.897045]  hrtimer_interrupt+0x101/0x220
[  150.897271]  __sysvec_apic_timer_interrupt+0x64/0x110
[  150.897553]  sysvec_apic_timer_interrupt+0x7b/0x90
[  150.897867]  </IRQ>
[  150.897991]  <TASK>
[  150.898114]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  150.898430] RIP: 0010:__alloc_pages_bulk+0x4f1/0x6d0
[  150.898708] Code: ff 0f 85 a8 fd ff ff 4c 63 6d b0 44 89 db 4d 89 d4 45 85 ed 0f 84 d3 00 00 00 48 f7 45 88 00 02 00 00 74 06 fb 0f 1f 44 00 00 <4c> 89 e0 49 2b 44 24 60 48 c1 f8 09 69 c0 ab aa aa aa 44 8d 70 04
[  150.899522] RSP: 0018:ff7e853701897a80 EFLAGS: 00000206
[  150.899780] RAX: 0000000000000000 RBX: 0000000000000046 RCX: 0000000000000000
[  150.900105] RDX: fff211ccc0303580 RSI: 0000000000000001 RDI: ff4f652b4c0d7000
[  150.900429] RBP: ff7e853701897b18 R08: 0000000000000046 R09: 000000000000365b
[  150.900763] R10: ff4f652b7ffb2600 R11: 0000000000000046 R12: ff4f652b7ffb2600
[  150.901134] R13: 0000000000000046 R14: ff4f652b7ec37448 R15: 0000000000000047
[  150.901620]  ? psi_task_switch+0xc6/0x220
[  150.901887]  alloc_pages_bulk_array_mempolicy+0xa3/0x290
[  150.902165]  vm_area_alloc_pages+0x90/0x180
[  150.902378]  ? __kmalloc_node+0x1c4/0x3e0
[  150.902620]  __vmalloc_area_node+0xf1/0x380
[  150.902859]  __vmalloc_node_range+0xce/0x230
[  150.903085]  ? 0xffffffffc02bb000
[  150.903278]  ? move_module+0x23/0x170
[  150.903476]  module_alloc+0x82/0xe0
[  150.903670]  ? move_module+0x23/0x170
[  150.903863]  move_module+0x23/0x170
[  150.904054]  layout_and_allocate+0xde/0x120
[  150.904277]  load_module+0x2d6/0xd30
[  150.904469]  ? kernel_read_file+0x230/0x290
[  150.904699]  __do_sys_finit_module+0xc8/0x140
[  150.904926]  ? __do_sys_finit_module+0xc8/0x140
[  150.905194]  __x64_sys_finit_module+0x18/0x20
[  150.905427]  do_syscall_64+0x5c/0x90
[  150.905620]  ? syscall_exit_to_user_mode+0x26/0x50
[  150.905884]  ? __x64_sys_lseek+0x18/0x20
[  150.906090]  ? do_syscall_64+0x69/0x90
[  150.906277]  ? irqentry_exit+0x3b/0x50
[  150.906482]  ? exc_page_fault+0x87/0x180
[  150.906692]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  150.906960] RIP: 0033:0x7fcb3e91ea3d
[  150.907158] Code: 5b 41 5c c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c3 a3 0f 00 f7 d8 64 89 01 48
[  150.907930] RSP: 002b:00007ffd90466c98 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  150.908169] RAX: ffffffffffffffda RBX: 000055a54123b9b0 RCX: 00007fcb3e91ea3d
[  150.908477] RDX: 0000000000000000 RSI: 00007fcb3eb5f441 RDI: 0000000000000006
[  150.908872] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000002
[  150.909205] R10: 0000000000000006 R11: 0000000000000246 R12: 00007fcb3eb5f441
[  150.909558] R13: 000055a54123ad80 R14: 000055a54123a4c0 R15: 000055a54123bc60
[  150.909928]  </TASK>
[  150.910778] Kernel Offset: 0xb400000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
solardiz commented 1 year ago

We didn't see these for months, but today here's another, which could be same or different:

https://github.com/lkrg-org/lkrg/actions/runs/3362987970/jobs/5575472489

[   18.937677] LKRG: ALIVE: Loading LKRG
[   18.966356] Freezing user space processes ... (elapsed 0.003 seconds) done.
[   18.975068] OOM killer disabled.
[   20.421013] LKRG: ISSUE: [kretprobe] register_kretprobe() for <ovl_dentry_is_whiteout> failed! [err=-2]
[   20.421638] LKRG: ISSUE: Can't hook 'ovl_dentry_is_whiteout'. This is expected when OverlayFS is not used.
[   21.909126] LKRG: ALIVE: LKRG initialized successfully
[   22.039814] OOM killer enabled.
[   22.040096] Restarting tasks ... done.
[  OK  ] Finished dracut pre-udev hook.
         Starting Rule-based Manage…for Device Events and Files...
[  OK  ] Started Rule-based Manager for Device Events and Files.
         Starting Coldplug All udev Devices...
[***   ] (1 of 2) A start job is running for… All udev Devices (12s / no limit)
[ ***  ] (2 of 2) A start job is running for…dev/gpt-auto-root (12s / 1min 30s)
[  OK  ] Finished Coldplug All udev Devices.
[  OK  ] Reached target System Initialization.
[  OK  ] Reached target Basic System.
         Starting dracut initqueue hook...
[  OK  ] Finished dracut initqueue hook.
[  OK  ] Reached target Preparation for Remote File Systems.
[  OK  ] Reached target Remote Encrypted Volumes.
[  OK  ] Reached target Remote File Systems.
[  *** ] A start job is running for /dev/gpt-auto-root (16s / 1min 30s)
[   ***] A start job is running for /dev/gpt-auto-root (16s / 1min 30s)
[    **] A start job is running for /dev/gpt-auto-root (17s / 1min 30s)
[   30.794403] scsi host0: Virtio SCSI HBA
[   30.874081] scsi 0:0:0:0: Direct-Access     QEMU     QEMU HARDDISK    2.5+ PQ: 0 ANSI: 5
[   31.107735] cryptd: max_cpu_qlen set to 1000
[     *] A start job is running for /dev/gpt-auto-root (18s / 1min 30s)
[   31.544419] sd 0:0:0:0: Power-on or device reset occurred
[   31.554285] sd 0:0:0:0: [sda] 8912976 512-byte logical blocks: (4.56 GB/4.25 GiB)
[   31.556180] sd 0:0:0:0: Attached scsi generic sg0 type 0
[   31.563730] sd 0:0:0:0: [sda] Write Protect is off
[   31.564007] sd 0:0:0:0: [sda] Mode Sense: 63 00 00 08
[   31.569437] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   31.640863]  sda: sda1 sda2
[   31.649851] sd 0:0:0:0: [sda] Attached SCSI disk
[    **] A start job is running for /dev/gpt-auto-root (18s / 1min 30s)
[   32.095928] ahci 0000:00:1f.2: version 3.0
[   32.117035] ACPI: \_SB_.GSIA: Enabled at IRQ 16
[   32.143870] ahci 0000:00:1f.2: AHCI 0001.0000 32 slots 6 ports 1.5 Gbps 0x3f impl SATA mode
[   32.144386] ahci 0000:00:1f.2: flags: 64bit ncq only 
[   32.399681] scsi host1: ahci
[   32.419668] scsi host2: ahci
[   ***] A start job is running for /dev/gpt-auto-root (19s / 1min 30s)
[   32.463800] scsi host3: ahci
[   32.483570] scsi host4: ahci
[   32.515674] scsi host5: ahci
[   32.543374] scsi host6: ahci
[   32.545106] ata1: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000100 irq 28
[   32.545552] ata2: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000180 irq 28
[   32.545899] ata3: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000200 irq 28
[   32.546246] ata4: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000280 irq 28
[   32.546579] ata5: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000300 irq 28
[   32.546912] ata6: SATA max UDMA/133 abar m4096@0xc0000000 port 0xc0000380 irq 28
[   32.870171] ata3: SATA link down (SStatus 0 SControl 300)
[   32.873832] ata2: SATA link down (SStatus 0 SControl 300)
[   32.874815] ata1: SATA link down (SStatus 0 SControl 300)
[   32.875388] ata4: SATA link down (SStatus 0 SControl 300)
[   32.881207] ata5: SATA link down (SStatus 0 SControl 300)
[   32.885392] ata6: SATA link down (SStatus 0 SControl 300)
[   32.953785] SSE version of gcm_enc/dec engaged.
[  *** ] A start job is running for /dev/gpt-auto-root (19s / 1min 30s)
[ ***  ] A start job is running for /dev/gpt-auto-root (20s / 1min 30s)
[***   ] A start job is running for /dev/gpt-auto-root (21s / 1min 30s)
[**    ] A start job is running for /dev/gpt-auto-root (21s / 1min 30s)
[  OK  ] Found device QEMU_HARDDISK root.
[  OK  ] Reached target Initrd Root Device.
         Starting File System Check on /dev/gpt-auto-root...
[  OK  ] Finished File System Check on /dev/gpt-auto-root.
         Mounting Root Partition...
[   36.156298] EXT4-fs (sda2): mounted filesystem with ordered data mode. Quota mode: none.
[  OK  ] Mounted Root Partition.
[  OK  ] Reached target Initrd Root File System.
         Starting Reload Configuration from the Real Root...
[  OK  ] Finished Reload Configuration from the Real Root.
[  OK  ] Reached target Initrd File Systems.
[  OK  ] Reached target Initrd Default Target.
         Starting dracut pre-pivot and cleanup hook...
[  OK  ] Finished dracut pre-pivot and cleanup hook.
         Starting Cleaning Up and Shutting Down Daemons...
[  OK  ] Stopped target Remote Encrypted Volumes.
[  OK  ] Stopped target Timer Units.
[  OK  ] Stopped dracut pre-pivot and cleanup hook.
[  OK  ] Stopped target Initrd Default Target.
[  OK  ] Stopped target Basic System.
[  OK  ] Stopped target Initrd Root Device.
[  OK  ] Stopped target Initrd /usr File System.
[  OK  ] Stopped target Path Units.
[  OK  ] Stopped target Remote File Systems.
[  OK  ] Stopped target Preparation for Remote File Systems.
[  OK  ] Stopped target Slice Units.
[  OK  ] Stopped target Socket Units.
[  OK  ] Stopped target System Initialization.
[  OK  ] Stopped target Local Encrypted Volumes.
[  OK  ] Stopped Dispatch Password …ts to Console Directory Watch.
[  OK  ] Stopped target Swaps.
[  OK  ] Stopped target Local Verity Protected Volumes.
[  OK  ] Stopped dracut initqueue hook.
[  OK  ] Stopped Apply Kernel Variables.
[  OK  ] Stopped Create Volatile Files and Directories.
[  OK  ] Stopped target Local File Systems.
[  OK  ] Stopped Coldplug All udev Devices.
         Stopping Rule-based Manage…for Device Events and Files...
[  OK  ] Stopped Rule-based Manager for Device Events and Files.
[  OK  ] Closed udev Control Socket.
[  OK  ] Closed udev Kernel Socket.
[  OK  ] Stopped dracut pre-udev hook.
[  OK  ] Stopped dracut cmdline hook.
[  OK  ] Stopped dracut ask for additional cmdline parameters.
         Starting Cleanup udev Database...
[  OK  ] Stopped Create Static Device Nodes in /dev.
[  OK  ] Stopped Create List of Static Device Nodes.
[  OK  ] Finished Cleaning Up and Shutting Down Daemons.
[  OK  ] Finished Cleanup udev Database.
[  OK  ] Reached target Switch Root.
         Starting Switch Root...
[   42.165378] systemd-journald[142]: Received SIGTERM from PID 1 (systemd).
[   43.916046] systemd[1]: systemd 251.4-1ubuntu7 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[   43.919827] systemd[1]: Detected virtualization qemu.
[   43.920539] systemd[1]: Detected architecture x86-64.
[   43.922412] systemd[1]: Detected first boot.

Welcome to Ubuntu 22.10!

[   51.108945] systemd[1]: Populated /etc with preset unit settings.
[   53.807327] systemd[1]: initrd-switch-root.service: Deactivated successfully.
[   53.812009] systemd[1]: Stopped Switch Root.
[  OK  ] Stopped Switch Root.
[   53.822719] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
[   53.835954] systemd[1]: Created slice Slice /system/getty.
[  OK  ] Created slice Slice /system/getty.
[   53.844628] systemd[1]: Created slice Slice /system/modprobe.
[  OK  ] Created slice Slice /system/modprobe.
[   53.852486] systemd[1]: Created slice Slice /system/serial-getty.
[  OK  ] Created slice Slice /system/serial-getty.
[   53.860165] systemd[1]: Created slice User and Session Slice.
[  OK  ] Created slice User and Session Slice.
[   53.865235] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started Dispatch Password …ts to Console Directory Watch.
[   53.869695] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[  OK  ] Started Forward Password R…uests to Wall Directory Watch.
[   53.878491] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[  OK  ] Set up automount Arbitrary…s File System Automount Point.
[   53.881423] systemd[1]: Reached target Local Encrypted Volumes.
[  OK  ] Reached target Local Encrypted Volumes.
[   53.883382] systemd[1]: Stopped target Switch Root.
[  OK  ] Stopped target Switch Root.
[   53.885082] systemd[1]: Stopped target Initrd File Systems.
[  OK  ] Stopped target Initrd File Systems.
[   53.886610] systemd[1]: Stopped target Initrd Root File System.
[  OK  ] Stopped target Initrd Root File System.
[   53.888113] systemd[1]: Reached target Local Integrity Protected Volumes.
[  OK  ] Reached target Local Integrity Protected Volumes.
[   53.890311] systemd[1]: Reached target Path Units.
[  OK  ] Reached target Path Units.
[   53.892166] systemd[1]: Reached target Remote Encrypted Volumes.
[  OK  ] Reached target Remote Encrypted Volumes.
[   53.893558] systemd[1]: Reached target Remote File Systems.
[  OK  ] Reached target Remote File Systems.
[   53.895191] systemd[1]: Reached target Remote Verity Protected Volumes.
[  OK  ] Reached target Remote Verity Protected Volumes.
[   53.896717] systemd[1]: Reached target Slice Units.
[  OK  ] Reached target Slice Units.
[   53.898059] systemd[1]: Reached target Swaps.
[  OK  ] Reached target Swaps.
[   53.900059] systemd[1]: Reached target Local Verity Protected Volumes.
[  OK  ] Reached target Local Verity Protected Volumes.
[   53.905834] systemd[1]: Listening on fsck to fsckd communication Socket.
[  OK  ] Listening on fsck to fsckd communication Socket.
[   53.909089] systemd[1]: Listening on initctl Compatibility Named Pipe.
[  OK  ] Listening on initctl Compatibility Named Pipe.
[   53.914372] systemd[1]: Listening on Network Service Netlink Socket.
[  OK  ] Listening on Network Service Netlink Socket.
[   53.919261] systemd[1]: Listening on udev Control Socket.
[  OK  ] Listening on udev Control Socket.
[   53.923506] systemd[1]: Listening on udev Kernel Socket.
[  OK  ] Listening on udev Kernel Socket.
[   53.956681] systemd[1]: Mounting Huge Pages File System...
         Mounting Huge Pages File System...
[   54.008040] systemd[1]: Mounting POSIX Message Queue File System...
         Mounting POSIX Message Queue File System...
[   54.076395] systemd[1]: Mounting Kernel Debug File System...
         Mounting Kernel Debug File System...
[   54.172470] systemd[1]: Mounting Kernel Trace File System...
         Mounting Kernel Trace File System...
[   54.181510] systemd[1]: Stopped Journal Service.
[  OK  ] Stopped Journal Service.
[   54.207609] systemd[1]: systemd-journald.service: Consumed 1.038s CPU time.
[   54.384523] systemd[1]: Journal Audit Socket was skipped because of a failed condition check (ConditionSecurity=audit).
[   54.385924] systemd[1]: Reached target Socket Units.
[  OK  ] Reached target Socket Units.
[   55.041611] systemd[1]: Starting Journal Service...
         Starting Journal Service...
[   55.109219] systemd[1]: Starting Create List of Static Device Nodes...
         Starting Create List of Static Device Nodes...
[   55.200775] systemd[1]: Starting Load Kernel Module chromeos_pstore...
         Starting Load Kernel Module chromeos_pstore...
[   55.317130] systemd[1]: Starting Load Kernel Module configfs...
         Starting Load Kernel Module configfs...
[   55.456804] systemd[1]: Starting Load Kernel Module drm...
         Starting Load Kernel Module drm...
[   55.600673] systemd[1]: Starting Load Kernel Module efi_pstore...
         Starting Load Kernel Module efi_pstore...
[   55.761079] systemd[1]: Starting Load Kernel Module fuse...
         Starting Load Kernel Module fuse...
[   56.064907] systemd[1]: Starting Load Kernel Module pstore_blk...
         Starting Load Kernel Module pstore_blk...
[   56.212730] systemd[1]: Starting Load Kernel Module pstore_zone...
         Starting Load Kernel Module pstore_zone...
[   56.438249] pstore: Using crash dump compression: deflate
[   56.469056] systemd[1]: Starting Load Kernel Module ramoops...
         Starting Load Kernel Module ramoops...
[   56.544457] pstore: Registered efi as persistent store backend
[   56.813283] systemd[1]: Starting Load Kernel Modules...
         Starting Load Kernel Modules...
[   57.137138] systemd[1]: Starting Generate network units from Kernel command line...
         Starting Generate network …ts from Kernel command line...
[   57.309623] systemd[1]: Starting Remount Root and Kernel File Systems...
         Starting Remount Root and Kernel File Systems...
[   57.348891] systemd[1]: Repartition Root Disk was skipped because all trigger condition checks failed.
[   57.729753] systemd[1]: Starting Coldplug All udev Devices...
         Starting Coldplug All udev Devices...
[   58.081242] systemd[1]: Started Journal Service.
[  OK  ] Started Journal Service.
[   58.111954] ACPI: bus type drm_connector registered
[  OK  ] Mounted Huge Pages File System.
[  OK  ] Mounted POSIX Message Queue File System.
[  OK  ] Mounted Kernel Debug File System.
[  OK  ] Mounted Kernel Trace File System.
[  OK  ] Finished Create List of Static Device Nodes.
[  OK  ] Finished Load Kernel Module chromeos_pstore.
[  OK  ] Finished Load Kernel Module configfs.
[  OK  ] Finished Load Kernel Module efi_pstore.
[  OK  ] Finished Load Kernel Module fuse.
[  OK  ] Finished Load Kernel Module pstore_zone.
[  OK  ] Finished Load Kernel Modules.
[  OK  ] Finished Generate network units from Kernel command line.
[  OK  ] Finished Remount Root and Kernel File Systems.
[  OK  ] Reached target Preparation for Network.
         Mounting FUSE Control File System...
         Mounting Kernel Configuration File System...
         Starting Flush Journal to Persistent Storage...
         Starting Load/Save Random Seed...
[   60.035201] systemd-journald[382]: Received client request to flush runtime journal.
         Starting Apply Kernel Variables...
         Starting Create System Users...
[  OK  ] Finished Load Kernel Module drm.
[  OK  ] Finished Load Kernel Module pstore_blk.
[  OK  ] Finished Load Kernel Module ramoops.
[  OK  ] Mounted FUSE Control File System.
[  OK  ] Mounted Kernel Configuration File System.
[  OK  ] Finished Load/Save Random Seed.
[  OK  ] Reached target First Boot Complete.
[  OK  ] Finished Apply Kernel Variables.
[  OK  ] Finished Flush Journal to Persistent Storage.
[  OK  ] Finished Create System Users.
         Starting Create Static Device Nodes in /dev...
[  OK  ] Finished Create Static Device Nodes in /dev.
[  OK  ] Reached target Preparation for Local File Systems.
[  OK  ] Set up automount EFI System Partition Automount.
[  OK  ] Reached target Local File Systems.
         Starting Restore /run/initramfs on shutdown...
         Starting Automatic Boot Loader Update...
         Starting Commit a transient machine-id on disk...
         Starting Create Volatile Files and Directories...
         Starting Rule-based Manage…for Device Events and Files...
[  OK  ] Finished Restore /run/initramfs on shutdown.
[  OK  ] Finished Commit a transient machine-id on disk.
[  OK  ] Finished Create Volatile Files and Directories.
         Starting Network Name Resolution...
         Starting Record System Boot/Shutdown in UTMP...
[  OK  ] Finished Record System Boot/Shutdown in UTMP.
[  OK  ] Started Rule-based Manager for Device Events and Files.
         Starting Network Configuration...
[  OK  ] Finished Coldplug All udev Devices.
[*     ] (1 of 5) A start job is running for…k Name Resolution (18s / 1min 42s)
[**    ] (1 of 5) A start job is running for…k Name Resolution (18s / 1min 42s)
[   93.592768] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [modprobe:421]
[   93.593295] Modules linked in: ramoops pstore_blk reed_solomon drm pstore_zone efi_pstore ip_tables x_tables crct10dif_pclmul crc32_pclmul polyval_generic ghash_clmulni_intel sha512_ssse3 aesni_intel crypto_simd ahci cryptd serio_raw libahci virtio_scsi lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4
[   93.595230] CPU: 0 PID: 421 Comm: modprobe Tainted: G           OE      6.1.0-060100rc3daily20221031-generic #202210302201
[   93.595862] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[   93.596361] RIP: 0010:_raw_spin_unlock_irqrestore+0x21/0x60
[   93.597021] Code: 0f 1f 84 00 00 00 00 00 90 0f 1f 44 00 00 55 49 89 f0 48 89 e5 c6 07 00 0f 1f 00 41 f7 c0 00 02 00 00 74 06 fb 0f 1f 44 00 00 <65> ff 0d e8 12 f0 46 74 13 5d 31 c0 31 d2 31 c9 31 f6 31 ff 45 31
[   93.597883] RSP: 0018:ff383b6181a63a78 EFLAGS: 00000206
[   93.598180] RAX: 0000000000000064 RBX: 0000000000000064 RCX: 0000000000000000
[   93.598503] RDX: ffb2c5ef402ba6c8 RSI: 0000000000000282 RDI: ff32a1b0fc237580
[   93.598822] RBP: ff383b6181a63a78 R08: 0000000000000282 R09: 0000000000000000
[   93.599150] R10: ff383b6181a55640 R11: 0000000000000064 R12: ff32a1b0fc237580
[   93.599518] R13: ff32a1b0fef6a600 R14: 0000000000000064 R15: ff32a1b0fc237580
[   93.599958] FS:  00007f18e8a61040(0000) GS:ff32a1b0fc200000(0000) knlGS:0000000000000000
[   93.600316] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   93.600571] CR2: 0000562643e43078 CR3: 000000000dc22000 CR4: 00000000007516f0
[   93.601027] PKRU: 55555554
[   93.601267] Call Trace:
[   93.601909]  <TASK>
[   93.602159]  __alloc_pages_bulk+0x5af/0x850
[   93.602574]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[   93.602864]  vm_area_alloc_pages+0x8d/0x190
[   93.603066]  __vmalloc_area_node+0xe1/0x3a0
[   93.603261]  __vmalloc_node_range+0xda/0x220
[   93.603469]  __vmalloc_node+0x4e/0x80
[   93.603669]  ? kernel_read_file+0x2b1/0x320
[   93.603891]  vmalloc+0x21/0x40
[   93.604047]  kernel_read_file+0x2b1/0x320
[   93.604278]  kernel_read_file_from_fd+0x5d/0xc0
[   93.604509]  __do_sys_finit_module+0x93/0x140
[   93.604734]  __x64_sys_finit_module+0x18/0x30
[   93.604974]  do_syscall_64+0x5b/0x90
[   93.605150]  ? exit_to_user_mode_prepare+0x30/0xb0
[   93.605432]  ? syscall_exit_to_user_mode+0x29/0x50
[   93.605675]  ? do_syscall_64+0x67/0x90
[   93.605867]  ? syscall_exit_to_user_mode+0x29/0x50
[   93.606085]  ? do_syscall_64+0x67/0x90
[   93.606260]  ? do_syscall_64+0x67/0x90
[   93.606582]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[   93.606979] RIP: 0033:0x7f18e8316c4d
[   93.607509] Code: 5d c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 83 f1 0d 00 f7 d8 64 89 01 48
[   93.608223] RSP: 002b:00007ffe0e70f3e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[   93.608563] RAX: ffffffffffffffda RBX: 0000559b32bbd2f0 RCX: 00007f18e8316c4d
[   93.608872] RDX: 0000000000000000 RSI: 0000559b3281ac3a RDI: 0000000000000000
[   93.609176] RBP: 0000559b3281ac3a R08: 0000000000000000 R09: 00007ffe0e70f510
[   93.609470] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000040000
ABORT
[   93.609796] R13: 0000559b32bbd170 R14: 0000000000000000 R15: 0000559b32bbd490
[   93.610138]  </TASK>
[   93.610691] Kernel panic - not syncing: softlockup: hung tasks
[   93.611092] CPU: 0 PID: 421 Comm: modprobe Tainted: G           OEL     6.1.0-060100rc3daily20221031-generic #202210302201
[   93.611572] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[   93.612010] Call Trace:
[   93.612276]  <IRQ>
[   93.612415]  show_stack+0x4e/0x61
[   93.612597]  dump_stack_lvl+0x4a/0x6f
[   93.612805]  dump_stack+0x10/0x18
[   93.612997]  panic+0x16e/0x31f
[   93.613193]  watchdog_timer_fn.cold+0xc/0x16
[   93.613406]  ? lockup_detector_update_enable+0x60/0x60
[   93.613680]  __hrtimer_run_queues+0x108/0x280
[   93.613900]  ? clockevents_program_event+0xb6/0x140
[   93.614148]  hrtimer_interrupt+0xf6/0x230
[   93.614353]  __sysvec_apic_timer_interrupt+0x62/0x110
[   93.614614]  sysvec_apic_timer_interrupt+0x8d/0xd0
[   93.614868]  </IRQ>
[   93.615002]  <TASK>
[   93.615124]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[   93.615808] RIP: 0010:_raw_spin_unlock_irqrestore+0x21/0x60
[   93.616092] Code: 0f 1f 84 00 00 00 00 00 90 0f 1f 44 00 00 55 49 89 f0 48 89 e5 c6 07 00 0f 1f 00 41 f7 c0 00 02 00 00 74 06 fb 0f 1f 44 00 00 <65> ff 0d e8 12 f0 46 74 13 5d 31 c0 31 d2 31 c9 31 f6 31 ff 45 31
[   93.616864] RSP: 0018:ff383b6181a63a78 EFLAGS: 00000206
[   93.617126] RAX: 0000000000000064 RBX: 0000000000000064 RCX: 0000000000000000
[   93.617435] RDX: ffb2c5ef402ba6c8 RSI: 0000000000000282 RDI: ff32a1b0fc237580
[   93.617743] RBP: ff383b6181a63a78 R08: 0000000000000282 R09: 0000000000000000
[   93.618069] R10: ff383b6181a55640 R11: 0000000000000064 R12: ff32a1b0fc237580
[   93.618375] R13: ff32a1b0fef6a600 R14: 0000000000000064 R15: ff32a1b0fc237580
[   93.618747]  __alloc_pages_bulk+0x5af/0x850
[   93.618987]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[   93.619241]  vm_area_alloc_pages+0x8d/0x190
[   93.619458]  __vmalloc_area_node+0xe1/0x3a0
[   93.619760]  __vmalloc_node_range+0xda/0x220
[   93.620089]  __vmalloc_node+0x4e/0x80
[   93.620401]  ? kernel_read_file+0x2b1/0x320
[   93.620634]  vmalloc+0x21/0x40
[   93.620836]  kernel_read_file+0x2b1/0x320
[   93.621135]  kernel_read_file_from_fd+0x5d/0xc0
[   93.621351]  __do_sys_finit_module+0x93/0x140
[   93.621557]  __x64_sys_finit_module+0x18/0x30
[   93.621772]  do_syscall_64+0x5b/0x90
[   93.621956]  ? exit_to_user_mode_prepare+0x30/0xb0
[   93.622186]  ? syscall_exit_to_user_mode+0x29/0x50
[   93.622513]  ? do_syscall_64+0x67/0x90
[   93.623254]  ? syscall_exit_to_user_mode+0x29/0x50
[   93.623721]  ? do_syscall_64+0x67/0x90
[   93.623940]  ? do_syscall_64+0x67/0x90
[   93.624201]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[   93.624647] RIP: 0033:0x7f18e8316c4d
[   93.624933] Code: 5d c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 83 f1 0d 00 f7 d8 64 89 01 48
[   93.625814] RSP: 002b:00007ffe0e70f3e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[   93.626121] RAX: ffffffffffffffda RBX: 0000559b32bbd2f0 RCX: 00007f18e8316c4d
[   93.626420] RDX: 0000000000000000 RSI: 0000559b3281ac3a RDI: 0000000000000000
[   93.626755] RBP: 0000559b3281ac3a R08: 0000000000000000 R09: 00007ffe0e70f510
[   93.627095] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000040000
[   93.627404] R13: 0000559b32bbd170 R14: 0000000000000000 R15: 0000559b32bbd490
[   93.627779]  </TASK>
[   93.628667] Kernel Offset: 0x37200000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
solardiz commented 1 year ago

All of these appear to be on unloading of some other module(s). We could want to see if our modules integrity checking support code can possibly introduce a deadlock into the kernel e.g. when multiple modules are attempted to be unloaded concurrently.

solardiz commented 9 months ago

One more, looks like this time on loading of a module (not unloading):

https://github.com/lkrg-org/lkrg/actions/runs/6447005125/job/17502826690

Last login: Sun Oct  8 10:24:57 UTC 2023 on tty1
[   95.853209] lpc_ich 0000:00:1f.0: I/O space for GPIO uninitialized
[   96.282039] i801_smbus 0000:00:1f.3: Enabling SMBus device
[   96.286502] i801_smbus 0000:00:1f.3: SMBus using PCI interrupt
[   96.295906] i2c i2c-0: 1/1 memory slots populated (from DMI)
[   96.296323] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
[   99.208504] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[  125.052640] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [(udev-worker):371]
[  125.053164] Modules linked in: irqbypass psmouse i2c_i801 lpc_ich i2c_smbus input_leds mac_hid cfg80211 drm efi_pstore dmi_sysfs ip_tables x_tables crct10dif_pclmul crc32_pclmul polyval_generic ghash_clmulni_intel sha512_ssse3 aesni_intel crypto_simd cryptd ahci libahci serio_raw lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4
[  125.055168] CPU: 0 PID: 371 Comm: (udev-worker) Tainted: G           OE      6.6.0-060600rc4daily20231008-generic #202310072201
[  125.055658] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[  125.056146] RIP: 0010:clear_page_erms+0x7/0x10
[  125.056847] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[  125.057741] RSP: 0018:ffa0000001c03a98 EFLAGS: 00000246
[  125.058031] RAX: 0000000000000000 RBX: 0000000000000047 RCX: 000000000000080c
[  125.058442] RDX: ffd40000001c0340 RSI: 0000000000000000 RDI: ff1100000700d7f4
[  125.058756] RBP: ffa0000001c03b30 R08: 0000000000000000 R09: 0000000000000000
[  125.059102] R10: 0000000000000000 R11: ff1100003ef6be00 R12: 0000000000000047
[  125.059460] R13: 0000000000000000 R14: ffa00000000c21d0 R15: 0000000000000064
[  125.059868] FS:  00007f2c0b64e8c0(0000) GS:ff1100003c200000(0000) knlGS:0000000000000000
[  125.060196] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  125.060475] CR2: 00007f2c0ad4f3c7 CR3: 0000000002f0e000 CR4: 00000000007516f0
[  125.060959] PKRU: 55555554
[  125.061201] Call Trace:
[  125.061933]  <IRQ>
[  125.062206]  ? show_regs+0x6d/0x80
[  125.062552]  ? watchdog_timer_fn+0x1d8/0x240
[  125.062909]  ? __pfx_watchdog_timer_fn+0x10/0x10
[  125.063178]  ? __hrtimer_run_queues+0x112/0x2a0
[  125.063374]  ? clockevents_program_event+0xc1/0x150
[  125.063653]  ? hrtimer_interrupt+0xf6/0x250
[  125.063905]  ? __sysvec_apic_timer_interrupt+0x51/0x150
[  125.064127]  ? sysvec_apic_timer_interrupt+0x8d/0xd0
[  125.064366]  </IRQ>
[  125.064515]  <TASK>
[  125.064632]  ? asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  125.065299]  ? clear_page_erms+0x7/0x10
[  125.065530]  ? __alloc_pages_bulk+0x326/0x760
[  125.065798]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[  125.066205]  __vmalloc_area_node+0x58b/0x630
[  125.066418]  __vmalloc_node_range+0xda/0x220
[  125.066667]  __vmalloc_node+0x4e/0x80
[  125.066882]  ? module_zstd_decompress+0xd7/0x2a0
[  125.067084]  vmalloc+0x21/0x40
[  125.067227]  module_zstd_decompress+0xd7/0x2a0
[  125.067446]  module_decompress+0x37/0xc0
[  125.067650]  init_module_from_file+0xd0/0x100
[  125.067875]  ? security_capable+0x1/0x80
[  125.068078]  idempotent_init_module+0x11c/0x2b0
[  125.068293]  __x64_sys_finit_module+0x64/0xd0
[  125.068527]  do_syscall_64+0x5c/0x90
[  125.068717]  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[  125.069083] RIP: 0033:0x7f2c0b525c7d
[  125.069571] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 6b 81 0d 00 f7 d8 64 89 01 48
[  125.070377] RSP: 002b:00007ffc31802658 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
ABORT
[  125.070800] RAX: ffffffffffffffda RBX: 000056471d160d70 RCX: 00007f2c0b525c7d
[  125.071143] RDX: 0000000000000004 RSI: 00007f2c0b86b44a RDI: 000000000000000f
[  125.071370] RBP: 00007f2c0b86b44a R08: 0000000000000007 R09: fffffffffffffde0
[  125.071684] R10: 0000000000000007 R11: 0000000000000246 R12: 0000000000020000
[  125.072080] R13: 000056471d1630b0 R14: 0000000000000000 R15: 000056471d164190
[  125.072433]  </TASK>
[  125.072926] Kernel panic - not syncing: softlockup: hung tasks
[  125.073448] CPU: 0 PID: 371 Comm: (udev-worker) Tainted: G           OEL     6.6.0-060600rc4daily20231008-generic #202310072201
[  125.073929] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[  125.074370] Call Trace:
[  125.074735]  <IRQ>
[  125.074890]  dump_stack_lvl+0x48/0x70
[  125.075147]  dump_stack+0x10/0x20
[  125.075336]  panic+0x1bb/0x3a0
[  125.075524]  watchdog_timer_fn+0x203/0x240
[  125.075787]  ? __pfx_watchdog_timer_fn+0x10/0x10
[  125.076182]  __hrtimer_run_queues+0x112/0x2a0
[  125.076523]  ? clockevents_program_event+0xc1/0x150
[  125.076904]  hrtimer_interrupt+0xf6/0x250
[  125.077228]  __sysvec_apic_timer_interrupt+0x51/0x150
[  125.077615]  sysvec_apic_timer_interrupt+0x8d/0xd0
[  125.078023]  </IRQ>
[  125.078225]  <TASK>
[  125.078415]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  125.078903] RIP: 0010:clear_page_erms+0x7/0x10
[  125.079298] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[  125.080426] RSP: 0018:ffa0000001c03a98 EFLAGS: 00000246
[  125.081070] RAX: 0000000000000000 RBX: 0000000000000047 RCX: 000000000000080c
[  125.081581] RDX: ffd40000001c0340 RSI: 0000000000000000 RDI: ff1100000700d7f4
[  125.082033] RBP: ffa0000001c03b30 R08: 0000000000000000 R09: 0000000000000000
[  125.082450] R10: 0000000000000000 R11: ff1100003ef6be00 R12: 0000000000000047
[  125.082932] R13: 0000000000000000 R14: ffa00000000c21d0 R15: 0000000000000064
[  125.083438]  ? __alloc_pages_bulk+0x326/0x760
[  125.083809]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[  125.084192]  __vmalloc_area_node+0x58b/0x630
[  125.084456]  __vmalloc_node_range+0xda/0x220
[  125.084692]  __vmalloc_node+0x4e/0x80
[  125.084966]  ? module_zstd_decompress+0xd7/0x2a0
[  125.085271]  vmalloc+0x21/0x40
[  125.085442]  module_zstd_decompress+0xd7/0x2a0
[  125.085689]  module_decompress+0x37/0xc0
[  125.085909]  init_module_from_file+0xd0/0x100
[  125.086209]  ? security_capable+0x1/0x80
[  125.086477]  idempotent_init_module+0x11c/0x2b0
[  125.086769]  __x64_sys_finit_module+0x64/0xd0
[  125.087024]  do_syscall_64+0x5c/0x90
[  125.087258]  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[  125.087522] RIP: 0033:0x7f2c0b525c7d
[  125.087744] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 6b 81 0d 00 f7 d8 64 89 01 48
[  125.088638] RSP: 002b:00007ffc31802658 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  125.089063] RAX: ffffffffffffffda RBX: 000056471d160d70 RCX: 00007f2c0b525c7d
[  125.089487] RDX: 0000000000000004 RSI: 00007f2c0b86b44a RDI: 000000000000000f
[  125.089832] RBP: 00007f2c0b86b44a R08: 0000000000000007 R09: fffffffffffffde0
[  125.090239] R10: 0000000000000007 R11: 0000000000000246 R12: 0000000000020000
[  125.090603] R13: 000056471d1630b0 R14: 0000000000000000 R15: 000056471d164190
[  125.091002]  </TASK>
[  125.092000] Kernel Offset: disabled
solardiz commented 8 months ago

One more on module loading: https://github.com/lkrg-org/lkrg/actions/runs/6559463339/job/17815126063

Last login: Wed Oct 18 10:26:11 UTC 2023 on tty1
[   99.188082] lpc_ich 0000:00:1f.0: I/O space for GPIO uninitialized
[  100.153532] i801_smbus 0000:00:1f.3: Enabling SMBus device
[  100.154362] i801_smbus 0000:00:1f.3: SMBus using PCI interrupt
[  100.173906] i2c i2c-0: 1/1 memory slots populated (from DMI)
[  100.174282] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
[  103.191236] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[  129.083664] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [(udev-worker):372]
[  129.084280] Modules linked in: irqbypass psmouse i2c_i801 i2c_smbus lpc_ich input_leds mac_hid cfg80211 drm efi_pstore dmi_sysfs ip_tables x_tables crct10dif_pclmul crc32_pclmul polyval_generic ghash_clmulni_intel sha512_ssse3 aesni_intel crypto_simd cryptd ahci libahci serio_raw lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4
[  129.086570] CPU: 0 PID: 372 Comm: (udev-worker) Tainted: G           OE      6.6.0-060600rc5daily20231013-generic #202310122203
[  129.087156] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[  129.087742] RIP: 0010:clear_page_erms+0x7/0x10
[  129.088637] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[  129.089845] RSP: 0018:ffa0000001c5fa90 EFLAGS: 00000246
[  129.090242] RAX: 0000000000000000 RBX: 0000000000000025 RCX: 000000000000052f
[  129.090683] RDX: ffd40000001c0700 RSI: 0000000000000000 RDI: ff1100000701cad1
[  129.091177] RBP: ffa0000001c5fb28 R08: 0000000000000000 R09: 0000000000000000
[  129.091684] R10: 0000000000000000 R11: ff1100003ef6be00 R12: 0000000000000025
[  129.096222] R13: 0000000000000000 R14: ffa00000000c20c0 R15: 0000000000000064
[  129.101071] FS:  00007ff7f0a5b8c0(0000) GS:ff1100003c200000(0000) knlGS:0000000000000000
[  129.107199] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  129.109241] CR2: 00007ff7f00b8ec9 CR3: 0000000030b52000 CR4: 00000000007516f0
[  129.110554] PKRU: 55555554
[  129.111637] Call Trace:
[  129.113025]  <IRQ>
[  129.114765]  ? show_regs+0x6d/0x80
[  129.116450]  ? watchdog_timer_fn+0x1d8/0x240
[  129.117221]  ? __pfx_watchdog_timer_fn+0x10/0x10
[  129.118334]  ? __hrtimer_run_queues+0x112/0x2a0
[  129.119102]  ? clockevents_program_event+0xc1/0x150
[  129.120003]  ? hrtimer_interrupt+0xf6/0x250
[  129.120770]  ? __sysvec_apic_timer_interrupt+0x51/0x150
[  129.121630]  ? sysvec_apic_timer_interrupt+0x8d/0xd0
[  129.122427]  </IRQ>
[  129.122854]  <TASK>
[  129.123384]  ? asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  129.124222]  ? clear_page_erms+0x7/0x10
[  129.124923]  ? __alloc_pages_bulk+0x326/0x760
[  129.125927]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[  129.127256]  __vmalloc_area_node+0x58b/0x630
[  129.127984]  __vmalloc_node_range+0xda/0x220
[  129.128300]  __vmalloc_node+0x4e/0x80
[  129.128558]  ? module_zstd_decompress+0xd7/0x2a0
[  129.128892]  vmalloc+0x21/0x40
[  129.129076]  module_zstd_decompress+0xd7/0x2a0
[  129.129403]  module_decompress+0x37/0xc0
[  129.129643]  init_module_from_file+0xd0/0x100
[  129.129891]  ? security_capable+0x1/0x80
[  129.130142]  idempotent_init_module+0x11c/0x2b0
[  129.130413]  __x64_sys_finit_module+0x64/0xd0
[  129.130664]  do_syscall_64+0x5c/0x90
[  129.131056]  ? exc_page_fault+0x94/0x1b0
[  129.131308]  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[  129.131689] RIP: 0033:0x7ff7f0925c7d
[  129.132460] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 6b 81 0d 00 f7 d8 64 89 01 48
[  129.133632] RSP: 002b:00007ffe8de27238 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  129.134271] RAX: ffffffffffffffda RBX: 000055fb6da6bbe0 RCX: 00007ff7f0925c7d
[  129.134650] RDX: 0000000000000004 RSI: 00007ff7f0c7844a RDI: 000000000000000f
[  129.135016] RBP: 00007ff7f0c7844a R08: 0000000000000040 R09: fffffffffffffde0
[  129.135542] R10: fffffffffffffe18 R11: 0000000000000246 R12: 0000000000020000
[  129.136228] R13: 000055fb6da2e8b0 R14: 0000000000000000 R15: 000055fb6da720d0
[  129.136726]  </TASK>
[  129.137106] Kernel panic - not syncing: softlockup: hung tasks
[  129.137577] CPU: 0 PID: 372 Comm: (udev-worker) Tainted: G           OEL     6.6.0-060600rc5daily20231013-generic #202310122203
[  129.138152] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[  129.138579] Call Trace:
[  129.138792]  <IRQ>
[  129.138964]  dump_stack_lvl+0x48/0x70
ABORT
[  129.140759]  dump_stack+0x10/0x20
[  129.140998]  panic+0x1bb/0x3a0
[  129.141217]  watchdog_timer_fn+0x203/0x240
[  129.141440]  ? __pfx_watchdog_timer_fn+0x10/0x10
[  129.141898]  __hrtimer_run_queues+0x112/0x2a0
[  129.142586]  ? clockevents_program_event+0xc1/0x150
[  129.142851]  hrtimer_interrupt+0xf6/0x250
[  129.143178]  __sysvec_apic_timer_interrupt+0x51/0x150
[  129.143600]  sysvec_apic_timer_interrupt+0x8d/0xd0
[  129.144522]  </IRQ>
[  129.144692]  <TASK>
[  129.144842]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[  129.145299] RIP: 0010:clear_page_erms+0x7/0x10
[  129.145725] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[  129.146858] RSP: 0018:ffa0000001c5fa90 EFLAGS: 00000246
[  129.147143] RAX: 0000000000000000 RBX: 0000000000000025 RCX: 000000000000052f
[  129.147512] RDX: ffd40000001c0700 RSI: 0000000000000000 RDI: ff1100000701cad1
[  129.147874] RBP: ffa0000001c5fb28 R08: 0000000000000000 R09: 0000000000000000
[  129.148278] R10: 0000000000000000 R11: ff1100003ef6be00 R12: 0000000000000025
[  129.149134] R13: 0000000000000000 R14: ffa00000000c20c0 R15: 0000000000000064
[  129.151212]  ? __alloc_pages_bulk+0x326/0x760
[  129.152321]  alloc_pages_bulk_array_mempolicy+0x9e/0x240
[  129.153608]  __vmalloc_area_node+0x58b/0x630
[  129.154651]  __vmalloc_node_range+0xda/0x220
[  129.155850]  __vmalloc_node+0x4e/0x80
[  129.156980]  ? module_zstd_decompress+0xd7/0x2a0
[  129.158089]  vmalloc+0x21/0x40
[  129.159011]  module_zstd_decompress+0xd7/0x2a0
[  129.160163]  module_decompress+0x37/0xc0
[  129.161101]  init_module_from_file+0xd0/0x100
[  129.162046]  ? security_capable+0x1/0x80
[  129.162844]  idempotent_init_module+0x11c/0x2b0
[  129.163836]  __x64_sys_finit_module+0x64/0xd0
[  129.165182]  do_syscall_64+0x5c/0x90
[  129.166003]  ? exc_page_fault+0x94/0x1b0
[  129.167024]  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[  129.168088] RIP: 0033:0x7ff7f0925c7d
[  129.168920] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 6b 81 0d 00 f7 d8 64 89 01 48
[  129.171640] RSP: 002b:00007ffe8de27238 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[  129.172644] RAX: ffffffffffffffda RBX: 000055fb6da6bbe0 RCX: 00007ff7f0925c7d
[  129.173451] RDX: 0000000000000004 RSI: 00007ff7f0c7844a RDI: 000000000000000f
[  129.174044] RBP: 00007ff7f0c7844a R08: 0000000000000040 R09: fffffffffffffde0
[  129.174444] R10: fffffffffffffe18 R11: 0000000000000246 R12: 0000000000020000
[  129.174798] R13: 000055fb6da2e8b0 R14: 0000000000000000 R15: 000055fb6da720d0
[  129.175156]  </TASK>
[  129.176296] Kernel Offset: disabled
solardiz commented 4 months ago

Yet another on module loading, with current LKRG and mainline kernel: https://github.com/solardiz/lkrg/actions/runs/7942964583/job/21686795633

[  OK  ] Finished modprobe@configfs.service - Load Kernel Module configfs.
[   65.055960] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [modprobe:458]
[   65.056418] Modules linked in: efi_pstore nfnetlink dmi_sysfs ip_tables x_tables crct10dif_pclmul crc32_pclmul polyval_generic ghash_clmulni_intel sha256_ssse3 ahci sha1_ssse3 libahci serio_raw lkrg(OE) dm_mirror dm_region_hash dm_log qemu_fw_cfg virtio_rng autofs4 aesni_intel crypto_simd cryptd
[   65.058159] CPU: 0 PID: 458 Comm: modprobe Tainted: G           OE      6.8.0-060800rc4daily20240217-generic #202402162102
[   65.058792] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[   65.059355] RIP: 0010:clear_page_erms+0x7/0x10
[   65.059940] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[   65.060900] RSP: 0018:ff64601601c5fa48 EFLAGS: 00000246
[   65.061236] RAX: 0000000000000000 RBX: 0000000000000400 RCX: 0000000000000a09
[   65.061645] RDX: ffe2539dc02f0000 RSI: ffe2539dc02e9240 RDI: ff4f977b4ba495f7
[   65.062057] RBP: ff64601601c5fa78 R08: 0000000000000000 R09: 0000000000000000
[   65.062408] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000010000
[   65.062812] R13: 000000000000000a R14: ffe2539dc02e0000 R15: 0000000000000001
[   65.063245] FS:  0000756c06dec040(0000) GS:ff4f977b7c200000(0000) knlGS:0000000000000000
[   65.063613] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   65.063917] CR2: 00007b31f0b9e2a8 CR3: 00000000030ec000 CR4: 00000000007516f0
[   65.064377] PKRU: 55555554
[   65.064601] Call Trace:
[   65.065150]  <IRQ>
[   65.065414]  ? show_regs+0x6d/0x80
[   65.065659]  ? watchdog_timer_fn+0x206/0x290
[   65.065932]  ? __pfx_watchdog_timer_fn+0x10/0x10
[   65.066191]  ? __hrtimer_run_queues+0x112/0x2a0
[   65.066417]  ? clockevents_program_event+0xc1/0x150
[   65.066677]  ? hrtimer_interrupt+0xf6/0x250
[   65.066894]  ? __sysvec_apic_timer_interrupt+0x51/0x150
[   65.067167]  ? sysvec_apic_timer_interrupt+0x8d/0xd0
[   65.067467]  </IRQ>
[   65.067601]  <TASK>
[   65.067714]  ? asm_sysvec_apic_timer_interrupt+0x1b/0x20
[   65.068059]  ? clear_page_erms+0x7/0x10
[   65.068265]  ? post_alloc_hook+0xcd/0x120
[   65.068484]  get_page_from_freelist+0x452/0x6d0
[   65.068854]  __alloc_pages+0x1e9/0x350
[   65.069073]  __kmalloc_large_node+0x75/0x130
[   65.069295]  __kmalloc_node+0x3ed/0x500
[   65.069532]  ? kvmalloc_node+0x5d/0x100
[   65.069774]  kvmalloc_node+0x5d/0x100
[   65.069957]  ? kvmalloc_node+0x5d/0x100
[   65.070155]  module_zstd_decompress+0xe1/0x2a0
[   65.070427]  module_decompress+0x37/0xc0
[   65.070669]  init_module_from_file+0xd0/0x100
[   65.070868]  ? security_capable+0x1/0x80
[   65.071132]  idempotent_init_module+0x11c/0x2b0
[   65.071408]  __x64_sys_finit_module+0x64/0xd0
[   65.071653]  do_syscall_64+0x77/0x140
[   65.071867]  ? do_syscall_64+0x83/0x140
[   65.072074]  ? syscall_exit_to_user_mode+0x97/0x1e0
[   65.072317]  ? do_syscall_64+0x83/0x140
[   65.072522]  ? syscall_exit_to_user_mode+0x97/0x1e0
[   65.072811]  ? do_syscall_64+0x83/0x140
[   65.073010]  ? exc_page_fault+0x94/0x1b0
[   65.073224]  entry_SYSCALL_64_after_hwframe+0x6e/0x76
[   65.073583] RIP: 0033:0x756c06525c7d
[   65.074072] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 73 81 0d 00 f7 d8 64 89 01 48
[   65.074839] RSP: 002b:00007ffe0cd09ef8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[   65.075269] RAX: ffffffffffffffda RBX: 000059530ea09ba0 RCX: 0000756c06525c7d
ABORT
[   65.075661] RDX: 0000000000000004 RSI: 000059530e06b727 RDI: 0000000000000000
[   65.076036] RBP: 000059530e06b727 R08: 0000000000000040 R09: 00007ffe0cd0a000
[   65.076503] R10: ffffffffffffffc0 R11: 0000000000000246 R12: 0000000000040000
[   65.076934] R13: 000059530ea09a20 R14: 000059530ea0aa10 R15: 000059530ea09d40
[   65.077319]  </TASK>
[   65.077666] Kernel panic - not syncing: softlockup: hung tasks
[   65.078053] CPU: 0 PID: 458 Comm: modprobe Tainted: G           OEL     6.8.0-060800rc4daily20240217-generic #202402162102
[   65.078480] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
[   65.078835] Call Trace:
[   65.079040]  <IRQ>
[   65.079153]  dump_stack_lvl+0x48/0x70
[   65.079357]  dump_stack+0x10/0x20
[   65.079541]  panic+0x35f/0x3c0
[   65.079733]  watchdog_timer_fn+0x245/0x290
[   65.079940]  ? __pfx_watchdog_timer_fn+0x10/0x10
[   65.080153]  __hrtimer_run_queues+0x112/0x2a0
[   65.080362]  ? clockevents_program_event+0xc1/0x150
[   65.080590]  hrtimer_interrupt+0xf6/0x250
[   65.080793]  __sysvec_apic_timer_interrupt+0x51/0x150
[   65.081041]  sysvec_apic_timer_interrupt+0x8d/0xd0
[   65.081303]  </IRQ>
[   65.081432]  <TASK>
[   65.081554]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
[   65.081868] RIP: 0010:clear_page_erms+0x7/0x10
[   65.082085] Code: 48 89 47 38 48 8d 7f 40 75 d9 90 c3 cc cc cc cc 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 b9 00 10 00 00 31 c0 <f3> aa c3 cc cc cc cc 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[   65.082820] RSP: 0018:ff64601601c5fa48 EFLAGS: 00000246
[   65.083072] RAX: 0000000000000000 RBX: 0000000000000400 RCX: 0000000000000a09
[   65.083385] RDX: ffe2539dc02f0000 RSI: ffe2539dc02e9240 RDI: ff4f977b4ba495f7
[   65.083714] RBP: ff64601601c5fa78 R08: 0000000000000000 R09: 0000000000000000
[   65.084067] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000010000
[   65.084429] R13: 000000000000000a R14: ffe2539dc02e0000 R15: 0000000000000001
[   65.084849]  ? post_alloc_hook+0xcd/0x120
[   65.085081]  get_page_from_freelist+0x452/0x6d0
[   65.085342]  __alloc_pages+0x1e9/0x350
[   65.085575]  __kmalloc_large_node+0x75/0x130
[   65.085838]  __kmalloc_node+0x3ed/0x500
[   65.086058]  ? kvmalloc_node+0x5d/0x100
[   65.086310]  kvmalloc_node+0x5d/0x100
[   65.086536]  ? kvmalloc_node+0x5d/0x100
[   65.086778]  module_zstd_decompress+0xe1/0x2a0
[   65.087066]  module_decompress+0x37/0xc0
[   65.087315]  init_module_from_file+0xd0/0x100
[   65.087582]  ? security_capable+0x1/0x80
[   65.087848]  idempotent_init_module+0x11c/0x2b0
[   65.088158]  __x64_sys_finit_module+0x64/0xd0
[   65.088422]  do_syscall_64+0x77/0x140
[   65.088644]  ? do_syscall_64+0x83/0x140
[   65.088856]  ? syscall_exit_to_user_mode+0x97/0x1e0
[   65.089126]  ? do_syscall_64+0x83/0x140
[   65.089308]  ? syscall_exit_to_user_mode+0x97/0x1e0
[   65.089561]  ? do_syscall_64+0x83/0x140
[   65.089768]  ? exc_page_fault+0x94/0x1b0
[   65.089963]  entry_SYSCALL_64_after_hwframe+0x6e/0x76
[   65.090208] RIP: 0033:0x756c06525c7d
[   65.090409] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 73 81 0d 00 f7 d8 64 89 01 48
[   65.091337] RSP: 002b:00007ffe0cd09ef8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[   65.091764] RAX: ffffffffffffffda RBX: 000059530ea09ba0 RCX: 0000756c06525c7d
[   65.092194] RDX: 0000000000000004 RSI: 000059530e06b727 RDI: 0000000000000000
[   65.092590] RBP: 000059530e06b727 R08: 0000000000000040 R09: 00007ffe0cd0a000
[   65.092972] R10: ffffffffffffffc0 R11: 0000000000000246 R12: 0000000000040000
[   65.093387] R13: 000059530ea09a20 R14: 000059530ea0aa10 R15: 000059530ea09d40
[   65.093793]  </TASK>
[   65.094470] Kernel Offset: 0x26600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)