Memory allocation errors, but lots of memory reclaimable (disk cache)

Installing and Using OpenWrt
1

Turris Omnia, armv7 CPU with 2 GB RAM.
I get memory allocation errors like these:

[92965.414528][    C0] nfsd: page allocation failure: order:2, mode:0x40820(GFP_ATOMIC|__GFP_COMP), nodemask=(null)
[92965.424816][    C0] CPU: 0 PID: 5007 Comm: nfsd Tainted: G        W  O       6.6.61 #0
[92965.424826][    C0] Hardware name: Marvell Armada 380/385 (Device Tree)
[92965.424834][    C0] [<c010f0b8>] (unwind_backtrace) from [<c010a6d8>] (show_stack+0x10/0x28)
...
[92965.425017][    C0] Exception stack(0xf2b41a70 to 0xf2b41ab8)
[92965.425022][    C0] 1a60:                                     00000001 c2eb9080 00000418 eefd1dc0
[92965.425029][    C0] 1a80: ef620900 00000000 0000065f 00031448 ef620900 00000000 00000001 f2b41abc
[92965.425034][    C0] 1aa0: 00000001 f2b41abc c022bd80 c015ec00 60000013 ffffffff
[92965.425038][    C0] [<c0100bd8>] (__irq_svc) from [<c015ec00>] (migrate_disable+0x44/0x80)
[92965.425054][    C0] [<c015ec00>] (migrate_disable) from [<c022bd80>] (__kmap_local_pfn_prot+0x14/0x134)
[92965.425072][    C0] [<c022bd80>] (__kmap_local_pfn_prot) from [<c0262504>] (__kernel_unpoison_pages+0x58/0x188)
[92965.425085][    C0] [<c0262504>] (__kernel_unpoison_pages) from [<c024d1c0>] (post_alloc_hook+0xbc/0x154)
[92965.425094][    C0] [<c024d1c0>] (post_alloc_hook) from [<c024ef5c>] (get_page_from_freelist+0x468/0xbdc)
[92965.425104][    C0] [<c024ef5c>] (get_page_from_freelist) from [<c024fcb0>] (__alloc_pages+0x130/0xbd8)
[92965.425113][    C0] [<c024fcb0>] (__alloc_pages) from [<c01f5180>] (__filemap_get_folio+0xd8/0x3c0)
[92965.425124][    C0] [<c01f5180>] (__filemap_get_folio) from [<c0335c80>] (ext4_write_begin+0xa0/0x568)
[92965.425138][    C0] [<c0335c80>] (ext4_write_begin) from [<c01f05d0>] (generic_perform_write+0xcc/0x240)
[92965.425156][    C0] [<c01f05d0>] (generic_perform_write) from [<c031f774>] (ext4_buffered_write_iter+0x60/0x13c)
[92965.425177][    C0] [<c031f774>] (ext4_buffered_write_iter) from [<c0272a64>] (do_iter_readv_writev+0xdc/0x160)
[92965.425190][    C0] [<c0272a64>] (do_iter_readv_writev) from [<c0273c98>] (do_iter_write+0x88/0x238)
[92965.425199][    C0] [<c0273c98>] (do_iter_write) from [<c0409940>] (nfsd_vfs_write+0x154/0x4b0)
[92965.425216][    C0] [<c0409940>] (nfsd_vfs_write) from [<c0409e2c>] (nfsd_write+0x88/0xd0)
[92965.425230][    C0] [<c0409e2c>] (nfsd_write) from [<c041409c>] (nfsd3_proc_write+0xd0/0x134)
[92965.425244][    C0] [<c041409c>] (nfsd3_proc_write) from [<c0404a54>] (nfsd_dispatch+0xf4/0x170)
[92965.425256][    C0] [<c0404a54>] (nfsd_dispatch) from [<c0b44ca4>] (svc_process_common+0x390/0x5c4)
[92965.425268][    C0] [<c0b44ca4>] (svc_process_common) from [<c0b45538>] (svc_process+0xdc/0x144)
[92965.425278][    C0] [<c0b45538>] (svc_process) from [<c040320c>] (nfsd+0x78/0xd8)
[92965.425288][    C0] [<c040320c>] (nfsd) from [<c0158854>] (kthread+0xd0/0xec)
[92965.425302][    C0] [<c0158854>] (kthread) from [<c010014c>] (ret_from_fork+0x14/0x28)
[92965.425312][    C0] Exception stack(0xf2b41fb0 to 0xf2b41ff8)
[92965.425316][    C0] 1fa0:                                     00000000 00000000 00000000 00000000
[92965.425322][    C0] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[92965.425327][    C0] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[92965.425331][    C0] Mem-Info:
[92965.425335][    C0] active_anon:1773 inactive_anon:2210 isolated_anon:0
[92965.425335][    C0]  active_file:322301 inactive_file:121208 isolated_file:0
[92965.425335][    C0]  unevictable:0 dirty:649 writeback:0
[92965.425335][    C0]  slab_reclaimable:8232 slab_unreclaimable:19749
[92965.425335][    C0]  mapped:4620 shmem:275 pagetables:267
[92965.425335][    C0]  sec_pagetables:0 bounce:0
[92965.425335][    C0]  kernel_misc_reclaimable:0
[92965.425335][    C0]  free:19131 free_pcp:981 free_cma:0
[92965.425348][    C0] Node 0 active_anon:7092kB inactive_anon:8840kB active_file:1289204kB inactive_file:484832kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:18480kB dirty:2596kB writeback:0kB shmem:1100kB writeback_tmp:0kB kernel_stack:1936kB pagetables:1068kB sec_pagetables:0kB all_unreclaimable? no
[92965.425359][    C0] Normal free:68568kB boost:36864kB min:53248kB low:57344kB high:61440kB reserved_highatomic:16384KB active_anon:16kB inactive_anon:16kB active_file:42380kB inactive_file:480284kB unevictable:0kB writepending:668kB present:786432kB managed:753904kB mlocked:0kB bounce:0kB free_pcp:3924kB local_pcp:568kB free_cma:0kB
[92965.425372][    C0] lowmem_reserve[]: 0 10240 10240
[92965.425382][    C0] Normal: 13226*4kB (UMEH) 1926*8kB (UMEH) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 68312kB
[92965.425417][    C0] 444619 total pagecache pages
[92965.425420][    C0] 772 pages in swap cache
[92965.425423][    C0] Free swap  = 1032012kB
[92965.425425][    C0] Total swap = 1048572kB
[92965.425428][    C0] 524288 pages RAM
[92965.425431][    C0] 327680 pages HighMem/MovableOnly
[92965.425433][    C0] 8132 pages reserved
[92965.425440][    C0] mvneta f1030000.ethernet eth1: Linux processing - Can't refill
[92965.433058][    C0] mvneta f1030000.ethernet eth1: bad rx status 0cc02000 (crc error), size=1528

