From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755332Ab2D1VvV (ORCPT ); Sat, 28 Apr 2012 17:51:21 -0400 Received: from mail-ob0-f174.google.com ([209.85.214.174]:46554 "EHLO mail-ob0-f174.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751637Ab2D1VvT (ORCPT ); Sat, 28 Apr 2012 17:51:19 -0400 Message-ID: <4F9C6653.9030407@gmail.com> Date: Sat, 28 Apr 2012 14:51:15 -0700 From: "Justin P. Mattock" User-Agent: Mozilla/5.0 (X11; Linux i686; rv:11.0) Gecko/20120329 Thunderbird/11.0.1 MIME-Version: 1.0 To: linux-kernel@vger.kernel.org Subject: NEXT: INFO: possible irq lock inversion dependency detected Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org This is showing up with the current linux-next over here: [ 6.633932] [ 6.634261] ========================================================= [ 6.634263] [ INFO: possible irq lock inversion dependency detected ] [ 6.634265] 3.4.0-rc4-next-20120427 #1 Not tainted [ 6.634266] --------------------------------------------------------- [ 6.634268] swapper/1/0 just changed the state of lock: [ 6.634270] (tg_stats_alloc_lock){+.-...}, at: [] throtl_pd_exit+0x23/0x60 [ 6.634278] but this lock was taken by another, HARDIRQ-safe lock in the past: [ 6.634279] (&(&q->__queue_lock)->rlock){-.-...} [ 6.634281] [ 6.634281] and interrupts could create inverse lock ordering between them. [ 6.634282] [ 6.634283] [ 6.634283] other info that might help us debug this: [ 6.634284] Chain exists of: [ 6.634285] &(&q->__queue_lock)->rlock --> &(&blkcg->lock)->rlock --> tg_stats_alloc_lock [ 6.634287] [ 6.634288] Possible interrupt unsafe locking scenario: [ 6.634288] [ 6.634289] CPU0 CPU1 [ 6.634289] ---- ---- [ 6.634290] lock(tg_stats_alloc_lock); [ 6.634291] local_irq_disable(); [ 6.634292] lock(&(&q->__queue_lock)->rlock); [ 6.634294] lock(&(&blkcg->lock)->rlock); [ 6.634295] [ 6.634296] lock(&(&q->__queue_lock)->rlock); [ 6.634297] [ 6.634297] *** DEADLOCK *** [ 6.634297] [ 6.634298] no locks held by swapper/1/0. [ 6.634299] [ 6.634300] the shortest dependencies between 2nd lock and 1st lock: [ 6.634306] -> (&(&q->__queue_lock)->rlock){-.-...} ops: 7758 { [ 6.634308] IN-HARDIRQ-W at: [ 6.634310] [] __lock_acquire+0x90f/0x1660 [ 6.634315] [] lock_acquire+0x80/0x120 [ 6.634318] [] _raw_spin_lock_irqsave+0x57/0x70 [ 6.634325] [] ata_qc_schedule_eh+0x48/0x80 [ 6.634332] [] ata_qc_complete+0x180/0x1f0 [ 6.634335] [] ata_do_link_abort+0x83/0xc0 [ 6.634338] [] ata_port_abort+0xf/0x20 [ 6.634341] [] ahci_interrupt+0x425/0x640 [ 6.634346] [] handle_irq_event_percpu+0x4c/0x240 [ 6.634351] [] handle_irq_event+0x3a/0x60 [ 6.634353] [] handle_edge_irq+0x66/0xf0 [ 6.634356] IN-SOFTIRQ-W at: [ 6.634357] [] __lock_acquire+0x4fd/0x1660 [ 6.634359] [] lock_acquire+0x80/0x120 [ 6.634361] [] _raw_spin_lock+0x43/0x50 [ 6.634364] [] scsi_device_unbusy+0x89/0xb0 [ 6.634370] [] scsi_finish_command+0x2a/0x100 [ 6.634372] [] scsi_softirq_done+0x118/0x140 [ 6.634374] [] blk_done_softirq+0x6b/0x80 [ 6.634378] [] __do_softirq+0x99/0x1f0 [ 6.634383] [] run_ksoftirqd+0xf7/0x1a0 [ 6.634386] [] kthread+0x7d/0x90 [ 6.634390] [] kernel_thread_helper+0x6/0x10 [ 6.634394] INITIAL USE at: [ 6.634395] [] __lock_acquire+0x265/0x1660 [ 6.634398] [] lock_acquire+0x80/0x120 [ 6.634401] [] _raw_spin_lock_irq+0x4e/0x60 [ 6.634404] [] blk_queue_bypass_start+0x17/0x80 [ 6.634410] [] blkcg_activate_policy+0x40/0x260 [ 6.634416] [] blk_throtl_init+0xb7/0xe0 [ 6.634419] [] blkcg_init_queue+0x28/0x30 [ 6.634422] [] blk_alloc_queue_node+0x1f8/0x240 [ 6.634425] [] blk_alloc_queue+0x12/0x20 [ 6.634428] [] brd_alloc+0x69/0x180 [ 6.634434] [] brd_init+0xb0/0x185 [ 6.634440] [] do_one_initcall+0x34/0x170 [ 6.634443] [] kernel_init+0x111/0x1a6 [ 6.634447] [] kernel_thread_helper+0x6/0x10 [ 6.634450] } [ 6.634451] ... key at: [] __key.34385+0x0/0x8 [ 6.634457] ... acquired at: [ 6.634458] [] lock_acquire+0x80/0x120 [ 6.634460] [] _raw_spin_lock_irqsave+0x57/0x70 [ 6.634463] [] get_from_free_list+0x1b/0x50 [ 6.634468] [] idr_get_empty_slot+0x26d/0x290 [ 6.634471] [] ida_get_new_above+0x69/0x230 [ 6.634473] [] ida_simple_get+0x58/0xe0 [ 6.634476] [] blk_alloc_queue_node+0x3c/0x240 [ 6.634478] [] blk_alloc_queue+0x12/0x20 [ 6.634481] [] brd_alloc+0x69/0x180 [ 6.634484] [] brd_init+0xb0/0x185 [ 6.634486] [] do_one_initcall+0x34/0x170 [ 6.634489] [] kernel_init+0x111/0x1a6 [ 6.634491] [] kernel_thread_helper+0x6/0x10 [ 6.634494] [ 6.634495] -> (&(&blkcg->lock)->rlock){......} ops: 89 { [ 6.634498] INITIAL USE at: [ 6.634499] [] __lock_acquire+0x265/0x1660 [ 6.634503] [] lock_acquire+0x80/0x120 [ 6.634505] [] _raw_spin_lock+0x43/0x50 [ 6.634508] [] __blkg_lookup_create+0x17c/0x2a0 [ 6.634512] [] blkcg_activate_policy+0x93/0x260 [ 6.634515] [] blk_throtl_init+0xb7/0xe0 [ 6.634517] [] blkcg_init_queue+0x28/0x30 [ 6.634520] [] blk_alloc_queue_node+0x1f8/0x240 [ 6.634523] [] blk_alloc_queue+0x12/0x20 [ 6.634526] [] brd_alloc+0x69/0x180 [ 6.634529] [] brd_init+0xb0/0x185 [ 6.634532] [] do_one_initcall+0x34/0x170 [ 6.634535] [] kernel_init+0x111/0x1a6 [ 6.634538] [] kernel_thread_helper+0x6/0x10 [ 6.634540] } [ 6.634541] ... key at: [] __key.29231+0x0/0x8 [ 6.634543] ... acquired at: [ 6.634544] [] lock_acquire+0x80/0x120 [ 6.634546] [] _raw_spin_lock+0x43/0x50 [ 6.634548] [] throtl_pd_init+0x7e/0xc0 [ 6.634550] [] blkcg_activate_policy+0x20b/0x260 [ 6.634552] [] blk_throtl_init+0xb7/0xe0 [ 6.634553] [] blkcg_init_queue+0x28/0x30 [ 6.634555] [] blk_alloc_queue_node+0x1f8/0x240 [ 6.634557] [] blk_alloc_queue+0x12/0x20 [ 6.634559] [] brd_alloc+0x69/0x180 [ 6.634561] [] brd_init+0xb0/0x185 [ 6.634562] [] do_one_initcall+0x34/0x170 [ 6.634564] [] kernel_init+0x111/0x1a6 [ 6.634565] [] kernel_thread_helper+0x6/0x10 [ 6.634567] [ 6.634568] -> (tg_stats_alloc_lock){+.-...} ops: 71 { [ 6.634570] HARDIRQ-ON-W at: [ 6.634571] [] __lock_acquire+0x521/0x1660 [ 6.634573] [] lock_acquire+0x80/0x120 [ 6.634575] [] _raw_spin_lock+0x43/0x50 [ 6.634577] [] throtl_pd_exit+0x23/0x60 [ 6.634579] [] blkg_free+0x2b/0x60 [ 6.634581] [] blkg_rcu_free+0x10/0x20 [ 6.634583] [] __rcu_process_callbacks+0x1c6/0x430 [ 6.634586] [] rcu_process_callbacks+0x26/0xe0 [ 6.634588] [] __do_softirq+0x99/0x1f0 [ 6.634591] IN-SOFTIRQ-W at: [ 6.634592] [] __lock_acquire+0x4fd/0x1660 [ 6.634594] [] lock_acquire+0x80/0x120 [ 6.634596] [] _raw_spin_lock+0x43/0x50 [ 6.634598] [] throtl_pd_exit+0x23/0x60 [ 6.634600] [] blkg_free+0x2b/0x60 [ 6.634602] [] blkg_rcu_free+0x10/0x20 [ 6.634604] [] __rcu_process_callbacks+0x1c6/0x430 [ 6.634606] [] rcu_process_callbacks+0x26/0xe0 [ 6.634608] [] __do_softirq+0x99/0x1f0 [ 6.634611] INITIAL USE at: [ 6.634612] [] __lock_acquire+0x265/0x1660 [ 6.634614] [] lock_acquire+0x80/0x120 [ 6.634616] [] _raw_spin_lock+0x43/0x50 [ 6.634618] [] throtl_pd_init+0x7e/0xc0 [ 6.634619] [] blkcg_activate_policy+0x20b/0x260 [ 6.634622] [] blk_throtl_init+0xb7/0xe0 [ 6.634624] [] blkcg_init_queue+0x28/0x30 [ 6.634626] [] blk_alloc_queue_node+0x1f8/0x240 [ 6.634628] [] blk_alloc_queue+0x12/0x20 [ 6.634630] [] brd_alloc+0x69/0x180 [ 6.634632] [] brd_init+0xb0/0x185 [ 6.634634] [] do_one_initcall+0x34/0x170 [ 6.634636] [] kernel_init+0x111/0x1a6 [ 6.634637] [] kernel_thread_helper+0x6/0x10 [ 6.634639] } [ 6.634640] ... key at: [] tg_stats_alloc_lock+0x10/0x20 [ 6.634644] ... acquired at: [ 6.634645] [] check_usage_backwards+0xf0/0x130 [ 6.634647] [] mark_lock+0x130/0x280 [ 6.634649] [] __lock_acquire+0x521/0x1660 [ 6.634651] [] lock_acquire+0x80/0x120 [ 6.634653] [] _raw_spin_lock+0x43/0x50 [ 6.634655] [] throtl_pd_exit+0x23/0x60 [ 6.634657] [] blkg_free+0x2b/0x60 [ 6.634659] [] blkg_rcu_free+0x10/0x20 [ 6.634661] [] __rcu_process_callbacks+0x1c6/0x430 [ 6.634663] [] rcu_process_callbacks+0x26/0xe0 [ 6.634665] [] __do_softirq+0x99/0x1f0 [ 6.634666] [ 6.634667] [ 6.634667] stack backtrace: [ 6.634669] Pid: 0, comm: swapper/1 Not tainted 3.4.0-rc4-next-20120427 #1 [ 6.634671] Call Trace: [ 6.634674] [] ? printk+0x1d/0x1f [ 6.634676] [] print_irq_inversion_bug.part.36+0x1a4/0x1b0 [ 6.634679] [] check_usage_backwards+0xf0/0x130 [ 6.634681] [] mark_lock+0x130/0x280 [ 6.634682] [] ? check_usage_forwards+0x130/0x130 [ 6.634685] [] __lock_acquire+0x521/0x1660 [ 6.634686] [] ? __lock_acquire+0x265/0x1660 [ 6.634688] [] ? __lock_acquire+0x265/0x1660 [ 6.634691] [] lock_acquire+0x80/0x120 [ 6.634692] [] ? throtl_pd_exit+0x23/0x60 [ 6.634695] [] _raw_spin_lock+0x43/0x50 [ 6.634696] [] ? throtl_pd_exit+0x23/0x60 [ 6.634698] [] throtl_pd_exit+0x23/0x60 [ 6.634700] [] blkg_free+0x2b/0x60 [ 6.634702] [] blkg_rcu_free+0x10/0x20 [ 6.634704] [] __rcu_process_callbacks+0x1c6/0x430 [ 6.634706] [] ? local_bh_enable_ip+0xd0/0xd0 [ 6.634708] [] rcu_process_callbacks+0x26/0xe0 [ 6.634710] [] ? local_bh_enable_ip+0xd0/0xd0 [ 6.634712] [] __do_softirq+0x99/0x1f0 [ 6.634714] [] ? local_bh_enable_ip+0xd0/0xd0 [ 6.634715] [] ? irq_exit+0x86/0xb0 [ 6.634718] [] ? smp_apic_timer_interrupt+0x59/0x88 [ 6.634722] [] ? trace_hardirqs_off_thunk+0xc/0x14 [ 6.634724] [] ? apic_timer_interrupt+0x36/0x3c [ 6.634728] [] ? timer_list_show+0x99b/0xec0 [ 6.634733] [] ? intel_idle+0xc7/0x120 [ 6.634736] [] ? cpuidle_enter+0x15/0x20 [ 6.634738] [] ? cpuidle_idle_call+0x8a/0x1e0 [ 6.634741] [] ? cpu_idle+0xaf/0x100 [ 6.634743] [] ? start_secondary+0x1f4/0x1fa [ 13.057885] EXT4-fs (sda6): mounted filesystem with ordered data mode. Opts: (null) full dmesg here: http://fpaste.org/IDFW/ Justin P. Mattock