Cache-unfriendly filesystem usage, memory fragmentation and ARC

[runderwo]

System information

Type	Version/Name
Distribution Name	Ubuntu/Debian
Distribution Version	LTS/latest
Kernel Version	6.8-6.11
Architecture	x86_64
OpenZFS Version	2.2.2-2.2.6

Describe the problem you're observing

After moderate uptime of a few weeks, when a program tries to read or index the whole filesystem or a large chunk of it, the system seizes up, becomes unresponsive to input/network for 15-20 minutes. Eventually it recovers to a sluggish but usable state (with the offending process still running, consuming core time and disk I/O) where a tool like atop can be used to observe lingering heavy free page scan activity, - despite up to 10GiB of free/avail memory! (Linux page cache has been zeroed by this time.)

ARC is maxed out at 97% (almost 50% of system RAM according to the default settings).

Examining /proc/buddyinfo, there are no free pages >= 1MiB in the steady state and can be even worse right after the "seizure" with no free pages >= 128KiB.

I suspect the partial recovery is thanks to kcompactd activity. I am thinking that ZFS should drop cached file blocks from ARC not just when the kernel low watermark is reached, but also when higher order free pages become exhausted.

Describe how to reproduce the problem

Simulate normal memory fragmentation on a host, including multiple hibernate/resume cycles, then run duplicity, tracker3-miner, or similar programs which ingest the whole filesystem in a cache-unfriendly and ZFS-unfriendly way while monitoring the situation with atop.

Include any warning/errors/backtraces from the system logs

