RHEL9: Soft lockups observed due to spinlock contention occurred from lru_gen functions

Issue

• Soft lockup occurred with the logs below:

[1886533.121548] watchdog: BUG: soft lockup - CPU#21 stuck for 22s! [postgres:1756463]
[1886533.122281] CPU: 21 PID: 1756463 Comm: postgres Kdump: loaded Tainted: G           OE     -------  ---  5.14.0-503.11.1.el9_5.x86_64 #1
[1886533.122489] Hardware name: Red Hat OpenStack Compute, BIOS 1.11.0-2.el7 04/01/2014
[1886533.122601] RIP: 0010:_raw_spin_unlock_irqrestore+0x1b/0x30
[1886533.122772] Code: 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 e8 36 07 00 00 90 f7 c6 00 02 00 00 74 01 fb 65 ff 0d dd ea 94 72 <74> 05 c3 cc cc cc cc 0f 1f 44 00 00 c3 cc cc cc cc 0f 1f 40 00 90
[1886533.122978] RSP: 0018:ffffb097ced07a08 EFLAGS: 00000246
[1886533.123080] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff96e4730795b8
[1886533.123177] RDX: 0000000000000001 RSI: 0000000000000206 RDI: ffff96f37ffffb70
[1886533.123279] RBP: ffff96e714beb000 R08: ffff96e714bee5b8 R09: ffff96ee619895b8
[1886533.123375] R10: ffff96f37ffffb20 R11: 0000000000000000 R12: ffffb097ced07b68
[1886533.123473] R13: ffff96e714bee000 R14: 0000000000000004 R15: ffff96e6ccccc5b8
[1886533.123578] FS:  00007fb135eab9c0(0000) GS:ffff96f33fb40000(0000) knlGS:0000000000000000
[1886533.123704] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[1886533.123819] CR2: 000055e6a21cbf88 CR3: 00000003ed7d8002 CR4: 00000000007706f0
[1886533.123932] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[1886533.124031] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[1886533.124140] PKRU: 55555554
[1886533.124236] Call Trace:
[1886533.127503]  <TASK>
[1886533.127764]  ? asm_sysvec_apic_timer_interrupt+0x16/0x20
[1886533.128068]  ? _raw_spin_unlock_irqrestore+0x1b/0x30
[1886533.128325]  ? _raw_spin_unlock_irqrestore+0xa/0x30
[1886533.128573]  shrink_many+0x160/0x2a0
[1886533.128827]  lru_gen_shrink_node+0x12c/0x1c0
[1886533.129065]  shrink_zones.constprop.0+0x88/0x280
[1886533.129299]  do_try_to_free_pages+0x92/0x2d0
[1886533.129530]  try_to_free_pages+0xd8/0x200
[1886533.129768]  __alloc_pages_slowpath.constprop.0+0x2fc/0x970
[1886533.130010]  ? get_page_from_freelist+0x28a/0x650
[1886533.130241]  __alloc_pages+0x21d/0x250
[1886533.130469]  __folio_alloc+0x17/0x50
[1886533.130701]  ? policy_node+0x4f/0x70
[1886533.130923]  vma_alloc_folio+0xa3/0x390
[1886533.131141]  do_anonymous_page+0x5e/0x410
[1886533.131353]  __handle_mm_fault+0x2fb/0x690
[1886533.131554]  ? nohz_balancer_kick+0x31/0x240
[1886533.131785]  handle_mm_fault+0xdc/0x270
[1886533.131972]  do_user_addr_fault+0x1b4/0x6a0
[1886533.132163]  exc_page_fault+0x62/0x150
[1886533.132344]  asm_exc_page_fault+0x22/0x30
[1886533.134265]  </TASK>

• Another pattern is that the memory is heavily under pressure with swap being fully used.

