Re: [LKP] [rcu] kernel BUG at include/linux/pagemap.h:149!
by Frederic Weisbecker
On Fri, Sep 11, 2015 at 10:19:47AM +0800, Boqun Feng wrote:
> Subject: [PATCH 01/27] rcu: Don't disable preemption for Tiny and Tree RCU
> readers
>
> Because preempt_disable() maps to barrier() for non-debug builds,
> it forces the compiler to spill and reload registers. Because Tree
> RCU and Tiny RCU now only appear in CONFIG_PREEMPT=n builds, these
> barrier() instances generate needless extra code for each instance of
> rcu_read_lock() and rcu_read_unlock(). This extra code slows down Tree
> RCU and bloats Tiny RCU.
>
> This commit therefore removes the preempt_disable() and preempt_enable()
> from the non-preemptible implementations of __rcu_read_lock() and
> __rcu_read_unlock(), respectively.
>
> For debug purposes, preempt_disable() and preempt_enable() are still
> kept if CONFIG_PREEMPT_COUNT=y, which makes the detection of sleeping
> inside atomic sections still work in non-preemptible kernels.
>
> Signed-off-by: Boqun Feng <boqun.feng(a)gmail.com>
> Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
> ---
> include/linux/rcupdate.h | 6 ++++--
> include/linux/rcutiny.h | 1 +
> kernel/rcu/tree.c | 9 +++++++++
> 3 files changed, 14 insertions(+), 2 deletions(-)
>
> diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h
> index d63bb77..6c3cece 100644
> --- a/include/linux/rcupdate.h
> +++ b/include/linux/rcupdate.h
> @@ -297,12 +297,14 @@ void synchronize_rcu(void);
>
> static inline void __rcu_read_lock(void)
> {
> - preempt_disable();
> + if (IS_ENABLED(CONFIG_PREEMPT_COUNT))
> + preempt_disable();
preempt_disable() is a no-op when !CONFIG_PREEMPT_COUNT, right?
Or rather it's a barrier(), which is anyway implied by rcu_read_lock().
So perhaps we can get rid of the IS_ENABLED() check?
1 year, 10 months
[test_parman_move] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper:1]
by Fengguang Wu
Hello,
FYI this happens in mainline kernel 4.15.0-rc1.
It at least dates back to v4.12 .
It occurs in 2 out of 2 boots.
[ 95.347718] test passed
[ 95.359028] test_printf: all 260 tests passed
[ 96.656859] test_bitmap: test 13: input is '0-2047:128/256' OK, Time: 3332
[ 96.770961] test_bitmap: all 460506 tests passed
[ 96.783469] test_uuid: all 18 tests passed
[ 124.230111] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper:1]
[ 124.230111] CPU: 0 PID: 1 Comm: swapper Not tainted 4.15.0-rc1 #360
[ 124.230111] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 124.230111] task: d3430000 task.stack: d342c000
[ 124.230111] EIP: test_parman_move+0xe/0xb0:
test_parman_move at lib/test_parman.c:119
[ 124.230111] EFLAGS: 00200212 CPU: 0
[ 124.230111] EAX: d0c00000 EBX: 00000004 ECX: 00000930 EDX: 0000090c
[ 124.230111] ESI: d0740324 EDI: d359f680 EBP: d342dec4 ESP: d342debc
[ 124.230111] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 124.230111] CR0: 80050033 CR2: 00000000 CR3: 02b2b000 CR4: 000006b0
[ 124.230111] Call Trace:
[ 124.230111] parman_lsort_item_add+0x9d/0x190:
__list_del_entry at include/linux/list.h:117
(inlined by) list_move_tail at include/linux/list.h:182
(inlined by) parman_prio_shift_down at lib/parman.c:144
(inlined by) parman_lsort_item_add at lib/parman.c:200
[ 124.230111] parman_item_add+0x9/0x10:
parman_item_add at lib/parman.c:356
[ 124.230111] test_parman_init+0x358/0x3b5:
test_parman_run at lib/test_parman.c:284
(inlined by) test_parman_lsort at lib/test_parman.c:369
(inlined by) test_parman_init at lib/test_parman.c:383
[ 124.230111] ? test_uuid_init+0x1a9/0x1a9:
test_parman_init at lib/test_parman.c:382
[ 124.230111] do_one_initcall+0x7c/0x10e:
do_one_initcall at init/main.c:826
[ 124.230111] ? kernel_init_freeable+0xc3/0x15b:
do_initcall_level at init/main.c:891
(inlined by) do_initcalls at init/main.c:900
(inlined by) do_basic_setup at init/main.c:918
(inlined by) kernel_init_freeable at init/main.c:1066
[ 124.230111] kernel_init_freeable+0xe3/0x15b:
do_initcall_level at init/main.c:892
(inlined by) do_initcalls at init/main.c:900
(inlined by) do_basic_setup at init/main.c:918
(inlined by) kernel_init_freeable at init/main.c:1066
[ 124.230111] ? rest_init+0xc0/0xc0:
kernel_init at init/main.c:990
[ 124.230111] kernel_init+0xb/0xf0:
kernel_init at init/main.c:995
[ 124.230111] ? schedule_tail_wrapper+0x9/0xc:
schedule_tail_wrapper at arch/x86/entry/entry_32.S:267
[ 124.230111] ret_from_fork+0x19/0x24:
ret_from_fork at arch/x86/entry/entry_32.S:299
[ 124.230111] Code: e8 48 5f c2 00 5d 85 c0 0f 94 c0 0f b6 c0 c3 90 90 90 90 90 90 90 90 90 90 90 90 90 90 55 89 e5 57 53 8b 5d 08 8b 40 04 c1 e3 02 <8d> 3c 90 89 fa 8d 04 88 89 d9 e8 a3 be c2 00 83 fb 08 89 da 73
[ 124.230111] Kernel panic - not syncing: softlockup: hung tasks
[ 124.230111] CPU: 0 PID: 1 Comm: swapper Tainted: G L 4.15.0-rc1 #360
[ 124.230111] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 124.230111] Call Trace:
[ 124.230111] dump_stack+0x16/0x19:
dump_stack at lib/dump_stack.c:64
[ 124.230111] panic+0x86/0x1bd:
panic at kernel/panic.c:194
[ 124.230111] watchdog_timer_fn+0x1e7/0x1f0:
watchdog_timer_fn at kernel/watchdog.c:443
[ 124.230111] ? watchdog+0x20/0x20:
watchdog_timer_fn at kernel/watchdog.c:340
[ 124.230111] hrtimer_run_queues+0xf3/0x1d0:
__run_hrtimer at kernel/time/hrtimer.c:1211
(inlined by) __hrtimer_run_queues at kernel/time/hrtimer.c:1275
(inlined by) hrtimer_run_queues at kernel/time/hrtimer.c:1414
[ 124.230111] run_local_timers+0x8/0x40:
run_local_timers at kernel/time/timer.c:1700
[ 124.230111] update_process_times+0x22/0x50:
update_process_times at kernel/time/timer.c:1630
[ 124.230111] tick_nohz_handler+0x66/0x100:
tick_nohz_handler at kernel/time/tick-sched.c:1068
[ 124.230111] smp_apic_timer_interrupt+0x40/0x80:
exiting_irq at arch/x86/include/asm/apic.h:540
(inlined by) smp_apic_timer_interrupt at arch/x86/kernel/apic/apic.c:1052
[ 124.230111] ? irq_exit+0x2f/0xb0:
tick_irq_exit at kernel/softirq.c:385
(inlined by) irq_exit at kernel/softirq.c:407
[ 124.230111] apic_timer_interrupt+0x35/0x3c:
apic_timer_interrupt at arch/x86/include/asm/entry_arch.h:36
[ 124.230111] EIP: test_parman_move+0xe/0xb0:
test_parman_move at lib/test_parman.c:119
[ 124.230111] EFLAGS: 00200212 CPU: 0
[ 124.230111] EAX: d0c00000 EBX: 00000004 ECX: 00000930 EDX: 0000090c
[ 124.230111] ESI: d0740324 EDI: d359f680 EBP: d342dec4 ESP: d342debc
[ 124.230111] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 124.230111] parman_lsort_item_add+0x9d/0x190:
__list_del_entry at include/linux/list.h:117
(inlined by) list_move_tail at include/linux/list.h:182
(inlined by) parman_prio_shift_down at lib/parman.c:144
(inlined by) parman_lsort_item_add at lib/parman.c:200
[ 124.230111] parman_item_add+0x9/0x10:
parman_item_add at lib/parman.c:356
[ 124.230111] test_parman_init+0x358/0x3b5:
test_parman_run at lib/test_parman.c:284
(inlined by) test_parman_lsort at lib/test_parman.c:369
(inlined by) test_parman_init at lib/test_parman.c:383
[ 124.230111] ? test_uuid_init+0x1a9/0x1a9:
test_parman_init at lib/test_parman.c:382
[ 124.230111] do_one_initcall+0x7c/0x10e:
do_one_initcall at init/main.c:826
[ 124.230111] ? kernel_init_freeable+0xc3/0x15b:
do_initcall_level at init/main.c:891
(inlined by) do_initcalls at init/main.c:900
(inlined by) do_basic_setup at init/main.c:918
(inlined by) kernel_init_freeable at init/main.c:1066
[ 124.230111] kernel_init_freeable+0xe3/0x15b:
do_initcall_level at init/main.c:892
(inlined by) do_initcalls at init/main.c:900
(inlined by) do_basic_setup at init/main.c:918
(inlined by) kernel_init_freeable at init/main.c:1066
[ 124.230111] ? rest_init+0xc0/0xc0:
kernel_init at init/main.c:990
[ 124.230111] kernel_init+0xb/0xf0:
kernel_init at init/main.c:995
[ 124.230111] ? schedule_tail_wrapper+0x9/0xc:
schedule_tail_wrapper at arch/x86/entry/entry_32.S:267
[ 124.230111] ret_from_fork+0x19/0x24:
ret_from_fork at arch/x86/entry/entry_32.S:299
[ 124.230111] Kernel Offset: disabled
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
2 years, 12 months
BUG: KASAN: slab-out-of-bounds in perf_callchain_user+0x494/0x530
by Fengguang Wu
Hello,
FYI this happens in mainline kernel 4.15.0-rc1.
It looks like a new regression and hard to bisect.
It occurs in 1 out of 57 boots.
[ 10.009610] chown (367) used greatest stack depth: 26944 bytes left
Kernel tests: Boot OK!
[ 30.357729] trinity-main uses obsolete (PF_INET,SOCK_PACKET)
[ 31.301433] sock: process `trinity-main' is using obsolete setsockopt SO_BSDCOMPAT
[ 31.310289] ==================================================================
[ 31.311490] BUG: KASAN: slab-out-of-bounds in perf_callchain_user+0x494/0x530:
perf_callchain_store at include/linux/perf_event.h:1128
(inlined by) perf_callchain_user at arch/x86/events/core.c:2485
[ 31.312659] Write of size 8 at addr ffff880011101300 by task trinity-main/518
[ 31.313842]
[ 31.314110] CPU: 0 PID: 518 Comm: trinity-main Not tainted 4.15.0-rc1 #138
[ 31.315231] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 31.316589] Call Trace:
[ 31.317012] ? dump_stack+0x7d/0xb4:
dump_stack at lib/dump_stack.c:55
[ 31.317599] ? print_address_description+0x7c/0x21c:
print_address_description at mm/kasan/report.c:253
[ 31.318407] ? perf_callchain_user+0x494/0x530:
perf_callchain_store at include/linux/perf_event.h:1128
(inlined by) perf_callchain_user at arch/x86/events/core.c:2485
[ 31.319142] ? kasan_report+0x225/0x24b:
kasan_report_error at mm/kasan/report.c:352
(inlined by) kasan_report at mm/kasan/report.c:409
[ 31.319790] ? perf_callchain_user+0x494/0x530:
perf_callchain_store at include/linux/perf_event.h:1128
(inlined by) perf_callchain_user at arch/x86/events/core.c:2485
[ 31.320523] ? perf_callchain_kernel+0x20d/0x248:
perf_callchain_kernel at arch/x86/events/core.c:2350 (discriminator 1)
[ 31.321300] ? perf_callchain_kernel+0x248/0x248:
perf_callchain_user at arch/x86/events/core.c:2443
[ 31.322063] ? arch_perf_update_userpage+0x17d/0x17d:
perf_callchain_kernel at arch/x86/events/core.c:2338
[ 31.322887] ? get_perf_callchain+0x2e4/0x356:
set_fs at arch/x86/include/asm/uaccess.h:32
(inlined by) get_perf_callchain at kernel/events/callchain.c:243
[ 31.323606] ? put_callchain_buffers+0x42/0x42:
get_perf_callchain at kernel/events/callchain.c:199
[ 31.324346] ? irq_exit+0x86/0xa7:
irq_exit at kernel/softirq.c:409
[ 31.324907] ? perf_callchain+0xbb/0xc8:
perf_callchain at kernel/events/callchain.c:193
[ 31.325541] ? schedule+0x29/0x42:
constant_test_bit at arch/x86/include/asm/bitops.h:325 (discriminator 1)
(inlined by) test_ti_thread_flag at include/linux/thread_info.h:79 (discriminator 1)
(inlined by) need_resched at include/linux/sched.h:1620 (discriminator 1)
(inlined by) schedule at kernel/sched/core.c:3436 (discriminator 1)
[ 31.326100] ? perf_prepare_sample+0x12b/0x832:
perf_prepare_sample at kernel/events/core.c:6004
[ 31.326841] ? is_bpf_text_address+0xc/0x1a:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __rcu_read_unlock at include/linux/rcupdate.h:89
(inlined by) rcu_read_unlock at include/linux/rcupdate.h:686
(inlined by) is_bpf_text_address at kernel/bpf/core.c:466
[ 31.327531] ? perf_output_sample+0x9e7/0x9e7:
perf_prepare_sample at kernel/events/core.c:5987
[ 31.328251] ? __kernel_text_address+0x9/0x2b:
__kernel_text_address at kernel/extable.c:107
[ 31.328972] ? unwind_next_frame+0x7a/0x101:
unwind_next_frame at arch/x86/kernel/unwind_guess.c:38 (discriminator 2)
[ 31.329662] ? unwind_get_return_address+0x6f/0x99:
unwind_get_return_address at arch/x86/kernel/unwind_guess.c:15 (discriminator 2)
[ 31.330452] ? __unwind_start+0xb2/0xb2:
unwind_get_return_address at arch/x86/kernel/unwind_guess.c:9
[ 31.331094] ? perf_event_output_backward+0x78/0xe1:
__perf_event_output at kernel/events/core.c:6122
(inlined by) perf_event_output_backward at kernel/events/core.c:6146
[ 31.331900] ? perf_event_output_forward+0xe1/0xe1:
perf_event_output_backward at kernel/events/core.c:6145
[ 31.332691] ? memcmp+0x26/0x46:
memcmp at lib/string.c:861
[ 31.333216] ? depot_save_stack+0x16b/0x3fd:
find_stack at lib/stackdepot.c:175
(inlined by) depot_save_stack at lib/stackdepot.c:225
[ 31.333917] ? kasan_kmalloc+0x120/0x143:
set_track at mm/kasan/kasan.c:459
(inlined by) kasan_kmalloc at mm/kasan/kasan.c:551
[ 31.334562] ? __perf_event_account_interrupt+0x9f/0x10d:
__perf_event_account_interrupt at kernel/events/core.c:7320
[ 31.335437] ? __perf_event_overflow+0xbd/0x12f:
perf_event_fasync at kernel/events/core.c:5414 (discriminator 1)
(inlined by) __perf_event_overflow at kernel/events/core.c:7373 (discriminator 1)
[ 31.336182] ? perf_swevent_overflow+0x49/0x61:
perf_swevent_overflow at kernel/events/core.c:7447
[ 31.336923] ? ___perf_sw_event+0x1b9/0x1f1:
do_perf_sw_event at kernel/events/core.c:7588
(inlined by) ___perf_sw_event at kernel/events/core.c:7619
[ 31.337614] ? perf_pending_event+0x6e/0x6e:
___perf_sw_event at kernel/events/core.c:7612
[ 31.338309] ? address_space_init_once+0xbd/0xc8:
address_space_init_once at fs/inode.c:356
[ 31.339070] ? __list_add_valid+0x40/0x87:
__list_add_valid at lib/list_debug.c:26 (discriminator 8)
[ 31.339743] ? cache_grow_end+0xd3/0x140:
__list_add at include/linux/list.h:60
(inlined by) list_add at include/linux/list.h:79
(inlined by) fixup_slab_list at mm/slab.c:2840
(inlined by) cache_grow_end at mm/slab.c:2732
[ 31.340391] ? do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.341085] ? _raw_spin_unlock+0x5/0xd:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __raw_spin_unlock at include/linux/spinlock_api_smp.h:152
(inlined by) _raw_spin_unlock at kernel/locking/spinlock.c:183
[ 31.341728] ? schedule+0x29/0x42:
constant_test_bit at arch/x86/include/asm/bitops.h:325 (discriminator 1)
(inlined by) test_ti_thread_flag at include/linux/thread_info.h:79 (discriminator 1)
(inlined by) need_resched at include/linux/sched.h:1620 (discriminator 1)
(inlined by) schedule at kernel/sched/core.c:3436 (discriminator 1)
[ 31.342282] ? sk_prot_alloc+0x35/0xff
[ 31.343007] ? init_timer_key+0x1d/0xe9:
__read_once_size at include/linux/compiler.h:183
(inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_timer_init at include/trace/events/timer.h:33
(inlined by) debug_init at kernel/time/timer.c:741
(inlined by) init_timer_key at kernel/time/timer.c:789
[ 31.343642] ? sock_init_data+0x42/0x39e:
sock_init_data at net/core/sock.c:2690
[ 31.344302] ? SyS_socket+0x72/0xf5
[ 31.344884] ? rb_next+0x66/0x75:
rb_next at lib/rbtree.c:553 (discriminator 1)
[ 31.345426] ? __update_load_avg_cfs_rq+0x20/0x29e
[ 31.346312] ? set_next_entity+0x91c/0x92f:
set_next_entity at kernel/sched/fair.c:4182
[ 31.346994] ? pick_next_entity+0x143/0x151:
pick_next_entity at kernel/sched/fair.c:4244
[ 31.347687] ? __list_add_valid+0x40/0x87:
__list_add_valid at lib/list_debug.c:26 (discriminator 8)
[ 31.348354] ? pick_next_task_fair+0x31f/0x7a4:
__write_once_size at include/linux/compiler.h:212
(inlined by) __list_add at include/linux/list.h:66
(inlined by) list_add at include/linux/list.h:79
(inlined by) list_move at include/linux/list.h:171
(inlined by) pick_next_task_fair at kernel/sched/fair.c:6682
[ 31.349093] ? __mutex_init+0x58/0x73:
__write_once_size at include/linux/compiler.h:211
(inlined by) atomic_set at arch/x86/include/asm/atomic.h:39
(inlined by) osq_lock_init at include/linux/osq_lock.h:30
(inlined by) __mutex_init at kernel/locking/mutex.c:45
[ 31.349710] ? load_balance+0xdab/0xdab:
pick_next_task_fair at kernel/sched/fair.c:6576
[ 31.350344] ? alloc_file+0x142/0x156:
alloc_file at fs/file_table.c:179
[ 31.350954] ? __schedule+0x933/0x967:
perf_sw_event_sched at include/linux/perf_event.h:1043
(inlined by) perf_event_task_sched_out at include/linux/perf_event.h:1081
(inlined by) prepare_task_switch at kernel/sched/core.c:2592
(inlined by) context_switch at kernel/sched/core.c:2764
(inlined by) __schedule at kernel/sched/core.c:3375
[ 31.351560] ? __schedule+0x933/0x967:
perf_sw_event_sched at include/linux/perf_event.h:1043
(inlined by) perf_event_task_sched_out at include/linux/perf_event.h:1081
(inlined by) prepare_task_switch at kernel/sched/core.c:2592
(inlined by) context_switch at kernel/sched/core.c:2764
(inlined by) __schedule at kernel/sched/core.c:3375
[ 31.352170] ? sock_init_data+0x38b/0x39e:
__write_once_size at include/linux/compiler.h:211
(inlined by) atomic_set at arch/x86/include/asm/atomic.h:39
(inlined by) sock_init_data at net/core/sock.c:2755
[ 31.352847] ? schedule+0x29/0x42:
constant_test_bit at arch/x86/include/asm/bitops.h:325 (discriminator 1)
(inlined by) test_ti_thread_flag at include/linux/thread_info.h:79 (discriminator 1)
(inlined by) need_resched at include/linux/sched.h:1620 (discriminator 1)
(inlined by) schedule at kernel/sched/core.c:3436 (discriminator 1)
[ 31.353401] ? sysctl_net_exit+0x13/0x13:
__schedule at kernel/sched/core.c:3288
[ 31.354051] ? schedule+0x29/0x42:
constant_test_bit at arch/x86/include/asm/bitops.h:325 (discriminator 1)
(inlined by) test_ti_thread_flag at include/linux/thread_info.h:79 (discriminator 1)
(inlined by) need_resched at include/linux/sched.h:1620 (discriminator 1)
(inlined by) schedule at kernel/sched/core.c:3436 (discriminator 1)
[ 31.354605] ? exit_to_usermode_loop+0x36/0xa1:
exit_to_usermode_loop at arch/x86/entry/common.c:153
[ 31.355346] ? syscall_return_slowpath+0x9f/0xbe:
get_current at arch/x86/include/asm/current.h:15
(inlined by) prepare_exit_to_usermode at arch/x86/entry/common.c:209
(inlined by) syscall_return_slowpath at arch/x86/entry/common.c:264
[ 31.356108] ? entry_SYSCALL_64_fastpath+0x93/0x95:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:243
[ 31.356897]
[ 31.357157] Allocated by task 518:
[ 31.357732] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.358392] memcg_check_events+0x20/0x277:
memcg_check_events at mm/memcontrol.c:673
[ 31.359073] get_random_u32+0xaf/0xbf:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) get_random_u32 at drivers/char/random.c:2153
[ 31.359690] __list_add_valid+0x40/0x87:
__list_add_valid at lib/list_debug.c:26 (discriminator 8)
[ 31.360325] cache_grow_end+0xd3/0x140:
__list_add at include/linux/list.h:60
(inlined by) list_add at include/linux/list.h:79
(inlined by) fixup_slab_list at mm/slab.c:2840
(inlined by) cache_grow_end at mm/slab.c:2732
[ 31.360947] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.361610] _raw_spin_unlock+0x5/0xd:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __raw_spin_unlock at include/linux/spinlock_api_smp.h:152
(inlined by) _raw_spin_unlock at kernel/locking/spinlock.c:183
[ 31.362221] cache_alloc_refill+0x26e/0x2f3:
cache_alloc_refill at mm/slab.c:3050
[ 31.362922] expand_files+0x0/0x2a2:
expand_files at fs/file.c:201
[ 31.363502] kmem_cache_alloc_trace+0x186/0x229:
__read_once_size at include/linux/compiler.h:183
(inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) memcg_kmem_enabled at include/linux/memcontrol.h:1123
(inlined by) slab_post_alloc_hook at mm/slab.h:445
(inlined by) slab_alloc at mm/slab.c:3385
(inlined by) kmem_cache_alloc_trace at mm/slab.c:3611
[ 31.364252] perf_event_alloc+0x6a/0xc87:
kmalloc at include/linux/slab.h:499
(inlined by) kzalloc at include/linux/slab.h:688
(inlined by) perf_event_alloc at kernel/events/core.c:9367
[ 31.364906] _raw_spin_unlock+0x5/0xd:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __raw_spin_unlock at include/linux/spinlock_api_smp.h:152
(inlined by) _raw_spin_unlock at kernel/locking/spinlock.c:183
[ 31.365517] __ptrace_may_access+0x78/0x1de:
__ptrace_may_access at kernel/ptrace.c:293
[ 31.366209] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.366878] SyS_perf_event_open+0x54c/0xf6a
[ 31.367584] SyS_perf_event_open+0x0/0xf6a
[ 31.368267] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.369004] entry_SYSCALL_64_fastpath+0x23/0x95:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:210
[ 31.369769] __lru_cache_add+0xc8/0xf2:
__read_once_size at include/linux/compiler.h:183
(inlined by) PageTail at include/linux/page-flags.h:156
(inlined by) PageCompound at include/linux/page-flags.h:161
(inlined by) __lru_cache_add at mm/swap.c:408
[ 31.370388] do_raw_read_lock+0xd/0x40:
do_raw_read_lock at kernel/locking/spinlock_debug.c:153
[ 31.371011] do_raw_read_unlock+0xd/0x30:
do_raw_read_unlock at kernel/locking/spinlock_debug.c:172
[ 31.371660] mod_node_page_state+0x19/0x84:
mod_node_state at mm/vmstat.c:539
(inlined by) mod_node_page_state at mm/vmstat.c:577
[ 31.372339] __list_add_valid+0x40/0x87:
__list_add_valid at lib/list_debug.c:26 (discriminator 8)
[ 31.372973] cache_grow_end+0xd3/0x140:
__list_add at include/linux/list.h:60
(inlined by) list_add at include/linux/list.h:79
(inlined by) fixup_slab_list at mm/slab.c:2840
(inlined by) cache_grow_end at mm/slab.c:2732
[ 31.373596] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.374264] _raw_spin_unlock+0x5/0xd:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __raw_spin_unlock at include/linux/spinlock_api_smp.h:152
(inlined by) _raw_spin_unlock at kernel/locking/spinlock.c:183
[ 31.374873] cache_alloc_refill+0x26e/0x2f3:
cache_alloc_refill at mm/slab.c:3050
[ 31.375565] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.376229] SyS_perf_event_open+0x54c/0xf6a
[ 31.376944] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.377684] kmem_cache_alloc_node_trace+0x18f/0x23d:
__read_once_size at include/linux/compiler.h:183
(inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) memcg_kmem_enabled at include/linux/memcontrol.h:1123
(inlined by) slab_post_alloc_hook at mm/slab.h:445
(inlined by) slab_alloc_node at mm/slab.c:3328
(inlined by) kmem_cache_alloc_node_trace at mm/slab.c:3654
[ 31.378495] __kmalloc_node+0x2d/0x4c:
__do_kmalloc_node at mm/slab.c:3675
(inlined by) __kmalloc_node at mm/slab.c:3682
[ 31.379110] get_callchain_buffers+0xc2/0x185:
alloc_callchain_buffers at kernel/events/callchain.c:91
(inlined by) get_callchain_buffers at kernel/events/callchain.c:138
[ 31.379837] perf_event_alloc+0x8c8/0xc87:
perf_event_alloc at kernel/events/core.c:9506
[ 31.380498] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.381174] SyS_perf_event_open+0x54c/0xf6a
[ 31.381887] SyS_perf_event_open+0x0/0xf6a
[ 31.382564] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.383303] entry_SYSCALL_64_fastpath+0x23/0x95:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:210
[ 31.384069] cache_grow_end+0xd3/0x140:
__list_add at include/linux/list.h:60
(inlined by) list_add at include/linux/list.h:79
(inlined by) fixup_slab_list at mm/slab.c:2840
(inlined by) cache_grow_end at mm/slab.c:2732
[ 31.384698] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.385359] _raw_spin_unlock+0x5/0xd:
__preempt_count_sub at arch/x86/include/asm/preempt.h:81
(inlined by) __raw_spin_unlock at include/linux/spinlock_api_smp.h:152
(inlined by) _raw_spin_unlock at kernel/locking/spinlock.c:183
[ 31.385973] cache_alloc_refill+0x26e/0x2f3:
cache_alloc_refill at mm/slab.c:3050
[ 31.386659] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.387332] SyS_perf_event_open+0x54c/0xf6a
[ 31.388035] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.388771] kmem_cache_alloc_node_trace+0x1b4/0x23d:
__read_once_size at include/linux/compiler.h:183
(inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_kmalloc_node at include/trace/events/kmem.h:100
(inlined by) kmem_cache_alloc_node_trace at mm/slab.c:3657
[ 31.389583] __kmalloc_node+0x2d/0x4c:
__do_kmalloc_node at mm/slab.c:3675
(inlined by) __kmalloc_node at mm/slab.c:3682
[ 31.390195] get_callchain_buffers+0xc2/0x185:
alloc_callchain_buffers at kernel/events/callchain.c:91
(inlined by) get_callchain_buffers at kernel/events/callchain.c:138
[ 31.390919] perf_event_alloc+0x8c8/0xc87:
perf_event_alloc at kernel/events/core.c:9506
[ 31.391582] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.392252] SyS_perf_event_open+0x54c/0xf6a
[ 31.392957] SyS_perf_event_open+0x0/0xf6a
[ 31.393636] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.394375] kmem_cache_alloc_node_trace+0x1b4/0x23d:
__read_once_size at include/linux/compiler.h:183
(inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_kmalloc_node at include/trace/events/kmem.h:100
(inlined by) kmem_cache_alloc_node_trace at mm/slab.c:3657
[ 31.395193] __kmalloc_node+0x42/0x4c:
__do_kmalloc_node at mm/slab.c:3675
(inlined by) __kmalloc_node at mm/slab.c:3682
[ 31.395811] get_callchain_buffers+0xc2/0x185:
alloc_callchain_buffers at kernel/events/callchain.c:91
(inlined by) get_callchain_buffers at kernel/events/callchain.c:138
[ 31.396525] perf_event_alloc+0x8c8/0xc87:
perf_event_alloc at kernel/events/core.c:9506
[ 31.397192] do_raw_spin_unlock+0xae/0xc0:
debug_spin_unlock at kernel/locking/spinlock_debug.c:103
(inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 31.397861] SyS_perf_event_open+0x54c/0xf6a
[ 31.398565] SyS_perf_event_open+0x0/0xf6a
[ 31.399248] trace_hardirqs_on_thunk+0x1a/0x1c:
trace_hardirqs_on_thunk at arch/x86/entry/thunk_64.S:42
[ 31.399981] entry_SYSCALL_64_fastpath+0x23/0x95:
entry_SYSCALL_64_fastpath at arch/x86/entry/entry_64.S:210
[ 31.400744]
[ 31.401002] Freed by task 0:
[ 31.401484] (stack is not available)
[ 31.402081]
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
3 years, 4 months
[lkp-robot] [fs/locks] 52306e882f: stress-ng.lockofd.ops_per_sec -11% regression
by kernel test robot
Greeting,
FYI, we noticed a -11% regression of stress-ng.lockofd.ops_per_sec due to commit:
commit: 52306e882f77d3fd73f91435c41373d634acc5d2 ("fs/locks: Use allocation rather than the stack in fcntl_getlk()")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: stress-ng
on test machine: 88 threads Intel(R) Xeon(R) CPU E5-2699 v4 @ 2.20GHz with 128G memory
with following parameters:
testtime: 1s
class: filesystem
cpufreq_governor: performance
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
testcase/path_params/tbox_group/run: stress-ng/1s-filesystem-performance/lkp-bdw-ep6
v4.13-rc1 52306e882f77d3fd73f91435c4
---------------- --------------------------
%stddev change %stddev
\ | \
1.219e+08 -11% 1.09e+08 stress-ng.lockofd.ops_per_sec
1.229e+08 -10% 1.103e+08 stress-ng.locka.ops_per_sec
1.233e+08 -10% 1.105e+08 stress-ng.locka.ops
1.223e+08 -11% 1.093e+08 stress-ng.lockofd.ops
1061237 10% 1168476 stress-ng.eventfd.ops
1061205 10% 1168414 stress-ng.eventfd.ops_per_sec
2913174 9% 3163165 stress-ng.time.voluntary_context_switches
89.90 -4% 86.58 stress-ng.time.user_time
26510 -6% 24822 stress-ng.io.ops
26489 -6% 24798 stress-ng.io.ops_per_sec
885499 ± 14% 18% 1042236 perf-stat.cpu-migrations
2.537e+08 10% 2.783e+08 perf-stat.node-store-misses
1067830 ± 4% 8% 1154877 ± 3% perf-stat.page-faults
5384755 ± 4% 7% 5747689 perf-stat.context-switches
32.28 7% 34.42 ± 3% perf-stat.node-store-miss-rate%
12245 ±110% -7e+03 5367 ± 29% latency_stats.avg.call_usermodehelper_exec.__request_module.get_fs_type.do_mount.SyS_mount.entry_SYSCALL_64_fastpath
311261 ±173% -3e+05 11702 ±100% latency_stats.avg.tty_release_struct.tty_release.__fput.____fput.task_work_run.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
1472 ± 60% 4e+03 5144 ± 97% latency_stats.max.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
225 ± 39% 3e+03 3698 ±132% latency_stats.max.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_do_close.[nfsv4].__nfs4_close.[nfsv4].nfs4_close_sync.[nfsv4].nfs4_close_context.[nfsv4].__put_nfs_open_context.nfs_file_clear_open_context.nfs_file_release.__fput.____fput.task_work_run
228 ± 34% 3e+03 3103 ±159% latency_stats.max.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs4_file_open.[nfsv4].do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open
270 ± 24% 3e+03 3110 ±162% latency_stats.max.io_schedule.wait_on_page_bit_common.__filemap_fdatawait_range.filemap_write_and_wait_range.nfs_file_fsync.vfs_fsync_range.vfs_fsync.nfs4_file_flush.[nfsv4].filp_close.do_dup2.SyS_dup2.entry_SYSCALL_64_fastpath
12245 ±110% -7e+03 5367 ± 29% latency_stats.max.call_usermodehelper_exec.__request_module.get_fs_type.do_mount.SyS_mount.entry_SYSCALL_64_fastpath
927506 ±173% -9e+05 11702 ±100% latency_stats.max.tty_release_struct.tty_release.__fput.____fput.task_work_run.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
7892 ± 54% 3e+04 33793 ±131% latency_stats.sum.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
12030 ±109% 2e+04 33536 ±136% latency_stats.sum.autofs4_wait.autofs4_mount_wait.autofs4_d_manage.follow_managed.lookup_fast.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
14311 ± 15% 7e+03 21729 ±116% latency_stats.sum.call_rwsem_down_read_failed.page_lock_anon_vma_read.rmap_walk_anon.rmap_walk.try_to_unmap.migrate_pages.migrate_misplaced_page.__handle_mm_fault.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
8095 ± 22% 7e+03 15421 ± 79% latency_stats.sum.call_rwsem_down_read_failed.rmap_walk_anon.rmap_walk.remove_migration_ptes.migrate_pages.migrate_misplaced_page.__handle_mm_fault.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
495 ± 39% 7e+03 7470 ±131% latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_do_close.[nfsv4].__nfs4_close.[nfsv4].nfs4_close_sync.[nfsv4].nfs4_close_context.[nfsv4].__put_nfs_open_context.nfs_file_clear_open_context.nfs_file_release.__fput.____fput.task_work_run
3449 ± 18% 7e+03 10001 ± 68% latency_stats.sum.io_schedule.wait_on_page_bit_common.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
378 ±123% 6e+03 6438 ±109% latency_stats.sum.io_schedule.__lock_page.find_lock_entry.shmem_getpage_gfp.shmem_fault.__do_fault.__handle_mm_fault.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
386 ± 34% 3e+03 3242 ±153% latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs4_file_open.[nfsv4].do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open
413 ± 19% 3e+03 3256 ±156% latency_stats.sum.io_schedule.wait_on_page_bit_common.__filemap_fdatawait_range.filemap_write_and_wait_range.nfs_file_fsync.vfs_fsync_range.vfs_fsync.nfs4_file_flush.[nfsv4].filp_close.do_dup2.SyS_dup2.entry_SYSCALL_64_fastpath
2874 ±173% -3e+03 0 latency_stats.sum.call_rwsem_down_write_failed.do_unlinkat.SyS_unlink.entry_SYSCALL_64_fastpath
3683 ±172% -4e+03 5 ±100% latency_stats.sum.call_rwsem_down_read_failed.lookup_slow.walk_component.path_lookupat.filename_lookup.user_path_at_empty.SyS_chmod.entry_SYSCALL_64_fastpath
12245 ±110% -7e+03 5367 ± 29% latency_stats.sum.call_usermodehelper_exec.__request_module.get_fs_type.do_mount.SyS_mount.entry_SYSCALL_64_fastpath
7320 ±136% -7e+03 0 latency_stats.sum.call_rwsem_down_write_failed.do_truncate.do_sys_ftruncate.SyS_ftruncate.entry_SYSCALL_64_fastpath
52297 ±124% -3e+04 26320 ± 16% latency_stats.sum.call_rwsem_down_read_failed.lookup_slow.walk_component.link_path_walk.path_parentat.filename_parentat.do_unlinkat.SyS_unlink.entry_SYSCALL_64_fastpath
64452 ± 83% -3e+04 31383 ± 30% latency_stats.sum.call_rwsem_down_write_failed.do_rmdir.SyS_rmdir.entry_SYSCALL_64_fastpath
1867567 ±173% -2e+06 11702 ±100% latency_stats.sum.tty_release_struct.tty_release.__fput.____fput.task_work_run.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Xiaolong
3 years, 4 months
[e1000_shutdown] e1000 0000:00:03.0: disabling already-disabled device
by Fengguang Wu
Hello,
FYI this happens in mainline kernel 4.14.0-01330-g3c07399.
It happens since 4.13 .
It occurs in 3 out of 162 boots.
[ 44.637743] advantechwdt: Unexpected close, not stopping watchdog!
[ 44.997548] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input6
[ 45.013419] e1000 0000:00:03.0: disabling already-disabled device
[ 45.013447] ------------[ cut here ]------------
[ 45.014868] WARNING: CPU: 1 PID: 71 at drivers/pci/pci.c:1641 pci_disable_device+0xa1/0x105:
pci_disable_device at drivers/pci/pci.c:1640
[ 45.016171] CPU: 1 PID: 71 Comm: rcu_perf_shutdo Not tainted 4.14.0-01330-g3c07399 #1
[ 45.017197] task: ffff88011bee9e40 task.stack: ffffc90000860000
[ 45.017987] RIP: 0010:pci_disable_device+0xa1/0x105:
pci_disable_device at drivers/pci/pci.c:1640
[ 45.018603] RSP: 0000:ffffc90000863e30 EFLAGS: 00010286
[ 45.019282] RAX: 0000000000000035 RBX: ffff88013a230008 RCX: 0000000000000000
[ 45.020182] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000203
[ 45.021084] RBP: ffff88013a3f31e8 R08: 0000000000000001 R09: 0000000000000000
[ 45.021986] R10: ffffffff827ec29c R11: 0000000000000002 R12: 0000000000000001
[ 45.022946] R13: ffff88013a230008 R14: ffff880117802b20 R15: ffffc90000863e8f
[ 45.023842] FS: 0000000000000000(0000) GS:ffff88013fd00000(0000) knlGS:0000000000000000
[ 45.024863] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 45.025583] CR2: ffffc900006d4000 CR3: 000000000220f000 CR4: 00000000000006a0
[ 45.026478] Call Trace:
[ 45.026811] __e1000_shutdown+0x1d4/0x1e2:
__e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5162
[ 45.027344] ? rcu_perf_cleanup+0x2a1/0x2a1:
rcu_perf_shutdown at kernel/rcu/rcuperf.c:627
[ 45.027883] e1000_shutdown+0x14/0x3a:
e1000_shutdown at drivers/net/ethernet/intel/e1000/e1000_main.c:5235
[ 45.028351] device_shutdown+0x110/0x1aa:
device_shutdown at drivers/base/core.c:2807
[ 45.028858] kernel_power_off+0x31/0x64:
kernel_power_off at kernel/reboot.c:260
[ 45.029343] rcu_perf_shutdown+0x9b/0xa7:
rcu_perf_shutdown at kernel/rcu/rcuperf.c:637
[ 45.029852] ? __wake_up_common_lock+0xa2/0xa2:
autoremove_wake_function at kernel/sched/wait.c:376
[ 45.030414] kthread+0x126/0x12e:
kthread at kernel/kthread.c:233
[ 45.030834] ? __kthread_bind_mask+0x8e/0x8e:
kthread at kernel/kthread.c:190
[ 45.031399] ? ret_from_fork+0x1f/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:443
[ 45.031883] ? kernel_init+0xa/0xf5:
kernel_init at init/main.c:997
[ 45.032325] ret_from_fork+0x1f/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:443
[ 45.032777] Code: 00 48 85 ed 75 07 48 8b ab a8 00 00 00 48 8d bb 98 00 00 00 e8 aa d1 11 00 48 89 ea 48 89 c6 48 c7 c7 d8 e4 0b 82 e8 55 7d da ff <0f> ff b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 f0 b1 61 82
[ 45.035222] ---[ end trace c257137b1b1976ef ]---
[ 45.037838] ACPI: Preparing to enter system sleep state S5
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
3 years, 4 months
d17a1d97dc ("x86/mm/kasan: don't use vmemmap_populate() to initialize shadow"): BUG: KASAN: use-after-scope in __drm_mm_interval_first
by Fengguang Wu
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit d17a1d97dc208d664c91cc387ffb752c7f85dc61
Author: Andrey Ryabinin <aryabinin(a)virtuozzo.com>
AuthorDate: Wed Nov 15 17:36:35 2017 -0800
Commit: Linus Torvalds <torvalds(a)linux-foundation.org>
CommitDate: Wed Nov 15 18:21:05 2017 -0800
x86/mm/kasan: don't use vmemmap_populate() to initialize shadow
The kasan shadow is currently mapped using vmemmap_populate() since that
provides a semi-convenient way to map pages into init_top_pgt. However,
since that no longer zeroes the mapped pages, it is not suitable for
kasan, which requires zeroed shadow memory.
Add kasan_populate_shadow() interface and use it instead of
vmemmap_populate(). Besides, this allows us to take advantage of
gigantic pages and use them to populate the shadow, which should save us
some memory wasted on page tables and reduce TLB pressure.
Link: http://lkml.kernel.org/r/20171103185147.2688-2-pasha.tatashin@oracle.com
Signed-off-by: Andrey Ryabinin <aryabinin(a)virtuozzo.com>
Signed-off-by: Pavel Tatashin <pasha.tatashin(a)oracle.com>
Cc: Steven Sistare <steven.sistare(a)oracle.com>
Cc: Daniel Jordan <daniel.m.jordan(a)oracle.com>
Cc: Bob Picco <bob.picco(a)oracle.com>
Cc: Michal Hocko <mhocko(a)suse.com>
Cc: Alexander Potapenko <glider(a)google.com>
Cc: Ard Biesheuvel <ard.biesheuvel(a)linaro.org>
Cc: Catalin Marinas <catalin.marinas(a)arm.com>
Cc: Christian Borntraeger <borntraeger(a)de.ibm.com>
Cc: David S. Miller <davem(a)davemloft.net>
Cc: Dmitry Vyukov <dvyukov(a)google.com>
Cc: Heiko Carstens <heiko.carstens(a)de.ibm.com>
Cc: "H. Peter Anvin" <hpa(a)zytor.com>
Cc: Ingo Molnar <mingo(a)redhat.com>
Cc: Mark Rutland <mark.rutland(a)arm.com>
Cc: Matthew Wilcox <willy(a)infradead.org>
Cc: Mel Gorman <mgorman(a)techsingularity.net>
Cc: Michal Hocko <mhocko(a)kernel.org>
Cc: Sam Ravnborg <sam(a)ravnborg.org>
Cc: Thomas Gleixner <tglx(a)linutronix.de>
Cc: Will Deacon <will.deacon(a)arm.com>
Signed-off-by: Andrew Morton <akpm(a)linux-foundation.org>
Signed-off-by: Linus Torvalds <torvalds(a)linux-foundation.org>
a4a3ede213 mm: zero reserved and unavailable struct pages
d17a1d97dc x86/mm/kasan: don't use vmemmap_populate() to initialize shadow
43570f0383 Merge branch 'linus' of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
5bef2980ad Add linux-next specific files for 20171128
+-------------------------------------------------------+------------+------------+------------+---------------+
| | a4a3ede213 | d17a1d97dc | 43570f0383 | next-20171128 |
+-------------------------------------------------------+------------+------------+------------+---------------+
| boot_successes | 30 | 0 | 0 | 0 |
| boot_failures | 8 | 15 | 19 | 2 |
| WARNING:at_drivers/pci/pci-sysfs.c:#pci_mmap_resource | 8 | | | |
| RIP:pci_mmap_resource | 8 | | | |
| BUG:KASAN:use-after-scope_in__drm_mm_interval_first | 0 | 15 | 19 | 2 |
+-------------------------------------------------------+------------+------------+------------+---------------+
[ 27.628251] AMD IOMMUv2 functionality not available on this system
[ 27.631925] drm_mm: Testing DRM range manger (struct drm_mm), with random_seed=0x248e657d max_iterations=8192 max_prime=128
[ 27.633191] drm_mm: igt_sanitycheck - ok!
[ 79.880445] Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 103.749567] ==================================================================
[ 103.750064] BUG: KASAN: use-after-scope in __drm_mm_interval_first+0xbb/0x1bf
[ 103.750064] Read of size 8 at addr ffff880016577c08 by task swapper/0/1
[ 103.750064]
[ 103.750064] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.14.0-04319-gd17a1d9 #1
[ 103.750064] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 103.750064] Call Trace:
[ 103.750064] ? dump_stack+0xd1/0x16c
[ 103.750064] ? _atomic_dec_and_lock+0x10f/0x10f
[ 103.750064] ? print_address_description+0x93/0x22e
[ 103.750064] ? __drm_mm_interval_first+0xbb/0x1bf
[ 103.750064] ? kasan_report+0x219/0x23f
[ 103.750064] ? __drm_mm_interval_first+0xbb/0x1bf
[ 103.750064] ? assert_continuous+0x13c/0x22f
[ 103.750064] ? drm_mm_replace_node+0x210/0x3ed
[ 103.750064] ? __igt_insert+0x5af/0xb3a
[ 103.750064] ? igt_bottomup+0x9e6/0x9e6
[ 103.750064] ? kvm_clock_read+0x21/0x29
[ 103.750064] ? kvm_sched_clock_read+0x5/0xd
[ 103.750064] ? sched_clock+0x5/0x8
[ 103.750064] ? sched_clock_local+0x36/0xe8
[ 103.750064] ? sched_clock_cpu+0x123/0x13f
[ 103.750064] ? rcu_irq_enter_disabled+0x8/0x8
[ 103.750064] ? next_prime_number+0x33f/0x368
[ 103.750064] ? rcu_note_context_switch+0x267/0x267
[ 103.750064] ? igt_replace+0x45/0xa9
[ 103.750064] ? test_drm_mm_init+0x112/0x164
[ 103.750064] ? drm_kms_helper_init+0x5/0x5
[ 103.750064] ? do_one_initcall+0xe7/0x1ef
[ 103.750064] ? initcall_blacklisted+0x15d/0x15d
[ 103.750064] ? up_read+0x2c/0x2c
[ 103.750064] ? kasan_unpoison_shadow+0xf/0x2e
[ 103.750064] ? kernel_init_freeable+0x2a8/0x33b
[ 103.750064] ? rest_init+0x24f/0x24f
[ 103.750064] ? kernel_init+0x7/0xfe
[ 103.750064] ? rest_init+0x24f/0x24f
[ 103.750064] ? ret_from_fork+0x24/0x30
[ 103.750064]
[ 103.750064] The buggy address belongs to the page:
[ 103.750064] page:ffff88001b1e3208 count:0 mapcount:0 mapping: (null) index:0x0
[ 103.750064] flags: 0x401fff800000()
[ 103.750064] raw: 0000401fff800000 0000000000000000 0000000000000000 00000000ffffffff
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 4fbd8d194f06c8a3fd2af1ce560ddb31f7ec8323 v4.14 --
git bisect bad 93ea0eb7d77afab34657715630d692a78b8cea6a # 04:25 B 0 1 15 0 Merge tag 'leaks-4.15-rc1' of git://github.com/tcharding/linux
git bisect good 32190f0afbf4f1c0a9142e5a886a078ee0b794fd # 04:53 G 11 0 3 3 Merge tag 'fscrypt-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tytso/fscrypt
git bisect good 37cb8e1f8e10c6e9bd2a1b95cdda0620a21b0551 # 05:10 G 11 0 2 2 Merge tag 'devicetree-for-4.15' of git://git.kernel.org/pub/scm/linux/kernel/git/robh/linux
git bisect good 6c4ba00c40d5acb17f32d4b7e02dbcd21f336d9f # 05:26 G 11 0 1 1 Merge tag 'hsi-for-4.15' of git://git.kernel.org/pub/scm/linux/kernel/git/sre/linux-hsi
git bisect good 766ec76a27aa9dfdfee3a80f29ddc1f7539c71f9 # 05:38 G 11 0 2 2 Merge branch 'for-4.15' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/percpu
git bisect good 1b6115fbe3b3db746d7baa11399dd617fc75e1c4 # 06:00 G 11 0 3 3 Merge tag 'pci-v4.15-changes' of git://git.kernel.org/pub/scm/linux/kernel/git/helgaas/pci
git bisect good 6363b3f3ac5be096d08c8c504128befa0c033529 # 06:17 G 11 0 4 4 Merge tag 'ipmi-for-4.15' of git://github.com/cminyard/linux-ipmi
git bisect bad 7c225c69f86c934e3be9be63ecde754e286838d7 # 06:30 B 0 11 25 0 Merge branch 'akpm' (patches from Andrew)
git bisect good 4be90299a1693c2112edb20ca78d6cc9f2183326 # 06:51 G 11 0 0 0 ceph: use pagevec_lookup_range_nr_tag()
git bisect bad 76253fbc8fbf6018401755fc5c07814a837cc832 # 07:11 B 0 1 15 0 mm: move accounting updates before page_cache_tree_delete()
git bisect good 353b1e7b5859e98860f984d8894fa7ddc242a90e # 08:16 G 11 0 2 2 x86/mm: set fields in deferred pages
git bisect bad 78c943662f4b1d53ddbfc515e427827915781377 # 08:43 B 0 11 25 0 sparc64: optimize struct page zeroing
git bisect good a4a3ede2132ae0863e2d43e06f9b5697c51a7a3b # 08:58 G 11 0 2 2 mm: zero reserved and unavailable struct pages
git bisect bad e17d8025f07e4fd9d73b137a8bcab04548126b83 # 09:19 B 0 11 29 4 arm64/mm/kasan: don't use vmemmap_populate() to initialize shadow
git bisect bad d17a1d97dc208d664c91cc387ffb752c7f85dc61 # 09:43 B 0 11 25 0 x86/mm/kasan: don't use vmemmap_populate() to initialize shadow
# first bad commit: [d17a1d97dc208d664c91cc387ffb752c7f85dc61] x86/mm/kasan: don't use vmemmap_populate() to initialize shadow
git bisect good a4a3ede2132ae0863e2d43e06f9b5697c51a7a3b # 09:50 G 32 0 6 8 mm: zero reserved and unavailable struct pages
# extra tests with debug options
git bisect bad d17a1d97dc208d664c91cc387ffb752c7f85dc61 # 10:21 B 0 5 24 4 x86/mm/kasan: don't use vmemmap_populate() to initialize shadow
# extra tests on HEAD of linux-devel/devel-catchup-201711282153
git bisect bad 2f623f1c616f6504ca8f87cd851c0512b7afd343 # 10:21 B 0 13 30 0 0day head guard for 'devel-catchup-201711282153'
# extra tests on tree/branch linus/master
git bisect bad 43570f0383d6d5879ae585e6c3cf027ba321546f # 10:45 B 0 5 19 0 Merge branch 'linus' of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
# extra tests with first bad commit reverted
git bisect good 749d726ffd5b18e874a743c6195801a55ddf1077 # 11:38 G 10 0 1 1 Revert "x86/mm/kasan: don't use vmemmap_populate() to initialize shadow"
# extra tests on tree/branch linux-next/master
git bisect bad 5bef2980adef8a6032d4f4709aebe9486181052f # 11:38 B 0 2 16 0 Add linux-next specific files for 20171128
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
3 years, 4 months
21729f81ce ("x86/mm: Provide general kernel support for memory encryption"): BUG: kernel reboot-without-warning in early-boot stage, last printk: early console in setup code
by Fengguang Wu
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit 21729f81ce8ae76a6995681d40e16f7ce8075db4
Author: Tom Lendacky <thomas.lendacky(a)amd.com>
AuthorDate: Mon Jul 17 16:10:07 2017 -0500
Commit: Ingo Molnar <mingo(a)kernel.org>
CommitDate: Tue Jul 18 11:38:00 2017 +0200
x86/mm: Provide general kernel support for memory encryption
Changes to the existing page table macros will allow the SME support to
be enabled in a simple fashion with minimal changes to files that use these
macros. Since the memory encryption mask will now be part of the regular
pagetable macros, we introduce two new macros (_PAGE_TABLE_NOENC and
_KERNPG_TABLE_NOENC) to allow for early pagetable creation/initialization
without the encryption mask before SME becomes active. Two new pgprot()
macros are defined to allow setting or clearing the page encryption mask.
The FIXMAP_PAGE_NOCACHE define is introduced for use with MMIO. SME does
not support encryption for MMIO areas so this define removes the encryption
mask from the page attribute.
Two new macros are introduced (__sme_pa() / __sme_pa_nodebug()) to allow
creating a physical address with the encryption mask. These are used when
working with the cr3 register so that the PGD can be encrypted. The current
__va() macro is updated so that the virtual address is generated based off
of the physical address without the encryption mask thus allowing the same
virtual address to be generated regardless of whether encryption is enabled
for that physical location or not.
Also, an early initialization function is added for SME. If SME is active,
this function:
- Updates the early_pmd_flags so that early page faults create mappings
with the encryption mask.
- Updates the __supported_pte_mask to include the encryption mask.
- Updates the protection_map entries to include the encryption mask so
that user-space allocations will automatically have the encryption mask
applied.
Signed-off-by: Tom Lendacky <thomas.lendacky(a)amd.com>
Reviewed-by: Thomas Gleixner <tglx(a)linutronix.de>
Reviewed-by: Borislav Petkov <bp(a)suse.de>
Cc: Alexander Potapenko <glider(a)google.com>
Cc: Andrey Ryabinin <aryabinin(a)virtuozzo.com>
Cc: Andy Lutomirski <luto(a)kernel.org>
Cc: Arnd Bergmann <arnd(a)arndb.de>
Cc: Borislav Petkov <bp(a)alien8.de>
Cc: Brijesh Singh <brijesh.singh(a)amd.com>
Cc: Dave Young <dyoung(a)redhat.com>
Cc: Dmitry Vyukov <dvyukov(a)google.com>
Cc: Jonathan Corbet <corbet(a)lwn.net>
Cc: Konrad Rzeszutek Wilk <konrad.wilk(a)oracle.com>
Cc: Larry Woodman <lwoodman(a)redhat.com>
Cc: Linus Torvalds <torvalds(a)linux-foundation.org>
Cc: Matt Fleming <matt(a)codeblueprint.co.uk>
Cc: Michael S. Tsirkin <mst(a)redhat.com>
Cc: Paolo Bonzini <pbonzini(a)redhat.com>
Cc: Peter Zijlstra <peterz(a)infradead.org>
Cc: Radim Krčmář <rkrcmar(a)redhat.com>
Cc: Rik van Riel <riel(a)redhat.com>
Cc: Toshimitsu Kani <toshi.kani(a)hpe.com>
Cc: kasan-dev(a)googlegroups.com
Cc: kvm(a)vger.kernel.org
Cc: linux-arch(a)vger.kernel.org
Cc: linux-doc(a)vger.kernel.org
Cc: linux-efi(a)vger.kernel.org
Cc: linux-mm(a)kvack.org
Link: http://lkml.kernel.org/r/b36e952c4c39767ae7f0a41cf5345adf27438480.1500319...
Signed-off-by: Ingo Molnar <mingo(a)kernel.org>
fd7e315988 x86/mm: Simplify p[g4um]d_page() macros
21729f81ce x86/mm: Provide general kernel support for memory encryption
7753ea0964 Merge tag 'kvm-4.15-2' of git://git.kernel.org/pub/scm/virt/kvm/kvm
6fc478f80f Add linux-next specific files for 20171124
+-----------------------------------------------------------------------------------------------+------------+------------+------------+---------------+
| | fd7e315988 | 21729f81ce | 7753ea0964 | next-20171124 |
+-----------------------------------------------------------------------------------------------+------------+------------+------------+---------------+
| boot_successes | 14 | 0 | 0 | 21 |
| boot_failures | 26 | 11 | 19 | 4 |
| WARNING:at_drivers/pci/pci-sysfs.c:#pci_mmap_resource | 17 | 0 | 0 | 4 |
| RIP:pci_mmap_resource | 17 | 0 | 0 | 4 |
| BUG:KASAN:slab-out-of-bounds_in_c | 5 | | | |
| WARNING:bad_unlock_balance_detected | 7 | | | |
| is_trying_to_release_lock(rcu_preempt_state)at | 7 | | | |
| calltrace:SyS_setpriority | 7 | | | |
| BUG:kernel_reboot-without-warning_in_early-boot_stage,last_printk:early_console_in_setup_code | 0 | 11 | 19 | |
+-----------------------------------------------------------------------------------------------+------------+------------+------------+---------------+
early console in setup code
BUG: kernel reboot-without-warning in early-boot stage, last printk: early console in setup code
Linux version 4.13.0-rc1-00045-g21729f8 #3
Command line: root=/dev/ram0 hung_task_panic=1 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw link=/kbuild-tests/run-queue/yocto-intel12/x86_64-randconfig-s1-11211736/linux-devel:rebased-cc73fee0bae2d66594d1fa2df92bbd783aa98e04:21729f81ce8ae76a6995681d40e16f7ce8075db4:bisect-linux-49/.vmlinuz-21729f81ce8ae76a6995681d40e16f7ce8075db4-20171125131312-7:yocto-intel12-1 branch=linux-devel/rebased-cc73fee0bae2d66594d1fa2df92bbd783aa98e04 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s1-11211736/gcc-6/21729f81ce8ae76a6995681d40e16f7ce8075db4/vmlinuz-4.13.0-rc1-00045-g21729f8 drbd.minor_count=8
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start e7cdb60fd28b252f1c15a0e50f79a01906124915 v4.13 --
git bisect bad 2500e287bca1beb313aa298f2d36be1257cbb483 # 23:19 B 0 4 18 0 Merge git://git.kvack.org/~bcrl/aio-next
git bisect bad c0da4fa0d1a54495d6055c009ac46b76d1da2c86 # 00:43 B 0 10 24 0 Merge tag 'media/v4.14-1' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
git bisect good b0c79f49c343cda8954b3322984c32f258ca4ccb # 01:58 G 10 0 2 2 Merge branch 'x86-asm-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad c7f396f12fb3644ff325acb2384b64c8eea7a746 # 02:52 B 0 1 15 0 Merge tag 'dlm-4.14' of git://git.kernel.org/pub/scm/linux/kernel/git/teigland/linux-dlm
git bisect bad 9e85ae6af6e907975f68d82ff127073ec024cb05 # 03:53 B 0 4 18 0 Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/s390/linux
git bisect bad b1b6f83ac938d176742c85757960dec2cf10e468 # 04:47 B 0 2 16 0 Merge branch 'x86-mm-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good f29139bf109d35967229b2caf4e6297c201cc690 # 06:02 G 11 0 6 6 Merge branch 'x86-debug-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good e0a195b5225e1285806622cc146dc5c3312fb392 # 06:57 G 11 0 6 6 Merge branch 'x86-spinlocks-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 6c51e67b64d169419fb13318035bb442f9176612 # 07:47 G 11 0 10 10 Merge branch 'x86-syscall-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 5f82e71a001d14824a7728ad9e49f6aea420f161 # 08:33 G 11 0 3 3 Merge branch 'locking-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad f655e6e6b992a2fb0d0334db2620607b98df39e7 # 09:12 B 0 4 18 0 x86/cpu/AMD: Make the microcode level available earlier in the boot
git bisect good fd7e315988b784509ba3f1b42f539bd0b1fca9bb # 10:01 G 11 0 8 8 x86/mm: Simplify p[g4um]d_page() macros
git bisect bad f99afd08a45fbbd9ce35a7624ffd1d850a1906c0 # 11:09 B 0 11 25 0 efi: Update efi_mem_type() to return an error rather than 0
git bisect bad 7f8b7e7f4ccbbd1fb8badddfabd28c955aea87b4 # 12:01 B 0 11 25 0 x86/mm: Add support for early encryption/decryption of memory
git bisect bad eef9c4abe77f55b1600f59d8ac5f1d953e2f5384 # 12:41 B 0 3 17 0 x86/mm: Add SME support for read_cr3_pa()
git bisect bad 21729f81ce8ae76a6995681d40e16f7ce8075db4 # 13:17 B 0 3 17 0 x86/mm: Provide general kernel support for memory encryption
# first bad commit: [21729f81ce8ae76a6995681d40e16f7ce8075db4] x86/mm: Provide general kernel support for memory encryption
git bisect good fd7e315988b784509ba3f1b42f539bd0b1fca9bb # 14:34 G 32 0 18 26 x86/mm: Simplify p[g4um]d_page() macros
# extra tests on HEAD of linux-devel/rebased-cc73fee0bae2d66594d1fa2df92bbd783aa98e04
git bisect bad c6633fb7bfbc4d02255fb1ab79dc84b2eda89620 # 14:35 B 0 444 458 0 ipc: msg: Make msg_queue timestamps y2038 safe
# extra tests on tree/branch linus/master
git bisect bad 7753ea09640807104c8e353f6d5dc47ee55307cf # 15:19 B 0 5 19 0 Merge tag 'kvm-4.15-2' of git://git.kernel.org/pub/scm/virt/kvm/kvm
# extra tests on tree/branch linux-next/master
git bisect good 6fc478f80f6809cc4b1a4230f47a62d3b7378dc0 # 16:20 G 11 0 4 4 Add linux-next specific files for 20171124
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
3 years, 4 months
[arch_copy_kprobe] WARNING: CPU: 0 PID: 1 at mm/vmalloc.c:301 vmalloc_to_page+0x2bf/0x416
by Fengguang Wu
Hello,
FYI this happens in mainline kernel 4.15.0-rc1.
It looks like a new regression. Bisect is on the way.
It occurs in 2 out of 11 boots.
[ 5.083644] rcu-perf:--- Start of test: nreaders=0 nwriters=1 verbose=1 shutdown=1
[ 5.085168] rcu-torture: Creating rcu_perf_shutdown task
[ 5.092218] rcu-torture: Creating rcu_perf_writer task
[ 5.093360] rcu-perf: rcu_perf_writer task started
[ 5.099058] Kprobe smoke test: started
[ 5.101137] WARNING: CPU: 0 PID: 1 at mm/vmalloc.c:301 vmalloc_to_page+0x2bf/0x416:
vmalloc_to_page at mm/vmalloc.c:301
[ 5.102564] Modules linked in:
[ 5.103087] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.15.0-rc1 #189
[ 5.104031] task: ffff88001d068000 task.stack: ffff88001d06c000
[ 5.104031] RIP: 0010:vmalloc_to_page+0x2bf/0x416:
vmalloc_to_page at mm/vmalloc.c:301
[ 5.104031] RSP: 0000:ffff88001d06fce8 EFLAGS: 00010293
[ 5.104031] RAX: 0000000000000003 RBX: ffffffffc0200000 RCX: 0000000000000000
[ 5.104031] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff9ed6e210
[ 5.104031] RBP: ffff880018815008 R08: ffffffff9e344ec6 R09: 0000000000000001
[ 5.104031] R10: ffff88001d06fc90 R11: 0000000000000b2c R12: 0000000000000000
[ 5.104031] R13: 0000000000000063 R14: 0000000000000001 R15: ffff88001d06fd61
[ 5.104031] FS: 0000000000000000(0000) GS:ffff88001d600000(0000) knlGS:0000000000000000
[ 5.104031] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 5.104031] CR2: 0000000000000000 CR3: 0000000018812000 CR4: 00000000000406f0
[ 5.104031] Call Trace:
[ 5.104031] ? 0xffffffffc01ff000
[ 5.104031] text_poke+0x4f/0x297:
text_poke at arch/x86/kernel/alternative.c:709
[ 5.104031] ? 0xffffffffc01ff002
[ 5.104031] arch_copy_kprobe+0xf7/0x106:
arch_copy_kprobe at arch/x86/kernel/kprobes/core.c:474
[ 5.104031] arch_prepare_kprobe+0x8c/0xc4:
arch_prepare_kprobe at arch/x86/kernel/kprobes/core.c:491
[ 5.104031] register_kprobe+0x6a8/0x875:
register_kprobe at kernel/kprobes.c:1567
[ 5.104031] ? do_early_param+0xb6/0xb6:
repair_env_string at init/main.c:245
[ 5.104031] ? init_test_probes+0x49/0x4bb:
test_kprobe at kernel/test_kprobes.c:69
(inlined by) init_test_probes at kernel/test_kprobes.c:377
[ 5.104031] init_test_probes+0x49/0x4bb:
test_kprobe at kernel/test_kprobes.c:69
(inlined by) init_test_probes at kernel/test_kprobes.c:377
[ 5.104031] init_kprobes+0x276/0x281:
init_kprobes at kernel/kprobes.c:2277
[ 5.104031] ? debugfs_kprobe_init+0xf7/0xf7:
init_kprobes at kernel/kprobes.c:2225
[ 5.104031] do_one_initcall+0x99/0x1a0:
do_one_initcall at init/main.c:826
[ 5.104031] ? do_early_param+0xb6/0xb6:
repair_env_string at init/main.c:245
[ 5.104031] kernel_init_freeable+0x11e/0x1e8:
do_initcall_level at init/main.c:891
(inlined by) do_initcalls at init/main.c:900
(inlined by) do_basic_setup at init/main.c:918
(inlined by) kernel_init_freeable at init/main.c:1066
[ 5.104031] ? rest_init+0x270/0x270:
kernel_init at init/main.c:993
[ 5.104031] kernel_init+0x5/0x156:
kernel_init at init/main.c:995
[ 5.104031] ret_from_fork+0x24/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:447
[ 5.104031] Code: 9e 48 39 c8 49 89 c4 41 0f 95 c6 31 c9 31 d2 44 89 f6 e8 36 48 f3 ff 49 63 c6 48 83 c0 02 48 ff 04 c5 c8 3b f0 9e 4d 39 ec 74 02 <0f> ff 31 d2 31 c9 48 c7 c7 e0 e1 d6 9e 44 89 f6 e8 0d 48 f3 ff
[ 5.104031] ---[ end trace 1e069188d28709ac ]---
[ 5.193423] Kprobe smoke test: passed successfully
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
3 years, 4 months
[ 0.003333] BUG: KASAN: use-after-scope in console_unlock+0x605/0xcc0
by Fengguang Wu
Hello,
FYI this happens in mainline kernel v4.15-rc1 .
It shows up after v4.14 . Bisect is on the way.
It occurs in 4 out of 4 boots.
[ 0.003333] RCU callback double-/use-after-free debug enabled.
[ 0.003333] RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
[ 0.003333] Tasks RCU enabled.
[ 0.003333] NR_IRQS: 4352, nr_irqs: 48, preallocated irqs: 16
[ 0.003333] ==================================================================
[ 0.003333] BUG: KASAN: use-after-scope in console_unlock+0x605/0xcc0:
atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
(inlined by) call_console_drivers at kernel/printk/printk.c:1556
(inlined by) console_unlock at kernel/printk/printk.c:2233
[ 0.003333] Write of size 4 at addr ffffffff83607aa0 by task swapper/0
[ 0.003333]
[ 0.003333] CPU: 0 PID: 0 Comm: swapper Not tainted 4.15.0-rc1 #1
[ 0.003333] Call Trace:
[ 0.003333] ? print_address_description+0x4f/0x3c0:
print_address_description at mm/kasan/report.c:253
[ 0.003333] ? console_unlock+0x605/0xcc0:
atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
(inlined by) call_console_drivers at kernel/printk/printk.c:1556
(inlined by) console_unlock at kernel/printk/printk.c:2233
[ 0.003333] ? kasan_report+0x304/0x390:
kasan_report_error at mm/kasan/report.c:352
(inlined by) kasan_report at mm/kasan/report.c:409
[ 0.003333] ? console_unlock+0x605/0xcc0:
atomic_read at arch/x86/include/asm/atomic.h:27
(inlined by) static_key_count at include/linux/jump_label.h:191
(inlined by) static_key_false at include/linux/jump_label.h:201
(inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
(inlined by) call_console_drivers at kernel/printk/printk.c:1556
(inlined by) console_unlock at kernel/printk/printk.c:2233
[ 0.003333] ? wake_up_klogd+0x180/0x180:
console_unlock at kernel/printk/printk.c:2138
[ 0.003333] ? _raw_spin_unlock_irqrestore+0xcf/0xf0:
__raw_spin_unlock_irqrestore at include/linux/spinlock_api_smp.h:161
(inlined by) _raw_spin_unlock_irqrestore at kernel/locking/spinlock.c:191
[ 0.003333] ? __down_trylock_console_sem+0xf8/0x120:
__down_trylock_console_sem at kernel/printk/printk.c:234
[ 0.003333] ? __down_trylock_console_sem+0x106/0x120:
__down_trylock_console_sem at kernel/printk/printk.c:235
[ 0.003333] ? vprintk_emit+0x63e/0x6f0:
vprintk_emit at kernel/printk/printk.c:1757
[ 0.003333] ? vprintk_func+0x11e/0x130:
vprintk_func at kernel/printk/printk_safe.c:379
[ 0.003333] ? printk+0xaf/0xcf:
printk at kernel/printk/printk.c:1824
[ 0.003333] ? show_regs_print_info+0x40/0x40:
printk at kernel/printk/printk.c:1824
[ 0.003333] ? __flush_tlb_all+0x1e/0x31:
__flush_tlb_global at arch/x86/include/asm/paravirt.h:298
(inlined by) __flush_tlb_all at arch/x86/include/asm/tlbflush.h:293
[ 0.003333] ? native_flush_tlb_global+0x5/0xa0:
native_flush_tlb_global at arch/x86/kernel/paravirt.c:199
[ 0.003333] ? kasan_init+0x276/0x306:
kasan_init at arch/x86/mm/kasan_init_64.c:349
[ 0.003333] ? setup_arch+0x1bb0/0x1cad:
setup_arch at arch/x86/kernel/setup.c:1236
[ 0.003333] ? reserve_standard_io_resources+0x88/0x88:
setup_arch at arch/x86/kernel/setup.c:829
[ 0.003333] ? vprintk_emit+0x6dc/0x6f0:
vprintk_emit at kernel/printk/printk.c:1761
[ 0.003333] ? vprintk_func+0x125/0x130:
vprintk_func at kernel/printk/printk_safe.c:380
[ 0.003333] ? printk+0xaf/0xcf:
printk at kernel/printk/printk.c:1824
[ 0.003333] ? show_regs_print_info+0x40/0x40:
printk at kernel/printk/printk.c:1824
[ 0.003333] ? trace_hardirqs_on+0x220/0x220:
trace_hardirqs_off at kernel/trace/trace_irqsoff.c:799
[ 0.003333] ? __early_make_pgtable+0x2a5/0x308:
__early_make_pgtable at arch/x86/kernel/head64.c:251
[ 0.003333] ? boot_cpu_init+0x16/0x56:
set_bit at arch/x86/include/asm/bitops.h:76
(inlined by) cpumask_set_cpu at include/linux/cpumask.h:297
(inlined by) set_cpu_online at include/linux/cpumask.h:799
(inlined by) boot_cpu_init at kernel/cpu.c:2012
[ 0.003333] ? start_kernel+0xe7/0x8cd:
add_latent_entropy at include/linux/random.h:26
(inlined by) start_kernel at init/main.c:535
[ 0.003333] ? thread_stack_cache_init+0x37/0x37
[ 0.003333] ? x86_cpuid_vendor+0xbe/0xd0:
x86_cpuid_vendor at arch/x86/include/asm/microcode.h:125
[ 0.003333] ? x86_family+0x2f/0x40:
x86_family at arch/x86/lib/cpu.c:14
[ 0.003333] ? load_ucode_bsp+0x3c4/0x46f:
load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:189
[ 0.003333] ? x86_early_init_platform_quirks+0x146/0x1a1:
x86_early_init_platform_quirks at arch/x86/kernel/platform-quirks.c:31
[ 0.003333] ? secondary_startup_64+0xa5/0xb0:
secondary_startup_64 at arch/x86/kernel/head_64.S:237
[ 0.003333]
[ 0.003333] Memory state around the buggy address:
[ 0.003333] ffffffff83607980: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 0.003333] ffffffff83607a00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 0.003333] >ffffffff83607a80: f1 f1 f1 f1 f8 f2 f2 f2 f2 f2 f2 f2 00 f2 f2 f2
Attached the full dmesg, kconfig and reproduce scripts.
Thanks,
Fengguang
3 years, 4 months
[lkp-robot] [torture] b151f93a71: INFO:rcu_preempt_detected_stalls_on_CPUs/tasks
by kernel test robot
FYI, we noticed the following commit (built with gcc-6):
commit: b151f93a71fc9fecb560e823a92402d882516483 ("torture: Eliminate torture_runnable")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2017.11.21a
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -smp 2 -m 320M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------+------------+------------+
| | 3d9d746535 | b151f93a71 |
+------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 76 | 88 |
| genirq:Flags_mismatch_irq##(ttyS0)vs.#(sir_ir) | 76 | 88 |
| INFO:rcu_preempt_self-detected_stall_on_CPU | 67 | 38 |
| EIP:__do_softirq | 67 | 38 |
| EIP:_raw_spin_unlock_irqrestore | 67 | 38 |
| INFO:rcu_preempt_detected_stalls_on_CPUs/tasks | 0 | 35 |
| EIP:preempt_count_sub | 0 | 1 |
| EIP:delay_tsc | 0 | 5 |
| EIP:preempt_count_add | 0 | 1 |
+------------------------------------------------+------------+------------+
[ 116.310716] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 116.311764] Tasks blocked on level-0 rcu_node (CPUs 0-0): P31
[ 116.312856] (detected by 0, t=10002 jiffies, g=-88, c=-89, q=352)
[ 116.314001] rcu_torture_rea R running task 7168 31 2 0x80000000
[ 116.315329] Call Trace:
[ 116.315801] __schedule+0x493/0x620
[ 116.316450] ? __softirqentry_text_start+0x8/0x8
[ 116.317306] preempt_schedule_irq+0x4a/0x70
[ 116.318083] resume_kernel+0x27/0x29
[ 116.318753] EIP: preempt_count_sub+0x130/0x140
[ 116.319579] EFLAGS: 00200297 CPU: 0
[ 116.320241] EAX: 47bd1665 EBX: 00000000 ECX: 00000000 EDX: 47bd1665
[ 116.321574] ESI: 7a647087 EDI: 0000000b EBP: 504e7ec4 ESP: 504e7ec4
[ 116.322821] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 116.323808] ? delay_tsc+0x65/0xd0
[ 116.324463] ? delay_tsc+0x65/0xd0
[ 116.325095] ? __queue_work+0x300/0x370
[ 116.325810] delay_tsc+0x65/0xd0
[ 116.326440] __delay+0xe/0x10
[ 116.327007] __const_udelay+0x25/0x30
[ 116.327675] rcu_read_delay+0x8a/0x110
[ 116.328414] ? kvm_sched_clock_read+0x8/0x20
[ 116.329242] rcu_torture_reader+0x189/0x320
[ 116.330019] ? rcu_torture_reader+0x320/0x320
[ 116.330833] kthread+0x103/0x110
[ 116.331513] ? rcu_torture_timer_cb+0x10/0x10
[ 116.332331] ? __kthread_create_on_node+0x140/0x140
[ 116.333247] ret_from_fork+0x19/0x24
[ 116.333938] rcu_torture_rea R running task 7168 31 2 0x80000000
[ 116.335236] Call Trace:
[ 116.335712] __schedule+0x493/0x620
[ 116.336367] ? __softirqentry_text_start+0x8/0x8
[ 116.337217] preempt_schedule_irq+0x4a/0x70
[ 116.338003] resume_kernel+0x27/0x29
[ 116.338674] EIP: preempt_count_sub+0x130/0x140
[ 116.339490] EFLAGS: 00200297 CPU: 0
[ 116.340162] EAX: 47bd1665 EBX: 00000000 ECX: 00000000 EDX: 47bd1665
[ 116.341300] ESI: 7a647087 EDI: 0000000b EBP: 504e7ec4 ESP: 504e7ec4
[ 116.342470] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 116.343449] ? delay_tsc+0x65/0xd0
[ 116.344080] ? delay_tsc+0x65/0xd0
[ 116.344762] ? __queue_work+0x300/0x370
[ 116.345471] delay_tsc+0x65/0xd0
[ 116.346062] __delay+0xe/0x10
[ 116.346642] __const_udelay+0x25/0x30
[ 116.347339] rcu_read_delay+0x8a/0x110
[ 116.348027] ? kvm_sched_clock_read+0x8/0x20
[ 116.348829] rcu_torture_reader+0x189/0x320
[ 116.349621] ? rcu_torture_reader+0x320/0x320
[ 116.350421] kthread+0x103/0x110
[ 116.351038] ? rcu_torture_timer_cb+0x10/0x10
[ 116.351853] ? __kthread_create_on_node+0x140/0x140
[ 116.352742] ret_from_fork+0x19/0x24
[ 116.353432] rcu_preempt kthread starved for 9974 jiffies! g4294967208 c4294967207 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x402 ->cpu=0
[ 116.355517] rcu_preempt I 7464 8 2 0x80000000
[ 116.356543] Call Trace:
[ 116.357008] __schedule+0x493/0x620
[ 116.357682] schedule+0x24/0x40
[ 116.358291] schedule_timeout+0x330/0x3b0
[ 116.359024] ? preempt_count_sub+0xea/0x140
[ 116.359806] ? collect_expired_timers+0xb0/0xb0
[ 116.360660] rcu_gp_kthread+0x6bf/0xef0
[ 116.361364] ? _raw_spin_unlock_irq+0x32/0x50
[ 116.362178] ? __schedule+0x4cd/0x620
[ 116.362874] kthread+0x103/0x110
[ 116.363476] ? rcu_implicit_dynticks_qs+0x3b0/0x3b0
[ 116.364377] ? __kthread_create_on_node+0x140/0x140
[ 116.365290] ret_from_fork+0x19/0x24
[ 116.367322] sir_ir sir_ir.0: Trapped in interrupt
[ 116.369468] sir_ir sir_ir.0: Trapped in interrupt
[ 116.371646] sir_ir sir_ir.0: Trapped in interrupt
[ 116.373797] sir_ir sir_ir.0: Trapped in interrupt
[ 116.375953] sir_ir sir_ir.0: Trapped in interrupt
[ 116.378112] sir_ir sir_ir.0: Trapped in interrupt
[ 116.380277] sir_ir sir_ir.0: Trapped in interrupt
[ 116.382452] sir_ir sir_ir.0: Trapped in interrupt
[ 116.384602] sir_ir sir_ir.0: Trapped in interrupt
[ 116.386762] sir_ir sir_ir.0: Trapped in interrupt
[ 116.388917] sir_ir sir_ir.0: Trapped in interrupt
[ 116.391059] sir_ir sir_ir.0: Trapped in interrupt
[ 116.393248] sir_ir sir_ir.0: Trapped in interrupt
[ 116.395407] sir_ir sir_ir.0: Trapped in interrupt
[ 116.397562] sir_ir sir_ir.0: Trapped in interrupt
[ 116.399723] sir_ir sir_ir.0: Trapped in interrupt
[ 116.401899] sir_ir sir_ir.0: Trapped in interrupt
[ 116.404055] sir_ir sir_ir.0: Trapped in interrupt
[ 116.406212] sir_ir sir_ir.0: Trapped in interrupt
[ 116.408371] sir_ir sir_ir.0: Trapped in interrupt
[ 116.410528] sir_ir sir_ir.0: Trapped in interrupt
[ 116.412710] sir_ir sir_ir.0: Trapped in interrupt
[ 116.414859] sir_ir sir_ir.0: Trapped in interrupt
[ 116.417008] sir_ir sir_ir.0: Trapped in interrupt
[ 116.419165] sir_ir sir_ir.0: Trapped in interrupt
[ 116.421342] sir_ir sir_ir.0: Trapped in interrupt
[ 116.424341] sir_ir sir_ir.0: Trapped in interrupt
[ 116.426505] sir_ir sir_ir.0: Trapped in interrupt
[ 116.428662] sir_ir sir_ir.0: Trapped in interrupt
[ 116.430817] sir_ir sir_ir.0: Trapped in interrupt
[ 116.432982] sir_ir sir_ir.0: Trapped in interrupt
[ 116.435134] sir_ir sir_ir.0: Trapped in interrupt
[ 116.437290] sir_ir sir_ir.0: Trapped in interrupt
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
3 years, 4 months