Date:   Thu, 19 Apr 2018 10:36:39 +0800
From:   Fengguang Wu <fengguang.wu@...el.com>
To:     Alexander Shishkin <alexander.shishkin@...ux.intel.com>
Cc:     linux-kernel@...r.kernel.org, lkp@...org
Subject: [dummy_stm_init] swapper/0: page allocation failure: order:9,
 mode:0x14040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)

Hi Alexander,

FYI this happens in mainline kernel 4.17.0-rc1.
It dates back to at least v4.15.

It occurs in 4 out of 4 boots. Here KVM has 1G memory.

This high order allocation caused lots of noises in our boot testing.
We could disable this device in our tests, but it would be great if
there are better ways out.

[   75.039408]       Product name: fake-design-for-testing
[   75.040995] fmc fake-design-for-testing-f001: Driver has no ID: matches all
[   75.042509] fmc_trivial: probe of fake-design-for-testing-f001 failed with error -95
[   75.044323] fmc fake-design-for-testing-f001: Driver has no ID: matches all
[   75.045644] fmc_chardev fake-design-for-testing-f001: Created misc device "fake-design-for-testing-f001"
[   75.061570] swapper/0: page allocation failure: order:9, mode:0x14040c0(GFP_KERNEL|__GFP_COMP), nodemask=(null)
[   75.063053] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.17.0-rc1 #262
[   75.063338] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   75.063338] Call Trace:
[   75.063338]  dump_stack+0x71/0xab:
						dump_stack at lib/dump_stack.c:115
[   75.063338]  warn_alloc+0x180/0x280:
						warn_alloc_show_mem at mm/page_alloc.c:3398
						 (inlined by) warn_alloc at mm/page_alloc.c:3437
[   75.063338]  ? zone_watermark_ok_safe+0x260/0x260:
						warn_alloc at mm/page_alloc.c:3417
[   75.063338]  ? __zone_watermark_ok+0x260/0x260:
						get_page_from_freelist at mm/page_alloc.c:3262
[   75.063338]  ? _cond_resched+0x14/0x30:
						_cond_resched at kernel/sched/core.c:4982
[   75.063338]  __alloc_pages_nodemask+0x1068/0x19a0:
						__alloc_pages_slowpath at mm/page_alloc.c:4293
						 (inlined by) __alloc_pages_nodemask at mm/page_alloc.c:4384
[   75.063338]  ? gfp_pfmemalloc_allowed+0x150/0x150:
						__alloc_pages_nodemask at mm/page_alloc.c:4350
[   75.063338]  ? sched_clock_cpu+0x14f/0x180:
						sched_clock_cpu at kernel/sched/clock.c:362
[   75.063338]  cache_alloc_refill+0x27e/0x770:
						kmem_getpages at mm/slab.c:1412
						 (inlined by) cache_grow_begin at mm/slab.c:2678
						 (inlined by) cache_alloc_refill at mm/slab.c:3045
[   75.063338]  ? lock_acquire+0xd0/0x190:
						get_current at arch/x86/include/asm/current.h:15
						 (inlined by) lock_acquire at kernel/locking/lockdep.c:3922
[   75.063338]  __kmalloc+0x14b/0x180:
						____cache_alloc at mm/slab.c:3127
						 (inlined by) __do_cache_alloc at mm/slab.c:3366
						 (inlined by) slab_alloc at mm/slab.c:3384
						 (inlined by) __do_kmalloc at mm/slab.c:3716
						 (inlined by) __kmalloc at mm/slab.c:3727
[   75.063338]  stm_register_device+0xf3/0x5c0:
						stm_register_device at drivers/hwtracing/stm/core.c:695
[   75.063338]  ? stp_policy_node_put+0x10/0x10:
						dummy_stm_packet at drivers/hwtracing/stm/dummy_stm.c:33
[   75.063338]  dummy_stm_init+0x175/0x2b0:
						dummy_stm_init at drivers/hwtracing/stm/dummy_stm.c:93
[   75.063338]  ? intel_th_pti_lpp_init+0x37/0x37:
						stm_core_init at drivers/hwtracing/stm/core.c:1149
[   75.063338]  ? dummy_stm_exit+0x80/0x80:
						dummy_stm_init at drivers/hwtracing/stm/dummy_stm.c:70
[   75.063338]  do_one_initcall+0xd8/0x1e0:
						do_trace_initcall_finish at init/main.c:867
						 (inlined by) do_one_initcall at init/main.c:884
[   75.063338]  ? start_kernel+0x9c2/0x9c2:
						do_one_initcall at init/main.c:874
[   75.063338]  ? __wake_up_common+0x580/0x580:
						__wake_up_common_lock at kernel/sched/wait.c:109
[   75.063338]  ? lock_downgrade+0x5e0/0x5e0:
						lock_release at kernel/locking/lockdep.c:3929
[   75.063338]  kernel_init_freeable+0x2b6/0x348:
						do_initcall_level at init/main.c:951
						 (inlined by) do_initcalls at init/main.c:959
						 (inlined by) do_basic_setup at init/main.c:977
						 (inlined by) kernel_init_freeable at init/main.c:1127
[   75.063338]  ? rest_init+0x170/0x170:
						kernel_init at init/main.c:1050
[   75.063338]  kernel_init+0xa/0x110:
						kernel_init at init/main.c:1055
[   75.063338]  ? rest_init+0x170/0x170:
						kernel_init at init/main.c:1050
[   75.063338]  ret_from_fork+0x1f/0x30:
						ret_from_fork at arch/x86/entry/entry_64.S:418
[   75.089849] Mem-Info:
[   75.090370] active_anon:0 inactive_anon:0 isolated_anon:0
[   75.090370]  active_file:0 inactive_file:0 isolated_file:0
[   75.090370]  unevictable:123532 dirty:0 writeback:0 unstable:0
[   75.090370]  slab_reclaimable:6653 slab_unreclaimable:10019
[   75.090370]  mapped:0 shmem:0 pagetables:0 bounce:0
[   75.090370]  free:10580 free_pcp:0 free_cma:0
[   75.094750] Node 0 active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:494128kB isolated(anon):0kB isolated(file):0kB mapped:0kB dirty:0kB writeback:0kB shmem:0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[   75.097690] DMA free:12232kB min:80kB low:100kB high:120kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:1180kB writepending:0kB present:15992kB managed:15904kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[   75.101009] lowmem_reserve[]: 0 588 588 588

Attached the full dmesg, kconfig and reproduce scripts.

Thanks,
Fengguang

View attachment "dmesg-vm-lkp-hsw01-1G-9:20180417231439:x86_64-randconfig-s5-04172210:4.17.0-rc1:262" of type "text/plain" (131828 bytes)

View attachment ".config" of type "text/plain" (120667 bytes)

View attachment "job-script" of type "text/plain" (3963 bytes)

View attachment "reproduce-vm-lkp-hsw01-1G-9:20180417231439:x86_64-randconfig-s5-04172210:4.17.0-rc1:262" of type "text/plain" (2103 bytes)

Powered by blists - more mailing lists