Kdenlive   bug tracker Home page

View Issue Details Jump to Notes ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0001711KdenliveMLTpublic2010-07-26 12:082011-06-10 10:48
Assigned Toddennedy 
Platform64 bitOSGentoo LinuxOS Version2008.0
Product Version0.7.7.1 
Target VersionFixed in Version0.8 
Summary0001711: Crash when loading project
DescriptionKdenlive crashes when i load a specific project. The crash happens in libX11 in the function dequeue_pending_request, which is called by the chain consumer_play_video consumer_get_dimensions -> XGetWindowAttributes -> _XGetWindowAtributes -> _XReply. The assertion 'req == dpy->xcb->pending_requests' fails.

The _XReply function initializes req to the value dpy->xcb->pending_requests, which is the head of a list of requests. When _XReply has called dequeue_pending_request(dpy, req), whose task is to remove one of the requests from the list, the wanted request has already been removed: the first item in the dpy->xcb->pending_requests list has sequence number 12, req has sequence number 11.The consecutive items in the list have numbers 13, 14, 15...

To me, this looks like a race condition. Since the crash occurs deep in libX11, it may not be a kdenlive bug at all, but a bug in libX11 or SDL. However, kdenlive is the only program on my machine that misbehaves like this.

I can work around the problem by closing the Monitor windows before loading the project. After loading the project, I can enable the Monitor windows again without any trouble, and everything works as it should.
Additional Information#0 0x00007ffff3b091b5 in *__GI_raise (sig=<value optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1 0x00007ffff3b0a5e0 in *__GI_abort () at abort.c:92
0000002 0x00007ffff3b022d1 in *__GI___assert_fail (assertion=0x7ffff3228598 "req == dpy->xcb->pending_requests", file=<value optimized out>, line=140, function=0x7ffff32287e0 "dequeue_pending_request") at assert.c:81
0000003 0x00007ffff3198ab2 in dequeue_pending_request (dpy=0x1577520, req=0xf3e6d0) at xcb_io.c:140
0000004 0x00007ffff3199c94 in _XReply (dpy=0x1577520, rep=0x7fffd6918be0, extra=0, discard=1) at xcb_io.c:562
0000005 0x00007ffff316e483 in _XGetWindowAttributes (dpy=0x1577520, w=0, attr=0x7fffd6918c70) at GetWAttrs.c:115
0000006 0x00007ffff316e61f in XGetWindowAttributes (dpy=0x1577520, w=0, attr=0x7fffd6918c70) at GetWAttrs.c:150
0000007 0x00007fffe4cba5cb in consumer_get_dimensions (width=0x12dc8d8, height=0x12dc8dc) at consumer_sdl_still.c:620
0000008 0x00007fffe4cba830 in consumer_play_video (arg=<value optimized out>) at consumer_sdl_still.c:402
0000009 consumer_thread (arg=<value optimized out>) at consumer_sdl_still.c:565
0000010 0x00007ffff54d0914 in start_thread (arg=<value optimized out>) at pthread_create.c:297
0000011 0x00007ffff3ba827d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
TagsNo tags attached.
Build/Install MethodDistribution package
Attached Filestxt file icon mlt-diff.txt [^] (6,352 bytes) 2010-09-28 21:15 [Show Content]

- Relationships
has duplicate 0001248acknowledged kdenlive crashed when loading project 
has duplicate 0001685new Random Crashes During Video Editing or Playback 
related to 0001825closedj-b-m Segmentation recovering project 
related to 0001762closedddennedy Segfault in consumer_sdl_still.c when loading project 
related to 0001560feedbackddennedy Crashes creating a project 
related to 0001961new Reopening some projects causes a segfault 

-  Notes
jem (reporter)
2010-07-26 17:12

After looking a bit more into this problem, I don't see how protection against concurrent access to libX11 is done in this application.

As far as I can tell, the XInitThreads function is not called at all. This means the LockDisplay(display) function is a no-op, because the lock field in the Display struct is null. If more than one thread calls XGetWindowAttributes or a similar functions concurrently, I'm not at all surprised the internal structures get messed up and assertions fail.
ttill (developer)
2010-08-03 11:54

