2015-06-14 08:57:37

by Fengguang Wu

[permalink] [raw]
Subject: [sched/preempt] BUG: KASan: out of bounds access in trace_graph_entry at addr ffff88000d717e48

Hi Frederic,

FYI, there are a number more bug messages showing up after this commit

git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master

commit b30f0e3ffedfa52b1d67a302ae5860c49998e5e2
Author: Frederic Weisbecker <[email protected]>
AuthorDate: Tue May 12 16:41:49 2015 +0200
Commit: Ingo Molnar <[email protected]>
CommitDate: Tue May 19 08:39:12 2015 +0200

sched/preempt: Optimize preemption operations on __schedule() callers

__schedule() disables preemption and some of its callers
(the preempt_schedule*() family) also set PREEMPT_ACTIVE.

So we have two preempt_count() modifications that could be performed
at once.

Lets remove the preemption disablement from __schedule() and pull
this responsibility to its callers in order to optimize preempt_count()
operations in a single place.

Suggested-by: Linus Torvalds <[email protected]>
Signed-off-by: Frederic Weisbecker <[email protected]>
Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Ingo Molnar <[email protected]>

===================================================
PARENT COMMIT NOT CLEAN. LOOK OUT FOR WRONG BISECT!
===================================================

Attached dmesg for the parent commit, too, to help confirm whether it is a noise error.

