[CI][HSW only] igt@* - Incomplete - timeout/system hang
Submitted by Marta Löfstedt @marta
Assigned to Francesco Balestrieri @baleboy
Link to original bug (#103540)
Description
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3307/shard-hsw5/igt@gem_softpin@noreloc-S3.html
First dmesg:
<5>[ 410.029726] owatch: Using watchdog device /dev/watchdog0
<5>[ 410.029792] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 410.030293] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
Last dmesg:
<7>[ 630.912561] [IGT] gem_softpin: starting subtest noreloc-S3
<6>[ 631.934079] PM: suspend entry (deep)
<6>[ 631.934082] PM: Syncing filesystems ... done.
run.log
[32/73] skip: 11, pass: 20, fail: 1 |
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3307@shard-hsw5 : FAILURE
CI_IGT_test runtime 625 seconds
Blocking
Activity
added CI GPU hang feature: display/Other platform: HSW priority::medium severity::normal + 1 deleted label
@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_6978/shard-hsw4/igt@kms_cursor_legacy@all-pipes-torture-bo.html
First dmesg:
<5>[ 514.464286] owatch: Using watchdog device /dev/watchdog0
<5>[ 514.464338] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 514.464680] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
Last dmesg:
<7>[ 732.865088] [IGT] gem_exec_parallel: exiting, ret=0
<7>[ 732.954598] [IGT] kms_cursor_legacy: executing
run.log:
[10/72] skip: 3, pass: 7 -
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test Patchwork_6978@shard-hsw4 : FAILURE
CI_IGT_test runtime 287 seconds
Looks like system hang.@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_3993/shard-hsw1/igt@kms_flip@vblank-vs-dpms-suspend.html
dmesg:
<5>[ 4868.543800] owatch: Using watchdog device /dev/watchdog0
<5>[ 4868.543854] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 4868.544357] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
...
<7>[ 4897.089326] [drm:intel_power_well_disable [i915]] disabling always-on
<6>[ 4897.241855] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
<6>[ 4897.282825] ata2.00: configured for UDMA/133
run.log:
running: igt/kms_flip/vblank-vs-suspend
[18/73] skip: 11, pass: 7 -
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3364/shard-hsw1/12 : FAILURE
CI_IGT_test runtime 276 seconds
Rebooting shard-hsw1@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3419/shard-hsw8/igt@kms_vblank@wait-forked.html
this caught my eye in dmesg:
<7>[ 513.201488] [IGT] gem_exec_suspend: executing
<4>[ 513.213950] Setting dangerous option reset - tainting kernel
<7>[ 513.214808] [IGT] gem_exec_suspend: starting subtest basic-S3
...
<7>[ 513.798733] [drm:i915_check_and_clear_faults [i915]] Unexpected fault
Addr: 0x00000000
Address space: PPGTT
Source ID: 24
Type: 2
...
<7>[ 513.845966] [drm:sandybridge_pcode_write [i915]] warning: pcode (write of 0x00000011 to mbox 11) mailbox access failed for hsw_write_dcomp [i915]: -6
...
However this incomplete is way later:
<4>[ 736.408137] Setting dangerous option reset - tainting kernel
<7>[ 736.409030] [IGT] gem_exec_async: starting subtest concurrent-writes-bsd
<7>[ 736.411044] [IGT] gem_exec_async: exiting, ret=0
run.log has no indication on timeout.@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3429/shard-hsw5/igt@kms_plane@plane-panning-bottom-right-suspend-pipe-a-planes.html
dmesg:
<5>[ 17.625788] owatch: Using watchdog device /dev/watchdog0
<5>[ 17.625904] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 17.626792] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
...
<7>[ 116.022862] [drm:gmbus_xfer [i915]] GMBUS [i915 gmbus dpd] NAK for addr: 0040 w(1)
<7>[ 116.022867] [drm:drm_dp_dual_mode_detect] DP dual mode HDMI ID: (err -6)
<7>[ 116.022873] [drm:drm_helper_hpd_irq_event] [CONNECTOR:72:HDMI-A-3] status updated from disconnected to disconnected
Followed by "stray"
run.log:
running: igt/kms_plane/plane-panning-bottom-right-suspend-pipe-a-planes
[52/75] skip: 24, pass: 28 |
FATAL: command execution failed
java.io.EOFException
...
Finished: FAILURE
Completed CI_IGT_test CI_DRM_3429/shard-hsw5/0 : FAILURE
CI_IGT_test runtime 224 seconds
Rebooting shard-hsw5@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3445/shard-hsw3/igt@kms_flip@vblank-vs-dpms-suspend-interruptible.html
Note none of the pstore appear to match dmesg timestamps
dmesg:
<7>[ 127.131153] [drm:verify_connector_state.isra.77 [i915]] [CONNECTOR:58:VGA-1]
<7>[ 127.131219] [drm:intel_atomic_commit_tail [i915]] [CRTC:37:pipe A]
<7>[ 127.131289] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<6>[ 127.182789] PM: suspend entry (deep)
run.log:
Finished: FAILURE
Completed CI_IGT_test CI_DRM_3445/shard-hsw3/2 : FAILURE
CI_IGT_test runtime 547 seconds
Rebooting shard-hsw3@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3450/shard-hsw4/igt@kms_frontbuffer_tracking@fbc-suspend.html
run.log indicates network issue:
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3450/shard-hsw4/run3.log@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4037/shard-hsw4/igt@kms_cursor_crc@cursor-64x64-suspend.html
last dmesg:
<7>[ 6527.477151] [drm:intel_crt_detect [i915]] CRT detected via hotplug
<6>[ 6527.689894] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
<6>[ 6527.713458] ata3.00: configured for UDMA/133
run.log:
[23/75] skip: 12, pass: 11 -
running: igt/kms_cursor_crc/cursor-64x64-suspend
[23/75] skip: 12, pass: 11 \
FATAL: command execution failed
java.io.EOFException
...
Finished: FAILURE
Completed CI_IGT_test CI_DRM_3452/shard-hsw4/11 : FAILURE
CI_IGT_test runtime 256 seconds
Rebooting shard-hsw4@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3457/shard-hsw8/igt@gem_exec_suspend@basic-s3.html
last dmesg:
<7>[ 809.762818] [IGT] gem_exec_suspend: executing
<4>[ 809.777894] Setting dangerous option reset - tainting kernel
<7>[ 809.778786] [IGT] gem_exec_suspend: starting subtest basic-S3
run.log:
pass: igt/gem_exec_suspend/basic-s3
[17/75] skip: 8, pass: 9 |
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3457/shard-hsw8/29 : FAILURE
CI_IGT_test runtime 183 seconds
Rebooting shard-hsw8@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3467/shard-hsw8/igt@gem_eio@hibernate.html
last dmesg:
<7>[ 79.416629] [IGT] gem_eio: executing
<4>[ 79.439221] Setting dangerous option reset - tainting kernel
<6>[ 79.441597] [drm] GPU HANG: ecode 7:0:0x87f3fffe, reason: Manually setting wedged to 18446744073709551615, action: reset
<6>[ 79.441732] [drm] GPU hangs can indicate a bug anywhere in the entire gfx stack, including userspace.
<6>[ 79.441736] [drm] Please file a new bug report on bugs.freedesktop.org against DRI -> DRM/Intel
<6>[ 79.441739] [drm] drm/i915 developers can then reassign to the right component if it's not a kernel issue.
<6>[ 79.441743] [drm] The gpu crash dump is required to analyze gpu hangs, so please always attach it.
<6>[ 79.441747] [drm] GPU crash dump saved to /sys/class/drm/card0/error
<7>[ 79.442619] [drm:i915_reset_device [i915]] resetting chip
<5>[ 79.442736] i915 0000:00:02.0: Resetting chip after gpu hang
<7>[ 79.443960] [drm:init_workarounds_ring [i915]] rcs0: Number of context specific w/a: 0
<7>[ 79.446291] [IGT] gem_eio: starting subtest hibernate
<4>[ 79.446354] Setting dangerous option reset - tainting kernel
<7>[ 79.446936] [drm:i915_reset_device [i915]] resetting chip
<5>[ 79.447648] i915 0000:00:02.0: Resetting chip after gpu hang
<7>[ 79.448025] [drm:i915_reset [i915]] GPU reset disabled
<6>[ 79.467560] PM: hibernation entry
run.log:
pass: igt/gem_eio/hibernate
[24/75] skip: 12, pass: 12 <br> FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3467/shard-hsw8/19 : FAILURE
CI_IGT_test runtime 224 seconds
Rebooting shard-hsw8@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4041/shard-hsw1/igt@gem_exec_create@basic.html
this is all in dmesg:
<5>[ 17.780372] owatch: Using watchdog device /dev/watchdog0
<5>[ 17.780484] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[ 17.781154] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
<6>[ 20.535043] Console: switching to colour dummy device 80x25
<7>[ 20.535136] [IGT] gem_bad_reloc: executing
<7>[ 20.572327] [IGT] gem_bad_reloc: starting subtest negative-reloc-bltcopy
<7>[ 20.675313] [IGT] gem_bad_reloc: exiting, ret=0
<7>[ 20.796516] [IGT] gem_exec_create: executing
<4>[ 20.831229] Setting dangerous option reset - tainting kernel
<7>[ 20.831920] [IGT] gem_exec_create: starting subtest basic
run.log doesn't show result on any tests:
Completed CI_IGT_test CI_DRM_3470/shard-hsw1/32 : FAILURE
CI_IGT_test runtime 15 seconds
Rebooting shard-hsw1
network issue folloed by Jenkins reboot?@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4042/shard-hsw5/igt@kms_cursor_crc@cursor-128x128-offscreen.html
last dmesg:
<7>[ 304.471679] [drm:haswell_crtc_enable [i915]] iCLKIP clock: found settings for 65000KHz refresh rate: auxdiv=0, divsel=27, phasedir=0, phaseinc=22
<7>[ 304.521857] [drm:verify_connector_state.isra.77 [i915]] [CONNECTOR:58:VGA-1]
<7>[ 304.521882] [drm:intel_atomic_commit_tail [i915]] [CRTC:37:pipe A]
<7>[ 304.521938] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<7>[ 304.521962] [drm:intel_atomic_commit_tail [i915]] [CRTC:57:pipe C]
Followed by "stray"
run.log:
[53/75] skip: 22, pass: 31 |
running: igt/gem_tiled_swapping/non-threaded
[53/75] skip: 22, pass: 31 /
FATAL: command execution failed
java.io.EOFException
...
Finished: FAILURE
Completed CI_IGT_test CI_DRM_3473/shard-hsw5/11 : FAILURE
CI_IGT_test runtime 430 seconds
Rebooting shard-hsw5
mismatch between run.log and results on the affected subtest indicates Jenkins reboot.@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3476/shard-hsw4/igt@kms_flip@flip-vs-panning.html
dmesg:
<7>[ 266.501168] [IGT] drv_suspend: starting subtest fence-restore-untiled-hibernate
<6>[ 266.564484] PM: hibernation entry
<6>[ 266.564781] PM: Syncing filesystems ...
<6>[ 266.564877] PM: done.
<6>[ 266.564879] Freezing user space processes ...
<3>[ 286.570138] Freezing of tasks failed after 20.005 seconds (5 tasks refusing to freeze, wq_busy=0):
<6>[ 286.570253] java D 0 1051 1015 0x00000004
<4>[ 286.570287] Call Trace:
<4>[ 286.570314] ? __schedule+0x3c3/0xaf0
<4>[ 286.570331] ? wait_on_page_bit_killable+0xff/0x160
<4>[ 286.570351] schedule+0x37/0x90
<4>[ 286.570366] io_schedule+0xd/0x30
<4>[ 286.570377] wait_on_page_bit_killable+0x10b/0x160
<4>[ 286.570397] ? add_to_page_cache_lru+0xc0/0xc0
<4>[ 286.570417] __lock_page_or_retry+0x9c/0xe0
<4>[ 286.570432] do_swap_page+0x57f/0x8f0
<4>[ 286.570452] ? __lock_acquire+0x42c/0x15a0
<4>[ 286.570471] __handle_mm_fault+0x83b/0xe40
<4>[ 286.570509] handle_mm_fault+0x14f/0x2f0
<4>[ 286.570525] __do_page_fault+0x2d1/0x560
<4>[ 286.570552] page_fault+0x22/0x30
<4>[ 286.570562] RIP: 0033:0x7f58dd0231d9
<4>[ 286.570570] RSP: 002b:00007f58f5d2e798 EFLAGS: 00010246
<4>[ 286.570584] RAX: 0000000000000000 RBX: 00007f58dc800a00 RCX: 00000007731182a8
<4>[ 286.570592] RDX: 0000000090500003 RSI: 0000000000000005 RDI: 00007f58ec00a000
<4>[ 286.570599] RBP: 00007f58f5d2e808 R08: 0000000000000000 R09: 0000000000000000
<4>[ 286.570607] R10: 00007f58f4f0d8c0 R11: 0000000000000206 R12: 0000000000000000
<4>[ 286.570614] R13: 00007f58f5d2e7a0 R14: 00007f58f5d2e818 R15: 00007f58ec00a000
<6>[ 286.570652] java D 0 1070 1015 0x00000004
run.log doesn't match results:
running: igt/gem_tiled_swapping/non-threaded
[53/75] skip: 22, pass: 31 /
FATAL: command execution failed
indicating another suspected Jenkins reboot.@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4052/shard-hsw7/igt@gem_exec_flush@basic-wb-pro-default.html
run.log doesn't match results:
running: igt/gem_tiled_swapping/non-threaded
[30/75] skip: 11, pass: 19 -
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3487/shard-hsw7/29 : FAILURE
CI_IGT_test runtime 211 seconds
Rebooting shard-hsw7
this has similar pattern
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4050/shard-hsw3/igt@kms_flip@absolute-wf_vblank.html
last test in run.log is:
running: igt/gem_tiled_swapping/non-threaded
[13/76] skip: 4, pass: 9 /
FATAL: command execution failed@martasaid:These two also has igt@gem_tiled_swapping@non-threaded as last test in run.log, however the incomplete is linked to tests running after.
https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4057/shard-hsw6/igt@gem_exec_flush@basic-uc-set-default.html
<7>[ 24.081678] [IGT] gem_tiled_swapping: starting subtest non-threaded
<5>[ 24.300979] random: crng init done
<6>[ 51.508286] Purging GPU memory, 50176 pages freed, 935 pages still pinned.
<6>[ 55.038871] Purging GPU memory, 50432 pages freed, 935 pages still pinned.
<7>[ 55.768070] [IGT] gem_tiled_swapping: exiting, ret=0
<7>[ 56.662909] [IGT] gem_exec_flush: executing
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3499/shard-hsw6/igt@perf_pmu@render-node-busy-vcs0.html
<7>[ 14.284709] [IGT] gem_tiled_swapping: executing
<7>[ 15.804253] [IGT] gem_tiled_swapping: starting subtest non-threaded
<5>[ 15.877672] random: crng init done
<6>[ 37.606221] Purging GPU memory, 41984 pages freed, 935 pages still pinned.
<6>[ 41.130918] Purging GPU memory, 42496 pages freed, 935 pages still pinned.
<3>[ 41.130930] 0 and 256 pages still available in the bound and unbound GPU page lists.
<6>[ 43.888349] Purging GPU memory, 42752 pages freed, 935 pages still pinned.
<6>[ 47.333043] Purging GPU memory, 42752 pages freed, 935 pages still pinned.
<6>[ 50.727754] Purging GPU memory, 42496 pages freed, 935 pages still pinned.
<7>[ 51.330125] [IGT] gem_tiled_swapping: exiting, ret=0
<7>[ 52.321979] [IGT] perf_pmu: executing
Maybe this should be moved to a separate bug.@martasaid:Note I moved the igt@gem_tiled_swapping@non-threaded related once to bug 104218
@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4058/shard-hsw7/igt@kms_flip@vblank-vs-modeset-suspend-interruptible.html
last dmesg:
<7>[ 33.026621] [drm:intel_atomic_commit_tail [i915]] [CRTC:37:pipe A]
<6>[ 33.187176] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
<6>[ 33.206205] ata3.00: configured for UDMA/133
Folloed by "stray"
run.log:
running: igt/kms_flip/vblank-vs-modeset-suspend-interruptible
[05/76] pass: 5 /
FATAL: command execution failed
java.io.EOFException
...
Completed CI_IGT_test CI_DRM_3499/shard-hsw7/12 : FAILURE
CI_IGT_test runtime 183 seconds
Rebooting shard-hsw7@martasaid:@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3546/shard-hsw3/igt@gem_eio@in-flight-external.html
<7>[ 121.567706] [drm:i915_reset_device [i915]] resetting chip
<5>[ 121.567799] i915 0000:00:02.0: Resetting chip after gpu hang
<7>[ 121.568746] [drm:sandybridge_pcode_read [i915]] warning: pcode (read from mbox 5) mailbox access failed for intel_enable_gt_powersave [i915]: -6
<7>[ 121.568983] [drm:init_workarounds_ring [i915]] rcs0: Number of context specific w/a: 0
<14>[ 121.570147] [IGT] gem_eio: starting subtest in-flight-external
<4>[ 121.571822] Setting dangerous option reset - tainting kernel
<3>[ 123.921863] INFO: task kswapd0:80 blocked for more than 60 seconds.
<3>[ 123.921887] Tainted: G U 4.15.0-rc4-CI-CI_DRM_3546+ #1 (moved)
<3>[ 123.921905] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 123.921926] kswapd0 D 0 80 2 0x80000000
<4>[ 123.921931] Call Trace:
<4>[ 123.921940] ? __schedule+0x3c3/0xaf0
<4>[ 123.921947] schedule+0x37/0x90
<4>[ 123.921951] io_schedule+0xd/0x30
<4>[ 123.921955] __lock_page+0x107/0x130
<4>[ 123.921960] ? add_to_page_cache_lru+0xc0/0xc0
<4>[ 123.921967] deferred_split_scan+0x25a/0x2b0
<4>[ 123.921975] shrink_slab.part.17+0x201/0x5d0
<4>[ 123.921986] shrink_node+0x2fd/0x310
<4>[ 123.921993] kswapd+0x31c/0x910
<4>[ 123.922004] kthread+0xfb/0x130
<4>[ 123.922007] ? mem_cgroup_shrink_node+0x300/0x300
<4>[ 123.922009] ? _kthread_create_on_node+0x30/0x30
<4>[ 123.922015] ret_from_fork+0x24/0x30
<4>[ 123.922023]
<4>[ 123.922023] Showing all locks held in the system:
<4>[ 123.922028] 2 locks held by khungtaskd/67:
<4>[ 123.922032] #0: (rcu_read_lock){....}, at: [<00000000af589633>] watchdog+0x9b/0x5e0
<4>[ 123.922043] #1 (moved): (tasklist_lock){.+.+}, at: [<000000004e9aafe9>] debug_show_all_locks+0x37/0x190
<4>[ 123.922056] 1 lock held by kswapd0/80:
<4>[ 123.922057] #0: (shrinker_rwsem)++, at: [<000000002678c2e8>] shrink_slab.part.17+0x46/0x5d0
<4>[ 123.922075] 1 lock held by in:imklog/571:
<4>[ 123.922076] #0: (&f->f_pos_lock){+.+.}, at: [<00000000044eb2e1>] __fdget_pos+0x3a/0x50
<4>[ 123.922097] 1 lock held by dmesg/1154:
<4>[ 123.922099] #0: (&user->lock){+.+.}, at: [<00000000b572ad75>] devkmsg_read+0x35/0x2f0
<4>[ 123.922111]
<4>[ 123.922113] =============================================
<4>[ 123.922113]
<4>[ 123.922116] NMI backtrace for cpu 0
<4>[ 123.922118] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc4-CI-CI_DRM_3546+ #1 (moved)
<4>[ 123.922120] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 123.922122] Call Trace:
<4>[ 123.922127] dump_stack+0x5f/0x86
<4>[ 123.922132] nmi_cpu_backtrace+0xb4/0xc0
<4>[ 123.922137] ? lapic_can_unplug_cpu+0x90/0x90
<4>[ 123.922140] nmi_trigger_cpumask_backtrace+0xb8/0xf0
<4>[ 123.922144] watchdog+0x43e/0x5e0
<4>[ 123.922149] kthread+0xfb/0x130
<4>[ 123.922151] ? reset_hung_task_detector+0x10/0x10
<4>[ 123.922154] ? _kthread_create_on_node+0x30/0x30
<4>[ 123.922157] ret_from_fork+0x24/0x30
<6>[ 123.922166] Sending NMI from CPU 0 to CPUs 1-7:
<4>[ 123.922175] NMI backtrace for cpu 4 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922189] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922192] NMI backtrace for cpu 3 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922195] NMI backtrace for cpu 1 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922199] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922212] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120
<4>[ 123.922218] NMI backtrace for cpu 5 skipped: idling at intel_idle+0x6f/0x120
<0>[ 123.923181] Kernel panic - not syncing: hung_task: blocked tasks
<4>[ 123.923221] CPU: 0 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc4-CI-CI_DRM_3546+ #1 (moved)
<4>[ 123.923274] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 123.923317] Call Trace:
<4>[ 123.923340] dump_stack+0x5f/0x86
<4>[ 123.923367] panic+0xcf/0x20d
<4>[ 123.923401] watchdog+0x44a/0x5e0
<4>[ 123.923431] kthread+0xfb/0x130
<4>[ 123.923455] ? reset_hung_task_detector+0x10/0x10
<4>[ 123.923485] ? _kthread_create_on_node+0x30/0x30
<4>[ 123.923519] ret_from_fork+0x24/0x30
<0>[ 123.924041] Dumping ftrace buffer:
<0>[ 123.924117] (ftrace buffer empty)
<0>[ 123.924131] Kernel Offset: disabled@martasaid:https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3552/shard-hsw4/igt@kms_flip@flip-vs-fences.html
<7>[ 179.489599] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<3>[ 185.394157] INFO: task kswapd0:80 blocked for more than 60 seconds.
<3>[ 185.394169] Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<3>[ 185.394171] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 185.394174] kswapd0 D 0 80 2 0x80000000
<4>[ 185.394179] Call Trace:
<4>[ 185.394188] ? __schedule+0x3c3/0xaf0
<4>[ 185.394196] schedule+0x37/0x90
<4>[ 185.394200] io_schedule+0xd/0x30
<4>[ 185.394204] __lock_page+0x107/0x130
<4>[ 185.394208] ? add_to_page_cache_lru+0xc0/0xc0
<4>[ 185.394215] deferred_split_scan+0x25a/0x2b0
<4>[ 185.394222] shrink_slab.part.17+0x201/0x5d0
<4>[ 185.394234] shrink_node+0x2fd/0x310
<4>[ 185.394242] kswapd+0x31c/0x910
<4>[ 185.394254] kthread+0xfb/0x130
<4>[ 185.394256] ? mem_cgroup_shrink_node+0x300/0x300
<4>[ 185.394258] ? _kthread_create_on_node+0x30/0x30
<4>[ 185.394263] ret_from_fork+0x24/0x30
<4>[ 185.394273]
<4>[ 185.394273] Showing all locks held in the system:
<4>[ 185.394284] 2 locks held by khungtaskd/67:
<4>[ 185.394289] #0: (rcu_read_lock){....}, at: [<00000000731ae36a>] watchdog+0x9b/0x5e0
<4>[ 185.394300] #1 (moved): (tasklist_lock){.+.+}, at: [<00000000a8a05d2a>] debug_show_all_locks+0x37/0x190
<4>[ 185.394312] 1 lock held by kswapd0/80:
<4>[ 185.394314] #0: (shrinker_rwsem)++, at: [<00000000a5d771df>] shrink_slab.part.17+0x46/0x5d0
<4>[ 185.394338] 3 locks held by kworker/3:2/223:
<4>[ 185.394339] #0: ((wq_completion)"events"){+.+.}, at: [<000000007bac85a9>] process_one_work+0x191/0x640
<4>[ 185.394349] #1 (moved): ((work_completion)(&i915->mm.free_work)){+.+.}, at: [<000000007bac85a9>] process_one_work+0x191/0x640
<4>[ 185.394358] #2: (&dev->struct_mutex){+.+.}, at: [<00000000a6527aa3>] __i915_gem_free_objects+0x7c/0x540 [i915]
<4>[ 185.394404] 1 lock held by in:imklog/572:
<4>[ 185.394405] #0: (&f->f_pos_lock){+.+.}, at: [<00000000a64b4995>] __fdget_pos+0x3a/0x50
<4>[ 185.394425] 1 lock held by dmesg/1146:
<4>[ 185.394427] #0: (&user->lock){+.+.}, at: [<0000000098ba0f15>] devkmsg_read+0x35/0x2f0
<4>[ 185.394438]
<4>[ 185.394440] =============================================
<4>[ 185.394440]
<4>[ 185.394442] NMI backtrace for cpu 1
<4>[ 185.394445] CPU: 1 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.394447] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.394448] Call Trace:
<4>[ 185.394454] dump_stack+0x5f/0x86
<4>[ 185.394457] nmi_cpu_backtrace+0xb4/0xc0
<4>[ 185.394462] ? lapic_can_unplug_cpu+0x90/0x90
<4>[ 185.394465] nmi_trigger_cpumask_backtrace+0xb8/0xf0
<4>[ 185.394469] watchdog+0x43e/0x5e0
<4>[ 185.394474] kthread+0xfb/0x130
<4>[ 185.394477] ? reset_hung_task_detector+0x10/0x10
<4>[ 185.394479] ? _kthread_create_on_node+0x30/0x30
<4>[ 185.394483] ret_from_fork+0x24/0x30
<6>[ 185.394493] Sending NMI from CPU 1 to CPUs 0,2-7:
<4>[ 185.394499] NMI backtrace for cpu 0
<4>[ 185.394510] CPU: 0 PID: 983 Comm: java Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.394511] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.394513] RIP: 0010:check_flags.part.25+0x8f/0x1b0
<4>[ 185.394513] RSP: 0018:ffffc900007afe58 EFLAGS: 00000046
<4>[ 185.394514] RAX: 0000000080000002 RBX: ffff88041fa1ab40 RCX: 0000000000000001
<4>[ 185.394515] RDX: ffffffff818b64b3 RSI: 0000000000000001 RDI: 0000000000000086
<4>[ 185.394515] RBP: ffff88041fa1ab58 R08: 0000000000000000 R09: 0000000000000001
<4>[ 185.394516] R10: 0000000000000000 R11: ffffffff810b553f R12: ffffffff818b64b3
<4>[ 185.394516] R13: 0000000000000086 R14: ffffc900007afed0 R15: ffff880403ada7c0
<4>[ 185.394517] FS: 00007f3b11ce4700(0000) GS:ffff88041fa00000(0000) knlGS:0000000000000000
<4>[ 185.394518] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 185.394518] CR2: 00007f4c6bee1000 CR3: 0000000403b16002 CR4: 00000000001606f0
<4>[ 185.394519] Call Trace:
<4>[ 185.394520] lock_release+0x200/0x300
<4>[ 185.394522] _raw_spin_unlock_irq+0x17/0x50
<4>[ 185.394524] __schedule+0x8b3/0xaf0
<4>[ 185.394526] schedule+0x37/0x90
<4>[ 185.394527] sys_sched_yield+0x8c/0xa0
<4>[ 185.394529] entry_SYSCALL_64_fastpath+0x1c/0x89
<4>[ 185.394529] RIP: 0033:0x7f3b383d50a7
<4>[ 185.394530] RSP: 002b:00007f3b11ce3c78 EFLAGS: 00000297 ORIG_RAX: 0000000000000018
<4>[ 185.394531] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f3b383d50a7
<4>[ 185.394531] RDX: 00007f3b37c56170 RSI: 00007f3b2162da80 RDI: 00000000066c25c8
<4>[ 185.394532] RBP: 00007f3b11ce3d00 R08: 0000000000000000 R09: 00007f3b37c95800
<4>[ 185.394532] R10: 0000000000000001 R11: 0000000000000297 R12: 00007f3b30007560
<4>[ 185.394533] R13: 00000000066c1292 R14: 0000000000000001 R15: 00000000066c1292
<4>[ 185.394534] Code: 85 db 75 ae e8 e3 3c 37 00 85 c0 74 10 44 8b 15 c0 73 1d 02 45 85 d2 0f 84 f7 00 00 00 48 c7 c7 70 6f c7 81 e8 b8 2f 01 00 eb 87<8b>35 83 72 17 02 85 f6 75 a0 65 48 8b 04 25 80 c5 00 00 8b 88
<4>[ 185.394549] NMI backtrace for cpu 4
<4>[ 185.394550] CPU: 4 PID: 63 Comm: kworker/4:1 Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.394551] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.394553] Workqueue: events delayed_fput
<4>[ 185.394555] RIP: 0010:check_preemption_disabled+0x2/0xe0
<4>[ 185.394556] RSP: 0018:ffffc9000025fb00 EFLAGS: 00000006
<4>[ 185.394557] RAX: ffffffffffffffc0 RBX: ffffffffffffffff RCX: 0000000000000001
<4>[ 185.394557] RDX: ffffffffffffffff RSI: ffffffff81d12ee1 RDI: ffffffff81cb850e
<4>[ 185.394558] RBP: 000000000001f9bf R08: ffff88040c8d0940 R09: 0000000044e5fc34
<4>[ 185.394558] R10: ffffc9000025fb30 R11: 0000000000000002 R12: 000000000000000e
<4>[ 185.394559] R13: 000000000001f9b0 R14: ffffffffffffffff R15: ffffffff81ef5240
<4>[ 185.394560] FS: 0000000000000000(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[ 185.394560] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 185.394561] CR2: 00007fdb0dd54390 CR3: 0000000003e0f005 CR4: 00000000001606e0
<4>[ 185.394561] Call Trace:
<4>[ 185.394564] __mod_node_page_state+0x64/0xa0
<4>[ 185.394566] unaccount_page_cache_page+0xa4/0x260
<4>[ 185.394567] __delete_from_page_cache+0x3f/0x240
<4>[ 185.394569] delete_from_page_cache+0x40/0x70
<4>[ 185.394570] truncate_inode_page+0x1d/0x30
<4>[ 185.394572] shmem_undo_range+0x46d/0x990
<4>[ 185.394575] shmem_truncate_range+0x11/0x30
<4>[ 185.394576] shmem_evict_inode+0xb8/0x1a0
<4>[ 185.394578] evict+0xb7/0x1b0
<4>[ 185.394580] __dentry_kill+0xb2/0x170
<4>[ 185.394581] __fput+0x13b/0x1e0
<4>[ 185.394583] delayed_fput+0x17/0x30
<4>[ 185.394585] process_one_work+0x215/0x640
<4>[ 185.394587] worker_thread+0x48/0x3a0
<4>[ 185.394588] ? _raw_spin_unlock_irqrestore+0x4c/0x60
<4>[ 185.394589] kthread+0xfb/0x130
<4>[ 185.394591] ? process_one_work+0x640/0x640
<4>[ 185.394591] ? _kthread_create_on_node+0x30/0x30
<4>[ 185.394593] ret_from_fork+0x24/0x30
<4>[ 185.394594] Code: 00 00 00 41 c7 44 24 08 00 00 00 00 e9 19 ff ff ff 48 89 e8 4c 8b 34 24 48 83 c8 01 e9 09 ff ff ff 90 90 90 90 90 90 90 90 41 55<41>54 65 8b 05 25 06 bb 7e 55 53 65 8b 1d 3c e2 ba 7e a9 ff ff
<4>[ 185.394611] NMI backtrace for cpu 3
<4>[ 185.394612] CPU: 3 PID: 3921 Comm: kms_flip Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.394612] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.394614] RIP: 0010:lock_acquire+0x27/0x200
<4>[ 185.394615] RSP: 0018:ffffc9000090f810 EFLAGS: 00000246
<4>[ 185.394616] RAX: ffff8803fc8d4f40 RBX: 0000000000000001 RCX: 0000000000000002
<4>[ 185.394616] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff81e443c0
<4>[ 185.394617] RBP: ffffc9000090f860 R08: 0000000000000000 R09: 0000000000000000
<4>[ 185.394617] R10: 0000000000000000 R11: 0000000000000001 R12: ffffc9000090f928
<4>[ 185.394618] R13: ffff88040a162740 R14: 0000000000000000 R15: 0000000000000000
<4>[ 185.394618] FS: 00007fc1054b5a40(0000) GS:ffff88041fac0000(0000) knlGS:0000000000000000
<4>[ 185.394619] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 185.394619] CR2: 00007f366c00a350 CR3: 000000040956a004 CR4: 00000000001606e0
<4>[ 185.394620] Call Trace:
<4>[ 185.394623] get_mem_cgroup_from_mm+0x33/0x2e0
<4>[ 185.394624] ? mem_cgroup_from_task+0x90/0x90
<4>[ 185.394625] mem_cgroup_try_charge+0x76/0x490
<4>[ 185.394628] shmem_getpage_gfp.isra.9+0x1b7/0xc80
<4>[ 185.394630] shmem_read_mapping_page_gfp+0x2e/0x50
<4>[ 185.394661] i915_gem_object_get_pages_gtt+0x13b/0x660 [i915]
<4>[ 185.394683] ____i915_gem_object_get_pages+0x17/0x70 [i915]
<4>[ 185.394703] __i915_gem_object_get_pages+0x59/0x80 [i915]
<4>[ 185.394724] __i915_vma_do_pin+0x6ef/0x980 [i915]
<4>[ 185.394743] eb_lookup_vmas+0x87f/0xe80 [i915]
<4>[ 185.394746] ? __pm_runtime_resume+0x4f/0x80
<4>[ 185.394764] i915_gem_do_execbuffer+0x57c/0x1690 [i915]
<4>[ 185.394781] ? i915_gem_execbuffer2+0x90/0x3a0 [i915]
<4>[ 185.394784] ? lock_acquire+0xaf/0x200
<4>[ 185.394786] ? __might_fault+0x39/0x90
<4>[ 185.394803] ? i915_gem_execbuffer+0x2c0/0x2c0 [i915]
<4>[ 185.394820] i915_gem_execbuffer2+0x1da/0x3a0 [i915]
<4>[ 185.394837] ? i915_gem_execbuffer+0x2c0/0x2c0 [i915]
<4>[ 185.394839] drm_ioctl_kernel+0x60/0xa0
<4>[ 185.394840] drm_ioctl+0x290/0x330
<4>[ 185.394856] ? i915_gem_execbuffer+0x2c0/0x2c0 [i915]
<4>[ 185.394858] ? _raw_spin_unlock_irq+0x2f/0x50
<4>[ 185.394859] ? finish_task_switch+0xa5/0x210
<4>[ 185.394859] ? finish_task_switch+0x6a/0x210
<4>[ 185.394861] do_vfs_ioctl+0x8a/0x670
<4>[ 185.394862] ? entry_SYSCALL_64_fastpath+0x5/0x89
<4>[ 185.394863] ? trace_hardirqs_on_caller+0xde/0x1c0
<4>[ 185.394865] SyS_ioctl+0x36/0x70
<4>[ 185.394866] entry_SYSCALL_64_fastpath+0x1c/0x89
<4>[ 185.394867] RIP: 0033:0x7fc1036b4587
<4>[ 185.394867] RSP: 002b:00007ffdd38a4398 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[ 185.394868] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007fc1036b4587
<4>[ 185.394869] RDX: 00007ffdd38a44d0 RSI: 0000000040406469 RDI: 0000000000000003
<4>[ 185.394869] RBP: 00007ffdd38a4380 R08: 0000000000000000 R09: 0000000000000007
<4>[ 185.394870] R10: 00007fc103977b58 R11: 0000000000000246 R12: 00000000c01864b0
<4>[ 185.394870] R13: 0000000000000003 R14: 0000000000000001 R15: 00007ffdd38a4670
<4>[ 185.394871] Code: 0f 1f 40 00 65 48 8b 04 25 80 c5 00 00 44 8b 90 ac 08 00 00 45 85 d2 0f 85 bd 00 00 00 41 57 41 56 4d 89 cf 41 55 41 54 45 89 c6<55>53 41 89 cd 41 89 d4 89 f5 48 83 ec 10 48 89 3c 24 9c 8f 44
<4>[ 185.394886] NMI backtrace for cpu 5
<4>[ 185.394888] CPU: 5 PID: 149 Comm: kworker/u16:2 Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.394888] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.394913] Workqueue: events_unbound intel_atomic_commit_work [i915]
<4>[ 185.394914] RIP: 0010:mutex_spin_on_owner+0xa5/0x170
<4>[ 185.394915] RSP: 0018:ffffc90000c33c90 EFLAGS: 00000246
<4>[ 185.394916] RAX: ffff8803fc8d4f41 RBX: ffff8803f89a0070 RCX: 0000000000000001
<4>[ 185.394916] RDX: ffff88040abe4f40 RSI: 0000000000000001 RDI: ffffffff81cb84fd
<4>[ 185.394917] RBP: ffffc90000c33cb0 R08: ffff88040abe5868 R09: 00000000c2ec3375
<4>[ 185.394917] R10: ffffc90000c33c20 R11: ffffffff810d1510 R12: 0000000000000000
<4>[ 185.394918] R13: 0000000000000000 R14: ffff8803fc8d4f40 R15: 0000000000000001
<4>[ 185.394918] FS: 0000000000000000(0000) GS:ffff88041fb40000(0000) knlGS:0000000000000000
<4>[ 185.394919] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[ 185.394919] CR2: 00007fa1ad770e20 CR3: 0000000003e0f003 CR4: 00000000001606e0
<4>[ 185.394920] Call Trace:
<4>[ 185.394922] __mutex_lock+0x691/0x9b0
<4>[ 185.394945] ? intel_cleanup_plane_fb+0x2a/0x50 [i915]
<4>[ 185.394946] ? complete_all+0x13/0x40
<4>[ 185.394948] ? mark_held_locks+0x64/0x90
<4>[ 185.394948] ? _raw_spin_unlock_irqrestore+0x4c/0x60
<4>[ 185.394949] ? _raw_spin_unlock_irqrestore+0x4c/0x60
<4>[ 185.394970] ? intel_cleanup_plane_fb+0x2a/0x50 [i915]
<4>[ 185.394989] intel_cleanup_plane_fb+0x2a/0x50 [i915]
<4>[ 185.394992] drm_atomic_helper_cleanup_planes+0x4a/0x60
<4>[ 185.395012] intel_atomic_commit_tail+0x739/0xce0 [i915]
<4>[ 185.395014] process_one_work+0x215/0x640
<4>[ 185.395016] worker_thread+0x48/0x3a0
<4>[ 185.395017] kthread+0xfb/0x130
<4>[ 185.395018] ? process_one_work+0x640/0x640
<4>[ 185.395019] ? _kthread_create_on_node+0x30/0x30
<4>[ 185.395020] ret_from_fork+0x24/0x30
<4>[ 185.395021] Code: 42 4d 85 e4 74 20 41 8b 44 24 10 85 c0 74 0c 48 8b 83 80 00 00 00 48 85 c0 75 28 4d 85 ed 74 63 4c 3b 6b 48 75 1d f3 90 48 8b 03<48>83 e0 f8 49 39 c6 75 58 41 8b 4e 60 85 c9 74 07 48 8b 02 a8
<4>[ 185.395037] NMI backtrace for cpu 7 skipped: idling at intel_idle+0x6f/0x120
<4>[ 185.395040] NMI backtrace for cpu 2 skipped: idling at intel_idle+0x6f/0x120
<4>[ 185.395042] NMI backtrace for cpu 6 skipped: idling at intel_idle+0x6f/0x120
<0>[ 185.395501] Kernel panic - not syncing: hung_task: blocked tasks
<4>[ 185.395506] CPU: 1 PID: 67 Comm: khungtaskd Tainted: G U 4.15.0-rc4-CI-CI_DRM_3552+ #1 (moved)
<4>[ 185.395508] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[ 185.395510] Call Trace:
<4>[ 185.395516] dump_stack+0x5f/0x86
<4>[ 185.395520] panic+0xcf/0x20d
<4>[ 185.395529] watchdog+0x44a/0x5e0
<4>[ 185.395535] kthread+0xfb/0x130
<4>[ 185.395538] ? reset_hung_task_detector+0x10/0x10
<4>[ 185.395541] ? _kthread_create_on_node+0x30/0x30
<4>[ 185.395546] ret_from_fork+0x24/0x30
<0>[ 185.395882] Dumping ftrace buffer:
<0>[ 185.395932] (ftrace buffer empty)
<0>[ 185.395934] Kernel Offset: disabled
