android_kernel_google_msm/kernel
Jan Kara fbbb720896 timer: Fix lock inversion between hrtimer_bases.lock and scheduler locks
commit 504d58745c upstream.

clockevents_increase_min_delta() calls printk() from under
hrtimer_bases.lock. That causes lock inversion on scheduler locks because
printk() can call into the scheduler. Lockdep puts it as:

======================================================
[ INFO: possible circular locking dependency detected ]
3.15.0-rc8-06195-g939f04b #2 Not tainted
-------------------------------------------------------
trinity-main/74 is trying to acquire lock:
 (&port_lock_key){-.....}, at: [<811c60be>] serial8250_console_write+0x8c/0x10c

but task is already holding lock:
 (hrtimer_bases.lock){-.-...}, at: [<8103caeb>] hrtimer_try_to_cancel+0x13/0x66

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #5 (hrtimer_bases.lock){-.-...}:
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f11d>] _raw_spin_lock_irqsave+0x2e/0x3e
       [<8103c918>] __hrtimer_start_range_ns+0x1c/0x197
       [<8107ec20>] perf_swevent_start_hrtimer.part.41+0x7a/0x85
       [<81080792>] task_clock_event_start+0x3a/0x3f
       [<810807a4>] task_clock_event_add+0xd/0x14
       [<8108259a>] event_sched_in+0xb6/0x17a
       [<810826a2>] group_sched_in+0x44/0x122
       [<81082885>] ctx_sched_in.isra.67+0x105/0x11f
       [<810828e6>] perf_event_sched_in.isra.70+0x47/0x4b
       [<81082bf6>] __perf_install_in_context+0x8b/0xa3
       [<8107eb8e>] remote_function+0x12/0x2a
       [<8105f5af>] smp_call_function_single+0x2d/0x53
       [<8107e17d>] task_function_call+0x30/0x36
       [<8107fb82>] perf_install_in_context+0x87/0xbb
       [<810852c9>] SYSC_perf_event_open+0x5c6/0x701
       [<810856f9>] SyS_perf_event_open+0x17/0x19
       [<8142f8ee>] syscall_call+0x7/0xb

-> #4 (&ctx->lock){......}:
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f04c>] _raw_spin_lock+0x21/0x30
       [<81081df3>] __perf_event_task_sched_out+0x1dc/0x34f
       [<8142cacc>] __schedule+0x4c6/0x4cb
       [<8142cae0>] schedule+0xf/0x11
       [<8142f9a6>] work_resched+0x5/0x30

-> #3 (&rq->lock){-.-.-.}:
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f04c>] _raw_spin_lock+0x21/0x30
       [<81040873>] __task_rq_lock+0x33/0x3a
       [<8104184c>] wake_up_new_task+0x25/0xc2
       [<8102474b>] do_fork+0x15c/0x2a0
       [<810248a9>] kernel_thread+0x1a/0x1f
       [<814232a2>] rest_init+0x1a/0x10e
       [<817af949>] start_kernel+0x303/0x308
       [<817af2ab>] i386_start_kernel+0x79/0x7d

-> #2 (&p->pi_lock){-.-...}:
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f11d>] _raw_spin_lock_irqsave+0x2e/0x3e
       [<810413dd>] try_to_wake_up+0x1d/0xd6
       [<810414cd>] default_wake_function+0xb/0xd
       [<810461f3>] __wake_up_common+0x39/0x59
       [<81046346>] __wake_up+0x29/0x3b
       [<811b8733>] tty_wakeup+0x49/0x51
       [<811c3568>] uart_write_wakeup+0x17/0x19
       [<811c5dc1>] serial8250_tx_chars+0xbc/0xfb
       [<811c5f28>] serial8250_handle_irq+0x54/0x6a
       [<811c5f57>] serial8250_default_handle_irq+0x19/0x1c
       [<811c56d8>] serial8250_interrupt+0x38/0x9e
       [<810510e7>] handle_irq_event_percpu+0x5f/0x1e2
       [<81051296>] handle_irq_event+0x2c/0x43
       [<81052cee>] handle_level_irq+0x57/0x80
       [<81002a72>] handle_irq+0x46/0x5c
       [<810027df>] do_IRQ+0x32/0x89
       [<8143036e>] common_interrupt+0x2e/0x33
       [<8142f23c>] _raw_spin_unlock_irqrestore+0x3f/0x49
       [<811c25a4>] uart_start+0x2d/0x32
       [<811c2c04>] uart_write+0xc7/0xd6
       [<811bc6f6>] n_tty_write+0xb8/0x35e
       [<811b9beb>] tty_write+0x163/0x1e4
       [<811b9cd9>] redirected_tty_write+0x6d/0x75
       [<810b6ed6>] vfs_write+0x75/0xb0
       [<810b7265>] SyS_write+0x44/0x77
       [<8142f8ee>] syscall_call+0x7/0xb

