Date:	Sat, 22 Nov 2014 10:47:15 -0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	"pang.xunlei" <pang.xunlei@...aro.org>
Cc:	John Stultz <john.stultz@...aro.org>, LKP <lkp@...org>,
	linux-kernel@...r.kernel.org
Subject: Re: [time] WARNING: CPU: 0 PID: 1 at kernel/time/timekeeping.c:1337
 update_wall_time()

Hi Xunlei,

FYI, here is another bisect result.

https://git.linaro.org/people/john.stultz/linux.git fortglx/3.19/time

commit 59fa38d60ca4bc7a2efffae1b40aa7960374ef9d
Author:     pang.xunlei <pang.xunlei@...aro.org>
AuthorDate: Wed Oct 8 15:03:34 2014 +0800
Commit:     John Stultz <john.stultz@...aro.org>
CommitDate: Thu Oct 23 21:26:24 2014 -0700

    time: Avoid possible NTP adjustment mult overflow.
    
    Ideally, __clocksource_updatefreq_scale, selects the largest shift
    value possible for a clocksource. This results in the mult memember of
    struct clocksource being particularly large, although not so large
    that NTP would adjust the clock to cause it to overflow.
    
    That said, nothing actually prohibits an overflow from occuring, its
    just that it "shouldn't" occur.
    
    So while very unlikely, and so far never observed, the value of
    (cs->mult+cs->maxadj) may have a chance to reach very near 0xFFFFFFFF,
    so there is a possibility it may overflow when doing NTP positive
    adjustment
    
    See the following detail: When NTP slewes the clock, kernel goes
    through update_wall_time()->...->timekeeping_apply_adjustment():
    	tk->tkr.mult += mult_adj;
    
    Since there is no guard against it, its possible tk->tkr.mult may
    overflow during this operation.
    
    This patch avoids any possible mult overflow by judging the overflow
    case before adding mult_adj to mult, also adds the WARNING message
    when capturing such case.
    
    Signed-off-by: pang.xunlei <pang.xunlei@...aro.org>
    [jstultz: Reworded commit message]
    Signed-off-by: John Stultz <john.stultz@...aro.org>

+---------------------------------------------------------+------------+------------+------------+
|                                                         | 3953d54968 | 59fa38d60c | 59fa38d60c |
+---------------------------------------------------------+------------+------------+------------+
| boot_successes                                          | 60         | 0          | 0          |
| boot_failures                                           | 0          | 11         | 11         |
| WARNING:at_kernel/time/timekeeping.c:update_wall_time() | 0          | 11         | 11         |
| backtrace:event_create_dir                              | 0          | 11         | 11         |
| backtrace:event_trace_init                              | 0          | 11         | 11         |
| backtrace:kernel_init_freeable                          | 0          | 11         | 11         |
+---------------------------------------------------------+------------+------------+------------+

