[CI][DRMTIP] WARNING: possible circular locking dependency detected in [acpi_power_meter]
Submitted by Martin Peres @mupuf
Assigned to Intel GFX Bugs mailing list
Link to original bug (#108903)
Description
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_144/fi-kbl-x1275/igt@runner@aborted.html
<4>[ 4.535797] ======================================================
<4>[ 4.535990] WARNING: possible circular locking dependency detected
<4>[ 4.536165] 4.20.0-rc2-g2ba924da1cb3-drmtip_144+ #1 (moved) Not tainted
<4>[ 4.536349] ------------------------------------------------------
<4>[ 4.536534] sensors/458 is trying to acquire lock:
<4>[ 4.536719] 00000000d251043c (&resource->lock){+.+.}, at: show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.536997]
but task is already holding lock:
<4>[ 4.536998] 0000000095f10a2d (kn->count#94)++, at: kernfs_seq_start+0x2d/0x80
<4>[ 4.537006]
which lock already depends on the new lock.
<4>[ 4.537850]
the existing dependency chain (in reverse order) is:
<4>[ 4.537851]
-> #1 (moved) (kn->count#94)++:
<4>[ 4.537854] kernfs_remove_by_name_ns+0x3b/0x80
<4>[ 4.537858] remove_attrs+0x34/0xd0 [acpi_power_meter]
<4>[ 4.538705] acpi_power_meter_notify+0x12b/0x1a0 [acpi_power_meter]
<4>[ 4.538706] acpi_ev_notify_dispatch+0x40/0x55
<4>[ 4.538708] acpi_os_execute_deferred+0x11/0x20
<4>[ 4.538710] process_one_work+0x262/0x630
<4>[ 4.538711] worker_thread+0x37/0x380
<4>[ 4.538713] kthread+0x119/0x130
<4>[ 4.538714] ret_from_fork+0x3a/0x50
<4>[ 4.538715]
-> #0 (&resource->lock){+.+.}:
<4>[ 4.538717] __mutex_lock+0x89/0x970
<4>[ 4.538718] show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.538720] dev_attr_show+0x17/0x50
<4>[ 4.538722] sysfs_kf_seq_show+0xba/0x110
<4>[ 4.538724] seq_read+0xdb/0x3c0
<4>[ 4.538725] __vfs_read+0x31/0x170
<4>[ 4.538727] vfs_read+0x9e/0x140
<4>[ 4.538728] ksys_read+0x50/0xc0
<4>[ 4.538729] do_syscall_64+0x55/0x190
<4>[ 4.538731] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 4.538731]
other info that might help us debug this:
<4>[ 4.538731] Possible unsafe locking scenario:
<4>[ 4.538732] CPU0 CPU1
<4>[ 4.538732] ---- ----
<4>[ 4.538732] lock(kn->count#94);
<4>[ 4.538733] lock(&resource->lock);
<4>[ 4.538734] lock(kn->count#94);
<4>[ 4.538734] lock(&resource->lock);
<4>[ 4.538735]
*** DEADLOCK ***
<4>[ 4.538736] 3 locks held by sensors/458:
<4>[ 4.538736] #0: 000000004f474723 (&p->lock){+.+.}, at: seq_read+0x37/0x3c0
<4>[ 4.538739] #1 (moved): 000000002b88effa (&of->mutex){+.+.}, at: kernfs_seq_start+0x25/0x80
<4>[ 4.538741] #2: 0000000095f10a2d (kn->count#94)++, at: kernfs_seq_start+0x2d/0x80
<4>[ 4.538743]
stack backtrace:
<4>[ 4.538745] CPU: 2 PID: 458 Comm: sensors Not tainted 4.20.0-rc2-g2ba924da1cb3-drmtip_144+ #1 (moved)
<4>[ 4.538746] Hardware name: Intel Corporation S1200SP/S1200SP, BIOS S1200SP.86B.03.01.0026.092720170729 09/27/2017
<4>[ 4.538746] Call Trace:
<4>[ 4.538750] dump_stack+0x67/0x9b
<4>[ 4.538753] print_circular_bug.isra.16+0x1c8/0x2b0
<4>[ 4.538756] __lock_acquire+0x183a/0x1b00
<4>[ 4.548434] ? lock_acquire+0xa6/0x1c0
<4>[ 4.548437] lock_acquire+0xa6/0x1c0
<4>[ 4.548800] ? show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.548803] __mutex_lock+0x89/0x970
<4>[ 4.548806] ? show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.549380] ? show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.549382] ? show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.549384] show_avg_interval+0x19/0x50 [acpi_power_meter]
<4>[ 4.549386] dev_attr_show+0x17/0x50
<4>[ 4.549388] sysfs_kf_seq_show+0xba/0x110
<4>[ 4.549391] seq_read+0xdb/0x3c0
<4>[ 4.549393] __vfs_read+0x31/0x170
<4>[ 4.549395] ? __se_sys_newfstat+0x3c/0x60
<4>[ 4.549397] vfs_read+0x9e/0x140
<4>[ 4.549399] ksys_read+0x50/0xc0
<4>[ 4.549401] do_syscall_64+0x55/0x190
<4>[ 4.549403] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 4.549404] RIP: 0033:0x7fc166075081
<4>[ 4.549406] Code: fe ff ff 48 8d 3d 67 9c 0a 00 48 83 ec 08 e8 a6 4c 02 00 66 0f 1f 44 00 00 48 8d 05 81 08 2e 00 8b 00 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 41 54 55 49 89 d4 53
<4>[ 4.549407] RSP: 002b:00007fff29db9198 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
<4>[ 4.549408] RAX: ffffffffffffffda RBX: 00005649f1d48330 RCX: 00007fc166075081
<4>[ 4.549409] RDX: 0000000000001000 RSI: 00005649f1d41b60 RDI: 0000000000000003
<4>[ 4.549410] RBP: 0000000000000d68 R08: 0000000000000000 R09: 0000000000000000
<4>[ 4.549411] R10: 00005649f1d3f010 R11: 0000000000000246 R12: 00007fc16634c760
<4>[ 4.549411] R13: 00007fc16634d2a0 R14: 00005649f1d48330 R15: 0000000000000000
<4>[ 4.553101] ------------[ cut here ]------------
<4>[ 4.554683] downgrading a read lock
<4>[ 4.554690] WARNING: CPU: 6 PID: 455 at kernel/locking/lockdep.c:3556 lock_downgrade+0x158/0x1e0
<4>[ 4.554692] Modules linked in: x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel igb mei_me mei prime_numbers acpi_power_meter
<4>[ 4.555429] CPU: 6 PID: 455 Comm: networkd-dispat Not tainted 4.20.0-rc2-g2ba924da1cb3-drmtip_144+ #1 (moved)
<4>[ 4.555430] Hardware name: Intel Corporation S1200SP/S1200SP, BIOS S1200SP.86B.03.01.0026.092720170729 09/27/2017
<4>[ 4.555432] RIP: 0010:lock_downgrade+0x158/0x1e0
<4>[ 4.555435] Code: ff e9 23 ff ff ff 4c 89 ea 4c 89 f6 48 89 df e8 2e bd ff ff 85 c0 74 aa eb 9a 48 c7 c7 62 f9 06 b0 48 89 04 24 e8 38 d2 f9 ff <0f> 0b 8b 54 24 0c 48 8b 04 24 e9 46 ff ff ff e8 64 6e 3a 00 85 c0
<4>[ 4.556536] RSP: 0018:ffffa9bc8083be38 EFLAGS: 00010082
<4>[ 4.556538] RAX: 0000000000000000 RBX: ffff9f6ed8a20040 RCX: 0000000000000000
<4>[ 4.556539] RDX: ffffffffaf1004eb RSI: 0000000000000001 RDI: ffffffffaf100500
<4>[ 4.556539] RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000000
<4>[ 4.556540] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000246
<4>[ 4.556541] R13: ffffffffaf1e70a3 R14: ffff9f6ed8b17548 R15: ffff9f6ed6ef6cb8
<4>[ 4.556542] FS: 00007f87087e2740(0000) GS:ffff9f6eeb780000(0000) knlGS:0000000000000000
<4>[ 4.556543] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 4.556544] CR2: 00007f8708764024 CR3: 0000000257024005 CR4: 00000000003606e0
<4>[ 4.556545] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[ 4.556546] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[ 4.556546] Call Trace:
<4>[ 4.556550] downgrade_write+0x12/0x80
<4>[ 4.556552] __do_munmap+0x393/0x400
<4>[ 4.556554] __vm_munmap+0x6e/0xc0
<4>[ 4.556556] __x64_sys_munmap+0x12/0x20
<4>[ 4.556558] do_syscall_64+0x55/0x190
<4>[ 4.556560] entry_SYSCALL_64_after_hwframe+0x49/0xbe
<4>[ 4.556561] RIP: 0033:0x7f8708304ab7
<4>[ 4.556562] Code: 10 e9 67 ff ff ff 0f 1f 44 00 00 48 8b 15 c9 f3 2c 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff e9 6b ff ff ff b8 0b 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 f3 2c 00 f7 d8 64 89 01 48
<4>[ 4.556563] RSP: 002b:00007ffe64198ba8 EFLAGS: 00000202 ORIG_RAX: 000000000000000b
<4>[ 4.556565] RAX: ffffffffffffffda RBX: 0000000000a92aa0 RCX: 00007f8708304ab7
<4>[ 4.556565] RDX: 0000000000040000 RSI: 0000000000040000 RDI: 00007f8708762000
<4>[ 4.556566] RBP: 00007f87087e1208 R08: 0000000000a92ad0 R09: 0000000000000012
<4>[ 4.556567] R10: 0000000000000009 R11: 0000000000000202 R12: 0000000000a92180
<4>[ 4.556568] R13: 00000000009d3e60 R14: 00007f87087e1208 R15: 00000000009d3d48
<4>[ 4.556570] irq event stamp: 13929
<4>[ 4.556572] hardirqs last enabled at (13929): [<ffffffffaf1a8138>] get_page_from_freelist+0xb8/0x13b0
<4>[ 4.556573] hardirqs last disabled at (13928): [<ffffffffaf1a821a>] get_page_from_freelist+0x19a/0x13b0
<4>[ 4.556575] softirqs last enabled at (13600): [<ffffffffafc0033a>] __do_softirq+0x33a/0x4b9
<4>[ 4.556577] softirqs last disabled at (13579): [<ffffffffaf092979>] irq_exit+0xa9/0xc0
<4>[ 4.556579] WARNING: CPU: 6 PID: 455 at kernel/locking/lockdep.c:3556 lock_downgrade+0x158/0x1e0
<4>[ 4.556580] ---[ end trace ec0600db2ca725d8 ]---
<4>[ 4.564624] **********************************************************
<4>[ 4.564625] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
<4>[ 4.564626] ** **
<4>[ 4.564626] ** trace_printk() being used. Allocating extra memory. **
<4>[ 4.564627] ** **
<4>[ 4.564628] ** This means that this is a DEBUG kernel and it is **
<4>[ 4.565790] ** unsafe for production use. **
<4>[ 4.565791] ** **
<4>[ 4.565792] ** If you see this message and you are not debugging **
<4>[ 4.565793] ** the kernel, report this immediately to your vendor! **
<4>[ 4.565793] ** **
<4>[ 4.565795] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
<4>[ 4.566964] **********************************************************