Bug 104918 - [SKL] enable_psr=1 on 4.15 causes rapid hangs
Summary: [SKL] enable_psr=1 on 4.15 causes rapid hangs
Status: CLOSED WORKSFORME
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: PatchSubmitted
Keywords:
Depends on:
Blocks:
 
Reported: 2018-02-02 19:22 UTC by Andy Lutomirski
Modified: 2018-04-25 11:14 UTC (History)
2 users (show)

See Also:
i915 platform: SKL
i915 features: display/PSR


Attachments
Non-working fix attempt (3.54 KB, patch)
2018-02-03 05:15 UTC, Andy Lutomirski
no flags Details | Splinter Review

Description Andy Lutomirski 2018-02-02 19:22:49 UTC
With enable_psr=1 on a 4.14 Fedora kernel, I have some minor lag issues, but everything works.  On 4.15, the system dies very quickly with PSR enabled, and the logs say:

[drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out

I'll follow up if I dig out more useful info.
Comment 1 Andy Lutomirski 2018-02-02 19:34:58 UTC
Here's the most recent hang with a bunch of debugging on.  It's a stock 4.15 kernel except that I added a couple extra DRM_DEBUG_KMS() calls in the PSR code.

Feb 02 11:24:50.016362: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 000000003a1e7cd0 to [CRTC:37:pipe A]
Feb 02 11:24:50.016424: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 000000003a1e7cd0
Feb 02 11:24:50.016485: [drm:drm_atomic_check_only [drm]] checking 00000000cb88e810
Feb 02 11:24:50.016588: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.016657: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.016720: [drm:drm_atomic_nonblocking_commit [drm]] committing 00000000cb88e810 nonblocking
Feb 02 11:24:50.021925: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.022054: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000cb88e810
Feb 02 11:24:50.022139: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000f22c4da1
Feb 02 11:24:50.022200: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000f22c4da1
Feb 02 11:24:50.022255: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000cb88e810
Feb 02 11:24:50.022310: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000f22c4da1
Feb 02 11:24:50.031876: [drm:drm_mode_addfb2 [drm]] [FB:85]
Feb 02 11:24:50.032108: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000f22c4da1
Feb 02 11:24:50.032251: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000091671cd2 state to 00000000f22c4da1
Feb 02 11:24:50.032331: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 0000000027471f78 state to 00000000f22c4da1
Feb 02 11:24:50.032396: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 0000000027471f78 to [CRTC:37:pipe A]
Feb 02 11:24:50.032458: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:85] for plane state 0000000027471f78
Feb 02 11:24:50.032520: [drm:drm_atomic_check_only [drm]] checking 00000000f22c4da1
Feb 02 11:24:50.032583: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 85
Feb 02 11:24:50.032656: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.032722: [drm:drm_atomic_nonblocking_commit [drm]] committing 00000000f22c4da1 nonblocking
Feb 02 11:24:50.037907: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.038048: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000f22c4da1
Feb 02 11:24:50.038139: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000098b0f501
Feb 02 11:24:50.038201: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000098b0f501
Feb 02 11:24:50.038256: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000f22c4da1
Feb 02 11:24:50.038311: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000098b0f501
Feb 02 11:24:50.048896: [drm:drm_mode_addfb2 [drm]] [FB:79]
Feb 02 11:24:50.049148: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000098b0f501
Feb 02 11:24:50.049226: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 00000000583c9d8d state to 0000000098b0f501
Feb 02 11:24:50.049292: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 000000008fa29d1b state to 0000000098b0f501
Feb 02 11:24:50.049356: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 000000008fa29d1b to [CRTC:37:pipe A]
Feb 02 11:24:50.049417: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 000000008fa29d1b
Feb 02 11:24:50.049498: [drm:drm_atomic_check_only [drm]] checking 0000000098b0f501
Feb 02 11:24:50.049571: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.049636: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.049699: [drm:drm_atomic_nonblocking_commit [drm]] committing 0000000098b0f501 nonblocking
Feb 02 11:24:50.054854: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.055109: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000098b0f501
Feb 02 11:24:50.055199: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000041b61820
Feb 02 11:24:50.055266: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000041b61820
Feb 02 11:24:50.055369: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000098b0f501
Feb 02 11:24:50.055440: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000041b61820
Feb 02 11:24:50.064848: [drm:drm_mode_addfb2 [drm]] [FB:85]
Feb 02 11:24:50.065060: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000bf6759a6
Feb 02 11:24:50.065130: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 00000000022b9432 state to 00000000bf6759a6
Feb 02 11:24:50.065186: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 00000000f1bfb6dd state to 00000000bf6759a6
Feb 02 11:24:50.065241: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 00000000f1bfb6dd to [CRTC:37:pipe A]
Feb 02 11:24:50.065308: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:85] for plane state 00000000f1bfb6dd
Feb 02 11:24:50.065365: [drm:drm_atomic_check_only [drm]] checking 00000000bf6759a6
Feb 02 11:24:50.065420: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 85
Feb 02 11:24:50.065475: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.065530: [drm:drm_atomic_nonblocking_commit [drm]] committing 00000000bf6759a6 nonblocking
Feb 02 11:24:50.071922: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.072162: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000bf6759a6
Feb 02 11:24:50.072255: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000f22c4da1
Feb 02 11:24:50.072323: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000f22c4da1
Feb 02 11:24:50.072398: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000bf6759a6
Feb 02 11:24:50.072465: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000f22c4da1
Feb 02 11:24:50.081880: [drm:drm_mode_addfb2 [drm]] [FB:79]
Feb 02 11:24:50.082071: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000f22c4da1
Feb 02 11:24:50.082144: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000091671cd2 state to 00000000f22c4da1
Feb 02 11:24:50.082209: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 000000006292593f state to 00000000f22c4da1
Feb 02 11:24:50.082272: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 000000006292593f to [CRTC:37:pipe A]
Feb 02 11:24:50.082334: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 000000006292593f
Feb 02 11:24:50.082397: [drm:drm_atomic_check_only [drm]] checking 00000000f22c4da1
Feb 02 11:24:50.082501: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.082570: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.082634: [drm:drm_atomic_nonblocking_commit [drm]] committing 00000000f22c4da1 nonblocking
Feb 02 11:24:50.087896: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.088068: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000008b80050d
Feb 02 11:24:50.088155: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000f22c4da1
Feb 02 11:24:50.088215: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000008b80050d
Feb 02 11:24:50.088270: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000008b80050d
Feb 02 11:24:50.088325: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000f22c4da1
Feb 02 11:24:50.097965: [drm:drm_mode_addfb2 [drm]] [FB:85]
Feb 02 11:24:50.098197: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000008b80050d
Feb 02 11:24:50.098284: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000050807970 state to 000000008b80050d
Feb 02 11:24:50.098392: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 0000000027471f78 state to 000000008b80050d
Feb 02 11:24:50.098464: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 0000000027471f78 to [CRTC:37:pipe A]
Feb 02 11:24:50.098526: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:85] for plane state 0000000027471f78
Feb 02 11:24:50.098588: [drm:drm_atomic_check_only [drm]] checking 000000008b80050d
Feb 02 11:24:50.098649: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 85
Feb 02 11:24:50.098712: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.098775: [drm:drm_atomic_nonblocking_commit [drm]] committing 000000008b80050d nonblocking
Feb 02 11:24:50.104847: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.105099: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000008b80050d
Feb 02 11:24:50.105184: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000098b0f501
Feb 02 11:24:50.105249: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000098b0f501
Feb 02 11:24:50.105312: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000008b80050d
Feb 02 11:24:50.105396: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000098b0f501
Feb 02 11:24:50.111910: [drm:intel_psr_work [i915]] intel_psr_work: waiting for ready
Feb 02 11:24:50.112100: [drm:intel_psr_work [i915]] intel_psr_work: activating PSR after 2us wait for ready
Feb 02 11:24:50.114923: [drm:drm_mode_addfb2 [drm]] [FB:79]
Feb 02 11:24:50.115079: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000098b0f501
Feb 02 11:24:50.115150: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 000000000edd6fce state to 0000000098b0f501
Feb 02 11:24:50.115216: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 000000004676cd2b state to 0000000098b0f501
Feb 02 11:24:50.115311: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 000000004676cd2b to [CRTC:37:pipe A]
Feb 02 11:24:50.115377: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 000000004676cd2b
Feb 02 11:24:50.115438: [drm:drm_atomic_check_only [drm]] checking 0000000098b0f501
Feb 02 11:24:50.115500: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.115581: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.115648: [drm:drm_atomic_nonblocking_commit [drm]] committing 0000000098b0f501 nonblocking
Feb 02 11:24:50.121881: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.122119: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000041b61820
Feb 02 11:24:50.122203: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000098b0f501
Feb 02 11:24:50.122269: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000098b0f501
Feb 02 11:24:50.122330: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000041b61820
Feb 02 11:24:50.122392: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000041b61820
Feb 02 11:24:50.130846: [drm:drm_mode_addfb2 [drm]] [FB:85]
Feb 02 11:24:50.131067: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000000f7659c4
Feb 02 11:24:50.131196: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 00000000022b9432 state to 000000000f7659c4
Feb 02 11:24:50.131388: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 00000000f1bfb6dd state to 000000000f7659c4
Feb 02 11:24:50.131459: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 00000000f1bfb6dd to [CRTC:37:pipe A]
Feb 02 11:24:50.131521: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:85] for plane state 00000000f1bfb6dd
Feb 02 11:24:50.131584: [drm:drm_atomic_check_only [drm]] checking 000000000f7659c4
Feb 02 11:24:50.131645: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 85
Feb 02 11:24:50.131707: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.131779: [drm:drm_atomic_nonblocking_commit [drm]] committing 000000000f7659c4 nonblocking
Feb 02 11:24:50.138926: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.139069: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000008b80050d
Feb 02 11:24:50.139143: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000000f7659c4
Feb 02 11:24:50.139209: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000000f7659c4
Feb 02 11:24:50.139303: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000008b80050d
Feb 02 11:24:50.139371: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000008b80050d
Feb 02 11:24:50.147922: [drm:drm_mode_addfb2 [drm]] [FB:79]
Feb 02 11:24:50.148102: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000008b80050d
Feb 02 11:24:50.148175: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000091671cd2 state to 000000008b80050d
Feb 02 11:24:50.148275: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 000000006292593f state to 000000008b80050d
Feb 02 11:24:50.148343: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 000000006292593f to [CRTC:37:pipe A]
Feb 02 11:24:50.148408: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 000000006292593f
Feb 02 11:24:50.148470: [drm:drm_atomic_check_only [drm]] checking 000000008b80050d
Feb 02 11:24:50.148532: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.148595: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.148677: [drm:drm_atomic_nonblocking_commit [drm]] committing 000000008b80050d nonblocking
Feb 02 11:24:50.154841: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.155014: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000005be86800
Feb 02 11:24:50.155095: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000005be86800
Feb 02 11:24:50.155161: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000008b80050d
Feb 02 11:24:50.155223: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000005be86800
Feb 02 11:24:50.155284: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000008b80050d
Feb 02 11:24:50.163858: [drm:drm_mode_addfb2 [drm]] [FB:85]
Feb 02 11:24:50.164084: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000005be86800
Feb 02 11:24:50.164202: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000034086183 state to 000000005be86800
Feb 02 11:24:50.164280: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 00000000ffb66fa4 state to 000000005be86800
Feb 02 11:24:50.164345: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 00000000ffb66fa4 to [CRTC:37:pipe A]
Feb 02 11:24:50.164449: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:85] for plane state 00000000ffb66fa4
Feb 02 11:24:50.164518: [drm:drm_atomic_check_only [drm]] checking 000000005be86800
Feb 02 11:24:50.164591: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 85
Feb 02 11:24:50.164657: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.164721: [drm:drm_atomic_nonblocking_commit [drm]] committing 000000005be86800 nonblocking
Feb 02 11:24:50.171847: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:24:50.172047: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000005be86800
Feb 02 11:24:50.172115: [drm:drm_atomic_state_init [drm]] Allocated atomic state 0000000098b0f501
Feb 02 11:24:50.172174: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 0000000098b0f501
Feb 02 11:24:50.172229: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000005be86800
Feb 02 11:24:50.172282: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 0000000098b0f501
Feb 02 11:24:50.215928: [drm:edp_panel_vdd_off_sync [i915]] Turning eDP port A VDD off
Feb 02 11:24:50.216199: [drm:edp_panel_vdd_off_sync [i915]] PP_STATUS: 0x80000008 PP_CONTROL: 0x00000007
Feb 02 11:24:50.216292: [drm:intel_power_well_disable [i915]] disabling DC off
Feb 02 11:24:50.216367: [drm:skl_enable_dc6 [i915]] Enabling DC6
Feb 02 11:24:50.216440: [drm:gen9_set_dc_state [i915]] Setting DC state from 00 to 02
Feb 02 11:24:50.223928: [drm:intel_psr_work [i915]] intel_psr_work: waiting for ready
Feb 02 11:24:50.224112: [drm:intel_psr_work [i915]] intel_psr_work: activating PSR after 2us wait for ready
Feb 02 11:24:50.855389: [drm:drm_mode_addfb2 [drm]] [FB:79]
Feb 02 11:24:50.855478: [drm:drm_atomic_state_init [drm]] Allocated atomic state 00000000b3bc1064
Feb 02 11:24:50.855528: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 000000004b6d3923 state to 00000000b3bc1064
Feb 02 11:24:50.855564: [drm:drm_atomic_get_plane_state [drm]] Added [PLANE:28:plane 1A] 0000000040b75f3e state to 00000000b3bc1064
Feb 02 11:24:50.855591: [drm:drm_atomic_set_crtc_for_plane [drm]] Link plane state 0000000040b75f3e to [CRTC:37:pipe A]
Feb 02 11:24:50.855621: [drm:drm_atomic_set_fb_for_plane [drm]] Set [FB:79] for plane state 0000000040b75f3e
Feb 02 11:24:50.855647: [drm:drm_atomic_check_only [drm]] checking 00000000b3bc1064
Feb 02 11:24:50.855675: [drm:intel_plane_atomic_calc_changes [i915]] [CRTC:37:pipe A] has [PLANE:28:plane 1A] with fb 79
Feb 02 11:24:50.855702: [drm:intel_plane_atomic_calc_changes [i915]] [PLANE:28:plane 1A] visible 1 -> 1, off 0, on 0, ms 0
Feb 02 11:24:50.855730: [drm:drm_atomic_nonblocking_commit [drm]] committing 00000000b3bc1064 nonblocking
Feb 02 11:25:01.223926: [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
Feb 02 11:25:01.224142: [drm:intel_psr_flush [i915]] intel_psr_flush: clear frontbuffer bits 1
Feb 02 11:25:01.224214: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 00000000b3bc1064
Feb 02 11:25:01.224271: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 00000000b3bc1064
Feb 02 11:25:01.327915: [drm:intel_psr_work [i915]] intel_psr_work: waiting for ready
Feb 02 11:25:01.328091: [drm:intel_psr_work [i915]] intel_psr_work: activating PSR after 2us wait for ready
Feb 02 11:25:02.331844: [drm:drm_atomic_state_init [drm]] Allocated atomic state 000000008cbfb741
Feb 02 11:25:02.332062: [drm:drm_atomic_get_crtc_state [drm]] Added [CRTC:37:pipe A] 0000000034086183 state to 000000008cbfb741
Feb 02 11:25:02.332403: [drm:drm_atomic_add_affected_connectors [drm]] Adding all current connectors for [CRTC:37:pipe A] to 000000008cbfb741
Feb 02 11:25:02.332555: [drm:drm_atomic_get_connector_state [drm]] Added [CONNECTOR:59:eDP-1] 000000005cdcefce state to 000000008cbfb741
Feb 02 11:25:02.332622: [drm:drm_atomic_check_only [drm]] checking 000000008cbfb741
Feb 02 11:25:02.332681: [drm:drm_atomic_helper_check_modeset [drm_kms_helper]] Updating routing for [CONNECTOR:59:eDP-1]
Feb 02 11:25:02.332745: [drm:drm_atomic_helper_check_modeset [drm_kms_helper]] [CONNECTOR:59:eDP-1] keeps [ENCODER:58:DDI A], now on [CRTC:37:pipe A]
Feb 02 11:25:02.332826: [drm:drm_atomic_commit [drm]] committing 000000008cbfb741
Feb 02 11:25:12.487852: [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
Feb 02 11:25:22.727892: [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:37:pipe A] flip_done timed out
Feb 02 11:25:22.728184: [drm:drm_atomic_state_default_clear [drm]] Clearing atomic state 000000008cbfb741
Feb 02 11:25:22.728277: [drm:__drm_atomic_state_free [drm]] Freeing atomic state 000000008cbfb741
Comment 2 Andy Lutomirski 2018-02-03 05:15:12 UTC
Created attachment 137145 [details] [review]
Non-working fix attempt

I wrote up the attached patch.  It makes the sequence of flushes and PSR activations make a lot more sense to me, although it's rather hacky.  It doesn't fix the hang, though.  It might fix the latency issue I was seeing, though, but it's very hard to tell when the system hangs so quickly.


(Part of the hackiness is that I'm not sure that schedule_delayed_work() actually promises to wait as long as it's asked to.  I suspect that a better solution would be to use timers or even to use the vblank interrupt to trigger PSR activation.  mod_timer() is actually intended for this type of usage.)
Comment 3 Andy Lutomirski 2018-02-03 17:08:58 UTC
Fixed by:

https://patchwork.freedesktop.org/series/37598/
Comment 4 Jani Saarinen 2018-03-29 07:11:45 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 5 Jani Saarinen 2018-04-25 11:14:14 UTC
Closing, please re-open is issue still exists.


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.