Hello Experts, I am facing one "Detected aborted journal" error for in below use cases, We are using Beaglebone Black(AM335x) based custom board, Which has 256MB of RAM, 4GB of eMMC and running Linux 3.12 Use Case 1 : ----------------- With following use case I am able to reproduce issue every single time 1. Create big rootfs.tar.gz ( 156MB actual file + 330MB of 4KB size files (approx. 82,000 files= ~480MB uncompressed). 2. Mount 500 MB of spare eMMC partition(fs:ext4) on one folder. (Journaling is enabled, with default option) 3. Untarr big rootfs.tar.gz on to mounted partition. 4. After a while(before untar is done) page allocation error followed by "Detected aborted journal" error is observed and then partition gets remounted as read-only. 5. Observe Log 1 below for above use case, Use Case 2 : ----------------- Another use case, in which error gets reproduced after random number of rounds, 1. Create a big rootfs (156MB actual files + 33 number of 10MB files = ~480MB uncompressed). 2. Write a small script to continuously untar to and delete files from mounted 500MB eMMC partition, in while loop. 3. In another terminal run dd to raw read partition in while loop. 4. After some number of rounds "page allocation error" followed by "Detected aborted journal" error is observed and then partition gets remounted as read-only. 5. Observe Log2 below for above use case. 6. During log2 capture in while loop I kept on adding mem-info using sysrq-trigger using command " echo -m > /proc/sysrq-trigger", and from mem-info I see just before error , 16KB budylist low and later it was empty. --------------------------- Some solutions I tried, ---------------------------- 1. When I disable journaling, I am not seeing issue but sudden power loss causes corruption in file system. 2. If I change /proc/sys/vm/min_free_kbytes from 2005 to 8192 reproducibility in both the cases changes, but issue is still reproducible. Note: - Same thing is not reproducible in Beaglebone black, even when I change RAM to 256MB by passing it in command line parameter. (mem=256M) --------------------------------------------------- Queries --------------------------------------------------- Now my question is what is the cause of the error ? 0. What is the root cause of this issue? Or how do I find it out? 1. if its fragmentation, what could be a possible solution? [ however I am wondering why its not happening in Beaglebone Black :( ] 2. Is there any feature/mount option in ext4 that can cause this issue ? 3. Is there any memory shrinker utility/module to shrink memory ? Suggestion/pointers ? ------------------------------------------------------------- Log 1 : Error observed when extracting tar ------------------------------------------------------------- [55111.941029] mmcqd/1: page allocation failure: order:3, mode:0x200020 [55111.941069] CPU: 0 PID: 613 Comm: mmcqd/1 Tainted: P O 3.12.10-005-ts-armv7l #1 [55111.941135] [<c0012d24>] (unwind_backtrace+0x0/0xf4) from [<c0011130>] (show_stack+0x10/0x14) [55111.941170] [<c0011130>] (show_stack+0x10/0x14) from [<c0087548>] (warn_alloc_failed+0xe0/0x118) [55111.941199] [<c0087548>] (warn_alloc_failed+0xe0/0x118) from [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) [55111.941229] [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) from [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) [55111.941252] [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) from [<c00b3224>] (__kmalloc+0xa0/0xe8) [55111.941289] [<c00b3224>] (__kmalloc+0xa0/0xe8) from [<c0212904>] (edma_prep_slave_sg+0x84/0x388) [55111.941324] [<c0212904>] (edma_prep_slave_sg+0x84/0x388) from [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) [55111.941351] [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) from [<c02d9240>] (mmc_start_request+0xc4/0xe0) [55111.941373] [<c02d9240>] (mmc_start_request+0xc4/0xe0) from [<c02da028>] (mmc_start_req+0x2d8/0x38c) [55111.941395] [<c02da028>] (mmc_start_req+0x2d8/0x38c) from [<c02e7310>] (mmc_blk_issue_rw_rq+0xb4/0x9d8) [55111.941417] [<c02e7310>] (mmc_blk_issue_rw_rq+0xb4/0x9d8) from [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) [55111.941437] [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) from [<c02e8760>] (mmc_queue_thread+0x88/0x118) [55111.941464] [<c02e8760>] (mmc_queue_thread+0x88/0x118) from [<c004d8b8>] (kthread+0xb4/0xb8) [55111.941488] [<c004d8b8>] (kthread+0xb4/0xb8) from [<c000e298>] (ret_from_fork+0x14/0x3c) [55111.941498] Mem-info: [55111.941508] Normal per-cpu: [55111.941518] CPU 0: hi: 90, btch: 15 usd: 17 [55111.941546] active_anon:7181 inactive_anon:19 isolated_anon:0 [55111.941546] active_file:6230 inactive_file:38799 isolated_file:0 [55111.941546] unevictable:422 dirty:3996 writeback:0 unstable:0 [55111.941546] free:1721 slab_reclaimable:6241 slab_unreclaimable:1180 [55111.941546] mapped:2185 shmem:42 pagetables:233 bounce:0 [55111.941546] free_cma:958 [55111.941607] Normal free:6884kB min:2004kB low:2504kB high:3004kB active_anon:28724kB inactive_anon:76kB active_file:24920kB inactive_file:155196kB unevictable:1688kB isolated(anon):0kB isolated(file):0kB present:260096kB managed:251496kB mlocked:1688kB dirty:15984kB writeback:0kB mapped:8740kB shmem:168kB slab_reclaimable:24964kB slab_unreclaimable:4720kB kernel_stack:1128kB pagetables:932kB unstable:0kB bounce:0kB free_cma:3832kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no 2016-09-16T02:19:52.250111-04:00 kernel: [55111.941619] lowmem_reserve[]: 0 0 0 2016-09-16T02:19:52.250137-04:00 kernel: [55111.941637] Normal: 541*4kB (EMC) 496*8kB (UEMC) 39*16kB (MC) 4*32kB (C) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 6884kB [55111.941691] 45425 total pagecache pages [55111.941707] 0 pages in swap cache [55111.941717] Swap cache stats: add 0, delete 0, find 0/0 [55111.941724] Free swap = 0kB [55111.941731] Total swap = 0kB [55111.941743] SLAB: Unable to allocate memory on node 0 (gfp=0x20) [55111.941755] cache: kmalloc-32768, object size: 32768, order: 3 [55111.941767] node 0: slabs: 3/3, objs: 3/3, free: 0 [55111.941811] omap_hsmmc 481d8000.mmc: prep_slave_sg() failed [55111.941825] omap_hsmmc 481d8000.mmc: MMC start dma failure [55111.943401] mmcblk0: unknown error -1 sending read/write command, card status 0x900 [55111.943751] blk_update_request: 338 callbacks suppressed [55111.943765] end_request: I/O error, dev mmcblk0, sector 1618876 [55111.943999] end_request: I/O error, dev mmcblk0, sector 1618878 [55111.944125] end_request: I/O error, dev mmcblk0, sector 1618880 [55111.944204] end_request: I/O error, dev mmcblk0, sector 1618882 [55111.944276] end_request: I/O error, dev mmcblk0, sector 1618884 [55111.944348] end_request: I/O error, dev mmcblk0, sector 1618886 [55111.944417] end_request: I/O error, dev mmcblk0, sector 1618888 [55111.944487] end_request: I/O error, dev mmcblk0, sector 1618890 [55111.944555] end_request: I/O error, dev mmcblk0, sector 1618892 [55111.944624] end_request: I/O error, dev mmcblk0, sector 1618894 [55111.959268] mmcqd/1: page allocation failure: order:3, mode:0x200020 [55111.959297] CPU: 0 PID: 613 Comm: mmcqd/1 Tainted: P O 3.12.10-005-ts-armv7l #1 [55111.959354] [<c0012d24>] (unwind_backtrace+0x0/0xf4) from [<c0011130>] (show_stack+0x10/0x14) [55111.959387] [<c0011130>] (show_stack+0x10/0x14) from [<c0087548>] (warn_alloc_failed+0xe0/0x118) [55111.959414] [<c0087548>] (warn_alloc_failed+0xe0/0x118) from [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) [55111.959442] [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) from [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) [55111.959465] [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) from [<c00b3224>] (__kmalloc+0xa0/0xe8) [55111.959499] [<c00b3224>] (__kmalloc+0xa0/0xe8) from [<c0212904>] (edma_prep_slave_sg+0x84/0x388) [55111.959533] [<c0212904>] (edma_prep_slave_sg+0x84/0x388) from [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) [55111.959559] [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) from [<c02d9240>] (mmc_start_request+0xc4/0xe0) [55111.959581] [<c02d9240>] (mmc_start_request+0xc4/0xe0) from [<c02da028>] (mmc_start_req+0x2d8/0x38c) [55111.959602] [<c02da028>] (mmc_start_req+0x2d8/0x38c) from [<c02e748c>] (mmc_blk_issue_rw_rq+0x230/0x9d8) [55111.959623] [<c02e748c>] (mmc_blk_issue_rw_rq+0x230/0x9d8) from [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) [55111.959645] [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) from [<c02e8760>] (mmc_queue_thread+0x88/0x118) [55111.959670] [<c02e8760>] (mmc_queue_thread+0x88/0x118) from [<c004d8b8>] (kthread+0xb4/0xb8) [55111.959694] [<c004d8b8>] (kthread+0xb4/0xb8) from [<c000e298>] (ret_from_fork+0x14/0x3c) [55111.959703] Mem-info: [55111.959712] Normal per-cpu: [55111.959722] CPU 0: hi: 90, btch: 15 usd: 52 [55111.959750] active_anon:7181 inactive_anon:19 isolated_anon:0 [55111.959750] active_file:6230 inactive_file:38782 isolated_file:0 [55111.959750] unevictable:422 dirty:3996 writeback:0 unstable:0 [55111.959750] free:1721 slab_reclaimable:6241 slab_unreclaimable:1172 [55111.959750] mapped:2185 shmem:42 pagetables:233 bounce:0 [55111.959750] free_cma:958 [55111.959809] Normal free:6884kB min:2004kB low:2504kB high:3004kB active_anon:28724kB inactive_anon:76kB active_file:24920kB inactive_file:155128kB unevictable:1688kB isolated(anon):0kB isolated(file):0kB present:260096kB managed:251496kB mlocked:1688kB dirty:15984kB writeback:0kB mapped:8740kB shmem:168kB slab_reclaimable:24964kB slab_unreclaimable:4688kB kernel_stack:1128kB pagetables:932kB unstable:0kB bounce:0kB free_cma:3832kB writeback_tmp:0kB pages_scanned:27 all_unreclaimable? no [55111.959821] lowmem_reserve[]: 0 0 0 [55111.959837] Normal: 541*4kB (EMC) 496*8kB (UEMC) 39*16kB (MC) 4*32kB (C) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 6884kB [55111.959889] 45398 total pagecache pages [55111.959905] 0 pages in swap cache [55111.959914] Swap cache stats: add 0, delete 0, find 0/0 [55111.959922] Free swap = 0kB [55111.959929] Total swap = 0kB [55111.959941] SLAB: Unable to allocate memory on node 0 (gfp=0x20) [55111.959952] cache: kmalloc-32768, object size: 32768, order: 3 [55111.959964] node 0: slabs: 3/3, objs: 3/3, free: 0 [55111.960055] omap_hsmmc 481d8000.mmc: prep_slave_sg() failed [55111.960071] omap_hsmmc 481d8000.mmc: MMC start dma failure [55111.967304] mmcblk0: unknown error -1 sending read/write command, card status 0x900 [55112.131849] Aborting journal on device mmcblk0p16-8. [55112.147130] EXT4-fs error (device mmcblk0p16): ext4_journal_check_start:56: Detected aborted journal [55112.156857] EXT4-fs (mmcblk0p16): Remounting filesystem read-only -------------------------------------------------------------------- Log2 : Error observed when untarring and running dd -------------------------------------------------------------------- [47359.152481] lowmem_reserve[]: 0 0 0 [47359.152495] Normal: 620*4kB (UEMRC) 306*8kB (UEM) 23*16kB (UEM) 4*32kB (EM) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 5488kB [47359.152553] 47145 total pagecache pages [47359.152569] 0 pages in swap cache [47359.152579] Swap cache stats: add 0, delete 0, find 0/0 [47359.152588] Free swap = 0kB [47359.152594] Total swap = 0kB [47359.163599] 65536 pages of RAM [47359.163610] 1738 free pages [47359.163616] 2662 reserved pages [47359.163624] 5665 slab pages [47359.163631] 312658 pages shared [47359.163639] 0 pages swap cached [47364.483654] Mem-info: [47364.483668] Normal per-cpu: [47364.483682] CPU 0: hi: 90, btch: 15 usd: 28 [47364.483710] active_anon:7464 inactive_anon:20 isolated_anon:0 [47364.483710] active_file:3168 inactive_file:41035 isolated_file:0 [47364.483710] unevictable:422 dirty:19 writeback:0 unstable:0 [47364.483710] free:4459 slab_reclaimable:4089 slab_unreclaimable:1111 [47364.483710] mapped:2356 shmem:43 pagetables:244 bounce:0 [47364.483710] free_cma:47 [47364.483771] Normal free:17836kB min:2004kB low:2504kB high:3004kB active_anon:29856kB inactive_anon:80kB active_file:12672kB inactive_file:164140kB unevictable:1688kB isolated(anon):0kB isolated(file):0kB present:260096kB managed:251496kB mlocked:1688kB dirty:76kB writeback:0kB mapped:9424kB shmem:172kB slab_reclaimable:16356kB slab_unreclaimable:4444kB kernel_stack:1160kB pagetables:976kB unstable:0kB bounce:0kB free_cma:188kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [47364.483783] lowmem_reserve[]: 0 0 0 [47364.483797] Normal: 2529*4kB (UEMRC) 893*8kB (UEMC) 16*16kB (UM) 6*32kB (M) 0*64kB 1*128kB (M) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 17836kB [47364.483855] 44590 total pagecache pages [47364.483871] 0 pages in swap cache [47364.483881] Swap cache stats: add 0, delete 0, find 0/0 [47364.483888] Free swap = 0kB [47364.483895] Total swap = 0kB [47364.494968] 65536 pages of RAM [47364.494978] 4767 free pages [47364.494985] 2662 reserved pages [47364.494993] 5200 slab pages [47364.495000] 310103 pages shared [47364.495008] 0 pages swap cached [47368.503176] mmcqd/1: page allocation failure: order:2, mode:0x200020 [47368.503216] CPU: 0 PID: 613 Comm: mmcqd/1 Tainted: P O 3.12.10-005-ts-armv7l #1 [47368.503282] [<c0012d24>] (unwind_backtrace+0x0/0xf4) from [<c0011130>] (show_stack+0x10/0x14) [47368.503317] [<c0011130>] (show_stack+0x10/0x14) from [<c0087548>] (warn_alloc_failed+0xe0/0x118) [47368.503346] [<c0087548>] (warn_alloc_failed+0xe0/0x118) from [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) [47368.503375] [<c008a3ac>] (__alloc_pages_nodemask+0x74c/0x8f8) from [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) [47368.503398] [<c00b2e8c>] (cache_alloc_refill+0x328/0x620) from [<c00b3224>] (__kmalloc+0xa0/0xe8) [47368.503433] [<c00b3224>] (__kmalloc+0xa0/0xe8) from [<c0212904>] (edma_prep_slave_sg+0x84/0x388) [47368.503469] [<c0212904>] (edma_prep_slave_sg+0x84/0x388) from [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) [47368.503497] [<c02eeb98>] (omap_hsmmc_request+0x414/0x508) from [<c02d9240>] (mmc_start_request+0xc4/0xe0) [47368.503519] [<c02d9240>] (mmc_start_request+0xc4/0xe0) from [<c02da028>] (mmc_start_req+0x2d8/0x38c) [47368.503540] [<c02da028>] (mmc_start_req+0x2d8/0x38c) from [<c02e7310>] (mmc_blk_issue_rw_rq+0xb4/0x9d8) [47368.503562] [<c02e7310>] (mmc_blk_issue_rw_rq+0xb4/0x9d8) from [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) [47368.503583] [<c02e7dd8>] (mmc_blk_issue_rq+0x1a4/0x468) from [<c02e8760>] (mmc_queue_thread+0x88/0x118) [47368.503609] [<c02e8760>] (mmc_queue_thread+0x88/0x118) from [<c004d8b8>] (kthread+0xb4/0xb8) [47368.503633] [<c004d8b8>] (kthread+0xb4/0xb8) from [<c000e298>] (ret_from_fork+0x14/0x3c) [47368.503644] Mem-info: [47368.503653] Normal per-cpu: [47368.503664] CPU 0: hi: 90, btch: 15 usd: 17 [47368.503691] active_anon:7530 inactive_anon:20 isolated_anon:0 [47368.503691] active_file:3142 inactive_file:44610 isolated_file:0 [47368.503691] unevictable:422 dirty:32 writeback:0 unstable:0 [47368.503691] free:1149 slab_reclaimable:3734 slab_unreclaimable:1130 [47368.503691] mapped:2362 shmem:43 pagetables:256 bounce:0 [47368.503691] free_cma:207 [47368.503752] Normal free:4596kB min:2004kB low:2504kB high:3004kB active_anon:30120kB inactive_anon:80kB active_file:12568kB inactive_file:178440kB unevictable:1688kB isolated(anon):0kB isolated(file):0kB present:260096kB managed:251496kB mlocked:1688kB dirty:128kB writeback:0kB mapped:9448kB shmem:172kB slab_reclaimable:14936kB slab_unreclaimable:4520kB kernel_stack:1176kB pagetables:1024kB unstable:0kB bounce:0kB free_cma:828kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [47368.503765] lowmem_reserve[]: 0 0 0 [47368.503782] Normal: 833*4kB (UEMRC) 158*8kB (MC) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 4596kB [47368.503833] 48144 total pagecache pages [47368.503849] 0 pages in swap cache [47368.503858] Swap cache stats: add 0, delete 0, find 0/0 [47368.503866] Free swap = 0kB [47368.503873] Total swap = 0kB [47368.503885] SLAB: Unable to allocate memory on node 0 (gfp=0x20) [47368.503896] cache: kmalloc-16384, object size: 16384, order: 2 [47368.503909] node 0: slabs: 7/7, objs: 7/7, free: 0 [47368.503932] omap_hsmmc 481d8000.mmc: prep_slave_sg() failed [47368.503945] omap_hsmmc 481d8000.mmc: MMC start dma failure [47368.512369] mmcblk0: unknown error -1 sending read/write command, card status 0x900 [47368.512578] blk_update_request: 371 callbacks suppressed [47368.512591] end_request: I/O error, dev mmcblk0, sector 1371894 [47368.512613] Buffer I/O error on device mmcblk0p16, logical block 145275 [47368.512623] lost page write due to I/O error on mmcblk0p16 [47368.512892] end_request: I/O error, dev mmcblk0, sector 1371896 [47368.512906] Buffer I/O error on device mmcblk0p16, logical block 145276 [47368.512916] lost page write due to I/O error on mmcblk0p16 [47368.513011] end_request: I/O error, dev mmcblk0, sector 1371898 [47368.513024] Buffer I/O error on device mmcblk0p16, logical block 145277 [47368.513034] lost page write due to I/O error on mmcblk0p16 [47368.513107] end_request: I/O error, dev mmcblk0, sector 1371900 [47368.513179] end_request: I/O error, dev mmcblk0, sector 1371902 [47368.513251] end_request: I/O error, dev mmcblk0, sector 1371904 [47368.513322] end_request: I/O error, dev mmcblk0, sector 1371906 [47368.513405] end_request: I/O error, dev mmcblk0, sector 1371908 [47368.513478] end_request: I/O error, dev mmcblk0, sector 1371910 [47368.513549] end_request: I/O error, dev mmcblk0, sector 1371912 [47368.796212] Aborting journal on device mmcblk0p16-8. [47368.802513] EXT4-fs error (device mmcblk0p16): ext4_journal_check_start:56: Detected aborted journal [47368.812303] EXT4-fs (mmcblk0p16): Remounting filesystem read-only [47369.669029] Mem-info: [47369.669043] Normal per-cpu: [47369.669057] CPU 0: hi: 90, btch: 15 usd: 47 [47369.669085] active_anon:7486 inactive_anon:20 isolated_anon:0 [47369.669085] active_file:3150 inactive_file:44775 isolated_file:0 [47369.669085] unevictable:422 dirty:37 writeback:0 unstable:0 [47369.669085] free:1041 slab_reclaimable:3730 slab_unreclaimable:1105 [47369.669085] mapped:2367 shmem:43 pagetables:250 bounce:0 [47369.669085] free_cma:176 [47369.669147] Normal free:4164kB min:2004kB low:2504kB high:3004kB active_anon:29944kB inactive_anon:80kB active_file:12600kB inactive_file:179100kB unevictable:1688kB isolated(anon):0kB isolated(file):0kB present:260096kB managed:251496kB mlocked:1688kB dirty:148kB writeback:0kB mapped:9468kB shmem:172kB slab_reclaimable:14920kB slab_unreclaimable:4420kB kernel_stack:1168kB pagetables:1000kB unstable:0kB bounce:0kB free_cma:704kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [47369.669159] lowmem_reserve[]: 0 0 0 [47369.669173] Normal: 733*4kB (UEMRC) 92*8kB (MC) 11*16kB (UMC) 6*32kB (UMC) 2*64kB (U) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB = 4164kB [47369.669230] 48312 total pagecache pages [47369.669246] 0 pages in swap cache [47369.669256] Swap cache stats: add 0, delete 0, find 0/0 [47369.669263] Free swap = 0kB [47369.669270] Total swap = 0kB [47369.680300] 65536 pages of RAM [47369.680310] 1372 free pages [47369.680317] 2662 reserved pages [47369.680324] 4835 slab pages [47369.680332] 312903 pages shared [47369.680339] 0 pages swap cached Thank you, Regards, Ankur -- To unsubscribe from this list: send the line "unsubscribe linux-omap" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html