From mboxrd@z Thu Jan 1 00:00:00 1970 From: Vlastimil Babka Subject: Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon Date: Wed, 20 Jan 2016 21:25:17 +0100 Message-ID: <569FED2D.8000603@suse.cz> References: <5698CB20.9050602@suse.cz> <20160115122629.GC23290@intel.com> <5699C5E5.90702@gmail.com> <569CC357.8030302@suse.cz> Mime-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: base64 Return-path: Received: from mx2.suse.de (mx2.suse.de [195.135.220.15]) by gabe.freedesktop.org (Postfix) with ESMTPS id 5545E6E1A0 for ; Wed, 20 Jan 2016 12:25:23 -0800 (PST) In-Reply-To: <569CC357.8030302@suse.cz> List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dri-devel-bounces@lists.freedesktop.org Sender: "dri-devel" To: Mario Kleiner , =?UTF-8?B?VmlsbGUgU3lyasOkbMOk?= Cc: Daniel Vetter , LKML , dri-devel@lists.freedesktop.org, mgraesslin@kde.org, kwin@kde.org, Alex Deucher , =?UTF-8?Q?Christian_K=c3=b6nig?= List-Id: dri-devel@lists.freedesktop.org T24gMDEvMTgvMjAxNiAxMTo0OSBBTSwgVmxhc3RpbWlsIEJhYmthIHdyb3RlOgo+IE9uIDAxLzE2 LzIwMTYgMDU6MjQgQU0sIE1hcmlvIEtsZWluZXIgd3JvdGU6Cj4+Cj4+Cj4+IE9uIDAxLzE1LzIw MTYgMDE6MjYgUE0sIFZpbGxlIFN5cmrDpGzDpCB3cm90ZToKPj4+IE9uIEZyaSwgSmFuIDE1LCAy MDE2IGF0IDExOjM0OjA4QU0gKzAxMDAsIFZsYXN0aW1pbCBCYWJrYSB3cm90ZToKPj4KPj4gSSdt IGN1cnJlbnRseSBydW5uaW5nLi4uCj4+Cj4+IHdoaWxlIHhpbml0IC91c3IvYmluL2tzcGxhc2hx bWwgLS10ZXN0IC0tIDoxIDsgZG8gZWNobyB5YXk7IGRvbmUKPj4KPj4gLi4uIGluIGFuIGVuZGxl c3MgbG9vcCBvbiBMaW51eCA0LjQgU01QIFBSRUVNUFQgb24gSEQtNTc3MCAgYW5kIHNvIGZhciBp Cj4+IGNhbid0IHRyaWdnZXIgYSBoYW5nIGFmdGVyIGh1bmRyZWRzIG9mIHJ1bnMuCj4+Cj4+IERv ZXMgdGhpcyBhbHNvIGhhbmcgZm9yIHlvdT8KPiAKPiBObywgdGVzdCBtb2RlIHNlZW1zIHRvIGJl IGZpbmUuCj4gCj4+IEkgdGhpbmsgYSBkcm0uZGVidWc9MHgyMSBzZXR0aW5nIGFuZCBncmVwJ3Bp bmcgdGhlIHN5c2xvZyBmb3IgInZibGFuayIKPj4gc2hvdWxkIHByb2JhYmx5IGdpdmUgdXNlZnVs IGluZm8gYXJvdW5kIHRoZSB0aW1lIG9mIHRoZSBoYW5nLgo+IAo+IEF0dGFjaGVkLiBDYXB0dXJl ZCBieSBoYXZpbmcga2RtIHJ1bm5pbmcsIHN3aXRjaGluZyB0byBjb25zb2xlLCBydW5uaW5nIAo+ ICJkbWVzZyAtQyA7IGRtZXNnIC13ID4gL3RtcC9kbWVzZyIsIHN3aXRjaCB0byBrZG0sIGVudGVy IHBhc3N3b3JkLCBzZWUgCj4gZnJvemVuIHNwbGFzaHNjcmVlbiwgc3dpdGNoIGJhY2ssIHRlcm1p bmF0ZSBkbWVzZy4gU28gc29tZXdoZXJlIGFyb3VuZCAKPiB0aGUgbWlkZGxlIHRoZXJlIHNob3Vs ZCBiZSB3aGVyZSBrc3BsYXNoc2NyZWVuIHN0YXJ0cy4uLgoKSG1tIHRoaXMgbG9va3Mgc3VzcGlj aW91cz8gKCEhISBtaW5lKQoKWyAgNTM4LjkxODk5MF0gW2RybTpkcm1fdXBkYXRlX3ZibGFua19j b3VudF0gdXBkYXRpbmcgdmJsYW5rIGNvdW50IG9uIGNydGMgMTogY3VycmVudD0zODU4NzY1ODks IGRpZmY9MSwgaHc9NjIyIGh3X2xhc3Q9NjIxClsgIDUzOC45MTg5OTFdIFtkcm06ZXZlcmdyZWVu X2lycV9wcm9jZXNzXSBJSDogRDIgdmJsYW5rClsgIDUzOC45MzUwMzVdIFtkcm06cmFkZW9uX2dl dF92YmxhbmtfY291bnRlcl9rbXNdIGNydGMgMDogZGlzdCBmcm9tIHZibGFuayBzdGFydCAzClsg IDUzOC45MzUwNDBdIFtkcm06cmFkZW9uX2dldF92YmxhbmtfY291bnRlcl9rbXNdIGNydGMgMDog ZGlzdCBmcm9tIHZibGFuayBzdGFydCAzClsgIDUzOC45MzUwNDFdIFtkcm06ZHJtX3VwZGF0ZV92 YmxhbmtfY291bnRdIHVwZGF0aW5nIHZibGFuayBjb3VudCBvbiBjcnRjIDA6IGN1cnJlbnQ9MTY4 MDgxMDAsIGRpZmY9MSwgaHc9MzA4ODUgaHdfbGFzdD0zMDg4NApbICA1MzguOTM1MDQyXSBbZHJt OmV2ZXJncmVlbl9pcnFfcHJvY2Vzc10gSUg6IEQxIHZibGFuawpbICA1MzguOTM5NzAyXSBbZHJt OmRybV93YWl0X3ZibGFua10gd2FpdGluZyBvbiB2YmxhbmsgY291bnQgMzg1ODc2NTkwLCBjcnRj IDEKWyAgNTM4LjkzOTcwNF0gW2RybTpkcm1fd2FpdF92YmxhbmtdIHJldHVybmluZyAzODU4NzY1 OTAgdG8gY2xpZW50ClsgIDUzOC45Mzk3MDldIFtkcm06ZHJtX3dhaXRfdmJsYW5rXSB3YWl0aW5n IG9uIHZibGFuayBjb3VudCAzODU4NzY1OTAsIGNydGMgMQpbICA1MzguOTM5NzEwXSBbZHJtOmRy bV93YWl0X3ZibGFua10gcmV0dXJuaW5nIDM4NTg3NjU5MCB0byBjbGllbnQKISEhNTM4LjkzOTcx NV0gW2RybTpkcm1fcXVldWVfdmJsYW5rX2V2ZW50XSBldmVudCBvbiB2YmxhbmsgY291bnQgMzg1 ODc2NTkxLCBjdXJyZW50IDM4NTg3NjU5MCwgY3J0YyAxClsgIDUzOC45NDQ0NTJdIFtkcm06ZHJt X3dhaXRfdmJsYW5rXSB3YWl0aW5nIG9uIHZibGFuayBjb3VudCAxNjgwODEwMSwgY3J0YyAwClsg IDUzOC45NDQ0NTNdIFtkcm06ZHJtX3dhaXRfdmJsYW5rXSByZXR1cm5pbmcgMTY4MDgxMDEgdG8g Y2xpZW50ClsgIDUzOC45NDQ0NThdIFtkcm06ZHJtX3dhaXRfdmJsYW5rXSB3YWl0aW5nIG9uIHZi bGFuayBjb3VudCAxNjgwODEwMSwgY3J0YyAwClsgIDUzOC45NDQ0NjBdIFtkcm06ZHJtX3dhaXRf dmJsYW5rXSByZXR1cm5pbmcgMTY4MDgxMDEgdG8gY2xpZW50ClsgIDUzOC45NDQ0NjVdIFtkcm06 ZHJtX3F1ZXVlX3ZibGFua19ldmVudF0gZXZlbnQgb24gdmJsYW5rIGNvdW50IDE2ODA4MTAyLCBj dXJyZW50IDE2ODA4MTAxLCBjcnRjIDAKWyAgNTM4Ljk0ODIxMF0gW2RybTpkcm1fd2FpdF92Ymxh bmtdIHdhaXRpbmcgb24gdmJsYW5rIGNvdW50IDE2ODA4MTAxLCBjcnRjIDAKWyAgNTM4Ljk0ODIx Ml0gW2RybTpkcm1fd2FpdF92YmxhbmtdIHJldHVybmluZyAxNjgwODEwMSB0byBjbGllbnQKWyAg NTM4Ljk0ODIyMl0gW2RybTpkcm1fd2FpdF92YmxhbmtdIHdhaXRpbmcgb24gdmJsYW5rIGNvdW50 IDE2ODA4MTAxLCBjcnRjIDAKWyAgNTM4Ljk0ODIyNF0gW2RybTpkcm1fd2FpdF92YmxhbmtdIHJl dHVybmluZyAxNjgwODEwMSB0byBjbGllbnQKWyAgNTM4Ljk0OTU4OV0gW2RybTpkcm1fd2FpdF92 YmxhbmtdIHdhaXRpbmcgb24gdmJsYW5rIGNvdW50IDE2ODA4MTAxLCBjcnRjIDAKWyAgNTM4Ljk0 OTU5MV0gW2RybTpkcm1fd2FpdF92YmxhbmtdIHJldHVybmluZyAxNjgwODEwMSB0byBjbGllbnQK WyAgNTM4Ljk1MTIzOF0gW2RybTpyYWRlb25fZ2V0X3ZibGFua19jb3VudGVyX2ttc10gY3J0YyAx OiBkaXN0IGZyb20gdmJsYW5rIHN0YXJ0IDYKWyAgNTM4Ljk1MTI0NV0gW2RybTpyYWRlb25fZ2V0 X3ZibGFua19jb3VudGVyX2ttc10gY3J0YyAxOiBkaXN0IGZyb20gdmJsYW5rIHN0YXJ0IDcKISEh NTM4Ljk1MTI0Nl0gW2RybTpkcm1fdXBkYXRlX3ZibGFua19jb3VudF0gdXBkYXRpbmcgdmJsYW5r IGNvdW50IG9uIGNydGMgMTogY3VycmVudD0zODU4NzY1OTAsIGRpZmY9MTY3NzY1OTcsIGh3PTMg aHdfbGFzdD02MjIKWyAgNTM4Ljk1MTI0N10gW2RybTpldmVyZ3JlZW5faXJxX3Byb2Nlc3NdIElI OiBEMiB2YmxhbmsKWyAgNTM4Ljk1MTc0Nl0gW2RybTpyYWRlb25fZ2V0X3ZibGFua19jb3VudGVy X2ttc10gY3J0YyAwOiBkaXN0IGZyb20gdmJsYW5rIHN0YXJ0IDQKWyAgNTM4Ljk1MTc1Ml0gW2Ry bTpyYWRlb25fZ2V0X3ZibGFua19jb3VudGVyX2ttc10gY3J0YyAwOiBkaXN0IGZyb20gdmJsYW5r IHN0YXJ0IDQKWyAgNTM4Ljk1MTc1M10gW2RybTpkcm1fdXBkYXRlX3ZibGFua19jb3VudF0gdXBk YXRpbmcgdmJsYW5rIGNvdW50IG9uIGNydGMgMDogY3VycmVudD0xNjgwODEwMSwgZGlmZj0xLCBo dz0zMDg4NiBod19sYXN0PTMwODg1ClsgIDUzOC45NTE3NTRdIFtkcm06ZHJtX2hhbmRsZV92Ymxh bmtfZXZlbnRzXSB2YmxhbmsgZXZlbnQgb24gMTY4MDgxMDIsIGN1cnJlbnQgMTY4MDgxMDIKWyAg NTM4Ljk1MTc1Nl0gW2RybTpldmVyZ3JlZW5faXJxX3Byb2Nlc3NdIElIOiBEMSB2YmxhbmsKWyAg NTM4Ljk2NDU3MF0gW2RybTpyYWRlb25fZ2V0X3ZibGFua19jb3VudGVyX2ttc10gY3J0YyAxOiBk aXN0IGZyb20gdmJsYW5rIHN0YXJ0IDcKWyAgNTM4Ljk2NDU4MV0gW2RybTpyYWRlb25fZ2V0X3Zi bGFua19jb3VudGVyX2ttc10gY3J0YyAxOiBkaXN0IGZyb20gdmJsYW5rIHN0YXJ0IC0xMDU4Clsg IDUzOC45NjQ1ODNdIFtkcm06ZHJtX3VwZGF0ZV92YmxhbmtfY291bnRdIHVwZGF0aW5nIHZibGFu ayBjb3VudCBvbiBjcnRjIDE6IGN1cnJlbnQ9NDAyNjUzMTg3LCBkaWZmPTEsIGh3PTQgaHdfbGFz dD0zCgpDb3VsZCBpdCBiZSB0aGF0IHRoZSB1bmRlcmZsb3cgY2F1c2VkIHNvbWUgc2lnbmVkIGxv Z2ljIHRvIG1pc2JlaGF2ZSBhbmQgZmFpbCB0byBkZXRlY3QgdGhhdCB3ZSBwYXNzZWQgMzg1ODc2 NTkxPwoKTGF0ZXIgd2UgaGF2ZSBhbm90aGVyIHN1Y2ggYmlnIHNraXAgKGJ1dCB0aGlzIHRpbWUg bm90aGluZyB3YWl0cyBmb3IgaXQgSSBndWVzcyk6CgpbICA1NDEuMzM3ODEzXSBbZHJtOmRybV91 cGRhdGVfdmJsYW5rX2NvdW50XSB1cGRhdGluZyB2YmxhbmsgY291bnQgb24gY3J0YyAxOiBjdXJy ZW50PTQwMjY1MzM2MywgZGlmZj0xNjc3NzA0MCwgaHc9MyBod19sYXN0PTE3OQoKCgo+PiBNYXli ZSBhbHNvIGNoZWNrIFhPcmcuMC5sb2cgZm9yIChXVykgd2FybmluZ3MgcmVsYXRlZCB0byBmbGlw Lgo+IAo+IE5vIHN1Y2ggd2FybmluZ3MgdGhlcmUuCj4gCj4+IHRoYW5rcywKPj4gLW1hcmlvCj4+ Cj4+Cj4+Pj4gVGhhbmtzLAo+Pj4+IFZsYXN0aW1pbAo+Pj4KPiAKCl9fX19fX19fX19fX19fX19f X19fX19fX19fX19fX19fX19fX19fX19fX19fX19fCmRyaS1kZXZlbCBtYWlsaW5nIGxpc3QKZHJp LWRldmVsQGxpc3RzLmZyZWVkZXNrdG9wLm9yZwpodHRwOi8vbGlzdHMuZnJlZWRlc2t0b3Aub3Jn L21haWxtYW4vbGlzdGluZm8vZHJpLWRldmVsCg== From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S935080AbcATUZ2 (ORCPT ); Wed, 20 Jan 2016 15:25:28 -0500 Received: from mx2.suse.de ([195.135.220.15]:51061 "EHLO mx2.suse.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754719AbcATUZX (ORCPT ); Wed, 20 Jan 2016 15:25:23 -0500 Subject: Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon To: Mario Kleiner , =?UTF-8?B?VmlsbGUgU3lyasOkbMOk?= References: <5698CB20.9050602@suse.cz> <20160115122629.GC23290@intel.com> <5699C5E5.90702@gmail.com> <569CC357.8030302@suse.cz> Cc: Alex Deucher , =?UTF-8?Q?Christian_K=c3=b6nig?= , Daniel Vetter , mgraesslin@kde.org, David Airlie , dri-devel@lists.freedesktop.org, LKML , kwin@kde.org From: Vlastimil Babka X-Enigmail-Draft-Status: N1110 Message-ID: <569FED2D.8000603@suse.cz> Date: Wed, 20 Jan 2016 21:25:17 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.3.0 MIME-Version: 1.0 In-Reply-To: <569CC357.8030302@suse.cz> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 8bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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 >>> >