Re: Hard and soft lockups with FIO and LTP runs on a large system

[Bharata B Rao <bharata@amd.com>]

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

On 17-Jul-24 4:59 PM, Mateusz Guzik wrote:
> On Wed, Jul 17, 2024 at 11:42 AM Vlastimil Babka <vbabka@suse.cz> wrote:
>>
>> On 7/3/24 5:11 PM, Bharata B Rao wrote:
>>> The general observation is that the problem usually surfaces when the
>>> system free memory goes very low and page cache/buffer consumption hits
>>> the ceiling. Most of the times the two contended locks are lruvec and
>>> inode->i_lock spinlocks.
>>>
> [snip mm stuff]
> 
> There are numerous avoidable i_lock acquires (including some only
> showing up under load), but I don't know if they play any role in this
> particular test.
> 
> Collecting all traces would definitely help, locked up or not, for example:
> bpftrace -e 'kprobe:queued_spin_lock_slowpath { @[kstack()] = count();
> }' -o traces

Here are the top 3 traces collected while the full list from a 30s 
collection duration when the workload was running, is attached.

@[
     native_queued_spin_lock_slowpath+1
     __remove_mapping+98
     remove_mapping+22
     mapping_evict_folio+118
     mapping_try_invalidate+214
     invalidate_mapping_pages+16
     invalidate_bdev+60
     blkdev_common_ioctl+1527
     blkdev_ioctl+265
     __x64_sys_ioctl+149
     x64_sys_call+4629
     do_syscall_64+126
     entry_SYSCALL_64_after_hwframe+118
]: 1787212
@[
     native_queued_spin_lock_slowpath+1
     folio_wait_bit_common+205
     filemap_get_pages+1543
     filemap_read+231
     blkdev_read_iter+111
     aio_read+242
     io_submit_one+546
     __x64_sys_io_submit+132
     x64_sys_call+6617
     do_syscall_64+126
     entry_SYSCALL_64_after_hwframe+118
]: 7922497
@[
     native_queued_spin_lock_slowpath+1
     clear_shadow_entry+92
     mapping_try_invalidate+337
     invalidate_mapping_pages+16
     invalidate_bdev+60
     blkdev_common_ioctl+1527
     blkdev_ioctl+265
     __x64_sys_ioctl+149
     x64_sys_call+4629
     do_syscall_64+126
     entry_SYSCALL_64_after_hwframe+118
]: 10357614

> 
> As for clear_shadow_entry mentioned in the opening mail, the content is:
>          spin_lock(&mapping->host->i_lock);
>          xa_lock_irq(&mapping->i_pages);
>          __clear_shadow_entry(mapping, index, entry);
>          xa_unlock_irq(&mapping->i_pages);
>          if (mapping_shrinkable(mapping))
>                  inode_add_lru(mapping->host);
>          spin_unlock(&mapping->host->i_lock);
> 
> so for all I know it's all about the xarray thing, not the i_lock per se.

The soft lockup signature has _raw_spin_lock and not _raw_spin_lock_irq 
and hence concluded it to be i_lock. Re-pasting the clear_shadow_entry 
softlockup here again:

kernel: watchdog: BUG: soft lockup - CPU#29 stuck for 11s! [fio:2701649]
kernel: CPU: 29 PID: 2701649 Comm: fio Tainted: G             L
6.10.0-rc3-mglru-irqstrc #24
kernel: RIP: 0010:native_queued_spin_lock_slowpath+0x2b4/0x300
kernel: Call Trace:
kernel:  <IRQ>
kernel:  ? show_regs+0x69/0x80
kernel:  ? watchdog_timer_fn+0x223/0x2b0
kernel:  ? __pfx_watchdog_timer_fn+0x10/0x10
<SNIP>
kernel:  </IRQ>
kernel:  <TASK>
kernel:  ? asm_sysvec_apic_timer_interrupt+0x1b/0x20
kernel:  ? native_queued_spin_lock_slowpath+0x2b4/0x300
kernel:  _raw_spin_lock+0x38/0x50
kernel:  clear_shadow_entry+0x3d/0x100
kernel:  ? __pfx_workingset_update_node+0x10/0x10
kernel:  mapping_try_invalidate+0x117/0x1d0
kernel:  invalidate_mapping_pages+0x10/0x20
kernel:  invalidate_bdev+0x3c/0x50
kernel:  blkdev_common_ioctl+0x5f7/0xa90
kernel:  blkdev_ioctl+0x109/0x270
kernel:  x64_sys_call+0x1215/0x20d0
kernel:  do_syscall_64+0x7e/0x130

Regards,
Bharata.

[-- Attachment #2: traces.gz --]
[-- Type: application/x-gzip, Size: 83505 bytes --]