Application: kolf (1.9) KDE Platform Version: 4.4.90 (KDE 4.4.90 (KDE 4.5 RC1)) "release 2" Qt Version: 4.6.3 Operating System: Linux 2.6.31.12-0.2-desktop i686 Distribution: "openSUSE 11.2 (i586)" -- Information about the crash: - What I was doing when the application crashed: I'm porting Kolf to KGameRenderer which uses KImageCache and therefore KSharedDataCache for pixmap caching. In the editor, resizing an object causes pixmaps in many different sizes to be resized in a short time. After some seconds of resizing an item with the mouse, Kolf crashes with this backtrace. When I try to start it up again, it immediately crashes when the cache is opened and the first key is trying to be read, i.e. the crash is also happening in the same KSharedDataCache::find method. The application works again when I remove the cache file, so it seems that the cache file is corrupted. If that helps you, I can send you a broken cache file. - Unusual behavior I noticed: The following debug output appears on the command line just before the crash. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "82-124-puddle" kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "78-126-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "64-138-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "58-140-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "54-150-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "52-156-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "52-158-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "52-160-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "52-162-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "52-164-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "54-166-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "56-166-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "60-168-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "64-168-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "66-170-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "74-170-puddle" kolf(29016)/kdeui (KIconLoader): Internal error: Requested more space than exists in the cache. kolf(29016)/kdeui (KIconLoader): Unable to free up memory for "76-170-puddle" kolf(29016)/kdeui (KIconLoader): Unable to re-open cache, unfortunately the connection had to be dropped for crash safety -- things will be much slower now. KCrash: Application 'kolf' crashing... The crash can be reproduced every time. -- Backtrace: Application: Kolf (kolf), signal: Segmentation fault [Current thread is 1 (Thread 0xb49e9700 (LWP 29016))] Thread 2 (Thread 0xb1f4fb70 (LWP 29018)): #0 0xffffe424 in __kernel_vsyscall () #1 0xb6d500c2 in pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/i386/i486/pthread_cond_timedwait.S:179 #2 0xb6dc785c in wait (time=<value optimized out>, this=<value optimized out>) at thread/qwaitcondition_unix.cpp:85 #3 QWaitCondition::wait (time=<value optimized out>, this=<value optimized out>) at thread/qwaitcondition_unix.cpp:159 #4 0xb6dbbc86 in QThreadPoolThread::run (this=0x8167d98) at concurrent/qthreadpool.cpp:140 #5 0xb6dc67cf in QThreadPrivate::start (arg=0x8167d98) at thread/qthread_unix.cpp:248 #6 0xb6d4b6e5 in start_thread (arg=0x0) at pthread_create.c:297 #7 0xb6d4b600 in ?? () at pthread_create.c:216 from /lib/libpthread.so.0 Thread 1 (Thread 0xb49e9700 (LWP 29016)): [KCrash Handler] #7 pageTableSize (this=<value optimized out>) at /usr/src/debug/kdelibs-4.4.90/kdecore/util/kshareddatacache.cpp:420 #8 indexTableSize (this=<value optimized out>) at /usr/src/debug/kdelibs-4.4.90/kdecore/util/kshareddatacache.cpp:427 #9 findNamedEntry (this=<value optimized out>) at /usr/src/debug/kdelibs-4.4.90/kdecore/util/kshareddatacache.cpp:576 #10 KSharedDataCache::find (this=<value optimized out>) at /usr/src/debug/kdelibs-4.4.90/kdecore/util/kshareddatacache.cpp:1339 #11 0xb75a4968 in KImageCache::findPixmap (this=0x8112910, key=..., destination=0xbfe02088) at /usr/src/debug/kdelibs-4.4.90/kdeui/util/kimagecache.cpp:130 #12 0xb5b66887 in KGameRendererPrivate::requestPixmap (this=0x81bb6f0, spec=..., client=0x0, synchronousResult=0xbfe021ac) at /home/stefan/Code/kde/git-kdegames/libkdegames/kgamerenderer.cpp:447 #13 0xb5b66c01 in KGameRenderer::spritePixmap (this=0x81c4ad0, key=..., size=..., frame=-1) at /home/stefan/Code/kde/git-kdegames/libkdegames/kgamerenderer.cpp:390 #14 0xb77b2d3c in KolfEllipse::setSize (this=0x8756950, width=96, height=170) at /home/stefan/Code/kde/git-kdegames/kolf/game.cpp:936 #15 0xb779e812 in KolfEllipse::newSize (this=0x8756950, width=96, height=170) at /home/stefan/Code/kde/git-kdegames/kolf/game.cpp:928 #16 0xb77a8935 in RectPoint::moveBy (this=0x8c58a40, dx=5, dy=-0) at /home/stefan/Code/kde/git-kdegames/kolf/game.cpp:92 #17 0xb77ace9d in KolfGame::handleMouseMoveEvent (this=0x8166720, e=0xbfe02428) at /home/stefan/Code/kde/git-kdegames/kolf/game.cpp:2952 #18 0xb77ad146 in KolfGame::mouseMoveEvent (this=0x8166720, e=0xbfe02bc0) at /home/stefan/Code/kde/git-kdegames/kolf/game.cpp:2914 #19 0xb63e2668 in QWidget::event (this=0x8166720, event=0xbfe02bc0) at kernel/qwidget.cpp:8029 #20 0xb67f00e5 in QFrame::event (this=0x8166720, e=0xbfe02bc0) at widgets/qframe.cpp:557 #21 0xb688d041 in QAbstractScrollArea::viewportEvent (this=0xd8d65a38, e=0x65) at widgets/qabstractscrollarea.cpp:1036 #22 0xb6a6f5c4 in QGraphicsView::viewportEvent (this=0x8166720, event=0xbfe02bc0) at graphicsview/qgraphicsview.cpp:2787 #23 0xb688f936 in viewportEvent (event=<value optimized out>, this=<value optimized out>) at widgets/qabstractscrollarea_p.h:100 #24 QAbstractScrollAreaFilter::eventFilter (event=<value optimized out>, this=<value optimized out>) at widgets/qabstractscrollarea_p.h:116 #25 0xb6eca9ee in QCoreApplicationPrivate::sendThroughObjectEventFilters (this=0x805ae60, receiver=0x87482e8, event=0xbfe02bc0) at kernel/qcoreapplication.cpp:841 #26 0xb6381e0d in QApplicationPrivate::notify_helper (this=0x805ae60, receiver=0x87482e8, e=0xbfe02bc0) at kernel/qapplication.cpp:4298 #27 0xb638963e in QApplication::notify (this=0xbfe028f4, receiver=0x87482e8, e=0xbfe02bc0) at kernel/qapplication.cpp:3867 #28 0xb751cec1 in KApplication::notify (this=0xbfe03434, receiver=0x87482e8, event=0xbfe02bc0) at /usr/src/debug/kdelibs-4.4.90/kdeui/kernel/kapplication.cpp:309 #29 0xb6ecb71e in QCoreApplication::notifyInternal (this=0xbfe03434, receiver=0x87482e8, event=0xbfe02bc0) at kernel/qcoreapplication.cpp:726 #30 0xb6388584 in sendSpontaneousEvent (event=<value optimized out>, receiver=<value optimized out>) at ../../src/corelib/kernel/qcoreapplication.h:218 #31 QApplicationPrivate::sendMouseEvent (event=<value optimized out>, receiver=<value optimized out>) at kernel/qapplication.cpp:2965 #32 0xb641641a in QETWidget::translateMouseEvent (this=0x8133d40, event=0xbfe030cc) at kernel/qapplication_x11.cpp:4380 #33 0xb64159c4 in QApplication::x11ProcessEvent (this=0xbfe03434, event=0xbfe030cc) at kernel/qapplication_x11.cpp:3391 #34 0xb64430e8 in x11EventSourceDispatch (s=0x805e9b0, callback=0, user_data=0x0) at kernel/qguieventdispatcher_glib.cpp:146 #35 0xb53604c2 in g_main_context_dispatch () from /usr/lib/libglib-2.0.so.0 #36 0xb5363d98 in ?? () from /usr/lib/libglib-2.0.so.0 #37 0xb5363ebe in g_main_context_iteration () from /usr/lib/libglib-2.0.so.0 #38 0xb6ef8381 in QEventDispatcherGlib::processEvents (this=0x805ae20, flags=...) at kernel/qeventdispatcher_glib.cpp:412 #39 0xb6442c3a in QGuiEventDispatcherGlib::processEvents (this=0x805ae20, flags=...) at kernel/qguieventdispatcher_glib.cpp:204 #40 0xb6ec9d8d in QEventLoop::processEvents (this=0xbfe03384, flags=) at kernel/qeventloop.cpp:149 #41 0xb6eca1d9 in QEventLoop::exec (this=0xbfe03384, flags=...) at kernel/qeventloop.cpp:201 #42 0xb6ecf480 in QCoreApplication::exec () at kernel/qcoreapplication.cpp:1003 #43 0xb6381ee4 in QApplication::exec () at kernel/qapplication.cpp:3581 #44 0x0804a61f in main (argc=1, argv=0xbfe03644) at /home/stefan/Code/kde/git-kdegames/kolf/main.cpp:104 Reported using DrKonqi
DrKonqi put this under Kolf, but it's a KSharedDataCache bug.
Well I will say that debugging crashes in the cache while I was developing it turned mostly into an exercise of "thought debugging" since the corruption very often happens far before the crash. The valgrind tool includes helgrind and drd tools for debugging broken threading, would it be possible to use one of the two and see if you can narrow the issue further? I ask because I did use some test applications that "stress test" the cache by loading all possible icons as fast as possible, but it was only single-process. With the whole desktop using KSharedDataCache it's possible there's a race in conjuction with high load that would eventually lead to corruption.
Created attachment 50563 [details] New crash information added by DrKonqi kgvtestbed (0) on KDE Platform 4.5.00 (KDE 4.5.0) using Qt 4.6.3 Here is another backtrace, which I obtained from a testbed for the new kgamevisuals library, of which KGameRenderer is a fundamental part. This testing application uses KGameRenderer to render the scene background of KDiamond. The crash occurred during a window resizing operation, so again a situation with high load. I can send you the source code if you wish. -- Backtrace (Reduced): #7 0xb774eec7 in SharedMemory::defragment (this=0xb27e9000) at /usr/src/debug/kdelibs-4.5.0/kdecore/util/kshareddatacache.cpp:547 #8 0xb774fb8b in SharedMemory::removeUsedPages (this=0xb27e9000, numberNeeded=372) at /usr/src/debug/kdelibs-4.5.0/kdecore/util/kshareddatacache.cpp:719 #9 0xb7721ba6 in KSharedDataCache::insert (this=0x813fd40, key=..., data=...) at /usr/src/debug/kdelibs-4.5.0/kdecore/util/kshareddatacache.cpp:1289 #10 0xb6cd0e3e in KImageCache::insertImage (this=0x813fd40, key=..., image=...) at /usr/src/debug/kdelibs-4.5.0/kdeui/util/kimagecache.cpp:80 #11 0xb75362f6 in KgvRendererPrivate::jobFinished (this=0x8139ff0, job=0x82697f0, isSynchronous=false) at /home/stefan/Code/kde/libkgame/visuals/rendering/kgvrenderer.cpp:502
This backtrace does look more useful, thanks very much for continuing to look into this. I would appreciate you sending the source code, and if you could CC: michael.pyne@gmail.com since I have reduced Internet connectivity that would greatly help me debug it.
OK, the testcase is very useful, I can also reproduce the output in question, although not the crash itself. I don't have time to debug further tonight and I will be at work until Saturday morning so hopefully I can track down the underlying issue over the weekend.
Created attachment 50839 [details] Avoid a poorly-handled case in KSharedDataCache when there is between 100-150% of requested item size available, and handling out-of-room Stefan, what I've found so far is that there is a couple of logic errors in the removeUsedPages handling in KSharedDataCache: 1. Sometimes more pages are requested to be removed than is possible. This is already checked by removeUsedPages, but gives an internal error warning so this is fixed with a qMin macro to ensure a sane request. 2. The code path in question is reached under the condition that there is not enough free pages available, or that there enough free pages but they are too heavily fragmented to handle the request. First, we check if it's feasible that simply defragmenting would free up the space by checking for 150% of required free space. BUT, we assume in the else condition when making the removeUsedPages call that the space available was less than 100%, which can result in a negative amount of pages request to removeUsedPages. This gets cast to uint, which results in enormous page free sizes, so I'm not sure how this would actually cause damage, but it seems possible. I haven't been able to get the testcase to crash yet so this may not be the end of the story, but if you can test with this patch applied to kdelibs it may help get closer to the cause.
I'll try to test the patch, though it is not likely to happen too soon. I'm usually working with a packaged kdelibs, so I'll have to setup the build first.
SVN commit 1167620 by mpyne: Attempt to fix a couple of KSharedDataCache bugs. 1. Stefan Majewsky has found a crasher under heavy cache load (bug 243573). The testcase he provided did not crash for me, but did reveal that it was possible to attempt to free a negative amount of pages, since we'd end up in the "not enough room" case and then try to free extra room. It was possible that the way the extra space was added caused more pages to be requested freed than were allocated. AFAICS this should not by itself cause a crash, as removeUsedPages notes that condition and fails. But it's still a bug. Now the number of pages requested is capped to page table size before figuring out the number of pages that are in use. 2. Parker Coates found a crash bug involving a cache sized just large enough to hold exactly 1 page (the page size was == cache size). The number of entries the cache supports is page table size / 2. 1 / 2 in integer math is 0, therefore the entry table size was 0, and the cache eventually crashed when trying to divide by the possible number of entries. This is fixed by ensuring that the cache is sized to support at least a minimum number of different pages. This means that the expectedItemSize parameter becomes more important in determining overall minimum cache size. With default settings (4KiB page size, 256 pages) the minimum cache size is 1MiB. I also added some debugging error messages to try and more easily diagnose these kind of logic errors in the future. This commit is for KDE Platform 4.6. I intend to backport to 4.5.1 as well. CCBUG:243573 M +22 -2 kshareddatacache.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1167620
SVN commit 1167621 by mpyne: Backport two KSharedDataCache bugfixes to KDE Platform 4.5.1. 1. Do not attempt to free more pages than are actually allocated. This might fix bug 243573, but I cannot get the testcase to crash. (I even disabled desktop effect for maximum resizing speed ;) 2. Force the cache to have a certain minimum number of pages (currently 256) to avoid crashes if the cache contains only a single page. The commit log for the trunk commit, r1167620, has the detailed reasoning. CCBUG:243573 M +22 -2 kshareddatacache.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1167621
I just installed the 4.5.1 update, yet the crash in SharedMemory::defragment from comment 3 is still reproducible here.
Created attachment 51150 [details] Valgrind output for the crash mentioned in comment 3 Here is the Valgrind output for my testing application which produces the crash. I have stripped some unrelated memleaks in QTransform to make it more readable for you.
SVN commit 1180814 by mpyne: Do not index past the very last page in the cache while defragmenting. Noted during a code review while bored in class (mental note, don't print kshareddatacache.cpp single-sided in the future). Also, while testing an upcoming patch by Alberto Villa I had the opportunity to test the version-change-detection code. Worked fine going from 1 to >1, but when reverting back to 1 the cacheSize came back as 0 somehow, which caused a hang. So check for the version being wrong but not 0 now. This has been tested with Stefan Majewsky's KGameRenderer testbed, and might even fix a crash in SharedMemory::defragment. I don't see how this error would cause the Valgrind output Stefan noted, but it might indirectly cause a later operation to fail I suppose. This commit applies to KDE Platform 4.6. I will also backport to 4.5.2. CCBUG:243573 M +11 -5 kshareddatacache.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1180814
SVN commit 1180816 by mpyne: Backport two KSharedDataCache fixes to KDE Platform 4.5.2. The initial commit was r1180814, and fixes the following: * Fix an error in defragmentation that could cause corruption of the index table if the very last page in the cache was in use during defragmentation. This very possibly fixes bug 243573. * A more reliable (well, in theory) check is performed to tell if the cache version has unexpectedly changed for a cache that was actually in use. CCBUG:243573 M +11 -5 kshareddatacache.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1180816
Stefan, when you get a chance could you see if you're still able to reproduce this crash? Otherwise I'm going to assume I found it for real this time. ;)
Created attachment 52327 [details] New crash information added by DrKonqi tagarotestbed (0) on KDE Platform 4.5.2 (KDE 4.5.2) using Qt 4.7.0 I just updated to 4.5.2. I did not encounter the defragment() crash in my first test, yet the original crash is reproducible in the testbed application (again by continued resizing). Because the backtrace is slightly different now, I attach it again. -- Backtrace (Reduced): #7 operator int (this=0x81c0798, key=..., destination=0xbf9a7dec) at /usr/include/QtCore/qbasicatomic.h:85 #8 cachePageSize (this=0x81c0798, key=..., destination=0xbf9a7dec) at /usr/src/debug/kdelibs-4.5.2/kdecore/util/kshareddatacache.cpp:274 #9 pageTableSize (this=0x81c0798, key=..., destination=0xbf9a7dec) at /usr/src/debug/kdelibs-4.5.2/kdecore/util/kshareddatacache.cpp:431 #10 indexTableSize (this=0x81c0798, key=..., destination=0xbf9a7dec) at /usr/src/debug/kdelibs-4.5.2/kdecore/util/kshareddatacache.cpp:438 #11 findNamedEntry (this=0x81c0798, key=..., destination=0xbf9a7dec) at /usr/src/debug/kdelibs-4.5.2/kdecore/util/kshareddatacache.cpp:593
Therefore changing this back from NEEDSINFO to NEW. After some more trials, I think that the defragment() crash is gone. On a nearly unrelated note, it's a bit irritating that kDebug() attributes KSharedDataCache's debug messages to KIconLoader.
Thanks for the update, although at this point I'm despairing of finding an issue in KSharedDataCache itself. I'm hoping it's not an underlying Qt bug, or some kind of improper usage of QAtomicInt. But I don't see any way for the cache's pageSize attribute to be 0 by this point in execution. It gets set at only one spot. I think what I can do is to verify the sanity of the various cache operands when an existing cache is mapped but even that's not foolproof if some logic error is causing that particular variable to get corrupted.
Git commit 561e6494bdd9a02cc8feef649f7dbbd40a1456c3 by Michael Pyne. Committed on 20/05/2012 at 00:13. Pushed by mpyne into branch 'KDE/4.8'. kshareddatacache: Validate cache page size. This commit ensures that the cache page size is actually a power-of-2 and within the band of possible sizes that could possibly have been set. If this is not the case the cache is assumed corrupted and reset. This should help with any cache-corruption bugs caused by a wrong cache page size (although these don't exactly make themselves obvious). More fixes to follow... This one /should/ fix 274252 outright and may be of interest to several others. Related: bug 274252, bug 249362, bug 253665, bug 281217, bug 297815, bug 293954, bug 293447, bug 270915, bug 255233 FIXED-IN:4.8.4 M +26 -1 kdecore/util/kshareddatacache.cpp http://commits.kde.org/kdelibs/561e6494bdd9a02cc8feef649f7dbbd40a1456c3
Git commit ca2a6a59784232857a35b313adc9599efb87bd5e by Michael Pyne. Committed on 21/05/2012 at 01:19. Pushed by mpyne into branch 'KDE/4.8'. kshareddatacache: Adopt KSDCCorrupted for exceptional errors. This involves converting many present assertions (which crash no matter what) and error-code return values (which have to be checked everywhere the return value is used at) into using the KSDCCorrupted exception. The nice thing about using the exception is that it can be trapped and handled so that it does not cause an application crash. There's still a bit more to do -- the end goal is that all accesses to shm, no matter how minor, are vetted beforehand to ensure it won't cause a page fault or bus violation. Related: bug 249362, bug 253665, bug 281217, bug 297815, bug 293954, bug 293447, bug 270915, bug 255233 M +49 -34 kdecore/util/kshareddatacache.cpp http://commits.kde.org/kdelibs/ca2a6a59784232857a35b313adc9599efb87bd5e
Thank you for the crash report. As it has been a while since this was reported, can you please test and confirm if this issue is still occurring or if this bug report can be marked as resolved. I have set the bug status to "needsinfo" pending your response, please change back to "reported" or "resolved/worksforme" when you respond, thank you.
Dear Bug Submitter, This bug has been in NEEDSINFO status with no change for at least 15 days. Please provide the requested information as soon as possible and set the bug status as REPORTED. Due to regular bug tracker maintenance, if the bug is still in NEEDSINFO status with no change in 30 days the bug will be closed as RESOLVED > WORKSFORME due to lack of needed information. For more information about our bug triaging procedures please read the wiki located here: https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging If you have already provided the requested information, please mark the bug as REPORTED so that the KDE team knows that the bug is ready to be confirmed. Thank you for helping us make KDE software even better for everyone!
This bug has been in NEEDSINFO status with no change for at least 30 days. The bug is now closed as RESOLVED > WORKSFORME due to lack of needed information. For more information about our bug triaging procedures please read the wiki located here: https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging Thank you for helping us make KDE software even better for everyone!