RHEL8.7 system with the kernel 4.18.0-425.10.1.el8_7 or higher hangs with soft lockup and rcu_sched CPU stall warning

Diagnostic Steps

• Check if the third-party [oracleoks] module linked to the kernel version 4.18.0-425.10.1.el8_7 or higher is built on top of the kernel-devel version 4.18.0-425.3.1.el8.

# find /lib/modules -name oracleoks.ko* | awk '{print "ls -ltr " $1}' | bash 
# find /lib/modules -name oracleoks.ko* | awk '{print "modinfo " $1}' | bash | egrep "filename|name|vermagic"

OR

# ls -lrt /usr/lib/modules/4.18.0-425.10.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko
# modinfo /usr/lib/modules/4.18.0-425.10.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko

# ls -lrt /usr/lib/modules/4.18.0-425.13.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko
# modinfo /usr/lib/modules/4.18.0-425.13.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko

Example:

# modinfo /usr/lib/modules/4.18.0-425.13.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko | grep vermagic
vermagic: 4.18.0-425.3.1.el8.x86_64 SMP mod_unload modversions 

Note: Check the vermagic: field in the output of the modinfo command.

Kernel Crash Dump (VMcore) Analysis:

• Check the version of the running kernel:

crash> sys | grep -e RELEASE
     RELEASE: 4.18.0-425.13.1.el8_7.x86_64

• Check the kernel ring buffer for soft lockup and rcu_sched CPU stall warnings:

crash> log | grep BUG: | tail
[1112594.536526] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112622.536589] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112650.536652] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112678.536715] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112718.536805] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112746.536868] watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [modprobe:3779]
[1112774.536930] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [modprobe:3779]
[1112802.536993] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [modprobe:3779]
[1112830.537056] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [modprobe:3779]
[1112858.537119] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [modprobe:3779]

crash> log | grep BUG: | awk '{print $(NF-4) , $(NF)}' | sort -nr | sort | uniq -c | sort -nr
    226 CPU#7 [modprobe:3779]  <<< - - -