I remember having this issue too, in the past. But I currently have no project which crashes this way.
The following introduces new crash instead of solving one:
- Add XInitThreads() to consumer_sdl_still_init
- put XLockDisplay(display) before XGetWindowAttributes and XUnlockDisplay(display) behind

I'm not familiar with X at all, looks like you are more into it. So maybe you can help or are even interested in a bit of MLT hacking?
jem (reporter)
2010-08-10 17:13

I also tried adding a call to XInitThreads and also managed to introduce a new crash.

This new crash happens in SDL_SetVideoMode called by consumer_start (in file consumer_sdl_still.c). SDL_SetVideoMode references current_video->screen (via the macro SDL_VideoSurface)

    /* Default to the current video bpp */
    if ( bpp == 0 ) {
        flags |= SDL_ANYFORMAT;
        bpp = SDL_VideoSurface->format->BitsPerPixel;

The problem is that the value of screen is 0, which results in a null pointer reference. Once again we fall victim to Tony Hoare's "Billion Dollar Mistake".

(Btw. the calls to XLockDisplay and XUnlockDisplay are unnecessary. They are only for explicitly locking the display. The call to XGetWindowAttributes handles the locking internally once locking has been set up via XInitThreads.)
jem (reporter)
2010-08-12 12:22

I just found bug report 1248, which is in fact a duplicate of this bug report:
http://www.kdenlive.org/mantis/view.php?id=1248 [^]
In the crash reports there you can clearly see that XLib is not prepared for multithreading: both threads 1 and 3 are in the middle of calls to XLib. This requires either a call to XInitThreads to prepare XLib for multithreading, or that you use your own locking to prevent multiple access. The locks that XInitThreads enable are off by default to optimize performance when running single-threaded.

As reported in my note above, adding a call to XInitThreads led to a new problem, which I have not fully investigated yet, but it seems to be a separate problem that I suspect is also a race condition.
ddennedy (developer)
2010-09-22 05:20

MLT uses SDL_LockSurface(). Does that call LockDisplay()?
jem (reporter)
2010-09-23 12:56

If I read the code correctly, SDL_LockSurface does not call LockDisplay. It does call XSync, and that "flushes the output buffer and then waits until all requests have been received and processed by the X server." But this does not affect locking.
jem (reporter)
2010-09-23 13:28

Here are some more details on the null pointer problem in my note from August 10th. When the program crashes, three threads are running; the call sequences of two of them are shown below.

What is interesting is that thread 0000006 is trying to access SDL_VideoSurface (defined as current_video->screen), which is initialized in the main thread. Apparently, the problem is that the main thread has not got around to do this initialization yet, because it is still waiting for the reply to an X11 library call from the X server. The initialization is next in turn, as can be seen from this code snippet from SDL_video.c:

    if ( video->VideoInit(video, &vformat) < 0 ) { // <- the main thread is waiting to return from VideoInit.

    /* Create a zero sized video surface of the appropriate format */
    video_flags = SDL_SWSURFACE;
    SDL_VideoSurface = SDL_CreateRGBSurface(video_flags, 0, 0, // VideoSurface initialized here.
                vformat.Rmask, vformat.Gmask, vformat.Bmask, 0);

The consumer thread should not have been started at this point if it relies on SDL_VideoSurface being set.

Thread 0000006:

#0 SDL_SetVideoMode() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/video/SDL_video.c:608
#1 consumer_play_video() at /usr/src/debug/media-libs/mlt-0.5.4-r2/mlt-0.5.4/src/modules/sdl/consumer_sdl_still.c:438
0000002 consumer_thread() at /usr/src/debug/media-libs/mlt-0.5.4-r2/mlt-0.5.4/src/modules/sdl/consumer_sdl_still.c:564
0000003 start_thread() at /usr/src/debug/sys-libs/glibc-2.12.1-r1/glibc-2.12.1/nptl/pthread_create.c:300
0000004 clone() at /usr/src/debug/sys-libs/glibc-2.12.1-r1/glibc-2.12.1/sysdeps/unix/sysv/linux/x86_64/clone.S:114

The main thread:

#0 __poll() at /usr/src/debug/sys-libs/glibc-2.12.1-r1/glibc-2.12.1/sysdeps/unix/sysv/linux/poll.c:86
#1 _xcb_conn_wait() at /usr/src/debug/x11-libs/libxcb-1.7/libxcb-1.7/src/xcb_conn.c:312
0000002 xcb_wait_for_reply() at /usr/src/debug/x11-libs/libxcb-1.7/libxcb-1.7/src/xcb_in.c:377
0000003 _XReply() at /usr/src/debug/x11-libs/libX11-1.3.6/libX11-1.3.6/src/xcb_io.c:531
0000004 XQueryExtension() at /usr/src/debug/x11-libs/libX11-1.3.6/libX11-1.3.6/src/QuExt.c:48
0000005 XInitExtension() at /usr/src/debug/x11-libs/libX11-1.3.6/libX11-1.3.6/src/InitExt.c:46
0000006 XRenderExtAddDisplay() at /usr/src/debug/x11-libs/libXrender-0.9.6/libXrender-0.9.6/src/Xrender.c:201
0000007 XRenderFindDisplay() at /usr/src/debug/x11-libs/libXrender-0.9.6/libXrender-0.9.6/src/Xrender.c:287
0000008 XRenderQueryExtension() at /usr/src/debug/x11-libs/libXrender-0.9.6/libXrender-0.9.6/src/Xrender.c:309
0000009 _XcursorGetDisplayInfo() at /usr/lib/libXcursor.so.1:-1
0000010 XcursorSupportsARGB() at /usr/lib/libXcursor.so.1:-1
0000011 XcursorNoticeCreateBitmap() at /usr/lib/libXcursor.so.1:-1
0000012 XCreatePixmap() at /usr/src/debug/x11-libs/libX11-1.3.6/libX11-1.3.6/src/CrPixmap.c:60
0000013 X11_CreateWMCursor() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/video/x11/SDL_x11mouse.c:103
0000014 X11_VideoInit() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/video/x11/SDL_x11video.c:690
0000015 SDL_VideoInit() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/video/SDL_video.c:245
0000016 SDL_InitSubSystem() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/SDL.c:69
0000017 SDL_Init() at /usr/src/debug/media-libs/libsdl-1.2.14-r3/SDL-1.2.14/src/SDL.c:161
0000018 consumer_start() at /usr/src/debug/media-libs/mlt-0.5.4-r2/mlt-0.5.4/src/modules/sdl/consumer_sdl_preview.c:176
0000019 Render::connectPlaylist() at /usr/src/debug/media-video/kdenlive-
0000020 Render::setSceneList() at /usr/src/debug/media-video/kdenlive-
0000021 Render::resetProfile() at /usr/src/debug/media-video/kdenlive-
0000022 Monitor::resetProfile() at /usr/src/debug/media-video/kdenlive-
0000023 MonitorManager::slotResetProfiles() at /usr/src/debug/media-video/kdenlive-
0000024 MonitorManager::resetProfiles() at /usr/src/debug/media-video/kdenlive-
0000025 MainWindow::connectDocument() at /usr/src/debug/media-video/kdenlive-
0000026 MainWindow::activateDocument() at /usr/src/debug/media-video/kdenlive-
0000027 MainWindow::qt_metacall() at /usr/src/debug/media-video/kdenlive-
0000028 QMetaObject::activate() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qobject.cpp:3286
0000029 QTabWidget::currentChanged() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/.moc/release-shared/moc_qtabwidget.cpp:199
0000030 QTabWidgetPrivate::_q_showTab() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qtabwidget.cpp:732
0000031 QTabWidget::qt_metacall() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/.moc/release-shared/moc_qtabwidget.cpp:141
0000032 KTabWidget::qt_metacall() at /usr/src/debug/kde-base/kdelibs-4.5.1/kdelibs-4.5.1_build/kdeui/ktabwidget.moc:127
0000033 QMetaObject::activate() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qobject.cpp:3286
0000034 QTabBar::currentChanged() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/.moc/release-shared/moc_qtabbar.cpp:200
0000035 QTabBar::insertTab() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qtabbar.cpp:845
0000036 QTabWidget::insertTab() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qtabwidget.cpp:455
0000037 MainWindow::doOpenFile() at /usr/src/debug/media-video/kdenlive-
0000038 MainWindow::openFile() at /usr/src/debug/media-video/kdenlive-
0000039 MainWindow::openFile() at /usr/src/debug/media-video/kdenlive-
0000040 MainWindow::qt_metacall() at /usr/src/debug/media-video/kdenlive-
0000041 QMetaObject::activate() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qobject.cpp:3286
0000042 QAction::triggered() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/.moc/release-shared/moc_qaction.cpp:262
0000043 QAction::activate() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qaction.cpp:1254
0000044 QAbstractButtonPrivate::click() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qabstractbutton.cpp:527
0000045 QAbstractButton::mouseReleaseEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qabstractbutton.cpp:1120
0000046 QToolButton::mouseReleaseEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/widgets/qtoolbutton.cpp:720
0000047 QWidget::event() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qwidget.cpp:8043
0000048 QApplicationPrivate::notify_helper() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qapplication.cpp:4301
0000049 QApplication::notify() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qapplication.cpp:3866
0000050 KApplication::notify() at /usr/src/debug/kde-base/kdelibs-4.5.1/kdelibs-4.5.1/kdeui/kernel/kapplication.cpp:309
0000051 QCoreApplication::notifyInternal() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qcoreapplication.cpp:725
0000052 sendEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qcoreapplication.h:214
0000053 QApplicationPrivate::sendMouseEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qapplication.cpp:2966
0000054 QETWidget::translateMouseEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qapplication_x11.cpp:4379
0000055 QApplication::x11ProcessEvent() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qapplication_x11.cpp:3512
0000056 x11EventSourceDispatch() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qguieventdispatcher_glib.cpp:145
0000057 g_main_dispatch() at /usr/src/debug/dev-libs/glib-2.24.2/glib-2.24.2/glib/gmain.c:1959
#58 IA__g_main_context_dispatch() at /usr/src/debug/dev-libs/glib-2.24.2/glib-2.24.2/glib/gmain.c:2512
0000059 g_main_context_iterate() at /usr/src/debug/dev-libs/glib-2.24.2/glib-2.24.2/glib/gmain.c:2590
0000060 IA__g_main_context_iteration() at /usr/src/debug/dev-libs/glib-2.24.2/glib-2.24.2/glib/gmain.c:2653
0000061 QEventDispatcherGlib::processEvents() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qeventdispatcher_glib.cpp:411
0000062 QGuiEventDispatcherGlib::processEvents() at /usr/src/debug/x11-libs/qt-gui-4.6.3/qt-everywhere-opensource-src-4.6.3/src/gui/kernel/qguieventdispatcher_glib.cpp:203
0000063 QEventLoop::processEvents() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qeventloop.cpp:148
0000064 QEventLoop::exec() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qeventloop.cpp:200
0000065 QCoreApplication::exec() at /usr/src/debug/x11-libs/qt-core-4.6.3/qt-everywhere-opensource-src-4.6.3/src/corelib/kernel/qcoreapplication.cpp:1002
0000066 main() at /usr/src/debug/media-video/kdenlive-
ddennedy (developer)
2010-09-23 19:49

Your insightful analysis will definitely help me to fix this, but first I need to be able to reproduce it fairly reliably. I will see if I can make a fairly complex project that triggers it. Otherwise, I could really use your help at the code level in mlt/src/modules/sdl/consumer_sdl.c and consumer_sdl_still.c
jem (reporter)
2010-09-24 07:49

I forgot to mention that I suspect the type of CPU (uniprocessor vs. multi-core) you run the program on plays a role when trying to trigger the bug. My computer is a four core AMD Phenom. If time permits, I'll try to investigate some more.
jem (reporter)
2010-09-24 15:22

Some more findings: the kdenlive main thread starts "consumer threads" by calling the consumer_start function of the appropriate MLT driver. At the end of each of these functions pthread_create is called which starts the new thread. Some of these consumer_start functions (for example, in consumer_sdl_still.c, consumer_sdl_preview.c and consumer_sdl_audio.c) call SDL_Init.

SDL_Init in turn calls SDL_VideoInit which (re)initializes the global pointer variable current_video. First it wipes the value it points to and then does some pretty time consuming tricks to refill the fields of the SDL_VideoDevice struct, including calling X11 functions to which it has to wait for replies to. See the code in note 5906.

Now, the problem is that previously started threads access the values pointed to by this global variable. For example, the consumer_thread function in the MLT module consumer_sdl_still.c calls consumer_play_video, which in turn calls SDL_SetVideoMode, which tries to reference current_video->screen->format.

This seems to be an MLT problem. It puzzles me why the SDL has to be initialized repeatedly and why nobody has run into this problem before.

Before closing this bug, keep in mind that we actually have two problems here: what I have just described and the Xlib threading issue.
ddennedy (developer)
2010-09-24 19:29

As you are looking at the code of these mlt services, please bear in mind that Kdenlive and other apps use sdl_preview, which loads both sdl and sdl_still as slaves to switch between them. sdl_still is used when paused to get off of the Xv port and regular sdl is used when playing. This complicates the initialization picture.
jem (reporter)
2010-09-27 12:39

Complicated picture or not, the crash is a fact. And MLT or SDL is obviously flawed. SDL does not even pretend to be thread-safe and MLT is not realizing this.

In summary: A consumer_sdl_still service has been started and is running in th background. At the same time the main thread starts a consumer_sdl_preview service. This smashes the SDL global variable current_video, which is common to all threads and does not seem to be protected by any mutex. Fortunately, the consumer_sdl_still thread tries to access it at a bad time (via the SDL API function SDL_SetVideoMode), and the program crashes. I say fortunately, because now we can fix this subtle bug.

Whose fault is it? As far as I can tell, the only thing MLT has done wrong is to rely on being able to call SDL functions concurrently. Are the SDL functions supposed to be thread safe, in which case the bug is in SDL and shoud be fixed? Or should MLT be aware of that SDL is not thread-safe and MLT should therefore be fixed?

Maybe this issue should be move to some other bug tracker (MLT/SDL)?
ddennedy (developer)
2010-09-27 19:10

There is no need to move this to another bug tracker. There is no need to point fingers of blame. I accept that the bug is in MLT. But where is the patch that fixes it?
jem (reporter)
2010-09-28 21:18

"But where is the patch that fixes it?" Here :)
ddennedy (developer)
2010-09-29 01:45

On initial brief review the patch looks very clean and sensible. I thank you very much.
ddennedy (developer)
2010-09-29 04:29

mlt git commit 6a226799.

- Issue History
Date Modified Username Field Change
2010-07-26 12:08 jem New Issue
2010-07-26 17:12 jem Note Added: 0005407
2010-08-03 11:54 ttill Note Added: 0005462
2010-08-03 11:54 ttill Status new => acknowledged
2010-08-10 17:13 jem Note Added: 0005508
2010-08-11 16:45 ttill Category File Loading => MLT
2010-08-12 12:22 jem Note Added: 0005593
2010-08-12 23:54 ttill Relationship added has duplicate 0001248
2010-09-22 05:16 ddennedy Assigned To => ddennedy
2010-09-22 05:16 ddennedy Status acknowledged => assigned
2010-09-22 05:20 ddennedy Note Added: 0005878
2010-09-23 12:56 jem Note Added: 0005905
2010-09-23 13:28 jem Note Added: 0005906
2010-09-23 19:49 ddennedy Note Added: 0005909
2010-09-24 07:49 jem Note Added: 0005911
2010-09-24 15:22 jem Note Added: 0005913
2010-09-24 19:29 ddennedy Note Added: 0005914
2010-09-27 12:39 jem Note Added: 0005920
2010-09-27 19:10 ddennedy Note Added: 0005921
2010-09-28 21:15 jem File Added: mlt-diff.txt
2010-09-28 21:18 jem Note Added: 0005922
2010-09-29 01:45 ddennedy Note Added: 0005927
2010-09-29 04:29 ddennedy Note Added: 0005928
2010-09-29 04:29 ddennedy Status assigned => resolved
2010-09-29 04:29 ddennedy Fixed in Version => Recent git
2010-09-29 04:29 ddennedy Resolution open => fixed
2010-09-29 20:42 j-b-m Relationship added related to 0001825
2010-11-12 05:44 ddennedy Relationship added has duplicate 0001685
2010-11-20 08:05 ddennedy Relationship added related to 0001762
2010-11-20 08:37 ddennedy Relationship added related to 0001560
2011-01-04 23:00 j-b-m Relationship added related to 0001961
2011-04-26 21:58 j-b-m Fixed in Version Recent git => 0.8
2011-06-10 10:48 Granjow Status resolved => closed

Copyright © 2000 - 2014 MantisBT Team
Powered by Mantis Bugtracker