Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
commit cb42c9a3ebbbb23448c3f9a25417fae6309b1a92
Author: Matt Fleming <matt(a)codeblueprint.co.uk>
AuthorDate: Wed Sep 21 14:38:13 2016 +0100
Commit: Ingo Molnar <mingo(a)kernel.org>
CommitDate: Sat Jan 14 11:29:35 2017 +0100
sched/core: Add debugging code to catch missing update_rq_clock() calls
There's no diagnostic checks for figuring out when we've accidentally
missed update_rq_clock() calls. Let's add some by piggybacking on the
rq_*pin_lock() wrappers.
The idea behind the diagnostic checks is that upon pining rq lock the
rq clock should be updated, via update_rq_clock(), before anybody
reads the clock with rq_clock() or rq_clock_task().
The exception to this rule is when updates have explicitly been
disabled with the rq_clock_skip_update() optimisation.
There are some functions that only unpin the rq lock in order to grab
some other lock and avoid deadlock. In that case we don't need to
update the clock again and the previous diagnostic state can be
carried over in rq_repin_lock() by saving the state in the rq_flags
context.
Since this patch adds a new clock update flag and some already exist
in rq::clock_skip_update, that field has now been renamed. An attempt
has been made to keep the flag manipulation code small and fast since
it's used in the heart of the __schedule() fast path.
For the !CONFIG_SCHED_DEBUG case the only object code change (other
than addresses) is the following change to reset RQCF_ACT_SKIP inside
of __schedule(),
- c7 83 38 09 00 00 00 movl $0x0,0x938(%rbx)
- 00 00 00
+ 83 a3 38 09 00 00 fc andl $0xfffffffc,0x938(%rbx)
Suggested-by: Peter Zijlstra <peterz(a)infradead.org>
Signed-off-by: Matt Fleming <matt(a)codeblueprint.co.uk>
Signed-off-by: Peter Zijlstra (Intel) <peterz(a)infradead.org>
Cc: Byungchul Park <byungchul.park(a)lge.com>
Cc: Frederic Weisbecker <fweisbec(a)gmail.com>
Cc: Jan Kara <jack(a)suse.cz>
Cc: Linus Torvalds <torvalds(a)linux-foundation.org>
Cc: Luca Abeni <luca.abeni(a)unitn.it>
Cc: Mel Gorman <mgorman(a)techsingularity.net>
Cc: Mike Galbraith <efault(a)gmx.de>
Cc: Mike Galbraith <umgwanakikbuti(a)gmail.com>
Cc: Petr Mladek <pmladek(a)suse.com>
Cc: Rik van Riel <riel(a)redhat.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work(a)gmail.com>
Cc: Thomas Gleixner <tglx(a)linutronix.de>
Cc: Wanpeng Li <wanpeng.li(a)hotmail.com>
Cc: Yuyang Du <yuyang.du(a)intel.com>
Link:
http://lkml.kernel.org/r/20160921133813.31976-8-matt@codeblueprint.co.uk
Signed-off-by: Ingo Molnar <mingo(a)kernel.org>
+-------------------------------------------------------+------------+------------+------------------+
| | 2fb8d36787 | cb42c9a3eb |
v4.10-rc8_021720 |
+-------------------------------------------------------+------------+------------+------------------+
| boot_successes | 698 | 181 | 15
|
| boot_failures | 0 | 56 | 40
|
| WARNING:at_kernel/sched/sched.h:#assert_clock_updated | 0 | 56 | 11
|
| BUG:unable_to_handle_kernel | 0 | 0 | 12
|
| Oops | 0 | 0 | 12
|
| Kernel_panic-not_syncing:Fatal_exception | 0 | 0 | 12
|
| BUG:kernel_hang_in_test_stage | 0 | 0 | 25
|
+-------------------------------------------------------+------------+------------+------------------+
[ 20.993502] RIO: rio_register_scan for mport_id=-1
[ 21.019923] Unregister pv shared memory for cpu 0
[ 21.031223] ------------[ cut here ]------------
[ 21.031922] WARNING: CPU: 0 PID: 9 at kernel/sched/sched.h:804
assert_clock_updated+0x31/0x33
[ 21.041531] rq->clock_update_flags < RQCF_ACT_SKIP
[ 21.041538] CPU: 0 PID: 9 Comm: migration/0 Not tainted 4.10.0-rc3-00256-gcb42c9a #1
[ 21.043339] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.9.3-20161025_171302-gandalf 04/01/2014
[ 21.052837] Call Trace:
[ 21.053210] dump_stack+0x7e/0xa6
[ 21.053701] ? assert_clock_updated+0x31/0x33
[ 21.054442] __warn+0x104/0x124
[ 21.054915] warn_slowpath_fmt+0x6a/0x73
[ 21.055491] assert_clock_updated+0x31/0x33
[ 21.056209] update_load_avg+0x3e/0x3ca
[ 21.060834] set_next_entity+0x4b/0x7e
[ 21.061387] ? set_next_entity+0x4b/0x7e
[ 21.061969] pick_next_task_fair+0x124/0x34a
[ 21.062593] ? kvm_clock_read+0x25/0x2e
[ 21.063162] ? kvm_sched_clock_read+0x9/0x12
[ 21.063805] pick_next_task+0x5f/0x7e
[ 21.076406] sched_cpu_dying+0xaa/0x1c1
[ 21.076977] ? sched_cpu_starting+0x54/0x54
[ 21.077588] cpuhp_invoke_callback+0x95/0x1ed
[ 21.078231] take_cpu_down+0x8e/0xb9
[ 21.078757] multi_cpu_stop+0xae/0xfa
[ 21.079301] ? cpu_stop_park+0x4b/0x4b
[ 21.079861] cpu_stopper_thread+0xb4/0x14c
[ 21.084530] smpboot_thread_fn+0x247/0x267
[ 21.085138] kthread+0x123/0x133
[ 21.085611] ? sort_range+0x35/0x35
[ 21.086130] ? init_completion+0x2d/0x2d
[ 21.086702] ret_from_fork+0x25/0x30
[ 21.087231] ---[ end trace d9c8c7fb767368d4 ]---
[ 21.092591] CPU 0 is now offline
git bisect start defec150f97b01a4c5cea17d7f13cc9cc272afcd
7089db84e356562f8ba737c29e472cc42d530dbc --
git bisect bad 7e8a6cc7fd0c7694c2073c5ea020814053a5f9f2 # 05:50 17- 3 Merge
'renesas/devel' into devel-hourly-2017021720
git bisect bad 226df0db92608d18eef51950c232fd2a0d99549c # 06:09 21- 1 Merge
'linux-review/Thomas-Falcon/ibmvnic-Fix-initial-MTU-settings/20170215-003803' into
devel-hourly-2017021720
git bisect bad dcd3e166307bdd11fe55ba738f9abcd338e113c0 # 06:35 18- 3 Merge
'linux-review/David-Sterba/More-GFP_NOFS-removals/20170213-215650' into
devel-hourly-2017021720
git bisect bad 2124cad846daf1e0e8b8d585ceb752b60f6f9831 # 06:58 8- 1 Merge
'linux-review/Dmitry-V-Levin/uapi-fix-linux-if_pppol2tp-h-userspace-compilation-errors/20170215-102728'
into devel-hourly-2017021720
git bisect bad 85261d19c2140b123211515d559c4f3e8098cec9 # 07:09 3- 2 Merge
'j.anaszewski-leds/for-4.12' into devel-hourly-2017021720
git bisect bad ce5b5f0f94dde879772c2d87cba2b284413cf1d7 # 07:39 13- 4 Merge
'linux-review/Dmitry-V-Levin/uapi-fix-linux-mqueue-h-userspace-compilation-errors/20170216-045036'
into devel-hourly-2017021720
git bisect good 917936d67c30cd3c47a068cb74b38c333203d6f2 # 08:03 236+ 0 Merge
'linux-review/Zhu-Yanjun/IB-ipoib-Remove-redudant-label/20170214-164858' into
devel-hourly-2017021720
git bisect bad b8bdc9d37f0c746b9f5162b15547e4e16442a9b6 # 08:19 16- 6 Merge
'ntb/ntb-next' into devel-hourly-2017021720
git bisect good c202829a464b140893b2466caefddda88ae2a6f7 # 08:42 236+ 0 Merge
'linux-review/Alexander-Alemayhu/bpf-reduce-compiler-warnings-by-adding-fallthrough-comments/20170214-070641'
into devel-hourly-2017021720
git bisect bad 13ac2637633ce2917d0835318ccec3c5404e067c # 08:59 37- 11 Merge
'linux-review/Matt-Fleming/sched-loadavg-Avoid-loadavg-spikes-caused-by-delayed-NO_HZ-accounting/20170217-202034'
into devel-hourly-2017021720
git bisect bad ba03ce822db234f8acb559de4a317a5c1f95c029 # 09:11 9- 2
sched/cputime: Remove the unused INIT_CPUTIME macro
git bisect bad 5680d8094ffa9e5cfc81afdd865027ee6417c263 # 09:27 31- 5
sched/clock: Provide better clock continuity
git bisect good d8ac897137a230ec351269f6378017f2decca512 # 09:41 236+ 0
sched/core: Add wrappers for lockdep_(un)pin_lock()
git bisect good 3bed5e2166a5e433bf62162f3cd3c5174d335934 # 09:55 233+ 1
sched/core: Add missing update_rq_clock() call for task_hot()
git bisect bad 12907fbb1a691807bb0420a27126e15934cb7954 # 10:06 10- 6
sched/clock, clocksource: Add optional cs::mark_unstable() method
git bisect bad cb42c9a3ebbbb23448c3f9a25417fae6309b1a92 # 10:16 4- 5
sched/core: Add debugging code to catch missing update_rq_clock() calls
git bisect good 2fb8d36787affe26f3536c3d8ec094995a48037d # 10:35 235+ 0
sched/core: Add missing update_rq_clock() call in set_user_nice()
# first bad commit: [cb42c9a3ebbbb23448c3f9a25417fae6309b1a92] sched/core: Add debugging
code to catch missing update_rq_clock() calls
git bisect good 2fb8d36787affe26f3536c3d8ec094995a48037d # 10:44 696+ 0
sched/core: Add missing update_rq_clock() call in set_user_nice()
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad cb42c9a3ebbbb23448c3f9a25417fae6309b1a92 # 10:57 6- 1
sched/core: Add debugging code to catch missing update_rq_clock() calls
# extra tests on HEAD of linux-devel/devel-hourly-2017021720
git bisect bad defec150f97b01a4c5cea17d7f13cc9cc272afcd # 10:57 0- 40 0day
head guard for 'devel-hourly-2017021720'
# extra tests on tree/branch linux-next/master
git bisect bad 4ce4a759a3e221b5265ebd03c2f8888b69a7cf3e # 11:10 2- 1 Add
linux-next specific files for 20170217
# extra tests on tree/branch linus/master
git bisect good 6dc39c50e4aeb769c8ae06edf2b1a732f3490913 # 12:55 691+ 3 Merge
branch 'for-linus' of git://git.kernel.dk/linux-block
# extra tests on tree/branch linux-next/master
git bisect bad 4ce4a759a3e221b5265ebd03c2f8888b69a7cf3e # 12:56 0- 99 Add
linux-next specific files for 20170217
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation