<html>
    <head>
      <base href="https://bugs.freedesktop.org/">
    </head>
    <body>
      <p>
        <div>
            <b><a class="bz_bug_link 
          bz_status_NEEDINFO "
   title="NEEDINFO - [SNB] igt@[vgem_*/prime_*/pm_*] dmesg-warn *ERROR* [CRTC:47:pipe B] flip_done timed out"
   href="https://bugs.freedesktop.org/show_bug.cgi?id=104145#c1">Comment # 1</a>
              on <a class="bz_bug_link 
          bz_status_NEEDINFO "
   title="NEEDINFO - [SNB] igt@[vgem_*/prime_*/pm_*] dmesg-warn *ERROR* [CRTC:47:pipe B] flip_done timed out"
   href="https://bugs.freedesktop.org/show_bug.cgi?id=104145">bug 104145</a>
              from <span class="vcard"><a class="email" href="mailto:elizabethx.de.la.torre.mena@intel.com" title="Elizabeth <elizabethx.de.la.torre.mena@intel.com>"> <span class="fn">Elizabeth</span></a>
</span></b>
        <pre>Created <span class=""><a href="attachment.cgi?id=136008" name="attach_136008" title="kern_log_SNB_flip_timeouts">attachment 136008</a> <a href="attachment.cgi?id=136008&action=edit" title="kern_log_SNB_flip_timeouts">[details]</a></span>
kern_log_SNB_flip_timeouts

It seems that problem is evolving, now I also get vblank warns and failed
tests.

Test igt@prime_vgem@basic-fence-flip, output:
IGT-Version: 1.20-g1db1246 (x86_64) (Linux:
4.15.0-rc2-drm-intel-qa-ww49-commit-1a0d67e+ x86_64)
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [test_flip+0x425]
  #2 [__real_main757+0x17df]
  #3 [main+0x23]
  #4 [__libc_start_main+0xf1]
  #5 [_start+0x29]
  #6 [<unknown>+0x29]
Subtest basic-fence-flip: FAIL (41.076s)
Test requirement not met in function __real_main757, file prime_vgem.c:849:
Test requirement: vgem_fence_has_flag(vgem, WIP_VGEM_FENCE_NOTIMEOUT)
(prime_vgem:22664) CRITICAL: Test assertion failure function test_flip, file
prime_vgem.c:738:
(prime_vgem:22664) CRITICAL: Failed assertion: (drmModePageFlip(i915, crtc_id,
fb_id[i], 0x01, &fb_id[i])) == 0
(prime_vgem:22664) CRITICAL: Last errno: 16, Device or resource busy
Subtest basic-fence-flip failed.
**** DEBUG ****
(prime_vgem:22664) ioctl-wrappers-DEBUG: Test requirement passed: has_modifiers
(prime_vgem:22664) ioctl-wrappers-DEBUG: Test requirement passed: has_modifiers
(prime_vgem:22664) DEBUG: Test requirement passed: (crtc_id =
set_fb_on_crtc(i915, 0, &bo[0], fb_id[0]))
(prime_vgem:22664) CRITICAL: Test assertion failure function test_flip, file
prime_vgem.c:738:
(prime_vgem:22664) CRITICAL: Failed assertion: (drmModePageFlip(i915, crtc_id,
fb_id[i], 0x01, &fb_id[i])) == 0
(prime_vgem:22664) CRITICAL: Last errno: 16, Device or resource busy
(prime_vgem:22664) igt-core-INFO: Stack trace:
(prime_vgem:22664) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
(prime_vgem:22664) igt-core-INFO:   #1 [test_flip+0x425]
(prime_vgem:22664) igt-core-INFO:   #2 [__real_main757+0x17df]
(prime_vgem:22664) igt-core-INFO:   #3 [main+0x23]
(prime_vgem:22664) igt-core-INFO:   #4 [__libc_start_main+0xf1]
(prime_vgem:22664) igt-core-INFO:   #5 [_start+0x29]
(prime_vgem:22664) igt-core-INFO:   #6 [<unknown>+0x29]
****  END  ****

