Re: [PATCH] powerpc/modules: Don't WARN on first module allocation tentative

[Erhard F.]

On Tue, 30 Nov 2021 11:10:43 +0100
Christophe Leroy <christophe.leroy@xxxxxxxxxx> wrote:

> module_alloc() first tries to allocate module text within
> 24 bits direct jump from kernel text, and tries a wider
> allocation if first one fails.
> 
> When first allocation fails the following is observed in kernel logs:
> 
> vmap allocation for size 2400256 failed: use vmalloc=<size> to increase size
> systemd-udevd: vmalloc error: size 2395133, vm_struct allocation failed, mode:0xcc0(GFP_KERNEL), nodemask=(null)
> CPU: 0 PID: 127 Comm: systemd-udevd Tainted: G        W         5.15.5-gentoo-PowerMacG4 #9
> Call Trace:
> [e2a53a50] [c0ba0048] dump_stack_lvl+0x80/0xb0 (unreliable)
> [e2a53a70] [c0540128] warn_alloc+0x11c/0x2b4
> [e2a53b50] [c0531be8] __vmalloc_node_range+0xd8/0x64c
> [e2a53c10] [c00338c0] module_alloc+0xa0/0xac
> [e2a53c40] [c027a368] load_module+0x2ae0/0x8148
> [e2a53e30] [c027fc78] sys_finit_module+0xfc/0x130
> [e2a53f30] [c0035098] ret_from_syscall+0x0/0x28
> --- interrupt: c00 at 0x25df10
> NIP:  0025df10 LR: 00416180 CTR: 00000000
> REGS: e2a53f40 TRAP: 0c00   Tainted: G        W          (5.15.5-gentoo-PowerMacG4)
> MSR:  0000d032 <EE,PR,ME,IR,DR,RI>  CR: 2822242c  XER: 20000000
> 
> GPR00: 00000161 afa8f060 a73a6160 00000011 0041dfa5 00000000 00000011 00000000
> GPR08: 00000000 20000000 0000007a afa8efe0 002113f8 0072f924 00000000 00000000
> GPR16: 00000005 afa8f1fc afa8f1e8 00000000 22222422 00000000 009603b0 22222422
> GPR24: 00000000 00000000 0041dfa5 008a5fc0 00020000 00000000 00444cc4 009958f0
> NIP [0025df10] 0x25df10
> LR [00416180] 0x416180
> --- interrupt: c00
> Mem-Info:
> active_anon:36 inactive_anon:4417 isolated_anon:0
>  active_file:3496 inactive_file:10535 isolated_file:0
>  unevictable:0 dirty:59 writeback:0
>  slab_reclaimable:3672 slab_unreclaimable:20540
>  mapped:5700 shmem:166 pagetables:185 bounce:0
>  kernel_misc_reclaimable:0
>  free:438282 free_pcp:1121 free_cma:0
> Node 0 active_anon:144kB inactive_anon:17668kB active_file:13984kB inactive_file:42140kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:22800kB dirty:404kB writeback:0kB shmem:664kB writeback_tmp:0kB kernel_stack:1352kB pagetables:740kB all_unreclaimable? no
> DMA free:267900kB min:2488kB low:3108kB high:3728kB reserved_highatomic:4096KB active_anon:0kB inactive_anon:0kB active_file:4016kB inactive_file:4224kB unevictable:0kB writepending:76kB present:524288kB managed:389432kB mlocked:0kB bounce:0kB free_pcp:2480kB local_pcp:1176kB free_cma:0kB
> lowmem_reserve[]: 0 0 1536 1536
> HighMem free:1485036kB min:512kB low:3032kB high:5552kB reserved_highatomic:0KB active_anon:136kB inactive_anon:17612kB active_file:9976kB inactive_file:37912kB unevictable:0kB writepending:364kB present:1572864kB managed:1572864kB mlocked:0kB bounce:0kB free_pcp:1776kB local_pcp:404kB free_cma:0kB
> BTRFS: selftest: sectorsize: 4096  nodesize: 8192
> lowmem_reserve[]: 0 0 0 0
> BTRFS: selftest: running btrfs free space cache tests
> DMA: 283*4kB (UMH) 282*8kB (UMH) 242*16kB (UMEH) 422*32kB (UMH) 187*64kB (UMH) 139*128kB (UME) 118*256kB (UM) 87*512kB (UME) 61*1024kB (UME) 27*2048kB (U) 6*4096kB (U) = 267612kB
> BTRFS: selftest: running extent only tests
> HighMem: 1*4kB (M) 1*8kB (M) 92*16kB (M) 43*32kB (UM) 21*64kB (M) 7*128kB (M) 3*256kB (UM) 1*512kB (U) 2*1024kB (UM) 1*2048kB (U) 360*4096kB (UM) = 1485036kB
> BTRFS: selftest: running bitmap only tests
> 14218 total pagecache pages
> 0 pages in swap cache
> Swap cache stats: add 0, delete 0, find 0/0
> Free swap  = 8388604kB
> Total swap = 8388604kB
> 524288 pages RAM
> 393216 pages HighMem/MovableOnly
> 33714 pages reserved
> 
> Add __GFP_NOWARN flag to first allocation so that no warning appears
> when it fails.
> 
> Reported-by: Erhard Furtner <erhard_f@xxxxxxxxxxx>
> Fixes: 2ec13df16704 ("powerpc/modules: Load modules closer to kernel text")
> Signed-off-by: Christophe Leroy <christophe.leroy@xxxxxxxxxx>
> ---
>  arch/powerpc/kernel/module.c | 11 ++++++-----
>  1 file changed, 6 insertions(+), 5 deletions(-)
> 
> diff --git a/arch/powerpc/kernel/module.c b/arch/powerpc/kernel/module.c
> index ed04a3ba66fe..40a583e9d3c7 100644
> --- a/arch/powerpc/kernel/module.c
> +++ b/arch/powerpc/kernel/module.c
> @@ -90,16 +90,17 @@ int module_finalize(const Elf_Ehdr *hdr,
>  }
>  
>  static __always_inline void *
> -__module_alloc(unsigned long size, unsigned long start, unsigned long end)
> +__module_alloc(unsigned long size, unsigned long start, unsigned long end, bool nowarn)
>  {
>  	pgprot_t prot = strict_module_rwx_enabled() ? PAGE_KERNEL : PAGE_KERNEL_EXEC;
> +	gfp_t gfp = GFP_KERNEL | (nowarn ? __GFP_NOWARN : 0);
>  
>  	/*
>  	 * Don't do huge page allocations for modules yet until more testing
>  	 * is done. STRICT_MODULE_RWX may require extra work to support this
>  	 * too.
>  	 */
> -	return __vmalloc_node_range(size, 1, start, end, GFP_KERNEL, prot,
> +	return __vmalloc_node_range(size, 1, start, end, gfp, prot,
>  				    VM_FLUSH_RESET_PERMS | VM_NO_HUGE_VMAP,
>  				    NUMA_NO_NODE, __builtin_return_address(0));
>  }
> @@ -114,13 +115,13 @@ void *module_alloc(unsigned long size)
>  
>  	/* First try within 32M limit from _etext to avoid branch trampolines */
>  	if (MODULES_VADDR < PAGE_OFFSET && MODULES_END > limit)
> -		ptr = __module_alloc(size, limit, MODULES_END);
> +		ptr = __module_alloc(size, limit, MODULES_END, true);
>  
>  	if (!ptr)
> -		ptr = __module_alloc(size, MODULES_VADDR, MODULES_END);
> +		ptr = __module_alloc(size, MODULES_VADDR, MODULES_END, false);
>  
>  	return ptr;
>  #else
> -	return __module_alloc(size, VMALLOC_START, VMALLOC_END);
> +	return __module_alloc(size, VMALLOC_START, VMALLOC_END, false);
>  #endif
>  }
> -- 
> 2.33.1

