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
