<html>
<head>
<base href="https://bugs.freedesktop.org/" />
</head>
<body><table border="1" cellspacing="0" cellpadding="8">
<tr>
<th>Bug ID</th>
<td><a class="bz_bug_link
bz_status_NEW "
title="NEW - [SKL/KBL] Vblank counter issues when DMC takes goes to DC5/DC6 impacting frontbuffer tracking and PSR with X modesetting(0) driver."
href="https://bugs.freedesktop.org/show_bug.cgi?id=94126">94126</a>
</td>
</tr>
<tr>
<th>Summary</th>
<td>[SKL/KBL] Vblank counter issues when DMC takes goes to DC5/DC6 impacting frontbuffer tracking and PSR with X modesetting(0) driver.
</td>
</tr>
<tr>
<th>Product</th>
<td>DRI
</td>
</tr>
<tr>
<th>Version</th>
<td>DRI git
</td>
</tr>
<tr>
<th>Hardware</th>
<td>Other
</td>
</tr>
<tr>
<th>OS</th>
<td>Linux (All)
</td>
</tr>
<tr>
<th>Status</th>
<td>NEW
</td>
</tr>
<tr>
<th>Severity</th>
<td>major
</td>
</tr>
<tr>
<th>Priority</th>
<td>medium
</td>
</tr>
<tr>
<th>Component</th>
<td>DRM/Intel
</td>
</tr>
<tr>
<th>Assignee</th>
<td>intel-gfx-bugs@lists.freedesktop.org
</td>
</tr>
<tr>
<th>Reporter</th>
<td>rodrigo.vivi@gmail.com
</td>
</tr>
<tr>
<th>QA Contact</th>
<td>intel-gfx-bugs@lists.freedesktop.org
</td>
</tr>
<tr>
<th>CC</th>
<td>intel-gfx-bugs@lists.freedesktop.org
</td>
</tr></table>
<p>
<div>
<pre>Note: PSR on SKL and KBL will be disabled by default while this case is not
properly handled because with X modesetting driver we can have a big slowness
between a type and the PSR getting Exit and screen consequently updated.
Issue: Hardware frame counters are reset to zero when DC5/DC6 are entered, but
cannot be restored because they are read-only registers. With this drm vblank
handlers get confused on the number and can take forever to return a wait for
vblank ioctl what can slow down some user space drawings. And much worst when
PSR is enabled and depend on frontbuffer tracking to exit and get screen
updated.
The working log on HSW:
[ 12.026748] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_SET_DOMAIN
[ 12.026757] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_MADVISE
[ 12.026769] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_MADVISE
[ 12.026776] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_BUSY
[ 12.026781] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_MADVISE
[ 12.026787] [drm:drm_ioctl] pid=1154, dev=0xe200, auth=1, I915_GEM_SET_DOMAIN
[ 12.026928] [drm:drm_ioctl] pid=1048, dev=0xe200, auth=1,
DRM_IOCTL_WAIT_VBLANK
[ 12.026936] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.026946] [drm:drm_wait_vblank] waiting on vblank count 529, crtc 0
[ 12.026949] [drm:drm_wait_vblank] returning 529 to client
[ 12.026952] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 12.026964] [drm:drm_ioctl] pid=1048, dev=0xe200, auth=1,
DRM_IOCTL_WAIT_VBLANK
[ 12.026968] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.026972] [drm:drm_wait_vblank] waiting on vblank count 529, crtc 0
[ 12.026975] [drm:drm_wait_vblank] returning 529 to client
[ 12.026978] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 12.026984] [drm:drm_ioctl] pid=1048, dev=0xe200, auth=1,
DRM_IOCTL_WAIT_VBLANK
[ 12.026988] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.026993] [drm:drm_queue_vblank_event] event on vblank count 530, current
529, crtc 0
[ 12.044837] [drm:drm_handle_vblank_events] vblank event on 530, current 531
[ 12.044841] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 12.044964] [drm:drm_ioctl] pid=1048, dev=0xe200, auth=1, I915_GEM_SW_FINISH
[ 12.044971] [drm:drm_ioctl] pid=1048, dev=0xe200, auth=1, I915_GEM_EXECBUFFER2
[ 12.045053] [drm:i915_gem_execbuffer_move_to_active [i915]] ERROR I915-DEBUG:
i915_gem_execbuffer_move_to_active 1118
[ 12.045080] [drm:intel_fb_obj_invalidate [i915]] ERROR I915-DEBUG:
intel_fb_obj_invalidate 90 fb_bits 1 origin 2
– PSR EXIT –
The Bad case on on SKL:
[ 12.079666] [drm:drm_ioctl] pid=1101, dev=0xe200, auth=1, I915_GEM_SET_DOMAIN
[ 12.079700] [drm:drm_ioctl] pid=1101, dev=0xe200, auth=1, I915_GEM_MADVISE
[ 12.079720] [drm:drm_ioctl] pid=1101, dev=0xe200, auth=1, I915_GEM_BUSY
[ 12.079732] [drm:drm_ioctl] pid=1101, dev=0xe200, auth=1, I915_GEM_MADVISE
[ 12.079746] [drm:drm_ioctl] pid=1101, dev=0xe200, auth=1, I915_GEM_SET_DOMAIN
[ 12.080020] [drm:drm_ioctl] pid=991, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
[ 12.080051] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.080797] [drm:drm_calc_vbltimestamp_from_scanoutpos] crtc 0: Noisy
timestamp 69 us > 20 us [3 reps].
[ 12.080833] [drm:drm_wait_vblank] waiting on vblank count 36, crtc 0
[ 12.080844] [drm:drm_wait_vblank] returning 36 to client
[ 12.080931] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 12.080991] [drm:drm_ioctl] pid=991, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
[ 12.081011] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.081025] [drm:drm_wait_vblank] waiting on vblank count 36, crtc 0
[ 12.081036] [drm:drm_wait_vblank] returning 36 to client
[ 12.081046] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 12.081068] [drm:drm_ioctl] pid=991, dev=0xe200, auth=1, DRM_IOCTL_WAIT_VBLANK
[ 12.081080] [drm:drm_vblank_enable] enabling vblank on crtc 0, ret: 0
[ 12.081100] [drm:drm_queue_vblank_event] event on vblank count 541, current
36, crtc 0
[ 20.497782] [drm:drm_handle_vblank_events] vblank event on 541, current 541
[ 20.497796] [drm:vblank_disable_fn] disabling vblank on crtc 0
[ 20.498061] [drm:drm_ioctl] pid=991, dev=0xe200, auth=1, I915_GEM_SW_FINISH
[ 20.498079] [drm:drm_ioctl] pid=991, dev=0xe200, auth=1, I915_GEM_EXECBUFFER2
[ 20.498296] [drm:i915_gem_execbuffer_move_to_active [i915]] ERROR I915-DEBUG:
i915_gem_execbuffer_move_to_active 1118
[ 20.498390] [drm:intel_fb_obj_invalidate [i915]] ERROR I915-DEBUG:
intel_fb_obj_invalidate 90 fb_bits 1 origin 2
– PSR EXIT –
So the slowness was caused by the vblank couter waiting to go from 36 to 541!</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>