crash> log
[1112858.537119] watchdog: BUG: soft lockup - CPU#7 stuck for 23s! [modprobe:3779]
[1112858.537603] Modules linked in: tmhook(O+) oracleoks(POE+) dsa_filter(PO) dsa_filter_hook(O) oracleasm(O) vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock sunrpc vfat fat intel_rapl_msr vmw_balloon intel_rapl_common isst_if_mbox_msr isst_if_common nfit libnvdimm crc32_pclmul rapl joydev pcspkr vmw_vmci i2c_piix4 binfmt_misc xfs libcrc32c ata_generic crct10dif_pclmul crc32c_intel sd_mod t10_pi sg vmwgfx drm_ttm_helper ttm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ahci ata_piix libahci serio_raw drm libata ghash_clmulni_intel vmxnet3 vmw_pvscsi dm_mirror dm_region_hash dm_log dm_mod fuse
[1112858.540022] CPU: 7 PID: 3779 Comm: modprobe Tainted: P        W  OEL   --------- -  - 4.18.0-425.13.1.el8_7.x86_64 #1
[1112858.540461] Hardware name: VMware, Inc. VMware7,1/440BX Desktop Reference Platform, BIOS VMW71.00V.17369862.B64.2012240522 12/24/2020
[1112858.541318] RIP: 0010:native_queued_spin_lock_slowpath+0x24/0x1c0
[1112858.541739] Code: ff ff 0f 1f 40 00 0f 1f 44 00 00 0f 1f 44 00 00 ba 01 00 00 00 8b 07 85 c0 75 0d f0 0f b1 17 85 c0 75 f2 e9 3e b7 aa 00 f3 90 <eb> e9 81 fe 00 01 00 00 74 44 81 e6 00 ff ff ff 75 71 f0 0f ba 2f
[1112858.542628] RSP: 0018:ffffa404539fb940 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13
[1112858.543074] RAX: 0000000000000001 RBX: 0000000000000176 RCX: 0000000000000000
[1112858.543540] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffffffffc0a58380
[1112858.543991] RBP: ffffffffc0a58380 R08: 000000000000198f R09: 4040207472617453
[1112858.544455] R10: 2f6c69615420676f R11: 4c734b2040404021 R12: 0000000000000000
[1112858.544902] R13: 0000000000000000 R14: 0000000000000001 R15: ffffa404539fb9e8
[1112858.545369] FS:  00007f9709534740(0000) GS:ffff9211dfdc0000(0000) knlGS:0000000000000000
[1112858.545836] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[1112858.546315] CR2: 00007f9708514470 CR3: 00000001ddb16003 CR4: 00000000007706e0
[1112858.546792] PKRU: 55555554
[1112858.547278] Call Trace:
[1112858.547745]  _raw_spin_lock+0x1e/0x30
[1112858.548215]  KsAcquireSpinLock_debug+0x60/0xf0 [oracleoks]
[1112858.548725]  KsLog+0x490/0x920 [oracleoks]
[1112858.549217]  KS_LOG+0x5a/0x80 [oracleoks]
[1112858.549723]  KsBlogAlert+0xf7/0x130 [oracleoks]
[1112858.550209]  sKsMsgPrint+0xb4/0xd0 [oracleoks]
[1112858.550709]  KsMsgIssue+0x2c5/0x8b0 [oracleoks]
[1112858.551204]  ? KsMalloc+0x8f/0x2d0 [oracleoks]
[1112858.551689]  ? __kmalloc+0x113/0x250
[1112858.552146]  KsLogReinit+0x241/0x2d0 [oracleoks]
[1112858.552637]  oks_init_module+0x151/0x2f0 [oracleoks]
[1112858.553125]  ? kcss_rbld_do_step+0x6e0/0x6e0 [oracleoks]
[1112858.553599]  do_one_initcall+0x46/0x1d0
[1112858.554029]  ? do_init_module+0x22/0x230
[1112858.554467]  ? kmem_cache_alloc_trace+0x142/0x280
[1112858.554890]  do_init_module+0x5a/0x230
[1112858.555317]  load_module+0x14bf/0x17f0
[1112858.555780]  ? __do_sys_finit_module+0xb1/0x110
[1112858.556223]  __do_sys_finit_module+0xb1/0x110
[1112858.556660]  do_syscall_64+0x5b/0x1b0
[1112858.557084]  entry_SYSCALL_64_after_hwframe+0x61/0xc6
[1112858.557532] RIP: 0033:0x7f970844a9bd
[1112858.557965] 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 9b 64 38 00 f7 d8 64 89 01 48
[1112858.558896] RSP: 002b:00007fffb47879b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[1112858.559366] RAX: ffffffffffffffda RBX: 00005565dbdc9710 RCX: 00007f970844a9bd
[1112858.559826] RDX: 0000000000000000 RSI: 00005565db0cc8b6 RDI: 0000000000000003
[1112858.560265] RBP: 00005565db0cc8b6 R08: 0000000000000000 R09: 0000000000000000
[1112858.560698] R10: 0000000000000003 R11: 0000000000000246 R12: 0000000000000000
[1112858.561104] R13: 00005565dbdd2d40 R14: 0000000000040000 R15: 0000000000000000

