Bug 111677

Summary: [CI][RESUME] igt@gem_exec_schedule@preempt-queue-* - incomplete
Product: DRI Reporter: Martin Peres <martin.peres>
Component: DRM/IntelAssignee: Intel GFX Bugs mailing list <intel-gfx-bugs>
Status: RESOLVED FIXED QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: not set    
Priority: high CC: intel-gfx-bugs
Version: XOrg git   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: TGL i915 features: GEM/Other

Description Martin Peres 2019-09-12 13:11:34 UTC 
https://intel-gfx-ci.01.org/tree/drm-tip/drmtip_365/fi-tgl-u/igt@gem_exec_schedule@preempt-queue-blt.html

<6> [336.188835] Console: switching to colour dummy device 80x25
<6> [336.189265] [IGT] gem_exec_schedule: executing
<5> [336.203959] Setting dangerous option reset - tainting kernel
<5> [336.209763] Setting dangerous option reset - tainting kernel
<5> [336.210062] Setting dangerous option reset - tainting kernel
<5> [336.215024] Setting dangerous option reset - tainting kernel
<5> [336.215201] Setting dangerous option reset - tainting kernel
<5> [336.220121] Setting dangerous option reset - tainting kernel
<5> [336.220300] Setting dangerous option reset - tainting kernel
<6> [336.223185] [IGT] gem_exec_schedule: starting subtest preempt-queue-blt
Comment 2 Chris Wilson 2019-09-12 13:19:36 UTC 
What a coincidence. Staring at