+-----------------------------------------------------------------------------+------------+------------+---------------+
| | 90b62b5129 | b30f0e3ffe | next-20150601 |
+-----------------------------------------------------------------------------+------------+------------+---------------+
| boot_successes | 1476 | 310 | 37 |
| boot_failures | 24 | 889 | 59 |
| BUG:kernel_boot_hang | 23 | 99 | 1 |
| kernel_BUG_at_arch/x86/kernel/traps.c | 1 | | |
| invalid_opcode | 1 | 4 | |
| RIP:do_device_not_available | 1 | | |
| Kernel_panic-not_syncing:Fatal_exception | 1 | 294 | 42 |
| backtrace:do_execve | 1 | | |
| backtrace:run_init_process | 1 | | |
| BUG:unable_to_handle_kernel | 0 | 398 | 25 |
| Oops | 0 | 395 | 25 |
| BUG:kernel_boot_crashed | 0 | 181 | |
| RIP:check_timers_list | 0 | 19 | |
| ptr_deref_or_user_memory_accessgeneral_protection_fault | 0 | 59 | 8 |
| RIP:print_ftrace_graph_addr | 0 | 95 | 1 |
| BUG:KASan:out_of_bounds_access_in_trace_graph_entry_at_addr | 0 | 16 | 4 |
| BUG_sighand_cache(Not_tainted):kasan:bad_access_detected | 0 | 20 | |
| INFO:Slab#objects=#used=#fp=0x(null)flags= | 0 | 24 | 4 |
| INFO:Object#@offset=#fp= | 0 | 20 | 3 |
| BUG:KASan:user-memory-access_on_address | 0 | 71 | 11 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 42 | |
| BUG:recent_printk_recursion | 0 | 3 | |
| BUG:KASan:out_of_bounds_access_in__trace_graph_return_at_addr | 0 | 7 | |
| BUG:KASan:out_of_bounds_access_in_tick_periodic_at_addr | 0 | 5 | |
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0 | 1 | |
| backtrace:cpu_startup_entry | 0 | 2 | 3 |
| RIP:__asan_load8 | 0 | 4 | |
| BUG:KASan:use_after_free_in_prepare_ftrace_return_at_addr | 0 | 2 | |
| BUG:KASan:use_after_free_in_trace_graph_entry_at_addr | 0 | 4 | |
| BUG:KASan:out_of_bounds_access_in__trace_graph_entry_at_addr | 0 | 7 | |
| BUG_sighand_cache(Tainted:G_D):kasan:bad_access_detected | 0 | 1 | |
| BUG:KASan:out_of_bounds_access_in_prepare_ftrace_return_at_addr | 0 | 5 | 2 |
| BUG_sighand_cache(Tainted:G_B):kasan:bad_access_detected | 0 | 3 | |
| RIP:native_read_tsc | 0 | 1 | |
| backtrace:smpboot_thread_fn | 0 | 4 | |
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 0 | 94 | 6 |
| backtrace:do_group_exit | 0 | 1 | |
| backtrace:SyS_exit_group | 0 | 1 | |
| BUG:scheduling_while_atomic | 0 | 36 | 1 |
| WARNING:at_kernel/trace/trace_functions_graph.c:#ftrace_return_to_handler() | 0 | 5 | 2 |
| backtrace:ftrace_graph_caller | 0 | 4 | 16 |
| general_protection_fault | 0 | 10 | 10 |
| RIP:preempt_count_add | 0 | 4 | 18 |
| BUG_kmalloc-#(Not_tainted):kasan:bad_access_detected | 0 | 7 | |
| INFO:Object#@offset=#fp=0x(null) | 0 | 2 | 1 |
| WARNING:at_kernel/sched/core.c:#return_to_handler() | 0 | 18 | |
| RIP:no_context | 0 | 1 | |
| RIP:_raw_spin_unlock_irq | 0 | 3 | |
| BUG_task_struct(Not_tainted):kasan:bad_access_detected | 0 | 2 | 4 |
| WARNING:at_kernel/time/timer.c:#return_to_handler() | 0 | 2 | |
| backtrace:show_stack | 0 | 1 | |
| backtrace:dump_stack | 0 | 3 | |
| RIP:scheduler_tick | 0 | 2 | |
| RIP:pick_next_task_rt | 0 | 5 | |
| RIP:__switch_to_xtra | 0 | 1 | |
| backtrace:irq_exit | 0 | 2 | |
| WARNING:at_kernel/softirq.c:#return_to_handler() | 0 | 2 | |
| backtrace:__local_bh_disable_ip | 0 | 2 | |
| backtrace:show_stack_log_lvl | 0 | 2 | |
| backtrace:apic_timer_interrupt | 0 | 1 | |
| RIP:__asan_loadN | 0 | 1 | |
| RIP:update_curr | 0 | 1 | |
| BUG:KASan:use_after_free_in_tick_periodic_at_addr | 0 | 1 | |
| RIP:preempt_schedule_context | 0 | 3 | |
| backtrace:register_tracer | 0 | 3 | |
| backtrace:init_graph_trace | 0 | 3 | |
| backtrace:kernel_init_freeable | 0 | 11 | 1 |
| RIP:_raw_spin_lock | 0 | 1 | |
| RIP:task_curr | 0 | 6 | |
| BUG:KASan:use_after_free_in__trace_graph_return_at_addr | 0 | 1 | |
| BUG:KASan:use_after_free_in__trace_graph_entry_at_addr | 0 | 1 | |
| BUG:KASan:use_after_free_in_ftrace_push_return_trace_at_addr | 0 | 1 | |
| RIP:rb_reserve_next_event | 0 | 1 | |
| BUG_kmalloc-#(Tainted:G_B):kasan:bad_access_detected | 0 | 2 | |
| BUG:KASan:out_of_bounds_access_in_ftrace_push_return_trace_at_addr | 0 | 1 | |
| WARNING:at_kernel/trace/trace.c:#register_tracer() | 0 | 2 | |
| BUG:KASan:out_of_bounds_access_in_vsnprintf_at_addr | 0 | 1 | |
| BUG:KASan:user-memory-access_on_address(null) | 0 | 1 | |
| BUG:KASan:use_after_free_in__switch_to_xtra_at_addr | 0 | 1 | |
| BUG:KASan:use_after_free_in_memcpy_at_addr | 0 | 1 | |
| RIP:memcpy_orig | 0 | 1 | |
| kernel_BUG_at_arch/x86/kernel/nmi.c | 0 | 1 | |
| WARNING:at_kernel/sched/core.c:#preempt_count_sub() | 0 | 74 | 2 |
| WARNING:at_kernel/trace/ring_buffer.c:#ring_buffer_unlock_commit() | 0 | 1 | |
| RIP:ftrace_push_return_trace | 0 | 1 | 1 |
| RIP:ftrace_likely_update | 0 | 1 | |
| RIP:parameqn | 0 | 8 | 1 |
| backtrace:parse_args | 0 | 8 | 1 |
| RIP:notifier_call_chain | 0 | 2 | |
| WARNING:at_kernel/sched/core.c:#preempt_count_add() | 0 | 0 | 1 |
| BUG_task_struct(Tainted:G_B):kasan:bad_access_detected | 0 | 0 | 2 |
| RIP:rb_next | 0 | 0 | 8 |
| INFO:rcu_sched_self-detected_stall_on_CPU | 0 | 0 | 1 |
| IP-Config:Auto-configuration_of_network_failed | 0 | 0 | 1 |
| WARNING:at_include/linux/uaccess.h:#is_prefetch() | 0 | 0 | 1 |
| WARNING:at_include/linux/uaccess.h:#show_regs() | 0 | 0 | 1 |
+-----------------------------------------------------------------------------+------------+------------+---------------+

