Bug 104573 - [IGT][SNB only] dmesg-warn [CRTC:37:pipe A] flip_done timed out and vblank wait timed out on crtc 0
Summary: [IGT][SNB only] dmesg-warn [CRTC:37:pipe A] flip_done timed out and vblank wa...
Status: CLOSED DUPLICATE of bug 103713
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: medium critical
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
: 105131 (view as bug list)
Depends on:
Blocks:
 
Reported: 2018-01-10 16:23 UTC by Elizabeth
Modified: 2018-09-11 13:13 UTC (History)
4 users (show)

See Also:
i915 platform: SNB
i915 features: display/Other

Attachments
kern_log_vblank_warn (14.27 MB, text/plain)
2018-01-15 23:14 UTC, Elizabeth 		no flags Details
flip done time out (54.89 KB, text/plain)
2018-01-30 13:28 UTC, L Bourgard 		no flags Details
View All

Description Elizabeth 2018-01-10 16:23:57 UTC 
This is the same as bug 103712, but according to comment https://bugs.freedesktop.org/show_bug.cgi?id=103712#c41, it should be already fixed upstream. 
Though we still are seeing those in our SNB wit tests:
igt@kms_setmode@basic-clone-single-crtc
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-a

Sample output:
IGT-Version: 1.20-g19c6c04 (x86_64) (Linux: 4.15.0-rc7-drm-intel-qa-ww2-commit-17fd162+ x86_64)
Testing: basic-clone-single-crtc 2 connector combinations
Subtest basic-clone-single-crtc: SUCCESS (61.466s)

