diff mbox

[2.6.35-rc5] INET?: possible irq lock inversion dependency

Message ID 1285055760.2617.27.camel@edumazet-laptop
State Superseded, archived
Delegated to: David Miller
Headers show

Commit Message

Eric Dumazet Sept. 21, 2010, 7:56 a.m. UTC 
Le mardi 21 septembre 2010 à 15:51 +0900, Tetsuo Handa a écrit :
> I succeeded to save undamaged messages by doing
> 
>   echo 1 > /proc/sys/kernel/printk_delay
> 
> . (Well, it would be nice to do above before printing lockdep warning because
> it prints a lot of lines enough to drop some lines.)
> 
> Although my patch is still applied, I believe my patch is not the culprit.
> This warning might be related to lock_sock_fast() which was introduced in
> 2.6.35 because I'm seeing this warning since 2.6.35-rcX . What can I do next?
> 
> Regards.
> 
> [  199.267633] nfsd: last server has exited, flushing export cache
> [  200.784089] 
> [  200.784094] =========================================================
> [  200.786186] [ INFO: possible irq lock inversion dependency detected ]
> [  200.786186] 2.6.36-rc5-old #2
> [  200.786186] ---------------------------------------------------------
> [  200.786186] kworker/0:1/10 just changed the state of lock:
> [  200.786186]  (clock-AF_INET){++.?..}, at: [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
> [  200.786186] but this lock was taken by another, SOFTIRQ-safe lock in the past:
> [  200.786186]  (slock-AF_INET){+.-...}
> [  200.786186] 
> [  200.786186] and interrupts could create inverse lock ordering between them.
> [  200.786186] 
> [  200.786186] 
> [  200.786186] other info that might help us debug this:
> [  200.786186] 3 locks held by kworker/0:1/10:
> [  200.786186]  #0:  (rpciod){+.+.+.}, at: [<c10516f6>] process_one_work+0xd6/0x3a0
> [  200.786186]  #1:  ((&xprt->task_cleanup)){+.+...}, at: [<c10516f6>] process_one_work+0xd6/0x3a0
> [  200.786186]  #2:  (sk_lock-AF_INET-RPC){+.+...}, at: [<c1333119>] inet_shutdown+0x49/0x110
> [  200.786186] 
> [  200.786186] the shortest dependencies between 2nd lock and 1st lock:
> [  200.786186]  -> (slock-AF_INET){+.-...} ops: 11832 {
> [  200.786186]     HARDIRQ-ON-W at:
> [  200.786186]                                          [<c106ab8e>] mark_irqflags+0xfe/0x180
> [  200.786186]                                          [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                          [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                          [<c138ca3e>] _raw_spin_lock_bh+0x3e/0x80
> [  200.786186]                                          [<c12dba59>] lock_sock_fast+0x29/0x90
> [  200.786186]                                          [<c132bdb4>] udp_destroy_sock+0x14/0x40
> [  200.786186]                                          [<c12dbdb3>] sk_common_release+0xb3/0xc0
> [  200.786186]                                          [<c132c728>] udp_lib_close+0x8/0x10
> [  200.786186]                                          [<c133268e>] inet_release+0xbe/0x100
> [  200.786186]                                          [<c12d5f66>] sock_release+0x66/0x80
> [  200.786186]                                          [<c12d6ce2>] sock_close+0x12/0x30
> [  200.786186]                                          [<c10c66fb>] __fput+0x1cb/0x240
> [  200.786186]                                          [<c10c6789>] fput+0x19/0x20
> [  200.786186]                                          [<c10c45c3>] filp_close+0x43/0x70
> [  200.786186]                                          [<c103fded>] close_files+0xad/0x150
> [  200.786186]                                          [<c103fef9>] put_files_struct+0x29/0xf0
> [  200.786186]                                          [<c1040050>] exit_files+0x40/0x50
> [  200.786186]                                          [<c1040716>] do_exit+0x116/0x2e0
> [  200.786186]                                          [<c1040944>] do_group_exit+0x34/0xb0
> [  200.786186]                                          [<c10409cf>] sys_exit_group+0xf/0x20
> [  200.786186]                                          [<c138d4e1>] syscall_call+0x7/0xb
> [  200.786186]     IN-SOFTIRQ-W at:
> [  200.786186]                                          [<c106abae>] mark_irqflags+0x11e/0x180
> [  200.786186]                                          [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                          [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                          [<c138c8c9>] _raw_spin_lock+0x39/0x70
> [  200.786186]                                          [<c12da3f1>] sk_clone+0xb1/0x2c0
> [  200.786186]                                          [<c13108ea>] inet_csk_clone+0x1a/0xb0
> [  200.786186]                                          [<c1325ecc>] tcp_create_openreq_child+0x1c/0x460
> [  200.786186]                                          [<c132359f>] tcp_v4_syn_recv_sock+0x3f/0x1e0
> [  200.786186]                                          [<c132649c>] tcp_check_req+0x18c/0x3b0
> [  200.786186]                                          [<c132378d>] tcp_v4_hnd_req+0x4d/0x160
> [  200.786186]                                          [<c1323ab9>] tcp_v4_do_rcv+0x159/0x280
> [  200.786186]                                          [<c1324154>] tcp_v4_rcv+0x574/0xa30
> [  200.786186]                                          [<c1305f63>] ip_local_deliver_finish+0x103/0x320
> [  200.786186]                                          [<c13061b0>] ip_local_deliver+0x30/0x40
> [  200.786186]                                          [<c1306329>] ip_rcv_finish+0x169/0x480
> [  200.786186]                                          [<c13067da>] ip_rcv+0x19a/0x2b0
> [  200.786186]                                          [<c12e743d>] __netif_receive_skb+0x21d/0x310
> [  200.786186]                                          [<c12e7f48>] process_backlog+0x88/0x160
> [  200.786186]                                          [<c12e8317>] net_rx_action+0x127/0x140
> [  200.786186]                                          [<c1042e90>] __do_softirq+0xd0/0x130
> [  200.786186]     INITIAL USE at:
> [  200.786186]                                         [<c106b740>] __lock_acquire+0x1c0/0x8e0
> [  200.786186]                                         [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                         [<c138ca3e>] _raw_spin_lock_bh+0x3e/0x80
> [  200.786186]                                         [<c12dba59>] lock_sock_fast+0x29/0x90
> [  200.786186]                                         [<c132bdb4>] udp_destroy_sock+0x14/0x40
> [  200.786186]                                         [<c12dbdb3>] sk_common_release+0xb3/0xc0
> [  200.786186]                                         [<c132c728>] udp_lib_close+0x8/0x10
> [  200.786186]                                         [<c133268e>] inet_release+0xbe/0x100
> [  200.786186]                                         [<c12d5f66>] sock_release+0x66/0x80
> [  200.786186]                                         [<c12d6ce2>] sock_close+0x12/0x30
> [  200.786186]                                         [<c10c66fb>] __fput+0x1cb/0x240
> [  200.786186]                                         [<c10c6789>] fput+0x19/0x20
> [  200.786186]                                         [<c10c45c3>] filp_close+0x43/0x70
> [  200.786186]                                         [<c103fded>] close_files+0xad/0x150
> [  200.786186]                                         [<c103fef9>] put_files_struct+0x29/0xf0
> [  200.786186]                                         [<c1040050>] exit_files+0x40/0x50
> [  200.786186]                                         [<c1040716>] do_exit+0x116/0x2e0
> [  200.786186]                                         [<c1040944>] do_group_exit+0x34/0xb0
> [  200.786186]                                         [<c10409cf>] sys_exit_group+0xf/0x20
> [  200.786186]                                         [<c138d4e1>] syscall_call+0x7/0xb
> [  200.786186]   }
> [  200.786186]   ... key      at: [<c1d4d9f0>] af_family_slock_keys+0x10/0x140
> [  200.786186]   ... acquired at:
> [  200.786186]    [<c10693bb>] check_prevs_add+0xab/0x100
> [  200.786186]    [<c1069745>] validate_chain+0x305/0x5a0
> [  200.786186]    [<c106b82d>] __lock_acquire+0x2ad/0x8e0
> [  200.786186]    [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]    [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
> [  200.786186]    [<c1310c16>] inet_csk_listen_stop+0x86/0x160
> [  200.786186]    [<c1313772>] tcp_close+0x382/0x390
> [  200.786186]    [<c133268e>] inet_release+0xbe/0x100
> [  200.786186]    [<c12d5f66>] sock_release+0x66/0x80
> [  200.786186]    [<c12d6ce2>] sock_close+0x12/0x30
> [  200.786186]    [<c10c66fb>] __fput+0x1cb/0x240
> [  200.786186]    [<c10c6789>] fput+0x19/0x20
> [  200.786186]    [<c10c45c3>] filp_close+0x43/0x70
> [  200.786186]    [<c10c465d>] sys_close+0x6d/0x110
> [  200.786186]    [<c138d4e1>] syscall_call+0x7/0xb
> [  200.786186] 
> [  200.786186] -> (clock-AF_INET){++.?..} ops: 2429 {
> [  200.786186]    HARDIRQ-ON-W at:
> [  200.786186]                                        [<c106ab8e>] mark_irqflags+0xfe/0x180
> [  200.786186]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                        [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
> [  200.786186]                                        [<c12dbd2f>] sk_common_release+0x2f/0xc0
> [  200.786186]                                        [<c132c728>] udp_lib_close+0x8/0x10
> [  200.786186]                                        [<c133268e>] inet_release+0xbe/0x100
> [  200.786186]                                        [<c12d5f66>] sock_release+0x66/0x80
> [  200.786186]                                        [<c12d6ce2>] sock_close+0x12/0x30
> [  200.786186]                                        [<c10c66fb>] __fput+0x1cb/0x240
> [  200.786186]                                        [<c10c6789>] fput+0x19/0x20
> [  200.786186]                                        [<c10c45c3>] filp_close+0x43/0x70
> [  200.786186]                                        [<c103fded>] close_files+0xad/0x150
> [  200.786186]                                        [<c103fef9>] put_files_struct+0x29/0xf0
> [  200.786186]                                        [<c1040050>] exit_files+0x40/0x50
> [  200.786186]                                        [<c1040716>] do_exit+0x116/0x2e0
> [  200.786186]                                        [<c1040944>] do_group_exit+0x34/0xb0
> [  200.786186]                                        [<c10409cf>] sys_exit_group+0xf/0x20
> [  200.786186]                                        [<c138d4e1>] syscall_call+0x7/0xb
> [  200.786186]    HARDIRQ-ON-R at:
> [  200.786186]                                        [<c106aafe>] mark_irqflags+0x6e/0x180
> [  200.786186]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                        [<c138cbe9>] _raw_read_lock+0x39/0x70
> [  200.786186]                                        [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]                                        [<c131c8a8>] tcp_rcv_synsent_state_process+0x398/0x590
> [  200.786186]                                        [<c131cf47>] tcp_rcv_state_process+0x4a7/0x560
> [  200.786186]                                        [<c13239d1>] tcp_v4_do_rcv+0x71/0x280
> [  200.786186]                                        [<c12dad26>] __release_sock+0x66/0x150
> [  200.786186]                                        [<c12dba27>] release_sock+0x87/0x90
> [  200.786186]                                        [<c1332a7a>] inet_stream_connect+0x5a/0x1b0
> [  200.786186]                                        [<c12d8888>] kernel_connect+0x18/0x30
> [  200.786186]                                        [<c135f66e>] xs_tcp_finish_connecting+0x4e/0x120
> [  200.786186]                                        [<c135f79b>] xs_tcp_setup_socket+0x5b/0x180
> [  200.786186]                                        [<c135f9d4>] xs_tcp_connect_worker4+0x14/0x20
> [  200.786186]                                        [<c1051767>] process_one_work+0x147/0x3a0
> [  200.786186]                                        [<c1051aa6>] worker_thread+0xa6/0x200
> [  200.786186]                                        [<c1056985>] kthread+0x75/0x80
> [  200.786186]                                        [<c10031fa>] kernel_thread_helper+0x6/0x1c
> [  200.786186]    IN-SOFTIRQ-R at:
> [  200.786186]                                        [<c106abae>] mark_irqflags+0x11e/0x180
> [  200.786186]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                        [<c138cbe9>] _raw_read_lock+0x39/0x70
> [  200.786186]                                        [<c135e891>] xs_tcp_data_ready+0x21/0x90
> [  200.786186]                                        [<c131ad68>] tcp_data_queue+0x248/0x820
> [  200.786186]                                        [<c131c0de>] tcp_rcv_established+0xae/0x4e0
> [  200.786186]                                        [<c1323b31>] tcp_v4_do_rcv+0x1d1/0x280
> [  200.786186]                                        [<c1324154>] tcp_v4_rcv+0x574/0xa30
> [  200.786186]                                        [<c1305f63>] ip_local_deliver_finish+0x103/0x320
> [  200.786186]                                        [<c13061b0>] ip_local_deliver+0x30/0x40
> [  200.786186]                                        [<c1306329>] ip_rcv_finish+0x169/0x480
> [  200.786186]                                        [<c13067da>] ip_rcv+0x19a/0x2b0
> [  200.786186]                                        [<c12e743d>] __netif_receive_skb+0x21d/0x310
> [  200.786186]                                        [<c12e7f48>] process_backlog+0x88/0x160
> [  200.786186]                                        [<c12e8317>] net_rx_action+0x127/0x140
> [  200.786186]                                        [<c1042e90>] __do_softirq+0xd0/0x130
> [  200.786186]    SOFTIRQ-ON-R at:
> [  200.786186]                                        [<c106ab72>] mark_irqflags+0xe2/0x180
> [  200.786186]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                        [<c138cbe9>] _raw_read_lock+0x39/0x70
> [  200.786186]                                        [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]                                        [<c1333167>] inet_shutdown+0x97/0x110
> [  200.786186]                                        [<c12d8a89>] kernel_sock_shutdown+0x9/0x10
> [  200.786186]                                        [<c135dcb7>] xs_tcp_shutdown+0x17/0x20
> [  200.786186]                                        [<c135dfb7>] xs_tcp_close+0x27/0x30
> [  200.786186]                                        [<c135c20d>] xprt_autoclose+0x1d/0x50
> [  200.786186]                                        [<c1051767>] process_one_work+0x147/0x3a0
> [  200.786186]                                        [<c1051aa6>] worker_thread+0xa6/0x200
> [  200.786186]                                        [<c1056985>] kthread+0x75/0x80
> [  200.786186]                                        [<c10031fa>] kernel_thread_helper+0x6/0x1c
> [  200.786186]    INITIAL USE at:
> [  200.786186]                                       [<c106b740>] __lock_acquire+0x1c0/0x8e0
> [  200.786186]                                       [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]                                       [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
> [  200.786186]                                       [<c12dbd2f>] sk_common_release+0x2f/0xc0
> [  200.786186]                                       [<c132c728>] udp_lib_close+0x8/0x10
> [  200.786186]                                       [<c133268e>] inet_release+0xbe/0x100
> [  200.786186]                                       [<c12d5f66>] sock_release+0x66/0x80
> [  200.786186]                                       [<c12d6ce2>] sock_close+0x12/0x30
> [  200.786186]                                       [<c10c66fb>] __fput+0x1cb/0x240
> [  200.786186]                                       [<c10c6789>] fput+0x19/0x20
> [  200.786186]                                       [<c10c45c3>] filp_close+0x43/0x70
> [  200.786186]                                       [<c103fded>] close_files+0xad/0x150
> [  200.786186]                                       [<c103fef9>] put_files_struct+0x29/0xf0
> [  200.786186]                                       [<c1040050>] exit_files+0x40/0x50
> [  200.786186]                                       [<c1040716>] do_exit+0x116/0x2e0
> [  200.786186]                                       [<c1040944>] do_group_exit+0x34/0xb0
> [  200.786186]                                       [<c10409cf>] sys_exit_group+0xf/0x20
> [  200.786186]                                       [<c138d4e1>] syscall_call+0x7/0xb
> [  200.786186]  }
> [  200.786186]  ... key      at: [<c1d4db30>] af_callback_keys+0x10/0x130
> [  200.786186]  ... acquired at:
> [  200.786186]    [<c1069ff6>] check_usage_backwards+0x76/0xd0
> [  200.786186]    [<c106a209>] mark_lock_irq+0x99/0x240
> [  200.786186]    [<c106aeac>] mark_lock+0x21c/0x3c0
> [  200.786186]    [<c106ab72>] mark_irqflags+0xe2/0x180
> [  200.786186]    [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]    [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]    [<c138cbe9>] _raw_read_lock+0x39/0x70
> [  200.786186]    [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]    [<c1333167>] inet_shutdown+0x97/0x110
> [  200.786186]    [<c12d8a89>] kernel_sock_shutdown+0x9/0x10
> [  200.786186]    [<c135dcb7>] xs_tcp_shutdown+0x17/0x20
> [  200.786186]    [<c135dfb7>] xs_tcp_close+0x27/0x30
> [  200.786186]    [<c135c20d>] xprt_autoclose+0x1d/0x50
> [  200.786186]    [<c1051767>] process_one_work+0x147/0x3a0
> [  200.786186]    [<c1051aa6>] worker_thread+0xa6/0x200
> [  200.786186]    [<c1056985>] kthread+0x75/0x80
> [  200.786186]    [<c10031fa>] kernel_thread_helper+0x6/0x1c
> [  200.786186] 
> [  200.786186] 
> [  200.786186] stack backtrace:
> [  200.786186] Pid: 10, comm: kworker/0:1 Not tainted 2.6.36-rc5-old #2
> [  200.786186] Call Trace:
> [  200.786186]  [<c103ded8>] ? printk+0x18/0x20
> [  200.786186]  [<c1069e88>] print_irq_inversion_bug+0x108/0x120
> [  200.786186]  [<c1069ff6>] check_usage_backwards+0x76/0xd0
> [  200.786186]  [<c106a209>] mark_lock_irq+0x99/0x240
> [  200.786186]  [<c1069f80>] ? check_usage_backwards+0x0/0xd0
> [  200.786186]  [<c106aeac>] mark_lock+0x21c/0x3c0
> [  200.786186]  [<c106ab72>] mark_irqflags+0xe2/0x180
> [  200.786186]  [<c106b90d>] __lock_acquire+0x38d/0x8e0
> [  200.786186]  [<c106cc0a>] ? __lock_is_held+0x3a/0x60
> [  200.786186]  [<c106ceaa>] lock_acquire+0x7a/0xa0
> [  200.786186]  [<c135e9be>] ? xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]  [<c138cbe9>] _raw_read_lock+0x39/0x70
> [  200.786186]  [<c135e9be>] ? xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]  [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
> [  200.786186]  [<c131fddf>] ? tcp_send_fin+0x4f/0xc0
> [  200.786186]  [<c1333167>] inet_shutdown+0x97/0x110
> [  200.786186]  [<c12d8a89>] kernel_sock_shutdown+0x9/0x10
> [  200.786186]  [<c135dcb7>] xs_tcp_shutdown+0x17/0x20
> [  200.786186]  [<c135dfb7>] xs_tcp_close+0x27/0x30
> [  200.786186]  [<c135c20d>] xprt_autoclose+0x1d/0x50
> [  200.786186]  [<c1051767>] process_one_work+0x147/0x3a0
> [  200.786186]  [<c10516f6>] ? process_one_work+0xd6/0x3a0
> [  200.786186]  [<c106d429>] ? __lock_acquired+0x119/0x1c0
> [  200.786186]  [<c135c1f0>] ? xprt_autoclose+0x0/0x50
> [  200.786186]  [<c1051a1c>] ? worker_thread+0x1c/0x200
> [  200.786186]  [<c1050537>] ? __need_more_worker+0x17/0x40
> [  200.786186]  [<c1051aa6>] worker_thread+0xa6/0x200
> [  200.786186]  [<c1056985>] kthread+0x75/0x80
> [  200.786186]  [<c1051a00>] ? worker_thread+0x0/0x200
> [  200.786186]  [<c1056910>] ? kthread+0x0/0x80
> [  200.786186]  [<c10031fa>] kernel_thread_helper+0x6/0x1c
> [  208.718821] Restarting system.
> [  208.720581] machine restart


I would say someone calls xs_tcp_state_change() while softirqs are not
masked.

If its expected, then following patch is needed ?



--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Comments

Tetsuo Handa Sept. 21, 2010, 9:10 a.m. UTC | #1 
Eric Dumazet wrote:
> I would say someone calls xs_tcp_state_change() while softirqs are not
> masked.
> 
> If its expected, then following patch is needed ?

After applying your patch, I got the same warning on different place.
I got this when doing "mount 127.0.0.1:/usr/src/ /mnt/".

Regards.

[  320.747630] 
[  320.747633] =========================================================
[  320.749957] [ INFO: possible irq lock inversion dependency detected ]
[  320.749957] 2.6.36-rc5-old #3
[  320.749957] ---------------------------------------------------------
[  320.749957] mount/3799 just changed the state of lock:
[  320.749957]  (clock-AF_INET){++.?..}, at: [<c135ec4c>] xs_udp_write_space+0x1c/0x50
[  320.749957] but this lock was taken by another, SOFTIRQ-safe lock in the past:
[  320.749957]  (slock-AF_INET){+.-...}
[  320.749957] 
[  320.749957] and interrupts could create inverse lock ordering between them.
[  320.749957] 
[  320.749957] 
[  320.749957] other info that might help us debug this:
[  320.749957] no locks held by mount/3799.
[  320.749957] 
[  320.749957] the shortest dependencies between 2nd lock and 1st lock:
[  320.749957]  -> (slock-AF_INET){+.-...} ops: 4340 {
[  320.749957]     HARDIRQ-ON-W at:
[  320.749957]                                          [<c106ab8e>] mark_irqflags+0xfe/0x180
[  320.749957]                                          [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                          [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                          [<c138ca3e>] _raw_spin_lock_bh+0x3e/0x80
[  320.749957]                                          [<c12dba59>] lock_sock_fast+0x29/0x90
[  320.749957]                                          [<c132bdb4>] udp_destroy_sock+0x14/0x40
[  320.749957]                                          [<c12dbdb3>] sk_common_release+0xb3/0xc0
[  320.749957]                                          [<c132c728>] udp_lib_close+0x8/0x10
[  320.749957]                                          [<c133268e>] inet_release+0xbe/0x100
[  320.749957]                                          [<c12d5f66>] sock_release+0x66/0x80
[  320.749957]                                          [<c12d6ce2>] sock_close+0x12/0x30
[  320.749957]                                          [<c10c66fb>] __fput+0x1cb/0x240
[  320.749957]                                          [<c10c6789>] fput+0x19/0x20
[  320.749957]                                          [<c10c45c3>] filp_close+0x43/0x70
[  320.749957]                                          [<c103fded>] close_files+0xad/0x150
[  320.749957]                                          [<c103fef9>] put_files_struct+0x29/0xf0
[  320.749957]                                          [<c1040050>] exit_files+0x40/0x50
[  320.749957]                                          [<c1040716>] do_exit+0x116/0x2e0
[  320.749957]                                          [<c1040944>] do_group_exit+0x34/0xb0
[  320.749957]                                          [<c10409cf>] sys_exit_group+0xf/0x20
[  320.749957]                                          [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957]     IN-SOFTIRQ-W at:
[  320.749957]                                          [<c106abae>] mark_irqflags+0x11e/0x180
[  320.749957]                                          [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                          [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                          [<c138c8c9>] _raw_spin_lock+0x39/0x70
[  320.749957]                                          [<c12da3f1>] sk_clone+0xb1/0x2c0
[  320.749957]                                          [<c13108ea>] inet_csk_clone+0x1a/0xb0
[  320.749957]                                          [<c1325ecc>] tcp_create_openreq_child+0x1c/0x460
[  320.749957]                                          [<c132359f>] tcp_v4_syn_recv_sock+0x3f/0x1e0
[  320.749957]                                          [<c132649c>] tcp_check_req+0x18c/0x3b0
[  320.749957]                                          [<c132378d>] tcp_v4_hnd_req+0x4d/0x160
[  320.749957]                                          [<c1323ab9>] tcp_v4_do_rcv+0x159/0x280
[  320.749957]                                          [<c1324154>] tcp_v4_rcv+0x574/0xa30
[  320.749957]                                          [<c1305f63>] ip_local_deliver_finish+0x103/0x320
[  320.749957]                                          [<c13061b0>] ip_local_deliver+0x30/0x40
[  320.749957]                                          [<c1306329>] ip_rcv_finish+0x169/0x480
[  320.749957]                                          [<c13067da>] ip_rcv+0x19a/0x2b0
[  320.749957]                                          [<c12e743d>] __netif_receive_skb+0x21d/0x310
[  320.749957]                                          [<c12e7f48>] process_backlog+0x88/0x160
[  320.749957]                                          [<c12e8317>] net_rx_action+0x127/0x140
[  320.749957]                                          [<c1042e90>] __do_softirq+0xd0/0x130
[  320.749957]     INITIAL USE at:
[  320.749957]                                         [<c106b740>] __lock_acquire+0x1c0/0x8e0
[  320.749957]                                         [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                         [<c138ca3e>] _raw_spin_lock_bh+0x3e/0x80
[  320.749957]                                         [<c12dba59>] lock_sock_fast+0x29/0x90
[  320.749957]                                         [<c132bdb4>] udp_destroy_sock+0x14/0x40
[  320.749957]                                         [<c12dbdb3>] sk_common_release+0xb3/0xc0
[  320.749957]                                         [<c132c728>] udp_lib_close+0x8/0x10
[  320.749957]                                         [<c133268e>] inet_release+0xbe/0x100
[  320.749957]                                         [<c12d5f66>] sock_release+0x66/0x80
[  320.749957]                                         [<c12d6ce2>] sock_close+0x12/0x30
[  320.749957]                                         [<c10c66fb>] __fput+0x1cb/0x240
[  320.749957]                                         [<c10c6789>] fput+0x19/0x20
[  320.749957]                                         [<c10c45c3>] filp_close+0x43/0x70
[  320.749957]                                         [<c103fded>] close_files+0xad/0x150
[  320.749957]                                         [<c103fef9>] put_files_struct+0x29/0xf0
[  320.749957]                                         [<c1040050>] exit_files+0x40/0x50
[  320.749957]                                         [<c1040716>] do_exit+0x116/0x2e0
[  320.749957]                                         [<c1040944>] do_group_exit+0x34/0xb0
[  320.749957]                                         [<c10409cf>] sys_exit_group+0xf/0x20
[  320.749957]                                         [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957]   }
[  320.749957]   ... key      at: [<c1d4d9f0>] af_family_slock_keys+0x10/0x140
[  320.749957]   ... acquired at:
[  320.749957]    [<c10693bb>] check_prevs_add+0xab/0x100
[  320.749957]    [<c1069745>] validate_chain+0x305/0x5a0
[  320.749957]    [<c106b82d>] __lock_acquire+0x2ad/0x8e0
[  320.749957]    [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]    [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
[  320.749957]    [<c1310c16>] inet_csk_listen_stop+0x86/0x160
[  320.749957]    [<c1313772>] tcp_close+0x382/0x390
[  320.749957]    [<c133268e>] inet_release+0xbe/0x100
[  320.749957]    [<c12d5f66>] sock_release+0x66/0x80
[  320.749957]    [<c12d6ce2>] sock_close+0x12/0x30
[  320.749957]    [<c10c66fb>] __fput+0x1cb/0x240
[  320.749957]    [<c10c6789>] fput+0x19/0x20
[  320.749957]    [<c10c45c3>] filp_close+0x43/0x70
[  320.749957]    [<c10c465d>] sys_close+0x6d/0x110
[  320.749957]    [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957] 
[  320.749957] -> (clock-AF_INET){++.?..} ops: 850 {
[  320.749957]    HARDIRQ-ON-W at:
[  320.749957]                                        [<c106ab8e>] mark_irqflags+0xfe/0x180
[  320.749957]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                        [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
[  320.749957]                                        [<c12dbd2f>] sk_common_release+0x2f/0xc0
[  320.749957]                                        [<c132c728>] udp_lib_close+0x8/0x10
[  320.749957]                                        [<c133268e>] inet_release+0xbe/0x100
[  320.749957]                                        [<c12d5f66>] sock_release+0x66/0x80
[  320.749957]                                        [<c12d6ce2>] sock_close+0x12/0x30
[  320.749957]                                        [<c10c66fb>] __fput+0x1cb/0x240
[  320.749957]                                        [<c10c6789>] fput+0x19/0x20
[  320.749957]                                        [<c10c45c3>] filp_close+0x43/0x70
[  320.749957]                                        [<c103fded>] close_files+0xad/0x150
[  320.749957]                                        [<c103fef9>] put_files_struct+0x29/0xf0
[  320.749957]                                        [<c1040050>] exit_files+0x40/0x50
[  320.749957]                                        [<c1040716>] do_exit+0x116/0x2e0
[  320.749957]                                        [<c1040944>] do_group_exit+0x34/0xb0
[  320.749957]                                        [<c10409cf>] sys_exit_group+0xf/0x20
[  320.749957]                                        [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957]    HARDIRQ-ON-R at:
[  320.749957]                                        [<c106aafe>] mark_irqflags+0x6e/0x180
[  320.749957]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                        [<c138cd5e>] _raw_read_lock_bh+0x3e/0x80
[  320.749957]                                        [<c135e9be>] xs_tcp_state_change+0x1e/0x1d0
[  320.749957]                                        [<c131c8a8>] tcp_rcv_synsent_state_process+0x398/0x590
[  320.749957]                                        [<c131cf47>] tcp_rcv_state_process+0x4a7/0x560
[  320.749957]                                        [<c13239d1>] tcp_v4_do_rcv+0x71/0x280
[  320.749957]                                        [<c12dad26>] __release_sock+0x66/0x150
[  320.749957]                                        [<c12dba27>] release_sock+0x87/0x90
[  320.749957]                                        [<c1332a7a>] inet_stream_connect+0x5a/0x1b0
[  320.749957]                                        [<c12d8888>] kernel_connect+0x18/0x30
[  320.749957]                                        [<c135f66e>] xs_tcp_finish_connecting+0x4e/0x120
[  320.749957]                                        [<c135f79b>] xs_tcp_setup_socket+0x5b/0x180
[  320.749957]                                        [<c135f9d4>] xs_tcp_connect_worker4+0x14/0x20
[  320.749957]                                        [<c1051767>] process_one_work+0x147/0x3a0
[  320.749957]                                        [<c1051aa6>] worker_thread+0xa6/0x200
[  320.749957]                                        [<c1056985>] kthread+0x75/0x80
[  320.749957]                                        [<c10031fa>] kernel_thread_helper+0x6/0x1c
[  320.749957]    IN-SOFTIRQ-R at:
[  320.749957]                                        [<c106abae>] mark_irqflags+0x11e/0x180
[  320.749957]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                        [<c138cbe9>] _raw_read_lock+0x39/0x70
[  320.749957]                                        [<c135e891>] xs_tcp_data_ready+0x21/0x90
[  320.749957]                                        [<c131ad68>] tcp_data_queue+0x248/0x820
[  320.749957]                                        [<c131c0de>] tcp_rcv_established+0xae/0x4e0
[  320.749957]                                        [<c1323b31>] tcp_v4_do_rcv+0x1d1/0x280
[  320.749957]                                        [<c1324154>] tcp_v4_rcv+0x574/0xa30
[  320.749957]                                        [<c1305f63>] ip_local_deliver_finish+0x103/0x320
[  320.749957]                                        [<c13061b0>] ip_local_deliver+0x30/0x40
[  320.749957]                                        [<c1306329>] ip_rcv_finish+0x169/0x480
[  320.749957]                                        [<c13067da>] ip_rcv+0x19a/0x2b0
[  320.749957]                                        [<c12e743d>] __netif_receive_skb+0x21d/0x310
[  320.749957]                                        [<c12e7f48>] process_backlog+0x88/0x160
[  320.749957]                                        [<c12e8317>] net_rx_action+0x127/0x140
[  320.749957]                                        [<c1042e90>] __do_softirq+0xd0/0x130
[  320.749957]    SOFTIRQ-ON-R at:
[  320.749957]                                        [<c106ab72>] mark_irqflags+0xe2/0x180
[  320.749957]                                        [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]                                        [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                        [<c138cbe9>] _raw_read_lock+0x39/0x70
[  320.749957]                                        [<c135ec4c>] xs_udp_write_space+0x1c/0x50
[  320.749957]                                        [<c135ed5a>] xs_udp_do_set_buffer_size+0x8a/0x90
[  320.749957]                                        [<c135ed9d>] xs_udp_set_buffer_size+0x3d/0x40
[  320.749957]                                        [<c135a0e8>] rpc_setbufsize+0x28/0x30
[  320.749957]                                        [<e09c4314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[  320.749957]                                        [<e09c4415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[  320.749957]                                        [<e09c4717>] nfs_create_server+0x87/0x240 [nfs]
[  320.749957]                                        [<e09ceaeb>] nfs_get_sb+0x8b/0x240 [nfs]
[  320.749957]                                        [<c10c82c1>] vfs_kern_mount+0x71/0x190
[  320.749957]                                        [<c10c8607>] do_kern_mount+0x37/0x90
[  320.749957]                                        [<c10deae7>] do_new_mount+0x57/0xa0
[  320.749957]                                        [<c10df111>] do_mount+0x171/0x1b0
[  320.749957]                                        [<c10df40c>] sys_mount+0x6c/0xa0
[  320.749957]                                        [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957]    INITIAL USE at:
[  320.749957]                                       [<c106b740>] __lock_acquire+0x1c0/0x8e0
[  320.749957]                                       [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]                                       [<c138d07e>] _raw_write_lock_bh+0x3e/0x80
[  320.749957]                                       [<c12dbd2f>] sk_common_release+0x2f/0xc0
[  320.749957]                                       [<c132c728>] udp_lib_close+0x8/0x10
[  320.749957]                                       [<c133268e>] inet_release+0xbe/0x100
[  320.749957]                                       [<c12d5f66>] sock_release+0x66/0x80
[  320.749957]                                       [<c12d6ce2>] sock_close+0x12/0x30
[  320.749957]                                       [<c10c66fb>] __fput+0x1cb/0x240
[  320.749957]                                       [<c10c6789>] fput+0x19/0x20
[  320.749957]                                       [<c10c45c3>] filp_close+0x43/0x70
[  320.749957]                                       [<c103fded>] close_files+0xad/0x150
[  320.749957]                                       [<c103fef9>] put_files_struct+0x29/0xf0
[  320.749957]                                       [<c1040050>] exit_files+0x40/0x50
[  320.749957]                                       [<c1040716>] do_exit+0x116/0x2e0
[  320.749957]                                       [<c1040944>] do_group_exit+0x34/0xb0
[  320.749957]                                       [<c10409cf>] sys_exit_group+0xf/0x20
[  320.749957]                                       [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957]  }
[  320.749957]  ... key      at: [<c1d4db30>] af_callback_keys+0x10/0x130
[  320.749957]  ... acquired at:
[  320.749957]    [<c1069ff6>] check_usage_backwards+0x76/0xd0
[  320.749957]    [<c106a209>] mark_lock_irq+0x99/0x240
[  320.749957]    [<c106aeac>] mark_lock+0x21c/0x3c0
[  320.749957]    [<c106ab72>] mark_irqflags+0xe2/0x180
[  320.749957]    [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]    [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]    [<c138cbe9>] _raw_read_lock+0x39/0x70
[  320.749957]    [<c135ec4c>] xs_udp_write_space+0x1c/0x50
[  320.749957]    [<c135ed5a>] xs_udp_do_set_buffer_size+0x8a/0x90
[  320.749957]    [<c135ed9d>] xs_udp_set_buffer_size+0x3d/0x40
[  320.749957]    [<c135a0e8>] rpc_setbufsize+0x28/0x30
[  320.749957]    [<e09c4314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[  320.749957]    [<e09c4415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[  320.749957]    [<e09c4717>] nfs_create_server+0x87/0x240 [nfs]
[  320.749957]    [<e09ceaeb>] nfs_get_sb+0x8b/0x240 [nfs]
[  320.749957]    [<c10c82c1>] vfs_kern_mount+0x71/0x190
[  320.749957]    [<c10c8607>] do_kern_mount+0x37/0x90
[  320.749957]    [<c10deae7>] do_new_mount+0x57/0xa0
[  320.749957]    [<c10df111>] do_mount+0x171/0x1b0
[  320.749957]    [<c10df40c>] sys_mount+0x6c/0xa0
[  320.749957]    [<c138d4e1>] syscall_call+0x7/0xb
[  320.749957] 
[  320.749957] 
[  320.749957] stack backtrace:
[  320.749957] Pid: 3799, comm: mount Not tainted 2.6.36-rc5-old #3
[  320.749957] Call Trace:
[  320.749957]  [<c103ded8>] ? printk+0x18/0x20
[  320.749957]  [<c1069e88>] print_irq_inversion_bug+0x108/0x120
[  320.749957]  [<c1069ff6>] check_usage_backwards+0x76/0xd0
[  320.749957]  [<c106a209>] mark_lock_irq+0x99/0x240
[  320.749957]  [<c1069f80>] ? check_usage_backwards+0x0/0xd0
[  320.749957]  [<c106aeac>] mark_lock+0x21c/0x3c0
[  320.749957]  [<c106ab72>] mark_irqflags+0xe2/0x180
[  320.749957]  [<c106b90d>] __lock_acquire+0x38d/0x8e0
[  320.749957]  [<c109a95e>] ? mempool_free_slab+0xe/0x10
[  320.749957]  [<c109a938>] ? mempool_free+0x98/0xa0
[  320.749957]  [<c106ceaa>] lock_acquire+0x7a/0xa0
[  320.749957]  [<c135ec4c>] ? xs_udp_write_space+0x1c/0x50
[  320.749957]  [<c138cbe9>] _raw_read_lock+0x39/0x70
[  320.749957]  [<c135ec4c>] ? xs_udp_write_space+0x1c/0x50
[  320.749957]  [<c135ec4c>] xs_udp_write_space+0x1c/0x50
[  320.749957]  [<c135ed5a>] xs_udp_do_set_buffer_size+0x8a/0x90
[  320.749957]  [<c135ed9d>] xs_udp_set_buffer_size+0x3d/0x40
[  320.749957]  [<c135ed60>] ? xs_udp_set_buffer_size+0x0/0x40
[  320.749957]  [<c135a0e8>] rpc_setbufsize+0x28/0x30
[  320.749957]  [<e09c4314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[  320.749957]  [<e09c4415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[  320.749957]  [<c10bf8b8>] ? cache_alloc_debugcheck_after+0x98/0x1d0
[  320.749957]  [<e09cb1d3>] ? nfs_alloc_fattr+0x23/0x30 [nfs]
[  320.749957]  [<e09c4717>] nfs_create_server+0x87/0x240 [nfs]
[  320.749957]  [<e09cb1f5>] ? nfs_alloc_fhandle+0x15/0x30 [nfs]
[  320.749957]  [<e09ceaeb>] nfs_get_sb+0x8b/0x240 [nfs]
[  320.749957]  [<e09ce9b0>] ? nfs_compare_super+0x0/0x90 [nfs]
[  320.749957]  [<c10c82c1>] vfs_kern_mount+0x71/0x190
[  320.749957]  [<c10dc4fc>] ? get_fs_type+0x8c/0xa0
[  320.749957]  [<c10c8607>] do_kern_mount+0x37/0x90
[  320.749957]  [<c10deae7>] do_new_mount+0x57/0xa0
[  320.749957]  [<c10df111>] do_mount+0x171/0x1b0
[  320.749957]  [<c10df40c>] sys_mount+0x6c/0xa0
[  320.749957]  [<c138d4e1>] syscall_call+0x7/0xb
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Eric Dumazet Sept. 21, 2010, 9:35 a.m. UTC | #2 
Le mardi 21 septembre 2010 à 18:10 +0900, Tetsuo Handa a écrit :
> Eric Dumazet wrote:
> > I would say someone calls xs_tcp_state_change() while softirqs are not
> > masked.
> > 
> > If its expected, then following patch is needed ?
> 
> After applying your patch, I got the same warning on different place.
> I got this when doing "mount 127.0.0.1:/usr/src/ /mnt/".

Hmm, but what are the changes in your tree ?


--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Eric Dumazet Sept. 21, 2010, 10:13 a.m. UTC | #3 
Le mardi 21 septembre 2010 à 11:36 +0200, Eric Dumazet a écrit :
> Le mardi 21 septembre 2010 à 18:10 +0900, Tetsuo Handa a écrit :
> > Eric Dumazet wrote:
> > > I would say someone calls xs_tcp_state_change() while softirqs are not
> > > masked.
> > > 
> > > If its expected, then following patch is needed ?
> > 
> > After applying your patch, I got the same warning on different place.
> > I got this when doing "mount 127.0.0.1:/usr/src/ /mnt/".
> 
> Hmm, but what are the changes in your tree ?
> 

(Because I dont have these lockdep splats here with 2.6.36-rc5)



--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Tetsuo Handa Sept. 22, 2010, 7:14 a.m. UTC | #4 
I established steps to reproduce this warning using clean 2.6.36-rc5 .

[   37.539697] =========================================================
[   37.541991] [ INFO: possible irq lock inversion dependency detected ]
[   37.541991] 2.6.36-rc5 #1
[   37.541991] ---------------------------------------------------------
[   37.541991] mount/2681 just changed the state of lock:
[   37.541991]  (clock-AF_INET){++.?..}, at: [<c135e03c>] xs_udp_write_space+0x1c/0x50
[   37.541991] but this lock was taken by another, SOFTIRQ-safe lock in the past:
[   37.541991]  (slock-AF_INET){+.-...}
[   37.541991] 
[   37.541991] and interrupts could create inverse lock ordering between them.
[   37.541991] 
[   37.541991] 
[   37.541991] other info that might help us debug this:
[   37.541991] no locks held by mount/2681.
[   37.541991] 
[   37.541991] the shortest dependencies between 2nd lock and 1st lock:
[   37.541991]  -> (slock-AF_INET){+.-...} ops: 562 {
[   37.541991]     HARDIRQ-ON-W at:
[   37.541991]                                          [<c106a8de>] mark_irqflags+0xfe/0x180
[   37.541991]                                          [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.541991]                                          [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.541991]                                          [<c138be2e>] _raw_spin_lock_bh+0x3e/0x80
[   37.541991]                                          [<c12daf39>] lock_sock_fast+0x29/0x90
[   37.541991]                                          [<c132b1a4>] udp_destroy_sock+0x14/0x40
[   37.541991]                                          [<c12db293>] sk_common_release+0xb3/0xc0
[   37.541991]                                          [<c132bb18>] udp_lib_close+0x8/0x10
[   37.541991]                                          [<c1331a7e>] inet_release+0xbe/0x100
[   37.541991]                                          [<c12d5476>] sock_release+0x66/0x80
[   37.541991]                                          [<c12d61f2>] sock_close+0x12/0x30
[   37.541991]                                          [<c10c637b>] __fput+0x1cb/0x240
[   37.541991]                                          [<c10c6409>] fput+0x19/0x20
[   37.541991]                                          [<c10c4263>] filp_close+0x43/0x70
[   37.541991]                                          [<c103fdcd>] close_files+0xad/0x150
[   37.541991]                                          [<c103fed9>] put_files_struct+0x29/0xf0
[   37.541991]                                          [<c1040030>] exit_files+0x40/0x50
[   37.541991]                                          [<c10406f6>] do_exit+0x116/0x2e0
[   37.541991]                                          [<c1040924>] do_group_exit+0x34/0xb0
[   37.541991]                                          [<c10409af>] sys_exit_group+0xf/0x20
[   37.541991]                                          [<c138c8d1>] syscall_call+0x7/0xb
[   37.541991]     IN-SOFTIRQ-W at:
[   37.541991]                                          [<c106a8fe>] mark_irqflags+0x11e/0x180
[   37.541991]                                          [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.541991]                                          [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.541991]                                          [<c138bcb9>] _raw_spin_lock+0x39/0x70
[   37.541991]                                          [<c12d98d1>] sk_clone+0xb1/0x2c0
[   37.541991]                                          [<c130fd7a>] inet_csk_clone+0x1a/0xb0
[   37.541991]                                          [<c132535c>] tcp_create_openreq_child+0x1c/0x460
[   37.541991]                                          [<c1322a2f>] tcp_v4_syn_recv_sock+0x3f/0x1e0
[   37.940862]                                          [<c132592c>] tcp_check_req+0x18c/0x3b0
[   37.940862]                                          [<c1322c1d>] tcp_v4_hnd_req+0x4d/0x160
[   37.940862]                                          [<c1322f49>] tcp_v4_do_rcv+0x159/0x280
[   37.940862]                                          [<c13235e4>] tcp_v4_rcv+0x574/0xa30
[   37.940862]                                          [<c1305443>] ip_local_deliver_finish+0x103/0x320
[   37.940862]                                          [<c1305690>] ip_local_deliver+0x30/0x40
[   37.940862]                                          [<c1305809>] ip_rcv_finish+0x169/0x480
[   37.940862]                                          [<c1305cba>] ip_rcv+0x19a/0x2b0
[   37.940862]                                          [<c12e691d>] __netif_receive_skb+0x21d/0x310
[   37.940862]                                          [<c12e7428>] process_backlog+0x88/0x160
[   37.940862]                                          [<c12e77f7>] net_rx_action+0x127/0x140
[   37.940862]                                          [<c1042e70>] __do_softirq+0xd0/0x130
[   37.940862]     INITIAL USE at:
[   37.940862]                                         [<c106b490>] __lock_acquire+0x1c0/0x8e0
[   37.940862]                                         [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                         [<c138be2e>] _raw_spin_lock_bh+0x3e/0x80
[   37.940862]                                         [<c12daf39>] lock_sock_fast+0x29/0x90
[   37.940862]                                         [<c132b1a4>] udp_destroy_sock+0x14/0x40
[   37.940862]                                         [<c12db293>] sk_common_release+0xb3/0xc0
[   37.940862]                                         [<c132bb18>] udp_lib_close+0x8/0x10
[   37.940862]                                         [<c1331a7e>] inet_release+0xbe/0x100
[   37.940862]                                         [<c12d5476>] sock_release+0x66/0x80
[   37.940862]                                         [<c12d61f2>] sock_close+0x12/0x30
[   37.940862]                                         [<c10c637b>] __fput+0x1cb/0x240
[   37.940862]                                         [<c10c6409>] fput+0x19/0x20
[   37.940862]                                         [<c10c4263>] filp_close+0x43/0x70
[   37.940862]                                         [<c103fdcd>] close_files+0xad/0x150
[   37.940862]                                         [<c103fed9>] put_files_struct+0x29/0xf0
[   37.940862]                                         [<c1040030>] exit_files+0x40/0x50
[   37.940862]                                         [<c10406f6>] do_exit+0x116/0x2e0
[   37.940862]                                         [<c1040924>] do_group_exit+0x34/0xb0
[   37.940862]                                         [<c10409af>] sys_exit_group+0xf/0x20
[   37.940862]                                         [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862]   }
[   37.940862]   ... key      at: [<c1d4c9d0>] af_family_slock_keys+0x10/0x140
[   37.940862]   ... acquired at:
[   37.940862]    [<c106910b>] check_prevs_add+0xab/0x100
[   37.940862]    [<c1069495>] validate_chain+0x305/0x5a0
[   37.940862]    [<c106b57d>] __lock_acquire+0x2ad/0x8e0
[   37.940862]    [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]    [<c138c46e>] _raw_write_lock_bh+0x3e/0x80
[   37.940862]    [<c13100a6>] inet_csk_listen_stop+0x86/0x160
[   37.940862]    [<c1312c02>] tcp_close+0x382/0x390
[   37.940862]    [<c1331a7e>] inet_release+0xbe/0x100
[   37.940862]    [<c12d5476>] sock_release+0x66/0x80
[   37.940862]    [<c12d61f2>] sock_close+0x12/0x30
[   37.940862]    [<c10c637b>] __fput+0x1cb/0x240
[   37.940862]    [<c10c6409>] fput+0x19/0x20
[   37.940862]    [<c10c4263>] filp_close+0x43/0x70
[   37.940862]    [<c10c42fd>] sys_close+0x6d/0x110
[   37.940862]    [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862] 
[   37.940862] -> (clock-AF_INET){++.?..} ops: 72 {
[   37.940862]    HARDIRQ-ON-W at:
[   37.940862]                                        [<c106a8de>] mark_irqflags+0xfe/0x180
[   37.940862]                                        [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]                                        [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                        [<c138c46e>] _raw_write_lock_bh+0x3e/0x80
[   37.940862]                                        [<c12db20f>] sk_common_release+0x2f/0xc0
[   37.940862]                                        [<c132bb18>] udp_lib_close+0x8/0x10
[   37.940862]                                        [<c1331a7e>] inet_release+0xbe/0x100
[   37.940862]                                        [<c12d5476>] sock_release+0x66/0x80
[   37.940862]                                        [<c12d61f2>] sock_close+0x12/0x30
[   37.940862]                                        [<c10c637b>] __fput+0x1cb/0x240
[   37.940862]                                        [<c10c6409>] fput+0x19/0x20
[   37.940862]                                        [<c10c4263>] filp_close+0x43/0x70
[   37.940862]                                        [<c103fdcd>] close_files+0xad/0x150
[   37.940862]                                        [<c103fed9>] put_files_struct+0x29/0xf0
[   37.940862]                                        [<c1040030>] exit_files+0x40/0x50
[   37.940862]                                        [<c10406f6>] do_exit+0x116/0x2e0
[   37.940862]                                        [<c1040924>] do_group_exit+0x34/0xb0
[   37.940862]                                        [<c10409af>] sys_exit_group+0xf/0x20
[   37.940862]                                        [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862]    HARDIRQ-ON-R at:
[   37.940862]                                        [<c106a84e>] mark_irqflags+0x6e/0x180
[   37.940862]                                        [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]                                        [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                        [<c138bfd9>] _raw_read_lock+0x39/0x70
[   37.940862]                                        [<c135ddae>] xs_tcp_state_change+0x1e/0x1d0
[   37.940862]                                        [<c131bd38>] tcp_rcv_synsent_state_process+0x398/0x590
[   37.940862]                                        [<c131c3d7>] tcp_rcv_state_process+0x4a7/0x560
[   37.940862]                                        [<c1322e61>] tcp_v4_do_rcv+0x71/0x280
[   37.940862]                                        [<c12da206>] __release_sock+0x66/0x150
[   37.940862]                                        [<c12daf07>] release_sock+0x87/0x90
[   37.940862]                                        [<c1331e6a>] inet_stream_connect+0x5a/0x1b0
[   37.940862]                                        [<c12d7d68>] kernel_connect+0x18/0x30
[   37.940862]                                        [<c135ea5e>] xs_tcp_finish_connecting+0x4e/0x120
[   37.940862]                                        [<c135eb8b>] xs_tcp_setup_socket+0x5b/0x180
[   37.940862]                                        [<c135edc4>] xs_tcp_connect_worker4+0x14/0x20
[   37.940862]                                        [<c1051547>] process_one_work+0x147/0x3a0
[   37.940862]                                        [<c1051886>] worker_thread+0xa6/0x200
[   37.940862]                                        [<c1056765>] kthread+0x75/0x80
[   37.940862]                                        [<c10031fa>] kernel_thread_helper+0x6/0x1c
[   37.940862]    IN-SOFTIRQ-R at:
[   37.940862]                                        [<c106a8fe>] mark_irqflags+0x11e/0x180
[   37.940862]                                        [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]                                        [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                        [<c138bfd9>] _raw_read_lock+0x39/0x70
[   37.940862]                                        [<c135dc81>] xs_tcp_data_ready+0x21/0x90
[   37.940862]                                        [<c131a1f8>] tcp_data_queue+0x248/0x820
[   37.940862]                                        [<c131b56e>] tcp_rcv_established+0xae/0x4e0
[   37.940862]                                        [<c1322fc1>] tcp_v4_do_rcv+0x1d1/0x280
[   37.940862]                                        [<c13235e4>] tcp_v4_rcv+0x574/0xa30
[   37.940862]                                        [<c1305443>] ip_local_deliver_finish+0x103/0x320
[   37.940862]                                        [<c1305690>] ip_local_deliver+0x30/0x40
[   37.940862]                                        [<c1305809>] ip_rcv_finish+0x169/0x480
[   37.940862]                                        [<c1305cba>] ip_rcv+0x19a/0x2b0
[   37.940862]                                        [<c12e691d>] __netif_receive_skb+0x21d/0x310
[   37.940862]                                        [<c12e7428>] process_backlog+0x88/0x160
[   37.940862]                                        [<c12e77f7>] net_rx_action+0x127/0x140
[   37.940862]                                        [<c1042e70>] __do_softirq+0xd0/0x130
[   37.940862]    SOFTIRQ-ON-R at:
[   37.940862]                                        [<c106a8c2>] mark_irqflags+0xe2/0x180
[   37.940862]                                        [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]                                        [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                        [<c138bfd9>] _raw_read_lock+0x39/0x70
[   37.940862]                                        [<c135e03c>] xs_udp_write_space+0x1c/0x50
[   37.940862]                                        [<c135e14a>] xs_udp_do_set_buffer_size+0x8a/0x90
[   37.940862]                                        [<c135e18d>] xs_udp_set_buffer_size+0x3d/0x40
[   37.940862]                                        [<c13594d8>] rpc_setbufsize+0x28/0x30
[   37.940862]                                        [<e0967314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[   37.940862]                                        [<e0967415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[   37.940862]                                        [<e0967717>] nfs_create_server+0x87/0x240 [nfs]
[   37.940862]                                        [<e0971aeb>] nfs_get_sb+0x8b/0x240 [nfs]
[   37.940862]                                        [<c10c7f41>] vfs_kern_mount+0x71/0x190
[   37.940862]                                        [<c10c8287>] do_kern_mount+0x37/0x90
[   37.940862]                                        [<c10de6c7>] do_new_mount+0x57/0xa0
[   37.940862]                                        [<c10decc1>] do_mount+0x171/0x1b0
[   37.940862]                                        [<c10defbc>] sys_mount+0x6c/0xa0
[   37.940862]                                        [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862]    INITIAL USE at:
[   37.940862]                                       [<c106b490>] __lock_acquire+0x1c0/0x8e0
[   37.940862]                                       [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]                                       [<c138c46e>] _raw_write_lock_bh+0x3e/0x80
[   37.940862]                                       [<c12db20f>] sk_common_release+0x2f/0xc0
[   37.940862]                                       [<c132bb18>] udp_lib_close+0x8/0x10
[   37.940862]                                       [<c1331a7e>] inet_release+0xbe/0x100
[   37.940862]                                       [<c12d5476>] sock_release+0x66/0x80
[   37.940862]                                       [<c12d61f2>] sock_close+0x12/0x30
[   37.940862]                                       [<c10c637b>] __fput+0x1cb/0x240
[   37.940862]                                       [<c10c6409>] fput+0x19/0x20
[   37.940862]                                       [<c10c4263>] filp_close+0x43/0x70
[   37.940862]                                       [<c103fdcd>] close_files+0xad/0x150
[   37.940862]                                       [<c103fed9>] put_files_struct+0x29/0xf0
[   37.940862]                                       [<c1040030>] exit_files+0x40/0x50
[   37.940862]                                       [<c10406f6>] do_exit+0x116/0x2e0
[   37.940862]                                       [<c1040924>] do_group_exit+0x34/0xb0
[   37.940862]                                       [<c10409af>] sys_exit_group+0xf/0x20
[   37.940862]                                       [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862]  }
[   37.940862]  ... key      at: [<c1d4cb10>] af_callback_keys+0x10/0x130
[   37.940862]  ... acquired at:
[   37.940862]    [<c1069d46>] check_usage_backwards+0x76/0xd0
[   37.940862]    [<c1069f59>] mark_lock_irq+0x99/0x240
[   37.940862]    [<c106abfc>] mark_lock+0x21c/0x3c0
[   37.940862]    [<c106a8c2>] mark_irqflags+0xe2/0x180
[   37.940862]    [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]    [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]    [<c138bfd9>] _raw_read_lock+0x39/0x70
[   37.940862]    [<c135e03c>] xs_udp_write_space+0x1c/0x50
[   37.940862]    [<c135e14a>] xs_udp_do_set_buffer_size+0x8a/0x90
[   37.940862]    [<c135e18d>] xs_udp_set_buffer_size+0x3d/0x40
[   37.940862]    [<c13594d8>] rpc_setbufsize+0x28/0x30
[   37.940862]    [<e0967314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[   37.940862]    [<e0967415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[   37.940862]    [<e0967717>] nfs_create_server+0x87/0x240 [nfs]
[   37.940862]    [<e0971aeb>] nfs_get_sb+0x8b/0x240 [nfs]
[   37.940862]    [<c10c7f41>] vfs_kern_mount+0x71/0x190
[   37.940862]    [<c10c8287>] do_kern_mount+0x37/0x90
[   37.940862]    [<c10de6c7>] do_new_mount+0x57/0xa0
[   37.940862]    [<c10decc1>] do_mount+0x171/0x1b0
[   37.940862]    [<c10defbc>] sys_mount+0x6c/0xa0
[   37.940862]    [<c138c8d1>] syscall_call+0x7/0xb
[   37.940862] 
[   37.940862] 
[   37.940862] stack backtrace:
[   37.940862] Pid: 2681, comm: mount Not tainted 2.6.36-rc5 #1
[   37.940862] Call Trace:
[   37.940862]  [<c103deb8>] ? printk+0x18/0x20
[   37.940862]  [<c1069bd8>] print_irq_inversion_bug+0x108/0x120
[   37.940862]  [<c1069d46>] check_usage_backwards+0x76/0xd0
[   37.940862]  [<c1069f59>] mark_lock_irq+0x99/0x240
[   37.940862]  [<c1069cd0>] ? check_usage_backwards+0x0/0xd0
[   37.940862]  [<c106abfc>] mark_lock+0x21c/0x3c0
[   37.940862]  [<c106a8c2>] mark_irqflags+0xe2/0x180
[   37.940862]  [<c106b65d>] __lock_acquire+0x38d/0x8e0
[   37.940862]  [<c109a5fe>] ? mempool_free_slab+0xe/0x10
[   37.940862]  [<c109a5d8>] ? mempool_free+0x98/0xa0
[   37.940862]  [<c106cbfa>] lock_acquire+0x7a/0xa0
[   37.940862]  [<c135e03c>] ? xs_udp_write_space+0x1c/0x50
[   37.940862]  [<c138bfd9>] _raw_read_lock+0x39/0x70
[   37.940862]  [<c135e03c>] ? xs_udp_write_space+0x1c/0x50
[   37.940862]  [<c135e03c>] xs_udp_write_space+0x1c/0x50
[   37.940862]  [<c135e14a>] xs_udp_do_set_buffer_size+0x8a/0x90
[   37.940862]  [<c135e18d>] xs_udp_set_buffer_size+0x3d/0x40
[   37.940862]  [<c135e150>] ? xs_udp_set_buffer_size+0x0/0x40
[   37.940862]  [<c13594d8>] rpc_setbufsize+0x28/0x30
[   37.940862]  [<e0967314>] nfs_server_set_fsinfo+0x364/0x400 [nfs]
[   37.940862]  [<e0967415>] nfs_probe_fsinfo+0x65/0x100 [nfs]
[   37.940862]  [<c10bf558>] ? cache_alloc_debugcheck_after+0x98/0x1d0
[   37.940862]  [<e096e1d3>] ? nfs_alloc_fattr+0x23/0x30 [nfs]
[   37.940862]  [<e0967717>] nfs_create_server+0x87/0x240 [nfs]
[   37.940862]  [<e096e1f5>] ? nfs_alloc_fhandle+0x15/0x30 [nfs]
[   37.940862]  [<e0971aeb>] nfs_get_sb+0x8b/0x240 [nfs]
[   37.940862]  [<e09719b0>] ? nfs_compare_super+0x0/0x90 [nfs]
[   37.940862]  [<c10c7f41>] vfs_kern_mount+0x71/0x190
[   37.940862]  [<c10dc11c>] ? get_fs_type+0x8c/0xa0
[   37.940862]  [<c10c8287>] do_kern_mount+0x37/0x90
[   37.940862]  [<c10de6c7>] do_new_mount+0x57/0xa0
[   37.940862]  [<c10decc1>] do_mount+0x171/0x1b0
[   37.940862]  [<c10defbc>] sys_mount+0x6c/0xa0
[   37.940862]  [<c138c8d1>] syscall_call+0x7/0xb

Boot and login and run test.sh below

--- test.sh start ---
#! /bin/sh
./a.out
echo 1 > /proc/sys/kernel/printk_delay
mount 127.0.0.1:/usr/src/ /mnt/
umount /mnt/
--- test.sh end ---

where a.out is made by "gcc -Wall -O3 test.c"

--- test.c start ---
#include <stdlib.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <arpa/inet.h>

int main(int argc, char *argv[])
{
	int fd1 = socket(AF_INET, SOCK_STREAM, 0);
	int fd2 = socket(AF_INET, SOCK_STREAM, 0);
	struct sockaddr_in addr = { };
	socklen_t size = sizeof(addr);
	addr.sin_family = AF_INET;
	addr.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
	addr.sin_port = htons(0);
	bind(fd1, (struct sockaddr *) &addr, sizeof(addr));
	listen(fd1, 5);
	getsockname(fd1, (struct sockaddr *) &addr, &size);
	connect(fd2, (struct sockaddr *) &addr, sizeof(addr));
	close(fd1);
	close(fd2);
	return 0;
}
--- test.c end ---

Config is at http://I-love.SAKURA.ne.jp/tmp/config-2.6.36-rc5
Full log is at http://I-love.SAKURA.ne.jp/tmp/dmesg-2.6.36-rc5.txt

I'm using Debian Sarge on i686.

Regards.
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index b6309db..fc94e5e 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -1301,7 +1301,7 @@  static void xs_tcp_state_change(struct sock *sk)
 {
 	struct rpc_xprt *xprt;
 
-	read_lock(&sk->sk_callback_lock);
+	read_lock_bh(&sk->sk_callback_lock);
 	if (!(xprt = xprt_from_sock(sk)))
 		goto out;
 	dprintk("RPC:       xs_tcp_state_change client %p...\n", xprt);
@@ -1313,7 +1313,7 @@  static void xs_tcp_state_change(struct sock *sk)
 
 	switch (sk->sk_state) {
 	case TCP_ESTABLISHED:
-		spin_lock_bh(&xprt->transport_lock);
+		spin_lock(&xprt->transport_lock);
 		if (!xprt_test_and_set_connected(xprt)) {
 			struct sock_xprt *transport = container_of(xprt,
 					struct sock_xprt, xprt);
@@ -1327,7 +1327,7 @@  static void xs_tcp_state_change(struct sock *sk)
 
 			xprt_wake_pending_tasks(xprt, -EAGAIN);
 		}
-		spin_unlock_bh(&xprt->transport_lock);
+		spin_unlock(&xprt->transport_lock);
 		break;
 	case TCP_FIN_WAIT1:
 		/* The client initiated a shutdown of the socket */
@@ -1365,7 +1365,7 @@  static void xs_tcp_state_change(struct sock *sk)
 		xs_sock_mark_closed(xprt);
 	}
  out:
-	read_unlock(&sk->sk_callback_lock);
+	read_unlock_bh(&sk->sk_callback_lock);
 }
 
 /**