[ 0.324653] Testing tracer irqsoff: PASSED
[ 0.407082] Testing tracer function_graph:
[ 1.288675] ==================================================================
[ 1.289000] BUG: KASan: out of bounds access in trace_graph_entry+0x90/0x260 at addr ffff88000d717e48
[ 1.289000] Read of size 4 by task swapper/0/1
[ 1.289000] =============================================================================
[ 1.289000] BUG task_struct (Not tainted): kasan: bad access detected
[ 1.289000] -----------------------------------------------------------------------------
[ 1.289000]
[ 1.289000] Disabling lock debugging due to kernel taint
[ 1.289000] INFO: Slab 0xffffea000035c400 objects=14 used=14 fp=0x (null) flags=0x1ffe00000004080
[ 1.289000] INFO: Object 0xffff88000d717d20 @offset=32032 fp=0x (null)
[ 1.289000]
[ 1.289000] Bytes b4 ffff88000d717d10: 90 7d 71 0d 00 88 ff ff 98 5a fe 82 ff ff ff ff .}q......Z......
[ 1.289000] Object ffff88000d717d20: 00 00 00 00 00 00 00 00 40 1e 31 81 ff ff ff ff [email protected].....
[ 1.289000] Object ffff88000d717d30: 48 7e 71 0d 00 88 ff ff 48 7e 71 0d 00 88 ff ff H~q.....H~q.....
[ 1.289000] Object ffff88000d717d40: 48 7e 71 0d 00 88 ff ff 04 00 00 00 00 00 00 00 H~q.............
[ 1.289000] Object ffff88000d717d50: 00 00 00 00 00 00 00 00 40 1e 31 81 ff ff ff ff [email protected].....
[ 1.289000] Object ffff88000d717d60: d0 7d 71 0d 00 88 ff ff 00 00 71 0d 00 88 ff ff .}q.......q.....
[ 1.289000] Object ffff88000d717d70: 40 7e 71 0d 00 88 ff ff 80 0b 89 84 ff ff ff ff @~q.............
[ 1.289000] Object ffff88000d717d80: 70 a2 1a 81 ff ff ff ff 00 00 00 00 00 00 00 00 p...............
[ 1.289000] Object ffff88000d717d90: d0 7d 71 0d 00 88 ff ff 98 5a fe 82 ff ff ff ff .}q......Z......
[ 1.289000] Object ffff88000d717da0: 00 00 00 00 00 00 00 00 02 00 00 00 00 00 00 00 ................
[ 1.289000] Object ffff88000d717db0: 20 7e 71 0d 00 88 ff ff f9 4e 31 81 ff ff ff ff ~q......N1.....
[ 1.289000] Object ffff88000d717dc0: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 1.289000] Object ffff88000d717dd0: 10 7e 71 0d 00 88 ff ff 40 1e 31 81 ff ff ff ff [email protected].....
[ 1.289000] Object ffff88000d717de0: 50 7e 71 0d 00 88 ff ff 00 00 71 0d 00 88 ff ff P~q.......q.....
[ 1.289000] Object ffff88000d717df0: 00 00 00 00 00 00 00 00 68 7f 71 0d 00 88 ff ff ........h.q.....
[ 1.661390] kernel tried to execute NX-protected page - exploit attempt? (uid: 0)
[ 1.661521] BUG: unable to handle kernel paging request at ffff88000da1ef38
[ 1.661691] IP: [<ffff88000da1ef38>] 0xffff88000da1ef38
[ 1.661908] PGD 50c2067 PUD 50c3067 PMD 800000000da001e3
[ 1.661972] Thread overran stack, or stack corrupted
[ 1.662000] Oops: 0011 [#1] PREEMPT SMP KASAN
[ 1.662000] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G B 4.1.0-rc4-00025-gb30f0e3 #1
[ 1.662000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 1.662000] task: ffffffff838176c0 ti: ffffffff83800000 task.ti: ffffffff83800000
[ 1.662000] RIP: 0010:[<ffff88000da1ef38>] [<ffff88000da1ef38>] 0xffff88000da1ef38
[ 1.662000] RSP: 0000:ffffffff837f9638 EFLAGS: 00010246
[ 1.662000] RAX: fffffbfff07f6b91 RBX: ffff88000da1ef38 RCX: dffffc0000000000
[ 1.662000] RDX: 00000000014aac94 RSI: 0000000000000008 RDI: ffff88000da1ef10
[ 1.662000] RBP: ffff88000da1ef10 R08: fffffbfff0846cbd R09: ffffffff842365ef
[ 1.662000] R10: 00000000014aacb1 R11: 00000000014da8df R12: ffff88000da19870
[ 1.662000] R13: 0000000000000008 R14: 00000000049c09bd R15: ffffffff837f96b8
[ 1.662000] FS: 0000000000000000(0000) GS:ffff88000da00000(0000) knlGS:0000000000000000
[ 1.662000] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 1.662000] CR2: ffff88000da1ef38 CR3: 000000000380c000 CR4: 00000000000006b4
[ 1.662000] Stack:
[ 1.662000] ffffffff82fe3e32 ffffffff837f96b8 00000000049c09bd 0000000000000008
[ 1.662000] ffff88000da19870 ffff88000da1ef10 ffff88000da1ef38 ffffffff83817b01
[ 1.662000] ffff88000d7111e0 ffffffff838176c0 ffffffff83800000 0000000000000002
[ 1.662000] Call Trace:
[ 1.662000] <UNK>
[ 1.662000] Code: 00 00 00 c0 76 81 83 ff ff ff ff c0 76 81 83 ff ff ff ff 50 62 71 0d 00 88 ff ff e4 72 fb ff 00 00 00 00 00 00 00 00 00 00 00 00 <01> 00 00 00 00 00 00 00 3d a1 03 63 00 00 00 00 3d a1 03 63 00
[ 1.662000] RIP [<ffff88000da1ef38>] 0xffff88000da1ef38
[ 1.662000] RSP <ffffffff837f9638>
[ 1.662000] CR2: ffff88000da1ef38
[ 1.662000] ---[ end trace 0e292f67bf70a095 ]---
[ 1.662000] Kernel panic - not syncing: Fatal exception