[  173.533488] gem_tile-5897    5d..1 164788949us : __execlists_submission_tasklet: bcs0: queue_priority_hint:-2147483648, submit:yes
[  173.533521] gem_tile-5897    5d..1 164788951us : trace_ports: bcs0: submit { 111c1:2, 0:0 }
[  173.533555] gem_tile-5897    5.... 164788982us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:201, end:202, idx:0, len:1, used:2 }
[  173.533595] gem_tile-5897    5.... 164788982us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:201, end:202, idx:0, len:1, used:2 }
[  173.533632] gem_tile-5897    5.... 164788983us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:201, end:202, idx:1, len:1, used:3 }
[  173.533670] gem_tile-5897    5...1 164788984us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:201, end:202, idx:1, len:1, used:1 } inserting pte
[  173.533706]   <idle>-0       6..s1 164789050us : process_csb: bcs0 cs-irq head=9, tail=10
[  173.533739]   <idle>-0       6..s1 164789052us : process_csb: bcs0 csb[10]: status=0x00008019:0x03ff8000
[  173.533775]   <idle>-0       6..s1 164789055us : trace_ports: bcs0: promote { 111c1:2*, 0:0 }
[  173.533805] gem_tile-5897    5.... 164789056us : __intel_context_do_pin: bcs0 context:111c2 pin ring:{head:0000, tail:0000}
[  173.533839]   <idle>-0       6d.s2 164789059us : __execlists_submission_tasklet: bcs0: queue_priority_hint:-2147483648, submit:no
[  173.533880] gem_tile-5897    5.... 164789075us : __i915_request_commit: bcs0 fence 111c2:2
[  173.533917] gem_tile-5897    5d..1 164789082us : __i915_request_submit: bcs0 fence 111c2:2, current 0
[  173.533949] gem_tile-5897    5d..1 164789083us : __execlists_submission_tasklet: bcs0: queue_priority_hint:-2147483648, submit:yes
[  173.533983] gem_tile-5897    5d..1 164789085us : trace_ports: bcs0: submit { 111c1:2*, 111c2:2 }
[  173.534013]   <idle>-0       6..s1 164789098us : process_csb: bcs0 cs-irq head=10, tail=11
[  173.534043]   <idle>-0       6..s1 164789098us : process_csb: bcs0 csb[11]: status=0x00008019:0x00008005
[  173.534073]   <idle>-0       6..s1 164789099us : trace_ports: bcs0: preempted { 111c1:2*, 0:0 }
[  173.534103]   <idle>-0       6..s1 164789101us : trace_ports: bcs0: promote { 111c1:2*, 111c2:2 }
[  173.534141]   <idle>-0       6d.s2 164789104us : __execlists_submission_tasklet: bcs0: expired last=111c1:2, prio=3, hint=3
[  173.534185] gem_tile-5897    5.... 164789105us : __i915_request_commit: bcs0 fence 111c1:4
[  173.534221]   <idle>-0       6d.s2 164789105us : __i915_request_unsubmit: bcs0 fence 111c2:2, current 0
[  173.534257]   <idle>-0       6d.s2 164789108us : __i915_request_unsubmit: bcs0 fence 111c1:2, current 1
[  173.534292]   <idle>-0       6d.s2 164789111us : __i915_request_submit: bcs0 fence 111c1:2, current 1
[  173.534326]   <idle>-0       6d.s2 164789114us : __i915_request_submit: bcs0 fence 111c2:2, current 0
[  173.534358]   <idle>-0       6d.s2 164789115us : __execlists_submission_tasklet: bcs0: queue_priority_hint:-2147483648, submit:yes
[  173.534392]   <idle>-0       6d.s2 164789116us : trace_ports: bcs0: submit { 111c1:2*, 111c2:2 }
[  173.534422]   <idle>-0       6..s1 164789128us : process_csb: bcs0 cs-irq head=11, tail=0
[  173.534454]   <idle>-0       6..s1 164789129us : process_csb: bcs0 csb[0]: status=0x00008019:0x00008005
[  173.534484]   <idle>-0       6..s1 164789130us : trace_ports: bcs0: preempted { 111c1:2*, 111c2:2 }
[  173.534514]   <idle>-0       6..s1 164789131us : trace_ports: bcs0: promote { 111c1:2*, 111c2:2 }
[  173.534551] gem_tile-5897    5.... 164789133us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:202, end:302, idx:0, len:1, used:2 }
[  173.534590] gem_tile-5897    5.... 164789134us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:202, end:302, idx:0, len:1, used:2 }
[  173.534627] gem_tile-5897    5.... 164789135us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:202, end:302, idx:1, len:1, used:3 }
[  173.534667] gem_tile-5897    5...1 164789135us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:202, end:302, idx:2, len:256, used:2 } inserting pte
[  173.534708] gem_tile-5897    5.... 164789151us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:302, end:303, idx:0, len:1, used:2 }
[  173.534744] gem_tile-5897    5.... 164789152us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:302, end:303, idx:0, len:1, used:2 }
[  173.534782] gem_tile-5897    5.... 164789152us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:302, end:303, idx:1, len:1, used:3 }
[  173.534824] gem_tile-5897    5...1 164789153us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:302, end:303, idx:258, len:1, used:258 } inserting pte
[  173.534862] gem_tile-5897    5.... 164789219us : __intel_context_do_pin: bcs0 context:111c3 pin ring:{head:0000, tail:0000}
[  173.534902] gem_tile-5897    5.... 164789236us : __i915_request_commit: bcs0 fence 111c3:2
[  173.534944] gem_tile-5897    5.... 164789259us : __i915_request_commit: bcs0 fence 111c1:6
[  173.534984] gem_tile-5897    5.... 164789284us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:303, end:304, idx:0, len:1, used:2 }
[  173.535029] gem_tile-5897    5.... 164789284us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:303, end:304, idx:0, len:1, used:2 }
[  173.535074] gem_tile-5897    5.... 164789285us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:303, end:304, idx:1, len:1, used:3 }
[  173.535114] gem_tile-5897    5...1 164789286us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:303, end:304, idx:259, len:1, used:259 } inserting pte
[  173.535148] gem_tile-5897    5.... 164789371us : __intel_context_do_pin: bcs0 context:111c4 pin ring:{head:0000, tail:0000}
[  173.535185] gem_tile-5897    5.... 164789387us : __i915_request_commit: bcs0 fence 111c4:2
[  173.535220] gem_tile-5897    5.... 164789407us : __i915_request_commit: bcs0 fence 111c1:8
[  173.535254] gem_tile-5897    5.... 164789434us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:304, end:305, idx:0, len:1, used:2 }
[  173.535290] gem_tile-5897    5.... 164789436us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:304, end:305, idx:0, len:1, used:2 }
[  173.535328] gem_tile-5897    5.... 164789436us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:304, end:305, idx:1, len:1, used:3 }
[  173.535364] gem_tile-5897    5...1 164789437us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:304, end:305, idx:260, len:1, used:260 } inserting pte
[  173.535399] gem_tile-5897    5.... 164789505us : __intel_context_do_pin: bcs0 context:111c5 pin ring:{head:0000, tail:0000}
[  173.535436] gem_tile-5897    5.... 164789520us : __i915_request_commit: bcs0 fence 111c5:2
[  173.535480] gem_tile-5897    5.... 164789541us : __i915_request_commit: bcs0 fence 111c1:10
[  173.535530] gem_tile-5897    5.... 164789568us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:305, end:306, idx:0, len:1, used:2 }
[  173.535568] gem_tile-5897    5.... 164789568us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:305, end:306, idx:0, len:1, used:2 }
[  173.535607] gem_tile-5897    5.... 164789569us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:305, end:306, idx:1, len:1, used:3 }
[  173.535643] gem_tile-5897    5...1 164789570us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:305, end:306, idx:261, len:1, used:261 } inserting pte
[  173.535680] gem_tile-5897    5.... 164789636us : __intel_context_do_pin: bcs0 context:111c6 pin ring:{head:0000, tail:0000}
[  173.535717] gem_tile-5897    5.... 164789651us : __i915_request_commit: bcs0 fence 111c6:2
[  173.535752] gem_tile-5897    5.... 164789671us : __i915_request_commit: bcs0 fence 111c1:12
[  173.535791] gem_tile-5897    5.... 164789694us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:3, start:306, end:307, idx:0, len:1, used:2 }
[  173.535827] gem_tile-5897    5.... 164789695us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:2, start:306, end:307, idx:0, len:1, used:2 }
[  173.535863] gem_tile-5897    5.... 164789696us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:1, start:306, end:307, idx:1, len:1, used:3 }
[  173.535901] gem_tile-5897    5...1 164789696us : __gen8_ppgtt_alloc: __gen8_ppgtt_alloc(00000000eaa593fb):{ lvl:0, start:306, end:307, idx:262, len:1, used:262 } inserting pte
[  173.535936] gem_tile-5897    5.... 164789758us : __intel_context_do_pin: bcs0 context:111c7 pin ring:{head:0000, tail:0000}
[  173.535974] gem_tile-5897    5.... 164789780us : __i915_request_commit: bcs0 fence 111c7:2
[  173.536010] gem_tile-5897    5.... 164789787us : i915_request_retire: bcs0 fence 111c1:2, current 3
[  173.536048] gem_tile-5897    5.... 164789804us : __i915_request_commit: bcs0 fence 111c1:14
[  173.536082] gem_tile-5897    5.... 164789826us : __i915_request_commit: bcs0 fence 111c1:16
[  173.536116] gem_tile-5897    5.... 164789846us : __i915_request_commit: bcs0 fence 111c1:18
[  173.536151]   <idle>-0       5..s1 164791352us : process_csb: bcs0 cs-irq head=0, tail=0
[  173.536186]   <idle>-0       5d.s2 164791355us : __i915_request_submit: bcs0 fence 111c1:4, current 13
[  173.536227]   <idle>-0       5d.s2 164791357us : __i915_request_submit: bcs0 fence 111c3:2, current 0
[  173.536267]   <idle>-0       5d.s2 164791358us : __i915_request_submit: bcs0 fence 111c1:6, current 13
[  173.536300]   <idle>-0       5d.s2 164791359us : __execlists_submission_tasklet: bcs0: queue_priority_hint:3, submit:yes
[  173.536334]   <idle>-0       5d.s2 164791360us : trace_ports: bcs0: submit { 111c2:2, 111c3:2 }
[  173.536372] kworker/-5409    4.... 166757544us : i915_request_retire: bcs0 fence 111c1:4, current 17
[  173.536406] kworker/-205     5.... 166757566us : process_csb: bcs0 cs-irq head=0, tail=0
[  173.536444] kworker/-5409    4d..1 166757607us : i915_sched_node_fini: i915_sched_node_fini:452 GEM_BUG_ON(!node_signaled(dep->signaler))