crash> log | grep INFO: | head -n 5
[1106212.639188] rcu: INFO: rcu_sched self-detected stall on CPU
[1106392.642593] rcu: INFO: rcu_sched self-detected stall on CPU
[1106572.645997] rcu: INFO: rcu_sched self-detected stall on CPU
[1106752.649401] rcu: INFO: rcu_sched self-detected stall on CPU
[1106932.652806] rc[1106212.639188] rcu: INFO: rcu_sched self-detected stall on CPU
[1106212.639730] rcu:   7-....: (1105157813 ticks this GP) idle=6aa/1/0x4000000000000002 softirq=9674/9674 fqs=276201232 
[1106212.640186]    (t=1106178435 jiffies g=22049 q=114476883)
[1106212.640575] NMI backtrace for cpu 7
[1106212.640946] CPU: 7 PID: 3779 Comm: modprobe Tainted: PWOEL ----------- 4.18.0-425.13.1.el8_7.x86_64 #1
[1106212.641325] Hardware name: VMware, Inc. VMware7,1/440BX Desktop Reference Platform, BIOS VMW71.00V.17369862.B64.2012240522 12/24/2020
[1106212.642089] Call Trace:
[1106212.642469]  <IRQ>
[1106212.642880]  dump_stack+0x41/0x60
[1106212.643253]  nmi_cpu_backtrace.cold.8+0x13/0x4f
[1106212.643623]  ? lapic_can_unplug_cpu.cold.30+0x43/0x43
[1106212.643986]  nmi_trigger_cpumask_backtrace+0xe9/0xee
[1106212.644344]  rcu_dump_cpu_stacks+0xc8/0xfc
[1106212.644698]  rcu_sched_clock_irq.cold.101+0xde/0x215
[1106212.645054]  ? tick_sched_do_timer+0x50/0x50
[1106212.645409]  ? tick_sched_do_timer+0x50/0x50
[1106212.645775]  update_process_times+0x55/0x80
[1106212.646127]  tick_sched_handle+0x22/0x60
[1106212.646474]  tick_sched_timer+0x37/0x80
[1106212.646818]  __hrtimer_run_queues+0x101/0x280
[1106212.647164]  hrtimer_interrupt+0x100/0x220
[1106212.647509]  ? sched_clock+0x5/0x10
[1106212.647851]  smp_apic_timer_interrupt+0x6a/0x130
[1106212.648201]  apic_timer_interrupt+0xf/0x20
[1106212.648555]  </IRQ>
[1106212.648913] RIP: 0010:native_queued_spin_lock_slowpath+0x24/0x1c0
[1106212.649264] Code: ff ff 0f 1f 40 00 0f 1f 44 00 00 0f 1f 44 00 00 ba 01 00 00 00 8b 07 85 c0 75 0d f0 0f b1 17 85 c0 75 f2 e9 3e b7 aa 00 f3 90 <eb> e9 81 fe 00 01 00 00 74 44 81 e6 00 ff ff ff 75 71 f0 0f ba 2f
[1106212.649994] RSP: 0018:ffffa404539fb940 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13
[1106212.650370] RAX: 0000000000000001 RBX: 0000000000000176 RCX: 0000000000000000
[1106212.650750] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffffffffc0a58380
[1106212.651129] RBP: ffffffffc0a58380 R08: 000000000000198f R09: 4040207472617453
[1106212.651509] R10: 2f6c69615420676f R11: 4c734b2040404021 R12: 0000000000000000
[1106212.651911] R13: 0000000000000000 R14: 0000000000000001 R15: ffffa404539fb9e8
[1106212.652301]  _raw_spin_lock+0x1e/0x30
[1106212.652687]  KsAcquireSpinLock_debug+0x60/0xf0 [oracleoks]
[1106212.653109]  KsLog+0x490/0x920 [oracleoks]
[1106212.653505]  KS_LOG+0x5a/0x80 [oracleoks]
[1106212.653889]  KsBlogAlert+0xf7/0x130 [oracleoks]
[1106212.654267]  sKsMsgPrint+0xb4/0xd0 [oracleoks]
[1106212.654643]  KsMsgIssue+0x2c5/0x8b0 [oracleoks]
[1106212.655030]  ? KsMalloc+0x8f/0x2d0 [oracleoks]
[1106212.655399]  ? __kmalloc+0x113/0x250
[1106212.655750]  KsLogReinit+0x241/0x2d0 [oracleoks]
[1106212.656118]  oks_init_module+0x151/0x2f0 [oracleoks]
[1106212.656485]  ? kcss_rbld_do_step+0x6e0/0x6e0 [oracleoks]
[1106212.656854]  do_one_initcall+0x46/0x1d0
[1106212.657208]  ? do_init_module+0x22/0x230
[1106212.657557]  ? kmem_cache_alloc_trace+0x142/0x280
[1106212.657904]  do_init_module+0x5a/0x230
[1106212.658237]  load_module+0x14bf/0x17f0
[1106212.658561]  ? __do_sys_finit_module+0xb1/0x110
[1106212.658876]  __do_sys_finit_module+0xb1/0x110
[1106212.659179]  do_syscall_64+0x5b/0x1b0
[1106212.659481]  entry_SYSCALL_64_after_hwframe+0x61/0xc6
[1106212.659791] RIP: 0033:0x7f970844a9bd
[1106212.660098] 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 9b 64 38 00 f7 d8 64 89 01 48
[1106212.660770] RSP: 002b:00007fffb47879b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[1106212.661111] RAX: ffffffffffffffda RBX: 00005565dbdc9710 RCX: 00007f970844a9bd
[1106212.661452] RDX: 0000000000000000 RSI: 00005565db0cc8b6 RDI: 0000000000000003
[1106212.661792] RBP: 00005565db0cc8b6 R08: 0000000000000000 R09: 0000000000000000
[1106212.662131] R10: 0000000000000003 R11: 0000000000000246 R12: 0000000000000000
[1106212.662474] R13: 00005565dbdd2d40 R14: 0000000000040000 R15: 0000000000000000u: INFO: rcu_sched self-detected stall on CPU