git bisect start e430ccc59c12619af6196c34707d3afa0728ca27 ba155e2d21f6bf05de86a78dbe5bfd8757604a65 --
git bisect good 11db825cd35b971e6ef0a7421b74dd0eda99b218 # 17:57 242+ 12 Merge remote-tracking branch 'hwmon-staging/hwmon-next'
git bisect good 8365bad28b9f8cf0bec48912bbb06fd656acfc00 # 18:08 242+ 7 Merge remote-tracking branch 'audit/next'
git bisect bad 29597791edec5a20b0e4d4fdc4f4bc709f283ad5 # 18:08 0- 145 Merge remote-tracking branch 'char-misc/char-misc-next'
git bisect bad cc2d26ffa3ce0eb218b85bd2996d1394166c0155 # 18:09 0- 140 Merge remote-tracking branch 'kvm/linux-next'
git bisect bad eec2f49932b2d459faaac8fae117066a5f917b3a # 18:09 0- 187 Merge remote-tracking branch 'clockevents/clockevents/next'
git bisect good 18b6e4be5ccd87d2585217672f51065af165b0b2 # 18:23 242+ 2 Merge remote-tracking branch 'mailbox/mailbox-for-next'
git bisect good 11e1652325b01b40b4a9b2781c94fdbe49110072 # 18:32 242+ 26 Merge remote-tracking branch 'spi/for-next'
git bisect bad 97354d679ddfd564a61fcb2466139783db36bb97 # 18:32 0- 188 Merge remote-tracking branch 'tip/auto-latest'
git bisect bad c41f3eb84e58355b9209c961328067e2c23a1aeb # 18:32 0- 237 Merge branch 'timers/nohz'
git bisect good 17186ccda374ae02ef231cbbc8f1825e7c19ddbd # 18:32 300+ 0 perf/x86/intel: Make WARN()ings consistent
git bisect bad b7794610cdd2533e303de1027c1a4d9576875e51 # 18:32 0- 222 manual merge of sched/core
git bisect bad 06931e62246844c73fba24d7aeb4a5dc897a2739 # 18:33 0- 227 sched/topology: Rename topology_thread_cpumask() to topology_sibling_cpumask()
git bisect bad 8bcbde5480f9777f8b74d71493722c663e22c21b # 18:33 0- 231 sched/preempt, mm/fault: Count pagefault_disable() levels in pagefault_disabled
git bisect good 7110744516276e906f9197e2857d026eb2343393 # 18:33 300+ 0 sched, timer: Use the atomic task_cputime in thread_group_cputimer
git bisect good a22ae718067c233af790b8690b3d8f6190859ead # 18:42 300+ 22 Merge tag 'v4.1-rc4' into sched/core, before applying new patches
git bisect good 90b62b5129d5cb50f62f40e684de7a1961e57197 # 07:10 300+ 18 sched/preempt: Rename PREEMPT_CHECK_OFFSET to PREEMPT_DISABLE_OFFSET
git bisect bad e017cf21ae82e0b36f026b22083a8ae67926f465 # 07:10 0- 194 sched/preempt: Fix out of date comment
git bisect bad b30f0e3ffedfa52b1d67a302ae5860c49998e5e2 # 07:11 0- 889 sched/preempt: Optimize preemption operations on __schedule() callers
# first bad commit: [b30f0e3ffedfa52b1d67a302ae5860c49998e5e2] sched/preempt: Optimize preemption operations on __schedule() callers
git bisect good 90b62b5129d5cb50f62f40e684de7a1961e57197 # 07:35 900+ 24 sched/preempt: Rename PREEMPT_CHECK_OFFSET to PREEMPT_DISABLE_OFFSET
# extra tests with DEBUG_INFO
git bisect bad b30f0e3ffedfa52b1d67a302ae5860c49998e5e2 # 07:47 40- 42 sched/preempt: Optimize preemption operations on __schedule() callers
# extra tests on HEAD of next/master
git bisect bad e430ccc59c12619af6196c34707d3afa0728ca27 # 07:47 0- 59 Add linux-next specific files for 20150601
# extra tests on tree/branch next/master
git bisect good f0939c364ffe7dc377c4d7946360f99cb7fc867b # 20:10 900+ 1 Add linux-next specific files for 20150611
# extra tests on tree/branch linus/master
git bisect good df5f4158415b6fc4a2d683c6fdc806be6da176bc # 09:09 900+ 16 Merge branch 'drm-fixes' of git://people.freedesktop.org/~airlied/linux
# extra tests on tree/branch next/master
git bisect good d9b5ec5b1b4d4055e256674de4a5337f6a66d284 # 22:21 900+ 19 Add linux-next specific files for 20150612


