ottok / shannon-direct-io-pcie-driver

2 stars 2 forks source link

Page allocation failures with driver 3.4.0 and Ubuntu 18.04 #3

Open ottok opened 4 years ago

ottok commented 4 years ago

Now mysqld does not crash anymore, but we still see frequent page allocation errors. From syslog:


 [317881.237218] mysqld: page allocation failure: order:4, mode:0x140c000(GFP_NOIO|__GFP_COMP|__GFP_ZERO), nodemask=(null)
 [317881.237220] mysqld cpuset=649b2ab5c04fb81c9dd93bf9f6a8b96fdac531af016fb401672157ca490f4937 mems_allowed=0-1
 [317881.237226] CPU: 22 PID: 64337 Comm: mysqld Tainted: G           OE    4.15.0-72-generic #81-Ubuntu
 [317881.237227] Hardware name: Huawei RH1288 V3/BC11HGSC0, BIOS 5.13 04/11/2019
 [317881.237228] Call Trace:
 [317881.237238]  dump_stack+0x63/0x8e
 [317881.237242]  warn_alloc+0xff/0x1a0
 [317881.237245]  ? __alloc_pages_direct_compact+0x51/0x100
 [317881.237247]  __alloc_pages_slowpath+0xdc5/0xe00
 [317881.237250]  __alloc_pages_nodemask+0x29a/0x2c0
 [317881.237255]  alloc_pages_current+0x6a/0xe0
 [317881.237260]  kmalloc_order+0x18/0x40
 [317881.237261]  kmalloc_order_trace+0x24/0xb0
 [317881.237263]  ? mempool_alloc_slab+0x15/0x20
 [317881.237266]  __kmalloc+0x209/0x220
 [317881.237289]  shannon_sg_alloc+0x1a/0x20 [shannon]
 [317881.237301]  shannon_convert_bio+0x74/0x600 [shannon]
 [317881.237311]  shannon_make_request+0xd7/0x2c0 [shannon]
 [317881.237321]  shannon_make_request_wrapper+0xe/0x20 [shannon]
 [317881.237324]  generic_make_request+0x124/0x300
 [317881.237326]  submit_bio+0x73/0x140
 [317881.237328]  ? submit_bio+0x73/0x140
 [317881.237331]  ext4_io_submit+0x4c/0x60
 [317881.237332]  ext4_writepages+0x476/0xf50
 [317881.237337]  do_writepages+0x4b/0xe0
 [317881.237338]  ? ext4_mark_inode_dirty+0x1d0/0x1d0
 [317881.237340]  ? do_writepages+0x4b/0xe0
 [317881.237342]  ? seccomp_run_filters+0x5d/0xd0
 [317881.237344]  __filemap_fdatawrite_range+0xc1/0x100
 [317881.237345]  ? __filemap_fdatawrite_range+0xc1/0x100
 [317881.237346]  file_write_and_wait_range+0x5a/0xb0
 [317881.237349]  ext4_sync_file+0x11e/0x3f0
 [317881.237352]  vfs_fsync_range+0x51/0xb0
 [317881.237354]  do_fsync+0x3d/0x70
 [317881.237356]  SyS_fsync+0x10/0x20
 [317881.237360]  do_syscall_64+0x73/0x130
 [317881.237362]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
 [317881.237364] RIP: 0033:0x7f3db6507d3d
 [317881.237365] RSP: 002b:00007f3cfcff8570 EFLAGS: 00000293 ORIG_RAX: 000000000000004a
 [317881.237367] RAX: ffffffffffffffda RBX: 0000000000000015 RCX: 00007f3db6507d3d
 [317881.237367] RDX: 00007f3db1044860 RSI: 0000000000000000 RDI: 0000000000000015
 [317881.237368] RBP: 00007f3cfcff85a0 R08: 0000000000000000 R09: 0000000000000000
 [317881.237369] R10: 00007f3db106e968 R11: 0000000000000293 R12: 0000000000000000
 [317881.237370] R13: 0000000051eb851f R14: 0000000000000015 R15: 00007f3db12f6168
 [317881.237371] Mem-Info:
 [317881.237381] active_anon:16768407 inactive_anon:7704909 isolated_anon:28
 [317881.237381]  active_file:1819256 inactive_file:1985302 isolated_file:0
 [317881.237381]  unevictable:41306 dirty:2534 writeback:317 unstable:0
 [317881.237381]  slab_reclaimable:1492365 slab_unreclaimable:2136949
 [317881.237381]  mapped:3171670 shmem:2672903 pagetables:380897 bounce:0
 [317881.237381]  free:169837 free_pcp:421 free_cma:0
 [317881.237384] Node 0 active_anon:42923088kB inactive_anon:14318228kB active_file:14588kB inactive_file:4964kB unevictable:4160kB isolated(anon):0kB isolated(file):0kB mapped:3876928kB dirty:316kB writeback:0kB shmem:4376684kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 129024kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
 [317881.237387] Node 1 active_anon:24150540kB inactive_anon:16501408kB active_file:7262436kB inactive_file:7936244kB unevictable:161064kB isolated(anon):112kB isolated(file):0kB mapped:8809752kB dirty:9820kB writeback:1268kB shmem:6314928kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 217088kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
 [317881.237388] Node 0 DMA free:15788kB min:8kB low:20kB high:32kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15868kB managed:15788kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
 [317881.237392] lowmem_reserve[]: 0 1504 63967 63967 63967
 [317881.237395] Node 0 DMA32 free:252372kB min:1052kB low:2592kB high:4132kB active_anon:961120kB inactive_anon:265516kB active_file:336kB inactive_file:284kB unevictable:0kB writepending:156kB present:1662848kB managed:1597204kB mlocked:0kB kernel_stack:844kB pagetables:20808kB bounce:0kB free_pcp:320kB local_pcp:0kB free_cma:0kB
 [317881.237399] lowmem_reserve[]: 0 0 62463 62463 62463
 [317881.237402] Node 0 Normal free:101248kB min:43812kB low:107772kB high:171732kB active_anon:41962748kB inactive_anon:14052712kB active_file:14252kB inactive_file:4680kB unevictable:4160kB writepending:160kB present:65011712kB managed:63962700kB mlocked:4160kB kernel_stack:170004kB pagetables:677200kB bounce:0kB free_pcp:120kB local_pcp:0kB free_cma:0kB
 [317881.237405] lowmem_reserve[]: 0 0 0 0 0
 [317881.237408] Node 1 Normal free:309940kB min:45228kB low:111252kB high:177276kB active_anon:24150760kB inactive_anon:16500984kB active_file:7262456kB inactive_file:7936404kB unevictable:161064kB writepending:11088kB present:67108864kB managed:66033216kB mlocked:161064kB kernel_stack:142696kB pagetables:825580kB bounce:0kB free_pcp:1200kB local_pcp:0kB free_cma:0kB
 [317881.237411] lowmem_reserve[]: 0 0 0 0 0
 [317881.237413] Node 0 DMA: 1*4kB (U) 3*8kB (U) 1*16kB (U) 0*32kB 2*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15788kB
 [317881.237423] Node 0 DMA32: 1096*4kB (UEH) 1426*8kB (UMEH) 1128*16kB (UMEH) 521*32kB (UMEH) 410*64kB (UMEH) 193*128kB (UMEH) 54*256kB (UME) 26*512kB (UME) 11*1024kB (UE) 9*2048kB (M) 23*4096kB (M) = 252496kB
 [317881.237434] Node 0 Normal: 6524*4kB (UMEH) 411*8kB (UMEH) 1089*16kB (UMEH) 1743*32kB (UMEH) 3*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 102776kB
 [317881.237442] Node 1 Normal: 140*4kB (UM) 833*8kB (UEH) 6420*16kB (UEH) 6294*32kB (UEH) 2*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 311480kB
 [317881.237452] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
 [317881.237453] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
 [317881.237454] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
 [317881.237455] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
 [317881.237455] 6542351 total pagecache pages
 [317881.237457] 91869 pages in swap cache
 [317881.237458] Swap cache stats: add 891432, delete 800545, find 12461943/12641420
 [317881.237459] Free swap  = 0kB
 [317881.237459] Total swap = 2097148kB
 [317881.237460] 33449823 pages RAM
 [317881.237461] 0 pages HighMem/MovableOnly
 [317881.237461] 547596 pages reserved
 [317881.237462] 0 pages cma reserved
 [317881.237462] 0 pages hwpoisoned
 [317889.285611] mysqld: page allocation failure: order:4, mode:0x140c000(GFP_NOIO|__GFP_COMP|__GFP_ZERO), nodemask=(null)
 [317889.285613] mysqld cpuset=649b2ab5c04fb81c9dd93bf9f6a8b96fdac531af016fb401672157ca490f4937 mems_allowed=0-1
 [317889.285620] CPU: 24 PID: 64337 Comm: mysqld Tainted: G           OE    4.15.0-72-generic #81-Ubuntu
 [317889.285621] Hardware name: Huawei RH1288 V3/BC11HGSC0, BIOS 5.13 04/11/2019
 [317889.285622] Call Trace:
 [317889.285635]  dump_stack+0x63/0x8e
 [317889.285641]  warn_alloc+0xff/0x1a0
 [317889.285644]  ? __alloc_pages_direct_compact+0x51/0x100
 [317889.285646]  __alloc_pages_slowpath+0xdc5/0xe00
 [317889.285651]  ? __switch_to_asm+0x35/0x70
 [317889.285653]  ? __switch_to_asm+0x41/0x70
 [317889.285655]  __alloc_pages_nodemask+0x29a/0x2c0
 [317889.285661]  alloc_pages_current+0x6a/0xe0
 [317889.285666]  kmalloc_order+0x18/0x40
 [317889.285668]  kmalloc_order_trace+0x24/0xb0
 [317889.285670]  ? mempool_alloc_slab+0x15/0x20
 [317889.285673]  __kmalloc+0x209/0x220
 [317889.285701]  shannon_sg_alloc+0x1a/0x20 [shannon]
 [317889.285712]  shannon_convert_bio+0x74/0x600 [shannon]
 [317889.285722]  shannon_make_request+0xd7/0x2c0 [shannon]
 [317889.285732]  shannon_make_request_wrapper+0xe/0x20 [shannon]
 [317889.285736]  generic_make_request+0x124/0x300
 [317889.285738]  submit_bio+0x73/0x140
 [317889.285740]  ? submit_bio+0x73/0x140
 [317889.285744]  ext4_io_submit+0x4c/0x60
 [317889.285745]  ext4_bio_write_page+0x262/0x530
 [317889.285749]  mpage_submit_page+0x59/0x80
 [317889.285751]  mpage_process_page_bufs+0xf6/0x100
 [317889.285753]  mpage_prepare_extent_to_map+0x214/0x2f0
 [317889.285755]  ext4_writepages+0x463/0xf50
 [317889.285759]  do_writepages+0x4b/0xe0
 [317889.285760]  ? ext4_mark_inode_dirty+0x1d0/0x1d0
 [317889.285762]  ? do_writepages+0x4b/0xe0
 [317889.285765]  ? seccomp_run_filters+0x5d/0xd0
 [317889.285766]  __filemap_fdatawrite_range+0xc1/0x100
 [317889.285767]  ? __filemap_fdatawrite_range+0xc1/0x100
 [317889.285769]  file_write_and_wait_range+0x5a/0xb0
 [317889.285771]  ext4_sync_file+0x11e/0x3f0
 [317889.285775]  vfs_fsync_range+0x51/0xb0
 [317889.285777]  do_fsync+0x3d/0x70
 [317889.285779]  SyS_fsync+0x10/0x20
 [317889.285782]  do_syscall_64+0x73/0x130
 [317889.285784]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
 [317889.285786] RIP: 0033:0x7f3db6507d3d
 [317889.285787] RSP: 002b:00007f3cfcff8570 EFLAGS: 00000293 ORIG_RAX: 000000000000004a
 [317889.285789] RAX: ffffffffffffffda RBX: 0000000000000016 RCX: 00007f3db6507d3d
 [317889.285790] RDX: 00007f3db1044860 RSI: 0000000000000000 RDI: 0000000000000016
 [317889.285790] RBP: 00007f3cfcff85a0 R08: 0000000000000000 R09: 0000000000000000
 [317889.285791] R10: 00007f3db106e968 R11: 0000000000000293 R12: 0000000000000000
 [317889.285792] R13: 0000000051eb851f R14: 0000000000000016 R15: 00007f3db12f6268
 [317889.285794] Mem-Info:
 [317889.285804] active_anon:16766120 inactive_anon:7708317 isolated_anon:27
 [317889.285804]  active_file:1816693 inactive_file:1973163 isolated_file:0
 [317889.285804]  unevictable:41306 dirty:3879 writeback:517 unstable:0
 [317889.285804]  slab_reclaimable:1491975 slab_unreclaimable:2136715
 [317889.285804]  mapped:3171941 shmem:2672908 pagetables:381087 bounce:0
 [317889.285804]  free:183239 free_pcp:136 free_cma:0
 [317889.285807] Node 0 active_anon:42914480kB inactive_anon:14321100kB active_file:14872kB inactive_file:5976kB unevictable:4160kB isolated(anon):0kB isolated(file):0kB mapped:3877404kB dirty:552kB writeback:20kB shmem:4376684kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 133120kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
 [317889.285810] Node 1 active_anon:24150000kB inactive_anon:16512168kB active_file:7251900kB inactive_file:7886676kB unevictable:161064kB isolated(anon):108kB isolated(file):0kB mapped:8810360kB dirty:14964kB writeback:2048kB shmem:6314948kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 215040kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
 [317889.285811] Node 0 DMA free:15788kB min:8kB low:20kB high:32kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15868kB managed:15788kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
 [317889.285815] lowmem_reserve[]: 0 1504 63967 63967 63967
 [317889.285818] Node 0 DMA32 free:252736kB min:1052kB low:2592kB high:4132kB active_anon:961268kB inactive_anon:265508kB active_file:340kB inactive_file:248kB unevictable:0kB writepending:12kB present:1662848kB managed:1597204kB mlocked:0kB kernel_stack:824kB pagetables:20792kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
 [317889.285822] lowmem_reserve[]: 0 0 62463 62463 62463
 [317889.285825] Node 0 Normal free:108412kB min:43812kB low:107772kB high:171732kB active_anon:41953232kB inactive_anon:14055592kB active_file:14532kB inactive_file:5728kB unevictable:4160kB writepending:560kB present:65011712kB managed:63962700kB mlocked:4160kB kernel_stack:169988kB pagetables:676624kB bounce:0kB free_pcp:240kB local_pcp:0kB free_cma:0kB
 [317889.285828] lowmem_reserve[]: 0 0 0 0 0
 [317889.285831] Node 1 Normal free:356020kB min:45228kB low:111252kB high:177276kB active_anon:24150160kB inactive_anon:16512228kB active_file:7251848kB inactive_file:7886900kB unevictable:161064kB writepending:16280kB present:67108864kB managed:66033216kB mlocked:161064kB kernel_stack:141940kB pagetables:826932kB bounce:0kB free_pcp:284kB local_pcp:0kB free_cma:0kB
 [317889.285834] lowmem_reserve[]: 0 0 0 0 0
 [317889.285837] Node 0 DMA: 1*4kB (U) 3*8kB (U) 1*16kB (U) 0*32kB 2*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15788kB
 [317889.285846] Node 0 DMA32: 1856*4kB (UMEH) 1589*8kB (UMEH) 1128*16kB (UMEH) 524*32kB (UMEH) 410*64kB (UMEH) 193*128kB (UMEH) 54*256kB (UME) 26*512kB (UME) 11*1024kB (UE) 7*2048kB (M) 23*4096kB (M) = 252840kB
 [317889.285857] Node 0 Normal: 4500*4kB (UMH) 1592*8kB (UEH) 1305*16kB (UEH) 1795*32kB (UEH) 3*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 109248kB
 [317889.285866] Node 1 Normal: 6672*4kB (UME) 7542*8kB (UMEH) 5100*16kB (UMEH) 5988*32kB (UEH) 2*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 360368kB
 [317889.285875] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
 [317889.285876] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
 [317889.285877] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
 [317889.285878] Node 1 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
 [317889.285879] 6527613 total pagecache pages
 [317889.285880] 91869 pages in swap cache
 [317889.285881] Swap cache stats: add 891432, delete 800545, find 12461990/12641467
 [317889.285882] Free swap  = 0kB
 [317889.285883] Total swap = 2097148kB
 [317889.285883] 33449823 pages RAM
 [317889.285884] 0 pages HighMem/MovableOnly
 [317889.285884] 547596 pages reserved
 [317889.285885] 0 pages cma reserved
 [317889.285886] 0 pages hwpoisoned
...
Aeon113 commented 4 years ago

Hi!
For efficiency the driver switch to vmalloc only after kmalloc fails. If the RAM on the server isn't suffcient this message will pop out frequently.

To avoid its apperance I suggest:

  1. Tune the cgroup or docker settings to allow the driver use more memory;
  2. Add more RAM to the server;
  3. Switch to an older kernel, since this only happens after kernel 4.2;
  4. Turn down the buffer size of the database. For MySQL/MariaDB using InnoDB it is the "innodb_buffer_pool_size" in the cnf file.

Thank you!