Greetings, 0day kernel testing robot got the below dmesg and the first bad commit is git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git ftrace/core commit a4543a2fa9ef31d6d0f854a4e14f8f82e7996d8d Author: Steven Rostedt (Red Hat) <rostedt(a)goodmis.org&gt; AuthorDate: Fri May 29 09:40:18 2015 -0400 Commit: Steven Rostedt <rostedt(a)goodmis.org&gt; CommitDate: Mon Jul 20 22:30:48 2015 -0400 ring-buffer: Get timestamp after event is allocated Move the capturing of the timestamp to after an event is allocated. If the event is not a commit (where it is an event that preempted another event), then no timestamp is needed, because the delta of nested events is always zero. If the event starts on a new page, no delta needs to be calculated as the full timestamp will be added to the page header, and the event will have a delta of zero. Now if the event requires a time extend (the delta does not fit in the 27 bit delta slot in the header), then the event is discarded, the length is extended to hold the TIME_EXTEND event that allows for a 59 bit delta, and the commit is tried again. If the event can't be discarded (another event came in after it), then the TIME_EXTEND is added directly to the allocated event and the rest of the event is given padding. Signed-off-by: Steven Rostedt <rostedt(a)goodmis.org&gt; +-------------------------------------------------------------------------+------------+------------+---------------+ | | 9826b2733a | a4543a2fa9 | next-20150902 | +-------------------------------------------------------------------------+------------+------------+---------------+ | boot_successes | 1218 | 290 | 164 | | boot_failures | 6 | 22 | 15 | | WARNING:at_kernel/locking/lockdep.c:#__lock_acquire() | 2 | 4 | | | BUG:spinlock_lockup_suspected_on_CPU | 2 | 4 | | | EIP_is_at_default_send_IPI_mask_logical | 2 | 4 | | | backtrace:fd_timer_workfn | 2 | 4 | | | WARNING:at_arch/x86/include/asm/fpu/internal.h:#fpu__restore() | 4 | 2 | | | WARNING:at_kernel/trace/ring_buffer_benchmark.c:#ring_buffer_consumer() | 0 | 16 | 14 | | backtrace:ring_buffer_consumer_thread | 0 | 15 | 14 | | WARNING:at_kernel/trace/ring_buffer.c:#rb_get_reader_page() | 0 | 2 | 2 | | Out_of_memory:Kill_process | 0 | 0 | 1 | | WARNING:at_kernel/trace/ring_buffer.c:#rb_buffer_peek() | 0 | 0 | 1 | | BUG:kernel_test_crashed | 0 | 0 | 1 | +-------------------------------------------------------------------------+------------+------------+---------------+ [ 70.767702] e1000: Copyright (c) 1999-2006 Intel Corporation. [ 72.904685] Writes: Total: 2 Max/Min: 0/0 Fail: 0 [ 75.675942] ------------[ cut here ]------------ [ 75.676625] WARNING: CPU: 0 PID: 44 at kernel/trace/ring_buffer.c:3597 rb_get_reader_page+0x2fa/0x330() [ 75.678123] CPU: 0 PID: 44 Comm: rb_consumer Not tainted 4.2.0-rc3-00006-ga4543a2 #1 [ 75.699195] 00000000 00000000 00000000 8a2afe30 8d17df4c 00000000 00000000 8d96e0dc [ 75.700448] 8a2afe64 8b6c3acf 8d964eb8 00000000 0000002c 8d96e0dc 00000e0d 8b8301fa [ 75.701531] 00000e0d 8b8301fa 8b39e9a8 8a779120 00000000 8a2afe74 8b6c3cbc 00000009 [ 75.702701] Call Trace: [ 75.703055] [<8d17df4c>] dump_stack+0x128/0x229 [ 75.703670] [<8b6c3acf>] warn_slowpath_common+0xff/0x190 [ 75.724489] [<8b8301fa>] ? rb_get_reader_page+0x2fa/0x330 [ 75.725245] [<8b8301fa>] ? rb_get_reader_page+0x2fa/0x330 [ 75.725934] [<8b6c3cbc>] warn_slowpath_null+0x3c/0x50 [ 75.726542] [<8b8301fa>] rb_get_reader_page+0x2fa/0x330 [ 75.727259] [<8b831058>] rb_buffer_peek+0x38/0x200 [ 75.727919] [<8b83696c>] ring_buffer_consume+0x18c/0x320 [ 75.728633] [<8b838724>] ring_buffer_consumer+0xa4/0x7e0 [ 75.749413] [<8b838ed7>] ring_buffer_consumer_thread+0x77/0x180 [ 75.750367] [<8b838e60>] ? ring_buffer_consumer+0x7e0/0x7e0 [ 75.751165] [<8b715e1e>] kthread+0x19e/0x1b0 [ 75.751685] [<8b838e60>] ? ring_buffer_consumer+0x7e0/0x7e0 [ 75.752364] [<8d1a4401>] ret_from_kernel_thread+0x21/0x30 [ 75.753148] [<8b715c80>] ? __kthread_unpark+0xf0/0xf0 [ 75.753864] ---[ end trace 44bfef31f1ea89ea ]--- [ 75.774637] ------------[ cut here ]------------ git bisect start 0e658695ffd1b8e0396ae3e4ee8bcea8ae597242 c13dcf9f2d6f5f06ef1bf79ec456df614c5e058b -- git bisect good b62d8a4c717845f7fb342f6bd27f92ca98d81361 # 15:36 310+ 0 Merge remote-tracking branch 'powerpc/next' git bisect good f59b6da5d01bc115b125c763797c952a5285e122 # 16:28 310+ 2 Merge remote-tracking branch 'mfd/for-mfd-next' git bisect bad 63fc7bf49627827b84b1e1c60eb360ba9c5241df # 17:07 296- 12 Merge remote-tracking branch 'chrome-platform/for-next' git bisect good bc79ac755db73f2a717d9a92d9e60721c904a37f # 17:51 310+ 1 Merge remote-tracking branch 'spi/for-next' git bisect bad d14784f470ce781e13c238b749d9a87584b57785 # 18:16 270- 18 Merge remote-tracking branch 'kvm-arm/next' git bisect good 73caaee8c8c96377b841bf2bf2d04479b45aca94 # 18:49 310+ 2 Merge remote-tracking branch 'irqchip/irqchip/for-next' git bisect bad e36b9c2f38dcac192c97e153b8c972b99c30c16b # 19:09 134- 9 Merge remote-tracking branch 'ftrace/for-next' git bisect bad d90fd77402d3de56a9ca3df04e5d868d0979dc59 # 20:12 309- 14 ring-buffer: Reorganize function locations git bisect good fcc742eaad7cbcbbb2a96edc8f1d22adbaa804cb # 20:56 310+ 4 ring-buffer: Add event descriptor to simplify passing data git bisect bad a4543a2fa9ef31d6d0f854a4e14f8f82e7996d8d # 21:30 249- 14 ring-buffer: Get timestamp after event is allocated git bisect good 9826b2733a4399149072058a11f611357479229d # 22:18 310+ 1 ring-buffer: Move the adding of the extended timestamp out of line # first bad commit: [a4543a2fa9ef31d6d0f854a4e14f8f82e7996d8d] ring-buffer: Get timestamp after event is allocated git bisect good 9826b2733a4399149072058a11f611357479229d # 00:38 910+ 6 ring-buffer: Move the adding of the extended timestamp out of line # extra tests with DEBUG_INFO git bisect bad a4543a2fa9ef31d6d0f854a4e14f8f82e7996d8d # 01:49 417- 17 ring-buffer: Get timestamp after event is allocated # extra tests on HEAD of linux-devel/devel-spot-201508241448 git bisect good 64e4b678a39e77f59c0095f301bb88eeb43fb233 # 04:02 910+ 11 0day head guard for 'devel-spot-201508241448' # extra tests on tree/branch trace/ftrace/core git bisect good b7dc42fd79390c074e2bff3b172b585d5c2d80c2 # 06:13 910+ 12 ring-buffer: Revert "ring-buffer: Get timestamp after event is allocated" # extra tests on tree/branch linus/master git bisect good 51e771c0d25b43d0f12b2c7c01939942becbbe28 # 08:22 902+ 4 Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/dtor/input # extra tests on tree/branch linux-next/master git bisect bad a672f924628456a5ebc13ad26c23e99e57d9b645 # 08:46 197- 14 Add linux-next specific files for 20150903 This script may reproduce the error. ---------------------------------------------------------------------------- #!/bin/bash kernel=$1 initrd=yocto-minimal-i386.cgz wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd kvm=( qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -kernel $kernel -initrd $initrd -m 256 -smp 1 -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[*]}" ---------------------------------------------------------------------------- --- 0-DAY kernel test infrastructure Open Source Technology Center https://lists.01.org/pipermail/lkp Intel Corporation