This script may reproduce the error.

----------------------------------------------------------------------------
#!/bin/bash

kernel=$1

kvm=(
qemu-system-x86_64
-enable-kvm
-cpu kvm64
-kernel $kernel
-m 300
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0
-boot order=nc
-no-reboot
-watchdog i6300esb
-rtc base=localtime
-serial stdio
-display none
-monitor null
)

append=(
hung_task_panic=1
earlyprintk=ttyS0,115200
systemd.log_level=err
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
console=ttyS0,115200
console=tty0
vga=normal
root=/dev/ram0
rw
drbd.minor_count=8
)

"${kvm[@]}" --append "${append[*]}"
----------------------------------------------------------------------------

Thanks,
Fengguang


Attachments:
(No filename) (22.51 kB)
dmesg-quantal-ivb41-52:20150606010148:x86_64-randconfig-v0-06021206:4.1.0-rc4-00025-gb30f0e3:1 (53.02 kB)
dmesg-quantal-intel12-11:20150606002017:x86_64-randconfig-v0-06021206:4.1.0-rc4-00024-g90b62b51:1 (44.89 kB)
config-4.1.0-rc4-00025-gb30f0e3 (87.00 kB)
Download all attachments

2015-06-14 12:33:42

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: [sched/preempt] BUG: KASan: out of bounds access in trace_graph_entry at addr ffff88000d717e48

