| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Thu, 30 Nov 2017 21:38:40 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: linux-mm@...ck.org
Cc: Andrew Morton <akpm@...ux-foundation.org>,
Michal Hocko <mhocko@...e.com>,
Vlastimil Babka <vbabka@...e.cz>,
Mel Gorman <mgorman@...hsingularity.net>,
Johannes Weiner <hannes@...xchg.org>,
linux-kernel@...r.kernel.org, lkp@...org
Subject: dd: page allocation failure: order:0, mode:0x1080020(GFP_ATOMIC),
nodemask=(null)
Hello,
It looks like a regression in 4.15.0-rc1 -- the test case simply run a
set of parallel dd's and there seems no reason to run into memory problem.
It occurs in 1 out of 4 tests.
The test goes like this:
https://git.kernel.org/pub/scm/linux/kernel/git/wfg/vm-scalability.git/tree/case-lru-file-readtwice
mount -t tmpfs -o size=100% vm-scalability-tmp /tmp/vm-scalability-tmp
truncate -s 67192406016 /tmp/vm-scalability-tmp/vm-scalability.img
mkfs.xfs -q /tmp/vm-scalability-tmp/vm-scalability.img
mount -o loop /tmp/vm-scalability-tmp/vm-scalability.img /tmp/vm-scalability-tmp/vm-scalability
./case-lru-file-readtwice
truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-1 -s 39268272420
truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-2 -s 39268272420
truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-3 -s 39268272420
...
truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-112 -s 39268272420
The test machine is
hostname: lkp-skl-2sp2
model: Skylake
nr_cpu: 112
memory: 64G
[ 35.877083]
[ 35.879974] 2017-11-29 10:02:06 truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-111 -s 39268272420
[ 35.879977]
[ 35.882960] 2017-11-29 10:02:06 truncate /tmp/vm-scalability-tmp/vm-scalability/sparse-lru-file-readtwice-112 -s 39268272420
[ 35.882964]
[ 71.088242] dd: page allocation failure: order:0, mode:0x1080020(GFP_ATOMIC), nodemask=(null)
[ 71.098654] dd cpuset=/ mems_allowed=0-1
[ 71.104460] CPU: 0 PID: 6016 Comm: dd Tainted: G O 4.15.0-rc1 #1
[ 71.113553] Call Trace:
[ 71.117886] <IRQ>
[ 71.121749] dump_stack+0x5c/0x7b:
dump_stack at lib/dump_stack.c:55
[ 71.126785] warn_alloc+0xbe/0x150:
preempt_count at arch/x86/include/asm/preempt.h:23
(inlined by) should_suppress_show_mem at mm/page_alloc.c:3244
(inlined by) warn_alloc_show_mem at mm/page_alloc.c:3254
(inlined by) warn_alloc at mm/page_alloc.c:3293
[ 71.131939] __alloc_pages_slowpath+0xda7/0xdf0:
__alloc_pages_slowpath at mm/page_alloc.c:4151
[ 71.138110] ? xhci_urb_enqueue+0x23d/0x580:
xhci_urb_enqueue at drivers/usb/host/xhci.c:1389
[ 71.143941] __alloc_pages_nodemask+0x269/0x280:
__alloc_pages_nodemask at mm/page_alloc.c:4245
[ 71.150167] page_frag_alloc+0x11c/0x150:
__page_frag_cache_refill at mm/page_alloc.c:4335
(inlined by) page_frag_alloc at mm/page_alloc.c:4364
[ 71.155668] __netdev_alloc_skb+0xa0/0x110:
__netdev_alloc_skb at net/core/skbuff.c:415
[ 71.161386] rx_submit+0x3b/0x2e0:
rx_submit at drivers/net/usb/usbnet.c:488
[ 71.166232] rx_complete+0x196/0x2d0:
rx_complete at drivers/net/usb/usbnet.c:659
[ 71.171354] __usb_hcd_giveback_urb+0x86/0x100:
arch_local_irq_restore at arch/x86/include/asm/paravirt.h:777
(inlined by) __usb_hcd_giveback_urb at drivers/usb/core/hcd.c:1769
[ 71.177281] xhci_giveback_urb_in_irq+0x86/0x100
[ 71.184107] xhci_td_cleanup+0xe7/0x170:
xhci_td_cleanup at drivers/usb/host/xhci-ring.c:1924
[ 71.189457] handle_tx_event+0x297/0x1190:
process_bulk_intr_td at drivers/usb/host/xhci-ring.c:2267
(inlined by) handle_tx_event at drivers/usb/host/xhci-ring.c:2598
[ 71.194905] ? reweight_entity+0x145/0x180:
enqueue_runnable_load_avg at kernel/sched/fair.c:2742
(inlined by) reweight_entity at kernel/sched/fair.c:2810
[ 71.200466] xhci_irq+0x300/0xb80:
xhci_handle_event at drivers/usb/host/xhci-ring.c:2676
(inlined by) xhci_irq at drivers/usb/host/xhci-ring.c:2777
[ 71.205195] ? scheduler_tick+0xb2/0xe0:
rq_last_tick_reset at kernel/sched/sched.h:1643
(inlined by) scheduler_tick at kernel/sched/core.c:3036
[ 71.210407] ? run_timer_softirq+0x73/0x460:
__collect_expired_timers at kernel/time/timer.c:1375
(inlined by) collect_expired_timers at kernel/time/timer.c:1609
(inlined by) __run_timers at kernel/time/timer.c:1656
(inlined by) run_timer_softirq at kernel/time/timer.c:1688
[ 71.215905] __handle_irq_event_percpu+0x3a/0x1a0:
__handle_irq_event_percpu at kernel/irq/handle.c:147
[ 71.221975] handle_irq_event_percpu+0x20/0x50:
handle_irq_event_percpu at kernel/irq/handle.c:189
[ 71.227641] handle_irq_event+0x3d/0x60:
handle_irq_event at kernel/irq/handle.c:206
[ 71.232682] handle_edge_irq+0x71/0x190:
handle_edge_irq at kernel/irq/chip.c:796
[ 71.237715] handle_irq+0xa5/0x100:
handle_irq at arch/x86/kernel/irq_64.c:78
[ 71.242326] do_IRQ+0x41/0xc0:
do_IRQ at arch/x86/kernel/irq.c:241
[ 71.246472] common_interrupt+0x96/0x96:
ret_from_intr at arch/x86/entry/entry_64.S:611
[ 71.251509] </IRQ>
[ 71.254696] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x20:
arch_local_irq_restore at arch/x86/include/asm/paravirt.h:777
(inlined by) __raw_spin_unlock_irqrestore at include/linux/spinlock_api_smp.h:160
(inlined by) _raw_spin_unlock_irqrestore at kernel/locking/spinlock.c:191
[ 71.261306] RSP: 0018:ffffc9000a0f7718 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffd9
[ 71.269926] RAX: 0000000000000001 RBX: ffffea00124bce40 RCX: 0000000000000000
[ 71.278165] RDX: ffffffff811d5b10 RSI: 0000000000000246 RDI: 0000000000000246
[ 71.286380] RBP: ffff8808196b0688 R08: 0000000000000001 R09: 0000000000000016
[ 71.294533] R10: ffff8804676c3258 R11: 0000000000000017 R12: 0000000000000001
[ 71.302666] R13: ffff8808196b0670 R14: 0000000000000246 R15: 0000000000000000
[ 71.310729] ? count_shadow_nodes+0xa0/0xa0:
workingset_update_node at mm/workingset.c:344
[ 71.315862] __remove_mapping+0xe8/0x200:
__remove_mapping at mm/vmscan.c:748
[ 71.320667] shrink_page_list+0x8e5/0xbd0:
shrink_page_list at mm/vmscan.c:1308 (discriminator 1)
[ 71.325599] shrink_inactive_list+0x216/0x550:
spin_lock_irq at include/linux/spinlock.h:340
(inlined by) shrink_inactive_list at mm/vmscan.c:1806
[ 71.330861] shrink_node_memcg+0x37e/0x780:
shrink_list at mm/vmscan.c:2161
(inlined by) shrink_node_memcg at mm/vmscan.c:2424
[ 71.335879] ? shrink_node+0xeb/0x2e0:
shrink_node at mm/vmscan.c:2617
[ 71.340356] shrink_node+0xeb/0x2e0:
shrink_node at mm/vmscan.c:2617
[ 71.344646] do_try_to_free_pages+0xb3/0x310:
shrink_zones at mm/vmscan.c:2743
(inlined by) do_try_to_free_pages at mm/vmscan.c:2860
[ 71.349761] try_to_free_pages+0xf2/0x1c0:
try_to_free_pages at mm/vmscan.c:3066
[ 71.354467] __alloc_pages_slowpath+0x3e2/0xdf0:
__perform_reclaim at mm/page_alloc.c:3625
(inlined by) __alloc_pages_direct_reclaim at mm/page_alloc.c:3646
(inlined by) __alloc_pages_slowpath at mm/page_alloc.c:4045
[ 71.359719] __alloc_pages_nodemask+0x269/0x280:
__alloc_pages_nodemask at mm/page_alloc.c:4245
[ 71.364901] __do_page_cache_readahead+0xfd/0x290:
__do_page_cache_readahead at mm/readahead.c:184
[ 71.370326] ? set_next_entity+0xa1/0x210:
set_next_entity at kernel/sched/fair.c:4165
[ 71.374955] ? current_time+0x18/0x70:
current_kernel_time at include/linux/timekeeping32.h:17
(inlined by) current_time at fs/inode.c:2118
[ 71.379284] ? ondemand_readahead+0x117/0x2c0:
ra_submit at mm/internal.h:66
(inlined by) ondemand_readahead at mm/readahead.c:478
[ 71.384303] ondemand_readahead+0x117/0x2c0:
ra_submit at mm/internal.h:66
(inlined by) ondemand_readahead at mm/readahead.c:478
[ 71.389205] generic_file_read_iter+0x731/0x980:
generic_file_buffered_read at mm/filemap.c:2103
(inlined by) generic_file_read_iter at mm/filemap.c:2365
[ 71.394425] ? _cond_resched+0xf/0x30:
_cond_resched at kernel/sched/core.c:4849
[ 71.398789] ? _cond_resched+0x19/0x30:
_cond_resched at kernel/sched/core.c:4855
[ 71.403210] ? down_read+0x21/0x40:
__down_read at arch/x86/include/asm/rwsem.h:83
(inlined by) down_read at kernel/locking/rwsem.c:26
[ 71.407317] xfs_file_buffered_aio_read+0x53/0xf0 [xfs]
[ 71.413255] xfs_file_read_iter+0x64/0xc0 [xfs]
[ 71.418424] __vfs_read+0xd2/0x140:
new_sync_read at fs/read_write.c:402
(inlined by) __vfs_read at fs/read_write.c:413
[ 71.422504] vfs_read+0x9b/0x140:
vfs_read at fs/read_write.c:448
[ 71.426392] SyS_read+0x42/0x90
[ 71.430203] entry_SYSCALL_64_fastpath+0x1a/0x7d:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:210
[ 71.435466] RIP: 0033:0x7ff145cae060
[ 71.439728] RSP: 002b:00007ffee3f33b98 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 71.447993] RAX: ffffffffffffffda RBX: 00000000000b1bf2 RCX: 00007ff145cae060
[ 71.455801] RDX: 0000000000001000 RSI: 0000000000ff4000 RDI: 0000000000000000
[ 71.463637] RBP: 0000000000001000 R08: 0000000000000003 R09: 0000000000003011
[ 71.471442] R10: 000000000000086d R11: 0000000000000246 R12: 0000000000ff4000
[ 71.479267] R13: 0000000000000000 R14: 0000000000ff4000 R15: 0000000000000000
[ 78.848629] dd: page allocation failure: order:0, mode:0x1080020(GFP_ATOMIC), nodemask=(null)
[ 78.857841] dd cpuset=/ mems_allowed=0-1
[ 78.862502] CPU: 0 PID: 6131 Comm: dd Tainted: G O 4.15.0-rc1 #1
[ 78.870437] Call Trace:
[ 78.873610] <IRQ>
[ 78.876342] dump_stack+0x5c/0x7b:
dump_stack at lib/dump_stack.c:55
[ 78.880414] warn_alloc+0xbe/0x150:
preempt_count at arch/x86/include/asm/preempt.h:23
(inlined by) should_suppress_show_mem at mm/page_alloc.c:3244
(inlined by) warn_alloc_show_mem at mm/page_alloc.c:3254
(inlined by) warn_alloc at mm/page_alloc.c:3293
[ 78.884550] __alloc_pages_slowpath+0xda7/0xdf0:
__alloc_pages_slowpath at mm/page_alloc.c:4151
[ 78.889822] ? xhci_urb_enqueue+0x23d/0x580:
xhci_urb_enqueue at drivers/usb/host/xhci.c:1389
[ 78.894713] __alloc_pages_nodemask+0x269/0x280:
__alloc_pages_nodemask at mm/page_alloc.c:4245
[ 78.899891] page_frag_alloc+0x11c/0x150:
__page_frag_cache_refill at mm/page_alloc.c:4335
(inlined by) page_frag_alloc at mm/page_alloc.c:4364
[ 78.904471] __netdev_alloc_skb+0xa0/0x110:
__netdev_alloc_skb at net/core/skbuff.c:415
[ 78.909277] rx_submit+0x3b/0x2e0:
rx_submit at drivers/net/usb/usbnet.c:488
[ 78.913256] rx_complete+0x196/0x2d0:
rx_complete at drivers/net/usb/usbnet.c:659
[ 78.917560] __usb_hcd_giveback_urb+0x86/0x100:
arch_local_irq_restore at arch/x86/include/asm/paravirt.h:777
(inlined by) __usb_hcd_giveback_urb at drivers/usb/core/hcd.c:1769
[ 78.922681] xhci_giveback_urb_in_irq+0x86/0x100
[ 78.928769] ? ip_rcv+0x261/0x390:
NF_HOOK at include/linux/netfilter.h:250
(inlined by) ip_rcv at net/ipv4/ip_input.c:493
[ 78.932739] xhci_td_cleanup+0xe7/0x170:
xhci_td_cleanup at drivers/usb/host/xhci-ring.c:1924
[ 78.937308] handle_tx_event+0x297/0x1190:
process_bulk_intr_td at drivers/usb/host/xhci-ring.c:2267
(inlined by) handle_tx_event at drivers/usb/host/xhci-ring.c:2598
[ 78.941990] xhci_irq+0x300/0xb80:
xhci_handle_event at drivers/usb/host/xhci-ring.c:2676
(inlined by) xhci_irq at drivers/usb/host/xhci-ring.c:2777
[ 78.945968] ? pciehp_isr+0x46/0x320
[ 78.950870] __handle_irq_event_percpu+0x3a/0x1a0:
__handle_irq_event_percpu at kernel/irq/handle.c:147
[ 78.956311] handle_irq_event_percpu+0x20/0x50:
handle_irq_event_percpu at kernel/irq/handle.c:189
[ 78.961466] handle_irq_event+0x3d/0x60:
handle_irq_event at kernel/irq/handle.c:206
[ 78.965962] handle_edge_irq+0x71/0x190:
handle_edge_irq at kernel/irq/chip.c:796
[ 78.970480] handle_irq+0xa5/0x100:
handle_irq at arch/x86/kernel/irq_64.c:78
[ 78.974565] do_IRQ+0x41/0xc0:
do_IRQ at arch/x86/kernel/irq.c:241
[ 78.978206] ? pagevec_move_tail_fn+0x350/0x350:
__activate_page at mm/swap.c:275
[ 78.983412] common_interrupt+0x96/0x96:
ret_from_intr at arch/x86/entry/entry_64.S:611
[ 78.987887] </IRQ>
[ 78.990638] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x20:
arch_local_irq_restore at arch/x86/include/asm/paravirt.h:777
(inlined by) __raw_spin_unlock_irqrestore at include/linux/spinlock_api_smp.h:160
(inlined by) _raw_spin_unlock_irqrestore at kernel/locking/spinlock.c:191
[ 78.996915] RSP: 0018:ffffc9000a347cf8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffd9
[ 79.005196] RAX: ffff881035e00008 RBX: 000000000000000e RCX: 0000000000000001
[ 79.013024] RDX: ffffea003eb91ba0 RSI: 0000000000000246 RDI: 0000000000000246
[ 79.020886] RBP: ffff88085d8166a0 R08: ffffea003eb91ba0 R09: 00000000005eb501
[ 79.028770] R10: ffff88107ffcd000 R11: ffffffffffffffff R12: 0000000000000246
[ 79.036607] R13: ffffffff811b33b0 R14: ffff88107ffcd000 R15: ffffea003eb91bc0
[ 79.044528] ? pagevec_move_tail_fn+0x350/0x350:
__activate_page at mm/swap.c:275
[ 79.049871] pagevec_lru_move_fn+0xab/0xd0:
spin_unlock_irqrestore at include/linux/spinlock.h:370
(inlined by) pagevec_lru_move_fn at mm/swap.c:212
[ 79.054723] activate_page+0xbb/0xd0:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) activate_page at mm/swap.c:314
[ 79.059035] mark_page_accessed+0x7a/0x150:
__read_once_size at include/linux/compiler.h:183
(inlined by) compound_head at include/linux/page-flags.h:147
(inlined by) ClearPageReferenced at include/linux/page-flags.h:268
(inlined by) mark_page_accessed at mm/swap.c:392
[ 79.063876] generic_file_read_iter+0x42d/0x980:
generic_file_buffered_read at mm/filemap.c:2188
(inlined by) generic_file_read_iter at mm/filemap.c:2365
[ 79.069112] ? _cond_resched+0x19/0x30:
_cond_resched at kernel/sched/core.c:4855
[ 79.073611] ? _cond_resched+0x19/0x30:
_cond_resched at kernel/sched/core.c:4855
[ 79.078092] ? down_read+0x21/0x40:
__down_read at arch/x86/include/asm/rwsem.h:83
(inlined by) down_read at kernel/locking/rwsem.c:26
[ 79.082287] xfs_file_buffered_aio_read+0x53/0xf0 [xfs]
[ 79.088284] xfs_file_read_iter+0x64/0xc0 [xfs]
[ 79.093515] __vfs_read+0xd2/0x140:
new_sync_read at fs/read_write.c:402
(inlined by) __vfs_read at fs/read_write.c:413
[ 79.097639] vfs_read+0x9b/0x140:
vfs_read at fs/read_write.c:448
[ 79.101563] SyS_read+0x42/0x90
[ 79.105374] entry_SYSCALL_64_fastpath+0x1a/0x7d:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:210
[ 79.110692] RIP: 0033:0x7f2611b8c060
[ 79.114910] RSP: 002b:00007ffd6360fda8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 79.123181] RAX: ffffffffffffffda RBX: 00000000000c4a1e RCX: 00007f2611b8c060
[ 79.131037] RDX: 0000000000001000 RSI: 00000000009a4000 RDI: 0000000000000000
[ 79.138858] RBP: 0000000000001000 R08: 0000000000000003 R09: 0000000000003011
[ 79.146708] R10: 000000000000086d R11: 0000000000000246 R12: 00000000009a4000
[ 79.154579] R13: 0000000000000000 R14: 00000000009a4000 R15: 0000000000000000
[ 85.364572] Terminated
[ 85.364576]
[ 85.806857] /usr/bin/curl -sSf http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/scheduled/lkp-skl-2sp2/vm-scalability-300s-lru-file-readtwice-performance-debian-x86_64-2016-08-31.cgz-CYCLIC_HEAD-20171128-58530-nmcjkk-0.yaml&job_state=post_run -o /dev/null
Thanks,
Fengguang
View attachment "dmesg-lkp-skl-2sp2:20171129101019:x86_64-rhel-7.2:gcc-7:4.15.0-rc1:1" of type "text/plain" (221354 bytes)
View attachment ".config" of type "text/plain" (164489 bytes)
Powered by blists - more mailing lists