The patch applies on 5.15.5 but I still get this vmalloc error. Looks a bit different though:

[..]
Running code patching self-tests ...
vmap allocation for size 33562624 failed: use vmalloc=<size> to increase size
swapper/0: vmalloc error: size 33558528, vm_struct allocation failed, mode:0xcc0(GFP_KERNEL), nodemask=(null)
CPU: 0 PID: 1 Comm: swapper/0 Tainted: G        W         5.15.5-PowerMacG4+ #2
Call Trace:
[f1033ba0] [c0b9fff0] dump_stack_lvl+0x80/0xb0 (unreliable)
[f1033bc0] [c05400d0] warn_alloc+0x11c/0x2b4
[f1033ca0] [c0531b90] __vmalloc_node_range+0xd8/0x64c
[f1033d60] [c05319a8] __vmalloc_node+0xec/0xf4
[f1033da0] [c1c0f998] test_code_patching+0x72c/0xd50
[f1033de0] [c0008994] do_one_initcall+0x2a0/0x5ac
[f1033eb0] [c1c040b0] kernel_init_freeable+0x590/0x5a4
[f1033f10] [c000946c] kernel_init+0x28/0x154
[f1033f30] [c0035148] ret_from_kernel_thread+0x14/0x1c
Mem-Info:
active_anon:0 inactive_anon:0 isolated_anon:0
 active_file:0 inactive_file:0 isolated_file:0
 unevictable:0 dirty:0 writeback:0
 slab_reclaimable:1154 slab_unreclaimable:4207
 mapped:0 shmem:0 pagetables:0 bounce:0
 kernel_misc_reclaimable:0
 free:474202 free_pcp:630 free_cma:0
Node 0 active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:0kB dirty:0kB writeback:0kB shmem:0kB writeback_tmp:0kB kernel_stack:848kB pagetables:0kB all_unreclaimable? no
DMA free:587836kB min:3140kB low:3924kB high:4708kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:786432kB managed:616760kB mlocked:0kB bounce:0kB free_pcp:1864kB local_pcp:1460kB free_cma:0kB
lowmem_reserve[]: 0 0 1280 1280
HighMem free:1308972kB min:512kB low:2180kB high:3848kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:1310720kB managed:1310720kB mlocked:0kB bounce:0kB free_pcp:656kB local_pcp:52kB free_cma:0kB
lowmem_reserve[]: 0 0 0 0
DMA: 5*4kB (UM) 1*8kB (M) 4*16kB (M) 3*32kB (UME) 4*64kB (ME) 3*128kB (ME) 5*256kB (UME) 6*512kB (UME) 3*1024kB (M) 3*2048kB (ME) 140*4096kB (M) = 587836kB
HighMem: 3*4kB (U) 2*8kB (U) 5*16kB (U) 0*32kB 1*64kB (U) 1*128kB (U) 0*256kB 0*512kB 0*1024kB 1*2048kB (U) 319*4096kB (M) = 1308972kB
0 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap  = 0kB
Total swap = 0kB
524288 pages RAM
327680 pages HighMem/MovableOnly
42418 pages reserved
code-patching: test failed at line 598
[...]

Updated /sys/kernel/debug/kernel_page_tables with the patch applied and default LOWMEM_SIZE=0x30000000 in the original bug report: https://bugzilla.kernel.org/show_bug.cgi?id=205099

Regards,
Erhard