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

From: Christian KÃnig
Date: Mon Jan 18 2016 - 09:15:04 EST

Next message: Alexander Kuleshov: "[PATCH] x86/calling.h: remove unused SAVE_ALL/RESTORE_ALL macros for !CONFIG_x86_64"
Previous message: Mark Rutland: "Re: [PATCH v2] kernel: add kcov code coverage"
In reply to: Vlastimil Babka: "Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon"
Next in thread: Vlastimil Babka: "Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Thread 3 seems to be waiting on some response to radeon's ioctl?

That's just the worker thread waiting for something to do. At least for this case you can ignore it.

The interesting one is calling DRI2GetBuffersWithFormat and waiting for a reply. For some reason the X server seems to be stuck waiting (most likely) for a page flip.

Regards,
Christian.

Am 18.01.2016 um 15:06 schrieb Vlastimil Babka:

On 01/18/2016 11:49 AM, Vlastimil Babka wrote:

On 01/16/2016 05:24 AM, Mario Kleiner wrote:

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...

Maybe also check XOrg.0.log for (WW) warnings related to flip.

No such warnings there.

This is how gdb backtraces look like from the 4 threads of ksplashqml that's stuck.
Thread 3 seems to be waiting on some response to radeon's ioctl?

(gdb) info threads
Id Target Id Frame
4 Thread 0x7feb296f5700 (LWP 3643) "QXcbEventReader" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
3 Thread 0x7feb199f8700 (LWP 3644) "ksplashqml" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
2 Thread 0x7feb18ff2700 (LWP 3645) "QQmlThread" 0x00007feb392bd24d in poll () at ../sysdeps/unix/syscall-template.S:84
* 1 Thread 0x7feb3b79f8c0 (LWP 3642) "ksplashqml" 0x00007feb392bd24d in poll () at ../sysdeps/unix/syscall-template.S:84
(gdb) bt
#0 0x00007feb392bd24d in poll () at ../sysdeps/unix/syscall-template.S:84
#1 0x00007feb32509432 in poll (__timeout=-1, __nfds=1, __fds=0x7ffce30ffb50) at /usr/include/bits/poll2.h:46
#2 _xcb_conn_wait (c=c@entry=0x17e25c0, cond=cond@entry=0x7ffce30ffc70, vector=vector@entry=0x0, count=count@entry=0x0) at xcb_conn.c:459
#3 0x00007feb3250ad57 in wait_for_reply (c=c@entry=0x17e25c0, request=request@entry=883, e=e@entry=0x7ffce30ffd48) at xcb_in.c:516
#4 0x00007feb3250aec1 in xcb_wait_for_reply64 (c=c@entry=0x17e25c0, request=883, e=e@entry=0x7ffce30ffd48) at xcb_in.c:560
#5 0x00007feb32b80300 in _XReply (dpy=dpy@entry=0x17e12c0, rep=rep@entry=0x7ffce30ffdc0, extra=extra@entry=0, discard=discard@entry=0) at xcb_io.c:596
#6 0x00007feb36eda712 in DRI2GetBuffersWithFormat (dpy=0x17e12c0, drawable=12582924, width=width@entry=0x181e528, height=height@entry=0x181e52c,
attachments=0x7ffce30fff10, count=1, outCount=0x7ffce30ffef0) at dri2.c:491
#7 0x00007feb36edaa17 in dri2GetBuffersWithFormat (driDrawable=<optimized out>, width=0x181e528, height=0x181e52c, attachments=<optimized out>,
count=<optimized out>, out_count=0x7ffce30ffef0, loaderPrivate=0x1fb1290) at dri2_glx.c:900
#8 0x00007feb20132618 in dri2_drawable_get_buffers (count=<synthetic pointer>, atts=0x1817da0, drawable=0x1816d20) at dri2.c:213
#9 dri2_allocate_textures (ctx=0x1a453d0, drawable=0x1816d20, statts=0x1817da0, statts_count=2) at dri2.c:407
#10 0x00007feb2012f17c in dri_st_framebuffer_validate (stctx=<optimized out>, stfbi=<optimized out>, statts=0x1817da0, count=2, out=0x7ffce3100050)
at dri_drawable.c:83
#11 0x00007feb2005b5fe in st_framebuffer_validate (stfb=0x1817940, st=st@entry=0x1b11f20) at state_tracker/st_manager.c:200
#12 0x00007feb2005c88e in st_api_make_current (stapi=<optimized out>, stctxi=0x1b11f20, stdrawi=0x1816d20, streadi=0x1816d20) at state_tracker/st_manager.c:831
#13 0x00007feb2012ecd1 in dri_make_current (cPriv=<optimized out>, driDrawPriv=0x181e500, driReadPriv=0x181e500) at dri_context.c:245
#14 0x00007feb2012dcb6 in driBindContext (pcp=<optimized out>, pdp=<optimized out>, prp=<optimized out>) at dri_util.c:531
#15 0x00007feb36edc38b in dri2_bind_context (context=0x1a70960, old=<optimized out>, draw=12582924, read=12582924) at dri2_glx.c:160
#16 0x00007feb36eb99b7 in MakeContextCurrent (dpy=0x17e12c0, draw=draw@entry=12582924, read=read@entry=12582924, gc_user=0x1a70960) at glxcurrent.c:228
#17 0x00007feb36eb9b3b in glXMakeCurrent (dpy=<optimized out>, draw=draw@entry=12582924, gc=<optimized out>) at glxcurrent.c:262
#18 0x00007feb288d9a2d in QGLXContext::makeCurrent (this=0x1a48760, surface=0x1a0ac40) at qglxintegration.cpp:476
#19 0x00007feb3a0f8750 in QOpenGLContext::makeCurrent (this=0x18401e0, surface=0x1842d90) at kernel/qopenglcontext.cpp:936
#20 0x00007feb3af63aef in QSGGuiThreadRenderLoop::renderWindow (this=this@entry=0x1913f50, window=0x1842d80)
at /usr/src/debug/qtdeclarative-opensource-src-5.5.1/src/quick/scenegraph/qsgrenderloop.cpp:341
#21 0x00007feb3af64d11 in QSGGuiThreadRenderLoop::event (this=0x1913f50, e=<optimized out>)
at /usr/src/debug/qtdeclarative-opensource-src-5.5.1/src/quick/scenegraph/qsgrenderloop.cpp:474
#22 0x00007feb39b7fbd9 in QCoreApplication::notify (this=<optimized out>, receiver=<optimized out>, event=<optimized out>) at kernel/qcoreapplication.cpp:1038
#23 0x00007feb39b7fcf3 in QCoreApplication::notifyInternal (this=0x7ffce3100740, receiver=0x1913f50, event=event@entry=0x7ffce31004c0)
at kernel/qcoreapplication.cpp:965
#24 0x00007feb39bd23bd in sendEvent (event=0x7ffce31004c0, receiver=<optimized out>) at ../../src/corelib/kernel/qcoreapplication.h:224
#25 QTimerInfoList::activateTimers (this=0x183e220) at kernel/qtimerinfo_unix.cpp:637
#26 0x00007feb39bd2909 in timerSourceDispatch (source=<optimized out>) at kernel/qeventdispatcher_glib.cpp:177
#27 idleTimerSourceDispatch (source=<optimized out>) at kernel/qeventdispatcher_glib.cpp:224
#28 0x00007feb35f4c097 in g_main_dispatch (context=0x7feb240016f0) at gmain.c:3154
#29 g_main_context_dispatch (context=context@entry=0x7feb240016f0) at gmain.c:3769
#30 0x00007feb35f4c2c8 in g_main_context_iterate (context=context@entry=0x7feb240016f0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>)
at gmain.c:3840
#31 0x00007feb35f4c36c in g_main_context_iteration (context=0x7feb240016f0, may_block=may_block@entry=1) at gmain.c:3901
#32 0x00007feb39bd350f in QEventDispatcherGlib::processEvents (this=0x183f080, flags=...) at kernel/qeventdispatcher_glib.cpp:418
#33 0x00007feb39b7d63a in QEventLoop::exec (this=this@entry=0x7ffce31006e0, flags=..., flags@entry=...) at kernel/qeventloop.cpp:204
#34 0x00007feb39b852fd in QCoreApplication::exec () at kernel/qcoreapplication.cpp:1229
#35 0x00007feb3a0bb53c in QGuiApplication::exec () at kernel/qguiapplication.cpp:1527
#36 0x0000000000405ce1 in main (argc=3, argv=0x7ffce3100878) at /usr/src/debug/plasma-workspace-5.5.2/ksplash/ksplashqml/main.cpp:98