dmesg:
[ 1269.219185] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1279.459181] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 1289.699188] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:28:primary A] flip_done timed out
[ 1299.939179] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1310.179180] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 1320.419183] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1320.703147] ------------[ cut here ]------------
[ 1320.703150] vblank wait timed out on crtc 0
[ 1320.703195] WARNING: CPU: 2 PID: 3475 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 1320.703196] Modules linked in: vgem ip6table_filter ip6_tables iptable_filter binfmt_misc nls_iso8859_1 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel dcdbas snd_hda_codec snd_hda_core intel_rapl snd_hwdep x86_pkg_temp_thermal intel_powerclamp coretemp snd_pcm kvm_intel kvm irqbypass snd_seq_midi snd_seq_midi_event crct10dif_pclmul crc32_pclmul snd_rawmidi ghash_clmulni_intel pcbc snd_seq snd_seq_device snd_timer aesni_intel aes_x86_64 crypto_simd glue_helper cryptd intel_cstate intel_rapl_perf serio_raw snd mei_me mei lpc_ich soundcore shpchp mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 i915 i2c_algo_bit prime_numbers drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops e1000e drm ahci psmouse libahci ptp pps_core video
[ 1320.703230] CPU: 2 PID: 3475 Comm: kms_setmode Tainted: G     U  W        4.15.0-rc7-drm-intel-qa-ww2-commit-17fd162+ #1
[ 1320.703231] Hardware name: Dell Inc. OptiPlex 990/06D7TR, BIOS A19 08/26/2015
[ 1320.703241] RIP: 0010:drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 1320.703242] RSP: 0018:ffffb271e2a27b80 EFLAGS: 00010282
[ 1320.703244] RAX: 0000000000000000 RBX: ffff97d4d0328000 RCX: 0000000000000006
[ 1320.703244] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff97d4dd296590
[ 1320.703245] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000019057
[ 1320.703246] R10: 0000000000000000 R11: 0000000000019057 R12: 0000000000000000
[ 1320.703247] R13: 0000000000000000 R14: 000000000000963e R15: ffff97d4ce414008
[ 1320.703248] FS:  00007f555a355a00(0000) GS:ffff97d4dd280000(0000) knlGS:0000000000000000
[ 1320.703249] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1320.703250] CR2: 00007fe934026e48 CR3: 00000004128c4004 CR4: 00000000000606e0
[ 1320.703251] Call Trace:
[ 1320.703258]  ? wait_woken+0x80/0x80
[ 1320.703296]  ironlake_crtc_enable+0x79b/0xbf0 [i915]
[ 1320.703326]  intel_update_crtc+0x3d/0x90 [i915]
[ 1320.703355]  intel_update_crtcs+0x57/0x70 [i915]
[ 1320.703381]  intel_atomic_commit_tail+0x35b/0xd90 [i915]
[ 1320.703407]  intel_atomic_commit+0x233/0x2e0 [i915]
[ 1320.703417]  restore_fbdev_mode_atomic+0x1ab/0x220 [drm_kms_helper]
[ 1320.703423]  drm_fb_helper_restore_fbdev_mode_unlocked+0x45/0x90 [drm_kms_helper]
[ 1320.703450]  intel_fbdev_restore_mode+0x30/0x80 [i915]
[ 1320.703472]  i915_driver_lastclose+0xa/0x10 [i915]
[ 1320.703482]  drm_lastclose+0x34/0xf0 [drm]
[ 1320.703492]  drm_release+0x2b6/0x370 [drm]
[ 1320.703495]  __fput+0xd5/0x210
[ 1320.703497]  task_work_run+0x80/0xa0
[ 1320.703501]  exit_to_usermode_loop+0xbb/0xc0
[ 1320.703503]  syscall_return_slowpath+0x81/0xa0
[ 1320.703506]  entry_SYSCALL_64_fastpath+0x7f/0x81
[ 1320.703508] RIP: 0033:0x7f55592606f0
[ 1320.703509] RSP: 002b:00007fff9c9224f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
[ 1320.703510] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f55592606f0
[ 1320.703511] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000004
[ 1320.703512] RBP: 0000000000000000 R08: 00000000024dad10 R09: 0000000000000001
[ 1320.703513] R10: 0000000000000078 R11: 0000000000000246 R12: 0000000000648100
[ 1320.703514] R13: 00007f555880bc20 R14: 0000000000000000 R15: 0000000000000000
[ 1320.703515] Code: 0a ff ff ff e8 55 8c 54 dc 48 89 e6 4c 89 ff e8 3a ba 58 dc 45 85 ed 0f 85 14 ff ff ff 89 ee 48 c7 c7 f8 46 15 c0 e8 93 89 54 dc <0f> ff e9 ff fe ff ff 66 90 66 2e 0f 1f 84 00 00 00 00 00 66 66 
[ 1320.703543] ---[ end trace 3514ad4a441eae3d ]---
[ 1321.139151] ------------[ cut here ]------------
[ 1321.139153] vblank wait timed out on crtc 1
[ 1321.139196] WARNING: CPU: 2 PID: 3475 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 1321.139196] Modules linked in: vgem ip6table_filter ip6_tables iptable_filter binfmt_misc nls_iso8859_1 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel dcdbas snd_hda_codec snd_hda_core intel_rapl snd_hwdep x86_pkg_temp_thermal intel_powerclamp coretemp snd_pcm kvm_intel kvm irqbypass snd_seq_midi snd_seq_midi_event crct10dif_pclmul crc32_pclmul snd_rawmidi ghash_clmulni_intel pcbc snd_seq snd_seq_device snd_timer aesni_intel aes_x86_64 crypto_simd glue_helper cryptd intel_cstate intel_rapl_perf serio_raw snd mei_me mei lpc_ich soundcore shpchp mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 i915 i2c_algo_bit prime_numbers drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops e1000e drm ahci psmouse libahci ptp pps_core video
[ 1321.139228] CPU: 2 PID: 3475 Comm: kms_setmode Tainted: G     U  W        4.15.0-rc7-drm-intel-qa-ww2-commit-17fd162+ #1
[ 1321.139229] Hardware name: Dell Inc. OptiPlex 990/06D7TR, BIOS A19 08/26/2015
[ 1321.139238] RIP: 0010:drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 1321.139239] RSP: 0018:ffffb271e2a27b80 EFLAGS: 00010282
[ 1321.139240] RAX: 0000000000000000 RBX: ffff97d4d0328000 RCX: 0000000000000006
[ 1321.139241] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff97d4dd296590
[ 1321.139242] RBP: 0000000000000001 R08: 0000000000000001 R09: 000000000001909a
[ 1321.139243] R10: 0000000000000000 R11: 000000000001909a R12: 0000000000000160
[ 1321.139243] R13: 0000000000000000 R14: 0000000000012756 R15: ffff97d4ce414168
[ 1321.139245] FS:  00007f555a355a00(0000) GS:ffff97d4dd280000(0000) knlGS:0000000000000000
[ 1321.139246] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1321.139246] CR2: 00007fe934026e48 CR3: 00000004128c4004 CR4: 00000000000606e0
[ 1321.139247] Call Trace:
[ 1321.139254]  ? wait_woken+0x80/0x80
[ 1321.139292]  ironlake_crtc_enable+0x79b/0xbf0 [i915]
[ 1321.139320]  intel_update_crtc+0x3d/0x90 [i915]
[ 1321.139347]  intel_update_crtcs+0x57/0x70 [i915]
[ 1321.139373]  intel_atomic_commit_tail+0x35b/0xd90 [i915]
[ 1321.139399]  intel_atomic_commit+0x233/0x2e0 [i915]
[ 1321.139409]  restore_fbdev_mode_atomic+0x1ab/0x220 [drm_kms_helper]
[ 1321.139416]  drm_fb_helper_restore_fbdev_mode_unlocked+0x45/0x90 [drm_kms_helper]
[ 1321.139443]  intel_fbdev_restore_mode+0x30/0x80 [i915]
[ 1321.139465]  i915_driver_lastclose+0xa/0x10 [i915]
[ 1321.139475]  drm_lastclose+0x34/0xf0 [drm]
[ 1321.139485]  drm_release+0x2b6/0x370 [drm]
[ 1321.139489]  __fput+0xd5/0x210
[ 1321.139492]  task_work_run+0x80/0xa0
[ 1321.139495]  exit_to_usermode_loop+0xbb/0xc0
[ 1321.139498]  syscall_return_slowpath+0x81/0xa0
[ 1321.139501]  entry_SYSCALL_64_fastpath+0x7f/0x81
[ 1321.139503] RIP: 0033:0x7f55592606f0
[ 1321.139504] RSP: 002b:00007fff9c9224f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
[ 1321.139505] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f55592606f0
[ 1321.139506] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000004
[ 1321.139507] RBP: 0000000000000000 R08: 00000000024dad10 R09: 0000000000000001
[ 1321.139508] R10: 0000000000000078 R11: 0000000000000246 R12: 0000000000648100
[ 1321.139509] R13: 00007f555880bc20 R14: 0000000000000000 R15: 0000000000000000
[ 1321.139510] Code: 0a ff ff ff e8 55 8c 54 dc 48 89 e6 4c 89 ff e8 3a ba 58 dc 45 85 ed 0f 85 14 ff ff ff 89 ee 48 c7 c7 f8 46 15 c0 e8 93 89 54 dc <0f> ff e9 ff fe ff ff 66 90 66 2e 0f 1f 84 00 00 00 00 00 66 66 
[ 1321.139535] ---[ end trace 3514ad4a441eae3e ]---
[ 1331.171190] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1341.411185] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:47:pipe B] flip_done timed out