PID: 1655607  TASK: ffff9dfb71b95700  CPU: 78   COMMAND: "ps_find.fcgi"
 #0 [fffffe01aece9e60] crash_nmi_callback at ffffffff8da69311
 #1 [fffffe01aece9e68] nmi_handle at ffffffff8da3008e
 #2 [fffffe01aece9eb0] default_do_nmi at ffffffff8e681fc0
 #3 [fffffe01aece9ed0] exc_nmi at ffffffff8e6821d1
 #4 [fffffe01aece9ef0] end_repeat_nmi at ffffffff8e801639
    [exception RIP: native_queued_spin_lock_slowpath+638]
    RIP: ffffffff8e6970de  RSP: ffffb961766b3898  RFLAGS: 00000046
    RAX: 0000000000000000  RBX: ffff9e203edb3e40  RCX: 00000000013c0000
    RDX: 0000000000000017  RSI: 0000000000600000  RDI: ffff9e213f0ffb28
    RBP: ffff9e213f0ffb28   R8: 0000000000000000   R9: 0000000000000003
    R10: 0000000000000005  R11: 0000000000000001  R12: 0000000000000000
    R13: 000000000000004e  R14: ffff9e213f0ffb28  R15: ffff9e22f7edb000
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0018
--- <NMI exception stack> ---
 #5 [ffffb961766b3898] native_queued_spin_lock_slowpath at ffffffff8e6970de
 #6 [ffffb961766b38b8] _raw_spin_lock_irqsave at ffffffff8e696660
 #7 [ffffb961766b38c8] lru_gen_rotate_memcg at ffffffff8dd45134
 #8 [ffffb961766b38f8] shrink_many at ffffffff8dd510c6
 #9 [ffffb961766b3950] shrink_node at ffffffff8dd51626
#10 [ffffb961766b39d0] shrink_zones.constprop.0 at ffffffff8dd522f8
#11 [ffffb961766b3a18] do_try_to_free_pages at ffffffff8dd52592
#12 [ffffb961766b3a60] try_to_free_pages at ffffffff8dd52c38
#13 [ffffb961766b3b00] __alloc_pages_slowpath.constprop.0 at ffffffff8ddaabb4
#14 [ffffb961766b3bd0] __alloc_pages at ffffffff8ddab3fd
#15 [ffffb961766b3c30] allocate_slab at ffffffff8dddd570
#16 [ffffb961766b3c88] ___slab_alloc at ffffffff8dddf93d
#17 [ffffb961766b3d60] __kmem_cache_alloc_node at ffffffff8dde2568
#18 [ffffb961766b3db0] __kmalloc at ffffffff8dd694bb
#19 [ffffb961766b3de0] __d_alloc at ffffffff8de50dfd
#20 [ffffb961766b3e08] d_alloc at ffffffff8de50e9b
#21 [ffffb961766b3e40] __lookup_hash at ffffffff8de3ff33
#22 [ffffb961766b3e78] do_unlinkat at ffffffff8de47f7a
#23 [ffffb961766b3ef0] __x64_sys_unlink at ffffffff8de4824e
#24 [ffffb961766b3f00] do_syscall_64 at ffffffff8e68045c
#25 [ffffb961766b3f50] entry_SYSCALL_64_after_hwframe at ffffffff8e8000ea

• Another pattern is that the kswapd and application is running at free_pages.

PID: 968      TASK: ffff9de1ea3c3a00  CPU: 111  COMMAND: "kswapd1"
 #0 [fffffe6793c3ae60] crash_nmi_callback at ffffffff8da69311
 #1 [fffffe6793c3ae68] nmi_handle at ffffffff8da3008e
 #2 [fffffe6793c3aeb0] default_do_nmi at ffffffff8e681fc0
 #3 [fffffe6793c3aed0] exc_nmi at ffffffff8e6821d1
 #4 [fffffe6793c3aef0] end_repeat_nmi at ffffffff8e801639
    [exception RIP: native_queued_spin_lock_slowpath+635]
    RIP: ffffffff8e6970db  RSP: ffffb95e4fdf7c98  RFLAGS: 00000046
    RAX: 0000000000000000  RBX: ffff9e603f7f3e40  RCX: 0000000001c00000
    RDX: 0000000000000044  RSI: 0000000001140000  RDI: ffff9e213f0ffb28
    RBP: ffff9e213f0ffb28   R8: 0000000000000001   R9: 0000000000000004
    R10: 0000000000000005  R11: 0000000000000001  R12: 0000000000000000
    R13: 000000000000006f  R14: ffff9e213f0ffb28  R15: ffff9e247279e000
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0018
--- <NMI exception stack> ---
 #5 [ffffb95e4fdf7c98] native_queued_spin_lock_slowpath at ffffffff8e6970db
 #6 [ffffb95e4fdf7cb8] _raw_spin_lock_irq at ffffffff8e696d16
 #7 [ffffb95e4fdf7cc0] lru_gen_release_memcg at ffffffff8dd50ea6
 #8 [ffffb95e4fdf7cf0] shrink_many at ffffffff8dd511c2
 #9 [ffffb95e4fdf7d48] shrink_node at ffffffff8dd51626
