Bug 104152

Summary:	[CI][HSW only] igt@kms_* - incomplete - Softdog
Product:	DRI	Reporter:	Marta Löfstedt <marta.lofstedt>
Component:	DRM/Intel	Assignee:	Intel GFX Bugs mailing list <intel-gfx-bugs>
Status:	CLOSED WORKSFORME	QA Contact:	Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity:	normal
Priority:	medium	CC:	intel-gfx-bugs
Version:	DRI git
Hardware:	Other
OS:	All
Whiteboard:	ReadyForDev
i915 platform:	HSW	i915 features:	display/Other

Description Marta Löfstedt 2017-12-07 07:53:02 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3461/shard-hsw5/igt@kms_chv_cursor_fail@pipe-b-128x128-top-edge.html

last dmesg:
<7>[   26.351735] [drm:drm_mode_setcrtc] [CRTC:47:pipe B]
<7>[   26.351752] [drm:drm_mode_setcrtc] [CONNECTOR:58:VGA-1]
<7>[   26.357158] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]

run.log:
running: igt/kms_chv_cursor_fail/pipe-b-128x128-top-edge

[33/76] skip: 17, pass: 16 /                            
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
FATAL: command execution failed
...
Completed CI_IGT_test CI_DRM_3461/shard-hsw5/1 : FAILURE
CI_IGT_test runtime 417 seconds
Rebooting shard-hsw5

Note: pstore does finally appear to work again:


<7>[   26.351735] [drm:drm_mode_setcrtc] [CRTC:47:pipe B]
<7>[   26.351752] [drm:drm_mode_setcrtc] [CONNECTOR:58:VGA-1]
<7>[   26.357158] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]
<12>[  386.278115] owatch: TIMEOUT!
<12>[  386.278203] owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
<6>[  386.278291] sysrq: SysRq : Trigger a crash
<1>[  386.278319] BUG: unable to handle kernel NULL pointer dereference at           (null)
<1>[  386.278331] IP: sysrq_handle_crash+0x3c/0x70
<6>[  386.278334] PGD 40976b067 P4D 40976b067 PUD 3fbc83067 PMD 0 
<4>[  386.278344] Oops: 0002 [#1] PREEMPT SMP
<0>[  386.278349] Dumping ftrace buffer:
<0>[  386.278355]    (ftrace buffer empty)
<4>[  386.278359] Modules linked in: vgem snd_hda_codec_hdmi i915 x86_pkg_temp_thermal snd_hda_codec_realtek intel_powerclamp snd_hda_codec_generic coretemp crct10dif_pclmul snd_hda_intel crc32_pclmul snd_hda_codec ghash_clmulni_intel snd_hwdep snd_hda_core snd_pcm r8169 mei_me mii mei lpc_ich prime_numbers
<4>[  386.278396] CPU: 4 PID: 1071 Comm: owatch Tainted: G     U           4.15.0-rc2-CI-CI_DRM_3461+ #1
<4>[  386.278399] Hardware name: MSI MS-7924/Z97M-G43(MS-7924), BIOS V1.12 02/15/2016
<4>[  386.278403] task: 0000000012e1be9a task.stack: 000000005bf9397f
<4>[  386.278407] RIP: 0010:sysrq_handle_crash+0x3c/0x70
<4>[  386.278410] RSP: 0018:ffffc90000cf7e10 EFLAGS: 00010282
<4>[  386.278414] RAX: ffff8803fd2652c0 RBX: 0000000000000063 RCX: 1fcaac1f00000000
<4>[  386.278417] RDX: 0000000000000001 RSI: 00000000469deb48 RDI: 0000000000000000
<4>[  386.278420] RBP: ffffc90000cf7e38 R08: ffff8803fd265b88 R09: 0000000067d877a6
<4>[  386.278423] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000004
<4>[  386.278426] R13: ffffffff81e9ab60 R14: 0000000000000000 R15: 00007ff7e385f400
<4>[  386.278429] FS:  00007ff7e3a6d700(0000) GS:ffff88041fb00000(0000) knlGS:0000000000000000
<4>[  386.278432] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  386.278435] CR2: 0000000000000000 CR3: 00000003f951f001 CR4: 00000000001606e0
<4>[  386.278438] Call Trace:
<4>[  386.278443]  __handle_sysrq+0x123/0x200
<4>[  386.278449]  write_sysrq_trigger+0x43/0x50
<4>[  386.278454]  proc_reg_write+0x38/0x60
<4>[  386.278461]  __vfs_write+0x1e/0x130
<4>[  386.278467]  ? rcu_read_lock_sched_held+0x6f/0x80
<4>[  386.278470]  ? rcu_sync_lockdep_assert+0x25/0x50
<4>[  386.278475]  ? __sb_start_write+0xd5/0x1f0
<4>[  386.278478]  ? __sb_start_write+0xef/0x1f0
<4>[  386.278484]  vfs_write+0xc0/0x1b0
<4>[  386.278490]  SyS_write+0x40/0xa0
<4>[  386.278496]  entry_SYSCALL_64_fastpath+0x1c/0x89
<4>[  386.278500] RIP: 0033:0x7ff7e35998f0
<4>[  386.278502] RSP: 002b:00007ffe4cce3958 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
<4>[  386.278507] RAX: ffffffffffffffda RBX: 0000000002085020 RCX: 00007ff7e35998f0
<4>[  386.278510] RDX: 0000000000000001 RSI: 0000000002085250 RDI: 0000000000000003
<4>[  386.278512] RBP: 00007ff7e385f400 R08: 00007ff7e3a6d700 R09: 0000000000000410
<4>[  386.278515] R10: 00007ff7e3862b58 R11: 0000000000000246 R12: 0000000000000000
<4>[  386.278518] R13: 00007ffe4cce3ba0 R14: 0000000000000000 R15: 0000000000000000
<4>[  386.278526] Code: 33 e8 69 74 b9 ff 48 c7 c2 42 bc 55 81 be 01 00 00 00 48 c7 c7 c0 49 e4 81 e8 01 a4 b7 ff c7 05 67 e1 e7 00 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 e8 36 a0 b9 ff 84 c0 75 c4 48 c7 c2 
<1>[  386.278610] RIP: sysrq_handle_crash+0x3c/0x70 RSP: ffffc90000cf7e10
<4>[  386.278613] CR2: 0000000000000000
<4>[  386.278618] ---[ end trace 5538ecf59feb7435 ]---
<0>[  389.255453] Kernel panic - not syncing: Fatal exception
<0>[  389.255465] Dumping ftrace buffer:
<0>[  389.255689]    (ftrace buffer empty)
<0>[  389.255691] Kernel Offset: disabled

