Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

zpool scrub leaks memory, leading to OOM within seconds #11756

Closed
sideeffect42 opened this issue Mar 16, 2021 · 5 comments
Closed

zpool scrub leaks memory, leading to OOM within seconds #11756

sideeffect42 opened this issue Mar 16, 2021 · 5 comments
Labels
Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang)

Comments

@sideeffect42
Copy link

System information

Type Version/Name
Distribution Name Devuan
Distribution Version beowulf (3)
Linux Kernel 4.19.171-2
Architecture ppc64el (Power 9)
ZFS Version 2.0.3-1~bpo10+1
SPL Version 2.0.3-1~bpo10+1

Describe the problem you're observing

Upon import of a ZFS pool the memory allocation increases until all memory has been allocated, triggering the OOM killer.
Once the OOM killer has killed everything it can, the kernel goes into memory deadlock.

[ 1466.189197] Out of memory and no killable processes...
[ 1466.189266] Kernel panic - not syncing: System is deadlocked on memory

Describe how to reproduce the problem

Boot the system, import the ZFS pool and wait a few seconds.

Include any warning/errors/backtraces from the system logs

Console output from init=/bin/bash:

root@(none):/# zpool import tank
[ 1452.330521]  zd0: p1 p2 p3
[ 1452.393000]  zd16: p1 p2 p3
[ 1452.458478]  zd32: p1 p2 p3
[ 1452.500614]  zd48: p1 p2 p3
[ 1452.525284]  zd64: p1 p2 p3
[ 1452.689894]  zd96: p1 p2 p3
[ 1452.768414]  zd112: p1 p2
[ 1452.798165]  zd128: p1 p2 p3
[ 1452.815358]  zd144: p1 p2 p3
root@(none):/# date; free
Tue Mar 16 14:15:08 CET 2021
              total        used        free      shared  buff/cache   available
Mem:       66640832    40411008    26132928        2112       96896    25861952
Swap:             0           0           0
root@(none):/etc/init.d# date; free
Tue Mar 16 14:15:10 CET 2021
              total        used        free      shared  buff/cache   available
Mem:       66640832    43243008    23300800        2112       97024    23029952
Swap:             0           0           0
root@(none):/etc/init.d# date; free
Tue Mar 16 14:15:12 CET 2021
              total        used        free      shared  buff/cache   available
Mem:       66640832    48985216    17558464        2112       97152    17287680
Swap:             0           0           0
root@(none):/etc/init.d# date; free
Tue Mar 16 14:15:14 CET 2021
              total        used        free      shared  buff/cache   available
Mem:       66640832    54236032    12307648        2112       97152    12036864
Swap:             0           0           0
root@(none):/etc/init.d# date; free
Tue Mar 16 14:15:16 CET 2021
              total        used        free      shared  buff/cache   available