• Verify the modprobe task:

crash> set 3779
    PID: 3779
COMMAND: "modprobe"
   TASK: ffff91fb1ac24000  [THREAD_INFO: ffff91fb1ac24000]
    CPU: 7
  STATE: TASK_RUNNING (ACTIVE)

crash> ps -m 3779
[12 21:07:13.179] [RU]  PID: 3779     TASK: ffff91fb1ac24000  CPU: 7    COMMAND: "modprobe"

• Check the backtrace of the modprobe task:

crash> bt -T
PID: 3779     TASK: ffff91fb1ac24000  CPU: 7    COMMAND: "modprobe"
  [ffffa404539fb7a8] vmw_fb_dirty_mark at ffffffffc047bb42 [vmwgfx]
  [ffffa404539fb7c8] number at ffffffffb53d2474
  [ffffa404539fb838] vsnprintf at ffffffffb53d5f45
  [ffffa404539fb878] string at ffffffffb53d2fa4
  [ffffa404539fb890] apic_timer_interrupt at ffffffffb5401c6a
  [ffffa404539fb918] native_queued_spin_lock_slowpath at ffffffffb4b55d44
  [ffffa404539fb940] _raw_spin_lock at ffffffffb53f14ee
  [ffffa404539fb948] KsAcquireSpinLock_debug at ffffffffc09b6ae0 [oracleoks]
  [ffffa404539fb970] KsLog at ffffffffc09ae2e0 [oracleoks]
  [ffffa404539fb9e0] KS_LOG at ffffffffc09ae7ca [oracleoks]
  [ffffa404539fba40] KsBlogAlert at ffffffffc09c32a7 [oracleoks]
  [ffffa404539fbab8] sKsMsgPrint at ffffffffc0a06124 [oracleoks]
  [ffffa404539fbb10] KsMsgIssue at ffffffffc09f8745 [oracleoks]
  [ffffa404539fbbb8] KsMalloc at ffffffffc09a7e9f [oracleoks]
  [ffffa404539fbbc0] __kmalloc at ffffffffb4d22973
  [ffffa404539fbc48] KsLogReinit at ffffffffc09a8dd1 [oracleoks]
  [ffffa404539fbc80] init_module at ffffffffc09f7f61 [oracleoks]
  [ffffa404539fbca8] oks_init_module at ffffffffc09f7e10 [oracleoks]
  [ffffa404539fbcb8] do_one_initcall at ffffffffb4a02816
  [ffffa404539fbcd0] do_init_module at ffffffffb4baa7d2
  [ffffa404539fbce0] kmem_cache_alloc_trace at ffffffffb4d22052
  [ffffa404539fbd28] do_init_module at ffffffffb4baa80a
  [ffffa404539fbd48] load_module at ffffffffb4baccff
  [ffffa404539fbe78] __do_sys_finit_module at ffffffffb4bad2a1
  [ffffa404539fbe80] __do_sys_finit_module at ffffffffb4bad2a1
  [ffffa404539fbf38] do_syscall_64 at ffffffffb4a043ab
  [ffffa404539fbf50] entry_SYSCALL_64_after_hwframe at ffffffffb54000a9
    RIP: 00007f970844a9bd  RSP: 00007fffb47879b8  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 00005565dbdc9710  RCX: 00007f970844a9bd
    RDX: 0000000000000000  RSI: 00005565db0cc8b6  RDI: 0000000000000003
    RBP: 00005565db0cc8b6   R8: 0000000000000000   R9: 0000000000000000
    R10: 0000000000000003  R11: 0000000000000246  R12: 0000000000000000
    R13: 00005565dbdd2d40  R14: 0000000000040000  R15: 0000000000000000
    ORIG_RAX: 0000000000000139  CS: 0033  SS: 002b