[    0.489933] Warning: could not register all branches stats
[    0.491673] Warning: could not register annotated branches stats
[    0.500012] ------------[ cut here ]------------
[    0.500012] WARNING: CPU: 0 PID: 1 at kernel/time/timekeeping.c:1337 update_wall_time+0x5d8/0x8dc()
[    0.500012] Modules linked in:
[    0.500012] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.18.0-rc1-00274-g59fa38d #496
[    0.500012] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[    0.500012]  0000000000000009 ffff880013a03e58 ffffffff818a545a 0000000000000000
[    0.500012]  0000000000000000 ffff880013a03e98 ffffffff810cd4d6 0000000100000000
[    0.500012]  ffffffff811659ec 0000000000002201 0000000000000001 0000000000000001
[    0.500012] Call Trace:
[    0.500012]  <IRQ>  [<ffffffff818a545a>] dump_stack+0x7e/0xaa
[    0.500012]  [<ffffffff810cd4d6>] warn_slowpath_common+0x98/0xb2
[    0.500012]  [<ffffffff811659ec>] ? update_wall_time+0x5d8/0x8dc
[    0.500012]  [<ffffffff810cd593>] warn_slowpath_null+0x1a/0x1c
[    0.500012]  [<ffffffff811659ec>] update_wall_time+0x5d8/0x8dc
[    0.500012]  [<ffffffff8116c91c>] tick_periodic+0x9d/0xc6
[    0.500012]  [<ffffffff8116cb91>] ? tick_handle_periodic+0x27/0xa7
[    0.500012]  [<ffffffff8116cb91>] tick_handle_periodic+0x27/0xa7
[    0.500012]  [<ffffffff8103ba1d>] local_apic_timer_interrupt+0x6c/0x70
[    0.500012]  [<ffffffff818b3de3>] smp_apic_timer_interrupt+0x40/0x52
[    0.500012]  [<ffffffff818b2a82>] apic_timer_interrupt+0x72/0x80
[    0.500012]  <EOI>  [<ffffffff811244ec>] ? __lock_acquire+0x7f4/0xc24
[    0.500012]  [<ffffffff811249e8>] ? lock_acquire+0xcc/0x12b
[    0.500012]  [<ffffffff81255903>] ? __d_instantiate+0x33/0x1c7
[    0.500012]  [<ffffffff818b0712>] _raw_spin_lock+0x36/0x84
[    0.500012]  [<ffffffff81255903>] ? __d_instantiate+0x33/0x1c7
[    0.500012]  [<ffffffff81255903>] __d_instantiate+0x33/0x1c7
[    0.500012]  [<ffffffff8125826f>] d_instantiate+0x7f/0xb1
[    0.500012]  [<ffffffff8126d12e>] simple_lookup+0x76/0x84
[    0.500012]  [<ffffffff81243b9a>] lookup_real+0x6d/0xb6
[    0.500012]  [<ffffffff812452b5>] __lookup_hash+0x42/0x49
[    0.500012]  [<ffffffff8124a95c>] lookup_one_len+0x224/0x233
[    0.500012]  [<ffffffff81388d70>] __create_file+0xbf/0x24c
[    0.500012]  [<ffffffff81388f1e>] debugfs_create_file+0x21/0x23
[    0.500012]  [<ffffffff81191990>] trace_create_file+0x12/0x33
[    0.500012]  [<ffffffff8119a176>] event_create_dir+0x36b/0x411
[    0.500012]  [<ffffffff82741dcf>] event_trace_init+0x1b9/0x23c
[    0.500012]  [<ffffffff82741c16>] ? event_trace_enable+0x170/0x170
[    0.500012]  [<ffffffff81000391>] do_one_initcall+0x14d/0x257
[    0.500012]  [<ffffffff810f3a28>] ? parse_args+0x352/0x433
[    0.500012]  [<ffffffff82718565>] kernel_init_freeable+0x111/0x1da
[    0.500012]  [<ffffffff8189c993>] ? rest_init+0xc7/0xc7
[    0.500012]  [<ffffffff8189c9a1>] kernel_init+0xe/0x157
[    0.500012]  [<ffffffff818b1a7c>] ret_from_fork+0x7c/0xb0
[    0.500012]  [<ffffffff8189c993>] ? rest_init+0xc7/0xc7
[    0.500012] ---[ end trace e756a48c2bb7ada1 ]---
[    0.713574] FS-Cache: Loaded

git bisect start 59fa38d60ca4bc7a2efffae1b40aa7960374ef9d 816fb4175c29b16948fb24a92053bea1e79908cc --
git bisect good 3953d54968793e0db56c8a7ffbdedc2ba9cb6d82  # 14:37     20+      0  time: Rename udelay_test.c to test_udelay.c
# first bad commit: [59fa38d60ca4bc7a2efffae1b40aa7960374ef9d] time: Avoid possible NTP adjustment mult overflow.
git bisect good 3953d54968793e0db56c8a7ffbdedc2ba9cb6d82  # 14:41     60+      0  time: Rename udelay_test.c to test_udelay.c
git bisect  bad b6adbbd9a2171aa4764ea8a56c4c1a5f63f2cca6  # 14:41      0-      2  Merge commit '039348d8c131329742e80e37122f11d230fd270b' into fortglx/3.19/time
git bisect good fc14f9c1272f62c3e8d01300f52467c0d9af50f9  # 14:44     60+      8  Linux 3.18-rc5
git bisect good 5b83d7ad910674ab8c059f3a5ff9c2b0c0a4b685  # 14:48     60+      0  Add linux-next specific files for 20141120


This script may reproduce the error.

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

kernel=$1
initrd=yocto-minimal-x86_64.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 320
	-smp 1
	-net nic,vlan=1,model=e1000
	-net user,vlan=1
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-rtc base=localtime
	-serial stdio
	-display none
	-monitor null 
)

append=(
	hung_task_panic=1
	earlyprintk=ttyS0,115200
	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-yocto-kbuild-13:20141121140855:x86_64-randconfig-ha2-1109:3.18.0-rc1-00274-g59fa38d:496" of type "text/plain" (68607 bytes)

_______________________________________________
LKP mailing list
LKP@...ux.intel.com

Powered by blists - more mailing lists