Oliver Hartkopp wrote:
2. I got this inconsistent lock state, i've not seen before:
Hm - that was not completely correct 8->
I found some more of these lock state issues in my /var/log/kern.log but
all of them are in the tg3 receive path ... (attached).
So this problem seems not to come from your request_firmware()
conversion. Maybe there was some other change in the 2.6.28-git that
causes these tg3 problems.
Regards,
Oliver
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752455]
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752459] =================================
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752467] [ INFO: inconsistent lock state ]
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752473] 2.6.28-05692-g7d3b56b #4
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752477] ---------------------------------
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752483] inconsistent {softirq-on-W} -> {in-softirq-W} usage.
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752490] swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752495] (&fbc->lock){-+..}, at: [<c0223d5b>] __percpu_counter_add+0x52/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752514] {softirq-on-W} state was registered at:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752518] [<c0140000>] __lock_acquire+0x2c4/0xb22
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752530] [<c01408bb>] lock_acquire+0x5d/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752540] [<c03b9601>] _spin_lock+0x1b/0x2a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752550] [<c0223d90>] __percpu_counter_sum+0xd/0x51
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752559] [<c01b4f23>] ext3_statfs+0xb5/0x159
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752568] [<c0172964>] vfs_statfs+0x3c/0x55
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752577] [<c0173c09>] sys_statfs64+0x44/0x80
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752587] [<c0102ed5>] sysenter_do_call+0x12/0x35
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752596] [<ffffffff>] 0xffffffff
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752613] irq event stamp: 566114
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752618] hardirqs last enabled at (566114): [<c0155c1c>] free_hot_cold_page+0x138/0x163
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752629] hardirqs last disabled at (566113): [<c0155b67>] free_hot_cold_page+0x83/0x163
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752639] softirqs last enabled at (566060): [<c01279db>] __do_softirq+0x135/0x13d
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752651] softirqs last disabled at (566083): [<c0127a1d>] do_softirq+0x3a/0x52
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752661]
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752663] other info that might help us debug this:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752669] 3 locks held by swapper/0:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752673] #0: (rcu_read_lock){..--}, at: [<c032b4df>] netif_receive_skb+0xb0/0x25f
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752690] #1: (rcu_read_lock){..--}, at: [<c033f210>] ip_local_deliver+0x49/0x145
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752706] #2: (slock-AF_INET/1){-+..}, at: [<c03553af>] tcp_v4_rcv+0x20b/0x4fd
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752724]
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752726] stack backtrace:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752732] Pid: 0, comm: swapper Not tainted 2.6.28-05692-g7d3b56b #4
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752738] Call Trace:
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752748] [<c03b75cb>] ? printk+0xf/0x11
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752757] [<c013f061>] valid_state+0x12a/0x13d
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752766] [<c013f31c>] mark_lock+0x133/0x340
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752776] [<c013ff7e>] __lock_acquire+0x242/0xb22
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752785] [<c013f207>] ? mark_lock+0x1e/0x340
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752794] [<c013f57c>] ? mark_held_locks+0x53/0x6a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752803] [<c01408bb>] lock_acquire+0x5d/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752812] [<c0223d5b>] ? __percpu_counter_add+0x52/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752820] [<c03b9601>] _spin_lock+0x1b/0x2a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752828] [<c0223d5b>] ? __percpu_counter_add+0x52/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752837] [<c0223d5b>] __percpu_counter_add+0x52/0x7a
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752845] [<c0354dc4>] tcp_v4_destroy_sock+0x15b/0x164
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752854] [<c0345e64>] inet_csk_destroy_sock+0x87/0xf4
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752862] [<c03476b2>] tcp_done+0x5d/0x60
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752872] [<c0350153>] tcp_rcv_state_process+0x7a6/0x883
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752880] [<c03553af>] ? tcp_v4_rcv+0x20b/0x4fd
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752887] [<c035515b>] tcp_v4_do_rcv+0x114/0x15d
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752895] [<c03554be>] tcp_v4_rcv+0x31a/0x4fd
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752904] [<c033f279>] ip_local_deliver+0xb2/0x145
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752911] [<c033f149>] ip_rcv+0x3d1/0x3fb
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752921] [<c03949b1>] ? packet_rcv_spkt+0x9c/0xa4
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752930] [<c032b65b>] netif_receive_skb+0x22c/0x25f
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752940] [<c02a09b1>] tg3_poll+0x6a6/0x8bf
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752949] [<c032a3a0>] net_rx_action+0x62/0x143
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752958] [<c0127935>] __do_softirq+0x8f/0x13d
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752966] [<c0127a1d>] do_softirq+0x3a/0x52
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752975] [<c0127b43>] irq_exit+0x44/0x7b
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752983] [<c0104c7e>] do_IRQ+0x92/0xa8
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.752991] [<c010352c>] common_interrupt+0x2c/0x34
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753001] [<c013007b>] ? ____call_usermodehelper+0x85/0x124
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753011] [<c0261acd>] ? acpi_idle_enter_simple+0x151/0x182
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753021] [<c026179e>] acpi_idle_enter_bm+0xc6/0x2a4
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753032] [<c031475d>] cpuidle_idle_call+0x60/0x93
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753039] [<c01020c5>] cpu_idle+0x73/0x96
Jan 4 15:02:48 vwagwolkf320 kernel: [ 112.753048] [<c03b4ef7>] start_secondary+0x19c/0x1a4
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800876]
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800878] =================================
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800884] [ INFO: inconsistent lock state ]
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800888] 2.6.28-03164-g11df0b0 #6
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800891] ---------------------------------
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800894] inconsistent {softirq-on-W} -> {in-softirq-W} usage.
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800899] swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800902] (&fbc->lock){-+..}, at: [<c0222900>] __percpu_counter_add+0x52/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800915] {softirq-on-W} state was registered at:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800919] [<c013fe6f>] __lock_acquire+0x2a6/0xadd
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800926] [<c0140703>] lock_acquire+0x5d/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800933] [<c03b75e9>] _spin_lock+0x1b/0x2a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800939] [<c0222871>] __percpu_counter_sum+0xd/0x4a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800949] [<c01b425b>] ext3_statfs+0xb5/0x159
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800953] [<c01724bc>] vfs_statfs+0x3c/0x55
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800958] [<c0173751>] sys_statfs64+0x44/0x80
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800961] [<c0102fd5>] sysenter_do_call+0x12/0x35
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800965] [<ffffffff>] 0xffffffff
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800974] irq event stamp: 976438
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800976] hardirqs last enabled at (976438): [<c0155959>] free_hot_cold_page+0x138/0x163
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800980] hardirqs last disabled at (976437): [<c01558a4>] free_hot_cold_page+0x83/0x163
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800984] softirqs last enabled at (976396): [<c012794a>] __do_softirq+0x135/0x13d
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800989] softirqs last disabled at (976407): [<c012798c>] do_softirq+0x3a/0x52
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800993]
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800994] other info that might help us debug this:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800996] 3 locks held by swapper/0:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.800998] #0: (rcu_read_lock){..--}, at: [<c0329b36>] netif_receive_skb+0xb0/0x25f
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801005] #1: (rcu_read_lock){..--}, at: [<c033d820>] ip_local_deliver+0x49/0x145
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801011] #2: (slock-AF_INET/1){-+..}, at: [<c0353853>] tcp_v4_rcv+0x20b/0x4fd
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801019]
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801019] stack backtrace:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801022] Pid: 0, comm: swapper Not tainted 2.6.28-03164-g11df0b0 #6
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801024] Call Trace:
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801028] [<c03b5735>] ? printk+0xf/0x11
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801032] [<c013eda5>] valid_state+0x12a/0x13d
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801036] [<c013f1f7>] mark_lock+0x133/0x330
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801039] [<c013fdf2>] __lock_acquire+0x229/0xadd
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801043] [<c013f0e2>] ? mark_lock+0x1e/0x330
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801046] [<c013f447>] ? mark_held_locks+0x53/0x6a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801050] [<c0140703>] lock_acquire+0x5d/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801053] [<c0222900>] ? __percpu_counter_add+0x52/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801056] [<c03b75e9>] _spin_lock+0x1b/0x2a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801060] [<c0222900>] ? __percpu_counter_add+0x52/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801063] [<c0222900>] __percpu_counter_add+0x52/0x7a
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801067] [<c0353268>] tcp_v4_destroy_sock+0x15b/0x164
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801071] [<c0344403>] inet_csk_destroy_sock+0x73/0xe0
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801074] [<c0345c02>] tcp_done+0x5d/0x60
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801078] [<c034e5fe>] tcp_rcv_state_process+0x7a6/0x884
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801081] [<c0353853>] ? tcp_v4_rcv+0x20b/0x4fd
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801084] [<c03535ff>] tcp_v4_do_rcv+0x114/0x15d
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801087] [<c0353962>] tcp_v4_rcv+0x31a/0x4fd
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801090] [<c033d889>] ip_local_deliver+0xb2/0x145
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801093] [<c033d759>] ip_rcv+0x3d1/0x3fb
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801097] [<c0392be7>] ? packet_rcv_spkt+0x9c/0xa4
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801100] [<c0329cb2>] netif_receive_skb+0x22c/0x25f
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801104] [<c029e797>] tg3_poll+0x6a6/0x8bf
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801109] [<c0328a0a>] net_rx_action+0x62/0x13e
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801112] [<c01278a4>] __do_softirq+0x8f/0x13d
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801116] [<c012798c>] do_softirq+0x3a/0x52
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801119] [<c0127ab0>] irq_exit+0x44/0x83
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801122] [<c0104d32>] do_IRQ+0x96/0xac
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801125] [<c010362c>] common_interrupt+0x2c/0x34
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801130] [<c013007b>] ? usermodehelper_disable+0x89/0xa3
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801134] [<c02606a2>] ? acpi_idle_enter_simple+0x151/0x182
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801138] [<c0260373>] acpi_idle_enter_bm+0xc6/0x2a4
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801142] [<c0312f5d>] cpuidle_idle_call+0x60/0x93
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801145] [<c0102139>] cpu_idle+0x70/0x93
Jan 4 15:49:56 vwagwolkf320 kernel: [ 374.801149] [<c03b2fae>] start_secondary+0x19a/0x1a2