• The modporbe command is trying to load the third-party [oracleoks] module.

ORIG_RAX: 0000000000000139

crash> sys -c 0x0000000000000139
NUM  SYSTEM CALL                FILE AND LINE NUMBER
313  __x64_sys_finit_module     ../kernel/module.c: 3921

RDI: 0000000000000003

crash> files -R 0000000000000003
PID: 3779     TASK: ffff91fb1ac24000  CPU: 7    COMMAND: "modprobe"
ROOT: /    CWD: /tmp/CYcRchdUsr 
 FD       FILE            DENTRY           INODE       TYPE PATH
  3 ffff9208495c1d00 ffff91fd99c12300 ffff91fd99c96720 REG  /usr/lib/modules/4.18.0-425.3.1.el8.x86_64/extra/usm/oracleoks.ko

• The CPU7 is busy acquiring a spinlock in the KsAcquireSpinLock_debug() function.

crash> dis -rl ffffffffc09b6ae0
0xffffffffc09b6a80 <KsAcquireSpinLock_debug>:   nopl   0x0(%rax,%rax,1) [FTRACE NOP]
0xffffffffc09b6a85 <KsAcquireSpinLock_debug+5>: push   %r13
0xffffffffc09b6a87 <KsAcquireSpinLock_debug+7>: push   %r12
0xffffffffc09b6a89 <KsAcquireSpinLock_debug+9>: mov    %esi,%r12d
0xffffffffc09b6a8c <KsAcquireSpinLock_debug+12>:    and    $0x10000,%esi
0xffffffffc09b6a92 <KsAcquireSpinLock_debug+18>:    push   %rbp
0xffffffffc09b6a93 <KsAcquireSpinLock_debug+19>:    mov    %rdi,%rbp
0xffffffffc09b6a96 <KsAcquireSpinLock_debug+22>:    push   %rbx
0xffffffffc09b6a97 <KsAcquireSpinLock_debug+23>:    mov    %edx,%ebx
0xffffffffc09b6a99 <KsAcquireSpinLock_debug+25>:    jne    0xffffffffc09b6b4d <KsAcquireSpinLock_debug+205>
0xffffffffc09b6a9f <KsAcquireSpinLock_debug+31>:    mov    0x998f3(%rip),%ecx        # 0xffffffffc0a50398 <ks_collect_lstats>
0xffffffffc09b6aa5 <KsAcquireSpinLock_debug+37>:    xor    %r13d,%r13d
0xffffffffc09b6aa8 <KsAcquireSpinLock_debug+40>:    test   %ecx,%ecx
0xffffffffc09b6aaa <KsAcquireSpinLock_debug+42>:    je     0xffffffffc09b6ac8 <KsAcquireSpinLock_debug+72>
0xffffffffc09b6aac <KsAcquireSpinLock_debug+44>:    mov    %ebx,%eax
0xffffffffc09b6aae <KsAcquireSpinLock_debug+46>:    lea    (%rax,%rax,2),%rdx
0xffffffffc09b6ab2 <KsAcquireSpinLock_debug+50>:    mov    $0x1,%eax
0xffffffffc09b6ab7 <KsAcquireSpinLock_debug+55>:    lock xadd %rax,-0x3f5afc60(,%rdx,8)
0xffffffffc09b6ac1 <KsAcquireSpinLock_debug+65>:    mov    -0xa7b0ac8(%rip),%r13        # 0xffffffffb6206000 <jiffies>
0xffffffffc09b6ac8 <KsAcquireSpinLock_debug+72>:    and    $0x20000,%r12d
0xffffffffc09b6acf <KsAcquireSpinLock_debug+79>:    mov    %rbp,%rdi
0xffffffffc09b6ad2 <KsAcquireSpinLock_debug+82>:    jne    0xffffffffc09b6adb <KsAcquireSpinLock_debug+91>
0xffffffffc09b6ad4 <KsAcquireSpinLock_debug+84>:    mov    0x10(%rbp),%edx
0xffffffffc09b6ad7 <KsAcquireSpinLock_debug+87>:    test   %edx,%edx
0xffffffffc09b6ad9 <KsAcquireSpinLock_debug+89>:    jne    0xffffffffc09b6b42 <KsAcquireSpinLock_debug+194>
0xffffffffc09b6adb <KsAcquireSpinLock_debug+91>:    call   0xffffffffb53f14d0 <_raw_spin_lock>
0xffffffffc09b6ae0 <KsAcquireSpinLock_debug+96>:    mov    0x998b2(%rip),%eax        # 0xffffffffc0a50398 <ks_collect_lstats>