(gdb) thread 2
[Switching to thread 2 (Thread 0x7feb18ff2700 (LWP 3645))]
#0 0x00007feb392bd24d in poll () at ../sysdeps/unix/syscall-template.S:84
84 in ../sysdeps/unix/syscall-template.S
(gdb) bt
#0 0x00007feb392bd24d in poll () at ../sysdeps/unix/syscall-template.S:84
#1 0x00007feb35f4c264 in g_main_context_poll (priority=2147483647, n_fds=1, fds=0x7feb14003070, timeout=<optimized out>, context=0x7feb14000990)
at gmain.c:4135
#2 g_main_context_iterate (context=context@entry=0x7feb14000990, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3835
#3 0x00007feb35f4c36c in g_main_context_iteration (context=0x7feb14000990, may_block=may_block@entry=1) at gmain.c:3901
#4 0x00007feb39bd350f in QEventDispatcherGlib::processEvents (this=0x7feb140008c0, flags=...) at kernel/qeventdispatcher_glib.cpp:418
#5 0x00007feb39b7d63a in QEventLoop::exec (this=this@entry=0x7feb18ff1cf0, flags=..., flags@entry=...) at kernel/qeventloop.cpp:204
#6 0x00007feb399a9b1c in QThread::exec (this=this@entry=0x184dc00) at thread/qthread.cpp:503
#7 0x00007feb38c799a5 in QQmlThreadPrivate::run (this=0x184dc00) at /usr/src/debug/qtdeclarative-opensource-src-5.5.1/src/qml/qml/ftw/qqmlthread.cpp:141
#8 0x00007feb399ae94f in QThreadPrivate::start (arg=0x184dc00) at thread/qthread_unix.cpp:331
#9 0x00007feb37a3d4a4 in start_thread (arg=0x7feb18ff2700) at pthread_create.c:334
#10 0x00007feb392c5bdd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