Comment 1 Marta Löfstedt 2017-12-08 07:12:54 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3476/shard-hsw5/igt@kms_pipe_crc_basic@read-crc-pipe-b.html

However, this looks a bit odd:

dmesg is only ~4 seconds:
<5>[   14.128001] owatch: Using watchdog device /dev/watchdog0
<5>[   14.128141] owatch: Watchdog /dev/watchdog0 is a software watchdog
<5>[   14.128774] owatch: timeout for /dev/watchdog0 set to 370 (requested 370)
...
<7>[   18.522093] [drm:intel_atomic_commit_tail [i915]] [CRTC:47:pipe B]
<7>[   18.522223] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<7>[   18.522631] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]

run.log:
running: igt/kms_pipe_crc_basic/read-crc-pipe-b

[01/76] skip: 1 /                              
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
FATAL: command execution failed
...
Finished: FAILURE
Completed CI_IGT_test CI_DRM_3476/shard-hsw5/1 : FAILURE
CI_IGT_test runtime 425 seconds
Rebooting shard-hsw5

so there is ~400 seconds of no dmesg

Comment 2 Marta Löfstedt 2017-12-11 08:36:54 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3492/shard-hsw7/igt@kms_chv_cursor_fail@pipe-b-64x64-bottom-edge.html

run.log:
running: igt/kms_chv_cursor_fail/pipe-b-64x64-bottom-edge

[01/76] pass: 1 /                                        
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set

last dmesg:
<7>[   15.967066] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<7>[   15.967403] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]
<5>[   52.707952] random: crng init done

Comment 3 Marta Löfstedt 2017-12-12 13:46:10 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3500/shard-hsw6/igt@kms_pipe_crc_basic@nonblocking-crc-pipe-b-frame-sequence.html

run.log:
running: igt/kms_pipe_crc_basic/nonblocking-crc-pipe-b-frame-sequence

[01/77] skip: 1 /                                                    
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)

last dmesg:
<7>[   15.160625] [drm:haswell_crtc_enable [i915]] iCLKIP clock: found settings for 65000KHz refresh rate: auxdiv=0, divsel=27, phasedir=0, phaseinc=22
<7>[   15.210806] [drm:verify_connector_state.isra.77 [i915]] [CONNECTOR:58:VGA-1]
<7>[   15.210831] [drm:intel_atomic_commit_tail [i915]] [CRTC:47:pipe B]
<7>[   15.210885] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<7>[   15.211235] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]
<5>[   55.012598] random: crng init done

Comment 4 Marta Löfstedt 2017-12-18 08:37:13 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/IGT_4066/shard-hsw1/igt@kms_pipe_crc_basic@read-crc-pipe-b-frame-sequence.html

run.log:
running: igt/kms_pipe_crc_basic/read-crc-pipe-b-frame-sequence

[00/77]  |                                                    
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
FATAL: command execution failed

last dmesg:
<7>[   21.218420] [drm:verify_single_dpll_state.isra.78 [i915]] SPLL
<7>[   21.218704] [drm:drm_mode_setcrtc] [CRTC:57:pipe C]
<12>[  380.110737] owatch: TIMEOUT!
<12>[  380.110878] owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
<6>[  380.111021] sysrq: SysRq : Trigger a crash

Comment 5 Marta Löfstedt 2018-01-02 08:28:19 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3569/shard-hsw6/igt@kms_chv_cursor_fail@pipe-c-128x128-top-edge.html

running: igt/kms_chv_cursor_fail/pipe-c-128x128-top-edge

[02/77] skip: 1, pass: 1 -                              
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
FATAL: command execution failed
java.io.EOFException

Comment 6 Marta Löfstedt 2018-01-03 07:28:50 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3588/shard-hsw8/igt@kms_plane@plane-position-hole-dpms-pipe-c-planes.html

[05/77] skip: 3, pass: 2 |
running: igt/kms_plane/plane-position-hole-dpms-pipe-c-planes

[05/77] skip: 3, pass: 2 /                                   
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)

Comment 7 Marta Löfstedt 2018-01-12 07:59:08 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3621/shard-hsw1/igt@kms_plane_multiple@legacy-pipe-b-tiling-none.html

run.log:
running: igt/kms_plane_multiple/legacy-pipe-b-tiling-none

[12/77] skip: 8, pass: 4 |                               
owatch: TIMEOUT!
owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
FATAL: command execution failed
java.io.EOFException

Comment 8 Marta Löfstedt 2018-01-15 07:22:10 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3627/shard-hsw8/igt@kms_pipe_crc_basic@hang-read-crc-pipe-b.html

<12>[  384.973744] owatch: TIMEOUT!

Comment 9 Marta Löfstedt 2018-02-23 08:08:46 UTC

Last seen CI_DRM_3627: 2018-01-14 / 320 runs ago

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.