Dmesg:
[ 2744.036434] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2754.276424] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:47:pipe B] flip_done timed out
[ 2764.516433] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 2774.756428] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 2784.996434] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:28:primary A] flip_done timed out
[ 2795.236431] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:38:primary B] flip_done timed out
[ 2805.476431] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2815.716425] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:47:pipe B] flip_done timed out
[ 2825.956434] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2836.196428] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 2846.436431] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:28:primary A] flip_done timed out
[ 2846.568413] ------------[ cut here ]------------
[ 2846.568415] vblank wait timed out on crtc 0
[ 2846.568465] WARNING: CPU: 2 PID: 22664 at drivers/gpu/drm/drm_vblank.c:1073
drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 2846.568466] Modules linked in: vgem ip6table_filter ip6_tables
iptable_filter snd_hda_codec_hdmi intel_rapl snd_hda_codec_realtek
x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_generic coretemp kvm_intel
kvm snd_hda_intel snd_hda_codec irqbypass snd_hda_core snd_hwdep
crct10dif_pclmul crc32_pclmul snd_pcm ghash_clmulni_intel pcbc snd_seq_midi
snd_seq_midi_event binfmt_misc snd_rawmidi aesni_intel aes_x86_64 crypto_simd
nls_iso8859_1 glue_helper cryptd snd_seq dcdbas intel_cstate snd_seq_device
intel_rapl_perf snd_timer serio_raw snd mei_me mei soundcore shpchp lpc_ich
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 drm e1000e psmouse ahci libahci ptp pps_core video
[ 2846.568489] CPU: 2 PID: 22664 Comm: prime_vgem Tainted: G     U  W       
4.15.0-rc2-drm-intel-qa-ww49-commit-1a0d67e+ #1
[ 2846.568490] Hardware name: Dell Inc. OptiPlex 990/06D7TR, BIOS A19
08/26/2015
[ 2846.568491] task: 00000000c9bea46b task.stack: 0000000056e5785a
[ 2846.568498] RIP: 0010:drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 2846.568499] RSP: 0018:ffffa534e1de7a30 EFLAGS: 00010282
[ 2846.568500] RAX: 0000000000000000 RBX: ffff8fd190220000 RCX:
0000000000000006
[ 2846.568500] RDX: 0000000000000007 RSI: 0000000000000092 RDI:
ffff8fd19d28dcd0
[ 2846.568501] RBP: 0000000000000000 R08: 0000000000000001 R09:
0000000000018ce5
[ 2846.568501] R10: 0000000000000000 R11: 0000000000018ce5 R12:
0000000000000000
[ 2846.568502] R13: 0000000000000000 R14: 000000000001edc8 R15:
ffff8fd19aa87c08
[ 2846.568503] FS:  00007fa7c4e62880(0000) GS:ffff8fd19d280000(0000)
knlGS:0000000000000000
[ 2846.568504] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2846.568504] CR2: 0000559639fd53a8 CR3: 0000000415a6a001 CR4:
00000000000606e0
[ 2846.568505] Call Trace:
[ 2846.568511]  ? wait_woken+0x80/0x80
[ 2846.568532]  ironlake_crtc_enable+0x792/0xbf0 [i915]
[ 2846.568552]  intel_update_crtc+0x3d/0x90 [i915]
[ 2846.568570]  intel_update_crtcs+0x57/0x70 [i915]
[ 2846.568587]  intel_atomic_commit_tail+0x39d/0xdd0 [i915]
[ 2846.568605]  ? intel_atomic_commit_ready+0x44/0x4c [i915]
[ 2846.568622]  intel_atomic_commit+0x1fd/0x2a0 [i915]
[ 2846.568627]  drm_atomic_helper_set_config+0x5c/0x90 [drm_kms_helper]
[ 2846.568630]  ? mutex_lock+0xe/0x30
[ 2846.568637]  __drm_mode_set_config_internal+0x61/0x110 [drm]
[ 2846.568645]  drm_mode_setcrtc+0x45b/0x5b0 [drm]
[ 2846.568653]  ? drm_mode_getencoder+0x11d/0x180 [drm]
[ 2846.568659]  ? drm_mode_getcrtc+0x170/0x170 [drm]
[ 2846.568666]  drm_ioctl_kernel+0x65/0xb0 [drm]
[ 2846.568672]  drm_ioctl+0x2e5/0x3e0 [drm]
[ 2846.568678]  ? drm_mode_getcrtc+0x170/0x170 [drm]
[ 2846.568681]  do_vfs_ioctl+0x9f/0x5f0
[ 2846.568684]  ? handle_mm_fault+0xc4/0x1b0
[ 2846.568686]  ? __do_page_fault+0x287/0x500
[ 2846.568687]  SyS_ioctl+0x74/0x80
[ 2846.568688]  entry_SYSCALL_64_fastpath+0x1e/0x81
[ 2846.568690] RIP: 0033:0x7fa7c33728b7
[ 2846.568690] RSP: 002b:00007fff92d552f8 EFLAGS: 00000246 ORIG_RAX:
0000000000000010
[ 2846.568691] RAX: ffffffffffffffda RBX: 00007fa7c3636b00 RCX:
00007fa7c33728b7
[ 2846.568692] RDX: 00007fff92d55430 RSI: 00000000c06864a2 RDI:
0000000000000004
[ 2846.568692] RBP: 0000000000044010 R08: 0000000000000300 R09:
0000000000000000
[ 2846.568693] R10: 00007fa7c4e1d010 R11: 0000000000000246 R12:
0000000000045000
[ 2846.568693] R13: 0000000000044010 R14: 0000000000001000 R15:
000000000000270c
[ 2846.568694] Code: 0a ff ff ff e8 85 b9 dc cb 48 89 e6 4c 89 ff e8 2a e6 e0
cb 45 85 ed 0f 85 14 ff ff ff 89 ee 48 c7 c7 38 f5 2c c0 e8 c3 b6 dc cb <0f> ff
e9 ff fe ff ff 66 90 66 2e 0f 1f 84 00 00 00 00 00 66 66 
[ 2846.568711] ---[ end trace 85c462e7447a738a ]---
[ 2856.676430] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2866.916428] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2877.156393] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:28:primary A] flip_done timed out
[ 2887.396429] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2897.636432] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2907.876430] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CRTC:47:pipe B] flip_done timed out
[ 2918.116433] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CONNECTOR:48:VGA-1] flip_done timed out
[ 2928.356402] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [CONNECTOR:56:DP-1] flip_done timed out
[ 2938.596433] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:28:primary A] flip_done timed out
[ 2948.836435] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]]
*ERROR* [PLANE:38:primary B] flip_done timed out
[ 2948.964414] ------------[ cut here ]------------
[ 2948.964417] vblank wait timed out on crtc 0
[ 2948.964467] WARNING: CPU: 6 PID: 22664 at drivers/gpu/drm/drm_vblank.c:1073
drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 2948.964467] Modules linked in: vgem ip6table_filter ip6_tables
iptable_filter snd_hda_codec_hdmi intel_rapl snd_hda_codec_realtek
x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_generic coretemp kvm_intel
kvm snd_hda_intel snd_hda_codec irqbypass snd_hda_core snd_hwdep
crct10dif_pclmul crc32_pclmul snd_pcm ghash_clmulni_intel pcbc snd_seq_midi
snd_seq_midi_event binfmt_misc snd_rawmidi aesni_intel aes_x86_64 crypto_simd
nls_iso8859_1 glue_helper cryptd snd_seq dcdbas intel_cstate snd_seq_device
intel_rapl_perf snd_timer serio_raw snd mei_me mei soundcore shpchp lpc_ich
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 drm e1000e psmouse ahci libahci ptp pps_core video
[ 2948.964493] CPU: 6 PID: 22664 Comm: prime_vgem Tainted: G     U  W       
4.15.0-rc2-drm-intel-qa-ww49-commit-1a0d67e+ #1
[ 2948.964493] Hardware name: Dell Inc. OptiPlex 990/06D7TR, BIOS A19
08/26/2015
[ 2948.964494] task: 00000000c9bea46b task.stack: 0000000056e5785a
[ 2948.964501] RIP: 0010:drm_wait_one_vblank+0x18d/0x1a0 [drm]
[ 2948.964501] RSP: 0018:ffffa534e1de7b80 EFLAGS: 00010282
[ 2948.964502] RAX: 0000000000000000 RBX: ffff8fd190220000 RCX:
0000000000000006
[ 2948.964503] RDX: 0000000000000007 RSI: 0000000000000096 RDI:
ffff8fd19d38dcd0
[ 2948.964504] RBP: 0000000000000000 R08: 0000000000000001 R09:
0000000000018d92
[ 2948.964504] R10: 0000000000000000 R11: 0000000000018d92 R12:
0000000000000000
[ 2948.964505] R13: 0000000000000000 R14: 00000000000205b4 R15:
ffff8fd19aa87c08
[ 2948.964506] FS:  00007fa7c4e62880(0000) GS:ffff8fd19d380000(0000)
knlGS:0000000000000000
[ 2948.964506] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2948.964507] CR2: 000055e8ce40bbb8 CR3: 0000000415a6a006 CR4:
00000000000606e0
[ 2948.964508] Call Trace:
[ 2948.964514]  ? wait_woken+0x80/0x80
[ 2948.964535]  ironlake_crtc_enable+0x792/0xbf0 [i915]
[ 2948.964556]  intel_update_crtc+0x3d/0x90 [i915]
[ 2948.964574]  intel_update_crtcs+0x57/0x70 [i915]
[ 2948.964591]  intel_atomic_commit_tail+0x39d/0xdd0 [i915]
[ 2948.964609]  ? intel_atomic_commit_ready+0x44/0x4c [i915]
[ 2948.964626]  intel_atomic_commit+0x1fd/0x2a0 [i915]
[ 2948.964630]  restore_fbdev_mode_atomic+0x1ab/0x220 [drm_kms_helper]
[ 2948.964634]  drm_fb_helper_restore_fbdev_mode_unlocked+0x45/0x90
[drm_kms_helper]
[ 2948.964653]  intel_fbdev_restore_mode+0x30/0x80 [i915]
[ 2948.964667]  i915_driver_lastclose+0xa/0x10 [i915]
[ 2948.964674]  drm_lastclose+0x34/0xf0 [drm]
[ 2948.964680]  drm_release+0x2b6/0x370 [drm]
[ 2948.964682]  __fput+0xd5/0x210
[ 2948.964685]  task_work_run+0x80/0xa0
[ 2948.964687]  exit_to_usermode_loop+0xbb/0xc0
[ 2948.964688]  syscall_return_slowpath+0x81/0xa0
[ 2948.964690]  entry_SYSCALL_64_fastpath+0x7f/0x81
[ 2948.964691] RIP: 0033:0x7fa7c408b730
[ 2948.964692] RSP: 002b:00007fff92d55b28 EFLAGS: 00000246 ORIG_RAX:
0000000000000003
[ 2948.964693] RAX: 0000000000000000 RBX: 0000000000000000 RCX:
00007fa7c408b730
[ 2948.964694] RDX: 0000000000000005 RSI: 00007fff92d55a20 RDI:
0000000000000005
[ 2948.964694] RBP: 0000000000624a00 R08: 00000000018dc460 R09:
0000000000000000
[ 2948.964695] R10: 0000000000000000 R11: 0000000000000246 R12:
0000000000000001
[ 2948.964695] R13: 00007fa7c3637c20 R14: 0000000000000000 R15:
0000000000000000
[ 2948.964696] Code: 0a ff ff ff e8 85 b9 dc cb 48 89 e6 4c 89 ff e8 2a e6 e0
cb 45 85 ed 0f 85 14 ff ff ff 89 ee 48 c7 c7 38 f5 2c c0 e8 c3 b6 dc cb <0f> ff
e9 ff fe ff ff 66 90 66 2e 0f 1f 84 00 00 00 00 00 66 66 
[ 2948.964713] ---[ end trace 85c462e7447a738b ]---
[ 2959.076434] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:37:pipe A] flip_done timed out
[ 2969.316427] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]]
*ERROR* [CRTC:47:pipe B] flip_done timed out

Other test failed with the vbland and/or flip timeout messages:
igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b
igt@prime_busy@basic-wait-before-default
igt@prime_busy@basic-before-default
igt@prime_busy@basic-after-default</pre>
        </div>
      </p>


      <hr>
      <span>You are receiving this mail because:</span>

      <ul>
          <li>You are the assignee for the bug.</li>
          <li>You are the QA Contact for the bug.</li>
          <li>You are on the CC list for the bug.</li>
      </ul>
    </body>
</html>