-> #1 (&tty->write_wait){-.....}:
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f11d>] _raw_spin_lock_irqsave+0x2e/0x3e
       [<81046332>] __wake_up+0x15/0x3b
       [<811b8733>] tty_wakeup+0x49/0x51
       [<811c3568>] uart_write_wakeup+0x17/0x19
       [<811c5dc1>] serial8250_tx_chars+0xbc/0xfb
       [<811c5f28>] serial8250_handle_irq+0x54/0x6a
       [<811c5f57>] serial8250_default_handle_irq+0x19/0x1c
       [<811c56d8>] serial8250_interrupt+0x38/0x9e
       [<810510e7>] handle_irq_event_percpu+0x5f/0x1e2
       [<81051296>] handle_irq_event+0x2c/0x43
       [<81052cee>] handle_level_irq+0x57/0x80
       [<81002a72>] handle_irq+0x46/0x5c
       [<810027df>] do_IRQ+0x32/0x89
       [<8143036e>] common_interrupt+0x2e/0x33
       [<8142f23c>] _raw_spin_unlock_irqrestore+0x3f/0x49
       [<811c25a4>] uart_start+0x2d/0x32
       [<811c2c04>] uart_write+0xc7/0xd6
       [<811bc6f6>] n_tty_write+0xb8/0x35e
       [<811b9beb>] tty_write+0x163/0x1e4
       [<811b9cd9>] redirected_tty_write+0x6d/0x75
       [<810b6ed6>] vfs_write+0x75/0xb0
       [<810b7265>] SyS_write+0x44/0x77
       [<8142f8ee>] syscall_call+0x7/0xb

-> #0 (&port_lock_key){-.....}:
       [<8104a62d>] __lock_acquire+0x9ea/0xc6d
       [<8104a942>] lock_acquire+0x92/0x101
       [<8142f11d>] _raw_spin_lock_irqsave+0x2e/0x3e
       [<811c60be>] serial8250_console_write+0x8c/0x10c
       [<8104e402>] call_console_drivers.constprop.31+0x87/0x118
       [<8104f5d5>] console_unlock+0x1d7/0x398
       [<8104fb70>] vprintk_emit+0x3da/0x3e4
       [<81425f76>] printk+0x17/0x19
       [<8105bfa0>] clockevents_program_min_delta+0x104/0x116
       [<8105c548>] clockevents_program_event+0xe7/0xf3
       [<8105cc1c>] tick_program_event+0x1e/0x23
       [<8103c43c>] hrtimer_force_reprogram+0x88/0x8f
       [<8103c49e>] __remove_hrtimer+0x5b/0x79
       [<8103cb21>] hrtimer_try_to_cancel+0x49/0x66
       [<8103cb4b>] hrtimer_cancel+0xd/0x18
       [<8107f102>] perf_swevent_cancel_hrtimer.part.60+0x2b/0x30
       [<81080705>] task_clock_event_stop+0x20/0x64
       [<81080756>] task_clock_event_del+0xd/0xf
       [<81081350>] event_sched_out+0xab/0x11e
       [<810813e0>] group_sched_out+0x1d/0x66
       [<81081682>] ctx_sched_out+0xaf/0xbf
       [<81081e04>] __perf_event_task_sched_out+0x1ed/0x34f
       [<8142cacc>] __schedule+0x4c6/0x4cb
       [<8142cae0>] schedule+0xf/0x11
       [<8142f9a6>] work_resched+0x5/0x30

other info that might help us debug this:

Chain exists of:
  &port_lock_key --> &ctx->lock --> hrtimer_bases.lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(hrtimer_bases.lock);
                               lock(&ctx->lock);
                               lock(hrtimer_bases.lock);
  lock(&port_lock_key);

 *** DEADLOCK ***

