https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6623/shard-hsw6/igt@perf_pmu@frequency.html https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6614/shard-apl1/igt@perf_pmu@busy-idle-no-semaphores-bcs0.html <6> [2113.893984] Console: switching to colour dummy device 80x25 <6> [2113.894183] [IGT] perf_pmu: executing <6> [2113.939239] [IGT] perf_pmu: starting subtest frequency <3> [2114.446296] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:909 <3> [2114.446416] in_atomic(): 1, irqs_disabled(): 1, pid: 0, name: swapper/0 <4> [2114.446475] no locks held by swapper/0/0. <4> [2114.446480] irq event stamp: 24815712 <4> [2114.446493] hardirqs last enabled at (24815709): [<ffffffff817d774a>] cpuidle_enter_state+0xaa/0x450 <4> [2114.446503] hardirqs last disabled at (24815710): [<ffffffff810019ea>] trace_hardirqs_off_thunk+0x1a/0x20 <4> [2114.446511] softirqs last enabled at (24815712): [<ffffffff810b8008>] irq_enter+0x58/0x60 <4> [2114.446517] softirqs last disabled at (24815711): [<ffffffff810b7fed>] irq_enter+0x3d/0x60 <3> [2114.446522] Preemption disabled at: <4> [2114.446528] [<ffffffff819c8a59>] schedule_preempt_disabled+0x19/0x20 <4> [2114.446568] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G U 5.3.0-rc2-CI-CI_DRM_6623+ #1 <4> [2114.446573] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4> [2114.446577] Call Trace: <4> [2114.446584] <IRQ> <4> [2114.446596] dump_stack+0x67/0x9b <4> [2114.446607] ___might_sleep+0x167/0x250 <4> [2114.446619] __mutex_lock+0x51/0x9b0 <4> [2114.446744] ? intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.446847] ? gen6_read32+0x97/0x280 [i915] <4> [2114.446965] ? __i915_pmu_maybe_start_timer+0x60/0x60 [i915] <4> [2114.446976] ? atomic_dec_and_mutex_lock+0x33/0x50 <4> [2114.446984] atomic_dec_and_mutex_lock+0x33/0x50 <4> [2114.447098] intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.447208] i915_sample+0x191/0x260 [i915] <4> [2114.447322] ? __i915_pmu_maybe_start_timer+0x60/0x60 [i915] <4> [2114.447330] __hrtimer_run_queues+0x11e/0x4b0 <4> [2114.447349] hrtimer_interrupt+0xea/0x250 <4> [2114.447360] ? recalibrate_cpu_khz+0x10/0x10 <4> [2114.447377] smp_apic_timer_interrupt+0x96/0x280 <4> [2114.447386] apic_timer_interrupt+0xf/0x20 <4> [2114.447393] </IRQ> <4> [2114.447403] RIP: 0010:cpuidle_enter_state+0xae/0x450 <4> [2114.447411] Code: 44 00 00 31 ff e8 42 2b 91 ff 45 84 f6 74 12 9c 58 f6 c4 02 0f 85 78 03 00 00 31 ff e8 fb 47 98 ff e8 16 5a 9c ff fb 45 85 ed <0f> 88 c9 02 00 00 4c 2b 24 24 48 ba cf f7 53 e3 a5 9b c4 20 49 63 <4> [2114.447417] RSP: 0018:ffffffff82203e58 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 <4> [2114.447424] RAX: ffffffff82217800 RBX: ffffffff822a0760 RCX: 0000000000000000 <4> [2114.447430] RDX: 0000000000000046 RSI: 0000000000000006 RDI: ffffffff82136201 <4> [2114.447435] RBP: ffffe8ffffa18c20 R08: 0000000000000002 R09: 0000000000000000 <4> [2114.447440] R10: 0000000000000000 R11: 0000000000000000 R12: 000001ec4ed1a6f3 <4> [2114.447445] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000005 <4> [2114.447471] ? cpuidle_enter_state+0xaa/0x450 <4> [2114.447486] cpuidle_enter+0x24/0x40 <4> [2114.447495] do_idle+0x1f3/0x260 <4> [2114.447509] cpu_startup_entry+0x14/0x20 <4> [2114.447521] start_kernel+0x506/0x528 <4> [2114.447537] secondary_startup_64+0xa4/0xb0 <4> [2114.447572] <4> [2114.447578] ================================ <4> [2114.447586] WARNING: inconsistent lock state <4> [2114.447594] 5.3.0-rc2-CI-CI_DRM_6623+ #1 Tainted: G U W <4> [2114.447603] -------------------------------- <4> [2114.447611] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. <4> [2114.447622] swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: <4> [2114.447630] 00000000bcddfa1e (wakeref#4){?.+.}, at: intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.447751] {HARDIRQ-ON-W} state was registered at: <4> [2114.447764] lock_acquire+0xa6/0x1c0 <4> [2114.447775] __mutex_lock+0x9d/0x9b0 <4> [2114.447784] atomic_dec_and_mutex_lock+0x33/0x50 <4> [2114.447897] intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.448008] __engine_park+0x109/0x1f0 [i915] <4> [2114.448113] __intel_wakeref_put_last+0x14/0x60 [i915] <4> [2114.448250] i915_request_retire+0x35e/0x840 [i915] <4> [2114.448387] ring_retire_requests+0x47/0x50 [i915] <4> [2114.448526] i915_retire_requests+0x57/0xc0 [i915] <4> [2114.448665] i915_gem_wait_for_idle+0x4e7/0x590 [i915] <4> [2114.448794] switch_to_kernel_context_sync+0x25/0xe0 [i915] <4> [2114.448934] i915_gem_init+0x618/0xa80 [i915] <4> [2114.449031] i915_driver_probe+0xdea/0x18a0 [i915] <4> [2114.449130] i915_pci_probe+0x43/0x1b0 [i915] <4> [2114.449144] pci_device_probe+0x9e/0x120 <4> [2114.449155] really_probe+0xea/0x3d0 <4> [2114.449164] driver_probe_device+0x10b/0x120 <4> [2114.449173] device_driver_attach+0x4a/0x50 <4> [2114.449183] __driver_attach+0x97/0x130 <4> [2114.449196] bus_for_each_dev+0x74/0xc0 <4> [2114.449204] bus_add_driver+0x13f/0x210 <4> [2114.449214] driver_register+0x56/0xe0 <4> [2114.449223] do_one_initcall+0x58/0x300 <4> [2114.449235] do_init_module+0x56/0x1f6 <4> [2114.449245] load_module+0x25bd/0x2a40 <4> [2114.449256] __se_sys_finit_module+0xd3/0xf0 <4> [2114.449265] do_syscall_64+0x55/0x1c0 <4> [2114.449278] entry_SYSCALL_64_after_hwframe+0x49/0xbe <4> [2114.449287] irq event stamp: 24815712 <4> [2114.449298] hardirqs last enabled at (24815709): [<ffffffff817d774a>] cpuidle_enter_state+0xaa/0x450 <4> [2114.449314] hardirqs last disabled at (24815710): [<ffffffff810019ea>] trace_hardirqs_off_thunk+0x1a/0x20 <4> [2114.449331] softirqs last enabled at (24815712): [<ffffffff810b8008>] irq_enter+0x58/0x60 <4> [2114.449346] softirqs last disabled at (24815711): [<ffffffff810b7fed>] irq_enter+0x3d/0x60 <4> [2114.449357] other info that might help us debug this: <4> [2114.449368] Possible unsafe locking scenario: <4> [2114.449377] CPU0 <4> [2114.449383] ---- <4> [2114.449388] lock(wakeref#4); <4> [2114.449397] <Interrupt> <4> [2114.449403] lock(wakeref#4); <4> [2114.449411] *** DEADLOCK *** <4> [2114.449422] no locks held by swapper/0/0. <4> [2114.449430] stack backtrace: <4> [2114.449441] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G U W 5.3.0-rc2-CI-CI_DRM_6623+ #1 <4> [2114.449454] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016 <4> [2114.449464] Call Trace: <4> [2114.449472] <IRQ> <4> [2114.449482] dump_stack+0x67/0x9b <4> [2114.449494] mark_lock+0x63f/0x650 <4> [2114.449506] ? check_usage_backwards+0x160/0x160 <4> [2114.449520] __lock_acquire+0xf95/0x1e90 <4> [2114.449534] lock_acquire+0xa6/0x1c0 <4> [2114.449647] ? intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.449661] __mutex_lock+0x9d/0x9b0 <4> [2114.449773] ? intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.449887] ? intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.449992] ? gen6_read32+0x97/0x280 [i915] <4> [2114.450103] ? __i915_pmu_maybe_start_timer+0x60/0x60 [i915] <4> [2114.450116] ? atomic_dec_and_mutex_lock+0x33/0x50 <4> [2114.450127] atomic_dec_and_mutex_lock+0x33/0x50 <4> [2114.450240] intel_gt_pm_put+0x25/0x50 [i915] <4> [2114.450351] i915_sample+0x191/0x260 [i915] <4> [2114.450462] ? __i915_pmu_maybe_start_timer+0x60/0x60 [i915] <4> [2114.450474] __hrtimer_run_queues+0x11e/0x4b0 <4> [2114.450486] hrtimer_interrupt+0xea/0x250 <4> [2114.450499] ? recalibrate_cpu_khz+0x10/0x10 <4> [2114.450512] smp_apic_timer_interrupt+0x96/0x280 <4> [2114.450523] apic_timer_interrupt+0xf/0x20 <4> [2114.450531] </IRQ> <4> [2114.450540] RIP: 0010:cpuidle_enter_state+0xae/0x450 <4> [2114.450551] Code: 44 00 00 31 ff e8 42 2b 91 ff 45 84 f6 74 12 9c 58 f6 c4 02 0f 85 78 03 00 00 31 ff e8 fb 47 98 ff e8 16 5a 9c ff fb 45 85 ed <0f> 88 c9 02 00 00 4c 2b 24 24 48 ba cf f7 53 e3 a5 9b c4 20 49 63 <4> [2114.450574] RSP: 0018:ffffffff82203e58 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 <4> [2114.450588] RAX: ffffffff82217800 RBX: ffffffff822a0760 RCX: 0000000000000000 <4> [2114.450599] RDX: 0000000000000046 RSI: 0000000000000006 RDI: ffffffff82136201 <4> [2114.450610] RBP: ffffe8ffffa18c20 R08: 0000000000000002 R09: 0000000000000000 <4> [2114.450621] R10: 0000000000000000 R11: 0000000000000000 R12: 000001ec4ed1a6f3 <4> [2114.450631] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000005 <4> [2114.450649] ? cpuidle_enter_state+0xaa/0x450 <4> [2114.450661] cpuidle_enter+0x24/0x40 <4> [2114.450671] do_idle+0x1f3/0x260 <4> [2114.450681] cpu_startup_entry+0x14/0x20 <4> [2114.450694] start_kernel+0x506/0x528 <4> [2114.450705] secondary_startup_64+0xa4/0xb0 <6> [2115.972951] [IGT] perf_pmu: exiting, ret=0 <5> [2115.973371] Setting dangerous option reset - tainting kernel <5> [2115.974079] Setting dangerous option reset - tainting kernel <7> [2115.976250] [drm:intel_fbc_enable [i915]] reserved 11796480 bytes of contiguous stolen space for FBC, threshold: 1 <7> [2115.976392] [drm:intel_fbc_enable [i915]] Enabling FBC on pipe A <7> [2115.987458] [drm:__intel_fbc_disable [i915]] Disabling FBC on pipe A <6> [2115.987820] Console: switching to colour frame buffer device 128x48 <7> [2116.002201] [drm:intel_fbc_enable [i915]] reserved 11796480 bytes of contiguous stolen space for FBC, threshold: 1 <7> [2116.002512] [drm:intel_fbc_enable [i915]] Enabling FBC on pipe A <7> [2116.002762] [drm:__intel_fbc_disable [i915]] Disabling FBC on pipe A
The CI Bug Log issue associated to this bug has been updated. ### New filters associated * HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6614/shard-apl1/igt@perf_pmu@busy-idle-no-semaphores-bcs0.html - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6623/shard-hsw6/igt@perf_pmu@frequency.html
The CI Bug Log issue associated to this bug has been updated. ### New filters associated * HSW APL: igt@runner@aborted - fail - perf_pmu ((busy-idle-no-semaphores-bcs0)|(frequency)) - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6614/shard-apl1/igt@runner@aborted.html - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6623/shard-hsw6/igt@runner@aborted.html
https://patchwork.freedesktop.org/series/64693/
A CI Bug Log filter associated to this bug has been updated: {- HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6625/shard-apl1/igt@perf_pmu@busy-idle-no-semaphores-vcs0.html
A CI Bug Log filter associated to this bug has been updated: {- HSW APL: igt@runner@aborted - fail - perf_pmu ((busy-idle-no-semaphores-bcs0)|(frequency)) -} {+ HSW APL: igt@runner@aborted - fail - perf_pmu ((busy-idle-no-semaphores-bcs0)|(frequency)) +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6625/shard-apl1/igt@runner@aborted.html
A CI Bug Log filter associated to this bug has been updated: {- HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6633/shard-skl7/igt@perf_pmu@busy-no-semaphores-bcs0.html * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6636/shard-glk5/igt@perf_pmu@busy-no-semaphores-vecs0.html
A CI Bug Log filter associated to this bug has been updated: {- HSW APL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW APL SKL GLK: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} No new failures caught with the new filter
A CI Bug Log filter associated to this bug has been updated: {- HSW APL SKL GLK: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6640/shard-iclb4/igt@perf_pmu@busy-idle-no-semaphores-vcs0.html
(In reply to CI Bug Log from comment #8) > A CI Bug Log filter associated to this bug has been updated: > > {- HSW APL SKL GLK: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock > state -} > {+ HSW APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent > lock state +} > > New failures caught by the filter: > > * > https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6640/shard-iclb4/ > igt@perf_pmu@busy-idle-no-semaphores-vcs0.html Also seen on ICL.
commit c7302f204490f3eb4ef839bec228315bcd3ba43f (drm-intel/for-linux-next, drm-intel/drm-intel-next-queued) Author: Chris Wilson <chris@chris-wilson.co.uk> Date: Thu Aug 8 21:27:58 2019 +0100 drm/i915: Defer final intel_wakeref_put to process context As we need to acquire a mutex to serialise the final intel_wakeref_put, we need to ensure that we are in process context at that time. However, we want to allow operation on the intel_wakeref from inside timer and other hardirq context, which means that need to defer that final put to a workqueue. Inside the final wakeref puts, we are safe to operate in any context, as we are simply marking up the HW and state tracking for the potential sleep. It's only the serialisation with the potential sleeping getting that requires careful wait avoidance. This allows us to retain the immediate processing as before (we only need to sleep over the same races as the current mutex_lock). v2: Add a selftest to ensure we exercise the code while lockdep watches. v3: That test was extremely loud and complained about many things! v4: Not a whale! Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=111295 References: https://bugs.freedesktop.org/show_bug.cgi?id=111245 References: https://bugs.freedesktop.org/show_bug.cgi?id=111256 Fixes: 18398904ca9e ("drm/i915: Only recover active engines") Fixes: 51fbd8de87dc ("drm/i915/pmu: Atomically acquire the gt_pm wakeref") Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com> Cc: Mika Kuoppala <mika.kuoppala@linux.intel.com> Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com> Link: https://patchwork.freedesktop.org/patch/msgid/20190808202758.10453-1-chris@chris-wilson.co.uk
A CI Bug Log filter associated to this bug has been updated: {- HSW APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW BYT APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_346/fi-byt-n2820/igt@perf_pmu@busy-hang-bcs0.html
(In reply to Chris Wilson from comment #10) > commit c7302f204490f3eb4ef839bec228315bcd3ba43f (drm-intel/for-linux-next, > drm-intel/drm-intel-next-queued) > Author: Chris Wilson <chris@chris-wilson.co.uk> > Date: Thu Aug 8 21:27:58 2019 +0100 > > drm/i915: Defer final intel_wakeref_put to process context > > As we need to acquire a mutex to serialise the final > intel_wakeref_put, we need to ensure that we are in process context at > that time. However, we want to allow operation on the intel_wakeref from > inside timer and other hardirq context, which means that need to defer > that final put to a workqueue. > > Inside the final wakeref puts, we are safe to operate in any context, as > we are simply marking up the HW and state tracking for the potential > sleep. It's only the serialisation with the potential sleeping getting > that requires careful wait avoidance. This allows us to retain the > immediate processing as before (we only need to sleep over the same > races as the current mutex_lock). > > v2: Add a selftest to ensure we exercise the code while lockdep watches. > v3: That test was extremely loud and complained about many things! > v4: Not a whale! > > Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=111295 > References: https://bugs.freedesktop.org/show_bug.cgi?id=111245 > References: https://bugs.freedesktop.org/show_bug.cgi?id=111256 > Fixes: 18398904ca9e ("drm/i915: Only recover active engines") > Fixes: 51fbd8de87dc ("drm/i915/pmu: Atomically acquire the gt_pm > wakeref") > Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk> > Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com> > Cc: Mika Kuoppala <mika.kuoppala@linux.intel.com> > Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com> > Link: > https://patchwork.freedesktop.org/patch/msgid/20190808202758.10453-1- > chris@chris-wilson.co.uk (In reply to CI Bug Log from comment #11) > A CI Bug Log filter associated to this bug has been updated: > > {- HSW APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent > lock state -} > {+ HSW BYT APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: > inconsistent lock state +} > > New failures caught by the filter: > > * > https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_346/fi-byt-n2820/ > igt@perf_pmu@busy-hang-bcs0.html Seen on BYT.
A CI Bug Log filter associated to this bug has been updated: {- HSW BYT APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state -} {+ HSW BYT APL SKL GLK ICL: igt@perf_pmu@* - dmesg-warn - WARNING: inconsistent lock state +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_347/fi-byt-n2820/igt@perf_pmu@most-busy-idle-check-all-vcs0.html
commit 6dcb85a0ad990455ae7c596e3fc966ad9c1ba9c5 Author: Chris Wilson <chris@chris-wilson.co.uk> Date: Fri Aug 23 14:26:46 2019 +0100 drm/i915: Hold irq-off for the entire fake lock period Sadly lockdep records when the irqs are re-enabled and then marks up the fake lock as being irq-unsafe. Our hand is forced and so we must mark up the entire fake lock critical section as irq-off. Hopefully this is the last tweak required! v2: Not quite, we need to mark the timeline spinlock as irqsafe. That was a genuine bug being hidden by the earlier lockdep splat. Fixes: d67739268cf0 ("drm/i915/gt: Mark up the nested engine-pm timeline lock as irqsafe") Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com> Cc: Mika Kuoppala <mika.kuoppala@linux.intel.com> Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com> Link: https://patchwork.freedesktop.org/patch/msgid/20190823132700.25286-2-chris@chris-wilson.co.uk
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.