On Sun, Jun 14, 2015 at 04:55:59PM +0800, Fengguang Wu wrote:
> Hi Frederic,
>
> FYI, there are a number more bug messages showing up after this commit
>
> git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
>
> commit b30f0e3ffedfa52b1d67a302ae5860c49998e5e2
> Author: Frederic Weisbecker <[email protected]>
> AuthorDate: Tue May 12 16:41:49 2015 +0200
> Commit: Ingo Molnar <[email protected]>
> CommitDate: Tue May 19 08:39:12 2015 +0200
>
> sched/preempt: Optimize preemption operations on __schedule() callers
>
> __schedule() disables preemption and some of its callers
> (the preempt_schedule*() family) also set PREEMPT_ACTIVE.
>
> So we have two preempt_count() modifications that could be performed
> at once.
>
> Lets remove the preemption disablement from __schedule() and pull
> this responsibility to its callers in order to optimize preempt_count()
> operations in a single place.
>
> Suggested-by: Linus Torvalds <[email protected]>
> Signed-off-by: Frederic Weisbecker <[email protected]>
> Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Thomas Gleixner <[email protected]>
> Link: http://lkml.kernel.org/r/[email protected]
> Signed-off-by: Ingo Molnar <[email protected]>

Do you still see that issue after latest tip:/sched/core. I fixed it a few days ago with:

9a92e3dc6ad02208a014d0d8404ebbd697e3d5ef (preempt: Reorganize the notrace definitions a bit)
4eaca0a887eaee04fc7a3866d0f5b51b34030dfa (preempt: Use preempt_schedule_context() as the official tracing preemption point)
be690035df893385ceaac2323b29be1fb7f2a67f (sched: Make preempt_schedule_context() function-tracing safe)

But maybe there are other issues remaining.

Thanks.

2015-06-15 00:57:53

by Fengguang Wu

[permalink] [raw]
Subject: Re: [sched/preempt] BUG: KASan: out of bounds access in trace_graph_entry at addr ffff88000d717e48

Hi Frederic,