AFAIK, page allocation failure: order:2 means the kernel needed 16KB contiguous free memory and didn't find any.

I assume it means these:
Normal: 13226*4kB (UMEH) 1926*8kB (UMEH) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 68312kB

But there are 13226 free 4 KB pages. Why didn't it compact 4 of those?
And there's also 480 MB of disk cache currently unused (inactive_file). Why not reclaim from there?
And also 1 GB swap space unused!

So, how is it possible to not be able to free 16 KB ?

2

please post the output of the ubus call system board. command.

3 
{
        "kernel": "6.6.61",
        "hostname": "GRAPHRT",
        "system": "ARMv7 Processor rev 1 (v7l)",
        "model": "Turris Omnia",
        "board_name": "cznic,turris-omnia",
        "rootfs_type": "squashfs",
        "release": {
                "distribution": "OpenWrt",
                "version": "SNAPSHOT",
                "revision": "r28116+17-cd92cbddf8",
                "target": "mvebu/cortexa9",
                "description": "OpenWrt SNAPSHOT r28116+17-cd92cbddf8",
                "builddate": "1731864854"
        }
}
4

What filesystem is under NFS? Stuff like FAT or BTRFS will explode ram usage with eg sparse files under virtual machines. ext4 is the thinnest, xfs will not need fsck for fast rebooting.

5

can you reproduce it using stable ?

6

There are several. The one being used at that moment was probably a 500 GB ext2 (ext4 driver is being used for ext2):
"[92965.425138][ C0] [] (ext4_write_begin) from [] (generic_perform_write+0xcc/0x240)"

But the log shows that's not the issue.

7

I didn't try. I can't reproduce the error on demand even with the current setup. It just happens from time to time.

Reproducing the error on main branch, even if I could do it, will generate the exact same type of log, but possibly with less info, because I enabled A LOT of debug options in this kernel.

I was looking for some explanation based on this log. Someone more knowledgeable than me could possibly determine the cause from the log.

In the mean time, I set vm.min_free_kbytes=65536 and vm.compaction_proactiveness=40. Maybe that will help.

8

I found the problem. It's caused by kernel's CONFIG_SLUB_CPU_PARTIAL. It doesn't happen when that option is disabled.

9

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.