shows us that our preemption logic for Tigerlake is snafu. I assume we need an update to the semaphore wait.
Comment 3 Chris Wilson 2019-09-17 16:43:11 UTC 
commit c210e85b8f3371168ce78c8da00b913839a84ec7 (HEAD -> drm-intel-next-queued, drm-intel/drm-intel-next-queued)
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Tue Sep 17 13:30:55 2019 +0100

    drm/i915/tgl: Extend MI_SEMAPHORE_WAIT
    
    On Tigerlake, MI_SEMAPHORE_WAIT grew an extra dword, so be sure to
    update the length field and emit that extra parameter and any padding
    noop as required.
    
    v2: Define the token shift while we are adding the updated MI_SEMAPHORE_WAIT
    v3: Use int instead of bool in the addition so that readers are not left
    wondering about the intricacies of the C spec. Now they just have to
    worry what the integer value of a boolean operation is...
    
    Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
    Cc: Mika Kuoppala <mika.kuoppala@linux.intel.com>
    Cc: Daniele Ceraolo Spurio <daniele.ceraolospurio@intel.com>
    Cc: Michal Winiarski <michal.winiarski@intel.com>
    Reviewed-by: Mika Kuoppala <mika.kuoppala@linux.intel.com>
    Link: https://patchwork.freedesktop.org/patch/msgid/20190917123055.28965-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.