4 locks held by trinity-main/74:
 #0:  (&rq->lock){-.-.-.}, at: [<8142c6f3>] __schedule+0xed/0x4cb
 #1:  (&ctx->lock){......}, at: [<81081df3>] __perf_event_task_sched_out+0x1dc/0x34f
 #2:  (hrtimer_bases.lock){-.-...}, at: [<8103caeb>] hrtimer_try_to_cancel+0x13/0x66
 #3:  (console_lock){+.+...}, at: [<8104fb5d>] vprintk_emit+0x3c7/0x3e4

stack backtrace:
CPU: 0 PID: 74 Comm: trinity-main Not tainted 3.15.0-rc8-06195-g939f04b #2
 00000000 81c3a310 8b995c14 81426f69 8b995c44 81425a99 8161f671 8161f570
 8161f538 8161f559 8161f538 8b995c78 8b142bb0 00000004 8b142fdc 8b142bb0
 8b995ca8 8104a62d 8b142fac 000016f2 81c3a310 00000001 00000001 00000003
Call Trace:
 [<81426f69>] dump_stack+0x16/0x18
 [<81425a99>] print_circular_bug+0x18f/0x19c
 [<8104a62d>] __lock_acquire+0x9ea/0xc6d
 [<8104a942>] lock_acquire+0x92/0x101
 [<811c60be>] ? serial8250_console_write+0x8c/0x10c
 [<811c6032>] ? wait_for_xmitr+0x76/0x76
 [<8142f11d>] _raw_spin_lock_irqsave+0x2e/0x3e
 [<811c60be>] ? serial8250_console_write+0x8c/0x10c
 [<811c60be>] serial8250_console_write+0x8c/0x10c
 [<8104af87>] ? lock_release+0x191/0x223
 [<811c6032>] ? wait_for_xmitr+0x76/0x76
 [<8104e402>] call_console_drivers.constprop.31+0x87/0x118
 [<8104f5d5>] console_unlock+0x1d7/0x398
 [<8104fb70>] vprintk_emit+0x3da/0x3e4
 [<81425f76>] printk+0x17/0x19
 [<8105bfa0>] clockevents_program_min_delta+0x104/0x116
 [<8105cc1c>] tick_program_event+0x1e/0x23
 [<8103c43c>] hrtimer_force_reprogram+0x88/0x8f
 [<8103c49e>] __remove_hrtimer+0x5b/0x79
 [<8103cb21>] hrtimer_try_to_cancel+0x49/0x66
 [<8103cb4b>] hrtimer_cancel+0xd/0x18
 [<8107f102>] perf_swevent_cancel_hrtimer.part.60+0x2b/0x30
 [<81080705>] task_clock_event_stop+0x20/0x64
 [<81080756>] task_clock_event_del+0xd/0xf
 [<81081350>] event_sched_out+0xab/0x11e
 [<810813e0>] group_sched_out+0x1d/0x66
 [<81081682>] ctx_sched_out+0xaf/0xbf
 [<81081e04>] __perf_event_task_sched_out+0x1ed/0x34f
 [<8104416d>] ? __dequeue_entity+0x23/0x27
 [<81044505>] ? pick_next_task_fair+0xb1/0x120
 [<8142cacc>] __schedule+0x4c6/0x4cb
 [<81047574>] ? trace_hardirqs_off_caller+0xd7/0x108
 [<810475b0>] ? trace_hardirqs_off+0xb/0xd
 [<81056346>] ? rcu_irq_exit+0x64/0x77

Fix the problem by using printk_deferred() which does not call into the
scheduler.

