unpinning an unpinned lock warning triggered by generic_file_fsync()

[Bart Van Assche <bart.vanassche@sandisk.com>]

Hello,

The warning below was triggered while I was testing SRP initiator changes on
top of v4.2-rc4. I don't think that this warning was triggered by my changes.
Has anyone seen this before ?

Thanks,

Bart.

Jul 31 16:02:37 srp-ini multipathd: mpatha: load table [0 5859375088 multipath 3 queue_if_no_path pg_init_retries 50 1 alua 2 1 queue-length 0 7 1 8:240 1 8:224 1 65:0 1 66:160 1 66:224 1 67:16 1 66:240 1 queue-length 0 8 1 8:32 1 8:48 1 8:96 1 65:224 1 65:112 1 65:240 1 66:0 1 67:160 1]
Jul 31 16:02:37 srp-ini multipathd: sdbg [67:160]: path added to devmap mpatha
Jul 31 16:02:37 srp-ini multipathd: sdbh: add path (uevent)
Jul 31 16:02:37 srp-ini kernel: sd 14:0:0:0: alua: port group 101 state S preferred supports tOlUSNA
Jul 31 16:02:37 srp-ini kernel: ------------[ cut here ]------------
Jul 31 16:02:37 srp-ini kernel: WARNING: CPU: 2 PID: 9262 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x105/0x110()
Jul 31 16:02:37 srp-ini kernel: unpinning an unpinned lock
Jul 31 16:02:37 srp-ini kernel: Modules linked in: dm_queue_length scsi_dh_alua af_packet xt_tcpudp ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 ipt_REJECT nf_reject_ipv4 xt_conntrack ebtable_nat ebtable_broute bridge stp llc ebtable_filter ebtables ip6table_nat nf_con
ntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_filter ip6_tables iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack msr iptable_mangle iptable_raw iptable_filter ip_tables x_tables sg ib_srp scsi_transport_srp x86_pk
g_temp_thermal coretemp crct10dif_pclmul crc32c_intel aesni_intel aes_x86_64 glue_helper lrw gf128mul ablk_helper cryptd microcode pcspkr tg3 libphy lpc_ich mfd_core ib_ipoib wmi acpi_power_meter rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm processor thermal_sys 
hwmon button dm_multipath scsi_dh dm_mod ext4 crc16 mbcache jbd2 mlx4_en ptp pps_core mlx4_ib ib_sa ib_mad ib_core ib_addr sd_mod sr_mod cdrom hid_generic usbhid hid ahci libahci libata ehci_pci ehci_hcd mlx4_core usbcore usb_common scsi_mod autofs4
Jul 31 16:02:37 srp-ini kernel: CPU: 2 PID: 9262 Comm: kworker/2:98 Not tainted 4.2.0-rc4-debug+ #1
Jul 31 16:02:37 srp-ini kernel: Hardware name: Dell Inc. PowerEdge R430/03XKDV, BIOS 1.0.2 11/17/2014
Jul 31 16:02:37 srp-ini kernel: Workqueue: dio/dm-2 dio_aio_complete_work
Jul 31 16:02:37 srp-ini kernel: ffffffff817a80ba ffff88006ea03a58 ffffffff814f9cde 0000000000000000
Jul 31 16:02:37 srp-ini kernel: ffff88006ea03aa8 ffff88006ea03a98 ffffffff810746ba ffff88006ea03aa8
Jul 31 16:02:37 srp-ini kernel: 0000000000000003 ffff88040d962c80 ffff88047fc95618 0000000000000092
Jul 31 16:02:37 srp-ini kernel: Call Trace:
Jul 31 16:02:37 srp-ini kernel: [<ffffffff814f9cde>] dump_stack+0x4c/0x65
Jul 31 16:02:37 srp-ini kernel: [<ffffffff810746ba>] warn_slowpath_common+0x8a/0xc0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81074736>] warn_slowpath_fmt+0x46/0x50
Jul 31 16:02:37 srp-ini kernel: [<ffffffff810bbaed>] ? __lock_is_held+0x4d/0x70
Jul 31 16:02:37 srp-ini kernel: [<ffffffff810bbd75>] lock_unpin_lock+0x105/0x110
Jul 31 16:02:37 srp-ini kernel: [<ffffffff814fc0f4>] __schedule+0x414/0xa90
Jul 31 16:02:37 srp-ini kernel: [<ffffffff814fc7ae>] schedule+0x3e/0x90
Jul 31 16:02:37 srp-ini kernel: [<ffffffff814fcac5>] schedule_preempt_disabled+0x15/0x20
Jul 31 16:02:37 srp-ini kernel: [<ffffffff814fe966>] mutex_lock_nested+0x156/0x3a0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811e7de4>] ? __generic_file_fsync+0x44/0x90
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811e7de4>] __generic_file_fsync+0x44/0x90
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811e7e4d>] generic_file_fsync+0x1d/0x40
Jul 31 16:02:37 srp-ini kernel: [<ffffffffa02db9f8>] ext4_sync_file+0x268/0x610 [ext4]
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811f316d>] vfs_fsync_range+0x3d/0xb0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811fcc41>] dio_complete+0x141/0x180
Jul 31 16:02:37 srp-ini kernel: [<ffffffff811fce07>] dio_aio_complete_work+0x27/0x30
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81091038>] process_one_work+0x1d8/0x7c0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81090fab>] ? process_one_work+0x14b/0x7c0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81091734>] worker_thread+0x114/0x460
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81091620>] ? process_one_work+0x7c0/0x7c0
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81097778>] kthread+0xf8/0x110
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81097680>] ? kthread_create_on_node+0x210/0x210
Jul 31 16:02:37 srp-ini kernel: [<ffffffff8150275f>] ret_from_fork+0x3f/0x70
Jul 31 16:02:37 srp-ini kernel: [<ffffffff81097680>] ? kthread_create_on_node+0x210/0x210
Jul 31 16:02:37 srp-ini kernel: ---[ end trace 50dfc2f612b77d64 ]---
Jul 31 16:02:38 srp-ini kernel: sd 14:0:0:0: alua: stpg sense code: 04/67/0a
Jul 31 16:02:38 srp-ini kernel: device-mapper: multipath: Failing path 8:240.
Jul 31 16:02:38 srp-ini kernel: sd 13:0:0:0: alua: port group 101 state S preferred supports tOlUSNA