crash> dis -rl ffffffffb53f14ee
/usr/src/debug/kernel-4.18.0-425.13.1.el8_7/linux-4.18.0-425.13.1.el8_7.x86_64/kernel/locking/spinlock.c: 153
0xffffffffb53f14d0 <_raw_spin_lock>:    nopl   0x0(%rax,%rax,1) [FTRACE NOP]
/usr/src/debug/kernel-4.18.0-425.13.1.el8_7/linux-4.18.0-425.13.1.el8_7.x86_64/./arch/x86/include/asm/atomic.h: 198
0xffffffffb53f14d5 <_raw_spin_lock+5>:  xor    %eax,%eax
0xffffffffb53f14d7 <_raw_spin_lock+7>:  mov    $0x1,%edx
0xffffffffb53f14dc <_raw_spin_lock+12>: lock cmpxchg %edx,(%rdi)
0xffffffffb53f14e0 <_raw_spin_lock+16>: jne    0xffffffffb53f14e7 <_raw_spin_lock+23>
/usr/src/debug/kernel-4.18.0-425.13.1.el8_7/linux-4.18.0-425.13.1.el8_7.x86_64/kernel/locking/spinlock.c: 155
0xffffffffb53f14e2 <_raw_spin_lock+18>: jmp    0xffffffffb5601480 <__x86_return_thunk>
/usr/src/debug/kernel-4.18.0-425.13.1.el8_7/linux-4.18.0-425.13.1.el8_7.x86_64/./arch/x86/include/asm/paravirt.h: 694
0xffffffffb53f14e7 <_raw_spin_lock+23>: mov    %eax,%esi
0xffffffffb53f14e9 <_raw_spin_lock+25>: call   0xffffffffb4b55d20 <native_queued_spin_lock_slowpath>
0xffffffffb53f14ee <_raw_spin_lock+30>: xchg   %ax,%ax   v
                                                         |
crash> search 0xffffffffb4b55d20   < - - - - - - - - - - '
ffff91fb000917f0: ffffffffb4b55d20 
ffff920848fd7a90: ffffffffb4b55d20 
ffff920849638500: ffffffffb4b55d20 
ffffffffb5bd7a90: ffffffffb4b55d20 
ffffffffb6238500: ffffffffb4b55d20 > - -,
                                        |
crash> kmem ffffffffb6238500   < - - - -'
ffffffffb6238500 (D) pv_lock_ops

      PAGE         PHYSICAL      MAPPING       INDEX CNT FLAGS
ffffcdf879258e00  e49638000                0        0  1 17ffffc0000800 reserved

• Determine the CPU holding the spinlock by checking the backtrace of active tasks on each CPU:

crash> bt -a
PID: 0        TASK: ffffffffb6218840  CPU: 0    COMMAND: "swapper/0"
 #0 [ffffffffb6203e80] cpuidle_enter at ffffffffb5199c1c
 #1 [ffffffffb6203ea0] do_idle at ffffffffb4b2b7b8
 #2 [ffffffffb6203ef0] cpu_startup_entry at ffffffffb4b2b9ff
 #3 [ffffffffb6203f10] start_kernel at ffffffffb6bbb2e8
 #4 [ffffffffb6203f50] secondary_startup_64_no_verify at ffffffffb4a00107