Dec 22 16:09:02 desktop kernel: zfs: module license 'CDDL' taints kernel.
Dec 22 16:09:02 desktop kernel: Disabling lock debugging due to kernel taint
Dec 22 16:09:02 desktop kernel: zfs: module license taints kernel.
Dec 22 16:09:02 desktop kernel: calling  openzfs_init+0x0/0xce0 [zfs] @ 428
Dec 22 16:09:02 desktop kernel: ZFS: Loaded module v2.2.2-0ubuntu9.1, ZFS pool version 5000, ZFS filesystem version 5
[..]
Jan 22 14:05:06 desktop systemd-journald[935]: Under memory pressure, flushing caches.
[..]
Jan 22 14:16:31 desktop kernel: INFO: task chrome:3547537 blocked for more than 122 seconds.
Jan 22 14:16:31 desktop kernel:       Tainted: P           OE      6.8.0-51-generic #52-Ubuntu
Jan 22 14:16:31 desktop kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.```
[etc, etc]

[amotin]

Have you tried to set zfs_arc_shrinker_limit=0 after updating to the latest 2.2.x release? It was made default in 2.3.0: #16909 .

[runderwo]

I have not, but will try that out and report back after it's had some time to bake on a host with extended uptime. Thanks for the pointer!

[XyFreak]

Hi,

I have been suffering from the exact same issue ever since upgrading to zfs 2.2.0. I'd like to add a few things:

• When indexing starts, the system seems normal at first but then memory consumption spikes rapidly. My server has about 64GB of ram and looking at htop while running the operation, memory usage will spike suddenly and rapidly. It takes about 3 seconds and the system is entirely OOM and unresponsive.
• Terminating the process that indexes the filesystem before the system becomes unresponsive helps but the used memory does not seem to get freed anymore. A reboot is required to reclaim said memory.
• There is a similar issue with filesystem watches - except it takes days to a week or two to trigger instead of seconds. Might be unrelated but I thought I'd mention it.

I just reproduced it and had a watch on both arc_summary (notice the nice "Available memory size") and /proc/slabinfo running in parallel.

Note that I copied the frozen terminal output into a text file since the system was no longer responsive. I hope it contains the relevant information you might be looking for. Otherwise I can try to extract some information on a partially bricked system where indexing has been killed before the system becomes unresponsive.

arc_summary.txt
slabinfo.txt
slabinfo after reboot

zfs_arc_shrinker_limit is already 0 (I double checked) on my setup as I am running zfs 2.3.0 right now, Kernel 6.12.8.
zfs_arc_max does not seem to really matter here. I have tried values ranging from 16GB to 60GB (set via modprobe on boot, not during runtime) and it happens no matter what.

Another tidbit: I had htop running and while the green bar (used memory) was not at 100% (not even a third), the yellow one (cache) basically filled up the empty space. This would explain runderwos observation of there being "free memory" if memory used for caches was not taken into account. Edit: It was mentioned, I evidently just can't read, sorry

The issue is reproducible moments after the system has rebooted for me so no causing "memory fragmentation" required at all. If I can provide or try anything else, lmk.

[amotin]

@XyFreak In the arc_summary.txt I see that your ARC freed everything else it could at that point, but there appears 36GB that it can not free for some reason (supposedly referenced by something):

        MRU data size:                                 99.5 %   36.5 GiB
        MRU evictable data size:                        0.0 %    0 Bytes

"since upgrading to zfs 2.2.0" is a long time of about a year. Since it is not a widely noticed issue, there must be something specific in your case that triggers it. It could help to find out what exactly is your "indexing", how does it access the files and how to reproduce it in minimal environment.

[runderwo]

I am still seeing the same behavior with zfs_arc_shrinker_limit=0. Extreme memory fragmentation grinds the system to a halt with free page scans despite multiple gigabytes of "free" memory.

[runderwo]

Is it possible that failure to hibernate after a significant uptime is related? This is on a laptop with 48GB RAM and 128GB hibernation/swapfile.

Mar 24 14:54:37 achpee2 kernel: Filesystems sync: 4.641 seconds
Mar 24 14:54:48 achpee2 kernel: Freezing user space processes
Mar 24 14:54:48 achpee2 kernel: Freezing user space processes completed (elapsed 0.002 seconds)
Mar 24 14:54:48 achpee2 kernel: OOM killer disabled.
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x00000000-0x00000fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x00058000-0x00058fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x00086000-0x000fffff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x55747000-0x55747fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x55757000-0x55758fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x55771000-0x55771fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x590ba000-0x590e4fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x60180000-0x601a2fff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x6f38e000-0x6fffdfff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Marking nosave pages: [mem 0x6ffff000-0xffffffff]
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Basic memory bitmaps created
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Preallocating image memory
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Image allocation is 849661 pages short
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: Basic memory bitmaps freed
Mar 24 14:54:48 achpee2 kernel: OOM killer enabled.
Mar 24 14:54:48 achpee2 kernel: Restarting tasks ... done.
Mar 24 14:54:48 achpee2 kernel: PM: hibernation: hibernation exit

[runderwo]

Saw the same "spinning in free page scan" meltdown again today. Afterwards significant fragmentation can be observed:

$ cat /proc/buddyinfo 
Node 0, zone      DMA      1      1      1      1      1      1      1      1      0      1      2 
Node 0, zone    DMA32   1610    842    863    674    377    234    162    103     57     29    108 
Node 0, zone   Normal   2057  15383  18048   5022  30170   3737   5160   1160    203      0      0 

[runderwo]

Happened again today. I have an atop log capturing the situation at 30 second intervals. Mem fragmentation is also terrible again:

Node 0, zone      DMA      1      1      1      1      1      1      1      1      0      1      2 
Node 0, zone    DMA32   1244    965    893    878    748   1616    136      5      0      0      0 
Node 0, zone   Normal  15091  68878  68007  72113  34303   4715    161      0      0      0      0 

I have upgraded to zfs 2.3.2 to see if the situation changes.

[amotin]

@runderwo ZFS allocates ARC in as big chunks as kernel allows. The more memory is fragmented, the smaller are new allocations, and potentially higher fragmentation is future. ARC memory is not movable, but evictable. It means kernel can not defragment it by moving pages around, but it can always request ZFS to evict something, and ZFS should obey the requests. If there are evidences that ZFS ignored some eviction requests, then we need to see them. Otherwise it is just a fact of life.

[runderwo]

@amotin I am precisely trying to help discover "evidence that ZFS ignored some eviction requests" for ARC memory. The unusability of the system while it grinds through page scans for up to an hour at a time, as well as the lingering amount of fragmentation on a system with completely normal use and 10GB free memory is simply unacceptable; it's difficult to imagine any userspace pattern causing it, so it must be a problem between ZFS (the heaviest slab consumer by far) and the kernel until proven otherwise. Do you have any suggestions for further evidence gathering?