1:06 p.m.
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
git://internal_merge_and_test_tree devel-catchup-201612130113
commit 3640269b04db583c0033678c9114f3406a0f489b
Author: Matt Fleming <matt(a)codeblueprint.co.uk>
AuthorDate: Wed Sep 21 14:38:13 2016 +0100
Commit: Peter Zijlstra <peterz(a)infradead.org>
CommitDate: Mon Dec 12 16:42:09 2016 +0100
sched/core: Add debug code to catch missing update_rq_clock()
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)
Cc: Yuyang Du <yuyang.du(a)intel.com>
Cc: Ingo Molnar <mingo(a)kernel.org>
Cc: Luca Abeni <luca.abeni(a)unitn.it>
Cc: Wanpeng Li <wanpeng.li(a)hotmail.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work(a)gmail.com>
Cc: Byungchul Park <byungchul.park(a)lge.com>
Cc: Frederic Weisbecker <fweisbec(a)gmail.com>
Cc: Thomas Gleixner <tglx(a)linutronix.de>
Cc: Jan Kara <jack(a)suse.cz>
Cc: Rik van Riel <riel(a)redhat.com>
Cc: Petr Mladek <pmladek(a)suse.com>
Cc: Mel Gorman <mgorman(a)techsingularity.net>
Cc: Mike Galbraith <umgwanakikbuti(a)gmail.com>
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>
Link: http://lkml.kernel.org/r/20160921133813.31976-8-matt@codeblueprint.co.uk
+-------------------------------------------------+------------+------------+-------------+
| | 1f68d84f91 | 3640269b04 | v4.9_121315
|
+-------------------------------------------------+------------+------------+-------------+
| boot_successes | 460 | 0 | 6
|
| boot_failures | 82 | 140 | 7
|
| BUG:kernel_reboot-without-warning_in_test_stage | 79 | 0 | 2
|
| invoked_oom-killer:gfp_mask=0x | 1 | |
|
| Mem-Info | 1 | |
|
| BUG:workqueue_lockup-pool | 2 | |
|
| WARNING:at_kernel/sched/sched.h:#rq_clock_task | 0 | 140 | 4
|
| calltrace:_do_fork | 0 | 140 |
|
| calltrace:torture_shuffle | 0 | 0 | 4
|
| BUG:unable_to_handle_kernel | 0 | 0 | 1
|
| Oops | 0 | 0 | 1
|
| RIP:strcmp | 0 | 0 | 1
|
| calltrace:intel_pmc_ipc_init | 0 | 0 | 1
|
| Kernel_panic-not_syncing:Fatal_exception | 0 | 0 | 1
|
+-------------------------------------------------+------------+------------+-------------+
[ 0.031009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.033107] Freeing SMP alternatives memory: 12K (ffffffff81b7b000 - ffffffff81b7e000)
[ 0.035721] ------------[ cut here ]------------
[ 0.036000] WARNING: CPU: 0 PID: 0 at kernel/sched/sched.h:804 rq_clock_task+0x51/0x70
[ 0.036000] rq->clock_update_flags < RQCF_ACT_SKIP
[ 0.036000] Modules linked in:
[ 0.036000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.9.0-rc8-00183-g3640269 #1
[ 0.036000] ffffffff81a03cc0 ffffffff8122375f ffffffff81a0f580 ffffffff81a03d28
[ 0.036000] 0000000000000000 ffffffff81098591 ffffffff81a03d00 ffffffff8106a63f
[ 0.036000] 0000000981a03d98 ffffffff81793092 ffff88001e6146c0 0000000000000000
[ 0.036000] Call Trace:
[ 0.036000] [<ffffffff8122375f>] dump_stack+0xb0/0x101
[ 0.036000] [<ffffffff81098591>] ? rq_clock_task+0x51/0x70
[ 0.036000] [<ffffffff8106a63f>] __warn+0x107/0x127
[ 0.036000] [<ffffffff8106a6c4>] warn_slowpath_fmt+0x65/0x6e
[ 0.036000] [<ffffffff81098591>] rq_clock_task+0x51/0x70
[ 0.036000] [<ffffffff81098e3c>] update_load_avg+0x4c/0x263
[ 0.036000] [<ffffffff8109908c>] attach_entity_cfs_rq+0x39/0x92
[ 0.036000] [<ffffffff8109908c>] ? attach_entity_cfs_rq+0x39/0x92
[ 0.036000] [<ffffffff81099efd>] post_init_entity_util_avg+0xa9/0xac
[ 0.036000] [<ffffffff810935a3>] wake_up_new_task+0x59/0xc3
[ 0.036000] [<ffffffff81069ab8>] _do_fork+0x1bc/0x283
[ 0.036000] [<ffffffff8123add0>] ? find_next_bit+0x45/0x51
[ 0.036000] [<ffffffff814cef26>] ? rest_init+0x16d/0x16d
[ 0.036000] [<ffffffff81069bb3>] kernel_thread+0x34/0x3b
[ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
[ 0.036000] [<ffffffff814ceddb>] rest_init+0x22/0x16d
[ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
[ 0.036000] [<ffffffff81aac10f>] start_kernel+0x4dc/0x4e9
[ 0.036000] [<ffffffff81aab120>] ? early_idt_handler_array+0x120/0x120
[ 0.036000] [<ffffffff81aab416>] x86_64_start_reservations+0x2a/0x2c
[ 0.036000] [<ffffffff81aab4fe>] x86_64_start_kernel+0xe6/0xf3
[ 0.036000] ---[ end trace 0000000000000000 ]---
[ 0.037197] smpboot: APIC(0) Converting physical 0 to logical package 0
git bisect start e84cc2b92f0301361c20d97210099d4ac7731196
69973b830859bc6529a7a0468ba0d80ee5117826 --
git bisect bad f50e71f8660649cc8ec74d0a35273ff627929a08 # 23:13 11- 5 Merge
'linux-review/Madalin-Bucur/powerpc-fsl-dts-add-QMan-and-BMan-portal-nodes-on-t1023rdb/20161207-034042'
into devel-hourly-2016121315
git bisect bad 1d169e013b8e9d7fa3e3af5af6e52145a8de114a # 23:30 10- 4 Merge
'miklos-vfs/misc' into devel-hourly-2016121315
git bisect good 068926f19428d7a4e9281fc4b8ec9d8a0856e26d # 00:10 132+ 29 Merge
'linux-review/Grygorii-Strashko/usb-dwc3-omap-fix-race-of-pm-runtime-with-irq-handler-in-probe/20161213-053605'
into devel-hourly-2016121315
git bisect bad 43d1a53eec3973cdabbd54215aff4aa5a70ad1b2 # 00:22 4- 3 Merge
'pinchartl-media/omapdrm/devel' into devel-hourly-2016121315
git bisect bad 85f539d220e9fb2c9c0b6f542527b6e4f3f0fe71 # 00:32 6- 2 Merge
'hwmon/watchdog-next' into devel-hourly-2016121315
git bisect good 2c22794aa932c328633337d1720bbc873d36d26f # 01:24 131+ 17 Merge
'ipmi/for-next' into devel-hourly-2016121315
git bisect bad f185bb4654ea9a94553b07ac1fa76a277750c278 # 01:44 9- 1 Merge
'linux-review/Himanshu-Madhani/qla2xxx-Feature-updaes-for-driver/20161213-064500'
into devel-hourly-2016121315
git bisect bad 1e09f27041eb80acbde6571e8896115174343d72 # 02:08 2- 2 Merge
'peterz-queue/sched/debug' into devel-hourly-2016121315
git bisect good 89ccba78fbed8c572404f77be3192323d163fa40 # 02:49 132+ 22 Merge
'linux-review/Andrew-Lunn/net-dsa-mv88e6xxx-Fix-opps-when-adding-vlan-bridge/20161212-095458'
into devel-hourly-2016121315
git bisect bad 08118b281b2052030a69fb727c9e8d7a8d29e2d4 # 03:01 12- 8 sched:
Add missing update_rq_clock() call for task_hot().
git bisect good 1f68d84f911b456c68d32adf83f0ad8e524a370e # 03:22 140+ 30
sched/fair: Push rq lock pin/unpin into idle_balance()
git bisect bad 73bc83482218caf16d09407e1547299dfc862613 # 03:38 0- 1 sched:
Add missing update_rq_clock() in post_init_entity_util_avg().
git bisect bad 3640269b04db583c0033678c9114f3406a0f489b # 03:59 0- 2
sched/core: Add debug code to catch missing update_rq_clock()
# first bad commit: [3640269b04db583c0033678c9114f3406a0f489b] sched/core: Add debug code
to catch missing update_rq_clock()
git bisect good 1f68d84f911b456c68d32adf83f0ad8e524a370e # 04:54 392+ 80
sched/fair: Push rq lock pin/unpin into idle_balance()
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad 3640269b04db583c0033678c9114f3406a0f489b # 05:03 0- 3
sched/core: Add debug code to catch missing update_rq_clock()
# extra tests on HEAD of linux-devel/devel-hourly-2016121315
git bisect bad e84cc2b92f0301361c20d97210099d4ac7731196 # 05:03 0- 7 0day
head guard for 'devel-hourly-2016121315'
# extra tests on tree/branch linux-devel/devel-catchup-201612130113
git bisect bad 072c2c3b3de7190fee772271e11b1d2003a5c8c5 # 06:50 0- 1 0day
head guard for 'devel-catchup-201612130113'
# extra tests on tree/branch linus/master
git bisect good b92e09bb5bf4db65aeb8ca0094fdd5142ed54451 # 09:49 396+ 61 Merge
branch 'for-4.10' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/libata
# extra tests on tree/branch linux-next/master
git bisect good c791961310927f816796c23bf197627621333652 # 10:05 392+ 392 Add
linux-next specific files for 20161213
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
7:35 p.m.
On Wed, Dec 14, 2016 at 10:06:48AM +0800, kernel test robot wrote:
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
git://internal_merge_and_test_tree devel-catchup-201612130113
commit 3640269b04db583c0033678c9114f3406a0f489b
Author: Matt Fleming <matt(a)codeblueprint.co.uk>
AuthorDate: Wed Sep 21 14:38:13 2016 +0100
Commit: Peter Zijlstra <peterz(a)infradead.org>
CommitDate: Mon Dec 12 16:42:09 2016 +0100
sched/core: Add debug code to catch missing update_rq_clock()
[ 0.031009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.033107] Freeing SMP alternatives memory: 12K (ffffffff81b7b000 -
ffffffff81b7e000)
[ 0.035721] ------------[ cut here ]------------
[ 0.036000] WARNING: CPU: 0 PID: 0 at kernel/sched/sched.h:804
rq_clock_task+0x51/0x70
[ 0.036000] rq->clock_update_flags < RQCF_ACT_SKIP
[ 0.036000] Modules linked in:
[ 0.036000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.9.0-rc8-00183-g3640269 #1
[ 0.036000] ffffffff81a03cc0 ffffffff8122375f ffffffff81a0f580 ffffffff81a03d28
[ 0.036000] 0000000000000000 ffffffff81098591 ffffffff81a03d00 ffffffff8106a63f
[ 0.036000] 0000000981a03d98 ffffffff81793092 ffff88001e6146c0 0000000000000000
[ 0.036000] Call Trace:
[ 0.036000] [<ffffffff8122375f>] dump_stack+0xb0/0x101
[ 0.036000] [<ffffffff81098591>] ? rq_clock_task+0x51/0x70
[ 0.036000] [<ffffffff8106a63f>] __warn+0x107/0x127
[ 0.036000] [<ffffffff8106a6c4>] warn_slowpath_fmt+0x65/0x6e
[ 0.036000] [<ffffffff81098591>] rq_clock_task+0x51/0x70
[ 0.036000] [<ffffffff81098e3c>] update_load_avg+0x4c/0x263
[ 0.036000] [<ffffffff8109908c>] attach_entity_cfs_rq+0x39/0x92
[ 0.036000] [<ffffffff8109908c>] ? attach_entity_cfs_rq+0x39/0x92
[ 0.036000] [<ffffffff81099efd>] post_init_entity_util_avg+0xa9/0xac
[ 0.036000] [<ffffffff810935a3>] wake_up_new_task+0x59/0xc3
[ 0.036000] [<ffffffff81069ab8>] _do_fork+0x1bc/0x283
[ 0.036000] [<ffffffff8123add0>] ? find_next_bit+0x45/0x51
[ 0.036000] [<ffffffff814cef26>] ? rest_init+0x16d/0x16d
[ 0.036000] [<ffffffff81069bb3>] kernel_thread+0x34/0x3b
[ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
[ 0.036000] [<ffffffff814ceddb>] rest_init+0x22/0x16d
[ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
[ 0.036000] [<ffffffff81aac10f>] start_kernel+0x4dc/0x4e9
[ 0.036000] [<ffffffff81aab120>] ? early_idt_handler_array+0x120/0x120
[ 0.036000] [<ffffffff81aab416>] x86_64_start_reservations+0x2a/0x2c
[ 0.036000] [<ffffffff81aab4fe>] x86_64_start_kernel+0xe6/0xf3
[ 0.036000] ---[ end trace 0000000000000000 ]---
[ 0.037197] smpboot: APIC(0) Converting physical 0 to logical package 0
git bisect start e84cc2b92f0301361c20d97210099d4ac7731196
69973b830859bc6529a7a0468ba0d80ee5117826 --
git bisect bad f50e71f8660649cc8ec74d0a35273ff627929a08 # 23:13 11- 5 Merge
'linux-review/Madalin-Bucur/powerpc-fsl-dts-add-QMan-and-BMan-portal-nodes-on-t1023rdb/20161207-034042'
into devel-hourly-2016121315
git bisect bad 1d169e013b8e9d7fa3e3af5af6e52145a8de114a # 23:30 10- 4 Merge
'miklos-vfs/misc' into devel-hourly-2016121315
git bisect good 068926f19428d7a4e9281fc4b8ec9d8a0856e26d # 00:10 132+ 29 Merge
'linux-review/Grygorii-Strashko/usb-dwc3-omap-fix-race-of-pm-runtime-with-irq-handler-in-probe/20161213-053605'
into devel-hourly-2016121315
git bisect bad 43d1a53eec3973cdabbd54215aff4aa5a70ad1b2 # 00:22 4- 3 Merge
'pinchartl-media/omapdrm/devel' into devel-hourly-2016121315
git bisect bad 85f539d220e9fb2c9c0b6f542527b6e4f3f0fe71 # 00:32 6- 2 Merge
'hwmon/watchdog-next' into devel-hourly-2016121315
git bisect good 2c22794aa932c328633337d1720bbc873d36d26f # 01:24 131+ 17 Merge
'ipmi/for-next' into devel-hourly-2016121315
git bisect bad f185bb4654ea9a94553b07ac1fa76a277750c278 # 01:44 9- 1 Merge
'linux-review/Himanshu-Madhani/qla2xxx-Feature-updaes-for-driver/20161213-064500'
into devel-hourly-2016121315
git bisect bad 1e09f27041eb80acbde6571e8896115174343d72 # 02:08 2- 2 Merge
'peterz-queue/sched/debug' into devel-hourly-2016121315
So as per that entry it appears you got the commit from my tree.
That tree also contains the below commit, right after the one you
fingered. And the above stacktrace looks very much like the one here,
no?
commit 73bc83482218caf16d09407e1547299dfc862613
Author: Peter Zijlstra <peterz(a)infradead.org>
Date: Mon Oct 3 16:20:59 2016 +0200
sched: Add missing update_rq_clock() in post_init_entity_util_avg().
WARNING: CPU: 0 PID: 0 at ../kernel/sched/sched.h:797
post_init_entity_util_avg+0x175/0x180
rq->clock_update_flags < RQCF_ACT_SKIPdModules linked in:
dCPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.8.0-00637-g67223e2-dirty #552
dHardware name: Intel Corporation S2600GZ/S2600GZ, BIOS
SE5C600.86B.02.02.0002.122320131210 12/23/2013
ffffffff82203d88 ffffffff81615285 ffffffff82203dd8 0000000000000000
ffffffff82203dc8 ffffffff810d5bab 0000031d8220b4c0 0000000000000200
ffff88042f817b68 ffff88042dbf0080 ffff88042f817b00 ffffffff82515440
Call Trace:
[<ffffffff81615285>] dump_stack+0x67/0x92
[<ffffffff810d5bab>] __warn+0xcb/0xf0
[<ffffffff810d5c1f>] warn_slowpath_fmt+0x4f/0x60
[<ffffffff8110fa25>] post_init_entity_util_avg+0x175/0x180
[<ffffffff811013d7>] wake_up_new_task+0xf7/0x240
[<ffffffff810d4eea>] _do_fork+0x12a/0x3b0
[<ffffffff8118a35f>] ? ftrace_process_locs+0x32f/0x430
[<ffffffff810d5199>] kernel_thread+0x29/0x30
[<ffffffff81a7d862>] rest_init+0x22/0x90
[<ffffffff8239ff28>] start_kernel+0x403/0x410
[<ffffffff8239f28f>] x86_64_start_reservations+0x2a/0x2c
[<ffffffff8239f409>] x86_64_start_kernel+0x178/0x18b
4---[ end trace dab466e88c65317a ]---
Signed-off-by: Peter Zijlstra (Intel) <peterz(a)infradead.org>
diff --git a/kernel/sched/core.c b/kernel/sched/core.c
index 32028a15f02d..cff3ac1247dd 100644
--- a/kernel/sched/core.c
+++ b/kernel/sched/core.c
@@ -2581,6 +2581,7 @@ void wake_up_new_task(struct task_struct *p)
__set_task_cpu(p, select_task_rq(p, task_cpu(p), SD_BALANCE_FORK, 0));
#endif
rq = __task_rq_lock(p, &rf);
+ update_rq_clock(rq);
post_init_entity_util_avg(&p->se);
activate_task(rq, p, 0);
diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index faf80e10d662..972b67622922 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -9267,6 +9267,7 @@ void online_fair_sched_group(struct task_group *tg)
se = tg->se[i];
raw_spin_lock_irq(&rq->lock);
+ update_rq_clock(rq);
attach_entity_cfs_rq(se);
sync_throttle(tg, i);
raw_spin_unlock_irq(&rq->lock);
9:36 p.m.
On Wed, 14 Dec, at 09:35:44AM, Peter Zijlstra wrote:
So as per that entry it appears you got the commit from my tree.
That tree also contains the below commit, right after the one you
fingered. And the above stacktrace looks very much like the one here,
no?
Should we rearrange these commits so that we fixup the missing
update_rq_clock() calls before enabling the SCHED_WARN_ON(), so as not
to break bisection?
9:52 p.m.
On Wed, Dec 14, 2016 at 09:35:44AM +0100, Peter Zijlstra wrote:
On Wed, Dec 14, 2016 at 10:06:48AM +0800, kernel test robot wrote:
> Greetings,
>
> 0day kernel testing robot got the below dmesg and the first bad commit is
>
> git://internal_merge_and_test_tree devel-catchup-201612130113
>
> commit 3640269b04db583c0033678c9114f3406a0f489b
> Author: Matt Fleming <matt(a)codeblueprint.co.uk>
> AuthorDate: Wed Sep 21 14:38:13 2016 +0100
> Commit: Peter Zijlstra <peterz(a)infradead.org>
> CommitDate: Mon Dec 12 16:42:09 2016 +0100
>
> sched/core: Add debug code to catch missing update_rq_clock()
>
> [ 0.031009] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
> [ 0.033107] Freeing SMP alternatives memory: 12K (ffffffff81b7b000 -
ffffffff81b7e000)
> [ 0.035721] ------------[ cut here ]------------
> [ 0.036000] WARNING: CPU: 0 PID: 0 at kernel/sched/sched.h:804
rq_clock_task+0x51/0x70
> [ 0.036000] rq->clock_update_flags < RQCF_ACT_SKIP
> [ 0.036000] Modules linked in:
> [ 0.036000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.9.0-rc8-00183-g3640269 #1
> [ 0.036000] ffffffff81a03cc0 ffffffff8122375f ffffffff81a0f580 ffffffff81a03d28
> [ 0.036000] 0000000000000000 ffffffff81098591 ffffffff81a03d00 ffffffff8106a63f
> [ 0.036000] 0000000981a03d98 ffffffff81793092 ffff88001e6146c0 0000000000000000
> [ 0.036000] Call Trace:
> [ 0.036000] [<ffffffff8122375f>] dump_stack+0xb0/0x101
> [ 0.036000] [<ffffffff81098591>] ? rq_clock_task+0x51/0x70
> [ 0.036000] [<ffffffff8106a63f>] __warn+0x107/0x127
> [ 0.036000] [<ffffffff8106a6c4>] warn_slowpath_fmt+0x65/0x6e
> [ 0.036000] [<ffffffff81098591>] rq_clock_task+0x51/0x70
> [ 0.036000] [<ffffffff81098e3c>] update_load_avg+0x4c/0x263
> [ 0.036000] [<ffffffff8109908c>] attach_entity_cfs_rq+0x39/0x92
> [ 0.036000] [<ffffffff8109908c>] ? attach_entity_cfs_rq+0x39/0x92
> [ 0.036000] [<ffffffff81099efd>] post_init_entity_util_avg+0xa9/0xac
> [ 0.036000] [<ffffffff810935a3>] wake_up_new_task+0x59/0xc3
> [ 0.036000] [<ffffffff81069ab8>] _do_fork+0x1bc/0x283
> [ 0.036000] [<ffffffff8123add0>] ? find_next_bit+0x45/0x51
> [ 0.036000] [<ffffffff814cef26>] ? rest_init+0x16d/0x16d
> [ 0.036000] [<ffffffff81069bb3>] kernel_thread+0x34/0x3b
> [ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
> [ 0.036000] [<ffffffff814ceddb>] rest_init+0x22/0x16d
> [ 0.036000] [<ffffffff81aaec89>] ? trap_init+0x20e/0x20e
> [ 0.036000] [<ffffffff81aac10f>] start_kernel+0x4dc/0x4e9
> [ 0.036000] [<ffffffff81aab120>] ? early_idt_handler_array+0x120/0x120
> [ 0.036000] [<ffffffff81aab416>] x86_64_start_reservations+0x2a/0x2c
> [ 0.036000] [<ffffffff81aab4fe>] x86_64_start_kernel+0xe6/0xf3
> [ 0.036000] ---[ end trace 0000000000000000 ]---
> [ 0.037197] smpboot: APIC(0) Converting physical 0 to logical package 0
>
> git bisect start e84cc2b92f0301361c20d97210099d4ac7731196
69973b830859bc6529a7a0468ba0d80ee5117826 --
> git bisect bad f50e71f8660649cc8ec74d0a35273ff627929a08 # 23:13 11- 5
Merge
'linux-review/Madalin-Bucur/powerpc-fsl-dts-add-QMan-and-BMan-portal-nodes-on-t1023rdb/20161207-034042'
into devel-hourly-2016121315
> git bisect bad 1d169e013b8e9d7fa3e3af5af6e52145a8de114a # 23:30 10- 4
Merge 'miklos-vfs/misc' into devel-hourly-2016121315
> git bisect good 068926f19428d7a4e9281fc4b8ec9d8a0856e26d # 00:10 132+ 29
Merge
'linux-review/Grygorii-Strashko/usb-dwc3-omap-fix-race-of-pm-runtime-with-irq-handler-in-probe/20161213-053605'
into devel-hourly-2016121315
> git bisect bad 43d1a53eec3973cdabbd54215aff4aa5a70ad1b2 # 00:22 4- 3
Merge 'pinchartl-media/omapdrm/devel' into devel-hourly-2016121315
> git bisect bad 85f539d220e9fb2c9c0b6f542527b6e4f3f0fe71 # 00:32 6- 2
Merge 'hwmon/watchdog-next' into devel-hourly-2016121315
> git bisect good 2c22794aa932c328633337d1720bbc873d36d26f # 01:24 131+ 17
Merge 'ipmi/for-next' into devel-hourly-2016121315
> git bisect bad f185bb4654ea9a94553b07ac1fa76a277750c278 # 01:44 9- 1
Merge
'linux-review/Himanshu-Madhani/qla2xxx-Feature-updaes-for-driver/20161213-064500'
into devel-hourly-2016121315
> git bisect bad 1e09f27041eb80acbde6571e8896115174343d72 # 02:08 2- 2
Merge 'peterz-queue/sched/debug' into devel-hourly-2016121315
So as per that entry it appears you got the commit from my tree.
Yes.
That tree also contains the below commit, right after the one you
fingered. And the above stacktrace looks very much like the one here,
no?
commit 73bc83482218caf16d09407e1547299dfc862613
Author: Peter Zijlstra <peterz(a)infradead.org>
Date: Mon Oct 3 16:20:59 2016 +0200
sched: Add missing update_rq_clock() in post_init_entity_util_avg().
It looks that commit still has the warning, however with a different
call trace:
Here is the dmesg:
[ 0.356906] TSC deadline timer enabled
[ 0.357541] smpboot: CPU0: GenuineIntel Intel Core Processor (Haswell) (family: 0x6,
model: 0x3c, stepping: 0x1)
[ 0.359332] Performance Events: no PMU driver, software events only.
[ 0.589465] ------------[ cut here ]------------
[ 0.590588] WARNING: CPU: 0 PID: 1 at kernel/sched/sched.h:804 rq_clock_task+0x51/0x70
[ 0.592998] rq->clock_update_flags < RQCF_ACT_SKIP
[ 0.594107] Modules linked in:
[ 0.594912] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.9.0-rc8-00184-g73bc834 #1
[ 0.596614] ffff88001e943b70 ffffffff81223767 ffffffff1e93c040 ffff88001e943bd8
[ 0.598568] 0000000000000000 ffffffff81098599 ffff88001e943bb0 ffffffff8106a63f
[ 0.600513] 000000091e943c48 ffffffff81793103 ffff88001fa146c0 0000000000000000
[ 0.602456] Call Trace:
[ 0.603089] [<ffffffff81223767>] dump_stack+0xb0/0x101
[ 0.604301] [<ffffffff81098599>] ? rq_clock_task+0x51/0x70
[ 0.605613] [<ffffffff8106a63f>] __warn+0x107/0x127
[ 0.606922] [<ffffffff8106a6c4>] warn_slowpath_fmt+0x65/0x6e
[ 0.608275] [<ffffffff81098599>] rq_clock_task+0x51/0x70
[ 0.609562] [<ffffffff81098e44>] update_load_avg+0x4c/0x263
[ 0.610994] [<ffffffff810992f5>] switched_from_fair+0x5b/0x143
[ 0.612425] [<ffffffff810992f5>] ? switched_from_fair+0x5b/0x143
[ 0.613897] [<ffffffff8109022e>] check_class_changed+0x24/0x55
[ 0.615273] [<ffffffff81094122>] __sched_setscheduler+0x5f0/0x680
[ 0.616784] [<ffffffff814d5000>] ? _raw_spin_unlock_bh+0x3/0x33
[ 0.618237] [<ffffffff81094212>] _sched_setscheduler+0x60/0x62
[ 0.619605] [<ffffffff810942bb>] sched_setscheduler_nocheck+0xb/0xd
[ 0.621181] [<ffffffff81094309>] sched_set_stop_task+0x4c/0x7f
[ 0.622580] [<ffffffff810e90be>] cpu_stop_create+0x2b/0x2d
[ 0.624015] [<ffffffff8108ee2a>] __smpboot_create_thread+0xf0/0x103
[ 0.625608] [<ffffffff8108f0dc>]
smpboot_register_percpu_thread_cpumask+0x7c/0xfa
[ 0.627482] [<ffffffff81ac7334>] cpu_stop_init+0x88/0xb4
[ 0.628828] [<ffffffff81ac72ac>] ? ikconfig_init+0x56/0x56
[ 0.630156] [<ffffffff810004b1>] do_one_initcall+0xa5/0x17e
[ 0.631513] [<ffffffff81013ec3>] ? print_cpu_info+0xc0/0xc5
[ 0.632919] [<ffffffff810155f5>] ? set_mtrr_aps_delayed_init+0x40/0x43
[ 0.634491] [<ffffffff81aac198>] kernel_init_freeable+0x7c/0x208
[ 0.635994] [<ffffffff814cef26>] ? rest_init+0x16d/0x16d
[ 0.637269] [<ffffffff814cef35>] kernel_init+0xf/0x153
[ 0.638526] [<ffffffff814cef26>] ? rest_init+0x16d/0x16d
[ 0.639884] [<ffffffff814d582a>] ret_from_fork+0x2a/0x40
[ 0.641163] ---[ end trace 0000000000000000 ]---
[ 0.398389] x86: Booted up 1 node, 1 CPUs
[ 0.399084] smpboot: Total of 1 processors activated (5387.01 BogoMIPS)
Regards,
Fengguang
2104
days inactive
2104
days old
3 comments
4 participants
participants (4)
-
Fengguang Wu -
kernel test robot
-
Matt Fleming -
Peter Zijlstra