4.6-rc3 - lockdep chain_key collision during usb driver probe

[Shuah Khan]

I am seeing the following lockdep warning during driver bind. The 8
lock depth sequence start when the device probe happens. I am not
sure which one of these locks could be suspect.

Any tips on debugging this problem? Full dmesg attached.

thanks,
-- Shuah

[  386.190872] bus: 'usb': driver_probe_device: matched device 1-5:1.0 with driv
er uvcvideo
[  386.217246] ------------[ cut here ]------------
[  386.217276] WARNING: CPU: 0 PID: 1774 at kernel/locking/lockdep.c:2096 __lock
_acquire+0x2f15/0x5f30
[  386.217283] DEBUG_LOCKS_WARN_ON(chain_hlocks[chain->base + j] != id)
[  386.217288] Modules linked in:
[  386.217294]  nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_R
EJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ebtable_filter ebtables ip6table_f
ilter ip6_tables iptable_filter ip_tables x_tables snd_usb_audio snd_usbmidi_lib
 snd_seq_midi snd_seq_midi_event snd_seq binfmt_misc snd_rawmidi ir_lirc_codec s
nd_seq_device lirc_dev rc_hauppauge au8522_dig nls_iso8859_1 xc5000 tuner au8522
_decoder au8522_common hp_wmi sparse_keymap au0828 ghash_clmulni_intel aesni_int
el aes_x86_64 ablk_helper cryptd lrw tveeprom gf128mul uvcvideo glue_helper dvb_
core rc_core v4l2_common videobuf2_vmalloc videobuf2_memops joydev videobuf2_v4l
2 videobuf2_core serio_raw videodev media k10temp i2c_piix4 snd_hda_codec_idt sn
d_hda_codec_generic snd_hda_codec_hdmi snd_hda_intel snd_hda_codec tpm_infineon
snd_hda_core
[  386.217442]  snd_hwdep snd_pcm hp_accel kvm_amd lis3lv02d input_polldev snd_t
imer kvm mac_hid tpm_tis irqbypass parport_pc ppdev lp parport autofs4 pl2303 us
bserial hid_generic radeon psmouse i2c_algo_bit usbhid ttm hid drm_kms_helper sy
scopyarea sysfillrect sysimgblt fb_sys_fops firewire_ohci sdhci_pci firewire_cor
e r8169 drm sdhci crc_itu_t mii wmi video
[  386.217539] CPU: 0 PID: 1774 Comm: bash Not tainted 4.6.0-rc3m+ #4
[  386.217546] Hardware name: Hewlett-Packard HP ProBook 6475b/180F, BIOS 68TTU
Ver. F.04 08/03/2012
[  386.217552]  ffffffff82a72e00 ffff8801f5977040 ffffffff81aeccb3 ffff8801f5977
0b8
[  386.217565]  0000000000000000 ffff8801f5977088 ffffffff811136c2 0000000000000
009
[  386.217576]  ffff880100000830 ffffed003eb2ee13 ffffffff837d6b80 0000000000000
002
[  386.217588] Call Trace:
[  386.217599]  [<ffffffff81aeccb3>] dump_stack+0x67/0x94
[  386.217610]  [<ffffffff811136c2>] __warn+0x172/0x1b0
[  386.217620]  [<ffffffff81113797>] warn_slowpath_fmt+0x97/0xb0
[  386.217628]  [<ffffffff81113700>] ? __warn+0x1b0/0x1b0
[  386.217639]  [<ffffffff81210a25>] __lock_acquire+0x2f15/0x5f30
[  386.217647]  [<ffffffff81205185>] ? __bfs+0x25/0x610
[  386.217657]  [<ffffffff8120db10>] ? debug_check_no_locks_freed+0x280/0x280
[  386.217666]  [<ffffffff8120eadd>] ? __lock_acquire+0xfcd/0x5f30
[  386.217676]  [<ffffffff8120db10>] ? debug_check_no_locks_freed+0x280/0x280
[  386.217687]  [<ffffffff812b78f2>] ? __module_address+0x252/0x350
[  386.217696]  [<ffffffff81215bcb>] lock_acquire+0x17b/0x2c0
[  386.217705]  [<ffffffff8210e190>] ? usb_hcd_submit_urb+0x470/0x2000
[  386.217715]  [<ffffffff828454a7>] _raw_spin_lock_irq+0x37/0x50
[  386.217723]  [<ffffffff8210e190>] ? usb_hcd_submit_urb+0x470/0x2000
[  386.217731]  [<ffffffff8210e190>] usb_hcd_submit_urb+0x470/0x2000
[  386.217715]  [<ffffffff828454a7>] _raw_spin_lock_irq+0x37/0x50
[  386.217723]  [<ffffffff8210e190>] ? usb_hcd_submit_urb+0x470/0x2000
[  386.217731]  [<ffffffff8210e190>] usb_hcd_submit_urb+0x470/0x2000
[  386.217741]  [<ffffffff81537e75>] ? deactivate_slab+0x475/0x570
[  386.217749]  [<ffffffff8210dd20>] ? usb_create_hcd+0x20/0x20
[  386.217757]  [<ffffffff81537e75>] ? deactivate_slab+0x475/0x570
[  386.217766]  [<ffffffff8120cfb8>] ? mark_held_locks+0xc8/0x120
[  386.217775]  [<ffffffff81207200>] ? lockdep_init_map+0xf0/0x1470
[  386.217783]  [<ffffffff81207200>] ? lockdep_init_map+0xf0/0x1470
[  386.217792]  [<ffffffff82113005>] usb_submit_urb+0xb65/0x1200
[  386.217801]  [<ffffffff82114704>] usb_start_wait_urb+0x104/0x4e0
[  386.217809]  [<ffffffff82114600>] ? sg_clean+0x200/0x200
[  386.217818]  [<ffffffff8153d0c6>] ? kasan_unpoison_shadow+0x36/0x50
[  386.217827]  [<ffffffff82111eac>] ? usb_alloc_urb+0x1c/0xa0
[  386.217836]  [<ffffffff8153d258>] ? memset+0x28/0x30
[  386.217844]  [<ffffffff82114dff>] usb_control_msg+0x31f/0x4e0
[  386.217853]  [<ffffffff82114ae0>] ? usb_start_wait_urb+0x4e0/0x4e0
[  386.217862]  [<ffffffff8120d5ed>] ? trace_hardirqs_on+0xd/0x10
[  386.217871]  [<ffffffff820fd6a2>] ? usb_port_resume+0x222/0x1290
[  386.217880]  [<ffffffff820ede13>] hub_ext_port_status+0x113/0x420
[  386.217890]  [<ffffffff820fd6ca>] usb_port_resume+0x24a/0x1290
[  386.217900]  [<ffffffff820fd480>] ? usb_port_suspend+0xbb0/0xbb0
[  386.217909]  [<ffffffff8120eadd>] ? __lock_acquire+0xfcd/0x5f30
[  386.217921]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.217929]  [<ffffffff8213b3eb>] generic_resume+0x3b/0x60
[  386.217937]  [<ffffffff8211f23a>] usb_resume_both+0x41a/0x630
[  386.217946]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.217955]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.217963]  [<ffffffff82122a0a>] usb_runtime_resume+0x1a/0x20
[  386.217972]  [<ffffffff81ec2032>] __rpm_callback+0x62/0xe0
[  386.217981]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.217989]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.217997]  [<ffffffff81ec2215>] rpm_callback+0x165/0x210
[  386.218006]  [<ffffffff821229f0>] ? usb_runtime_suspend+0x100/0x100
[  386.218014]  [<ffffffff81ec3988>] rpm_resume+0xb68/0x15f0
[  386.218023]  [<ffffffff81ec2e20>] ?
pm_runtime_autosuspend_expiration+0x60/0x60
[  386.218031]  [<ffffffff81ec6f5a>] ? __pm_runtime_resume+0x6a/0xa0
[  386.218041]  [<ffffffff81ec6f68>] __pm_runtime_resume+0x78/0xa0
[  386.218052]  [<ffffffff81ea8b4c>] driver_probe_device+0x8c/0xc20
[  386.218062]  [<ffffffff81ea45c6>] bind_store+0x216/0x320
[  386.218071]  [<ffffffff81ea43b0>] ? bus_uevent_store+0xe0/0xe0
[  386.218080]  [<ffffffff81ea20f0>] ? drv_attr_show+0xa0/0xa0
[  386.218088]  [<ffffffff81ea215c>] drv_attr_store+0x6c/0xb0
[  386.218097]  [<ffffffff816df605>] sysfs_kf_write+0x115/0x180
[  386.218105]  [<ffffffff816df4f0>] ? sysfs_file_ops+0x170/0x170
[  386.218113]  [<ffffffff816dcda5>] kernfs_fop_write+0x275/0x3a0
[  386.218122]  [<ffffffff8156e0a0>] __vfs_write+0xe0/0x3e0
[  386.218131]  [<ffffffff8120db10>] ? debug_check_no_locks_freed+0x280/0x280
[  386.218140]  [<ffffffff815c8a2f>] ? __fd_install+0x1df/0x480
[  386.218148]  [<ffffffff8156dfc0>] ? __vfs_read+0x3d0/0x3d0
[  386.218158]  [<ffffffff81579147>] ? __sb_start_write+0xb7/0xf0
[  386.218168]  [<ffffffff8125b9f5>] ? rcu_sync_lockdep_assert+0x75/0xb0
[  386.218176]  [<ffffffff8120226b>] ? update_fast_ctr+0x1b/0x90
[  386.218184]  [<ffffffff81202359>] ? percpu_down_read+0x49/0x90
[  386.218192]  [<ffffffff81579147>] ? __sb_start_write+0xb7/0xf0
[  386.218201]  [<ffffffff81579147>] ? __sb_start_write+0xb7/0xf0
[  386.218209]  [<ffffffff815710af>] vfs_write+0x13f/0x4a0
[  386.218217]  [<ffffffff81574fc1>] SyS_write+0x111/0x230
[  386.218225]  [<ffffffff81574eb0>] ? SyS_read+0x230/0x230
[  386.218234]  [<ffffffff8100301b>] ? trace_hardirqs_on_thunk+0x1b/0x1d
[  386.218243]  [<ffffffff82845ce5>] entry_SYSCALL_64_fastpath+0x18/0xa8
[  386.218251] ---[ end trace fa30ce7efe7386b6 ]---