Will add logs as soon as I get the SNB to test.
Comment 1 Elizabeth 2018-01-15 23:14:03 UTC 
Created attachment 136742 [details]
kern_log_vblank_warn
Comment 2 Elizabeth 2018-01-16 19:49:41 UTC 
On today's ff:
SNB, igt@kms_pipe_crc_basic@suspend-read-crc-pipe-a, commit-a0ca279+
SNB, igt@kms_setmode@basic-clone-single-crtc, commit-a0ca279+

[  389.843007] vblank wait timed out on crtc 0
[  389.843052] WARNING: CPU: 3 PID: 28418 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0 [drm]
...
[  400.355021] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[  410.594996] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:47:pipe B] flip_done timed out

And may be related:
https://bugs.freedesktop.org/show_bug.cgi?id=104614
https://bugs.freedesktop.org/show_bug.cgi?id=101269
https://bugs.freedesktop.org/show_bug.cgi?id=103713
Comment 3 Elizabeth 2018-01-22 21:35:36 UTC 
igt@kms_setmode@basic-clone-single-crtc

IGT-Version: 1.21-g94bd67c (x86_64) (Linux: 4.15.0-rc9-drm-intel-qa-ww4-commit-8748fd9+ x86_64)
Testing: basic-clone-single-crtc 2 connector combinations
Subtest basic-clone-single-crtc: SUCCESS (61.462s)

