linux-kernel - [console_unlock] WARNING: at kernel/sched/clock.c:219 sched_clock

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 for Android: free password hash cracker in your pocket

[<prev] [next>] [thread-next>] [day] [month] [year] [list]

Message-ID: <20130208020659.GE5224@localhost>
Date:	Fri, 8 Feb 2013 10:06:59 +0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	Johannes Weiner <hannes@...xchg.org>
Cc:	Jan Kara <jack@...e.cz>, linux-kernel@...r.kernel.org
Subject: [console_unlock] WARNING: at kernel/sched/clock.c:219
 sched_clock_cpu()

Greetings,

I got the below oops and the first bad commit is

commit c6a6e37da505d1cd79d8dfa7ac68ef953d2bf6dd
Author: Jan Kara <jack@...e.cz>
Date:   Wed Feb 6 02:04:42 2013 +0000

    printk: Avoid softlockups in console_unlock()
    
    A CPU can be caught in console_unlock() for a long time (tens of seconds
    are reported by our customers) when other CPUs are using printk heavily
    and serial console makes printing slow.  Despite serial console drivers
    are calling touch_nmi_watchdog() this triggers softlockup warnings because
    interrupts are disabled for the whole time console_unlock() runs (e.g.
    vprintk() calls console_unlock() with interrupts disabled).  Thus IPIs
    cannot be processed and other CPUs get stuck spinning in calls like
    smp_call_function_many().  Also RCU eventually starts reporting lockups.
    
    In my artificial testing I also managed to trigger a situation when disk
    disappeared from the system apparently because commands to / from it could
    not be delivered for long enough.  This is why just silencing watchdogs
    isn't a reliable solution to the problem and we simply have to avoid
    spending too long in console_unlock().
    
    We fix the issue by limiting the time we spend in console_unlock() to
    watchdog_thresh() / 4 (unless we are in an early boot stage or oops is
    happening).  The rest of the buffer will be printed either by further
    callers to printk() or by a queued work.
    
    Signed-off-by: Jan Kara <jack@...e.cz>
    Cc: Frederic Weisbecker <fweisbec@...il.com>
    Cc: Steven Rostedt <rostedt@...dmis.org>
    Cc: Ingo Molnar <mingo@...e.hu>
    Signed-off-by: Andrew Morton <akpm@...ux-foundation.org>

[    0.000000] Console: colour VGA+ 80x25
[    0.000000] ------------[ cut here ]------------
[    0.000000] WARNING: at /c/kernel-tests/src/linux/kernel/sched/clock.c:219 sched_clock_cpu+0x65/0x140()
[    0.000000] Hardware name: Bochs
[    0.000000] Modules linked in:
[    0.000000] Pid: 0, comm: swapper Not tainted 3.8.0-rc6-mm1-00539-g83b324c #39
[    0.000000] Call Trace:
[    0.000000]  [<c102ba37>] warn_slowpath_common+0x87/0xb0
[    0.000000]  [<c1063025>] ? sched_clock_cpu+0x65/0x140
[    0.000000]  [<c1063025>] ? sched_clock_cpu+0x65/0x140
[    0.000000]  [<c102ba82>] warn_slowpath_null+0x22/0x30
[    0.000000]  [<c1063025>] sched_clock_cpu+0x65/0x140
[    0.000000]  [<c102d8f9>] __console_unlock+0x39/0x490
[    0.000000]  [<c12eeb23>] ? printk+0x3d/0x3f
[    0.000000]  [<c102dd5d>] console_unlock+0xd/0x20
[    0.000000]  [<c14bbbb0>] con_init+0x1fb/0x20e
[    0.000000]  [<c14bb1b2>] console_init+0x12/0x20
[    0.000000]  [<c149e969>] start_kernel+0x258/0x35f
[    0.000000]  [<c149e4cc>] ? repair_env_string+0x51/0x51
[    0.000000]  [<c149e376>] i386_start_kernel+0x12c/0x12f
[    0.000000] ---[ end trace e006f8c3d589c9a1 ]---

git bisect start 83b324c5ff5cca85bbeb2ba913d465f108afe472 259d51a40fe48cf12038fb8b5a417d1d21d2732e --
git bisect good f8df01c1d7833ff2dfb45ccd0017c38c7e803872  #    10  2013-02-06 18:47:56  memcg: debugging facility to access dangling memcgs
git bisect  bad 4538bd3e5b6543108230b034cccd8011ba968496  #     0  2013-02-06 19:18:10  Documentation/cgroups/blkio-controller.txt: fix typo
git bisect  bad a612644e542ef0212d668d2ecee308e8d57cd2e4  #     0  2013-02-06 19:19:36  drivers/video/backlight/ld9040.c: use devm_regulator_bulk_get() API
git bisect  bad c48d189f2ef81158f786a84975ad8db05278f6dd  #     0  2013-02-06 19:20:45  backlight: s6e63m0: remove unnecessary NULL deference check
git bisect good d78fb70a902de2247e9e44fcf7b8e73b96a4a7b3  #    10  2013-02-06 19:52:00  kernel/smp.c: cleanups
git bisect  bad 10fdc3252f827e3ab9652870773349e099e2f4d6  #     0  2013-02-06 20:22:12  backlight-add-lms501kf03-lcd-driver-fix-fix
git bisect  bad 6c35e4b5601ad676682232beed50d558bef11331  #     0  2013-02-06 20:23:31  get_maintainer.pl: find maintainers for removed files
git bisect  bad c6a6e37da505d1cd79d8dfa7ac68ef953d2bf6dd  #     0  2013-02-06 20:24:42  printk: Avoid softlockups in console_unlock()
git bisect good 8e798f4e517d1f32fe9794e75802d4e864a916b7  #    10  2013-02-06 20:55:59  lib/vsprintf.c: add git bisect good 8e798f4e517d1f32fe9794e75802d4e864a916b7  #    30  2013-02-06 22:26:32  lib/vsprintf.c: add git bisect good 1587f71ebbf5aedf754062baa11fcc9e9b49ecf0  #    30  2013-02-07 00:27:22  Add linux-next specific files for 20130125

Thanks,
Fengguang

View attachment "dmesg-kvm-inn-53699-2013-02-06-14-21-18-3.8.0-rc6-mm1-00539-g83b324c-39" of type "text/plain" (65261 bytes)

View attachment "83b324c-bisect.log" of type "text/plain" (10503 bytes)

View attachment ".config-bisect" of type "text/plain" (77725 bytes)