[  386.218260] ======================
[  386.218264] [chain_key collision ]
[  386.218270] 4.6.0-rc3m+ #4 Tainted: G        W
[  386.218274] ----------------------
[  386.218278] bash/1774: Hash chain already cached but the contents
don't match!
[  386.218284] Held locks:depth: 8
[  386.218292]  class_idx:644 -> chain_key:0000000000000284
(sb_writers#6){.+.+.+}, at: [<ffffffff81579147>]
__sb_start_write+0xb7/0xf0
[  386.218315]  class_idx:651 -> chain_key:000000000050828b
(&of->mutex){+.+.+.}, at: [<ffffffff816dcc25>]
kernfs_fop_write+0xf5/0x3a0
[  386.218332]  class_idx:432 -> chain_key:0000000a105161b0
(s_active#2){++++.+}, at: [<ffffffff816dcc48>]
kernfs_fop_write+0x118/0x3a0
[  386.218352]  class_idx:183 -> chain_key:0001420a2c3600b7
(&dev->mutex){......}, at: [<ffffffff81ea45a1>] bind_store+0x1f1/0x320
[  386.218369]  class_idx:183 -> chain_key:28414586c016e0b7
(&dev->mutex){......}, at: [<ffffffff81ea45b7>] bind_store+0x207/0x320
[  386.218387]  class_idx:507 -> chain_key:28b0d802dc16e4f3
(&port_dev->status_lock){+.+.+.}, at: [<ffffffff820fd6a2>]
usb_port_resume+0x222/0x1290
[  386.218405]  class_idx:494 -> chain_key:1b005b82dc9e64f8
(&hub->status_mutex){+.+.+.}, at: [<ffffffff820edd4a>]
hub_ext_port_status+0x4a/0x420
[  386.218423]  class_idx:486 -> chain_key:0b705b93cc9f0286
(hcd_root_hub_lock){-.-...}, at: [<ffffffff8210e190>]
usb_hcd_submit_urb+0x470/0x2000
[  386.218439] Locks in cached chain:depth: 8
[  386.218446]  class_idx:644 -> chain_key:0000000000000284
(sb_writers#6){.+.+.+}
[  386.218459]  class_idx:651 -> chain_key:000000000050828b (&of->mutex){+.+.+.}
[  386.218470]  class_idx:433 -> chain_key:0000000a105161b1 (s_active#3){++++.+}
[  386.218482]  class_idx:183 -> chain_key:0001420a2c3620b7
(&dev->mutex){......}
[  386.218493]  class_idx:183 -> chain_key:28414586c416e0b7
(&dev->mutex){......}
[  386.218504]  class_idx:507 -> chain_key:28b0d882dc16e4f3
(&port_dev->status_lock){+.+.+.}
[  386.218515]  class_idx:494 -> chain_key:1b105b82dc9e64f8
(&hub->status_mutex){+.+.+.}
[  386.218527]  class_idx:484 -> chain_key:0b705b93cc9f0286
(&(&ehci->lock)->rlock){-.-...}
[  386.218538]
               stack backtrace:
[  386.218547] CPU: 0 PID: 1774 Comm: bash Tainted: G        W
4.6.0-rc3m+ #4
[  386.218553] Hardware name: Hewlett-Packard HP ProBook 6475b/180F,
BIOS 68TTU Ver. F.04 08/03/2012
[  386.218558]  0000000000000008 ffff8801f59770d8 ffffffff81aeccb3
ffffffff837d6b80
[  386.218570]  0b705b93cc9f0286 ffff8801f5977130 ffffffff81209530 ffff880100000

Attachment: dmesg_chain_lock_collision
Description: Binary data