[ 1271.520530] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1281.760475] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 1292.000469] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:28:primary A] flip_done timed out
[ 1302.240475] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1312.480469] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 1322.720469] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1323.000482] ------------[ cut here ]------------
[ 1323.000488] vblank wait timed out on crtc 0
[ 1323.000525] WARNING: CPU: 4 PID: 14451 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0
...
Comment 4 Elizabeth 2018-01-26 19:45:13 UTC 
This time with commit-59275f1 while 
igt@kms_setmode@basic-clone-single-crtc
was SUCCESS and have the vblank warns, 
these other two other had a timeout and the warn:
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-a
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b

Stdout	
An internal exception that should have been handled was not:
Test run time exceeded timeout value (600 seconds)

dmesg	
[ 1106.654971] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1116.894968] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:28:primary A] flip_done timed out
[ 1127.134967] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1137.374964] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 1147.614962] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 1157.854961] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:28:primary A] flip_done timed out
[ 1168.094964] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1178.334962] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1188.574962] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1198.814958] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1209.054944] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 1219.294957] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1219.442951] ------------[ cut here ]------------
[ 1219.442954] vblank wait timed out on crtc 1
[ 1219.442971] WARNING: CPU: 4 PID: 10942 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0
[ 1219.442972] Modules linked in: vgem ip6table_filter ip6_tables iptable_filter binfmt_misc nls_iso8859_1 snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel intel_rapl snd_hda_codec x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_core snd_hwdep kvm_intel snd_pcm dcdbas kvm irqbypass snd_seq_midi crct10dif_pclmul snd_seq_midi_event crc32_pclmul ghash_clmulni_intel snd_rawmidi pcbc aesni_intel snd_seq aes_x86_64 crypto_simd glue_helper cryptd intel_cstate snd_seq_device intel_rapl_perf snd_timer serio_raw snd lpc_ich soundcore shpchp mei_me mei mac_hid parport_pc ppdev lp parport ip_tables x_tables autofs4 i915 e1000e ahci psmouse ptp libahci pps_core video
[ 1219.443009] CPU: 4 PID: 10942 Comm: kms_pipe_crc_ba Tainted: G     U  W        4.15.0-rc9-drm-intel-qa-ww4-commit-59275f1+ #1
[ 1219.443010] Hardware name: Dell Inc. OptiPlex 990/06D7TR, BIOS A19 08/26/2015
[ 1219.443011] RIP: 0010:drm_wait_one_vblank+0x18d/0x1a0
[ 1219.443012] RSP: 0018:ffffb59f0a50ba38 EFLAGS: 00010282
[ 1219.443013] RAX: 0000000000000000 RBX: ffff9775cea00000 RCX: 0000000000000006
[ 1219.443013] RDX: 0000000000000007 RSI: 0000000000000086 RDI: ffff9775dd316590
[ 1219.443014] RBP: 0000000000000001 R08: 0000000000000001 R09: 0000000000018a0e
[ 1219.443014] R10: 0000000000000000 R11: 0000000000018a0e R12: 0000000000000160
[ 1219.443015] R13: 0000000000000000 R14: 0000000000006ee3 R15: ffff9775cf1e4168
[ 1219.443016] FS:  00007f4e38c1ba00(0000) GS:ffff9775dd300000(0000) knlGS:0000000000000000
[ 1219.443016] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1219.443017] CR2: 00007f5760c59000 CR3: 000000041808a002 CR4: 00000000000606e0
[ 1219.443018] Call Trace:
[ 1219.443021]  ? wait_woken+0x80/0x80
[ 1219.443043]  ironlake_crtc_enable+0x79b/0xbf0 [i915]
[ 1219.443062]  intel_update_crtc+0x3d/0x90 [i915]
[ 1219.443080]  intel_update_crtcs+0x57/0x70 [i915]
[ 1219.443096]  intel_atomic_commit_tail+0x35b/0xd90 [i915]
[ 1219.443113]  intel_atomic_commit+0x22a/0x2f0 [i915]
[ 1219.443114]  drm_atomic_helper_set_config+0x5c/0x90
[ 1219.443116]  ? mutex_lock+0xe/0x30
[ 1219.443117]  __drm_mode_set_config_internal+0x61/0x110
[ 1219.443118]  drm_mode_setcrtc+0x45b/0x5b0
[ 1219.443120]  ? drm_mode_getcrtc+0x170/0x170
[ 1219.443121]  drm_ioctl_kernel+0x65/0xb0
[ 1219.443122]  drm_ioctl+0x2e5/0x3e0
[ 1219.443123]  ? drm_mode_getcrtc+0x170/0x170
[ 1219.443125]  ? remove_vma+0x5e/0x70
[ 1219.443127]  do_vfs_ioctl+0x9f/0x5f0
[ 1219.443128]  ? do_munmap+0x334/0x440
[ 1219.443129]  SyS_ioctl+0x74/0x80
[ 1219.443131]  entry_SYSCALL_64_fastpath+0x24/0x87
[ 1219.443132] RIP: 0033:0x7f4e36e104b7
[ 1219.443132] RSP: 002b:00007ffced613388 EFLAGS: 00000246
[ 1219.443133] Code: 0a ff ff ff e8 e5 ba a9 ff 48 89 e6 4c 89 ff e8 da e8 ad ff 45 85 ed 0f 85 14 ff ff ff 89 ee 48 c7 c7 e0 95 52 ae e8 23 b8 a9 ff <0f> ff e9 ff fe ff ff 66 90 66 2e 0f 1f 84 00 00 00 00 00 66 66 
[ 1219.443150] ---[ end trace 406804a9499dac6d ]---
[ 1229.534956] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1239.774934] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 1705.694910] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1715.934906] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1726.174909] [drm:drm_atomic_helper_wait_for_flip_done] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1736.414909] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[ 1746.654908] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 1756.894891] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
[ 1757.030901] ------------[ cut here ]------------
[ 1757.030903] vblank wait timed out on crtc 0
...
Comment 5 L Bourgard 2018-01-30 13:28:53 UTC 
Created attachment 137049 [details]
flip done time out