(gdb) thread 3
[Switching to thread 3 (Thread 0x7feb199f8700 (LWP 3644))]
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
185 ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S: No such file or directory.
(gdb) bt
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007feb20496e63 in cnd_wait (mtx=0x18abc90, cond=0x18abcb8) at ../../../../../include/c11/threads_posix.h:159
#2 pipe_semaphore_wait (sema=0x18abc90) at ../../../../../src/gallium/auxiliary/os/os_thread.h:259
#3 radeon_drm_cs_emit_ioctl (param=param@entry=0x18ab940) at radeon_drm_winsys.c:653
#4 0x00007feb204966a7 in impl_thrd_routine (p=<optimized out>) at ../../../../../include/c11/threads_posix.h:87
#5 0x00007feb37a3d4a4 in start_thread (arg=0x7feb199f8700) at pthread_create.c:334
#6 0x00007feb392c5bdd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

(gdb) thread 4
[Switching to thread 4 (Thread 0x7feb296f5700 (LWP 3643))]
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
185 in ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S
(gdb) bt
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007feb32509689 in _xcb_conn_wait (c=c@entry=0x17e25c0, cond=cond@entry=0x17e2600, vector=vector@entry=0x0, count=count@entry=0x0) at xcb_conn.c:427
#2 0x00007feb3250b007 in xcb_wait_for_event (c=0x17e25c0) at xcb_in.c:693
#3 0x00007feb2ba48e29 in QXcbEventReader::run (this=0x17f55d0) at qxcbconnection.cpp:1229
#4 0x00007feb399ae94f in QThreadPrivate::start (arg=0x17f55d0) at thread/qthread_unix.cpp:331
#5 0x00007feb37a3d4a4 in start_thread (arg=0x7feb296f5700) at pthread_create.c:334
#6 0x00007feb392c5bdd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Next message: Alexander Kuleshov: "[PATCH] x86/calling.h: remove unused SAVE_ALL/RESTORE_ALL macros for !CONFIG_x86_64"
Previous message: Mark Rutland: "Re: [PATCH v2] kernel: add kcov code coverage"
In reply to: Vlastimil Babka: "Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon"
Next in thread: Vlastimil Babka: "Re: linux-4.4 bisected: kwin5 stuck on kde5 loading screen with radeon"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]