Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon

From	Vlastimil Babka <vbabka@suse.cz>
Newsgroups	linux.kernel
Subject	Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon
Date	2016-01-20 21:30 +0100
Message-ID	<qT7ya-3ae-9@gated-at.bofh.it> (permalink)
References	<qR9Xr-4OZ-13@gated-at.bofh.it> <qRbFV-60h-23@gated-at.bofh.it> <qRqEV-7L3-1@gated-at.bofh.it> <qSfHs-7W3-11@gated-at.bofh.it>
Organization	linux.* mail to news gateway

Show all headers | View raw

On 01/18/2016 11:49 AM, Vlastimil Babka wrote:
> On 01/16/2016 05:24 AM, Mario Kleiner wrote:
>>
>>
>> On 01/15/2016 01:26 PM, Ville Syrjälä wrote:
>>> On Fri, Jan 15, 2016 at 11:34:08AM +0100, Vlastimil Babka wrote:
>>
>> I'm currently running...
>>
>> while xinit /usr/bin/ksplashqml --test -- :1 ; do echo yay; done
>>
>> ... in an endless loop on Linux 4.4 SMP PREEMPT on HD-5770  and so far i
>> can't trigger a hang after hundreds of runs.
>>
>> Does this also hang for you?
> 
> No, test mode seems to be fine.
> 
>> I think a drm.debug=0x21 setting and grep'ping the syslog for "vblank"
>> should probably give useful info around the time of the hang.
> 
> Attached. Captured by having kdm running, switching to console, running 
> "dmesg -C ; dmesg -w > /tmp/dmesg", switch to kdm, enter password, see 
> frozen splashscreen, switch back, terminate dmesg. So somewhere around 
> the middle there should be where ksplashscreen starts...

Hmm this looks suspicious? (!!! mine)

[  538.918990] [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=385876589, diff=1, hw=622 hw_last=621
[  538.918991] [drm:evergreen_irq_process] IH: D2 vblank
[  538.935035] [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
[  538.935040] [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 3
[  538.935041] [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=16808100, diff=1, hw=30885 hw_last=30884
[  538.935042] [drm:evergreen_irq_process] IH: D1 vblank
[  538.939702] [drm:drm_wait_vblank] waiting on vblank count 385876590, crtc 1
[  538.939704] [drm:drm_wait_vblank] returning 385876590 to client
[  538.939709] [drm:drm_wait_vblank] waiting on vblank count 385876590, crtc 1
[  538.939710] [drm:drm_wait_vblank] returning 385876590 to client
!!!538.939715] [drm:drm_queue_vblank_event] event on vblank count 385876591, current 385876590, crtc 1
[  538.944452] [drm:drm_wait_vblank] waiting on vblank count 16808101, crtc 0
[  538.944453] [drm:drm_wait_vblank] returning 16808101 to client
[  538.944458] [drm:drm_wait_vblank] waiting on vblank count 16808101, crtc 0
[  538.944460] [drm:drm_wait_vblank] returning 16808101 to client
[  538.944465] [drm:drm_queue_vblank_event] event on vblank count 16808102, current 16808101, crtc 0
[  538.948210] [drm:drm_wait_vblank] waiting on vblank count 16808101, crtc 0
[  538.948212] [drm:drm_wait_vblank] returning 16808101 to client
[  538.948222] [drm:drm_wait_vblank] waiting on vblank count 16808101, crtc 0
[  538.948224] [drm:drm_wait_vblank] returning 16808101 to client
[  538.949589] [drm:drm_wait_vblank] waiting on vblank count 16808101, crtc 0
[  538.949591] [drm:drm_wait_vblank] returning 16808101 to client
[  538.951238] [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 6
[  538.951245] [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 7
!!!538.951246] [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=385876590, diff=16776597, hw=3 hw_last=622
[  538.951247] [drm:evergreen_irq_process] IH: D2 vblank
[  538.951746] [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
[  538.951752] [drm:radeon_get_vblank_counter_kms] crtc 0: dist from vblank start 4
[  538.951753] [drm:drm_update_vblank_count] updating vblank count on crtc 0: current=16808101, diff=1, hw=30886 hw_last=30885
[  538.951754] [drm:drm_handle_vblank_events] vblank event on 16808102, current 16808102
[  538.951756] [drm:evergreen_irq_process] IH: D1 vblank
[  538.964570] [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start 7
[  538.964581] [drm:radeon_get_vblank_counter_kms] crtc 1: dist from vblank start -1058
[  538.964583] [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=402653187, diff=1, hw=4 hw_last=3

Could it be that the underflow caused some signed logic to misbehave and fail to detect that we passed 385876591?

Later we have another such big skip (but this time nothing waits for it I guess):

[  541.337813] [drm:drm_update_vblank_count] updating vblank count on crtc 1: current=402653363, diff=16777040, hw=3 hw_last=179



>> Maybe also check XOrg.0.log for (WW) warnings related to flip.
> 
> No such warnings there.
> 
>> thanks,
>> -mario
>>
>>
>>>> Thanks,
>>>> Vlastimil
>>>
>

Thread

linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon Vlastimil Babka <vbabka@suse.cz> - 2016-01-15 11:40 +0100
  Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Ville Syrjälä <ville.syrjala@linux.intel.com> - 2016-01-15 13:30 +0100
    Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Vlastimil Babka <vbabka@suse.cz> - 2016-01-15 13:50 +0100
    Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-16 05:30 +0100
      Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Vlastimil Babka <vbabka@suse.cz> - 2016-01-18 15:10 +0100
      Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Vlastimil Babka <vbabka@suse.cz> - 2016-01-20 21:30 +0100
      Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-20 21:40 +0100
        Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-21 04:50 +0100
          Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-21 06:40 +0100
            Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-21 07:40 +0100
              Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-21 07:50 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Daniel Vetter <daniel@ffwll.ch> - 2016-01-21 09:00 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-21 09:40 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Daniel Vetter <daniel@ffwll.ch> - 2016-01-21 11:10 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-22 04:10 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Ville Syrjälä <ville.syrjala@linux.intel.com> - 2016-01-22 16:20 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-22 19:30 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-23 19:30 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Michel Dänzer <michel@daenzer.net> - 2016-01-25 05:20 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-25 14:20 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Ville Syrjälä <ville.syrjala@linux.intel.com> - 2016-01-25 14:30 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-25 14:50 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Ville Syrjälä <ville.syrjala@linux.intel.com> - 2016-01-25 16:00 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-25 17:40 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Daniel Vetter <daniel@ffwll.ch> - 2016-01-25 20:00 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-25 20:40 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Daniel Vetter <daniel@ffwll.ch> - 2016-01-25 21:40 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-25 22:50 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon Daniel Vetter <daniel@ffwll.ch> - 2016-01-25 23:10 +0100
              Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Mario Kleiner <mario.kleiner.de@gmail.com> - 2016-01-21 09:30 +0100
                Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with  radeon Vlastimil Babka <vbabka@suse.cz> - 2016-01-21 10:20 +0100

csiph-web