Page Allocation Failure and Page allocation stalls
Hi All, Please help me to decode the error messages and reason for this errors. System Configuration 1. Kernel 4.14.65 For Android Pie. 2. RAM 2GB As per my understanding its because of i) I am out of memory or due to fragmentation. I also tried to set /proc/sys/vm/min_freekbytes from 3MB to 64MB, but issue still persists. Below are the errors. 1) [ 3205.818891] HwBinder:1894_6: page allocation failure: order:7, mode:0x14040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null) [ 3205.830189] CPU: 3 PID: 23012 Comm: HwBinder:1894_6 Tainted: P O 4.14.65 #261 [ 3205.838803] Hardware name: Android(Flattened Device Tree) [ 3205.845153] Backtrace: [ 3205.847617] [<8020dbec>] (dump_backtrace) from [<8020ded0>] (show_stack+0x18/0x1c) [ 3205.855187] r6:600f0013 r5:8141c21c r4:00000000 r3:d98a4108 [ 3205.860852] [<8020deb8>] (show_stack) from [<80bab014>] (dump_stack+0x94/0xa8) [ 3205.868081] [<80baaf80>] (dump_stack) from [<80350674>] (warn_alloc+0xe0/0x194) [ 3205.875389] r6:80e09abc r5:00000000 r4:81216588 r3:d98a4108 [ 3205.881054] [<80350598>] (warn_alloc) from [<80351544>] (__alloc_pages_nodemask+0xd70/0x124c) [ 3205.889576] r3:00000007 r2:80e09abc [ 3205.893149] r6:00000040 r5:00000000 r4:00000000 [ 3205.897771] [<803507d4>] (__alloc_pages_nodemask) from [<80375484>] (kmalloc_order_trace+0x34/0x124) [ 3205.906906] r10:00080000 r9:803a983c r8:00080000 r7:00000007 r6:17c00000 r5:014000c0 [ 3205.914731] r4:bf20b800 [ 3205.917268] [<80375450>] (kmalloc_order_trace) from [<803a983c>] (__kmalloc+0x1e0/0x318) [ 3205.925358] r9:80607760 r8:014000c0 r7:20000008 r6:17c00000 r5:17c00000 r4:bf20b800 [ 3205.933107] [<803a965c>] (__kmalloc) from [<806a9464>] (dma_common_contiguous_remap+0x40/0xc8) [ 3205.941721] r10:bf20b800 r9:80607760 r8:af78bd34 r7:20000008 r6:17c00000 r5:17c00000 [ 3205.949546] r4:bf20b800 [ 3205.952085] [<806a9424>] (dma_common_contiguous_remap) from [<802187e4>] (__alloc_from_contiguous+0x118/0x144) [ 3205.962086] r7:00017c00 r6:17c00000 r5:81216588 r4:00000001 [ 3205.967748] [<802186cc>] (__alloc_from_contiguous) from [<80218854>] (cma_allocator_alloc+0x44/0x4c) [ 3205.976881] r10:00000000 r9:af78bdd8 r8:81216588 r7:00c00000 r6:b93ac300 r5:80607760 [ 3205.984707] r4:00000001 [ 3205.987241] [<80218810>] (cma_allocator_alloc) from [<80217e28>] (__dma_alloc+0x19c/0x2e4) [ 3205.995501] r5:be30a400 r4:014000c0 [ 3205.999094] [<80217c8c>] (__dma_alloc) from [<80218000>] (arm_dma_alloc+0x4c/0x54) [ 3206.006677] r10:00000080 r9:17c00000 r8:80c01778 r7:be30a400 r6:81216588 r5:00c00000 [ 3206.014533] r4:00000707 [ 3206.017100] [<80217fb4>] (arm_dma_alloc) from [<80607760>] (pmap_cma_alloc+0xbc/0x14c) [ 3206.025048] r5:814278b8 r4:814901f8 2) [ 671.925663] kworker/u8:13: page allocation stalls for 10090ms, order:1, mode:0x15080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null) [ 671.938469] CPU: 2 PID: 3551 Comm: kworker/u8:13 Tainted: P O 4.14.65#273 [ 671.946822] Hardware name: Android (Flattened Device Tree) [ 671.953184] Workqueue: events_unbound call_usermodehelper_exec_work [ 671.959449] Backtrace: [ 671.961901] [<8020dbec>] (dump_backtrace) from [<8020ded0>] (show_stack+0x18/0x1c) [ 671.969469] r6:60060113 r5:8141c09c r4:00000000 r3:db12065c [ 671.975129] [<8020deb8>] (show_stack) from [<80ba6850>] (dump_stack+0x94/0xa8) [ 671.982356] [<80ba67bc>] (dump_stack) from [<80350610>] (warn_alloc+0xe0/0x194) [ 671.989664] r6:80e09180 r5:00000000 r4:81216588 r3:db12065c [ 671.995326] [<80350534>] (warn_alloc) from [<80351520>] (__alloc_pages_nodemask+0xdb0/0x124c) [ 672.003846] r3:0000276a r2:80e09180 [ 672.007417] r6:812166a4 r5:8141d880 r4:00000000 [ 672.012039] [<80350770>] (__alloc_pages_nodemask) from [<8021e914>] (copy_process.part.5+0x114/0x1a28) [ 672.021345] r10:00000000 r9:99848780 r8:00000000 r7:81447c48 r6:81216588 r5:00808111 [ 672.029169] r4:9b355280 [ 672.031702] [<8021e800>] (copy_process.part.5) from [<802203b0>] (_do_fork+0xd0/0x464) [ 672.039617] r10:00000000 r9:00000000 r8:9d008400 r7:00000000 r6:81216588 r5:9b62f840 [ 672.047441] r4:00808111 [ 672.049972] [<802202e0>] (_do_fork) from [<802207a4>] (kernel_thread+0x38/0x40) [ 672.057281] r10:00000000 r9:81422554 r8:9d008400 r7:00000000 r6:9d004500 r5:9b62f840 [ 672.065105] r4:81216588 [ 672.067642] [<8022076c>] (kernel_thread) from [<802399b4>] (call_usermodehelper_exec_work+0x44/0xe0) [ 672.076775] [<80239970>] (call_usermodehelper_exec_work) from [<8023cfc8>] (process_one_work+0x154/0x518) [ 672.086338] r5:9b62f840 r4:98b43480 [ 672.089913] [<8023ce74>] (process_one_work) from [<8023d3e4>] (worker_thread+0x58/0x56c) [ 672.098003] r10:00000088 r9:98b43480 r8:98b43498 r7:8120f900 r6:88eea038 r5:9d008424 [ 672.105827] r4:9d008400 [ 672.108362] [<8023d38c>] (worker_thread) from [<802440d8>] (kthread+0x134/0x164) [ 672.115757] r10:838dbe68 r9:99e7a2a8 r8:8023d38c r7:98b43480 r6:9bf0d600 r5:00000000 [ 672.123581] r4:99e7a280 [ 672.126116] [<80243fa4>] (kthread) from [<80209258>] (ret_from_fork+0x14/0x3c) [ 672.133338] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:80243fa4 [ 672.141162] r4:9bf0d600 r3:00000000 [ 672.147376] Mem-Info: [ 672.149667] active_anon:68540 inactive_anon:101042 isolated_anon:207 [ 672.149667] active_file:26674 inactive_file:17535 isolated_file:2 [ 672.149667] unevictable:610 dirty:0 writeback:152 unstable:0 [ 672.149667] slab_reclaimable:5039 slab_unreclaimable:9749 [ 672.149667] mapped:32149 shmem:45729 pagetables:4266 bounce:0 [ 672.149667] free:18378 free_pcp:59 free_cma:0 [ 672.183745] Node 0 active_anon:274456kB inactive_anon:404216kB active_file:106672kB inactive_file:70164kB unevictable:2440kB isolated(anon):416kB isolated(file):8kB mapped:128596kB dirty:0kB writeback:544kB shmem:182916kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no [ 672.208055] DMA free:72984kB min:65536kB low:87004kB high:103388kB active_anon:109860kB inactive_anon:109304kB active_file:408kB inactive_file:772kB unevictable:0kB writepending:616kB present:450560kB managed:414704kB mlocked:0kB kernel_stack:5984kB pagetables:7024kB bounce:0kB free_pcp:708kB local_pcp:4kB free_cma:0kB Regards, Pankaj
On Thu, 02 May 2019 04:56:05 +0530, Pankaj Suryawanshi said:
Please help me to decode the error messages and reason for this errors.
[ 3205.818891] HwBinder:1894_6: page allocation failure: order:7, mode:0x14040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)
Order 7 - so it wants 2**7 contiguous pages. 128 4K pages.
[ 3205.967748] [<802186cc>] (__alloc_from_contiguous) from [<80218854>] (cma_allocator_alloc+0x44/0x4c)
And that 3205.nnn tells me the system has been running for almost an hour. Going to be hard finding that much contiguous free memory. Usually CMA is called right at boot to avoid this problem - why is this triggering so late?
[ �671.925663] kworker/u8:13: page allocation stalls for 10090ms, order:1, mode:0x15080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null)
That's.... a *really* long stall.
[ �672.031702] [<8021e800>] (copy_process.part.5) from [<802203b0>] (_do_fork+0xd0/0x464) [ �672.039617] �r10:00000000 r9:00000000 r8:9d008400 r7:00000000 r6:81216588 r5:9b62f840 [ �672.047441] �r4:00808111 [ �672.049972] [<802202e0>] (_do_fork) from [<802207a4>] (kernel_thread+0x38/0x40) [ �672.057281] �r10:00000000 r9:81422554 r8:9d008400 r7:00000000 r6:9d004500 r5:9b62f840 [ �672.065105] �r4:81216588 [ �672.067642] [<8022076c>] (kernel_thread) from [<802399b4>] (call_usermodehelper_exec_work+0x44/0xe0)
First possibility that comes to mind is that a usermodehelper got launched, and it then tried to fork with a very large active process image. Do we have any clues what was going on? Did a device get hotplugged?
On Thu, May 2, 2019 at 10:51 AM Valdis Klētnieks <valdis.kletnieks@vt.edu> wrote:
On Thu, 02 May 2019 04:56:05 +0530, Pankaj Suryawanshi said:
Please help me to decode the error messages and reason for this errors.
[ 3205.818891] HwBinder:1894_6: page allocation failure: order:7, mode:0x14040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)
Order 7 - so it wants 2**7 contiguous pages. 128 4K pages.
kmalloc fails to allocate 2**7
[ 3205.967748] [<802186cc>] (__alloc_from_contiguous) from [<80218854>] (cma_allocator_alloc+0x44/0x4c)
And that 3205.nnn tells me the system has been running for almost an hour. Going to be hard finding that much contiguous free memory.
Usually CMA is called right at boot to avoid this problem - why is this triggering so late?
The use case for late triggering is someone try to play video after an hour, and video memory from CMA area, maybe its due to fragmentation.
[ 671.925663] kworker/u8:13: page allocation stalls for 10090ms, order:1, mode:0x15080c0(GFP_KERNEL_ACCOUNT|__GFP_ZERO), nodemask=(null)
That's.... a *really* long stall.
Yes very long any pointers to block this warnings/errors.
[ 672.031702] [<8021e800>] (copy_process.part.5) from [<802203b0>] (_do_fork+0xd0/0x464) [ 672.039617] r10:00000000 r9:00000000 r8:9d008400 r7:00000000 r6:81216588 r5:9b62f840 [ 672.047441] r4:00808111 [ 672.049972] [<802202e0>] (_do_fork) from [<802207a4>] (kernel_thread+0x38/0x40) [ 672.057281] r10:00000000 r9:81422554 r8:9d008400 r7:00000000 r6:9d004500 r5:9b62f840 [ 672.065105] r4:81216588 [ 672.067642] [<8022076c>] (kernel_thread) from [<802399b4>] (call_usermodehelper_exec_work+0x44/0xe0)
First possibility that comes to mind is that a usermodehelper got launched, and it then tried to fork with a very large active process image. Do we have any clues what was going on? Did a device get hotplugged?
Yes,The system is android and it tries to allocate memory for video player from CMA reserved memory using custom octl call for dma apis. Please let me know how to overcome this issues, or how to reduce fragmentation of memory so that higher order allocation get suuceed ? Thanks
On 5/3/19 7:44 PM, Pankaj Suryawanshi wrote:
First possibility that comes to mind is that a usermodehelper got launched, and it then tried to fork with a very large active process image. Do we have any clues what was going on? Did a device get hotplugged?
Yes,The system is android and it tries to allocate memory for video player from CMA reserved memory using custom octl call for dma apis.
The stacktrace doesn't look like a CMA allocation though. That would be doing alloc_contig_range(), not kmalloc(). Could be some CMA area setup issue?
Please let me know how to overcome this issues, or how to reduce fragmentation of memory so that higher order allocation get suuceed ?
Thanks
On Mon, May 6, 2019 at 2:35 PM Vlastimil Babka <vbabka@suse.cz> wrote:
On 5/3/19 7:44 PM, Pankaj Suryawanshi wrote:
First possibility that comes to mind is that a usermodehelper got launched, and it then tried to fork with a very large active process image. Do we have any clues what was going on? Did a device get hotplugged?
Yes,The system is android and it tries to allocate memory for video player from CMA reserved memory using custom octl call for dma apis.
The stacktrace doesn't look like a CMA allocation though. That would be doing alloc_contig_range(), not kmalloc(). Could be some CMA area setup issue?
I know cma uses alloc_contig_range() but using dma api it will uses many functions. the failure is coming from dma_common_contiguous_remap() for kmalloc , and which is called by dma_alloc_attr for cma allocation. Please let me know, how to avoid page allocation stalls. any reason ? Cpu Utilization issue ? or I am running out of memory ? My System configuration is 2GB RAM Memory Spilt 2G/2G vmalloc=1024M CMA=1024 Max contiguous memory required 390M
Please let me know how to overcome this issues, or how to reduce fragmentation of memory so that higher order allocation get suuceed ?
Thanks
participants (3)
-
Pankaj Suryawanshi -
Valdis Klētnieks -
Vlastimil Babka