Bug 112363 - [CI][BAT]igt@i915_selftest@live_execlists - incomplete - i915_request_retire: bcs0 fence 18b59:382, current 382
Summary: [CI][BAT]igt@i915_selftest@live_execlists - incomplete - i915_request_retire:...
Status: RESOLVED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: not set not set
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
: 112362 (view as bug list)
Depends on:
Blocks:
 
Reported: 2019-11-21 08:04 UTC by Lakshmi
Modified: 2019-11-22 07:07 UTC (History)
2 users (show)

See Also:
i915 platform: SKL
i915 features: GEM/Other


Attachments

Description Lakshmi 2019-11-21 08:04:13 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_7387/fi-skl-6770hq/igt@i915_selftest@live_execlists.html
<7> [521.942652] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [521.942767] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [521.942873] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [521.943474] [drm:intel_power_well_disable [i915]] disabling always-on
<7> [521.943979] [drm:intel_power_well_enable [i915]] enabling always-on
<7> [521.944132] [drm:intel_power_well_enable [i915]] enabling DC off
<7> [521.944326] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [521.946930] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [521.947118] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [521.947268] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [521.947843] [drm:intel_power_well_disable [i915]] disabling always-on
<6> [521.955183] i915: Running intel_execlists_live_selftests/live_preempt
<7> [521.956334] [drm:intel_power_well_enable [i915]] enabling always-on
<7> [521.956446] [drm:intel_power_well_enable [i915]] enabling DC off
<7> [521.956824] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [521.958731] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [521.958830] [drm:skl_enable_dc6 [i915]] Enabling DC6
<7> [521.958922] [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
<7> [521.959509] [drm:intel_power_well_disable [i915]] disabling always-on
<7> [521.959877] [drm:intel_power_well_enable [i915]] enabling always-on
<7> [521.959977] [drm:intel_power_well_enable [i915]] enabling DC off
<7> [521.960296] [drm:gen9_set_dc_state [i915]] Setting DC state from 02 to 00
<7> [521.961246] [drm:intel_power_well_disable [i915]] disabling DC off
<7> [521.961347] [drm:skl_enable_dc6 [i915]] Enabling DC6
<0> [521.969546] igt/bcs0-5311    7.... 504959857us : i915_request_retire: bcs0 fence 18b59:382, current 382
<0> [521.981475] igt/bcs0-5311    7.... 504962267us : i915_request_retire_upto: bcs0 fence 18b4c:394, current 394
<0> [521.989658] igt/bcs0-5311    7.... 504963793us : process_csb: bcs0 cs-irq head=2, tail=5
<0> [521.997936] igt/bcs0-5311    7.... 504965065us : __i915_request_commit: bcs0 fence 18b48:410
<0> [522.009899] igt/vecs-5314    7d..1 504971157us : __execlists_submission_tasklet: vecs0: queue_priority_hint:291, submit:yes
<0> [522.021538] igt/bcs0-5311    2.... 504974659us : __i915_request_commit: bcs0 fence 18b48:458
<0> [522.029645] igt/bcs0-5311    2d..1 504975813us : __execlists_submission_tasklet: bcs0: queue_priority_hint:147, submit:yes
<0> [522.038223] igt/bcs0-5311    2.... 504976888us : process_csb: bcs0 csb[0]: status=0x00000818:0x00000040
<0> [522.050119] igt/vecs-5314    7.... 504978121us : trace_ports: vecs0: completed { 18b70:254!, 18b6f:256 }
<0> [522.061824] igt/bcs0-5311    2d..1 504979492us : __i915_request_submit: bcs0 fence 18b52:480, current 476
<0> [522.069884] igt/vcs1-5313    7.... 504980219us : i915_request_retire: vcs1 fence 18b4b:414, current 414
<0> [522.078188] igt/bcs0-5311    2.... 504981140us : i915_request_retire_upto: bcs0 fence 18b59:486, current 486
<0> [522.090070] igt/bcs0-5311    2.... 504982710us : i915_request_retire_upto: bcs0 fence 18b4c:494, current 494
<0> [522.101756] igt/vcs1-5313    7.... 504983872us : __i915_request_commit: vcs1 fence 18b6b:430
<0> [522.110051] igt/vcs1-5313    7.... 504984836us : __i915_request_commit: vcs1 fence 18b68:434
<0> [522.118496] igt/vcs1-5313    7.... 504985786us : i915_request_retire: vcs1 fence 18b4b:436, current 438
<0> [522.130349] igt/bcs0-5311    2.... 504987015us : __i915_request_commit: bcs0 fence 18b59:514
<0> [522.142145] igt/vcs1-5313    7.... 504988495us : __i915_request_commit: vcs1 fence 18b5b:452
<0> [522.150368] igt/vcs1-5313    7.... 504989262us : i915_request_retire_upto: vcs1 fence 18b60:454, current 454
<0> [522.158551] igt/vcs1-5313    7.... 504990218us : i915_request_retire_upto: vcs1 fence 18b55:458, current 458
<0> [522.170688] igt/bcs0-5311    2.... 504991411us : trace_ports: bcs0: completed { 18b4c:534!, 18b5e:532 }
<0> [522.182685] igt/bcs0-5311    2.... 504992607us : i915_request_retire_upto: bcs0 fence 18b5e:536, current 536
<0> [522.190972] igt/vcs1-5313    7.... 504993414us : __i915_request_commit: vcs1 fence 18b4b:476
<0> [522.199075] igt/bcs0-5311    2.... 504994205us : i915_request_retire: bcs0 fence 18b5c:544, current 544
<0> [522.210834] igt/vcs1-5313    7.... 504995632us : i915_request_retire: vcs1 fence 18b65:484, current 484
<0> [522.222369] igt/bcs0-5311    2.... 504996599us : trace_ports: bcs0: completed { 18b52:556!, 18b4c:556 }
<0> [522.230662] igt/vcs1-5313    7.... 504997811us : __i915_request_commit: vcs1 fence 18b51:496
<0> [522.238848] igt/vcs1-5313    7d..1 504998651us : __execlists_submission_tasklet: vcs1: queue_priority_hint:-2147483648, submit:yes
<0> [522.250596] igt/bcs0-5311    2.... 504999946us : __i915_request_commit: bcs0 fence 18b4c:572
<0> [522.262404] igt/bcs0-5311    2d..1 505001454us : __execlists_submission_tasklet: bcs0: queue_priority_hint:-2147483648, submit:yes
<0> [522.270508] igt/bcs0-5311    2.... 505002294us : i915_request_retire: bcs0 fence 18b4f:580, current 580
<0> [522.278478] igt/bcs0-5311    2.... 505003322us : i915_request_retire: bcs0 fence 18b59:584, current 584
<0> [522.290496] igt/vcs1-5313    7.... 505004439us : __i915_request_commit: vcs1 fence 18b65:524
<0> [522.302354] igt/bcs0-5311    2.... 505005833us : trace_ports: bcs0: completed { 18b56:596!, 18b48:598 }
<0> [522.310817] igt/vcs1-5313    7.... 505007122us : i915_request_retire: vcs1 fence 18b68:532, current 532
<0> [522.319164] igt/vcs1-5313    7d..1 505008047us : __execlists_submission_tasklet: vcs1: queue_priority_hint:131, submit:yes
Comment 1 CI Bug Log 2019-11-21 08:05:11 UTC
The CI Bug Log issue associated to this bug has been updated.

### New filters associated

* SKL: igt@i915_selftest@live_execlists - incomplete - i915_request_retire: bcs0 fence 18b59:382, current 382
  - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_7387/fi-skl-6770hq/igt@i915_selftest@live_execlists.html
Comment 2 Chris Wilson 2019-11-21 08:12:51 UTC
We have to look at the pstore to get the final death throes...

<0>[  534.577515] i915_sel-5332    7d..1 521975229us : trace_ports: vcs1: submit { 19005:2, 19004:2 }
<0>[  534.577567]   <idle>-0       1..s1 521975268us : process_csb: vcs1 cs-irq head=5, tail=0
<0>[  534.577619]   <idle>-0       1..s1 521975269us : process_csb: vcs1 csb[0]: status=0x00000802:0x00000060
<0>[  534.577670]   <idle>-0       1..s1 521975270us : trace_ports: vcs1: preempted { 19004:2*, 0:0 }
<0>[  534.577719]   <idle>-0       1..s1 521975271us : trace_ports: vcs1: promote { 19005:2!, 19004:2 }
<0>[  534.577784] i915_sel-5332    7.... 521975305us : i915_request_retire: vcs1 fence 19004:2, current 2
<0>[  534.577836] i915_sel-5332    7.... 521975308us : intel_context_unpin: vcs1 context:19004 retire
<0>[  534.577886] i915_sel-5332    7.... 521975311us : __intel_context_retire: vcs1 context:19004 retire
<0>[  534.577944]   <idle>-0       1..s1 521975324us : assert_pending_valid: Unpinned context:19004 in pending[1]
<0>[  534.577997]   <idle>-0       1..s1 521975329us : process_csb: process_csb:2166 GEM_BUG_ON(!assert_pending_valid(execlists, "promote"))
<0>[  534.578002] ---------------------------------

Which looks like a valid race in the debug; that is the HW managed to complete and we processed that completion on another CPU, before we were able to perform our assertions!
Comment 3 Chris Wilson 2019-11-21 08:13:12 UTC
*** Bug 112362 has been marked as a duplicate of this bug. ***
Comment 4 Chris Wilson 2019-11-21 13:33:19 UTC
commit c95d31c3df1b9ff29bcd85c47324e16d430bbd5a
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Nov 21 10:35:46 2019 +0000

    drm/i915/execlists: Lock the request while validating it during promotion
    
    Since the request is already on the HW as we perform its validation, it
    and even its subsequent barrier may be concurrently retired before we
    process the assertions. If it is retired already and so off the HW, our
    assertions become void and we need to ignore them.
    
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=112363
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
    Reviewed-by: Joonas Lahtinen <joonas.lahtinen@linux.intel.com>
    Link: https://patchwork.freedesktop.org/patch/msgid/20191121103546.146487-1-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.