On Sun, Jun 14, 2015 at 02:33:32PM +0200, Frederic Weisbecker wrote:
> On Sun, Jun 14, 2015 at 04:55:59PM +0800, Fengguang Wu wrote:
> > Hi Frederic,
> >
> > FYI, there are a number more bug messages showing up after this commit
> >
> > git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
> >
> > commit b30f0e3ffedfa52b1d67a302ae5860c49998e5e2
> > Author: Frederic Weisbecker <[email protected]>
> > AuthorDate: Tue May 12 16:41:49 2015 +0200
> > Commit: Ingo Molnar <[email protected]>
> > CommitDate: Tue May 19 08:39:12 2015 +0200
> >
> > sched/preempt: Optimize preemption operations on __schedule() callers
> >
> > __schedule() disables preemption and some of its callers
> > (the preempt_schedule*() family) also set PREEMPT_ACTIVE.
> >
> > So we have two preempt_count() modifications that could be performed
> > at once.
> >
> > Lets remove the preemption disablement from __schedule() and pull
> > this responsibility to its callers in order to optimize preempt_count()
> > operations in a single place.
> >
> > Suggested-by: Linus Torvalds <[email protected]>
> > Signed-off-by: Frederic Weisbecker <[email protected]>
> > Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
> > Cc: Peter Zijlstra <[email protected]>
> > Cc: Thomas Gleixner <[email protected]>
> > Link: http://lkml.kernel.org/r/[email protected]
> > Signed-off-by: Ingo Molnar <[email protected]>
>
> Do you still see that issue after latest tip:/sched/core. I fixed it a few days ago with:
>
> 9a92e3dc6ad02208a014d0d8404ebbd697e3d5ef (preempt: Reorganize the notrace definitions a bit)
> 4eaca0a887eaee04fc7a3866d0f5b51b34030dfa (preempt: Use preempt_schedule_context() as the official tracing preemption point)
> be690035df893385ceaac2323b29be1fb7f2a67f (sched: Make preempt_schedule_context() function-tracing safe)
>
> But maybe there are other issues remaining.

The tip sched/core HEAD looks perfect now -- 1000 boots are all fine
except for 2 OOM errors, which look like noises.

Thanks,
Fengguang

2015-06-16 13:20:56

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: [sched/preempt] BUG: KASan: out of bounds access in trace_graph_entry at addr ffff88000d717e48

On Mon, Jun 15, 2015 at 08:57:04AM +0800, Fengguang Wu wrote:
> Hi Frederic,
>
> On Sun, Jun 14, 2015 at 02:33:32PM +0200, Frederic Weisbecker wrote:
> > On Sun, Jun 14, 2015 at 04:55:59PM +0800, Fengguang Wu wrote:
> > > Hi Frederic,
> > >
> > > FYI, there are a number more bug messages showing up after this commit
> > >
> > > git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
> > >
> > > commit b30f0e3ffedfa52b1d67a302ae5860c49998e5e2
> > > Author: Frederic Weisbecker <[email protected]>
> > > AuthorDate: Tue May 12 16:41:49 2015 +0200
> > > Commit: Ingo Molnar <[email protected]>
> > > CommitDate: Tue May 19 08:39:12 2015 +0200
> > >
> > > sched/preempt: Optimize preemption operations on __schedule() callers
> > >
> > > __schedule() disables preemption and some of its callers
> > > (the preempt_schedule*() family) also set PREEMPT_ACTIVE.
> > >
> > > So we have two preempt_count() modifications that could be performed
> > > at once.
> > >
> > > Lets remove the preemption disablement from __schedule() and pull
> > > this responsibility to its callers in order to optimize preempt_count()
> > > operations in a single place.
> > >
> > > Suggested-by: Linus Torvalds <[email protected]>
> > > Signed-off-by: Frederic Weisbecker <[email protected]>
> > > Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
> > > Cc: Peter Zijlstra <[email protected]>
> > > Cc: Thomas Gleixner <[email protected]>
> > > Link: http://lkml.kernel.org/r/[email protected]
> > > Signed-off-by: Ingo Molnar <[email protected]>
> >
> > Do you still see that issue after latest tip:/sched/core. I fixed it a few days ago with:
> >
> > 9a92e3dc6ad02208a014d0d8404ebbd697e3d5ef (preempt: Reorganize the notrace definitions a bit)
> > 4eaca0a887eaee04fc7a3866d0f5b51b34030dfa (preempt: Use preempt_schedule_context() as the official tracing preemption point)
> > be690035df893385ceaac2323b29be1fb7f2a67f (sched: Make preempt_schedule_context() function-tracing safe)
> >
> > But maybe there are other issues remaining.
>
> The tip sched/core HEAD looks perfect now -- 1000 boots are all fine
> except for 2 OOM errors, which look like noises.

Oh great! Thanks a lot!