Mem:       66640832    58403776     8139904        2112       97152     7869120
Swap:             0           0           0
root@(none):/etc/init.d# date; free
Tue Mar 16 14:15:18 CET 2021
[ 1466.185310] bash invoked oom-killer: gfp_mask=0x7080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null), order=0, oom_score_adj=0
[ 1466.185334] bash cpuset=/ mems_allowed=0
[ 1466.185347] CPU: 9 PID: 1 Comm: bash Tainted: P           O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
[ 1466.185374] Call Trace:
[ 1466.185385] [c000000f27793880] [c0000000009a4ae8] dump_stack+0xbc/0x104 (unreliable)
[ 1466.185412] [c000000f277938c0] [c0000000002d9c28] dump_header+0x78/0x310
[ 1466.185426] [c000000f27793980] [c0000000002dbaa4] out_of_memory+0x6b4/0x730
[ 1466.185455] [c000000f27793a20] [c0000000002e4468] __alloc_pages_nodemask+0xf78/0x1020
[ 1466.185496] [c000000f27793bf0] [c0000000003700ec] alloc_pages_current+0xbc/0x140
[ 1466.185526] [c000000f27793c30] [c0000000002ddaa8] __get_free_pages+0x28/0x80
[ 1466.185563] [c000000f27793c50] [c000000000103910] mm_init+0x140/0x2f0
[ 1466.185600] [c000000f27793ca0] [c000000000105b44] copy_process.isra.4.part.5+0x1074/0x1d00
[ 1466.185650] [c000000f27793da0] [c000000000106a30] _do_fork+0xf0/0x550
[ 1466.185665] [c000000f27793e30] [c00000000000bc98] ppc_clone+0x8/0xc
[ 1466.185699] Mem-Info:
[ 1466.185731] active_anon:49 inactive_anon:10 isolated_anon:0
[ 1466.185731]  active_file:17 inactive_file:35 isolated_file:0
[ 1466.185731]  unevictable:417 dirty:1 writeback:0 unstable:0
[ 1466.185731]  slab_reclaimable:431 slab_unreclaimable:5825
[ 1466.185731]  mapped:196 shmem:33 pagetables:3 bounce:0
[ 1466.185731]  free:55263 free_pcp:0 free_cma:52480
[ 1466.185796] Node 0 active_anon:3136kB inactive_anon:640kB active_file:1088kB inactive_file:2240kB unevictable:26688kB isolated(anon):0kB isolated(file):0kB mapped:12544kB dirty:64kB writeback:0kB shmem:2112kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 10240kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[ 1466.185865] Node 0 DMA free:3536832kB min:180224kB low:246784kB high:313344kB active_anon:3136kB inactive_anon:640kB active_file:0kB inactive_file:0kB unevictable:26688kB writepending:64kB present:67108864kB managed:66640832kB mlocked:27392kB kernel_stack:7760kB pagetables:192kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:3358720kB
[ 1466.185984] lowmem_reserve[]: 0 0 0 0
[ 1466.186009] Node 0 DMA: 157*64kB (UME) 119*128kB (ME) 71*256kB (UM) 29*512kB (UM) 9*1024kB (M) 4*2048kB (UM) 3*4096kB (ME) 2*8192kB (UM) 210*16384kB (MC) = 3545024kB
[ 1466.186086] Node 0 hugepages_total=512 hugepages_free=512 hugepages_surp=0 hugepages_size=2048kB
[ 1466.186149] Node 0 hugepages_total=16 hugepages_free=16 hugepages_surp=0 hugepages_size=1048576kB
[ 1466.186179] 256 total pagecache pages
[ 1466.186199] 0 pages in swap cache
[ 1466.186231] Swap cache stats: add 0, delete 0, find 0/0
[ 1466.186277] Free swap  = 0kB
[ 1466.186310] Total swap = 0kB
[ 1466.186329] 1048576 pages RAM
[ 1466.186358] 0 pages HighMem/MovableOnly
[ 1466.186377] 7313 pages reserved
[ 1466.186396] 52480 pages cma reserved
[ 1466.186426] 0 pages hwpoisoned
[ 1466.186449] Unreclaimable slab info:
[ 1466.186477] Name                      Used          Total
[ 1466.186503] zfs_znode_cache          126KB        126KB
[ 1466.186526] kcopyd_job               504KB        504KB
[ 1466.186551] sd_ext_cdb               576KB        576KB
[ 1466.186572] scsi_sense_cache        1472KB       1472KB
[ 1466.186594] RAWv6                     63KB         63KB
[ 1466.186640] mqueue_inode_cache         64KB         64KB
[ 1466.186662] kioctx                   255KB        255KB
[ 1466.186707] secpath_cache            320KB        320KB
[ 1466.186729] RAW                       64KB         64KB
[ 1466.186765] hugetlbfs_inode_cache         63KB         63KB
[ 1466.186796] eventpoll_pwq           1215KB       1215KB
[ 1466.186838] inotify_inode_mark        447KB        447KB
[ 1466.186880] request_queue           1007KB       1007KB
[ 1466.186912] blkdev_ioc              2047KB       2047KB
[ 1466.186947] biovec-max              1920KB       1920KB
[ 1466.186979] biovec-128                64KB         64KB
[ 1466.187004] biovec-64                 64KB         64KB
[ 1466.187036] khugepaged_mm_slot        639KB        639KB
[ 1466.187068] ksm_rmap_item            384KB        384KB
[ 1466.187100] skbuff_fclone_cache         64KB         64KB
[ 1466.187132] skbuff_head_cache       1920KB       1920KB
[ 1466.187152] file_lock_cache         1213KB       1213KB
[ 1466.187185] fsnotify_mark_connector        511KB        511KB
[ 1466.187197] shmem_inode_cache       1919KB       1919KB
[ 1466.187218] taskstats                446KB        446KB
[ 1466.187253] proc_dir_entry           959KB        959KB
[ 1466.187284] pde_opener              1983KB       1983KB
[ 1466.187326] sigqueue                2045KB       2045KB
[ 1466.187358] kernfs_node_cache       7282KB       7282KB
[ 1466.187389] mnt_cache               2103KB       2103KB
[ 1466.187422] names_cache             4096KB       4096KB
[ 1466.187464] nsproxy                  831KB        831KB
[ 1466.187497] vm_area_struct          2175KB       2175KB
[ 1466.187523] mm_struct               8096KB       8096KB
[ 1466.187533] files_cache             1848KB       1848KB
[ 1466.187568] signal_cache            3150KB       3150KB
[ 1466.187603] sighand_cache           4271KB       4271KB
[ 1466.187624] task_struct            11636KB      11636KB
[ 1466.187657] cred_jar                2816KB       2816KB
[ 1466.187688] thread_stack           44032KB      44032KB
[ 1466.187709] anon_vma_chain          2112KB       2112KB
[ 1466.187746] anon_vma                2046KB       2046KB
[ 1466.187792] pid                     2048KB       2048KB
[ 1466.187815] numa_policy               63KB         63KB
[ 1466.187860] trace_event_file         319KB        319KB
[ 1466.187887] ftrace_event_field        319KB        319KB
[ 1466.187897] pool_workqueue          2112KB       2112KB
[ 1466.187908] task_group               127KB        127KB
[ 1466.187918] pgtable-2^9             8448KB       8448KB
[ 1466.187940] kmalloc-131072         13312KB      13312KB
[ 1466.187965] kmalloc-65536          16896KB      16896KB
[ 1466.187986] kmalloc-32768           3584KB       3584KB
[ 1466.188021] kmalloc-16384          11776KB      11776KB
[ 1466.188052] kmalloc-8192            6656KB       6656KB
[ 1466.188084] kmalloc-4096           16896KB      16896KB
[ 1466.188115] kmalloc-2048           16162KB      16192KB
[ 1466.188159] kmalloc-1024            7744KB       7744KB
[ 1466.188212] kmalloc-512             4096KB       4096KB
[ 1466.188285] kmalloc-256             2240KB       2240KB
[ 1466.188374] kmalloc-192             9654KB       9654KB
[ 1466.188432] kmalloc-128             2176KB       2176KB
[ 1466.188481] kmalloc-96             67773KB      67773KB
[ 1466.188560] kmalloc-64             49152KB      49152KB
[ 1466.188623] kmalloc-32              2176KB       2176KB
[ 1466.188699] kmalloc-16              2176KB       2176KB
[ 1466.188736] kmalloc-8               9728KB       9728KB
[ 1466.188805] kmem_cache_node          512KB        512KB
[ 1466.188873] kmem_cache               510KB        510KB
[ 1466.188922] Tasks state (memory values in pages):
[ 1466.188988] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[ 1466.189114] [   6465]     0  6465     3340      382    29696        0         -1000 dmeventd
[ 1466.189197] Out of memory and no killable processes...
[ 1466.189266] Kernel panic - not syncing: System is deadlocked on memory
[ 1466.189266]
[ 1466.189355] CPU: 9 PID: 1 Comm: bash Tainted: P           O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
[ 1466.189484] Call Trace:
[ 1466.189523] [c000000f277938b0] [c0000000009a4ae8] dump_stack+0xbc/0x104 (unreliable)
[ 1466.189624] [c000000f277938f0] [c0000000001082f8] panic+0x140/0x318
[ 1466.189696] [c000000f27793980] [c0000000002dbb08] out_of_memory+0x718/0x730
[ 1466.189791] [c000000f27793a20] [c0000000002e4468] __alloc_pages_nodemask+0xf78/0x1020
[ 1466.189883] [c000000f27793bf0] [c0000000003700ec] alloc_pages_current+0xbc/0x140
[ 1466.189981] [c000000f27793c30] [c0000000002ddaa8] __get_free_pages+0x28/0x80
[ 1466.190072] [c000000f27793c50] [c000000000103910] mm_init+0x140/0x2f0
[ 1466.190142] [c000000f27793ca0] [c000000000105b44] copy_process.isra.4.part.5+0x1074/0x1d00
[ 1466.190255] [c000000f27793da0] [c000000000106a30] _do_fork+0xf0/0x550
[ 1466.190305] [c000000f27793e30] [c00000000000bc98] ppc_clone+0x8/0xc
[ 1467.483570] ---[ end Kernel panic - not syncing: System is deadlocked on memory
[ 1467.483570]  ]---
[ 1480.038462] watchdog: CPU 9 detected hard LOCKUP on other CPUs 0-8
[ 1480.038483] watchdog: CPU 9 TB:820288910718, last SMP heartbeat TB:812095152709 (16003ms ago)
[ 1480.129490] watchdog: CPU 0 Hard LOCKUP
[ 1480.129491] watchdog: CPU 0 TB:820288984407, last heartbeat TB:812094873606 (16004ms ago)
[ 1480.129491] Modules linked in: zfs(PO) zunicode(PO) zzstd(O) zlua(O) zcommon(PO) znvpair(PO) zavl(PO) icp(PO) spl(O) ext4 crc16 mbcache jbd2 fscrypto ecb dm_snapshot dm_bufio dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor sg sd_mod raid6_pq libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod xhci_pci xhci_hcd mpt3sas usbcore tg3 libphy raid_class usb_common scsi_transport_sas [last unloaded: zunicode]
[ 1480.129508] CPU: 0 PID: 0 Comm: swapper/0 Tainted: P           O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
[ 1480.129508] NIP:  c000000000047f3c LR: c000000000048e40 CTR: c000000000047f30
[ 1480.129509] REGS: c000000fff607d80 TRAP: 0100   Tainted: P           O       (4.19.0-14-powerpc64le Debian 4.19.171-2)
[ 1480.129510] MSR:  9000000000081033 <SF,HV,ME,IR,DR,RI,LE>  CR: 24002824  XER: 00000000
[ 1480.129513] CFAR: c000000000047f3c IRQMASK: 1
[ 1480.129515] GPR00: c000000000048e40 c000000001143b20 c000000001146900 c000000001143be0
[ 1480.129517] GPR04: c000000001143d40 c0000000000a2dcc 0000000024000824 c0000000011d01c0
[ 1480.129519] GPR08: 00000000fffffdfe 0000000000000000 c0000000011d6900 0000000000000000
[ 1480.129521] GPR12: c000000000047f30 c0000000013f0000 0000000000000000 0000000000000000
[ 1480.129523] GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 1480.129525] GPR20: 0000000000000001 00000000100051e6 0000000000000000 0000000000000005
[ 1480.129527] GPR24: c0000000010a3ac8 0000000000000005 0000000000000000 0000000000000005
[ 1480.129529] GPR28: c0000000010a3ac8 c000000001143be0 c000000000047f30 0000000000000001
[ 1480.129532] NIP [c000000000047f3c] nmi_stop_this_cpu+0xc/0x10
[ 1480.129532] LR [c000000000048e40] smp_handle_nmi_ipi+0xe0/0x130
[ 1480.129533] Call Trace:
[ 1480.129533] [c000000001143b20] [c000000000048d94] smp_handle_nmi_ipi+0x34/0x130 (unreliable)
[ 1480.129535] [c000000001143b70] [c0000000000a84c0] pnv_system_reset_exception+0x20/0x40
[ 1480.129536] [c000000001143b90] [c000000000027264] system_reset_exception+0x84/0x230
[ 1480.129537] [c000000001143bc0] [c000000000017fd0] replay_system_reset+0x40/0x60
[ 1480.129538] [c000000001143d40] [c0000000000a3324] power9_idle_type+0x24/0x40
[ 1480.129539] [c000000001143d60] [c0000000007a8ef0] stop_loop+0x40/0x60
[ 1480.129540] [c000000001143d90] [c0000000007a51d8] cpuidle_enter_state+0xa8/0x4c0
[ 1480.129541] [c000000001143e00] [c00000000015051c] call_cpuidle+0x4c/0x80
[ 1480.129542] [c000000001143e20] [c000000000150b3c] do_idle+0x33c/0x390
[ 1480.129543] [c000000001143ea0] [c000000000150dc8] cpu_startup_entry+0x38/0x40
[ 1480.129544] [c000000001143ed0] [c0000000000109d8] rest_init+0xe0/0xf8
[ 1480.129544] [c000000001143f00] [c000000000c2427c] start_kernel+0x610/0x634
[ 1480.129545] [c000000001143f90] [c00000000000b2e4] start_here_common+0x1c/0x20
[ 1480.129546] Instruction dump:
[ 1480.129547] 4e800421 e8410018 38210020 e8010010 7c0803a6 4e800020 60000000 60000000
[ 1480.129550] 60000000 7c0802a6 60000000 7c210b78 <48000000> 3c4c0110 3842e9c0 7c0802a6
[ 1480.129553] Oops: Unrecoverable nested System Reset, sig: 6 [#1]
[ 1480.129553] LE SMP NR_CPUS=2048 NUMA PowerNV
[ 1480.129555] Modules linked in: zfs(PO) zunicode(PO) zzstd(O) zlua(O) zcommon(PO) znvpair(PO) zavl(PO) icp(PO) spl(O) ext4 crc16 mbcache jbd2 fscrypto ecb dm_snapshot dm_bufio dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor sg sd_mod raid6_pq libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod xhci_pci xhci_hcd mpt3sas usbcore tg3 libphy raid_class usb_common scsi_transport_sas [last unloaded: zunicode]
[ 1480.129571] CPU: 0 PID: 0 Comm: swapper/0 Tainted: P           O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
[ 1480.129571] NIP:  c000000000047f3c LR: c000000000048e40 CTR: c000000000047f30
[ 1480.129572] REGS: c000000fff607d80 TRAP: 0100   Tainted: P           O       (4.19.0-14-powerpc64le Debian 4.19.171-2)
[ 1480.129573] MSR:  9000000000081033 <SF,HV,ME,IR,DR,RI,LE>  CR: 24002824  XER: 00000000
[ 1480.129576] CFAR: c000000000047f3c IRQMASK: 1
[ 1480.129577] GPR00: c000000000048e40 c000000001143b20 c000000001146900 c000000001143be0
[ 1480.129580] GPR04: c000000001143d40 c0000000000a2dcc 0000000024000824 c0000000011d01c0
[ 1480.129582] GPR08: 00000000fffffdfe 0000000000000000 c0000000011d6900 0000000000000000
[ 1480.129584] GPR12: c000000000047f30 c0000000013f0000 0000000000000000 0000000000000000
[ 1480.129586] GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 1480.129588] GPR20: 0000000000000001 00000000100051e6 0000000000000000 0000000000000005
[ 1480.129590] GPR24: c0000000010a3ac8 0000000000000005 0000000000000000 0000000000000005
[ 1480.129592] GPR28: c0000000010a3ac8 c000000001143be0 c000000000047f30 0000000000000001
[ 1480.129594] NIP [c000000000047f3c] nmi_stop_this_cpu+0xc/0x10
[ 1480.129595] LR [c000000000048e40] smp_handle_nmi_ipi+0xe0/0x130
[ 1480.129595] Call Trace:
[ 1480.129596] [c000000001143b20] [c000000000048d94] smp_handle_nmi_ipi+0x34/0x130 (unreliable)
[ 1480.129597] [c000000001143b70] [c0000000000a84c0] pnv_system_reset_exception+0x20/0x40
[ 1480.129598] [c000000001143b90] [c000000000027264] system_reset_exception+0x84/0x230
[ 1480.129599] [c000000001143bc0] [c000000000017fd0] replay_system_reset+0x40/0x60
[ 1480.129600] [c000000001143d40] [c0000000000a3324] power9_idle_type+0x24/0x40
[ 1480.129601] [c000000001143d60] [c0000000007a8ef0] stop_loop+0x40/0x60
[ 1480.129602] [c000000001143d90] [c0000000007a51d8] cpuidle_enter_state+0xa8/0x4c0
[ 1480.129603] [c000000001143e00] [c00000000015051c] call_cpuidle+0x4c/0x80
[ 1480.129604] [c000000001143e20] [c000000000150b3c] do_idle+0x33c/0x390
[ 1480.129605] [c000000001143ea0] [c000000000150dc8] cpu_startup_entry+0x38/0x40
[ 1480.129606] [c000000001143ed0] [c0000000000109d8] rest_init+0xe0/0xf8
[ 1480.129607] [c000000001143f00] [c000000000c2427c] start_kernel+0x610/0x634
[ 1480.129608] [c000000001143f90] [c00000000000b2e4] start_here_common+0x1c/0x20
[ 1480.129609] Instruction dump:
[ 1480.129609] 4e800421 e8410018 38210020 e8010010 7c0803a6 4e800020 60000000 60000000
[ 1480.129612] 60000000 7c0802a6 60000000 7c210b78 <48000000> 3c4c0110 3842e9c0 7c0802a6
[ 1480.129616] ---[ end trace 5cb5b73f035b55be ]---
[ 1480.129616] watchdog: CPU 1 Hard LOCKUP
[ 1480.129617] watchdog: CPU 1 TB:820294160884, last heartbeat TB:812094873611 (16014ms ago)
[ 1480.129618] Modules linked in: zfs(PO) zunicode(PO) zzstd(O) zlua(O) zcommon(PO) znvpair(PO) zavl(PO) icp(PO) spl(O) ext4 crc16 mbcache jbd2 fscrypto ecb dm_snapshot dm_bufio dm_mod raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor sg sd_mod raid6_pq libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod xhci_pci xhci_hcd mpt3sas usbcore tg3 libphy raid_class usb_common scsi_transport_sas [last unloaded: zunicode]
[ 1480.129633] CPU: 1 PID: 0 Comm: swapper/1 Tainted: P      D    O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
[ 1480.129634] NIP:  c000000000047f3c LR: c000000000048e40 CTR: c000000000047f30
[ 1480.129635] REGS: c000000fff5fbd80 TRAP: 0100   Tainted: P      D    O       (4.19.0-14-powerpc64le Debian 4.19.171-2)
[ 1480.129635] MSR:  9000000000081033 <SF,HV,ME,IR,DR,RI,LE>  CR: 24002424  XER: 00000000
[ 1480.129639] CFAR: c000000000047f3c IRQMASK: 1
[ 1480.129640] GPR00: c000000000048e40 c000000f277ebb40 c000000001146900 c000000f277ebc00
[ 1480.129642] GPR04: c000000f277ebd60 c0000000000a2dcc 0000000024004424 c0000000011d01c0
[ 1480.129644] GPR08: 00000000fffffdfc 0000000000000000 c0000000011d6900 0000000000000000
[ 1480.129646] GPR12: c000000000047f30 c000000fff7fee80 c000000f277ebf90 0000000000000000
[ 1480.129648] GPR16: 0000000000000000 c000000000047da0 c000000000047d70 c000000001182494
[ 1480.129650] GPR20: c000000000d05278 0000000000000800 0000000000000000 0000000000000006
[ 1480.129652] GPR24: c0000000010a3ac8 0000000000000006 0000000000000000 0000000000000006
[ 1480.129655] GPR28: c0000000010a3ac8 c000000f277ebc00 c000000000047f30 0000000000000001
[ 1480.129657] NIP [c000000000047f3c] nmi_stop_this_cpu+0xc/0x10
[ 1480.129658] LR [c000000000048e40] smp_handle_nmi_ipi+0xe0/0x130
[ 1480.129658] Call Trace:
[ 1480.129659] [c000000f277ebb40] [c000000000048d94] smp_handle_nmi_ipi+0x34/0x130 (unreliable)
[ 1480.129660] [c000000f277ebb90] [c0000000000a84c0] pnv_system_reset_exception+0x20/0x40
[ 1480.129661] [c000000f277ebbb0] [c000000000027264] system_reset_exception+0x84/0x230
[ 1480.129662] [c000000f277ebbe0] [c000000000017fd0] replay_system_reset+0x40/0x60
[ 1480.129663] [c000000f277ebd60] [c0000000000a3324] power9_idle_type+0x24/0x40
[ 1480.129664] [c000000f277ebd80] [c0000000007a8ef0] stop_loop+0x40/0x60
[ 1480.129665] [c000000f277ebdb0] [c0000000007a51d8] cpuidle_enter_state+0xa8/0x4c0
[ 1480.129666] [c000000f277ebe20] [c00000000015051c] call_cpuidle+0x4c/0x80
[ 1480.129667] [c000000f277ebe40] [c000000000150b3c] do_idle+0x33c/0x390
[ 1480.129668] [c000000f277ebec0] [c000000000150dc8] cpu_startup_entry+0x38/0x40
[ 1480.129669] [c000000f277ebef0] [c00000000004a1b0] start_secondary+0x4f0/0x520
[ 1480.129670] [c000000f277ebf90] [c00000000000b270] start_secondary_prolog+0x10/0x14
[ 1480.129670] Instruction dump:
[ 1480.129671] 4e800421 e8410018 38210020 e8010010 7c0803a6 4e800020 60000000 60000000
[ 1480.129674] 60000000 7c0802a6 60000000 7c210b78 <48000000> 3c4c0110 3842e9c0 7c0802a6
...
@sideeffect42 sideeffect42 added Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang) labels Mar 16, 2021
@sideeffect42
Copy link
Author

