igt@i915_module_load@reload-with-fault-injection - process_csb:2211 GEM_BUG_ON(!i915_request_completed(*execlists->active) && !reset_in_progress(execlists))
<0>[ 337.394775] i915_mod-3200 10.... 316403984us : execlists_reset_finish: 0000:00:02.0 vecs0: depth->0
<0>[ 337.394848] i915_mod-3200 10.... 316403988us : __intel_gt_set_wedged.part.30: end
<0>[ 337.394917] i915_mod-3200 10.... 316403992us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.394963] i915_mod-3200 10.... 316403998us : execlists_reset_prepare: 0000:00:02.0 rcs0: depth<-0
<0>[ 337.395058] i915_mod-3200 10.... 316403999us : intel_engine_stop_cs: 0000:00:02.0 rcs0:
<0>[ 337.395128] i915_mod-3200 10.... 316404000us : execlists_reset_prepare: 0000:00:02.0 bcs0: depth<-0
<0>[ 337.395201] i915_mod-3200 10.... 316404000us : intel_engine_stop_cs: 0000:00:02.0 bcs0:
<0>[ 337.395271] i915_mod-3200 10.... 316404001us : execlists_reset_prepare: 0000:00:02.0 vcs0: depth<-0
<0>[ 337.395343] i915_mod-3200 10.... 316404001us : intel_engine_stop_cs: 0000:00:02.0 vcs0:
<0>[ 337.395413] i915_mod-3200 10.... 316404002us : execlists_reset_prepare: 0000:00:02.0 vecs0: depth<-0
<0>[ 337.395486] i915_mod-3200 10.... 316404003us : intel_engine_stop_cs: 0000:00:02.0 vecs0:
<0>[ 337.395558] i915_mod-3200 10.... 316404004us : __intel_gt_reset: engine_mask=ff
<0>[ 337.395627] i915_mod-3200 10.... 316404013us : execlists_reset_rewind: 0000:00:02.0 rcs0:
<0>[ 337.395697] i915_mod-3200 10d..1 316404014us : process_csb: 0000:00:02.0 rcs0: cs-irq head=5, tail=5
<0>[ 337.395769] i915_mod-3200 10.... 316404015us : execlists_reset_rewind: 0000:00:02.0 bcs0:
<0>[ 337.395839] i915_mod-3200 10d..1 316404015us : process_csb: 0000:00:02.0 bcs0: cs-irq head=5, tail=5
<0>[ 337.395911] i915_mod-3200 10.... 316404017us : execlists_reset_rewind: 0000:00:02.0 vcs0:
<0>[ 337.395980] i915_mod-3200 10d..1 316404017us : process_csb: 0000:00:02.0 vcs0: cs-irq head=5, tail=5
<0>[ 337.396051] i915_mod-3200 10.... 316404019us : execlists_reset_rewind: 0000:00:02.0 vecs0:
<0>[ 337.396121] i915_mod-3200 10d..1 316404019us : process_csb: 0000:00:02.0 vecs0: cs-irq head=5, tail=5
<0>[ 337.396193] i915_mod-3200 10.... 316404023us : execlists_reset_finish: 0000:00:02.0 rcs0: depth->0
<0>[ 337.396264] i915_mod-3200 10.... 316404023us : execlists_reset_finish: 0000:00:02.0 bcs0: depth->0
<0>[ 337.396335] i915_mod-3200 10.... 316404023us : execlists_reset_finish: 0000:00:02.0 vcs0: depth->0
<0>[ 337.396405] i915_mod-3200 10.... 316404023us : execlists_reset_finish: 0000:00:02.0 vecs0: depth->0
<0>[ 337.396477] i915_mod-3200 10.... 316404024us : intel_gt_suspend_late: 0000:00:02.0
<0>[ 337.396546] i915_mod-3200 10.... 316404071us : intel_context_unpin: 0000:00:02.0 rcs0: context:3c11retire
<0>[ 337.396619] i915_mod-3200 10.... 316404101us : __intel_context_retire: 0000:00:02.0 rcs0: context:3c11retire
<0>[ 337.396692] i915_mod-3200 10.... 316404172us : intel_context_unpin: 0000:00:02.0 bcs0: context:3c13retire
<0>[ 337.396764] i915_mod-3200 10.... 316404174us : __intel_context_retire: 0000:00:02.0 bcs0: context:3c13retire
<0>[ 337.396836] i915_mod-3200 10.... 316404186us : intel_context_unpin: 0000:00:02.0 vcs0: context:3c15retire
<0>[ 337.396907] i915_mod-3200 10.... 316404188us : __intel_context_retire: 0000:00:02.0 vcs0: context:3c15retire
<0>[ 337.396979] i915_mod-3200 10.... 316404206us : intel_context_unpin: 0000:00:02.0 vecs0: context:3c17retire
<0>[ 337.397050] i915_mod-3200 10.... 316404208us : __intel_context_retire: 0000:00:02.0 vecs0: context:3c17retire
<0>[ 337.397124] i915_mod-3200 3.... 316730773us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.397172] i915_mod-3200 3.... 316730802us : __intel_gt_reset: engine_mask=ff
<0>[ 337.397263] i915_mod-3200 4.... 316752048us : __intel_context_do_pin: 0000:00:02.0 rcs'0: context:3c20pin ring:{head:0000, tail:0000}
<0>[ 337.397341] i915_mod-3200 4.... 316752266us : __intel_context_do_pin: 0000:00:02.0 bcs'0: context:3c22pin ring:{head:0000, tail:0000}
<0>[ 337.397419] i915_mod-3200 4.... 316752409us : __intel_context_do_pin: 0000:00:02.0 vcs'0: context:3c24pin ring:{head:0000, tail:0000}
<0>[ 337.397496] i915_mod-3200 4.... 316752554us : __intel_context_do_pin: 0000:00:02.0 vecs'0: context:3c26pin ring:{head:0000, tail:0000}
<0>[ 337.397575] i915_mod-3200 4.... 316753535us : intel_gt_resume: 0000:00:02.0
<0>[ 337.397642] i915_mod-3200 4.... 316753559us : __gt_unpark: 0000:00:02.0
<0>[ 337.397708] i915_mod-3200 4.... 316759447us : __engine_unpark: 0000:00:02.0 rcs'0:
<0>[ 337.397786] i915_mod-3200 4d... 316759672us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c20:2, current 0
<0>[ 337.397862] i915_mod-3200 4d... 316759691us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.397940] i915_mod-3200 4d..2 316759747us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:2, current 0
<0>[ 337.398019] i915_mod-3200 4d..2 316759784us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c20:2, 0:0 }
<0>[ 337.398094] <idle>-0 2..s1 316759791us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=5, tail=0
<0>[ 337.398168] <idle>-0 2..s1 316759792us : process_csb: 0000:00:02.0 rcs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.398244] i915_mod-3200 4.... 316759867us : __engine_unpark: 0000:00:02.0 bcs'0:
<0>[ 337.398322] i915_mod-3200 4d... 316759944us : __i915_request_commit: 0000:00:02.0 bcs'0: fence 3c22:2, current 0
<0>[ 337.398399] i915_mod-3200 4d... 316759945us : __engine_park: 0000:00:02.0 bcs'0:
<0>[ 337.398476] i915_mod-3200 4d..2 316759952us : __i915_request_submit: 0000:00:02.0 bcs'0: fence 3c22:2, current 0
<0>[ 337.398554] i915_mod-3200 4d..2 316759960us : trace_ports: 0000:00:02.0 bcs'0: submit { 3c22:2, 0:0 }
<0>[ 337.398628] i915_mod-3200 4.... 316759965us : __engine_unpark: 0000:00:02.0 vcs'0:
<0>[ 337.398706] i915_mod-3200 4d... 316759988us : __i915_request_commit: 0000:00:02.0 vcs'0: fence 3c24:2, current 0
<0>[ 337.398782] i915_mod-3200 4d... 316759989us : __engine_park: 0000:00:02.0 vcs'0:
<0>[ 337.398860] i915_mod-3200 4d..2 316759996us : __i915_request_submit: 0000:00:02.0 vcs'0: fence 3c24:2, current 0
<0>[ 337.398939] i915_mod-3200 4d..2 316760003us : trace_ports: 0000:00:02.0 vcs'0: submit { 3c24:2, 0:0 }
<0>[ 337.399012] i915_mod-3200 4.... 316760008us : __engine_unpark: 0000:00:02.0 vecs'0:
<0>[ 337.399090] i915_mod-3200 4d... 316760030us : __i915_request_commit: 0000:00:02.0 vecs'0: fence 3c26:2, current 0
<0>[ 337.399168] i915_mod-3200 4d... 316760031us : __engine_park: 0000:00:02.0 vecs'0:
<0>[ 337.399245] i915_mod-3200 4d..2 316760037us : __i915_request_submit: 0000:00:02.0 vecs'0: fence 3c26:2, current 0
<0>[ 337.399325] i915_mod-3200 4d..2 316760044us : trace_ports: 0000:00:02.0 vecs'0: submit { 3c26:2, 0:0 }
<0>[ 337.399399] <idle>-0 2.Ns1 316760089us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c20:2!, 0:0 }
<0>[ 337.399482] kworker/-3518 2.... 316760160us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c20:2, current 2
<0>[ 337.399565] kworker/-3518 2d... 316760248us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c20:4, current 2
<0>[ 337.399642] kworker/-3518 2d... 316760251us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.399720] kworker/-3518 2d..2 316760263us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:4, current 2
<0>[ 337.399799] kworker/-3518 2d..2 316760273us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c20:4, 0:0 }
<0>[ 337.399881] kworker/-3518 2.... 316760293us : i915_request_retire: 0000:00:02.0 vecs'0: fence 3c26:2, current 2
<0>[ 337.399958] kworker/-3518 2.... 316760294us : __engine_park: 0000:00:02.0 vecs'0:
<0>[ 337.400029] kworker/-3518 2..s. 316760341us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=0, tail=3
<0>[ 337.400103] kworker/-3518 2..s. 316760341us : process_csb: 0000:00:02.0 rcs'0: csb[1]: status=0x00000818:0x00000000
<0>[ 337.400180] kworker/-3518 2..s. 316760341us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c20:2!, 0:0 }
<0>[ 337.400253] kworker/-3518 2..s. 316760346us : process_csb: 0000:00:02.0 rcs'0: csb[2]: status=0x00000001:0x00000000
<0>[ 337.400329] kworker/-3518 2..s. 316760347us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c20:4!, 0:0 }
<0>[ 337.400402] kworker/-3518 2..s. 316760347us : process_csb: 0000:00:02.0 rcs'0: csb[3]: status=0x00000818:0x00000000
<0>[ 337.400478] kworker/-3518 2..s. 316760347us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c20:4!, 0:0 }
<0>[ 337.400550] kworker/-3518 2..s. 316760349us : process_csb: 0000:00:02.0 bcs'0: cs-irq head=5, tail=1
<0>[ 337.400622] kworker/-3518 2..s. 316760349us : process_csb: 0000:00:02.0 bcs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.400697] kworker/-3518 2..s. 316760349us : trace_ports: 0000:00:02.0 bcs'0: promote { 3c22:2!, 0:0 }
<0>[ 337.400769] kworker/-3518 2..s. 316760350us : process_csb: 0000:00:02.0 bcs'0: csb[1]: status=0x00000818:0x00000000
<0>[ 337.400843] kworker/-3518 2..s. 316760350us : trace_ports: 0000:00:02.0 bcs'0: completed { 3c22:2!, 0:0 }
<0>[ 337.400916] kworker/-3518 2..s. 316760351us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=5, tail=1
<0>[ 337.400988] kworker/-3518 2..s. 316760351us : process_csb: 0000:00:02.0 vcs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.401063] kworker/-3518 2..s. 316760351us : trace_ports: 0000:00:02.0 vcs'0: promote { 3c24:2!, 0:0 }
<0>[ 337.401135] kworker/-3518 2..s. 316760352us : process_csb: 0000:00:02.0 vcs'0: csb[1]: status=0x00000818:0x00000000
<0>[ 337.401210] kworker/-3518 2..s. 316760352us : trace_ports: 0000:00:02.0 vcs'0: completed { 3c24:2!, 0:0 }
<0>[ 337.401283] kworker/-3518 2..s. 316760353us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=5, tail=1
<0>[ 337.401354] kworker/-3518 2..s. 316760353us : process_csb: 0000:00:02.0 vecs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.401429] kworker/-3518 2..s. 316760353us : trace_ports: 0000:00:02.0 vecs'0: promote { 3c26:2!, 0:0 }
<0>[ 337.401501] kworker/-3518 2..s. 316760354us : process_csb: 0000:00:02.0 vecs'0: csb[1]: status=0x00000818:0x00000000
<0>[ 337.401576] kworker/-3518 2..s. 316760354us : trace_ports: 0000:00:02.0 vecs'0: completed { 3c26:2!, 0:0 }
<0>[ 337.401659] kworker/-3518 2.... 316760402us : i915_request_retire: 0000:00:02.0 vcs'0: fence 3c24:2, current 2
<0>[ 337.401735] kworker/-3518 2.... 316760403us : __engine_park: 0000:00:02.0 vcs'0:
<0>[ 337.401812] kworker/-3518 2.... 316760410us : i915_request_retire: 0000:00:02.0 bcs'0: fence 3c22:2, current 2
<0>[ 337.401888] kworker/-3518 2.... 316760412us : __engine_park: 0000:00:02.0 bcs'0:
<0>[ 337.401958] i915_mod-3200 4.... 316760415us : __intel_context_do_pin: 0000:00:02.0 rcs'0: context:3c27pin ring:{head:0000, tail:0000}
<0>[ 337.402046] kworker/-3518 2.... 316760418us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c20:4, current 4
<0>[ 337.402131] i915_mod-3200 4.... 316760510us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c27:2, current 0
<0>[ 337.402214] i915_mod-3200 4d..1 316760523us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c27:2, current 0
<0>[ 337.402292] i915_mod-3200 4d..1 316760526us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c27:2, 0:0 }
<0>[ 337.402366] <idle>-0 2..s1 316760557us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=3, tail=4
<0>[ 337.402439] <idle>-0 2..s1 316760557us : process_csb: 0000:00:02.0 rcs'0: csb[4]: status=0x00000001:0x00000000
<0>[ 337.402514] <idle>-0 2..s1 316760559us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c27:2, 0:0 }
<0>[ 337.402586] <idle>-0 2..s1 316760653us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=4, tail=5
<0>[ 337.402657] <idle>-0 2..s1 316760654us : process_csb: 0000:00:02.0 rcs'0: csb[5]: status=0x00000818:0x00000020
<0>[ 337.402731] <idle>-0 2..s1 316760655us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c27:2!, 0:0 }
<0>[ 337.402814] kworker/-3518 2.... 316760665us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c27:2, current 2
<0>[ 337.402890] i915_mod-3200 4.... 316760775us : __engine_unpark: 0000:00:02.0 bcs'0:
<0>[ 337.402959] i915_mod-3200 4.... 316760813us : __intel_context_do_pin: 0000:00:02.0 bcs'0: context:3c28pin ring:{head:0000, tail:0000}
<0>[ 337.403048] i915_mod-3200 4.... 316760819us : __i915_request_commit: 0000:00:02.0 bcs'0: fence 3c28:2, current 0
<0>[ 337.403131] i915_mod-3200 4d..1 316760823us : __i915_request_submit: 0000:00:02.0 bcs'0: fence 3c28:2, current 0
<0>[ 337.403210] i915_mod-3200 4d..1 316760825us : trace_ports: 0000:00:02.0 bcs'0: submit { 3c28:2, 0:0 }
<0>[ 337.403284] kworker/-3518 2..s1 316760849us : process_csb: 0000:00:02.0 bcs'0: cs-irq head=1, tail=3
<0>[ 337.403356] kworker/-3518 2..s1 316760849us : process_csb: 0000:00:02.0 bcs'0: csb[2]: status=0x00000001:0x00000000
<0>[ 337.403431] kworker/-3518 2..s1 316760850us : trace_ports: 0000:00:02.0 bcs'0: promote { 3c28:2!, 0:0 }
<0>[ 337.403503] kworker/-3518 2..s1 316760851us : process_csb: 0000:00:02.0 bcs'0: csb[3]: status=0x00000818:0x00000020
<0>[ 337.403578] kworker/-3518 2..s1 316760851us : trace_ports: 0000:00:02.0 bcs'0: completed { 3c28:2!, 0:0 }
<0>[ 337.403651] kworker/-3518 2.... 316760854us : intel_context_unpin: 0000:00:02.0 rcs'0: context:3c27retire
<0>[ 337.403734] kworker/-3518 2d... 316760920us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c20:6, current 4
<0>[ 337.403811] kworker/-3518 2d... 316760923us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.403889] kworker/-3518 2d..2 316761015us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:6, current 4
<0>[ 337.403967] kworker/-3518 2d..2 316761053us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c20:6, 0:0 }
<0>[ 337.404040] i915_mod-3200 4.... 316761056us : __engine_unpark: 0000:00:02.0 vcs'0:
<0>[ 337.404109] i915_mod-3200 4.... 316761058us : __intel_context_do_pin: 0000:00:02.0 vcs'0: context:3c29pin ring:{head:0000, tail:0000}
<0>[ 337.404198] i915_mod-3200 4.... 316761069us : __i915_request_commit: 0000:00:02.0 vcs'0: fence 3c29:2, current 0
<0>[ 337.404281] i915_mod-3200 4d..1 316761074us : __i915_request_submit: 0000:00:02.0 vcs'0: fence 3c29:2, current 0
<0>[ 337.404359] i915_mod-3200 4d..1 316761075us : trace_ports: 0000:00:02.0 vcs'0: submit { 3c29:2, 0:0 }
<0>[ 337.404433] kworker/-3518 2..s1 316761082us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=1, tail=2
<0>[ 337.404506] kworker/-3518 2..s1 316761082us : process_csb: 0000:00:02.0 vcs'0: csb[2]: status=0x00000001:0x00000000
<0>[ 337.404581] kworker/-3518 2..s1 316761083us : trace_ports: 0000:00:02.0 vcs'0: promote { 3c29:2!, 0:0 }
<0>[ 337.404652] kworker/-3518 2..s1 316761086us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=2, tail=3
<0>[ 337.404723] kworker/-3518 2..s1 316761086us : process_csb: 0000:00:02.0 vcs'0: csb[3]: status=0x00000818:0x00000020
<0>[ 337.404798] kworker/-3518 2..s1 316761087us : trace_ports: 0000:00:02.0 vcs'0: completed { 3c29:2!, 0:0 }
<0>[ 337.404870] kworker/-3518 2..s. 316761092us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=5, tail=0
<0>[ 337.404941] kworker/-3518 2..s. 316761092us : process_csb: 0000:00:02.0 rcs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.405015] kworker/-3518 2..s. 316761093us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c20:6, 0:0 }
<0>[ 337.405097] kworker/-3518 2.... 316761095us : i915_request_retire: 0000:00:02.0 bcs'0: fence 3c28:2, current 2
<0>[ 337.405172] kworker/-3518 2d.h2 316761121us : __intel_context_retire: 0000:00:02.0 rcs'0: context:3c27retire
<0>[ 337.405248] kworker/-3518 2..s1 316761135us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=0, tail=1
<0>[ 337.405321] kworker/-3518 2..s1 316761135us : process_csb: 0000:00:02.0 rcs'0: csb[1]: status=0x00000818:0x00000040
<0>[ 337.405396] kworker/-3518 2..s1 316761136us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c20:6!, 0:0 }
<0>[ 337.405470] kworker/-3518 2.... 316761138us : intel_context_unpin: 0000:00:02.0 bcs'0: context:3c28retire
<0>[ 337.405553] kworker/-3518 2d... 316761144us : __i915_request_commit: 0000:00:02.0 bcs'0: fence 3c22:4, current 2
<0>[ 337.405630] kworker/-3518 2d... 316761146us : __engine_park: 0000:00:02.0 bcs'0:
<0>[ 337.405708] kworker/-3518 2d..2 316761154us : __i915_request_submit: 0000:00:02.0 bcs'0: fence 3c22:4, current 2
<0>[ 337.405786] kworker/-3518 2d..2 316761162us : trace_ports: 0000:00:02.0 bcs'0: submit { 3c22:4, 0:0 }
<0>[ 337.405859] kworker/-3518 2d.H1 316761173us : __intel_context_retire: 0000:00:02.0 bcs'0: context:3c28retire
<0>[ 337.405934] kworker/-3518 2..s. 316761180us : process_csb: 0000:00:02.0 bcs'0: cs-irq head=3, tail=5
<0>[ 337.406006] kworker/-3518 2..s. 316761180us : process_csb: 0000:00:02.0 bcs'0: csb[4]: status=0x00000001:0x00000000
<0>[ 337.406081] kworker/-3518 2..s. 316761180us : trace_ports: 0000:00:02.0 bcs'0: promote { 3c22:4!, 0:0 }
<0>[ 337.406154] kworker/-3518 2..s. 316761180us : process_csb: 0000:00:02.0 bcs'0: csb[5]: status=0x00000818:0x00000040
<0>[ 337.406228] kworker/-3518 2..s. 316761181us : trace_ports: 0000:00:02.0 bcs'0: completed { 3c22:4!, 0:0 }
<0>[ 337.406311] kworker/-3518 2.... 316761183us : i915_request_retire: 0000:00:02.0 vcs'0: fence 3c29:2, current 2
<0>[ 337.406385] kworker/-3518 2.... 316761185us : intel_context_unpin: 0000:00:02.0 vcs'0: context:3c29retire
<0>[ 337.406468] kworker/-3518 2d... 316761191us : __i915_request_commit: 0000:00:02.0 vcs'0: fence 3c24:4, current 2
<0>[ 337.406544] kworker/-3518 2d... 316761192us : __engine_park: 0000:00:02.0 vcs'0:
<0>[ 337.406612] i915_mod-3200 4.... 316761194us : __engine_unpark: 0000:00:02.0 vecs'0:
<0>[ 337.406680] i915_mod-3200 4.... 316761195us : __intel_context_do_pin: 0000:00:02.0 vecs'0: context:3c2apin ring:{head:0000, tail:0000}
<0>[ 337.406769] kworker/-3518 2d..2 316761199us : __i915_request_submit: 0000:00:02.0 vcs'0: fence 3c24:4, current 2
<0>[ 337.406847] kworker/-3518 2d..2 316761207us : trace_ports: 0000:00:02.0 vcs'0: submit { 3c24:4, 0:0 }
<0>[ 337.406929] i915_mod-3200 4.... 316761215us : __i915_request_commit: 0000:00:02.0 vecs'0: fence 3c2a:2, current 0
<0>[ 337.407006] kworker/-3518 2d.H2 316761216us : __intel_context_retire: 0000:00:02.0 vcs'0: context:3c29retire
<0>[ 337.407089] i915_mod-3200 4d..1 316761219us : __i915_request_submit: 0000:00:02.0 vecs'0: fence 3c2a:2, current 0
<0>[ 337.407169] i915_mod-3200 4d..1 316761221us : trace_ports: 0000:00:02.0 vecs'0: submit { 3c2a:2, 0:0 }
<0>[ 337.407242] kworker/-3518 2..s1 316761221us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=3, tail=5
<0>[ 337.407314] kworker/-3518 2..s1 316761221us : process_csb: 0000:00:02.0 vcs'0: csb[4]: status=0x00000001:0x00000000
<0>[ 337.407389] kworker/-3518 2..s1 316761222us : trace_ports: 0000:00:02.0 vcs'0: promote { 3c24:4!, 0:0 }
<0>[ 337.407461] kworker/-3518 2..s1 316761222us : process_csb: 0000:00:02.0 vcs'0: csb[5]: status=0x00000818:0x00000040
<0>[ 337.407534] kworker/-3518 2..s1 316761222us : trace_ports: 0000:00:02.0 vcs'0: completed { 3c24:4!, 0:0 }
<0>[ 337.407606] kworker/-3518 2..s. 316761225us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=1, tail=2
<0>[ 337.407677] kworker/-3518 2..s. 316761226us : process_csb: 0000:00:02.0 vecs'0: csb[2]: status=0x00000001:0x00000000
<0>[ 337.407751] kworker/-3518 2..s. 316761226us : trace_ports: 0000:00:02.0 vecs'0: promote { 3c2a:2!, 0:0 }
<0>[ 337.407822] kworker/-3518 2..s. 316761230us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=2, tail=3
<0>[ 337.407893] kworker/-3518 2..s. 316761230us : process_csb: 0000:00:02.0 vecs'0: csb[3]: status=0x00000818:0x00000020
<0>[ 337.407967] kworker/-3518 2..s. 316761230us : trace_ports: 0000:00:02.0 vecs'0: completed { 3c2a:2!, 0:0 }
<0>[ 337.408049] kworker/-3518 2.... 316761233us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c20:6, current 6
<0>[ 337.408126] kworker/-3518 2.... 316761234us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.408204] kworker/-3518 2.... 316761246us : i915_request_retire: 0000:00:02.0 bcs'0: fence 3c22:4, current 4
<0>[ 337.408279] kworker/-3518 2.... 316761247us : __engine_park: 0000:00:02.0 bcs'0:
<0>[ 337.408356] kworker/-3518 2.... 316761270us : i915_request_retire: 0000:00:02.0 vcs'0: fence 3c24:4, current 4
<0>[ 337.408432] kworker/-3518 2.... 316761271us : __engine_park: 0000:00:02.0 vcs'0:
<0>[ 337.408508] kworker/-3518 2.... 316761295us : i915_request_retire: 0000:00:02.0 vecs'0: fence 3c2a:2, current 2
<0>[ 337.408584] kworker/-3518 2.... 316761296us : intel_context_unpin: 0000:00:02.0 vecs'0: context:3c2aretire
<0>[ 337.408666] kworker/-3518 2d... 316761302us : __i915_request_commit: 0000:00:02.0 vecs'0: fence 3c26:4, current 2
<0>[ 337.408743] kworker/-3518 2d... 316761303us : __engine_park: 0000:00:02.0 vecs'0:
<0>[ 337.408821] kworker/-3518 2d..2 316761311us : __i915_request_submit: 0000:00:02.0 vecs'0: fence 3c26:4, current 2
<0>[ 337.408899] kworker/-3518 2d..2 316761318us : trace_ports: 0000:00:02.0 vecs'0: submit { 3c26:4, 0:0 }
<0>[ 337.408973] kworker/-3518 2d.H3 316761343us : __intel_context_retire: 0000:00:02.0 vecs'0: context:3c2aretire
<0>[ 337.409048] kworker/-3518 2..s1 316761349us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=3, tail=5
<0>[ 337.409121] kworker/-3518 2..s1 316761349us : process_csb: 0000:00:02.0 vecs'0: csb[4]: status=0x00000001:0x00000000
<0>[ 337.409197] kworker/-3518 2..s1 316761349us : trace_ports: 0000:00:02.0 vecs'0: promote { 3c26:4!, 0:0 }
<0>[ 337.409268] kworker/-3518 2..s1 316761350us : process_csb: 0000:00:02.0 vecs'0: csb[5]: status=0x00000818:0x00000040
<0>[ 337.409343] kworker/-3518 2..s1 316761350us : trace_ports: 0000:00:02.0 vecs'0: completed { 3c26:4!, 0:0 }
<0>[ 337.409426] kworker/-3518 2.... 316761354us : i915_request_retire: 0000:00:02.0 vecs'0: fence 3c26:4, current 4
<0>[ 337.409502] kworker/-3518 2.... 316761355us : __engine_park: 0000:00:02.0 vecs'0:
<0>[ 337.409571] kworker/-3518 2.... 316761438us : __gt_park: 0000:00:02.0
<0>[ 337.409635] i915_mod-3200 4.... 316761541us : __engine_unpark: 0000:00:02.0 rcs'0:
<0>[ 337.409703] i915_mod-3200 4.... 316761561us : __gt_unpark: 0000:00:02.0
<0>[ 337.409779] i915_mod-3200 4.... 316761703us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c20:8, current 6
<0>[ 337.409862] i915_mod-3200 4d..1 316761712us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:8, current 6
<0>[ 337.409941] i915_mod-3200 4d..1 316761716us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c20:8, 0:0 }
<0>[ 337.410015] <idle>-0 2..s1 316761777us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=1, tail=2
<0>[ 337.410088] <idle>-0 2..s1 316761777us : process_csb: 0000:00:02.0 rcs'0: csb[2]: status=0x00000001:0x00000000
<0>[ 337.410163] <idle>-0 2..s1 316761778us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c20:8!, 0:0 }
<0>[ 337.410235] <idle>-0 2..s1 316761797us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=2, tail=3
<0>[ 337.410306] <idle>-0 2..s1 316761797us : process_csb: 0000:00:02.0 rcs'0: csb[3]: status=0x00000818:0x00000060
<0>[ 337.410380] <idle>-0 2..s1 316761797us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c20:8!, 0:0 }
<0>[ 337.410463] kworker/-3518 2.... 316761805us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c20:8, current 8
<0>[ 337.410546] kworker/-3518 2d... 316761814us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c20:10, current 8
<0>[ 337.410623] kworker/-3518 2d... 316761815us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.410700] kworker/-3518 2d..2 316761823us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:10, current 8
<0>[ 337.410778] i915_mod-3200 4.... 316761828us : __intel_gt_set_wedged.part.30: start
<0>[ 337.410849] kworker/-3518 2d..2 316761829us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c20:10, 0:0 }
<0>[ 337.410922] i915_mod-3200 4.... 316761832us : execlists_reset_prepare: 0000:00:02.0 rcs'0: depth<-0
<0>[ 337.410994] i915_mod-3200 4.... 316761836us : intel_engine_stop_cs: 0000:00:02.0 rcs'0:
<0>[ 337.411063] i915_mod-3200 4.... 316761864us : execlists_reset_prepare: 0000:00:02.0 bcs'0: depth<-0
<0>[ 337.411135] i915_mod-3200 4.... 316761864us : intel_engine_stop_cs: 0000:00:02.0 bcs'0:
<0>[ 337.411204] i915_mod-3200 4.... 316761865us : execlists_reset_prepare: 0000:00:02.0 vcs'0: depth<-0
<0>[ 337.411275] i915_mod-3200 4.... 316761866us : intel_engine_stop_cs: 0000:00:02.0 vcs'0:
<0>[ 337.411344] i915_mod-3200 4.... 316761867us : execlists_reset_prepare: 0000:00:02.0 vecs'0: depth<-0
<0>[ 337.411416] i915_mod-3200 4.... 316761867us : intel_engine_stop_cs: 0000:00:02.0 vecs'0:
<0>[ 337.411487] i915_mod-3200 4.... 316762093us : __intel_gt_reset: engine_mask=ff
<0>[ 337.411555] i915_mod-3200 4.... 316762206us : execlists_reset_cancel: 0000:00:02.0 rcs'0:
<0>[ 337.411625] i915_mod-3200 4d..1 316762206us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=3, tail=4
<0>[ 337.411696] i915_mod-3200 4d..1 316762207us : process_csb: 0000:00:02.0 rcs'0: csb[4]: status=0x00000001:0x00000000
<0>[ 337.411771] i915_mod-3200 4d..1 316762208us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c20:10, 0:0 }
<0>[ 337.411842] i915_mod-3200 4d..1 316762218us : __execlists_reset: 0000:00:02.0 rcs'0: replay {head:0220, tail:0298}
<0>[ 337.411927] i915_mod-3200 4d..1 316762220us : __i915_request_unsubmit: 0000:00:02.0 rcs'0: fence 3c20:10, current 8
<0>[ 337.412011] i915_mod-3200 4d..1 316762229us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c20:10, current 10
<0>[ 337.412094] kworker/-230 4.... 316762244us : i915_request_retire: 0000:00:02.0 rcs'0: fence 3c20:10, current 10
<0>[ 337.412171] kworker/-230 4.... 316762246us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.412240] kworker/-230 4.... 316762256us : __gt_park: 0000:00:02.0
<0>[ 337.412307] i915_mod-3200 4.... 316762271us : execlists_reset_cancel: 0000:00:02.0 bcs'0:
<0>[ 337.412377] i915_mod-3200 4d..1 316762271us : process_csb: 0000:00:02.0 bcs'0: cs-irq head=5, tail=5
<0>[ 337.412449] i915_mod-3200 4.... 316762273us : execlists_reset_cancel: 0000:00:02.0 vcs'0:
<0>[ 337.412518] i915_mod-3200 4d..1 316762273us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=5, tail=5
<0>[ 337.412588] i915_mod-3200 4.... 316762275us : execlists_reset_cancel: 0000:00:02.0 vecs'0:
<0>[ 337.412657] i915_mod-3200 4d..1 316762275us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=5, tail=5
<0>[ 337.412728] i915_mod-3200 4.... 316762277us : execlists_reset_finish: 0000:00:02.0 rcs'0: depth->0
<0>[ 337.412797] i915_mod-3200 4.N.. 316762325us : execlists_reset_finish: 0000:00:02.0 bcs'0: depth->0
<0>[ 337.412867] i915_mod-3200 4.N.. 316762332us : execlists_reset_finish: 0000:00:02.0 vcs'0: depth->0
<0>[ 337.412937] i915_mod-3200 4.N.. 316762337us : execlists_reset_finish: 0000:00:02.0 vecs'0: depth->0
<0>[ 337.413009] i915_mod-3200 4.... 316762341us : __intel_gt_set_wedged.part.30: end
<0>[ 337.413076] i915_mod-3200 4.... 316762346us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.413121] i915_mod-3200 4.... 316762353us : execlists_reset_prepare: 0000:00:02.0 rcs'0: depth<-0
<0>[ 337.413215] i915_mod-3200 4.... 316762353us : intel_engine_stop_cs: 0000:00:02.0 rcs'0:
<0>[ 337.413285] i915_mod-3200 4.... 316762354us : execlists_reset_prepare: 0000:00:02.0 bcs'0: depth<-0
<0>[ 337.413357] i915_mod-3200 4.... 316762354us : intel_engine_stop_cs: 0000:00:02.0 bcs'0:
<0>[ 337.413425] i915_mod-3200 4.... 316762355us : execlists_reset_prepare: 0000:00:02.0 vcs'0: depth<-0
<0>[ 337.413497] i915_mod-3200 4.... 316762355us : intel_engine_stop_cs: 0000:00:02.0 vcs'0:
<0>[ 337.413566] i915_mod-3200 4.... 316762357us : execlists_reset_prepare: 0000:00:02.0 vecs'0: depth<-0
<0>[ 337.413637] i915_mod-3200 4.... 316762357us : intel_engine_stop_cs: 0000:00:02.0 vecs'0:
<0>[ 337.413708] i915_mod-3200 4.... 316762358us : __intel_gt_reset: engine_mask=ff
<0>[ 337.413776] i915_mod-3200 4.... 316762368us : execlists_reset_rewind: 0000:00:02.0 rcs'0:
<0>[ 337.413845] i915_mod-3200 4d..1 316762368us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=5, tail=5
<0>[ 337.413916] i915_mod-3200 4.... 316762374us : execlists_reset_rewind: 0000:00:02.0 bcs'0:
<0>[ 337.413985] i915_mod-3200 4d..1 316762374us : process_csb: 0000:00:02.0 bcs'0: cs-irq head=5, tail=5
<0>[ 337.414056] i915_mod-3200 4.... 316762376us : execlists_reset_rewind: 0000:00:02.0 vcs'0:
<0>[ 337.414125] i915_mod-3200 4d..1 316762376us : process_csb: 0000:00:02.0 vcs'0: cs-irq head=5, tail=5
<0>[ 337.414196] i915_mod-3200 4.... 316762378us : execlists_reset_rewind: 0000:00:02.0 vecs'0:
<0>[ 337.414265] i915_mod-3200 4d..1 316762378us : process_csb: 0000:00:02.0 vecs'0: cs-irq head=5, tail=5
<0>[ 337.414335] i915_mod-3200 4.N.. 316762381us : execlists_reset_finish: 0000:00:02.0 rcs'0: depth->0
<0>[ 337.414405] i915_mod-3200 4.N.. 316762386us : execlists_reset_finish: 0000:00:02.0 bcs'0: depth->0
<0>[ 337.414475] i915_mod-3200 4.N.. 316762389us : execlists_reset_finish: 0000:00:02.0 vcs'0: depth->0
<0>[ 337.414544] i915_mod-3200 4.N.. 316762393us : execlists_reset_finish: 0000:00:02.0 vecs'0: depth->0
<0>[ 337.414614] i915_mod-3200 4.... 316762396us : intel_gt_suspend_late: 0000:00:02.0
<0>[ 337.414683] i915_mod-3200 4.... 316762428us : intel_context_unpin: 0000:00:02.0 rcs'0: context:3c20retire
<0>[ 337.414754] i915_mod-3200 4.... 316762451us : __intel_context_retire: 0000:00:02.0 rcs'0: context:3c20retire
<0>[ 337.414826] i915_mod-3200 4.... 316762527us : intel_context_unpin: 0000:00:02.0 bcs'0: context:3c22retire
<0>[ 337.414897] i915_mod-3200 4.... 316762528us : __intel_context_retire: 0000:00:02.0 bcs'0: context:3c22retire
<0>[ 337.414968] i915_mod-3200 4.... 316762539us : intel_context_unpin: 0000:00:02.0 vcs'0: context:3c24retire
<0>[ 337.415037] i915_mod-3200 4.... 316762540us : __intel_context_retire: 0000:00:02.0 vcs'0: context:3c24retire
<0>[ 337.415108] i915_mod-3200 4.... 316762551us : intel_context_unpin: 0000:00:02.0 vecs'0: context:3c26retire
<0>[ 337.415180] i915_mod-3200 4.... 316762552us : __intel_context_retire: 0000:00:02.0 vecs'0: context:3c26retire
<0>[ 337.415260] i915_mod-3200 2.... 317055357us : i915_gem_suspend: 0000:00:02.0
<0>[ 337.415329] i915_mod-3200 3.... 317085011us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.415377] i915_mod-3200 3.... 317085023us : __intel_gt_reset: engine_mask=ff
<0>[ 337.415467] i915_mod-3200 3.... 317085036us : intel_gt_suspend_late: 0000:00:02.0
<0>[ 337.415536] i915_mod-3200 3.... 317085042us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.415583] i915_mod-3200 3.... 317085048us : __intel_gt_reset: engine_mask=ff
<0>[ 337.415673] i915_mod-3200 3.... 317085058us : intel_gt_suspend_late: 0000:00:02.0
<0>[ 337.415740] i915_mod-3200 4.... 317387792us : intel_gt_sanitize: 0000:00:02.0 force:no
<0>[ 337.415787] i915_mod-3200 4.... 317387821us : __intel_gt_reset: engine_mask=ff
<0>[ 337.415877] i915_mod-3200 8.... 317409219us : __intel_context_do_pin: 0000:00:02.0 rcs'0: context:3c2fpin ring:{head:0000, tail:0000}
<0>[ 337.415955] i915_mod-3200 8.... 317409427us : __intel_context_do_pin: 0000:00:02.0 bcs'0: context:3c31pin ring:{head:0000, tail:0000}
<0>[ 337.416032] i915_mod-3200 8.... 317409654us : __intel_context_do_pin: 0000:00:02.0 vcs'0: context:3c33pin ring:{head:0000, tail:0000}
<0>[ 337.416110] i915_mod-3200 8.... 317409803us : __intel_context_do_pin: 0000:00:02.0 vecs'0: context:3c35pin ring:{head:0000, tail:0000}
<0>[ 337.416188] i915_mod-3200 8.... 317410734us : intel_gt_resume: 0000:00:02.0
<0>[ 337.416255] i915_mod-3200 8.... 317410758us : __gt_unpark: 0000:00:02.0
<0>[ 337.416319] i915_mod-3200 8.... 317415448us : __engine_unpark: 0000:00:02.0 rcs'0:
<0>[ 337.416396] i915_mod-3200 8d... 317415668us : __i915_request_commit: 0000:00:02.0 rcs'0: fence 3c2f:2, current 0
<0>[ 337.416471] i915_mod-3200 8d... 317415687us : __engine_park: 0000:00:02.0 rcs'0:
<0>[ 337.416547] i915_mod-3200 8d..2 317415743us : __i915_request_submit: 0000:00:02.0 rcs'0: fence 3c2f:2, current 0
<0>[ 337.416625] i915_mod-3200 8d..2 317415780us : trace_ports: 0000:00:02.0 rcs'0: submit { 3c2f:2, 0:0 }
<0>[ 337.416698] <idle>-0 2..s1 317415807us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=5, tail=0
<0>[ 337.416770] <idle>-0 2..s1 317415808us : process_csb: 0000:00:02.0 rcs'0: csb[0]: status=0x00000001:0x00000000
<0>[ 337.416845] <idle>-0 2..s1 317415809us : trace_ports: 0000:00:02.0 rcs'0: promote { 3c2f:2, 0:0 }
<0>[ 337.416917] <idle>-0 2..s1 317415830us : process_csb: 0000:00:02.0 rcs'0: cs-irq head=0, tail=1
<0>[ 337.416988] <idle>-0 2..s1 317415830us : process_csb: 0000:00:02.0 rcs'0: csb[1]: status=0x00000018:0x00000000
<0>[ 337.417062] <idle>-0 2..s1 317415831us : trace_ports: 0000:00:02.0 rcs'0: completed { 3c2f:2, 0:0 }
<0>[ 337.417135] i915_mod-3200 8.... 317415847us : __engine_unpark: 0000:00:02.0 bcs'0:
<0>[ 337.417203] <idle>-0 2..s1 317415869us : process_csb: process_csb:2211 GEM_BUG_ON(!i915_request_completed(*execlists->active) && !reset_in_progress(execlists))Edited by Chris Wilson