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

Mon Jan 18 06:14:38 PST 2016

> 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 at entry=0x17e25c0, cond=cond at entry=0x7ffce30ffc70, vector=vector at entry=0x0, count=count at entry=0x0) at xcb_conn.c:459
> #3  0x00007feb3250ad57 in wait_for_reply (c=c at entry=0x17e25c0, request=request at entry=883, e=e at entry=0x7ffce30ffd48) at xcb_in.c:516
> #4  0x00007feb3250aec1 in xcb_wait_for_reply64 (c=c at entry=0x17e25c0, request=883, e=e at entry=0x7ffce30ffd48) at xcb_in.c:560
> #5  0x00007feb32b80300 in _XReply (dpy=dpy at entry=0x17e12c0, rep=rep at entry=0x7ffce30ffdc0, extra=extra at entry=0, discard=discard at entry=0) at xcb_io.c:596
> #6  0x00007feb36eda712 in DRI2GetBuffersWithFormat (dpy=0x17e12c0, drawable=12582924, width=width at entry=0x181e528, height=height at 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 at 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 at entry=12582924, read=read at entry=12582924, gc_user=0x1a70960) at glxcurrent.c:228
> #17 0x00007feb36eb9b3b in glXMakeCurrent (dpy=<optimized out>, draw=draw at 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 at 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 at 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 at entry=0x7feb240016f0) at gmain.c:3769
> #30 0x00007feb35f4c2c8 in g_main_context_iterate (context=context at entry=0x7feb240016f0, block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>)
>      at gmain.c:3840
> #31 0x00007feb35f4c36c in g_main_context_iteration (context=0x7feb240016f0, may_block=may_block at 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 at entry=0x7ffce31006e0, flags=..., flags at 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 at entry=0x7feb14000990, block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>) at gmain.c:3835
> #3  0x00007feb35f4c36c in g_main_context_iteration (context=0x7feb14000990, may_block=may_block at 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 at entry=0x7feb18ff1cf0, flags=..., flags at entry=...) at kernel/qeventloop.cpp:204
> #6  0x00007feb399a9b1c in QThread::exec (this=this at 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 at 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 at entry=0x17e25c0, cond=cond at entry=0x17e2600, vector=vector at entry=0x0, count=count at 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
>
>