Here is another report:
lines of potential interest start at:
[   29.773561] pipe A vblank wait timed out
Comment 6 Elizabeth 2018-02-02 19:53:17 UTC 
With commit commit-e1b21c1+:
igt@kms_setmode@basic-clone-single-crtc, has the vblank warn
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b, has the vblank warn
igt@pm_rps@basic-api, has the flip_done timed out messages:

	
[  941.284590] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:37:pipe A] flip_done timed out
[  951.524479] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CRTC:47:pipe B] flip_done timed out
[  961.764509] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[  972.004510] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[  982.244509] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:28:primary A] flip_done timed out
[  992.484512] [drm:drm_atomic_helper_wait_for_dependencies] *ERROR* [PLANE:38:primary B] flip_done timed out
Comment 7 Elizabeth 2018-02-06 23:16:56 UTC 
Results with commit-078873d+

igt@kms_setmode@basic-clone-single-crtc
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b

[  746.216376] ------------[ cut here ]------------
[  746.216378] vblank wait timed out on crtc 0
[  746.216397] WARNING: CPU: 4 PID: 32416 at drivers/gpu/drm/drm_vblank.c:1073 drm_wait_one_vblank+0x18d/0x1a0
Comment 8 ak 2018-02-18 05:27:01 UTC 
Just close the bug Elizabeth since you have not heard about the bug for a "long" time, just like you did with all the same bugs.

Apparently, no opened bug reports means no bugs, hence Elizabeth is happy. Keep doing excellent job you are doing.
Comment 9 Elizabeth 2018-02-19 15:41:40 UTC 
*** Bug 105131 has been marked as a duplicate of this bug. ***
Comment 10 Elizabeth 2018-02-20 21:42:56 UTC 
With commit-67f1480+:
igt@kms_setmode@basic-clone-single-crtc, vblank warn and flip_done errors
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b, vblank warn and flip_done errors
igt@pm_rps@basic-api, flip_done errors.
Comment 11 Elizabeth 2018-03-05 18:16:45 UTC 
Sporadically appearing. Today's FF with commit-995edb2+ gave same results:
igt@kms_setmode@basic-clone-single-crtc, vblank warn and flip_done errors
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b, vblank warn and flip_done errors
igt@pm_rps@basic-api, flip_done errors.
Comment 12 russianneuromancer 2018-03-07 08:23:09 UTC 
@Elizabeth

> Sporadically appearing.

For me it's very easy to reproduce this bug on Dell 7140 with Linux 4.15 in Gnome Shell Wayland session. There is two ways of reproducing this: 

