Hi Bharata, On Wed, Jul 3, 2024 at 9:11 AM Bharata B Rao <bharata@xxxxxxx> wrote: > > Many soft and hard lockups are seen with upstream kernel when running a > bunch of tests that include FIO and LTP filesystem test on 10 NVME > disks. The lockups can appear anywhere between 2 to 48 hours. Originally > this was reported on a large customer VM instance with passthrough NVME > disks on older kernels(v5.4 based). However, similar problems were > reproduced when running the tests on bare metal with latest upstream > kernel (v6.10-rc3). Other lockups with different signatures are seen but > in this report, only those related to MM area are being discussed. > Also note that the subsequent description is related to the lockups in > bare metal upstream (and not VM). > > 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. > > - Could this be a scalability issue in LRU list handling and/or page > cache invalidation typical to a large system configuration? > - Are there any MM/FS tunables that could help here? > > Hardware configuration > ====================== > Dual socket AMD EPYC 128 Core processor (256 cores, 512 threads) > Memory: 1.5 TB > 10 NVME - 3.5TB each > available: 2 nodes (0-1) > node 0 cpus: 0-127,256-383 > node 0 size: 773727 MB > node 1 cpus: 128-255,384-511 > node 1 size: 773966 MB > > Workload details > ================ > Workload includes concurrent runs of FIO and a few FS tests from LTP. > > FIO is run with a size of 1TB on each NVME partition with different > combinations of ioengine/blocksize/mode parameters and buffered-IO. > Selected FS tests from LTP are run on 256GB partitions of all NVME > disks. This is the typical NVME partition layout. > > nvme2n1 259:4 0 3.5T 0 disk > ├─nvme2n1p1 259:6 0 256G 0 part /data_nvme2n1p1 > └─nvme2n1p2 259:7 0 3.2T 0 part > > Though many different runs exist in the workload, the combination that > results in the problem is buffered-IO run with sync engine. > > fio -filename=/dev/nvme1n1p2 -direct=0 -thread -size=1024G \ > -rwmixwrite=30 --norandommap --randrepeat=0 -ioengine=sync -bs=4k \ > -numjobs=400 -runtime=25000 --time_based -group_reporting -name=mytest > > Watchdog threshold was reduced to 5s to reproduce the problem early and > all CPU backtrace enabled. > > Problem details and analysis > ============================ > One of the hard lockups which was observed and analyzed in detail is this: > > kernel: watchdog: Watchdog detected hard LOCKUP on cpu 284 > kernel: CPU: 284 PID: 924096 Comm: cat Not tainted 6.10.0-rc3-lruvec #9 > kernel: RIP: 0010:native_queued_spin_lock_slowpath+0x2b4/0x300 > kernel: Call Trace: > kernel: <NMI> > kernel: ? show_regs+0x69/0x80 > kernel: ? watchdog_hardlockup_check+0x19e/0x360 > <SNIP> > kernel: ? native_queued_spin_lock_slowpath+0x2b4/0x300 > kernel: </NMI> > kernel: <TASK> > kernel: ? __pfx_lru_add_fn+0x10/0x10 > kernel: _raw_spin_lock_irqsave+0x42/0x50 > kernel: folio_lruvec_lock_irqsave+0x62/0xb0 > kernel: folio_batch_move_lru+0x79/0x2a0 > kernel: folio_add_lru+0x6d/0xf0 > kernel: filemap_add_folio+0xba/0xe0 > kernel: __filemap_get_folio+0x137/0x2e0 > kernel: ext4_da_write_begin+0x12c/0x270 > kernel: generic_perform_write+0xbf/0x200 > kernel: ext4_buffered_write_iter+0x67/0xf0 > kernel: ext4_file_write_iter+0x70/0x780 > kernel: vfs_write+0x301/0x420 > kernel: ksys_write+0x67/0xf0 > kernel: __x64_sys_write+0x19/0x20 > kernel: x64_sys_call+0x1689/0x20d0 > kernel: do_syscall_64+0x6b/0x110 > kernel: entry_SYSCALL_64_after_hwframe+0x76/0x7e kernel: RIP: > 0033:0x7fe21c314887 > > With all CPU backtraces enabled, many CPUs are waiting for lruvec_lock > acquisition. We measured the lruvec spinlock start, end and hold > time(htime) using sched_clock(), along with a BUG() if the hold time was > more than 10s. The below case shows that lruvec spin lock was held for ~25s. > > kernel: vmscan: unlock_page_lruvec_irq: stime 27963327514341, etime > 27963324369895, htime 25889317166 > kernel: ------------[ cut here ]------------ > kernel: kernel BUG at include/linux/memcontrol.h:1677! > kernel: Oops: invalid opcode: 0000 [#1] PREEMPT SMP NOPTI > kernel: CPU: 21 PID: 3211 Comm: kswapd0 Tainted: G W > 6.10.0-rc3-qspindbg #10 > kernel: RIP: 0010:shrink_active_list+0x40a/0x520 > > And the corresponding trace point for the above: > kswapd0-3211 [021] dN.1. 27963.324332: mm_vmscan_lru_isolate: > classzone=0 order=0 nr_requested=1 nr_scanned=156946361 > nr_skipped=156946360 nr_taken=1 lru=active_file > > This shows that isolate_lru_folios() is scanning through a huge number > (~150million) of folios (order=0) with lruvec spinlock held. This is > happening because a large number of folios are being skipped to isolate > a few ZONE_DMA folios. Though the number of folios to be scanned is > bounded (32), there exists a genuine case where this can become > unbounded, i.e. in case where folios are skipped. > > Meminfo output shows that the free memory is around ~2% and page/buffer > cache grows very high when the lockup happens. > > MemTotal: 1584835956 kB > MemFree: 27805664 kB > MemAvailable: 1568099004 kB > Buffers: 1386120792 kB > Cached: 151894528 kB > SwapCached: 30620 kB > Active: 1043678892 kB > Inactive: 494456452 kB > > Often times, the perf output at the time of the problem shows heavy > contention on lruvec spin lock. Similar contention is also observed with > inode i_lock (in clear_shadow_entry path) > > 98.98% fio [kernel.kallsyms] [k] native_queued_spin_lock_slowpath > | > --98.96%--native_queued_spin_lock_slowpath > | > --98.96%--_raw_spin_lock_irqsave > folio_lruvec_lock_irqsave > | > --98.78%--folio_batch_move_lru > | > --98.63%--deactivate_file_folio > mapping_try_invalidate > invalidate_mapping_pages > invalidate_bdev > blkdev_common_ioctl > blkdev_ioctl > __x64_sys_ioctl > x64_sys_call > do_syscall_64 > entry_SYSCALL_64_after_hwframe > > Some experiments tried > ====================== > 1) When MGLRU was enabled many soft lockups were observed, no hard > lockups were seen for 48 hours run. Below is once such soft lockup. This is not really an MGLRU issue -- can you please try one of the attached patches? It (truncate.patch) should help with or without MGLRU. > 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 > > This happens to be contending on inode i_lock spinlock. > > Below preemptirqsoff trace points to preemption being disabled for more > than 10s and the lock in picture is lruvec spinlock. Also if you could try the other patch (mglru.patch) please. It should help reduce unnecessary rotations from deactivate_file_folio(), which in turn should reduce the contention on the LRU lock for MGLRU. > # tracer: preemptirqsoff > # > # preemptirqsoff latency trace v1.1.5 on 6.10.0-rc3-mglru-irqstrc > # -------------------------------------------------------------------- > # latency: 10382682 us, #4/4, CPU#128 | (M:desktop VP:0, KP:0, SP:0 > HP:0 #P:512) > # ----------------- > # | task: fio-2701523 (uid:0 nice:0 policy:0 rt_prio:0) > # ----------------- > # => started at: deactivate_file_folio > # => ended at: deactivate_file_folio > # > # > # _------=> CPU# > # / _-----=> irqs-off/BH-disabled > # | / _----=> need-resched > # || / _---=> hardirq/softirq > # ||| / _--=> preempt-depth > # |||| / _-=> migrate-disable > # ||||| / delay > # cmd pid |||||| time | caller > # \ / |||||| \ | / > fio-2701523 128...1. 0us$: deactivate_file_folio > <-deactivate_file_folio > fio-2701523 128.N.1. 10382681us : deactivate_file_folio > <-deactivate_file_folio > fio-2701523 128.N.1. 10382683us : tracer_preempt_on > <-deactivate_file_folio > fio-2701523 128.N.1. 10382691us : <stack trace> > => deactivate_file_folio > => mapping_try_invalidate > => invalidate_mapping_pages > => invalidate_bdev > => blkdev_common_ioctl > => blkdev_ioctl > => __x64_sys_ioctl > => x64_sys_call > => do_syscall_64 > => entry_SYSCALL_64_after_hwframe > > 2) Increased low_watermark_threshold to 10% to prevent system from > entering into extremely low memory situation. Although hard lockups > weren't seen, but soft lockups (clear_shadow_entry()) were still seen. > > 3) AMD has a BIOS setting called NPS (Nodes per socket), using which a > socket can be further partitioned into smaller NUMA nodes. With NPS=4, > there will be four NUMA nodes in one socket, and hence 8 NUMA nodes in > the system. This was done to check if having more number of kswapd > threads working on lesser number of folios per node would make a > difference. However here too, multiple soft lockups were seen (in > clear_shadow_entry() as seen in MGLRU case). No hard lockups were observed. > > Any insights/suggestion into these lockups and suggestions are welcome! Thanks!
Attachment:
mglru.patch
Description: Binary data
Attachment:
truncate.patch
Description: Binary data