PID: 5481     TASK: ffff91fb88478000  CPU: 1    COMMAND: "osysmond.bin"
 #0 [ffffa40454dd7ee8] __audit_syscall_exit at ffffffffb4bd45a5
 #1 [ffffa40454dd7f10] syscall_slow_exit_work at ffffffffb4a03a29
 #2 [ffffa40454dd7f38] do_syscall_64 at ffffffffb4a044c4
 #3 [ffffa40454dd7f50] entry_SYSCALL_64_after_hwframe at ffffffffb54000a9
    RIP: 00007f68f8e3fec6  RSP: 00007f68d7ce9120  RFLAGS: 00000246
    RAX: fffffffffffffff5  RBX: 00000000000000f0  RCX: 00007f68f8e3fec6
    RDX: 0000000000000001  RSI: 00007f68d7ce9160  RDI: 00000000000000f0
    RBP: 0000000000000000   R8: 0000000000000000   R9: 0000000000000000
    R10: 0000000000004000  R11: 0000000000000246  R12: 00007f68d7ce9160
    R13: 0000000000000001  R14: 0000000000004000  R15: 00007f68bc04e7f8
    ORIG_RAX: 000000000000002c  CS: 0033  SS: 002b

PID: 14142    TASK: ffff91fe1557c000  CPU: 2    COMMAND: "sadc"
 #0 [ffffa40460dcbec8] vfs_read at ffffffffb4d5d151
 #1 [ffffa40460dcbf00] ksys_read at ffffffffb4d5d5bf
 #2 [ffffa40460dcbf38] do_syscall_64 at ffffffffb4a043ab
 #3 [ffffa40460dcbf50] entry_SYSCALL_64_after_hwframe at ffffffffb54000a9
    RIP: 00007f675485ab25  RSP: 00007ffd70189068  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 0000559eda5682a0  RCX: 00007f675485ab25
    RDX: 0000000000001000  RSI: 0000559eda56c780  RDI: 0000000000000004
    RBP: 0000000000000d68   R8: 0000000000000063   R9: 0000000000000003
    R10: 0000000000000000  R11: 0000000000000246  R12: 00007f6754af6860
    R13: 00007f6754af73a0  R14: 0000000000000000  R15: 0000000000000000
    ORIG_RAX: 0000000000000000  CS: 0033  SS: 002b

PID: 0        TASK: ffff91fb068b4000  CPU: 3    COMMAND: "swapper/3"
 #0 [ffffa404462dfea0] cpuidle_enter at ffffffffb5199c1c
 #1 [ffffa404462dfec0] do_idle at ffffffffb4b2b7b8
 #2 [ffffa404462dff10] cpu_startup_entry at ffffffffb4b2b9ff
 #3 [ffffa404462dff30] start_secondary at ffffffffb4a5d0bc
 #4 [ffffa404462dff50] secondary_startup_64_no_verify at ffffffffb4a00107

PID: 0        TASK: ffff91fb068b8000  CPU: 4    COMMAND: "swapper/4"
 #0 [ffffa404462e7ea0] cpuidle_enter at ffffffffb5199c1c
 #1 [ffffa404462e7ec0] do_idle at ffffffffb4b2b7b8
 #2 [ffffa404462e7f10] cpu_startup_entry at ffffffffb4b2b9ff
 #3 [ffffa404462e7f30] start_secondary at ffffffffb4a5d0bc
 #4 [ffffa404462e7f50] secondary_startup_64_no_verify at ffffffffb4a00107

PID: 3641     TASK: ffff91fb1fba4000  CPU: 5    COMMAND: "evmd.bin"
 #0 [ffffa4045223bec0] syscall_trace_enter at ffffffffb4a03f2f
 #1 [ffffa4045223bf38] do_syscall_64 at ffffffffb4a043ab
 #2 [ffffa4045223bf50] entry_SYSCALL_64_after_hwframe at ffffffffb54000a9
    RIP: 00007fb9973a2ec6  RSP: 00007fb9928cfbe0  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 000000000000005d  RCX: 00007fb9973a2ec6
    RDX: 0000000000000001  RSI: 00007fb9928cfc40  RDI: 000000000000005d
    RBP: 0000000000000000   R8: 0000000000000000   R9: 0000000000000000
    R10: 0000000000004000  R11: 0000000000000246  R12: 00007fb9928cfc40
    R13: 0000000000000001  R14: 0000000000004000  R15: 00007fb980092018
    ORIG_RAX: 000000000000002c  CS: 0033  SS: 002b

