Bug 103546

Summary:	[BAT] EDID is invalid: -> dmesg-warn:ERROR [CRTC:36:pipe A] flip_done timed out -> incomplete: warn_on: vblank wait timed out on crtc 1
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:	critical
Priority:	high	CC:	intel-gfx-bugs
Version:	DRI git
Hardware:	Other
OS:	All
Whiteboard:	ReadyForDev
i915 platform:	SKL	i915 features:	display/Other

Description Marta Löfstedt 2017-11-02 14:18:53 UTC

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3309/fi-skl-6700k/igt@kms_pipe_crc_basic@nonblocking-crc-pipe-a-frame-sequence.html

[  403.624011] i915 0000:00:02.0: DP-1: EDID is invalid:
[  403.624026] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624032] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624039] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624045] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624051] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624057] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624063] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.624069] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765604] i915 0000:00:02.0: DP-1: EDID is invalid:
[  403.765617] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765624] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765630] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765636] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765642] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765648] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765654] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  403.765660] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  415.407803] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:36:pipe A] flip_done timed out
[  425.652876] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:46:pipe B] flip_done timed out
[  435.898031] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:56:pipe C] flip_done timed out

followed by:
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3309/fi-skl-6700k/igt@kms_pipe_crc_basic@nonblocking-crc-pipe-b.html

