From mboxrd@z Thu Jan 1 00:00:00 1970 From: Jongman Heo Subject: [vmxnet3] possible irq lock inversion dependency detected Date: Fri, 21 Jan 2011 09:44:46 +0000 (UTC) Message-ID: Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit To: netdev@vger.kernel.org Return-path: Received: from lo.gmane.org ([80.91.229.12]:47392 "EHLO lo.gmane.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750955Ab1AUJuG (ORCPT ); Fri, 21 Jan 2011 04:50:06 -0500 Received: from list by lo.gmane.org with local (Exim 4.69) (envelope-from ) id 1PgDd5-00075E-Mt for netdev@vger.kernel.org; Fri, 21 Jan 2011 10:50:04 +0100 Received: from 210.94.41.89 ([210.94.41.89]) by main.gmane.org with esmtp (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Fri, 21 Jan 2011 10:50:03 +0100 Received: from jongman.heo by 210.94.41.89 with local (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Fri, 21 Jan 2011 10:50:03 +0100 Sender: netdev-owner@vger.kernel.org List-ID: I'm using Fedora 14 on VMWare. With latest Linus git tree(2b1caf6ed7b888), following warnings are printed. Is this a known issue? I don't know whether this is a regression or not. This is my first time using vmxnet3 driver. =============================================================== [ 17.593243] NET: Registered protocol family 10 [ 17.640420] ip6_tables: (C) 2000-2006 Netfilter Core Team [ 18.418134] auditd (733): /proc/733/oom_adj is deprecated, please use /proc/733/oom_score_adj instead. [ 24.074627] eth0: intr type 3, mode 0, 5 vectors allocated [ 24.075450] eth0: NIC Link is Up 10000 Mbps [ 24.081505] [ 24.081507] ========================================================= [ 24.081693] [ INFO: possible irq lock inversion dependency detected ] [ 24.081797] 2.6.38-rc1+ #85 [ 24.081914] --------------------------------------------------------- [ 24.082061] dbus-daemon/847 just changed the state of lock: [ 24.082200] (&(&mc->mca_lock)->rlock){+.-...}, at: [] mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.082488] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 24.082690] (&(&adapter->cmd_lock)->rlock){+.+...} [ 24.082769] [ 24.082770] and interrupts could create inverse lock ordering between them. [ 24.082772] [ 24.083196] [ 24.083197] other info that might help us debug this: [ 24.083415] 3 locks held by dbus-daemon/847: [ 24.083538] #0: (&mm->mmap_sem){++++++}, at: [] do_page_fault+0x140/0x33b [ 24.083799] #1: (&idev->mc_ifc_timer){+.-...}, at: [] run_timer_softirq+0x11c/0x268 [ 24.084081] #2: (&ndev->lock){++.-..}, at: [] mld_ifc_timer_expire+0x1b/0x1f2 [ipv6] [ 24.084364] [ 24.084365] the shortest dependencies between 2nd lock and 1st lock: [ 24.084659] -> (&(&adapter->cmd_lock)->rlock){+.+...} ops: 28 { [ 24.084826] HARDIRQ-ON-W at: [ 24.084987] [] __lock_acquire+0x2d9/0xbf2 [ 24.085302] [] lock_acquire+0xb7/0xd7 [ 24.085507] [] _raw_spin_lock+0x33/0x40 [ 24.085708] [] vmxnet3_alloc_intr_resources+0x18/0x1c1 [vmxnet3] [ 24.085964] [] vmxnet3_probe_device+0x503/0x712 [vmxnet3] [ 24.086180] [] local_pci_probe+0x2f/0x5a [ 24.086382] [] pci_device_probe+0x48/0x6b [ 24.086582] [] driver_probe_device+0x115/0x1ec [ 24.086788] [] __driver_attach+0x3f/0x5b [ 24.087014] [] bus_for_each_dev+0x3d/0x60 [ 24.087214] [] driver_attach+0x19/0x1b [ 24.087411] [] bus_add_driver+0xbd/0x215 [ 24.087611] [] driver_register+0x7f/0xde [ 24.087811] [] __pci_register_driver+0x4c/0xa9 [ 24.088046] [] 0xf8568036 [ 24.088238] [] do_one_initcall+0x87/0x143 [ 24.088439] [] sys_init_module+0x130d/0x14aa [ 24.088643] [] sysenter_do_call+0x12/0x38 [ 24.088844] SOFTIRQ-ON-W at: [ 24.115469] [] __lock_acquire+0x2f8/0xbf2 [ 24.115483] [] lock_acquire+0xb7/0xd7 [ 24.115486] [] _raw_spin_lock+0x33/0x40 [ 24.115493] [] vmxnet3_alloc_intr_resources+0x18/0x1c1 [vmxnet3] [ 24.115508] [] vmxnet3_probe_device+0x503/0x712 [vmxnet3] [ 24.115513] [] local_pci_probe+0x2f/0x5a [ 24.115519] [] pci_device_probe+0x48/0x6b [ 24.115523] [] driver_probe_device+0x115/0x1ec [ 24.115529] [] __driver_attach+0x3f/0x5b [ 24.115532] [] bus_for_each_dev+0x3d/0x60 [ 24.115535] [] driver_attach+0x19/0x1b [ 24.115539] [] bus_add_driver+0xbd/0x215 [ 24.115542] [] driver_register+0x7f/0xde [ 24.115545] [] __pci_register_driver+0x4c/0xa9 [ 24.115555] [] 0xf8568036 [ 24.115562] [] do_one_initcall+0x87/0x143 [ 24.115567] [] sys_init_module+0x130d/0x14aa [ 24.115590] [] sysenter_do_call+0x12/0x38 [ 24.115596] INITIAL USE at: [ 24.115598] [] __lock_acquire+0x34d/0xbf2 [ 24.115602] [] lock_acquire+0xb7/0xd7 [ 24.115606] [] _raw_spin_lock+0x33/0x40 [ 24.115609] [] vmxnet3_alloc_intr_resources+0x18/0x1c1 [vmxnet3] [ 24.115614] [] vmxnet3_probe_device+0x503/0x712 [vmxnet3] [ 24.115619] [] local_pci_probe+0x2f/0x5a [ 24.115622] [] pci_device_probe+0x48/0x6b [ 24.115626] [] driver_probe_device+0x115/0x1ec [ 24.115629] [] __driver_attach+0x3f/0x5b [ 24.115633] [] bus_for_each_dev+0x3d/0x60 [ 24.115636] [] driver_attach+0x19/0x1b [ 24.115639] [] bus_add_driver+0xbd/0x215 [ 24.115642] [] driver_register+0x7f/0xde [ 24.115645] [] __pci_register_driver+0x4c/0xa9 [ 24.115648] [] 0xf8568036 [ 24.115652] [] do_one_initcall+0x87/0x143 [ 24.115655] [] sys_init_module+0x130d/0x14aa [ 24.115659] [] sysenter_do_call+0x12/0x38 [ 24.115662] } [ 24.115663] ... key at: [] __key.40447+0x0/0xffffe7b2 [vmxnet3] [ 24.115668] ... acquired at: [ 24.115670] [] lock_acquire+0xb7/0xd7 [ 24.115673] [] _raw_spin_lock_irqsave+0x40/0x50 [ 24.115676] [] vmxnet3_set_mc+0x11a/0x165 [vmxnet3] [ 24.115684] [] __dev_set_rx_mode+0x76/0x7a [ 24.115689] [] dev_set_rx_mode+0x1b/0x26 [ 24.115692] [] __dev_open+0x9d/0xaf [ 24.115694] [] __dev_change_flags+0x98/0x10d [ 24.115697] [] dev_change_flags+0x13/0x3f [ 24.115699] [] do_setlink+0x245/0x56b [ 24.115703] [] rtnl_setlink+0xaa/0xc6 [ 24.115706] [] rtnetlink_rcv_msg+0x1a0/0x1af [ 24.115709] [] netlink_rcv_skb+0x32/0x73 [ 24.115712] [] rtnetlink_rcv+0x1b/0x22 [ 24.115714] [] netlink_unicast+0xc4/0x120 [ 24.115716] [] netlink_sendmsg+0x25a/0x271 [ 24.115719] [] __sock_sendmsg+0x54/0x5b [ 24.115723] [] sock_sendmsg+0x95/0xac [ 24.115726] [] sys_sendmsg+0x181/0x1e8 [ 24.115729] [] sys_socketcall+0x22c/0x287 [ 24.115732] [] sysenter_do_call+0x12/0x38 [ 24.115735] [ 24.115736] -> (_xmit_ETHER){+.....} ops: 6 { [ 24.115741] HARDIRQ-ON-W at: [ 24.115742] [] __lock_acquire+0x2d9/0xbf2 [ 24.115746] [] lock_acquire+0xb7/0xd7 [ 24.115750] [] _raw_spin_lock_bh+0x38/0x45 [ 24.115753] [] __dev_mc_add+0x23/0x61 [ 24.115761] [] dev_mc_add+0xa/0xc [ 24.115764] [] igmp6_group_added+0x56/0x139 [ipv6] [ 24.115784] [] ipv6_dev_mc_inc+0x1fb/0x20c [ipv6] [ 24.115799] [] ipv6_add_dev+0x26d/0x28b [ipv6] [ 24.115834] [] addrconf_notify+0x57/0x52c [ipv6] [ 24.115848] [] register_netdevice_notifier+0x54/0x14e [ 24.115852] [] 0xf866b324 [ 24.115856] [] 0xf866b18a [ 24.115859] [] do_one_initcall+0x87/0x143 [ 24.115862] [] sys_init_module+0x130d/0x14aa [ 24.115867] [] sysenter_do_call+0x12/0x38 [ 24.115870] INITIAL USE at: [ 24.115872] [] __lock_acquire+0x34d/0xbf2 [ 24.115876] [] lock_acquire+0xb7/0xd7 [ 24.115880] [] _raw_spin_lock_bh+0x38/0x45 [ 24.115884] [] __dev_mc_add+0x23/0x61 [ 24.115887] [] dev_mc_add+0xa/0xc [ 24.115891] [] igmp6_group_added+0x56/0x139 [ipv6] [ 24.115911] [] ipv6_dev_mc_inc+0x1fb/0x20c [ipv6] [ 24.115926] [] ipv6_add_dev+0x26d/0x28b [ipv6] [ 24.115939] [] addrconf_notify+0x57/0x52c [ipv6] [ 24.115951] [] register_netdevice_notifier+0x54/0x14e [ 24.115954] [] 0xf866b324 [ 24.115957] [] 0xf866b18a [ 24.115960] [] do_one_initcall+0x87/0x143 [ 24.115963] [] sys_init_module+0x130d/0x14aa [ 24.115966] [] sysenter_do_call+0x12/0x38 [ 24.115970] } [ 24.115971] ... key at: [] netdev_addr_lock_key+0x8/0x1d0 [ 24.115985] ... acquired at: [ 24.115986] [] lock_acquire+0xb7/0xd7 [ 24.115990] [] _raw_spin_lock_bh+0x38/0x45 [ 24.115992] [] __dev_mc_add+0x23/0x61 [ 24.115995] [] dev_mc_add+0xa/0xc [ 24.115997] [] igmp6_group_added+0x56/0x139 [ipv6] [ 24.116013] [] ipv6_dev_mc_inc+0x1fb/0x20c [ipv6] [ 24.116027] [] ipv6_add_dev+0x26d/0x28b [ipv6] [ 24.116039] [] addrconf_notify+0x57/0x52c [ipv6] [ 24.116051] [] register_netdevice_notifier+0x54/0x14e [ 24.116054] [] 0xf866b324 [ 24.116056] [] 0xf866b18a [ 24.116058] [] do_one_initcall+0x87/0x143 [ 24.116061] [] sys_init_module+0x130d/0x14aa [ 24.116064] [] sysenter_do_call+0x12/0x38 [ 24.116067] [ 24.116068] -> (&(&mc->mca_lock)->rlock){+.-...} ops: 6 { [ 24.116071] HARDIRQ-ON-W at: [ 24.116073] [] __lock_acquire+0x2d9/0xbf2 [ 24.116077] [] lock_acquire+0xb7/0xd7 [ 24.116080] [] _raw_spin_lock_bh+0x38/0x45 [ 24.116083] [] igmp6_group_added+0x28/0x139 [ipv6] [ 24.116102] [] ipv6_dev_mc_inc+0x1fb/0x20c [ipv6] [ 24.116118] [] ipv6_add_dev+0x26d/0x28b [ipv6] [ 24.116130] [] 0xf866b2f0 [ 24.116133] [] 0xf866b18a [ 24.116136] [] do_one_initcall+0x87/0x143 [ 24.116139] [] sys_init_module+0x130d/0x14aa [ 24.116143] [] sysenter_do_call+0x12/0x38 [ 24.116146] IN-SOFTIRQ-W at: [ 24.116148] [] __lock_acquire+0x284/0xbf2 [ 24.116151] [] lock_acquire+0xb7/0xd7 [ 24.116154] [] _raw_spin_lock_bh+0x38/0x45 [ 24.116158] [] mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116173] [] run_timer_softirq+0x19f/0x268 [ 24.116180] [] __do_softirq+0xa9/0x16a [ 24.116183] INITIAL USE at: [ 24.116185] [] __lock_acquire+0x34d/0xbf2 [ 24.116188] [] lock_acquire+0xb7/0xd7 [ 24.116191] [] _raw_spin_lock_bh+0x38/0x45 [ 24.116195] [] igmp6_group_added+0x28/0x139 [ipv6] [ 24.116210] [] ipv6_dev_mc_inc+0x1fb/0x20c [ipv6] [ 24.116226] [] ipv6_add_dev+0x26d/0x28b [ipv6] [ 24.116238] [] 0xf866b2f0 [ 24.116241] [] 0xf866b18a [ 24.116244] [] do_one_initcall+0x87/0x143 [ 24.116247] [] sys_init_module+0x130d/0x14aa [ 24.116251] [] sysenter_do_call+0x12/0x38 [ 24.116254] } [ 24.116255] ... key at: [] __key.38329+0x0/0xffff9cd8 [ipv6] [ 24.116266] ... acquired at: [ 24.116268] [] check_usage_forwards+0x6f/0x77 [ 24.116271] [] mark_lock+0xf3/0x1bb [ 24.116273] [] __lock_acquire+0x284/0xbf2 [ 24.116276] [] lock_acquire+0xb7/0xd7 [ 24.116279] [] _raw_spin_lock_bh+0x38/0x45 [ 24.116282] [] mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116296] [] run_timer_softirq+0x19f/0x268 [ 24.116299] [] __do_softirq+0xa9/0x16a [ 24.116302] [ 24.116303] [ 24.116303] stack backtrace: [ 24.116307] Pid: 847, comm: dbus-daemon Not tainted 2.6.38-rc1+ #85 [ 24.116309] Call Trace: [ 24.116314] [] ? print_irq_inversion_bug+0xfc/0x106 [ 24.116317] [] ? check_usage_forwards+0x6f/0x77 [ 24.116320] [] ? mark_lock+0xf3/0x1bb [ 24.116323] [] ? check_usage_forwards+0x0/0x77 [ 24.116327] [] ? __lock_acquire+0x284/0xbf2 [ 24.116330] [] ? save_trace+0x37/0x93 [ 24.116333] [] ? __lock_acquire+0xb44/0xbf2 [ 24.116348] [] ? mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116352] [] ? lock_acquire+0xb7/0xd7 [ 24.116366] [] ? mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116370] [] ? _raw_spin_lock_bh+0x38/0x45 [ 24.116385] [] ? mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116400] [] ? mld_ifc_timer_expire+0x12a/0x1f2 [ipv6] [ 24.116403] [] ? run_timer_softirq+0x11c/0x268 [ 24.116410] [] ? run_timer_softirq+0x19f/0x268 [ 24.116413] [] ? run_timer_softirq+0x11c/0x268 [ 24.116428] [] ? mld_ifc_timer_expire+0x0/0x1f2 [ipv6] [ 24.116432] [] ? __do_softirq+0xa9/0x16a [ 24.116434] [] ? __do_softirq+0x0/0x16a [ 24.116436] [] ? irq_exit+0x38/0x6c [ 24.116443] [] ? smp_apic_timer_interrupt+0x66/0x73 [ 24.116447] [] ? trace_hardirqs_off_thunk+0xc/0x10 [ 24.116451] [] ? apic_timer_interrupt+0x36/0x3c [ 24.116456] [] ? copy_user_highpage.clone.44+0x21/0x34 [ 24.116459] [] ? do_wp_page+0x397/0x514 [ 24.116462] [] ? _raw_spin_lock+0x3a/0x40 [ 24.116465] [] ? handle_pte_fault+0x67f/0x6ea [ 24.116468] [] ? handle_mm_fault+0xac/0xb8 [ 24.116472] [] ? do_page_fault+0x323/0x33b [ 24.116475] [] ? lock_acquire+0xcf/0xd7 [ 24.116478] [] ? restore_all_notrace+0x0/0x18 [ 24.116481] [] ? trace_hardirqs_off_caller+0x2e/0x86 [ 24.116484] [] ? do_page_fault+0x0/0x33b [ 24.116487] [] ? error_code+0x6c/0x74 [ 24.550299] RPC: Registered udp transport module. [ 24.550405] RPC: Registered tcp transport module. [ 24.550498] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 28.499064] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 28.725260] NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory [ 28.783996] NFSD: starting 90-second grace period [ 33.488381] Bridge firewalling registered [ 34.443551] ------------[ cut here ]------------ [ 34.443561] WARNING: at net/core/dev.c:1351 dev_disable_lro+0x54/0x57() [ 34.443563] Hardware name: VMware Virtual Platform [ 34.443565] Modules linked in: ipt_MASQUERADE iptable_nat nf_nat bridge stp llc nfsd lockd nfs_acl auth_rpcgss exportfs sunrpc xt_physdev nf_conntrack_tftp nf_conntrack_netbios_ns ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables ipv6 vmhgfs uinput snd_ens1371 gameport snd_rawmidi snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm snd_timer microcode vmxnet3 vmci snd soundcore snd_page_alloc i2c_piix4 mptspi mptscsih mptbase scsi_transport_spi [last unloaded: scsi_wait_scan] [ 34.443605] Pid: 1358, comm: libvirtd Not tainted 2.6.38-rc1+ #85 [ 34.443607] Call Trace: [ 34.443615] [] ? warn_slowpath_common+0x77/0x8c [ 34.443618] [] ? dev_disable_lro+0x54/0x57 [ 34.443620] [] ? dev_disable_lro+0x54/0x57 [ 34.443623] [] ? warn_slowpath_null+0x1d/0x1f [ 34.443626] [] ? dev_disable_lro+0x54/0x57 [ 34.443630] [] ? devinet_sysctl_forward+0xd5/0x139 [ 34.443633] [] ? devinet_sysctl_forward+0x0/0x139 [ 34.443638] [] ? proc_sys_call_handler.clone.0+0x6a/0x89 [ 34.443641] [] ? proc_sys_write+0x0/0x22 [ 34.443643] [] ? proc_sys_write+0x1d/0x22 [ 34.443649] [] ? vfs_write+0x86/0xde [ 34.443651] [] ? fget_light+0x5f/0x66 [ 34.443654] [] ? sys_write+0x3d/0x5e [ 34.443659] [] ? sysenter_do_call+0x12/0x38 [ 34.443662] ---[ end trace 06a697a570356b0c ]---