PID: 0        TASK: ffff91fb068d0000  CPU: 6    COMMAND: "swapper/6"
 #0 [ffffa404462f7ea0] cpuidle_enter at ffffffffb5199c1c
 #1 [ffffa404462f7ec0] do_idle at ffffffffb4b2b7b8
 #2 [ffffa404462f7f10] cpu_startup_entry at ffffffffb4b2b9ff
 #3 [ffffa404462f7f30] start_secondary at ffffffffb4a5d0bc
 #4 [ffffa404462f7f50] secondary_startup_64_no_verify at ffffffffb4a00107

PID: 3779     TASK: ffff91fb1ac24000  CPU: 7    COMMAND: "modprobe"
 #0 [ffffa404539fbb10] KsMsgIssue at ffffffffc09f8745 [oracleoks]
 #1 [ffffa404539fbc48] KsLogReinit at ffffffffc09a8dd1 [oracleoks]
 #2 [ffffa404539fbc80] init_module at ffffffffc09f7f61 [oracleoks]
 #3 [ffffa404539fbcb8] do_one_initcall at ffffffffb4a02816
 #4 [ffffa404539fbd28] do_init_module at ffffffffb4baa80a
 #5 [ffffa404539fbd48] load_module at ffffffffb4baccff
 #6 [ffffa404539fbe78] __do_sys_finit_module at ffffffffb4bad2a1
 #7 [ffffa404539fbf38] do_syscall_64 at ffffffffb4a043ab
 #8 [ffffa404539fbf50] entry_SYSCALL_64_after_hwframe at ffffffffb54000a9
    RIP: 00007f970844a9bd  RSP: 00007fffb47879b8  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 00005565dbdc9710  RCX: 00007f970844a9bd
    RDX: 0000000000000000  RSI: 00005565db0cc8b6  RDI: 0000000000000003
    RBP: 00005565db0cc8b6   R8: 0000000000000000   R9: 0000000000000000
    R10: 0000000000000003  R11: 0000000000000246  R12: 0000000000000000
    R13: 00005565dbdd2d40  R14: 0000000000040000  R15: 0000000000000000
    ORIG_RAX: 0000000000000139  CS: 0033  SS: 002b

• The backtraces suggest that none of the active tasks is holding the spinlock.

• Check the detail of an out-of-tree (O) kernel module: [oracleoks]

crash> mod -t | grep -e NAME -e oracleoks
NAME             TAINTS
oracleoks        POE

crash> mod | grep -e NAME -e oracleoks
     MODULE       NAME                                     BASE           SIZE  OBJECT FILE
ffffffffc0a3fb80  oracleoks                          ffffffffc09a7000   827392  (not loaded)  [CONFIG_KALLSYMS]

crash> module.state,name,version,srcversion,rhelversion,sig_ok 0xffffffffc0a3fb80
  state       = MODULE_STATE_COMING,
  name        = "oracleoks\000\000\000\000\000\000\000\000\000\000\000\000\000",
  version     = 0x0,
  srcversion  = 0xffff91fb52d22f20 "533BB7E5866E52F63B9ACCB",
  rhelversion = 0xffff91fbc2f64a10 "8.7",
  sig_ok      = false,

• The [oracleoks] kernel module file inside 4.18.0-425.13.1.el8_7.x86_64/weak-updates/usm directory is a symlink to the [oracleoks] kernel module inside 4.18.0-425.3.1.el8.x86_64/extra/usm directory.

crash> files -d 0xffff91fd99c12b40
     DENTRY           INODE           SUPERBLK     TYPE PATH
ffff91fd99c12b40 ffff91fd99c93860 ffff91fca1b3d800 LNK  /usr/lib/modules/4.18.0-425.13.1.el8_7.x86_64/weak-updates/usm/oracleoks.ko

crash> struct inode.i_ino,i_size,i_nlink 0xffff91fd99c93860
  i_ino = 2499,
  i_size = 61,
    i_nlink = 1,

crash> files -d 0xffff91fd99c12300
     DENTRY           INODE           SUPERBLK     TYPE PATH
ffff91fd99c12300 ffff91fd99c96720 ffff91fca1b3d800 REG  /usr/lib/modules/4.18.0-425.3.1.el8.x86_64/extra/usm/oracleoks.ko

crash> struct inode.i_ino,i_size,i_nlink 0xffff91fd99c96720
  i_ino = 16799073,
  i_size = 22038200,
    i_nlink = 1,

• The out-of-tree (O) kernel module [oracleoks] is shipped by Oracle Corporation.