<4>[  510.815462] vblank wait timed out on crtc 1
<4>[  510.815496] ------------[ cut here ]------------
<4>[  510.815517] WARNING: CPU: 3 PID: 4274 at drivers/gpu/drm/drm_vblank.c:1072 drm_wait_one_vblank+0x19f/0x1b0
<4>[  510.815523] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core e1000e snd_pcm mei_me prime_numbers mei ptp pps_core pinctrl_sunrisepoint pinctrl_intel i2c_hid
<4>[  510.815678] CPU: 3 PID: 4274 Comm: kms_pipe_crc_ba Tainted: G     U          4.14.0-rc7-CI-CI_DRM_3309+ #1
<4>[  510.815685] Hardware name: System manufacturer System Product Name/Z170M-PLUS, BIOS 1805 06/20/2016
<4>[  510.815692] task: ffff880218efd0c0 task.stack: ffffc90002f34000
<4>[  510.815703] RIP: 0010:drm_wait_one_vblank+0x19f/0x1b0
<4>[  510.815710] RSP: 0018:ffffc90002f37a00 EFLAGS: 00010286
<4>[  510.815723] RAX: 000000000000001f RBX: ffff880221f70000 RCX: 0000000000000001
<4>[  510.815729] RDX: 0000000080000001 RSI: ffffffff81d19e3f RDI: 00000000ffffffff
<4>[  510.815736] RBP: ffffc90002f37a58 R08: ffff880218efd9d0 R09: 0000000000000000
<4>[  510.815742] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
<4>[  510.815749] R13: 0000000000000001 R14: 0000000000000210 R15: 000000000000656a
<4>[  510.815757] FS:  00007fd419a6ca40(0000) GS:ffff880236cc0000(0000) knlGS:0000000000000000
<4>[  510.815763] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  510.815770] CR2: 00007fd414647000 CR3: 00000002228b0005 CR4: 00000000003606e0
<4>[  510.815777] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[  510.815783] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[  510.815790] Call Trace:
<4>[  510.815806]  ? wait_woken+0x90/0x90
<4>[  510.815909]  skl_update_crtcs+0x167/0x1d0 [i915]
<4>[  510.816007]  intel_atomic_commit_tail+0x286/0xbe0 [i915]
<4>[  510.816099]  intel_atomic_commit+0x223/0x2d0 [i915]
<4>[  510.816117]  drm_atomic_commit+0x4b/0x50
<4>[  510.816130]  drm_atomic_helper_set_config+0x81/0x90
<4>[  510.816141]  __drm_mode_set_config_internal+0x65/0x110
<4>[  510.816151]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.816159]  drm_mode_setcrtc+0x4c8/0x650
<4>[  510.816189]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.816201]  drm_ioctl_kernel+0x69/0xb0
<4>[  510.816215]  drm_ioctl+0x2f9/0x3d0
<4>[  510.816223]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.816246]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.816261]  do_vfs_ioctl+0x94/0x670
<4>[  510.816274]  ? entry_SYSCALL_64_fastpath+0x5/0xb1
<4>[  510.816284]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.816294]  ? trace_hardirqs_on_caller+0xe3/0x1b0
<4>[  510.816308]  SyS_ioctl+0x41/0x70
<4>[  510.816323]  entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[  510.816330] RIP: 0033:0x7fd417c66f07
<4>[  510.816337] RSP: 002b:00007ffcde6efe78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[  510.816350] RAX: ffffffffffffffda RBX: ffffffff81491e03 RCX: 00007fd417c66f07
<4>[  510.816357] RDX: 00007ffcde6efeb0 RSI: 00000000c06864a2 RDI: 0000000000000003
<4>[  510.816363] RBP: ffffc90002f37f88 R08: 0000000000000000 R09: 0000000000000000
<4>[  510.816451] R10: 0000000000000000 R11: 0000000000000246 R12: 0000556698cfd460
<4>[  510.816459] R13: 0000000000000003 R14: 00000000c06864a2 R15: 0000000000000003
<4>[  510.816474]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.816496] Code: c0 e9 23 ff ff ff 48 8b 7d a8 48 8d 75 b0 e8 79 24 ac ff 45 85 e4 0f 85 12 ff ff ff 44 89 ee 48 c7 c7 38 7b ce 81 e8 e2 6e ae ff <0f> ff e9 fc fe ff ff 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 
<4>[  510.816936] ---[ end trace 5dc7f12cf71a7b5a ]---
<4>[  510.919517] vblank wait timed out on crtc 2
<4>[  510.919549] ------------[ cut here ]------------
<4>[  510.919564] WARNING: CPU: 3 PID: 4274 at drivers/gpu/drm/drm_vblank.c:1072 drm_wait_one_vblank+0x19f/0x1b0
<4>[  510.919570] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic i915 x86_pkg_temp_thermal intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core e1000e snd_pcm mei_me prime_numbers mei ptp pps_core pinctrl_sunrisepoint pinctrl_intel i2c_hid
<4>[  510.919723] CPU: 3 PID: 4274 Comm: kms_pipe_crc_ba Tainted: G     U  W       4.14.0-rc7-CI-CI_DRM_3309+ #1
<4>[  510.919729] Hardware name: System manufacturer System Product Name/Z170M-PLUS, BIOS 1805 06/20/2016
<4>[  510.919737] task: ffff880218efd0c0 task.stack: ffffc90002f34000
<4>[  510.919747] RIP: 0010:drm_wait_one_vblank+0x19f/0x1b0
<4>[  510.919754] RSP: 0018:ffffc90002f37a00 EFLAGS: 00010286
<4>[  510.919767] RAX: 000000000000001f RBX: ffff880221f70000 RCX: 0000000000000001
<4>[  510.919773] RDX: 0000000080000001 RSI: ffffffff81d19e3f RDI: 00000000ffffffff
<4>[  510.919780] RBP: ffffc90002f37a58 R08: ffff880218efd9d0 R09: 0000000000000000
<4>[  510.919786] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
<4>[  510.919793] R13: 0000000000000002 R14: 0000000000000420 R15: 0000000000006491
<4>[  510.919801] FS:  00007fd419a6ca40(0000) GS:ffff880236cc0000(0000) knlGS:0000000000000000
<4>[  510.919807] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[  510.919814] CR2: 00007fd414647000 CR3: 00000002228b0005 CR4: 00000000003606e0
<4>[  510.919821] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>[  510.919827] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
<4>[  510.919833] Call Trace:
<4>[  510.919849]  ? wait_woken+0x90/0x90
<4>[  510.919952]  skl_update_crtcs+0x167/0x1d0 [i915]
<4>[  510.920052]  intel_atomic_commit_tail+0x286/0xbe0 [i915]
<4>[  510.920146]  intel_atomic_commit+0x223/0x2d0 [i915]
<4>[  510.920163]  drm_atomic_commit+0x4b/0x50
<4>[  510.920176]  drm_atomic_helper_set_config+0x81/0x90
<4>[  510.920188]  __drm_mode_set_config_internal+0x65/0x110
<4>[  510.920197]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.920206]  drm_mode_setcrtc+0x4c8/0x650
<4>[  510.920236]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.920248]  drm_ioctl_kernel+0x69/0xb0
<4>[  510.920262]  drm_ioctl+0x2f9/0x3d0
<4>[  510.920271]  ? drm_mode_getcrtc+0x190/0x190
<4>[  510.920293]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.920307]  do_vfs_ioctl+0x94/0x670
<4>[  510.920319]  ? entry_SYSCALL_64_fastpath+0x5/0xb1
<4>[  510.920329]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.920340]  ? trace_hardirqs_on_caller+0xe3/0x1b0
<4>[  510.920353]  SyS_ioctl+0x41/0x70
<4>[  510.920368]  entry_SYSCALL_64_fastpath+0x1c/0xb1
<4>[  510.920376] RIP: 0033:0x7fd417c66f07
<4>[  510.920383] RSP: 002b:00007ffcde6efe78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
<4>[  510.920396] RAX: ffffffffffffffda RBX: ffffffff81491e03 RCX: 00007fd417c66f07
<4>[  510.920402] RDX: 00007ffcde6efeb0 RSI: 00000000c06864a2 RDI: 0000000000000003
<4>[  510.920408] RBP: ffffc90002f37f88 R08: 0000000000000000 R09: 0000000000000000
<4>[  510.920415] R10: 0000000000000000 R11: 0000000000000246 R12: 0000556698cfd460
<4>[  510.920501] R13: 0000000000000003 R14: 00000000c06864a2 R15: 0000000000000003
<4>[  510.920515]  ? __this_cpu_preempt_check+0x13/0x20
<4>[  510.920531] Code: c0 e9 23 ff ff ff 48 8b 7d a8 48 8d 75 b0 e8 79 24 ac ff 45 85 e4 0f 85 12 ff ff ff 44 89 ee 48 c7 c7 38 7b ce 81 e8 e2 6e ae ff <0f> ff e9 fc fe ff ff 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 
<4>[  510.920973] ---[ end trace 5dc7f12cf71a7b5b ]---
<3>[  520.932524] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:46:pipe B] flip_done timed out
<12>[  526.071590] owatch: TIMEOUT!
<12>[  526.071714] owatch: timeout for /dev/watchdog0 set to 10 (requested 10)
<12>[  526.072257] owatch: timeout for /dev/watchdog0 set to 1 (requested 1)
<2>[  527.072694] softdog: Initiating panic
<0>[  527.076509] Kernel panic - not syncing: Software Watchdog Timer expired
<4>[  527.083349] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G     U  W       4.14.0-rc7-CI-CI_DRM_3309+ #1
<4>[  527.092506] Hardware name: System manufacturer System Product Name/Z170M-PLUS, BIOS 1805 06/20/2016
<4>[  527.101811] Call Trace:
<4>[  527.104303]  <IRQ>
<4>[  527.106364]  dump_stack+0x68/0x9f
<4>[  527.109810]  panic+0xd4/0x21d
<4>[  527.112843]  ? printk+0x43/0x4b
<4>[  527.116061]  softdog_fire+0x6b/0x70
<4>[  527.119619]  __hrtimer_run_queues+0xed/0x4d0
<4>[  527.124023]  ? softdog_ping+0x50/0x50
<4>[  527.127781]  hrtimer_interrupt+0xb5/0x200
<4>[  527.131915]  smp_apic_timer_interrupt+0x7d/0x2e0
<4>[  527.136651]  apic_timer_interrupt+0x9a/0xa0
<4>[  527.140967]  </IRQ>
<4>[  527.143119] RIP: 0010:cpuidle_enter_state+0x136/0x370
<4>[  527.148316] RSP: 0018:ffffc900000c3e80 EFLAGS: 00000216 ORIG_RAX: ffffffffffffff10
<4>[  527.156096] RAX: ffff88022d32a880 RBX: 0000000000030266 RCX: 0000000000000001
<4>[  527.163429] RDX: 0000000000000000 RSI: ffffffff81d0eb14 RDI: ffffffff81cc26f6
<4>[  527.170738] RBP: ffffc900000c3eb8 R08: 000000000000b264 R09: 0000000000000018
<4>[  527.178078] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000003
<4>[  527.185403] R13: 0000000000000003 R14: ffff880236ce5818 R15: 0000007ab7f7d6bd
<4>[  527.192718]  cpuidle_enter+0x17/0x20
<4>[  527.196378]  call_cpuidle+0x23/0x40
<4>[  527.199961]  do_idle+0x192/0x1e0
<4>[  527.203268]  cpu_startup_entry+0x1d/0x20
<4>[  527.207287]  start_secondary+0x11c/0x140
<4>[  527.211315]  secondary_startup_64+0xa5/0xa5
<0>[  527.215849] Kernel Offset: disabled

Comment 1 Marta Löfstedt 2017-11-07 14:22:14 UTC

Here is similar on a Patchwork run:
https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_6962/fi-skl-6700k/igt@kms_flip@basic-plain-flip.html
	
[  378.724217] i915 0000:00:02.0: DP-1: EDID is invalid:
[  378.724220] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724222] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724223] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724224] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724226] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724227] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724228] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  378.724229] 	[00] ZERO 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[  400.174146] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:36:pipe A] flip_done timed out

https://intel-gfx-ci.01.org/tree/drm-tip/Patchwork_6962/fi-skl-6700k/igt@kms_force_connector_basic@force-connector-state.html

From run.log:
[220/289] skip: 16, pass: 203, dmesg-warn: 1 \
running: igt/kms_force_connector_basic/force-connector-state
[220/289] skip: 16, pass: 203, dmesg-warn: 1 |              
owatch: TIMEOUT!
CI_IGT_test runtime 585 seconds

Comment 2 Marta Löfstedt 2017-12-08 07:43:49 UTC

last seen CI_DRM_3309: 2017-11-02 / 223 I will close and archive

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.