Reported-by: Fengguang Wu <fengguang.wu@intel.com>
Signed-off-by: Jan Kara <jack@suse.cz>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
2014-08-07 12:00:10 -07:00
..
debug kdb,vt_console: Fix missed data due to pager overruns 2012-10-21 09:27:59 -07:00
events perf: Fix race in removing an event 2014-06-11 12:04:11 -07:00
gcov
irq genirq: Sanitize spurious interrupt detection of threaded irqs 2014-06-30 20:01:33 -07:00
power PM / sleep: Fix request_firmware() error at resume 2014-07-28 07:06:46 -07:00
sched printk: rename printk_sched to printk_deferred 2014-08-07 12:00:10 -07:00
time timer: Fix lock inversion between hrtimer_bases.lock and scheduler locks 2014-08-07 12:00:10 -07:00
trace tracing: Remove ftrace_stop/start() from reading the trace file 2014-07-17 15:39:50 -07:00
.gitignore
acct.c
async.c Fix a dead loop in async_synchronize_full() 2012-10-02 10:30:35 -07:00
audit.c audit: wait_for_auditd() should use TASK_UNINTERRUPTIBLE 2014-04-14 06:44:15 -07:00
audit.h
audit_tree.c kernel/audit_tree.c: tree will leak memory when failure occurs in audit_trim_trees() 2013-05-11 13:48:14 -07:00
audit_watch.c
auditfilter.c
auditsc.c auditsc: audit_krule mask accesses need bounds checking 2014-06-16 13:45:46 -07:00
backtracetest.c
bounds.c
capability.c
cgroup.c cgroup: cgroup_subsys->fork() should be called after the task is added to css_set 2014-03-11 16:10:03 -07:00
cgroup_freezer.c cgroup: cgroup_subsys->fork() should be called after the task is added to css_set 2014-03-11 16:10:03 -07:00
compat.c compat: Fix RT signal mask corruption via sigprocmask 2012-05-10 08:58:33 -07:00
configs.c
cpu.c sched: Fix hotplug vs. set_cpus_allowed_ptr() 2014-06-11 12:04:11 -07:00
cpu_pm.c
cpuset.c cpuset,mempolicy: fix sleeping function called from invalid context 2014-07-17 15:39:49 -07:00
crash_dump.c
cred.c cred: copy_process() should clear child->replacement_session_keyring 2012-04-11 08:20:11 -07:00
delayacct.c
dma.c Remove all #inclusions of asm/system.h 2012-03-28 18:30:03 +01:00
elfcore.c
exec_domain.c
exit.c wait: fix reparent_leader() vs EXIT_DEAD->EXIT_ZOMBIE race 2014-04-26 17:13:20 -07:00
extable.c
fork.c tracing: Fix syscall_*regfunc() vs copy_process() race 2014-07-06 18:49:20 -07:00
freezer.c PM / Freezer: Remove references to TIF_FREEZE in comments 2012-03-04 23:08:54 +01:00
futex.c futex: Make lookup_pi_state more robust 2014-06-07 16:02:16 -07:00
futex_compat.c futex: Revert "futex: Mark get_robust_list as deprecated" 2013-02-28 06:59:01 -08:00
groups.c
hrtimer.c hrtimer: Set expiry time before switch_hrtimer_base() 2014-06-07 16:02:01 -07:00
hung_task.c hung_task: fix the broken rcu_lock_break() logic 2012-03-05 15:49:42 -08:00
irq_work.c irq_work: fix compile failure on tile from missing include 2012-04-13 13:15:16 -04:00
itimer.c itimer: Use printk_once instead of WARN_ONCE 2012-04-10 11:00:30 +02:00
jump_label.c static keys: Inline the static_key_enabled() function 2012-02-28 20:01:08 +01:00
kallsyms.c
Kconfig.freezer
Kconfig.hz
Kconfig.locks locking/kconfig: Simplify INLINE_SPIN_UNLOCK usage 2012-03-23 13:18:57 +01:00
Kconfig.preempt locking/kconfig: Simplify INLINE_SPIN_UNLOCK usage 2012-03-23 13:18:57 +01:00
kexec.c Merge branch 'akpm' (Andrew's patch-bomb) 2012-03-28 17:19:28 -07:00
kfifo.c
kmod.c usermodehelper: check subprocess_info->path != NULL 2013-05-19 10:54:50 -07:00
kprobes.c kprobes: return proper error code from register_kprobe() 2012-03-05 15:49:42 -08:00
ksysfs.c
kthread.c kthread_worker: reimplement flush_kthread_work() to allow freeing the work item being executed 2012-10-02 10:30:40 -07:00
latencytop.c
lockdep.c lockdep: Add CPU-idle/offline warning to lockdep-RCU splat 2012-02-21 09:06:06 -08:00
lockdep_internals.h
lockdep_proc.c
lockdep_states.h
Makefile
module.c ftrace/module: Hardcode ftrace_module_init() call into load_module() 2014-06-07 16:02:00 -07:00
mutex-debug.c
mutex-debug.h
mutex.c sched/rt: Use schedule_preempt_disabled() 2012-03-01 10:28:03 +01:00
mutex.h
notifier.c
nsproxy.c
padata.c padata: Fix cpu hotplug 2012-03-29 19:52:46 +08:00
panic.c panic: fix a possible deadlock in panic() 2013-04-12 09:38:47 -07:00
params.c params: <level>_initcall-like kernel parameters 2012-03-26 12:50:51 +10:30
pid.c
pid_namespace.c pidns: add reboot_pid_ns() to handle the reboot syscall 2012-03-28 17:14:36 -07:00
posix-cpu-timers.c posix-cpu-timers: Fix nanosleep task_struct leak 2013-02-28 06:58:59 -08:00
posix-timers.c posix-timer: Don't call idr_find() with out-of-range ID 2013-03-04 06:06:38 +08:00
printk.c printk: rename printk_sched to printk_deferred 2014-08-07 12:00:10 -07:00
profile.c
ptrace.c exec/ptrace: fix get_dumpable() incorrect tests 2013-11-29 10:50:34 -08:00
range.c
rcu.h rcu: Allow nesting of rcu_idle_enter() and rcu_idle_exit() 2012-02-21 09:06:12 -08:00
rcupdate.c rcu: Check for illegal use of RCU from offlined CPUs 2012-02-21 09:06:03 -08:00
rcutiny.c rcu: Add RCU_NONIDLE() for idle-loop RCU read-side critical sections 2012-02-21 09:06:13 -08:00
rcutiny_plugin.h rcu: Simplify unboosting checks 2012-02-21 09:03:43 -08:00
rcutorture.c PTR_ERR should be called before its argument is cleared. 2012-02-21 09:06:10 -08:00
rcutree.c rcu: Fix batch-limit size problem 2012-12-17 10:37:46 -08:00
rcutree.h rcu: Rework detection of use of RCU by offline CPUs 2012-02-21 09:06:07 -08:00
rcutree_plugin.h rcu: Hold off RCU_FAST_NO_HZ after timer posted 2012-02-21 09:42:30 -08:00
rcutree_trace.c rcu: Rework detection of use of RCU by offline CPUs 2012-02-21 09:06:07 -08:00
relay.c splice: fix racy pipe->buffers uses 2012-07-16 09:04:42 -07:00
res_counter.c
resource.c kernel/resource.c: fix stack overflow in __reserve_region_with_split() 2013-02-14 10:48:53 -08:00
rtmutex-debug.c
rtmutex-debug.h rtmutex: Handle deadlock detection smarter 2014-07-17 15:39:50 -07:00
rtmutex-tester.c
rtmutex.c rtmutex: Plug slow unlock race 2014-07-17 15:39:50 -07:00
rtmutex.h rtmutex: Handle deadlock detection smarter 2014-07-17 15:39:50 -07:00
rtmutex_common.h
rwsem.c Remove all #inclusions of asm/system.h 2012-03-28 18:30:03 +01:00
seccomp.c
semaphore.c
signal.c kernel/signal.c: stop info leak via the tkill and the tgkill syscalls 2013-04-25 21:19:54 -07:00
smp.c smp: Fix SMP function call empty cpu mask race 2013-02-03 18:24:42 -06:00
softirq.c Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip 2012-03-20 10:32:09 -07:00
spinlock.c locking/kconfig: Simplify INLINE_SPIN_UNLOCK usage 2012-03-23 13:18:57 +01:00
srcu.c rcu: Call out dangers of expedited RCU primitives 2012-02-21 09:06:08 -08:00
stacktrace.c
stop_machine.c
sys.c reboot: rigrate shutdown/reboot to boot cpu 2013-06-20 11:58:45 -07:00
sys_ni.c
sysctl.c hung_task: check the value of "sysctl_hung_task_timeout_sec" 2014-05-06 07:51:45 -07:00
sysctl_binary.c sysctl: fix null checking in bin_dn_node_address() 2013-03-04 06:06:41 +08:00
taskstats.c
test_kprobes.c
time.c time: Remove bogus comments 2012-03-15 18:17:55 -07:00
timeconst.pl timeconst.pl: Eliminate Perl warning 2013-02-28 06:58:58 -08:00
timer.c timer: Prevent overflow in apply_slack 2014-06-07 16:02:00 -07:00
tracepoint.c tracepoint: Do not waste memory on mods with no tracepoints 2014-05-18 05:25:56 -07:00
tsacct.c
uid16.c
up.c
user-return-notifier.c
user.c
user_namespace.c
utsname.c
utsname_sysctl.c
wait.c
watchdog.c watchdog: using u64 in get_sample_period() 2012-12-03 11:47:17 -08:00
workqueue.c workqueue: cond_resched() after processing each work item 2014-04-14 06:44:16 -07:00
workqueue_sched.h