[Bug 94126] New: [SKL/KBL] Vblank counter issues when DMC takes goes to DC5/DC6 impacting frontbuffer tracking and PSR with X modesetting(0) driver.

bugzilla-daemon at freedesktop.org bugzilla-daemon at freedesktop.org
Fri Feb 12 20:05:41 UTC 2016 

https://bugs.freedesktop.org/show_bug.cgi?id=94126

            Bug ID: 94126
           Summary: [SKL/KBL] Vblank counter issues when DMC takes goes to
                    DC5/DC6 impacting frontbuffer tracking and PSR with X
                    modesetting(0) driver.
           Product: DRI
           Version: DRI git
          Hardware: Other
                OS: Linux (All)
            Status: NEW
          Severity: major
          Priority: medium
         Component: DRM/Intel
          Assignee: intel-gfx-bugs at lists.freedesktop.org
          Reporter: rodrigo.vivi at gmail.com
        QA Contact: intel-gfx-bugs at lists.freedesktop.org
                CC: intel-gfx-bugs at lists.freedesktop.org

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!

-- 
You are receiving this mail because:
You are the assignee for the bug.
You are the QA Contact for the bug.
You are on the CC list for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/intel-gfx-bugs/attachments/20160212/62b75978/attachment.html>

More information about the intel-gfx-bugs mailing list