https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3385/shard-apl3/igt@gem_exec_reloc@basic-wc-gtt-active.html dmesg: <5>[ 703.500041] owatch: Using watchdog device /dev/watchdog0 <5>[ 703.500147] owatch: Watchdog /dev/watchdog0 is a software watchdog <5>[ 703.501677] owatch: timeout for /dev/watchdog0 set to 370 (requested 370) ... <4>[ 953.947982] hpet1: lost 7161 rtc interrupts <4>[ 954.837466] hpet1: lost 7161 rtc interrupts <4>[ 955.728351] hpet1: lost 7160 rtc interrupts run.log: running: igt/gem_exec_reloc/basic-wc-gtt-active [48/75] skip: 16, pass: 31, fail: 1 | FATAL: command execution failed java.io.EOFException ... Finished: FAILURE Completed CI_IGT_test CI_DRM_3385/shard-apl3/20 : FAILURE CI_IGT_test runtime 328 seconds Rebooting shard-apl3
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3388/shard-apl2/igt@drv_selftest@mock_breadcrumbs.html dmesg: <5>[ 1702.026113] owatch: Using watchdog device /dev/watchdog0 <5>[ 1702.029167] owatch: Watchdog /dev/watchdog0 is a software watchdog <5>[ 1702.067375] owatch: timeout for /dev/watchdog0 set to 370 (requested 370) ... <4>[ 1830.939223] hpet1: lost 7160 rtc interrupts <4>[ 1831.824734] hpet1: lost 7161 rtc interrupts <4>[ 1832.710064] hpet1: lost 7161 rtc interrupts run.log: running: igt/drv_selftest/mock_breadcrumbs [05/43] pass: 4, dmesg-warn: 1 / FATAL: command execution failed java.io.EOFException ... Finished: FAILURE Completed CI_IGT_test CI_DRM_3388/shard-apl2/35 : FAILURE CI_IGT_test runtime 190 seconds Rebooting shard-apl2
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3416/shard-apl6/igt@gem_tiled_swapping@non-threaded.html dmesg: <5>[ 1048.871613] owatch: Using watchdog device /dev/watchdog0 <5>[ 1048.871720] owatch: Watchdog /dev/watchdog0 is a software watchdog <5>[ 1048.873275] owatch: timeout for /dev/watchdog0 set to 370 (requested 370) ... <7>[ 1203.843465] [drm:drm_dp_read_desc] DP branch: OUI 00-00-00 dev-ID HW-rev 0.0 SW-rev 0.0 quirks 0x0000 <7>[ 1203.843520] [drm:intel_dp_detect [i915]] Sink is not MST capable <7>[ 1203.848943] [drm:drm_helper_hpd_irq_event] [CONNECTOR:72:DP-2] status updated from connected to connected <7>[ 1203.991750] [IGT] gem_tiled_swapping: executing no indication of timeout or softdog in run.log, i.e. looks like system hang.
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3434/shard-apl5/igt@kms_flip@2x-flip-vs-rmfb-interruptible.html dmesg: <5>[ 1128.849581] owatch: Using watchdog device /dev/watchdog0 <5>[ 1128.849994] owatch: Watchdog /dev/watchdog0 is a software watchdog <5>[ 1128.851845] owatch: timeout for /dev/watchdog0 set to 370 (requested 370) <4>[ 1129.140345] hpet1: lost 7161 rtc interrupts ... <4>[ 1465.370844] hpet1: lost 7161 rtc interrupts <4>[ 1466.262777] hpet1: lost 7161 rtc interrupts <4>[ 1467.154938] hpet1: lost 7161 rtc interrupts Folloed by "stray" run.log: running: igt/kms_flip/2x-flip-vs-rmfb-interruptible [20/75] skip: 9, pass: 11 | FATAL: command execution failed ... Finished: FAILURE Completed CI_IGT_test CI_DRM_3434/shard-apl5/28 : FAILURE CI_IGT_test runtime 388 seconds Rebooting shard-apl5
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3528/shard-apl5/igt@gem_eio@suspend.html
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3574/shard-apl1/igt@gem_cs_tlb@render.html run.log: running: igt/gem_exec_flush/basic-uc-set-default [46/76] skip: 22, pass: 24 - FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3574/shard-apl1/26 : FAILURE CI_IGT_test runtime 547 seconds Rebooting shard-apl1 dmesg: <4>[ 330.029664] Setting dangerous option reset - tainting kernel <7>[ 330.032933] [IGT] gem_exec_flush: starting subtest basic-uc-set-default <7>[ 335.431877] [IGT] gem_exec_flush: exiting, ret=0 <7>[ 335.627075] [IGT] gem_cs_tlb: executing <7>[ 335.644193] [IGT] gem_cs_tlb: starting subtest render
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3624/shard-apl6/igt@drv_selftest@live_hugepages.html run.log: running: igt/drv_selftest/live_gtt [20/43] pass: 19, dmesg-warn: 1 | FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3624/shard-apl6/35 : FAILURE CI_IGT_test runtime 461 seconds Rebooting shard-apl6 there is pstore: <0>[ 431.286708] drv_self-5805 1..s1 253153398us : execlists_submission_tasklet: vecs0 in[0]: ctx=2.1, seqno=1 ... <0>[ 431.414112] <idle>-0 0.Ns1 361042309us : execlists_submission_tasklet: vcs0 out[0]: ctx=3.1, seqno=1358 <0>[ 431.414242] --------------------------------- <0>[ 431.414306] Kernel Offset: disabled dmesg: <7>[ 257.267285] [IGT] drv_selftest: starting subtest live_gtt ... <7>[ 341.784308] [IGT] drv_selftest: starting subtest live_hugepages ... <6>[ 341.982461] failed to allocate THP, finishing test early <5>[ 342.986261] igt_write_huge timed out on engine=1, offset_low=22bd0000 offset_high=ffffdd230000, max_page_size=10000
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4148/shard-apl8/igt@perf_pmu@busy-double-start-vecs0.html there is pstore, but it is hard to interpret since it is dominated by ftrace.
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4172/shard-apl5/igt@kms_cursor_crc@cursor-256x256-suspend.html <1>[ 5.150957] BUG: unable to handle kernel NULL pointer dereference at (null) <1>[ 5.150971] IP: hda_widget_sysfs_reinit+0x13c/0x200 [snd_hda_core] <6>[ 5.150973] PGD 0 P4D 0 <4>[ 5.150977] Oops: 0000 [#1] PREEMPT SMP PTI <4>[ 5.150979] Modules linked in: snd_hda_codec_hdmi(+) snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul snd_hda_intel ghash_clmulni_intel snd_hda_codec snd_hwdep snd_hda_core r8169 lpc_ich mii snd_pcm mei_me mei prime_numbers pinctrl_broxton pinctrl_intel <4>[ 5.151001] CPU: 3 PID: 253 Comm: systemd-udevd Not tainted 4.15.0-rc9-CI-CI_DRM_3673+ #1 <4>[ 5.151002] Hardware name: /NUC6CAYB, BIOS AYAPLCEL.86A.0040.2017.0619.1722 06/19/2017 <4>[ 5.151008] RIP: 0010:hda_widget_sysfs_reinit+0x13c/0x200 [snd_hda_core] <4>[ 5.151009] RSP: 0018:ffffc900003e3b80 EFLAGS: 00010246 <4>[ 5.151011] RAX: 0000000000000000 RBX: 0000000000000003 RCX: ffff88025ff69b58 <4>[ 5.151012] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff82246460 <4>[ 5.151014] RBP: ffff880265b84548 R08: 0000000000000001 R09: ffff88026e3fa198 <4>[ 5.151015] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000 <4>[ 5.151016] R13: 0000000000000038 R14: ffffffffa00a67c0 R15: ffff88026a193e38 <4>[ 5.151017] FS: 00007fbaf82658c0(0000) GS:ffff88027fd80000(0000) knlGS:0000000000000000 <4>[ 5.151018] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 5.151020] CR2: 0000000000000000 CR3: 000000027326c000 CR4: 00000000003406e0 <4>[ 5.151021] Call Trace: <4>[ 5.151030] snd_hdac_refresh_widgets+0x65/0x90 [snd_hda_core] <4>[ 5.151040] snd_hda_codec_update_widgets+0xe/0x50 [snd_hda_codec] <4>[ 5.151047] intel_hsw_common_init.part.20+0x2b/0x90 [snd_hda_codec_hdmi] <4>[ 5.151053] hda_codec_driver_probe+0x5e/0x100 [snd_hda_codec] <4>[ 5.151059] driver_probe_device+0x2a3/0x480 <4>[ 5.151063] __driver_attach+0xd9/0xe0 <4>[ 5.151066] ? driver_probe_device+0x480/0x480 <4>[ 5.151067] bus_for_each_dev+0x57/0x90 <4>[ 5.151070] bus_add_driver+0x168/0x260 <4>[ 5.151074] driver_register+0x52/0xc0 <4>[ 5.151075] ? 0xffffffffa03a1000 <4>[ 5.151078] do_one_initcall+0x39/0x150 <4>[ 5.151082] ? rcu_read_lock_sched_held+0x6f/0x80 <4>[ 5.151085] ? kmem_cache_alloc_trace+0x248/0x2b0 <4>[ 5.151088] do_init_module+0x56/0x1ef <4>[ 5.151091] load_module+0x231c/0x2d70 <4>[ 5.151096] ? show_coresize+0x20/0x20 <4>[ 5.151098] ? vfs_read+0x126/0x150 <4>[ 5.151106] ? SyS_finit_module+0xa5/0xe0 <4>[ 5.151108] SyS_finit_module+0xa5/0xe0 <4>[ 5.151115] do_syscall_64+0x59/0x1a0 <4>[ 5.151119] entry_SYSCALL64_slow_path+0x25/0x25 <4>[ 5.151121] RIP: 0033:0x7fbaf70ee9f9 <4>[ 5.151122] RSP: 002b:00007ffefb0c8e58 EFLAGS: 00000202 ORIG_RAX: 0000000000000139 <4>[ 5.151124] RAX: ffffffffffffffda RBX: 00005591f5ae89f0 RCX: 00007fbaf70ee9f9 <4>[ 5.151125] RDX: 0000000000000000 RSI: 00007fbaf7a11e23 RDI: 0000000000000007 <4>[ 5.151126] RBP: 00007fbaf7a11e23 R08: 0000000000000000 R09: 0000000000000000 <4>[ 5.151127] R10: 0000000000000007 R11: 0000000000000202 R12: 0000000000000000 <4>[ 5.151128] R13: 00005591f5aac150 R14: 0000000000020000 R15: 00005591f4a6fe30 <4>[ 5.151135] Code: e4 49 c7 c6 c0 67 0a a0 83 e8 01 4c 8d 2c c5 08 00 00 00 eb 2b 48 8b 8d a8 04 00 00 0f b7 d3 83 c3 01 29 c2 48 63 c2 48 8b 51 10 <48> 8b 14 c2 49 8b 47 10 4a 89 14 20 49 83 c4 08 4d 39 e5 74 36 <1>[ 5.151183] RIP: hda_widget_sysfs_reinit+0x13c/0x200 [snd_hda_core] RSP: ffffc900003e3b80 <4>[ 5.151184] CR2: 0000000000000000 <4>[ 5.151187] ---[ end trace 8765903cf6e4535d ]---
This is a Meta bug to capture all unexplained incompletes on APL-shards
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3706/shard-apl3/igt@perf_pmu@most-busy-check-all-vecs0.html pstore only has ftrace info. Note CI_DRM_3704 - CI_DRM_3706 looks strange, lots of not run tests.
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3718/shard-apl4/igt@perf_pmu@busy-double-start-vcs0.html This has pstore which unfortunately only has ftrace information.
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3789/fi-bxt-dsi/igt@kms_pipe_crc_basic@suspend-read-crc-pipe-c.html run.log not matching results
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3964/fi-bxt-dsi/igt@kms_pipe_crc_basic@suspend-read-crc-pipe-a.html running: igt/kms_pipe_crc_basic/suspend-read-crc-pipe-a [240/285] skip: 26, pass: 214 | FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3964/fi-bxt-dsi/0 : FAILURE CI_IGT_test runtime 562 seconds Rebooting fi-bxt-dsi Last dmesg: <7>[ 450.080918] [IGT] kms_pipe_crc_basic: starting subtest suspend-read-crc-pipe-A <7>[ 450.081382] [drm:drm_mode_addfb2] [FB:107] <7>[ 450.109061] [drm:drm_mode_setcrtc] [CRTC:46:pipe A] <7>[ 450.109110] [drm:drm_mode_setcrtc] [CONNECTOR:98:DSI-1] <7>[ 450.127575] [drm:drm_mode_setcrtc] [CRTC:65:pipe B] <7>[ 450.129837] [drm:drm_mode_setcrtc] [CRTC:79:pipe C] <7>[ 450.226438] [drm:drm_mode_addfb2] [FB:106] <7>[ 450.244482] [drm:drm_mode_setcrtc] [CRTC:46:pipe A] <7>[ 450.244553] [drm:drm_mode_setcrtc] [CONNECTOR:98:DSI-1]
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3974/fi-bxt-dsi/igt@kms_flip@basic-flip-vs-dpms.html run.log: running: igt/kms_flip/basic-flip-vs-dpms [215/285] skip: 22, pass: 193 \ FATAL: command execution failed ... Completed CI_IGT_test CI_DRM_3974/fi-bxt-dsi/0 : FAILURE CI_IGT_test runtime 461 seconds Rebooting fi-bxt-dsi Last dmesg: <7>[ 354.175870] [IGT] kms_flip: executing ... <7>[ 354.214763] [drm:drm_dp_i2c_do_msg] native defer <7>[ 354.215624] [drm:lspcon_wait_mode [i915]] Current LSPCON mode P
So far, I couldn't reproduce any of the issues reported here, using my BXT. I took all the tests mentioned and run them around 100 times. So those are either some specific hardware/configuration issues or they are fixed.
There seems to be some problem with drv_selftests: it occassionally runs out of memory(memory leak?), which causes then all subsequent tests to fail: <3>[ 170.754357] Out of memory: Kill process 5670 (drv_selftest) score 999 or sacrifice child <7>[ 170.754702] [drm:vma_print_allocator.constprop.12 [i915]] vma.node [ffffe000 + 00001000] is pinned: inserted at i915_gem_gtt_insert+0x135/0x510 [i915] __i915_vma_do_pin+0x462/0xd90 [i915] logical_render_ring_init+0x33e/0x470 [i915] intel_engines_init+0x4f/0x120 [i915] i915_gem_init+0x20b/0x6a0 [i915] i915_driver_load+0xc3a/0x1070 [i915] i915_pci_probe+0x29/0x90 [i915] pci_device_probe+0xa1/0x130 driver_probe_device+0x306/0x480 __driver_attach+0xdb/0x100 bus_for_each_dev+0x74/0xc0 bus_add_driver+0x15f/0x250 driver_register+0x56/0xe0 do_one_initcall+0x58/0x370 do_init_module+0x56/0x1ea load_module+0x24 <3>[ 170.763513] Out of memory: Kill process 782 (java) score 12 or sacrifice child <7>[ 170.763902] [drm:vma_print_allocator.constprop.12 [i915]] vma.node [ffffe000 + 00001000] is pinned: inserted at i915_gem_gtt_insert+0x135/0x510 [i915] __i915_vma_do_pin+0x462/0xd90 [i915] logical_render_ring_init+0x33e/0x470 [i915] intel_engines_init+0x4f/0x120 [i915] i915_gem_init+0x20b/0x6a0 [i915] i915_driver_load+0xc3a/0x1070 [i915] i915_pci_probe+0x29/0x90 [i915] pci_device_probe+0xa1/0x130 driver_probe_device+0x306/0x480 __driver_attach+0xdb/0x100 bus_for_each_dev+0x74/0xc0 bus_add_driver+0x15f/0x250 driver_register+0x56/0xe0 do_one_initcall+0x58/0x370 do_init_module+0x56/0x1ea load_module+0x24 And so on. I guess this could be one of the reasons for getting lots of incomplete tests.
> There seems to be some problem with drv_selftests: it occassionally runs out > of memory(memory leak?), which causes then all subsequent tests to fail Was this ever followed-up? It sounds like it could be major.
This seems to be kind of generic bug, summarizing all test case incompletes, not just some specific failure, so I guess we will always have something here. According to http://gfx-ci.fi.intel.com/cibuglog-ng/issue/138/history all the recent issues happen to ApolloLake. To me it seems that it either runs out of memory or there is a memory leak in self_tests. I will check it, since didn't have time to do that yet unfortunately.
Setting to medium since it's a meta-bug of sorts.
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5198/fi-bxt-j4205/igt@runner@aborted.html Out Aborting. Previous test: i915_module_load (reload-with-fault-injection) Next test: pm_rpm (module-reload) Kernel tainted (0x2c0 -- 280) https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_5198/fi-bxt-j4205/igt%40i915_module_load%40reload-with-fault-injection.html <4> [353.865920] CPU: 2 PID: 3280 Comm: i915_module_loa Tainted: G U 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4> [353.866244] i915_driver_load+0x845/0x1550 [i915] <4> [353.866356] i915_pci_probe+0x29/0xa0 [i915] <0> [353.866953] CPU:0 [LOST 5585480 EVENTS]\x0ai915_mod-3280 0.... 351609810us : i915_request_add: marking (null) as active <0> [353.867071] i915_mod-3280 0d..1 351609885us : process_csb: rcs0 cs-irq head=1, tail=1 <0> [353.867169] i915_mod-3280 0d..1 351609887us : __i915_request_submit: rcs0 fence 1646:1 -> global=2, current 1 <0> [353.867269] i915_mod-3280 0d..1 351609927us : __execlists_submission_tasklet: rcs0 in[0]: ctx=0.1, global=2 (fence 1646:1) (current 1), prio=-4094 <0> [353.867367] i915_mod-3280 0.... 351609982us : i915_gem_switch_to_kernel_context: emit barrier on bcs0 <0> [353.867462] i915_mod-3280 0.... 351609996us : i915_request_add: bcs0 fence 1649:1 <0> [353.867553] i915_mod-3280 0.... 351609998us : i915_request_add: marking (null) as active <0> [353.867649] i915_mod-3280 0d..1 351610048us : process_csb: bcs0 cs-irq head=1, tail=1 <0> [353.867747] i915_mod-3280 0d..1 351610083us : __i915_request_submit: bcs0 fence 1649:1 -> global=2, current 1 <0> [353.867845] i915_mod-3280 0d..1 351610095us : __execlists_submission_tasklet: bcs0 in[0]: ctx=0.1, global=2 (fence 1649:1) (current 1), prio=-4094 <0> [353.867943] i915_mod-3280 0.... 351610100us : i915_gem_switch_to_kernel_context: emit barrier on vcs0 <0> [353.868039] i915_mod-3280 0.... 351610112us : i915_request_add: vcs0 fence 164c:1 <0> [353.868134] i915_mod-3280 0.... 351610114us : i915_request_add: marking (null) as active <0> [353.868233] i915_mod-3280 0d..1 351610126us : process_csb: vcs0 cs-irq head=1, tail=1 <0> [353.868328] i915_mod-3280 0d..1 351610127us : __i915_request_submit: vcs0 fence 164c:1 -> global=2, current 1 <0> [353.868425] i915_mod-3280 0d..1 351610139us : __execlists_submission_tasklet: vcs0 in[0]: ctx=0.1, global=2 (fence 164c:1) (current 1), prio=-4094 <0> [353.868528] i915_mod-3280 0.... 351610144us : last_request_on_engine: last request for (null) on engine vecs0: 1654:1 <0> [353.868623] i915_mod-3280 0.... 351610146us : engine_has_kernel_context_barrier: (null) needs barrier for 1654:1 <0> [353.868715] i915_mod-3280 0.... 351610146us : i915_gem_switch_to_kernel_context: emit barrier on vecs0 <0> [353.868807] i915_mod-3280 0.... 351610158us : last_request_on_engine: last request for (null) on engine vecs0: 1654:1 <0> [353.868903] i915_mod-3280 0.... 351610159us : i915_gem_switch_to_kernel_context: add barrier on vecs0 for 1654:1 <0> [353.868999] i915_mod-3280 0.... 351610170us : i915_request_add: vecs0 fence 164f:1 <0> [353.869092] i915_mod-3280 0.... 351610172us : i915_request_add: marking (null) as active <0> [353.869188] i915_mod-3280 0d..1 351610185us : process_csb: vecs0 cs-irq head=1, tail=1 <0> [353.869283] i915_mod-3280 0d..1 351610186us : __i915_request_submit: vecs0 fence 164f:1 -> global=2, current 1 <0> [353.869393] i915_mod-3280 0d..1 351610198us : __execlists_submission_tasklet: vecs0 in[0]: ctx=0.1, global=2 (fence 164f:1) (current 1), prio=-4094 <0> [353.869498] i915_mod-3280 0.... 351610203us : i915_gem_wait_for_idle: flags=2 (locked), timeout=200 <0> [353.869595] i915_mod-3280 0.... 351610244us : i915_request_retire: vecs0 fence 164f:1, global=2, current 2 <0> [353.869690] i915_mod-3280 0.... 351610245us : i915_request_retire: marking (null) as inactive <0> [353.869784] i915_mod-3280 0.... 351610246us : i915_request_retire: __retire_engine_request(vecs0) fence 1654:1, global=1, current 2 <0> [353.869882] i915_mod-3280 0.... 351610249us : i915_request_retire: __retire_engine_request(vecs0) fence 164f:1, global=2, current 2 <0> [353.869981] i915_mod-3280 0.... 351610262us : i915_request_retire: vcs0 fence 164c:1, global=2, current 2 <0> [353.870075] i915_mod-3280 0.... 351610263us : i915_request_retire: marking (null) as inactive <0> [353.870170] i915_mod-3280 0.... 351610264us : i915_request_retire: __retire_engine_request(vcs0) fence 164c:1, global=2, current 2 <0> [353.870267] i915_mod-3280 0.... 351610279us : i915_request_retire: bcs0 fence 1649:1, global=2, current 2 <0> [353.870361] i915_mod-3280 0.... 351610280us : i915_request_retire: marking (null) as inactive <0> [353.870455] i915_mod-3280 0.... 351610281us : i915_request_retire: __retire_engine_request(bcs0) fence 1649:1, global=2, current 2 <0> [353.870554] i915_mod-3280 0.... 351610295us : i915_request_retire: rcs0 fence 1646:1, global=2, current 2 <0> [353.870649] i915_mod-3280 0.... 351610295us : i915_request_retire: marking (null) as inactive <0> [353.870742] i915_mod-3280 0.... 351610296us : i915_request_retire: __retire_engine_request(rcs0) fence 1646:1, global=2, current 2 <0> [353.870841] i915_mod-3280 0.... 351610310us : i915_request_retire: vecs0 fence 1654:1, global=1, current 2 <0> [353.870934] i915_mod-3280 0.... 351610310us : i915_request_retire: marking (null) as inactive <0> [353.871026] i915_mod-3280 0.... 351610314us : i915_gem_park: <0> [353.871115] i915_mod-3280 0.... 351610329us : __i915_gem_park: <0> [353.871203] i915_mod-3280 0.... 351610694us : i915_gem_suspend: <0> [353.871288] i915_mod-3280 0.... 351610697us : i915_gem_switch_to_kernel_context: awake?=no <0> [353.871381] i915_mod-3280 0.... 351610699us : i915_gem_wait_for_idle: flags=13 (locked), timeout=9223372036854775807 (forever) <0> [353.871478] i915_mod-3280 0.... 351612054us : i915_gem_sanitize: <0> [353.871568] i915_mod-3280 0.... 351612063us : intel_engine_stop_cs: rcs0 <0> [353.871659] i915_mod-3280 0.... 351612080us : intel_engine_stop_cs: bcs0 <0> [353.871751] i915_mod-3280 0.... 351612096us : intel_engine_stop_cs: vcs0 <0> [353.871842] i915_mod-3280 0.... 351612114us : intel_engine_stop_cs: vecs0 <0> [353.871936] i915_mod-3280 0.... 351612165us : intel_gpu_reset: engine_mask=ffffffff, ret=0, retry=0 <0> [353.872031] i915_mod-3280 0.... 351612166us : intel_engines_sanitize: <0> [353.872128] i915_mod-3280 0.... 351612167us : execlists_reset: rcs0 request global=0, current=2 <0> [353.872224] i915_mod-3280 0.... 351612170us : execlists_reset: bcs0 request global=0, current=2 <0> [353.872322] i915_mod-3280 0.... 351612171us : execlists_reset: vcs0 request global=0, current=2 <0> [353.872422] i915_mod-3280 0.... 351612172us : execlists_reset: vecs0 request global=0, current=2 <0> [353.872448] i915_mod-3280 0.... 351920276us : 0xffffffffa013b910: <0> [353.872467] i915_mod-3280 0.... 351920340us : 0xffffffffa0160cdb: rcs0 <0> [353.872487] i915_mod-3280 0.... 351920358us : 0xffffffffa0160cdb: bcs0 <0> [353.872506] i915_mod-3280 0.... 351920373us : 0xffffffffa0160cdb: vcs0 <0> [353.872526] i915_mod-3280 0.... 351920391us : 0xffffffffa0160cdb: vecs0 <0> [353.872546] i915_mod-3280 0.... 351920441us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.872570] i915_mod-3280 0.... 351920442us : 0xffffffffa0161650: <0> [353.872591] CPU:1 [LOST 921083 EVENTS]\x0ai915_mod-3280 1.... 351987471us : 0xffffffffa014b770: rcs0 fence 1665:1 <0> [353.872619] i915_mod-3280 1.... 351987576us : 0xffffffffa014bd19: marking (null) as active <0> [353.872642] i915_mod-3280 1d..1 351987679us : 0xffffffffa016cc00: rcs0 cs-irq head=5, tail=5 <0> [353.872666] i915_mod-3280 1d..1 351987680us : 0xffffffffa014a980: rcs0 fence 1665:1 -> global=1, current 0 <0> [353.872691] i915_mod-3280 1d..1 351987834us : 0xffffffffa016dc57: rcs0 in[0]: ctx=2.1, global=1 (fence 1665:1) (current 0), prio=2 <0> [353.872719] i915_mod-3280 1.... 351988383us : 0xffffffffa014b770: bcs0 fence 1666:1 <0> [353.872741] i915_mod-3280 1.... 351988386us : 0xffffffffa014bd19: marking (null) as active <0> [353.872768] i915_mod-3280 1d..1 351988392us : 0xffffffffa016cc00: bcs0 cs-irq head=5, tail=5 <0> [353.872792] i915_mod-3280 1d..1 351988394us : 0xffffffffa014a980: bcs0 fence 1666:1 -> global=1, current 0 <0> [353.872817] i915_mod-3280 1d..1 351988400us : 0xffffffffa016dc57: bcs0 in[0]: ctx=2.1, global=1 (fence 1666:1) (current 0), prio=2 <0> [353.872845] i915_mod-3280 1.... 351988666us : 0xffffffffa014b770: vcs0 fence 1667:1 <0> [353.872867] i915_mod-3280 1.... 351988669us : 0xffffffffa014bd19: marking (null) as active <0> [353.872889] i915_mod-3280 1d..1 351988674us : 0xffffffffa016cc00: vcs0 cs-irq head=5, tail=5 <0> [353.872913] i915_mod-3280 1d..1 351988675us : 0xffffffffa014a980: vcs0 fence 1667:1 -> global=1, current 0 <0> [353.872938] i915_mod-3280 1d..1 351988679us : 0xffffffffa016dc57: vcs0 in[0]: ctx=2.1, global=1 (fence 1667:1) (current 0), prio=2 <0> [353.872966] i915_mod-3280 1.... 351988979us : 0xffffffffa014b770: vecs0 fence 1668:1 <0> [353.872988] i915_mod-3280 1.... 351988982us : 0xffffffffa014bd19: marking (null) as active <0> [353.873010] i915_mod-3280 1d..1 351988987us : 0xffffffffa016cc00: vecs0 cs-irq head=5, tail=5 <0> [353.873034] i915_mod-3280 1d..1 351988988us : 0xffffffffa014a980: vecs0 fence 1668:1 -> global=1, current 0 <0> [353.873060] i915_mod-3280 1d..1 351988992us : 0xffffffffa016dc57: vecs0 in[0]: ctx=2.1, global=1 (fence 1668:1) (current 0), prio=2 <0> [353.873087] i915_mod-3280 1.... 351988997us : 0xffffffffa01125f0: awake?=yes <0> [353.873109] i915_mod-3280 1.... 351988999us : 0xffffffffa0149d40: vcs0 fence 1667:1, global=1, current 1 <0> [353.873133] i915_mod-3280 1.... 351989045us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.873157] i915_mod-3280 1.... 351989047us : 0xffffffffa0149fd3: __retire_engine_request(vcs0) fence 1667:1, global=1, current 1 <0> [353.873185] i915_mod-3280 1.... 351989331us : 0xffffffffa0149d40: bcs0 fence 1666:1, global=1, current 1 <0> [353.873209] i915_mod-3280 1.... 351989332us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.873233] i915_mod-3280 1.... 351989333us : 0xffffffffa0149fd3: __retire_engine_request(bcs0) fence 1666:1, global=1, current 1 <0> [353.873260] i915_mod-3280 1.... 351989346us : 0xffffffffa0149d40: rcs0 fence 1665:1, global=1, current 1 <0> [353.873285] i915_mod-3280 1.... 351989346us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.873308] i915_mod-3280 1.... 351989359us : 0xffffffffa0149fd3: __retire_engine_request(rcs0) fence 1665:1, global=1, current 1 <0> [353.873335] i915_mod-3280 1.... 351989370us : 0xffffffffa01126ab: emit barrier on rcs0 <0> [353.873358] i915_mod-3280 1.... 351989386us : 0xffffffffa014b770: rcs0 fence 165a:1 <0> [353.873379] i915_mod-3280 1.... 351989388us : 0xffffffffa014bd19: marking (null) as active <0> [353.873402] i915_mod-3280 1d..1 351989463us : 0xffffffffa016cc00: rcs0 cs-irq head=1, tail=1 <0> [353.873426] i915_mod-3280 1d..1 351989465us : 0xffffffffa014a980: rcs0 fence 165a:1 -> global=2, current 1 <0> [353.873452] i915_mod-3280 1d..1 351989505us : 0xffffffffa016dc57: rcs0 in[0]: ctx=0.1, global=2 (fence 165a:1) (current 1), prio=-4094 <0> [353.873480] i915_mod-3280 1.... 351989510us : 0xffffffffa01126ab: emit barrier on bcs0 <0> [353.873502] i915_mod-3280 1.... 351989522us : 0xffffffffa014b770: bcs0 fence 165d:1 <0> [353.873524] i915_mod-3280 1.... 351989524us : 0xffffffffa014bd19: marking (null) as active <0> [353.873546] i915_mod-3280 1d..1 351989537us : 0xffffffffa016cc00: bcs0 cs-irq head=1, tail=1 <0> [353.873570] i915_mod-3280 1d..1 351989538us : 0xffffffffa014a980: bcs0 fence 165d:1 -> global=2, current 1 <0> [353.873595] i915_mod-3280 1d..1 351989551us : 0xffffffffa016dc57: bcs0 in[0]: ctx=0.1, global=2 (fence 165d:1) (current 1), prio=-4094 <0> [353.873623] i915_mod-3280 1.... 351989555us : 0xffffffffa01126ab: emit barrier on vcs0 <0> [353.873645] i915_mod-3280 1.... 351989567us : 0xffffffffa014b770: vcs0 fence 1660:1 <0> [353.873667] i915_mod-3280 1.... 351989569us : 0xffffffffa014bd19: marking (null) as active <0> [353.873690] i915_mod-3280 1d..1 351989581us : 0xffffffffa016cc00: vcs0 cs-irq head=1, tail=1 <0> [353.873714] i915_mod-3280 1d..1 351989582us : 0xffffffffa014a980: vcs0 fence 1660:1 -> global=2, current 1 <0> [353.873740] i915_mod-3280 1d..1 351989594us : 0xffffffffa016dc57: vcs0 in[0]: ctx=0.1, global=2 (fence 1660:1) (current 1), prio=-4094 <0> [353.873769] i915_mod-3280 1.... 351989600us : 0xffffffffa010e586: last request for (null) on engine vecs0: 1668:1 <0> [353.873794] i915_mod-3280 1.... 351989601us : 0xffffffffa010ea5a: (null) needs barrier for 1668:1 <0> [353.873818] i915_mod-3280 1.... 351989601us : 0xffffffffa01126ab: emit barrier on vecs0 <0> [353.873840] i915_mod-3280 1.... 351989614us : 0xffffffffa010e586: last request for (null) on engine vecs0: 1668:1 <0> [353.873866] i915_mod-3280 1.... 351989615us : 0xffffffffa011272d: add barrier on vecs0 for 1668:1 <0> [353.873889] i915_mod-3280 1.... 351989626us : 0xffffffffa014b770: vecs0 fence 1663:1 <0> [353.873911] i915_mod-3280 1.... 351989628us : 0xffffffffa014bd19: marking (null) as active <0> [353.873934] i915_mod-3280 1d..1 351989640us : 0xffffffffa016cc00: vecs0 cs-irq head=1, tail=1 <0> [353.873957] i915_mod-3280 1d..1 351989641us : 0xffffffffa014a980: vecs0 fence 1663:1 -> global=2, current 1 <0> [353.873983] i915_mod-3280 1d..1 351989653us : 0xffffffffa016dc57: vecs0 in[0]: ctx=0.1, global=2 (fence 1663:1) (current 1), prio=-4094 <0> [353.874012] i915_mod-3280 1.... 351989658us : 0xffffffffa0133d60: flags=2 (locked), timeout=200 <0> [353.874035] i915_mod-3280 1.... 351989699us : 0xffffffffa0149d40: vecs0 fence 1663:1, global=2, current 2 <0> [353.874060] i915_mod-3280 1.... 351989700us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.874083] i915_mod-3280 1.... 351989701us : 0xffffffffa0149fd3: __retire_engine_request(vecs0) fence 1668:1, global=1, current 2 <0> [353.874112] i915_mod-3280 1.... 351989704us : 0xffffffffa0149fd3: __retire_engine_request(vecs0) fence 1663:1, global=2, current 2 <0> [353.874140] i915_mod-3280 1.... 351989716us : 0xffffffffa0149d40: vcs0 fence 1660:1, global=2, current 2 <0> [353.874164] i915_mod-3280 1.... 351989717us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.874187] i915_mod-3280 1.... 351989718us : 0xffffffffa0149fd3: __retire_engine_request(vcs0) fence 1660:1, global=2, current 2 <0> [353.874215] i915_mod-3280 1.... 351989734us : 0xffffffffa0149d40: bcs0 fence 165d:1, global=2, current 2 <0> [353.874239] i915_mod-3280 1.... 351989735us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.874263] i915_mod-3280 1.... 351989736us : 0xffffffffa0149fd3: __retire_engine_request(bcs0) fence 165d:1, global=2, current 2 <0> [353.874291] i915_mod-3280 1.... 351989750us : 0xffffffffa0149d40: rcs0 fence 165a:1, global=2, current 2 <0> [353.874315] i915_mod-3280 1.... 351989750us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.874338] i915_mod-3280 1.... 351989751us : 0xffffffffa0149fd3: __retire_engine_request(rcs0) fence 165a:1, global=2, current 2 <0> [353.874366] i915_mod-3280 1.... 351989765us : 0xffffffffa0149d40: vecs0 fence 1668:1, global=1, current 2 <0> [353.874391] i915_mod-3280 1.... 351989765us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.874413] i915_mod-3280 1.... 351989769us : 0xffffffffa012f670: <0> [353.874432] i915_mod-3280 1.... 351989784us : 0xffffffffa012d590: <0> [353.874451] i915_mod-3280 1.... 351990197us : 0xffffffffa013b9d0: <0> [353.874470] i915_mod-3280 1.... 351990201us : 0xffffffffa01125f0: awake?=no <0> [353.874491] i915_mod-3280 1.... 351990203us : 0xffffffffa0133d60: flags=13 (locked), timeout=9223372036854775807 (forever) <0> [353.874517] i915_mod-3280 1.... 351991501us : 0xffffffffa013b910: <0> [353.874537] i915_mod-3280 1.... 351991511us : 0xffffffffa0160cdb: rcs0 <0> [353.874557] i915_mod-3280 1.... 351991529us : 0xffffffffa0160cdb: bcs0 <0> [353.874576] i915_mod-3280 1.... 351991544us : 0xffffffffa0160cdb: vcs0 <0> [353.874596] i915_mod-3280 1.... 351991562us : 0xffffffffa0160cdb: vecs0 <0> [353.874616] i915_mod-3280 1.... 351991613us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.874640] i915_mod-3280 1.... 351991614us : 0xffffffffa0161650: <0> [353.874660] i915_mod-3280 1.... 351991615us : 0xffffffffa016e900: rcs0 request global=0, current=2 <0> [353.874683] i915_mod-3280 1.... 351991618us : 0xffffffffa016e900: bcs0 request global=0, current=2 <0> [353.874708] i915_mod-3280 1.... 351991619us : 0xffffffffa016e900: vcs0 request global=0, current=2 <0> [353.874731] i915_mod-3280 1.... 351991620us : 0xffffffffa016e900: vecs0 request global=0, current=2 <0> [353.874755] i915_mod-3280 1.... 351999582us : 0xffffffffa0133470: start <0> [353.874775] i915_mod-3280 1.... 352000857us : 0xffffffffa016d390: rcs0: depth<-0 <0> [353.874796] i915_mod-3280 1d..1 352000861us : 0xffffffffa016cc00: rcs0 cs-irq head=5, tail=5 <0> [353.874819] i915_mod-3280 1.... 352000862us : 0xffffffffa016d390: bcs0: depth<-0 <0> [353.874841] i915_mod-3280 1d..1 352000863us : 0xffffffffa016cc00: bcs0 cs-irq head=5, tail=5 <0> [353.874863] i915_mod-3280 1.... 352000864us : 0xffffffffa016d390: vcs0: depth<-0 <0> [353.874885] i915_mod-3280 1d..1 352000864us : 0xffffffffa016cc00: vcs0 cs-irq head=5, tail=5 <0> [353.874908] i915_mod-3280 1.... 352000865us : 0xffffffffa016d390: vecs0: depth<-0 <0> [353.874929] i915_mod-3280 1d..1 352000866us : 0xffffffffa016cc00: vecs0 cs-irq head=5, tail=5 <0> [353.874952] i915_mod-3280 1.... 352000868us : 0xffffffffa0160cdb: rcs0 <0> [353.874971] i915_mod-3280 1.... 352000885us : 0xffffffffa0160cdb: bcs0 <0> [353.874991] i915_mod-3280 1.... 352000901us : 0xffffffffa0160cdb: vcs0 <0> [353.875010] i915_mod-3280 1.... 352000961us : 0xffffffffa0160cdb: vecs0 <0> [353.875030] i915_mod-3280 1.... 352001011us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.875054] i915_mod-3280 1.... 352007068us : 0xffffffffa016e590: rcs0 current 2 <0> [353.875075] i915_mod-3280 1.... 352007073us : 0xffffffffa016e590: bcs0 current 2 <0> [353.875096] i915_mod-3280 1.... 352007075us : 0xffffffffa016e590: vcs0 current 2 <0> [353.875118] i915_mod-3280 1.... 352007077us : 0xffffffffa016e590: vecs0 current 2 <0> [353.875139] i915_mod-3280 1.... 352016156us : 0xffffffffa0167373: rcs0: depth->0 <0> [353.875161] i915_mod-3280 1.... 352016162us : 0xffffffffa0167373: bcs0: depth->0 <0> [353.875182] i915_mod-3280 1.... 352016165us : 0xffffffffa0167373: vcs0: depth->0 <0> [353.875203] i915_mod-3280 1.... 352016168us : 0xffffffffa0167373: vecs0: depth->0 <0> [353.875224] i915_mod-3280 1.... 352016178us : 0xffffffffa0133603: end <0> [353.875243] i915_mod-3280 0.... 352268783us : 0xffffffffa013b9d0: <0> [353.875261] i915_mod-3280 0.... 352300447us : 0xffffffffa013b910: <0> [353.875280] i915_mod-3280 0.... 352300648us : 0xffffffffa0133887: start <0> [353.875299] i915_mod-3280 0.... 352300657us : 0xffffffffa0160cdb: rcs0 <0> [353.875317] i915_mod-3280 0.... 352300674us : 0xffffffffa0160cdb: bcs0 <0> [353.875336] i915_mod-3280 0.... 352300690us : 0xffffffffa0160cdb: vcs0 <0> [353.875355] i915_mod-3280 0.... 352300708us : 0xffffffffa0160cdb: vecs0 <0> [353.875375] i915_mod-3280 0.... 352300757us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.875398] i915_mod-3280 0.... 352300758us : 0xffffffffa0161650: <0> [353.875417] i915_mod-3280 0.... 352300760us : 0xffffffffa016e900: rcs0 request global=0, current=2 <0> [353.875440] i915_mod-3280 0.... 352300762us : 0xffffffffa016e900: bcs0 request global=0, current=2 <0> [353.875463] i915_mod-3280 0.... 352300764us : 0xffffffffa016e900: vcs0 request global=0, current=2 <0> [353.875486] i915_mod-3280 0.... 352300765us : 0xffffffffa016e900: vecs0 request global=0, current=2 <0> [353.875509] i915_mod-3280 0.... 352300768us : 0xffffffffa0133998: end <0> [353.875528] i915_mod-3280 0.... 352300769us : 0xffffffffa0160cdb: rcs0 <0> [353.875548] i915_mod-3280 0.... 352300786us : 0xffffffffa0160cdb: bcs0 <0> [353.875566] i915_mod-3280 0.... 352300801us : 0xffffffffa0160cdb: vcs0 <0> [353.875585] i915_mod-3280 0.... 352300819us : 0xffffffffa0160cdb: vecs0 <0> [353.875605] i915_mod-3280 0.... 352300867us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.875628] i915_mod-3280 0.... 352300868us : 0xffffffffa0161650: <0> [353.875647] i915_mod-3280 0.... 352300869us : 0xffffffffa016e900: rcs0 request global=0, current=2 <0> [353.875670] i915_mod-3280 0.... 352300870us : 0xffffffffa016e900: bcs0 request global=0, current=2 <0> [353.875693] i915_mod-3280 0.... 352300871us : 0xffffffffa016e900: vcs0 request global=0, current=2 <0> [353.875716] i915_mod-3280 0.... 352300872us : 0xffffffffa016e900: vecs0 request global=0, current=2 <0> [353.875840] CPU:3 [LOST 1048713 EVENTS]\x0ai915_mod-3280 3.... 352702305us : i915_request_add: marking (null) as active <0> [353.875957] i915_mod-3280 3d..1 352702311us : process_csb: bcs0 cs-irq head=5, tail=5 <0> [353.876050] i915_mod-3280 3d..1 352702312us : __i915_request_submit: bcs0 fence 167a:1 -> global=1, current 0 <0> [353.876147] i915_mod-3280 3d..1 352702317us : __execlists_submission_tasklet: bcs0 in[0]: ctx=2.1, global=1 (fence 167a:1) (current 0), prio=2 <0> [353.876245] i915_mod-3280 3.... 352702665us : i915_request_add: vcs0 fence 167b:1 <0> [353.876334] i915_mod-3280 3.... 352702667us : i915_request_add: marking (null) as active <0> [353.876428] i915_mod-3280 3d..1 352702672us : process_csb: vcs0 cs-irq head=5, tail=5 <0> [353.876519] i915_mod-3280 3d..1 352702673us : __i915_request_submit: vcs0 fence 167b:1 -> global=1, current 0 <0> [353.876615] i915_mod-3280 3d..1 352702677us : __execlists_submission_tasklet: vcs0 in[0]: ctx=2.1, global=1 (fence 167b:1) (current 0), prio=2 <0> [353.876713] i915_mod-3280 3.... 352703049us : i915_request_add: vecs0 fence 167c:1 <0> [353.876802] i915_mod-3280 3.... 352703051us : i915_request_add: marking (null) as active <0> [353.876895] i915_mod-3280 3d..1 352703056us : process_csb: vecs0 cs-irq head=5, tail=5 <0> [353.876986] i915_mod-3280 3d..1 352703057us : __i915_request_submit: vecs0 fence 167c:1 -> global=1, current 0 <0> [353.877083] i915_mod-3280 3d..1 352703062us : __execlists_submission_tasklet: vecs0 in[0]: ctx=2.1, global=1 (fence 167c:1) (current 0), prio=2 <0> [353.877177] i915_mod-3280 3.... 352703066us : i915_gem_switch_to_kernel_context: awake?=yes <0> [353.877269] i915_mod-3280 3.... 352703068us : i915_request_retire: vcs0 fence 167b:1, global=1, current 1 <0> [353.877361] i915_mod-3280 3.... 352703069us : i915_request_retire: marking (null) as inactive <0> [353.877453] i915_mod-3280 3.... 352703071us : i915_request_retire: __retire_engine_request(vcs0) fence 167b:1, global=1, current 1 <0> [353.877549] i915_mod-3280 3.... 352703325us : i915_request_retire: bcs0 fence 167a:1, global=1, current 1 <0> [353.877641] i915_mod-3280 3.... 352703327us : i915_request_retire: marking (null) as inactive <0> [353.877733] i915_mod-3280 3.... 352703328us : i915_request_retire: __retire_engine_request(bcs0) fence 167a:1, global=1, current 1 <0> [353.877829] i915_mod-3280 3.... 352703340us : i915_request_retire: rcs0 fence 1679:1, global=1, current 1 <0> [353.877921] i915_mod-3280 3.... 352703341us : i915_request_retire: marking (null) as inactive <0> [353.878014] i915_mod-3280 3.... 352703353us : i915_request_retire: __retire_engine_request(rcs0) fence 1679:1, global=1, current 1 <0> [353.878110] i915_mod-3280 3.... 352703365us : i915_gem_switch_to_kernel_context: emit barrier on rcs0 <0> [353.878203] i915_mod-3280 3.... 352703380us : i915_request_add: rcs0 fence 166e:1 <0> [353.878303] i915_mod-3280 3.... 352703382us : i915_request_add: marking (null) as active <0> [353.878400] i915_mod-3280 3d..1 352703458us : process_csb: rcs0 cs-irq head=1, tail=1 <0> [353.878494] i915_mod-3280 3d..1 352703459us : __i915_request_submit: rcs0 fence 166e:1 -> global=2, current 1 <0> [353.878596] i915_mod-3280 3d..1 352703498us : __execlists_submission_tasklet: rcs0 in[0]: ctx=0.1, global=2 (fence 166e:1) (current 1), prio=-4094 <0> [353.878692] i915_mod-3280 3.... 352703503us : i915_gem_switch_to_kernel_context: emit barrier on bcs0 <0> [353.878786] i915_mod-3280 3.... 352703516us : i915_request_add: bcs0 fence 1671:1 <0> [353.878877] i915_mod-3280 3.... 352703517us : i915_request_add: marking (null) as active <0> [353.878970] i915_mod-3280 3d..1 352703530us : process_csb: bcs0 cs-irq head=1, tail=1 <0> [353.879062] i915_mod-3280 3d..1 352703531us : __i915_request_submit: bcs0 fence 1671:1 -> global=2, current 1 <0> [353.879160] i915_mod-3280 3d..1 352703543us : __execlists_submission_tasklet: bcs0 in[0]: ctx=0.1, global=2 (fence 1671:1) (current 1), prio=-4094 <0> [353.879255] i915_mod-3280 3.... 352703547us : i915_gem_switch_to_kernel_context: emit barrier on vcs0 <0> [353.879348] i915_mod-3280 3.... 352703559us : i915_request_add: vcs0 fence 1674:1 <0> [353.879440] i915_mod-3280 3.... 352703561us : i915_request_add: marking (null) as active <0> [353.879534] i915_mod-3280 3d..1 352703573us : process_csb: vcs0 cs-irq head=1, tail=1 <0> [353.879626] i915_mod-3280 3d..1 352703574us : __i915_request_submit: vcs0 fence 1674:1 -> global=2, current 1 <0> [353.879722] i915_mod-3280 3d..1 352703586us : __execlists_submission_tasklet: vcs0 in[0]: ctx=0.1, global=2 (fence 1674:1) (current 1), prio=-4094 <0> [353.879817] i915_mod-3280 3.... 352703591us : last_request_on_engine: last request for (null) on engine vecs0: 167c:1 <0> [353.879907] i915_mod-3280 3.... 352703592us : engine_has_kernel_context_barrier: (null) needs barrier for 167c:1 <0> [353.880001] i915_mod-3280 3.... 352703592us : i915_gem_switch_to_kernel_context: emit barrier on vecs0 <0> [353.880092] i915_mod-3280 3.... 352703604us : last_request_on_engine: last request for (null) on engine vecs0: 167c:1 <0> [353.880188] i915_mod-3280 3.... 352703605us : i915_gem_switch_to_kernel_context: add barrier on vecs0 for 167c:1 <0> [353.880287] i915_mod-3280 3.... 352703617us : i915_request_add: vecs0 fence 1677:1 <0> [353.880380] i915_mod-3280 3.... 352703618us : i915_request_add: marking (null) as active <0> [353.880476] i915_mod-3280 3d..1 352703631us : process_csb: vecs0 cs-irq head=1, tail=1 <0> [353.880569] i915_mod-3280 3d..1 352703632us : __i915_request_submit: vecs0 fence 1677:1 -> global=2, current 1 <0> [353.880666] i915_mod-3280 3d..1 352703644us : __execlists_submission_tasklet: vecs0 in[0]: ctx=0.1, global=2 (fence 1677:1) (current 1), prio=-4094 <0> [353.880765] i915_mod-3280 3.... 352703649us : i915_gem_wait_for_idle: flags=2 (locked), timeout=200 <0> [353.880857] i915_mod-3280 3.... 352703688us : i915_request_retire: vecs0 fence 1677:1, global=2, current 2 <0> [353.880951] i915_mod-3280 3.... 352703689us : i915_request_retire: marking (null) as inactive <0> [353.881043] i915_mod-3280 3.... 352703690us : i915_request_retire: __retire_engine_request(vecs0) fence 167c:1, global=1, current 2 <0> [353.881140] i915_mod-3280 3.... 352703693us : i915_request_retire: __retire_engine_request(vecs0) fence 1677:1, global=2, current 2 <0> [353.881240] i915_mod-3280 3.... 352703704us : i915_request_retire: vcs0 fence 1674:1, global=2, current 2 <0> [353.881333] i915_mod-3280 3.... 352703705us : i915_request_retire: marking (null) as inactive <0> [353.881424] i915_mod-3280 3.... 352703706us : i915_request_retire: __retire_engine_request(vcs0) fence 1674:1, global=2, current 2 <0> [353.881520] i915_mod-3280 3.... 352703722us : i915_request_retire: bcs0 fence 1671:1, global=2, current 2 <0> [353.881613] i915_mod-3280 3.... 352703722us : i915_request_retire: marking (null) as inactive <0> [353.881707] i915_mod-3280 3.... 352703723us : i915_request_retire: __retire_engine_request(bcs0) fence 1671:1, global=2, current 2 <0> [353.881807] i915_mod-3280 3.... 352703737us : i915_request_retire: rcs0 fence 166e:1, global=2, current 2 <0> [353.881900] i915_mod-3280 3.... 352703737us : i915_request_retire: marking (null) as inactive <0> [353.881991] i915_mod-3280 3.... 352703738us : i915_request_retire: __retire_engine_request(rcs0) fence 166e:1, global=2, current 2 <0> [353.882088] i915_mod-3280 3.... 352703751us : i915_request_retire: vecs0 fence 167c:1, global=1, current 2 <0> [353.882180] i915_mod-3280 3.... 352703752us : i915_request_retire: marking (null) as inactive <0> [353.882270] i915_mod-3280 3.... 352703755us : i915_gem_park: <0> [353.882354] i915_mod-3280 3.... 352703771us : __i915_gem_park: <0> [353.882439] i915_mod-3280 0.... 352957225us : i915_gem_suspend: <0> [353.882522] i915_mod-3280 0.... 352957233us : i915_gem_switch_to_kernel_context: awake?=no <0> [353.882613] i915_mod-3280 0.... 352957239us : i915_gem_wait_for_idle: flags=13 (locked), timeout=9223372036854775807 (forever) <0> [353.882707] i915_mod-3280 0.... 352983690us : i915_gem_sanitize: <0> [353.882797] i915_mod-3280 0.... 352983906us : intel_engine_stop_cs: rcs0 <0> [353.882886] i915_mod-3280 0.... 352983953us : intel_engine_stop_cs: bcs0 <0> [353.882975] i915_mod-3280 0.... 352983969us : intel_engine_stop_cs: vcs0 <0> [353.883064] i915_mod-3280 0.... 352983987us : intel_engine_stop_cs: vecs0 <0> [353.883156] i915_mod-3280 0.... 352984038us : intel_gpu_reset: engine_mask=ffffffff, ret=0, retry=0 <0> [353.883249] i915_mod-3280 0.... 352984040us : intel_engines_sanitize: <0> [353.883339] i915_mod-3280 0.... 352984042us : execlists_reset: rcs0 request global=0, current=2 <0> [353.883433] i915_mod-3280 0.... 352984045us : execlists_reset: bcs0 request global=0, current=2 <0> [353.883526] i915_mod-3280 0.... 352984046us : execlists_reset: vcs0 request global=0, current=2 <0> [353.883619] i915_mod-3280 0.... 352984048us : execlists_reset: vecs0 request global=0, current=2 <0> [353.883646] CPU:2 [LOST 713842 EVENTS]\x0ai915_mod-3280 2d.s1 353384712us : 0xffffffffa016cec5: rcs0 completed ctx=2 <0> [353.883677] i915_mod-3280 2.... 353385121us : 0xffffffffa014b770: bcs0 fence 168e:1 <0> [353.883698] i915_mod-3280 2.... 353385124us : 0xffffffffa014bd19: marking (null) as active <0> [353.883720] i915_mod-3280 2d..1 353385130us : 0xffffffffa016cc00: bcs0 cs-irq head=5, tail=5 <0> [353.883743] i915_mod-3280 2d..1 353385131us : 0xffffffffa014a980: bcs0 fence 168e:1 -> global=1, current 0 <0> [353.883768] i915_mod-3280 2d..1 353385136us : 0xffffffffa016dc57: bcs0 in[0]: ctx=2.1, global=1 (fence 168e:1) (current 0), prio=2 <0> [353.883799] i915_mod-3280 2..s. 353385147us : 0xffffffffa016e100: bcs0 awake?=1, active=1 <0> [353.883820] i915_mod-3280 2d.s1 353385148us : 0xffffffffa016cc00: bcs0 cs-irq head=5, tail=1 <0> [353.883845] i915_mod-3280 2d.s1 353385149us : 0xffffffffa016cc9c: bcs0 csb[0]: status=0x00000001:0x00000000, active=0x1 <0> [353.883871] i915_mod-3280 2d.s1 353385149us : 0xffffffffa016cc9c: bcs0 csb[1]: status=0x00000018:0x00000002, active=0x5 <0> [353.883899] i915_mod-3280 2d.s1 353385150us : 0xffffffffa016cd7e: bcs0 out[0]: ctx=2.1, global=1 (fence 168e:1) (current 1), prio=2 <0> [353.883926] i915_mod-3280 2d.s1 353385151us : 0xffffffffa016cec5: bcs0 completed ctx=2 <0> [353.883948] i915_mod-3280 2..s. 353385156us : 0xffffffffa016e100: bcs0 awake?=1, active=0 <0> [353.883970] i915_mod-3280 2d.s1 353385157us : 0xffffffffa016cc00: bcs0 cs-irq head=1, tail=1 <0> [353.883992] i915_mod-3280 2.... 353385425us : 0xffffffffa014b770: vcs0 fence 168f:1 <0> [353.884013] i915_mod-3280 2.... 353385427us : 0xffffffffa014bd19: marking (null) as active <0> [353.884035] i915_mod-3280 2d..1 353385432us : 0xffffffffa016cc00: vcs0 cs-irq head=5, tail=5 <0> [353.884058] i915_mod-3280 2d..1 353385433us : 0xffffffffa014a980: vcs0 fence 168f:1 -> global=1, current 0 <0> [353.884082] i915_mod-3280 2d..1 353385438us : 0xffffffffa016dc57: vcs0 in[0]: ctx=2.1, global=1 (fence 168f:1) (current 0), prio=2 <0> [353.884109] i915_mod-3280 2..s. 353385448us : 0xffffffffa016e100: vcs0 awake?=1, active=1 <0> [353.884131] i915_mod-3280 2d.s1 353385449us : 0xffffffffa016cc00: vcs0 cs-irq head=5, tail=1 <0> [353.884154] i915_mod-3280 2d.s1 353385450us : 0xffffffffa016cc9c: vcs0 csb[0]: status=0x00000001:0x00000000, active=0x1 <0> [353.884180] i915_mod-3280 2d.s1 353385450us : 0xffffffffa016cc9c: vcs0 csb[1]: status=0x00000018:0x00000002, active=0x5 <0> [353.884206] i915_mod-3280 2d.s1 353385452us : 0xffffffffa016cd7e: vcs0 out[0]: ctx=2.1, global=1 (fence 168f:1) (current 1), prio=2 <0> [353.884233] i915_mod-3280 2d.s1 353385452us : 0xffffffffa016cec5: vcs0 completed ctx=2 <0> [353.884255] i915_mod-3280 2..s. 353385457us : 0xffffffffa016e100: vcs0 awake?=1, active=0 <0> [353.884277] i915_mod-3280 2d.s1 353385458us : 0xffffffffa016cc00: vcs0 cs-irq head=1, tail=1 <0> [353.884299] i915_mod-3280 2.... 353385720us : 0xffffffffa014b770: vecs0 fence 1690:1 <0> [353.884320] i915_mod-3280 2.... 353385722us : 0xffffffffa014bd19: marking (null) as active <0> [353.884342] i915_mod-3280 2d..1 353385727us : 0xffffffffa016cc00: vecs0 cs-irq head=5, tail=5 <0> [353.884365] i915_mod-3280 2d..1 353385728us : 0xffffffffa014a980: vecs0 fence 1690:1 -> global=1, current 0 <0> [353.884390] i915_mod-3280 2d..1 353385733us : 0xffffffffa016dc57: vecs0 in[0]: ctx=2.1, global=1 (fence 1690:1) (current 0), prio=2 <0> [353.884416] i915_mod-3280 2.... 353385737us : 0xffffffffa01125f0: awake?=yes <0> [353.884437] i915_mod-3280 2..s2 353385737us : 0xffffffffa016e100: vecs0 awake?=1, active=1 <0> [353.884459] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cc00: vecs0 cs-irq head=5, tail=1 <0> [353.884481] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cc9c: vecs0 csb[0]: status=0x00000001:0x00000000, active=0x1 <0> [353.884508] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cc9c: vecs0 csb[1]: status=0x00000018:0x00000002, active=0x5 <0> [353.884534] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cd7e: vecs0 out[0]: ctx=2.1, global=1 (fence 1690:1) (current 1), prio=2 <0> [353.884561] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cec5: vecs0 completed ctx=2 <0> [353.884583] i915_mod-3280 2..s2 353385737us : 0xffffffffa016e100: vecs0 awake?=1, active=0 <0> [353.884605] i915_mod-3280 2d.s3 353385737us : 0xffffffffa016cc00: vecs0 cs-irq head=1, tail=1 <0> [353.884627] i915_mod-3280 2.... 353385755us : 0xffffffffa0149d40: vecs0 fence 1690:1, global=1, current 1 <0> [353.884651] i915_mod-3280 2.... 353385757us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.884674] i915_mod-3280 2.... 353385758us : 0xffffffffa0149fd3: __retire_engine_request(vecs0) fence 1690:1, global=1, current 1 <0> [353.884701] i915_mod-3280 2.... 353386110us : 0xffffffffa0149d40: vcs0 fence 168f:1, global=1, current 1 <0> [353.884724] i915_mod-3280 2.... 353386112us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.884747] i915_mod-3280 2.... 353386114us : 0xffffffffa0149fd3: __retire_engine_request(vcs0) fence 168f:1, global=1, current 1 <0> [353.884774] i915_mod-3280 2.... 353386125us : 0xffffffffa0149d40: bcs0 fence 168e:1, global=1, current 1 <0> [353.884798] i915_mod-3280 2.... 353386126us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.884820] i915_mod-3280 2.... 353386127us : 0xffffffffa0149fd3: __retire_engine_request(bcs0) fence 168e:1, global=1, current 1 <0> [353.884847] i915_mod-3280 2.... 353386137us : 0xffffffffa0149d40: rcs0 fence 168d:1, global=1, current 1 <0> [353.884871] i915_mod-3280 2.... 353386138us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.884893] i915_mod-3280 2.... 353386151us : 0xffffffffa0149fd3: __retire_engine_request(rcs0) fence 168d:1, global=1, current 1 <0> [353.884920] i915_mod-3280 2.... 353386152us : 0xffffffffa012f670: <0> [353.884938] i915_mod-3280 2.... 353386169us : 0xffffffffa01126ab: emit barrier on rcs0 <0> [353.884959] i915_mod-3280 2.... 353386170us : 0xffffffffa012f740: <0> [353.884978] i915_mod-3280 2.... 353386185us : 0xffffffffa014b770: rcs0 fence 1682:1 <0> [353.884998] i915_mod-3280 2.... 353386187us : 0xffffffffa014bd19: marking (null) as active <0> [353.885020] i915_mod-3280 2d..1 353386262us : 0xffffffffa016cc00: rcs0 cs-irq head=1, tail=1 <0> [353.885043] i915_mod-3280 2d..1 353386264us : 0xffffffffa014a980: rcs0 fence 1682:1 -> global=2, current 1 <0> [353.885068] i915_mod-3280 2d..1 353386303us : 0xffffffffa016dc57: rcs0 in[0]: ctx=0.1, global=2 (fence 1682:1) (current 1), prio=-4094 <0> [353.885095] i915_mod-3280 2.... 353386308us : 0xffffffffa01126ab: emit barrier on bcs0 <0> [353.885117] i915_mod-3280 2..s. 353386316us : 0xffffffffa016e100: rcs0 awake?=1, active=1 <0> [353.885138] i915_mod-3280 2d.s1 353386317us : 0xffffffffa016cc00: rcs0 cs-irq head=1, tail=2 <0> [353.885161] i915_mod-3280 2d.s1 353386318us : 0xffffffffa016cc9c: rcs0 csb[2]: status=0x00000001:0x00000000, active=0x1 <0> [353.885187] i915_mod-3280 2.... 353386331us : 0xffffffffa014b770: bcs0 fence 1685:1 <0> [353.885207] i915_mod-3280 2.... 353386333us : 0xffffffffa014bd19: marking (null) as active <0> [353.885229] i915_mod-3280 2d..1 353386345us : 0xffffffffa016cc00: bcs0 cs-irq head=1, tail=1 <0> [353.885252] i915_mod-3280 2d..1 353386346us : 0xffffffffa014a980: bcs0 fence 1685:1 -> global=2, current 1 <0> [353.885277] i915_mod-3280 2d..1 353386358us : 0xffffffffa016dc57: bcs0 in[0]: ctx=0.1, global=2 (fence 1685:1) (current 1), prio=-4094 <0> [353.885304] i915_mod-3280 2..s1 353386374us : 0xffffffffa016e100: rcs0 awake?=1, active=5 <0> [353.885326] i915_mod-3280 2d.s2 353386375us : 0xffffffffa016cc00: rcs0 cs-irq head=2, tail=3 <0> [353.885349] i915_mod-3280 2d.s2 353386376us : 0xffffffffa016cc9c: rcs0 csb[3]: status=0x00000018:0x00000000, active=0x5 <0> [353.885375] i915_mod-3280 2d.s2 353386377us : 0xffffffffa016cd7e: rcs0 out[0]: ctx=0.1, global=2 (fence 1682:1) (current 2), prio=-4094 <0> [353.885403] i915_mod-3280 2d.s2 353386378us : 0xffffffffa016cec5: rcs0 completed ctx=0 <0> [353.885424] i915_mod-3280 2..s1 353386379us : 0xffffffffa016e100: bcs0 awake?=1, active=1 <0> [353.885446] i915_mod-3280 2d.s2 353386380us : 0xffffffffa016cc00: bcs0 cs-irq head=1, tail=3 <0> [353.885469] i915_mod-3280 2d.s2 353386380us : 0xffffffffa016cc9c: bcs0 csb[2]: status=0x00000001:0x00000000, active=0x1 <0> [353.885495] i915_mod-3280 2d.s2 353386381us : 0xffffffffa016cc9c: bcs0 csb[3]: status=0x00000018:0x00000000, active=0x5 <0> [353.885521] i915_mod-3280 2d.s2 353386382us : 0xffffffffa016cd7e: bcs0 out[0]: ctx=0.1, global=2 (fence 1685:1) (current 2), prio=-4094 <0> [353.885548] i915_mod-3280 2d.s2 353386383us : 0xffffffffa016cec5: bcs0 completed ctx=0 <0> [353.885570] i915_mod-3280 2.... 353386385us : 0xffffffffa01126ab: emit barrier on vcs0 <0> [353.885593] i915_mod-3280 2.... 353386397us : 0xffffffffa014b770: vcs0 fence 1688:1 <0> [353.885614] i915_mod-3280 2.... 353386399us : 0xffffffffa014bd19: marking (null) as active <0> [353.885636] i915_mod-3280 2d..1 353386412us : 0xffffffffa016cc00: vcs0 cs-irq head=1, tail=1 <0> [353.885659] i915_mod-3280 2d..1 353386413us : 0xffffffffa014a980: vcs0 fence 1688:1 -> global=2, current 1 <0> [353.885683] i915_mod-3280 2d..1 353386425us : 0xffffffffa016dc57: vcs0 in[0]: ctx=0.1, global=2 (fence 1688:1) (current 1), prio=-4094 <0> [353.885711] i915_mod-3280 2.... 353386430us : 0xffffffffa01126ab: emit barrier on vecs0 <0> [353.885732] i915_mod-3280 2..s. 353386435us : 0xffffffffa016e100: vcs0 awake?=1, active=1 <0> [353.885754] i915_mod-3280 2d.s1 353386436us : 0xffffffffa016cc00: vcs0 cs-irq head=1, tail=3 <0> [353.885777] i915_mod-3280 2d.s1 353386437us : 0xffffffffa016cc9c: vcs0 csb[2]: status=0x00000001:0x00000000, active=0x1 <0> [353.885803] i915_mod-3280 2d.s1 353386437us : 0xffffffffa016cc9c: vcs0 csb[3]: status=0x00000018:0x00000000, active=0x5 <0> [353.885829] i915_mod-3280 2d.s1 353386438us : 0xffffffffa016cd7e: vcs0 out[0]: ctx=0.1, global=2 (fence 1688:1) (current 2), prio=-4094 <0> [353.885856] i915_mod-3280 2d.s1 353386439us : 0xffffffffa016cec5: vcs0 completed ctx=0 <0> [353.885878] i915_mod-3280 2..s. 353386444us : 0xffffffffa016e100: vcs0 awake?=1, active=0 <0> [353.885900] i915_mod-3280 2d.s1 353386445us : 0xffffffffa016cc00: vcs0 cs-irq head=3, tail=3 <0> [353.885924] i915_mod-3280 2.... 353386457us : 0xffffffffa014b770: vecs0 fence 168b:1 <0> [353.885945] i915_mod-3280 2.... 353386459us : 0xffffffffa014bd19: marking (null) as active <0> [353.885967] i915_mod-3280 2d..1 353386472us : 0xffffffffa016cc00: vecs0 cs-irq head=1, tail=1 <0> [353.885989] i915_mod-3280 2d..1 353386472us : 0xffffffffa014a980: vecs0 fence 168b:1 -> global=2, current 1 <0> [353.886015] i915_mod-3280 2d..1 353386485us : 0xffffffffa016dc57: vecs0 in[0]: ctx=0.1, global=2 (fence 168b:1) (current 1), prio=-4094 <0> [353.886043] i915_mod-3280 2..s1 353386494us : 0xffffffffa016e100: vecs0 awake?=1, active=1 <0> [353.886065] i915_mod-3280 2d.s2 353386495us : 0xffffffffa016cc00: vecs0 cs-irq head=1, tail=3 <0> [353.886088] i915_mod-3280 2d.s2 353386496us : 0xffffffffa016cc9c: vecs0 csb[2]: status=0x00000001:0x00000000, active=0x1 <0> [353.886114] i915_mod-3280 2d.s2 353386496us : 0xffffffffa016cc9c: vecs0 csb[3]: status=0x00000018:0x00000000, active=0x5 <0> [353.886140] i915_mod-3280 2d.s2 353386497us : 0xffffffffa016cd7e: vecs0 out[0]: ctx=0.1, global=2 (fence 168b:1) (current 2), prio=-4094 <0> [353.886168] i915_mod-3280 2d.s2 353386498us : 0xffffffffa016cec5: vecs0 completed ctx=0 <0> [353.886190] i915_mod-3280 2..s1 353386503us : 0xffffffffa016e100: vecs0 awake?=1, active=0 <0> [353.886211] i915_mod-3280 2d.s2 353386504us : 0xffffffffa016cc00: vecs0 cs-irq head=3, tail=3 <0> [353.886234] i915_mod-3280 2.... 353386505us : 0xffffffffa0133d60: flags=2 (locked), timeout=200 <0> [353.886257] i915_mod-3280 2.... 353386545us : 0xffffffffa0149d40: vecs0 fence 168b:1, global=2, current 2 <0> [353.886280] i915_mod-3280 2.... 353386545us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.886303] i915_mod-3280 2.... 353386546us : 0xffffffffa0149fd3: __retire_engine_request(vecs0) fence 168b:1, global=2, current 2 <0> [353.886330] i915_mod-3280 2.... 353386564us : 0xffffffffa0149d40: vcs0 fence 1688:1, global=2, current 2 <0> [353.886354] i915_mod-3280 2.... 353386565us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.886376] i915_mod-3280 2.... 353386566us : 0xffffffffa0149fd3: __retire_engine_request(vcs0) fence 1688:1, global=2, current 2 <0> [353.886403] i915_mod-3280 2.... 353386579us : 0xffffffffa0149d40: bcs0 fence 1685:1, global=2, current 2 <0> [353.886427] i915_mod-3280 2.... 353386580us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.886450] i915_mod-3280 2.... 353386581us : 0xffffffffa0149fd3: __retire_engine_request(bcs0) fence 1685:1, global=2, current 2 <0> [353.886477] i915_mod-3280 2.... 353386594us : 0xffffffffa0149d40: rcs0 fence 1682:1, global=2, current 2 <0> [353.886500] i915_mod-3280 2.... 353386594us : 0xffffffffa014a2fc: marking (null) as inactive <0> [353.886523] i915_mod-3280 2.... 353386595us : 0xffffffffa0149fd3: __retire_engine_request(rcs0) fence 1682:1, global=2, current 2 <0> [353.886549] i915_mod-3280 2.... 353386600us : 0xffffffffa012f670: <0> [353.886567] i915_mod-3280 2.... 353386613us : 0xffffffffa012d590: <0> [353.886585] i915_mod-3280 3.... 353554300us : 0xffffffffa013b9d0: <0> [353.886603] i915_mod-3280 3.... 353554308us : 0xffffffffa01125f0: awake?=no <0> [353.886624] i915_mod-3280 3.... 353554314us : 0xffffffffa0133d60: flags=13 (locked), timeout=9223372036854775807 (forever) <0> [353.886649] i915_mod-3280 3.... 353568495us : 0xffffffffa013b910: <0> [353.886667] i915_mod-3280 3.... 353568708us : 0xffffffffa0160cdb: rcs0 <0> [353.886686] i915_mod-3280 3.... 353568726us : 0xffffffffa0160cdb: bcs0 <0> [353.886704] i915_mod-3280 3.... 353568741us : 0xffffffffa0160cdb: vcs0 <0> [353.886723] i915_mod-3280 3.... 353568759us : 0xffffffffa0160cdb: vecs0 <0> [353.886742] i915_mod-3280 3.... 353568810us : 0xffffffffa017d058: engine_mask=ffffffff, ret=0, retry=0 <0> [353.886765] i915_mod-3280 3.... 353568812us : 0xffffffffa0161650: <0> [353.886784] i915_mod-3280 3.... 353568813us : 0xffffffffa016e900: rcs0 request global=0, current=2 <0> [353.886807] i915_mod-3280 3.... 353568816us : 0xffffffffa016e900: bcs0 request global=0, current=2 <0> [353.886831] i915_mod-3280 3.... 353568819us : 0xffffffffa016e900: vcs0 request global=0, current=2 <0> [353.886854] i915_mod-3280 3.... 353568821us : 0xffffffffa016e900: vecs0 request global=0, current=2 <0> [353.886963] i915_mod-3280 2.... 353891415us : i915_gem_sanitize: <0> [353.887053] i915_mod-3280 2.... 353891470us : intel_engine_stop_cs: rcs0 <0> [353.887148] i915_mod-3280 2.... 353891715us : intel_engine_stop_cs: bcs0 <0> [353.887236] i915_mod-3280 2.... 353891731us : intel_engine_stop_cs: vcs0 <0> [353.887324] i915_mod-3280 2.... 353891749us : intel_engine_stop_cs: vecs0 <0> [353.887417] i915_mod-3280 2.... 353891798us : intel_gpu_reset: engine_mask=ffffffff, ret=0, retry=0 <0> [353.887509] i915_mod-3280 2.... 353891800us : intel_engines_sanitize: <3> [353.894117] in_atomic(): 1, irqs_disabled(): 1, pid: 3280, name: i915_module_loa <4> [353.894851] CPU: 2 PID: 3280 Comm: i915_module_loa Tainted: G UD 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4> [353.895345] i915_driver_load+0x845/0x1550 [i915] <4> [353.895464] i915_pci_probe+0x29/0xa0 [i915] <3> [353.895977] BUG: scheduling while atomic: i915_module_loa/3280/0x00000002 <4> [353.901687] CPU: 2 PID: 3280 Comm: i915_module_loa Tainted: G UD W 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4> [353.902283] i915_driver_load+0x845/0x1550 [i915] <4> [353.902392] i915_pci_probe+0x29/0xa0 [i915] <4> [353.902928] CPU: 2 PID: 3280 Comm: i915_module_loa Tainted: G UD W 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4> [353.903592] i915_driver_load+0x845/0x1550 [i915] <4> [353.903693] i915_pci_probe+0x29/0xa0 [i915] <3> [354.921775] in_atomic(): 0, irqs_disabled(): 0, pid: 3280, name: i915_module_loa <4> [354.921821] CPU: 3 PID: 3280 Comm: i915_module_loa Tainted: G UD W 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4> [354.922309] i915_driver_load+0x845/0x1550 [i915] <4> [354.922414] i915_pci_probe+0x29/0xa0 [i915]
Setting the priority to Highest as it causes BAT test failure. From the history it can be seen that this issue occurs in either shards and/or BAT tests.
Stan, did you figure out anything from the latest logs?
(In reply to Francesco Balestrieri from comment #22) > Stan, did you figure out anything from the latest logs? There is a NULL pointer deref in do_remove_conflicting_framebuffers function: <4>[ 353.865901] general protection fault: 0000 [#1] PREEMPT SMP PTI <4>[ 353.865920] CPU: 2 PID: 3280 Comm: i915_module_loa Tainted: G U 4.20.0-rc3-CI-CI_DRM_5198+ #1 <4>[ 353.865938] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./J4205-ITX, BIOS P1.10 09/29/2016 <4>[ 353.865962] RIP: 0010:do_remove_conflicting_framebuffers+0x55/0x180 <4>[ 353.865975] Code: ee 41 89 ef 48 85 c0 74 53 f6 40 0a 08 74 4d 4d 85 ed 4c 8b a0 78 04 00 00 74 20 4d 85 e4 74 1b 41 8b 4d 00 31 db 85 c9 74 11 <41> 8b 14 24 85 d2 75 45 83 c3 01 41 39 5d 00 77 ef 4d 85 e4 74 1c <4>[ 353.866006] RSP: 0018:ffffc900002bfa58 EFLAGS: 00010202 <4>[ 353.866017] RAX: ffff888275e7e678 RBX: 0000000000000000 RCX: 0000000000000001 <4>[ 353.866031] RDX: 0000000000000001 RSI: ffffffffa05a2dc2 RDI: ffff88825c0e6178 <4>[ 353.866045] RBP: 0000000000000000 R08: 00000000cfaa903d R09: 0000000000000001 <4>[ 353.866058] R10: ffffc900002bfac0 R11: ffffffff820e2810 R12: 6b6b6b6b6b6b6b6b <4>[ 353.866071] R13: ffff88825c0e6178 R14: ffffffff82339400 R15: 0000000000000000 <4>[ 353.866086] FS: 00007f71e4e18980(0000) GS:ffff888277f00000(0000) knlGS:0000000000000000 <4>[ 353.866102] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 <4>[ 353.866113] CR2: 000055cd8d020a90 CR3: 0000000269ca8000 CR4: 00000000003406e0 <4>[ 353.866127] Call Trace: <4>[ 353.866141] remove_conflicting_framebuffers+0x2d/0xc0 <4>[ 353.866244] i915_driver_load+0x845/0x1550 [i915] <4>[ 353.866262] ? _raw_spin_unlock_irqrestore+0x4c/0x60 <4>[ 353.866280] ? lockdep_hardirqs_on+0xe0/0x1b0 <4>[ 353.866356] i915_pci_probe+0x29/0xa0 [i915] <4>[ 353.866369] pci_device_probe+0xa1/0x130 <4>[ 353.866383] really_probe+0xf3/0x3e0 <4>[ 353.866394] driver_probe_device+0x10a/0x120 <4>[ 353.866406] __driver_attach+0xdb/0x100 <4>[ 353.866416] ? driver_probe_device+0x120/0x120 <4>[ 353.866427] ? driver_probe_device+0x120/0x120 <4>[ 353.866438] bus_for_each_dev+0x74/0xc0 <4>[ 353.866449] bus_add_driver+0x15f/0x250 <4>[ 353.866460] ? 0xffffffffa0730000 <4>[ 353.866470] driver_register+0x56/0xe0 <4>[ 353.866479] ? 0xffffffffa0730000 <4>[ 353.866489] do_one_initcall+0x58/0x2e0 <4>[ 353.866501] ? do_init_module+0x1d/0x1ea <4>[ 353.866512] ? rcu_read_lock_sched_held+0x6f/0x80 <4>[ 353.866525] ? kmem_cache_alloc_trace+0x264/0x290 <4>[ 353.866538] do_init_module+0x56/0x1ea <4>[ 353.866549] load_module+0x2714/0x29f0 <4>[ 353.866570] ? __se_sys_finit_module+0xd3/0xf0 <4>[ 353.866581] __se_sys_finit_module+0xd3/0xf0 <4>[ 353.866597] do_syscall_64+0x55/0x190 <4>[ 353.866609] entry_SYSCALL_64_after_hwframe+0x49/0xbe <4>[ 353.866621] RIP: 0033:0x7f71e44c1839 <4>[ 353.866631] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 1f f6 2c 00 f7 d8 64 89 01 48 <4>[ 353.866662] RSP: 002b:00007fff86e10c38 EFLAGS: 00000246 ORIG_RAX: 0000000000000139 <4>[ 353.866678] RAX: ffffffffffffffda RBX: 0000563533cef0b0 RCX: 00007f71e44c1839 <4>[ 353.866691] RDX: 0000000000000000 RSI: 0000563533ce91f0 RDI: 0000000000000005 <4>[ 353.866705] RBP: 0000563533ce91f0 R08: 0000000000000000 R09: 0000000000000000 <4>[ 353.866718] R10: 0000000000000005 R11: 0000000000000246 R12: 0000000000000000 <4>[ 353.866732] R13: 0000563533cece30 R14: 0000000000000020 R15: 0000000000000016 <4>[ 353.866751] Modules linked in: i915(+) vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel i2c_i801 lpc_ich r8169 snd_hda_codec snd_hwdep snd_hda_core mei_me snd_pcm pinctrl_broxton mei pinctrl_intel prime_numbers [last unloaded: i915]
I'm going to test a patch today, looks like some of the fb apertures are 0. For which reason I can't say, however, I guess it is still worth checking if its zero so that we at least don't crash in that case.
(In reply to Stanislav Lisovskiy from comment #23) > (In reply to Francesco Balestrieri from comment #22) > > Stan, did you figure out anything from the latest logs? > > There is a NULL pointer deref in do_remove_conflicting_framebuffers > function: That's a known-use-after-free. You can't guarantee that you even see a NULL pointer as its value depends on what else gets written by a third party.
(In reply to Chris Wilson from comment #25) > (In reply to Stanislav Lisovskiy from comment #23) > > (In reply to Francesco Balestrieri from comment #22) > > > Stan, did you figure out anything from the latest logs? > > > > There is a NULL pointer deref in do_remove_conflicting_framebuffers > > function: > > That's a known-use-after-free. You can't guarantee that you even see a NULL > pointer as its value depends on what else gets written by a third party. Ok, is there any patch available elsewhere?
(In reply to Stanislav Lisovskiy from comment #26) > (In reply to Chris Wilson from comment #25) > > (In reply to Stanislav Lisovskiy from comment #23) > > > (In reply to Francesco Balestrieri from comment #22) > > > > Stan, did you figure out anything from the latest logs? > > > > > > There is a NULL pointer deref in do_remove_conflicting_framebuffers > > > function: > > > > That's a known-use-after-free. You can't guarantee that you even see a NULL > > pointer as its value depends on what else gets written by a third party. > > Ok, is there any patch available elsewhere? Nope, we are hoping for a kasan hit to tell us where the use-after-free emanated from.
(In reply to Chris Wilson from comment #27) > (In reply to Stanislav Lisovskiy from comment #26) > > (In reply to Chris Wilson from comment #25) > > > (In reply to Stanislav Lisovskiy from comment #23) > > > > (In reply to Francesco Balestrieri from comment #22) > > > > > Stan, did you figure out anything from the latest logs? > > > > > > > > There is a NULL pointer deref in do_remove_conflicting_framebuffers > > > > function: > > > > > > That's a known-use-after-free. You can't guarantee that you even see a NULL > > > pointer as its value depends on what else gets written by a third party. > > > > Ok, is there any patch available elsewhere? > > Nope, we are hoping for a kasan hit to tell us where the use-after-free > emanated from. We could try also poisoning registered_fb[i] somehow to mark and determine when it was freed.
This bug has too many completely unrelated issues caught up in it.
(In reply to Chris Wilson from comment #29) > This bug has too many completely unrelated issues caught up in it. Agree. With such kind of filtering it's not going to be closed ever + it is very hard to track completely different issues in it.
(In reply to Stanislav Lisovskiy from comment #30) > (In reply to Chris Wilson from comment #29) > > This bug has too many completely unrelated issues caught up in it. > > Agree. With such kind of filtering it's not going to be closed ever + it is > very hard to track completely different issues in it. I will start splitting the giant incomplete bugs into sub-bugs, when it seems tests are easily reproducing the issue.
A CI Bug Log filter associated to this bug has been updated: {- fi-bxt-j4205: igt@runner@aborted - fail - Previous test: i915_module_load \(reload-with-fault-injection\) -} {+ fi-bxt-j4205: igt@runner@aborted - fail - Previous test: (i915_module_load \(reload-with-fault-injection\)|i915_selftest (mock_timelines)) +} New failures caught by the filter: * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6968/shard-apl4/igt@runner@aborted.html * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6969/shard-apl5/igt@runner@aborted.html * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6970/shard-apl6/igt@runner@aborted.html * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6971/shard-apl7/igt@runner@aborted.html
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.