1. Let iio-sensor-proxy rotate screen few times in a row.
2. Let Gnome's powermanagement turn off tablet's screen and wait 10-15 minutes - issue will happen on  screen wakeup.

However, in case it's Broadwell, while I see "[SNB only]" in bugreport title. Should I fill separate issue or stay here?

Log:

[ 2602.205687] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out                                                                                                                                                        
[ 2612.445854] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2621.288552] i2c_hid i2c-SMO91D0:00: i2c_hid_get_input: incomplete report (53/13568)
[ 2622.686005] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out                                                                                                                                                        
[ 2634.718161] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2660.888675] i2c_hid i2c-SMO91D0:00: i2c_hid_get_input: incomplete report (53/13568)
[ 2664.926594] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
Comment 13 Elizabeth 2018-03-07 15:27:12 UTC 
(In reply to russianneuromancer from comment #12)
> @Elizabeth
> 
> > Sporadically appearing.
> 
> For me it's very easy to reproduce this bug on Dell 7140 with Linux 4.15 in
> Gnome Shell Wayland session. There is two ways of reproducing this: 
> 
> 1. Let iio-sensor-proxy rotate screen few times in a row.
> 2. Let Gnome's powermanagement turn off tablet's screen and wait 10-15
> minutes - issue will happen on  screen wakeup.
> 
> However, in case it's Broadwell, while I see "[SNB only]" in bugreport
> title. Should I fill separate issue or stay here?
> ...
Hello, yes please. Could you open a new bug for BDW with the information mentioned in comment 12 and dmesg or kern logs with debug information, drm.debug=0xe on grub? Thank you.
Comment 14 russianneuromancer 2018-03-08 23:06:10 UTC 
> Could you open a new bug for BDW with the information mentioned in comment 12 and dmesg or kern logs with debug information, drm.debug=0xe on grub? Thank you.

Done: bug 105405
Comment 15 Jani Saarinen 2018-03-29 07:11:36 UTC 
First of all. Sorry about spam.
This is mass update for our bugs. 

Sorry if you feel this annoying but with this trying to understand if bug still valid or not.
If bug investigation still in progress, please ignore this and I apologize!

If you think this is not anymore valid, please comment to the bug that can be closed.
If you haven't tested with our latest pre-upstream tree(drm-tip), can you do that also to see if issue is valid there still and if you cannot see issue there, please comment to the bug.
Comment 16 Elizabeth 2018-04-09 19:44:29 UTC 
Last seen with SNB:

igt@kms_pipe_crc_basic@suspend-read-crc-pipe-A, 4.16.0-rc5-ww11-commit-e867298+

Still it happens too sporadically now, so I'll mark as resolved. Please reopen if the warn shows again.
Comment 17 L Bourgard 2018-04-26 20:32:03 UTC 
Hi,

I reopened this bug, as it is not fixed.
It is very sporadic now, but sometimes it is still triggered.

It started displaying new messages though. Those are:

[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:40:LVDS-1] flip_done timed out
[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:28:primary A] flip_done timed out
[drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:40:LVDS-1] flip_done timed out
[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:28:primary A] flip_done timed out
Comment 18 Francesco Balestrieri 2018-07-03 12:10:18 UTC 
Changing priority to medium given the reproduction rate.
Comment 19 L Bourgard 2018-07-04 02:09:57 UTC 
For information it is very easy to trigger the flip_done timeout.

I'm running a Sandy Bridge processor (intel i5-2410m). From several reports that I've gathered this problem is very common on these processors, but very hard to reproduce on others.

Everyone that reported this problem is on a Sandy Bridge processor.
Comment 20 Martin Peres 2018-09-04 12:17:01 UTC 
(In reply to L Bourgard from comment #19)
> For information it is very easy to trigger the flip_done timeout.
> 
> I'm running a Sandy Bridge processor (intel i5-2410m). From several reports
> that I've gathered this problem is very common on these processors, but very
> hard to reproduce on others.
> 
> Everyone that reported this problem is on a Sandy Bridge processor.

We are using https://bugs.freedesktop.org/show_bug.cgi?id=103713 to keep track of this issue, since we automatically CI data for it.

*** This bug has been marked as a duplicate of bug 103713 ***

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.