Tried to downgrade v2.0.2-1~bpo10+1 to see if the issue is limited to 2.0.3.
It didn't change.

@sideeffect42
Copy link
Author

This issue could be related to #11754.

@sideeffect42
Copy link
Author

sideeffect42 commented Mar 16, 2021 •
edited
Loading

Importing the pool using zpool import tank -o readonly=on works.

zpool status on the readonly pool prints:

  scan: scrub in progress since Sun Mar 14 00:24:01 2021
	0B scanned at 0B/s, 0B issued at 0B/s, 156G total
	0B repaired, 0.00% done, no estimated completion time

Further investigation has revealed that cron has indeed started a scrub of the pool on Sun Mar 14 00:24:01 2021.
As per the syslog the kernel OOM killer kicked in on Mar 14 00:24:30.

Mar 14 00:24:01 kamor CRON[16477]: (root) CMD (if [ $(date +%w) -eq 0 ] && [ -x /usr/lib/zfs-linux/scrub ]; then /usr/lib/zfs-linux/scrub; fi)
Mar 14 00:24:01 kamor zed[3691]: Invoking "all-syslog.sh" eid=31 pid=16492
Mar 14 00:24:01 kamor zed: eid=31 class=scrub_start pool='tank'
Mar 14 00:24:01 kamor zed[3691]: Finished "all-syslog.sh" eid=31 pid=16492 exit=0
Mar 14 00:24:01 kamor zed[3691]: Invoking "all-syslog.sh" eid=32 pid=16494
Mar 14 00:24:01 kamor zed[3691]: Finished "all-syslog.sh" eid=32 pid=16494 exit=0
Mar 14 00:24:01 kamor zed[3691]: Invoking "history_event-zfs-list-cacher.sh" eid=32 pid=16495
Mar 14 00:24:02 kamor zed[3691]: Finished "history_event-zfs-list-cacher.sh" eid=32 pid=16495 exit=0
Mar 14 00:24:30 kamor kernel: [373025.520176] qemu-system-ppc invoked oom-killer: gfp_mask=0x6000c0(GFP_KERNEL), nodemask=(null), order=0, oom_score_adj=0
Mar 14 00:24:30 kamor kernel: [373025.520200] qemu-system-ppc cpuset=emulator mems_allowed=0
Mar 14 00:24:30 kamor kernel: [373025.520211] CPU: 3 PID: 24286 Comm: qemu-system-ppc Tainted: P           O      4.19.0-14-powerpc64le #1 Debian 4.19.171-2
Mar 14 00:24:30 kamor kernel: [373025.520234] Call Trace:
Mar 14 00:24:30 kamor kernel: [373025.520241] [c000000d0e76b450] [c0000000009a4ae8] dump_stack+0xbc/0x104 (unreliable)
Mar 14 00:24:30 kamor kernel: [373025.520273] [c000000d0e76b490] [c0000000002d9c28] dump_header+0x78/0x310
Mar 14 00:24:30 kamor kernel: [373025.520283] [c000000d0e76b550] [c0000000002da7e4] oom_kill_process+0x164/0x420
Mar 14 00:24:30 kamor kernel: [373025.520305] [c000000d0e76b600] [c0000000002db510] out_of_memory+0x120/0x730
Mar 14 00:24:30 kamor kernel: [373025.520340] [c000000d0e76b6a0] [c0000000002e4468] __alloc_pages_nodemask+0xf78/0x1020
Mar 14 00:24:30 kamor kernel: [373025.520365] [c000000d0e76b870] [c0000000003700ec] alloc_pages_current+0xbc/0x140
Mar 14 00:24:30 kamor kernel: [373025.520406] [c000000d0e76b8b0] [c0000000002ddaa8] __get_free_pages+0x28/0x80
Mar 14 00:24:30 kamor kernel: [373025.520440] [c000000d0e76b8d0] [c0000000003e31e4] __pollwait+0xe4/0x150
Mar 14 00:24:30 kamor kernel: [373025.520469] [c000000d0e76b920] [c000000000439cc0] eventfd_poll+0x50/0xb0
Mar 14 00:24:30 kamor kernel: [373025.520500] [c000000d0e76b950] [c0000000003e4710] do_sys_poll+0x280/0x630
Mar 14 00:24:30 kamor kernel: [373025.520523] [c000000d0e76bda0] [c0000000003e58ec] sys_ppoll+0x19c/0x1d0
Mar 14 00:24:30 kamor kernel: [373025.520546] [c000000d0e76be30] [c00000000000b9dc] system_call+0x5c/0x70
Mar 14 00:24:30 kamor kernel: [373025.520554] Mem-Info:
...

Then, on reimport of the pool, ZFS wants to continue scrubbing making it OOM again.

Thanks to the great advice of DeHackEd from #zfsonlinux I found a workaround.
Setting zfs_scan_legacy=1 "fixes" the memory leak and the scrub can finish just fine.

After the scrub has finished and with zfs_scan_legacy=0, the pool imports fine, but running zpool scrub tank reproduces the bug.

@sideeffect42 sideeffect42 changed the title ZFS 2.0.3 leaks memory, leading to kernel lockup within seconds zpool scrub leaks memory, leading to OOM within seconds Mar 16, 2021
@sideeffect42
Copy link
Author

Now, with further information, this is possibly a duplicate of #11574.

@sideeffect42
Copy link
Author

Closing this issue as it seems very closely related to #11574.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Status: Triage Needed New issue which needs to be triaged Type: Defect Incorrect behavior (e.g. crash, hang)
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@sideeffect42