#10 [ffffb95e4fdf7dc8] balance_pgdat at ffffffff8dd5196e
#11 [ffffb95e4fdf7ee0] kswapd at ffffffff8dd51ef2
#12 [ffffb95e4fdf7f18] kthread at ffffffff8db358d0
#13 [ffffb95e4fdf7f50] ret_from_fork at ffffffff8da02c6c

• Another pattern is that Transparent Huge Pages (THP) are enabled and memory is free in the system but THP allocation causes soft lockup.

kernel: watchdog: BUG: soft lockup - CPU#11 stuck for 26s! [khugepaged:2643139]
kernel: watchdog: BUG: soft lockup - CPU#11 stuck for 26s! [khugepaged:2643139]

PID: 460979   TASK: ff46f09dd5394680  CPU: 137  COMMAND: "HanaWorker"
 #0 [ff7fa73d1ab04d68] machine_kexec at ffffffff81e782f7
 #1 [ff7fa73d1ab04dc0] __crash_kexec at ffffffff81fef99a
 #2 [ff7fa73d1ab04e80] panic at ffffffff82a2c8cd
 #3 [ff7fa73d1ab04f00] watchdog_timer_fn.cold at ffffffff82a382ff
 #4 [ff7fa73d1ab04f28] __hrtimer_run_queues at ffffffff81fc79d7
 #5 [ff7fa73d1ab04f88] hrtimer_interrupt at ffffffff81fc841c
 #6 [ff7fa73d1ab04fd8] __sysvec_apic_timer_interrupt at ffffffff81e6d5ac
 #7 [ff7fa73d1ab04ff0] sysvec_apic_timer_interrupt at ffffffff82a8606d
--- <IRQ stack> ---
 #8 [ff7fa73d2c997928] asm_sysvec_apic_timer_interrupt at ffffffff82c00e86
    [exception RIP: _raw_spin_unlock_irqrestore+28]
    RIP: ffffffff82a9871c  RSP: ff7fa73d2c9979d8  RFLAGS: 00000246
    RAX: 0000000000000001  RBX: ff46f09cdc5ec5b8  RCX: 0000000000000001
    RDX: ff46f099fffd5008  RSI: 0000000000000246  RDI: ff46f099fffffb28
    RBP: 0000000000000002   R8: 0000000000000002   R9: 0000000000000001
    R10: ff46f0d3e1e6f5b8  R11: ff46f0d0d5fc05b8  R12: ff46f09e6bffa000
    R13: ff7fa73d2c997b48  R14: 0000000000000001  R15: ff46f0a363059000
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0000
 #9 [ff7fa73d2c9979d0] _raw_spin_unlock_irqrestore at ffffffff82a9870a
#10 [ff7fa73d2c9979d8] shrink_many at ffffffff82151594
#11 [ff7fa73d2c997a30] shrink_node at ffffffff82151b46
#12 [ff7fa73d2c997ab0] shrink_zones.constprop.0 at ffffffff82152818
#13 [ff7fa73d2c997af8] do_try_to_free_pages at ffffffff82152ab2
#14 [ff7fa73d2c997b40] try_to_free_pages at ffffffff82153158
#15 [ff7fa73d2c997be0] __alloc_pages_slowpath.constprop.0 at ffffffff821ab2a4
#16 [ff7fa73d2c997cb0] __alloc_pages at ffffffff821abaed
#17 [ff7fa73d2c997d10] __folio_alloc at ffffffff821ac237
#18 [ff7fa73d2c997d28] vma_alloc_folio at ffffffff821d0b21
#19 [ff7fa73d2c997d78] do_huge_pmd_anonymous_page at ffffffff821f16c6
#20 [ff7fa73d2c997dc0] __handle_mm_fault at ffffffff821849f1
#21 [ff7fa73d2c997ea0] handle_mm_fault at ffffffff82184add
#22 [ff7fa73d2c997ed8] do_user_addr_fault at ffffffff81e8ade4
#23 [ff7fa73d2c997f28] exc_page_fault at ffffffff82a86aa2
#24 [ff7fa73d2c997f50] asm_exc_page_fault at ffffffff82c00c12