lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:	Sun, 14 Jun 2015 16:55:59 +0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	Frederic Weisbecker <fweisbec@...il.com>
Cc:	fengguang.wu@...el.com, Ingo Molnar <mingo@...nel.org>,
	"Peter Zijlstra (Intel)" <peterz@...radead.org>, LKP <lkp@...org>,
	LKML <linux-kernel@...r.kernel.org>
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 <fweisbec@...il.com>
AuthorDate: Tue May 12 16:41:49 2015 +0200
Commit:     Ingo Molnar <mingo@...nel.org>
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 <torvalds@...ux-foundation.org>
    Signed-off-by: Frederic Weisbecker <fweisbec@...il.com>
    Signed-off-by: Peter Zijlstra (Intel) <peterz@...radead.org>
    Cc: Peter Zijlstra <peterz@...radead.org>
    Cc: Thomas Gleixner <tglx@...utronix.de>
    Link: http://lkml.kernel.org/r/1431441711-29753-5-git-send-email-fweisbec@gmail.com
    Signed-off-by: Ingo Molnar <mingo@...nel.org>

===================================================
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#@...set=#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#@...set=#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  ........@.......
[    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  ........@.......
[    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  .~q.....@.......
[    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

View attachment "dmesg-quantal-ivb41-52:20150606010148:x86_64-randconfig-v0-06021206:4.1.0-rc4-00025-gb30f0e3:1" of type "text/plain" (54288 bytes)

View attachment "dmesg-quantal-intel12-11:20150606002017:x86_64-randconfig-v0-06021206:4.1.0-rc4-00024-g90b62b51:1" of type "text/plain" (45963 bytes)

View attachment "config-4.1.0-rc4-00025-gb30f0e3" of type "text/plain" (89092 bytes)

Powered by blists - more mailing lists