Bug 234781

Created attachment 42889 [details]
plasmoid that's crashed

The Make Progress data engine should be installed:
http://nikita.melnichenko.name/download.php?q=make-progress-0.1.0.engine

Steps to reprodice:
1. run in plasmoidviewer
You will see many strings in console like that:
plasmoidviewer(14515)/kdecore (KConfigSkeleton) KCoreConfigSkeleton::writeConfig:
They will be mixed with replies from engine.
2. click the button, notification should appear
3. wait until replies stop printing (there would be only writeConfig lines)
4. click again -> crash

There are also these messages in console before crash:

plasmoidviewer(14515)/kdecore (KConfigSkeleton) KCoreConfigSkeleton::writeConfig:
plasmoidviewer(14515)/kdecore (KConfigSkeleton) KCoreConfigSkeleton::writeConfig:
plasmoidviewer(14515)/kdecore (KConfigSkeleton) KCoreConfigSkeleton::writeConfig:
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515): Failed to lock file "/var/tmp/kdecache-nikita/kpc/plasma_theme_default.lock" , last result = 2 
plasmoidviewer(14515)/kdecore (KConfigSkeleton) KCoreConfigSkeleton::writeConfig:
clicked
QProcessPrivate::createPipe: Cannot create pipe 0x2d1fd28: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0x2d1fd50: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0x2d1fd78: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0x2d1fe00: Too many open files
QProcessPrivate::createPipe: Cannot create pipe 0x2d1fe08: Too many open files
QSocketNotifier: Invalid socket specified
QSocketNotifier: Invalid socket specified
KCrash: Application 'plasmoidviewer' crashing...
sock_file=/home/nikita/.kde4/socket-razor/kdeinit4__0

[1]+  Stopped                 plasmoidviewer .


This is why a button is needed - to force opening a new file. These messages show that bug#232973 is probably the same issue. Plasma can't lock plasma_theme_default.lock so it can't show any icons.

I can confirm this on my machine.
Steps to reproduce:

1. Download Make-Progress Engine 0.1.1 and Plasmoid 0.1.0
http://nikita.melnichenko.name/download.php?q=make-progress-latest.engine
http://nikita.melnichenko.name/download.php?q=make-progress-0.1.0.plasmoid

2. Install engine
$ plasmapkg -u make-progress-0.1.1.engine -t dataengine

3. Extract and start plasmoid
$ unzip make-progress-0.1.0.plasmoid -d plasmoid-make-progress
$ plasmoidviewer plasmoid-make-progress

4A. Add one long timer (min. 4 minutes) manually or via dbus, then start it
$ TIMER=$(qdbus name.melnichenko.nikita.make-progress.plasmoid / AddItem Timer); qdbus name.melnichenko.nikita.make-progress.plasmoid /$TIMER SetMaximum 240000; qdbus name.melnichenko.nikita.make-progress.plasmoid /$TIMER Start

4B. Instead of using one long timer, you can add multiple short timers (e.g. 8 x 10 seconds). This way you do not have to wait 4 minutes ;)
$ for i in {1..8};do TIMER=$(qdbus name.melnichenko.nikita.make-progress.plasmoid / AddItem Timer);qdbus name.melnichenko.nikita.make-progress.plasmoid /$TIMER SetMaximum 10000; qdbus name.melnichenko.nikita.make-progress.plasmoid /$TIMER Start;sleep 1s; done

5. plasmoidviewer/plasma crashes as soon as the first timer is done.

Versions:
KDE SC: 4.4.2
Qt: 4.6.2
Python: 2.6.4
PyQt: 4.7.2


end of output:
[...]
[Make progress!] Notification: Task e3 is complete.
QProcessPrivate::createPipe: Cannot create pipe 0xab108e0: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0xab108f8: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0xab10910: Too many open files
QSocketNotifier: Invalid socket specified
QProcessPrivate::createPipe: Cannot create pipe 0xab10970: Too many open files
QProcessPrivate::createPipe: Cannot create pipe 0xab10978: Too many open files
QSocketNotifier: Invalid socket specified
QSocketNotifier: Invalid socket specified
KCrash: Application 'plasmoidviewer' crashing...


Crashlog:
 Application: Plasma-Miniprogramm-Anzeige (plasmoidviewer), signal: Segmentation fault
[Current thread is 1 (Thread 0xb77b4710 (LWP 10270))]

Thread 2 (Thread 0xac643b70 (LWP 10272)):
#0  0x00e75422 in __kernel_vsyscall ()
#1  0x00dcbe15 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/tls/i686/cmov/libpthread.so.0
#2  0x0354487d in pthread_cond_wait () from /lib/tls/i686/cmov/libc.so.6
#3  0x02ba6887 in ?? () from /usr/lib/libQtScript.so.4
#4  0x02ba68d1 in ?? () from /usr/lib/libQtScript.so.4
#5  0x00dc780e in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#6  0x035378de in clone () from /lib/tls/i686/cmov/libc.so.6

Thread 1 (Thread 0xb77b4710 (LWP 10270)):
[KCrash Handler]
#6  0x009a2869 in ?? () from /usr/lib/libQtCore.so.4
#7  0x0095ef7f in QProcess::waitForStarted(int) () from /usr/lib/libQtCore.so.4
#8  0x01a3b4d5 in ?? () from /usr/lib/libkio.so.5
#9  0x01a3b562 in ?? () from /usr/lib/libkio.so.5
#10 0x01a3c362 in ?? () from /usr/lib/libkio.so.5
#11 0x01a3c9ee in KRun::runCommand(QString const&, QString const&, QString const&, QWidget*, QByteArray const&, QString const&) () from /usr/lib/libkio.so.5
#12 0x01a3cc58 in KRun::runCommand(QString const&, QWidget*, QString const&) () from /usr/lib/libkio.so.5
#13 0x01a3ce6a in KRun::runCommand(QString const&, QWidget*) () from /usr/lib/libkio.so.5
#14 0x081ea5df in ?? () from /usr/lib/kde4/plasma_appletscript_simple_javascript.so
#15 0x02beb07b in ?? () from /usr/lib/libQtScript.so.4
#16 0x02b12db0 in ?? () from /usr/lib/libQtScript.so.4
#17 0x02ab0c0c in ?? () from /usr/lib/libQtScript.so.4
#18 0x028c4737 in ?? ()
#19 0x02ad8471 in ?? () from /usr/lib/libQtScript.so.4
#20 0x02b41a1d in ?? () from /usr/lib/libQtScript.so.4
#21 0x02b12e0e in ?? () from /usr/lib/libQtScript.so.4
#22 0x02b49333 in ?? () from /usr/lib/libQtScript.so.4
#23 0x02beccc5 in ?? () from /usr/lib/libQtScript.so.4
#24 0x02ab0f1d in ?? () from /usr/lib/libQtScript.so.4
#25 0x028c0aad in ?? ()
#26 0x02ad8471 in ?? () from /usr/lib/libQtScript.so.4
#27 0x02b41a1d in ?? () from /usr/lib/libQtScript.so.4
#28 0x02b12e0e in ?? () from /usr/lib/libQtScript.so.4
#29 0x02bf7d63 in ?? () from /usr/lib/libQtScript.so.4
#30 0x02bf8146 in ?? () from /usr/lib/libQtScript.so.4
#31 0x009cde5a in QMetaObject::metacall(QObject*, QMetaObject::Call, int, void**) () from /usr/lib/libQtCore.so.4
#32 0x009dc5f5 in QMetaObject::activate(QObject*, QMetaObject const*, int, void**) () from /usr/lib/libQtCore.so.4
#33 0x00a2dc97 in QTimer::timeout() () from /usr/lib/libQtCore.so.4
#34 0x009e479e in QTimer::timerEvent(QTimerEvent*) () from /usr/lib/libQtCore.so.4
#35 0x009d9494 in QObject::event(QEvent*) () from /usr/lib/libQtCore.so.4
#36 0x00fab3cc in QApplicationPrivate::notify_helper(QObject*, QEvent*) () from /usr/lib/libQtGui.so.4
#37 0x00fb201e in QApplication::notify(QObject*, QEvent*) () from /usr/lib/libQtGui.so.4
#38 0x006595ba in KApplication::notify(QObject*, QEvent*) () from /usr/lib/libkdeui.so.5
#39 0x009c8beb in QCoreApplication::notifyInternal(QObject*, QEvent*) () from /usr/lib/libQtCore.so.4
#40 0x009f7eb6 in ?? () from /usr/lib/libQtCore.so.4
#41 0x009f4b47 in ?? () from /usr/lib/libQtCore.so.4
#42 0x01bfee88 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#43 0x01c02730 in ?? () from /lib/libglib-2.0.so.0
#44 0x01c02863 in g_main_context_iteration () from /lib/libglib-2.0.so.0
#45 0x009f4805 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/libQtCore.so.4
#46 0x0106ab35 in ?? () from /usr/lib/libQtGui.so.4
#47 0x009c7209 in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/libQtCore.so.4
#48 0x009c765a in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/libQtCore.so.4
#49 0x009cb84f in QCoreApplication::exec() () from /usr/lib/libQtCore.so.4
#50 0x00fab467 in QApplication::exec() () from /usr/lib/libQtGui.so.4
#51 0x08050bf7 in _start ()

what command is getting run (as apparently there is a call to runCommand there) and how often is it getting called?

It's a python, if I understood you right. Here it is:
plasmoid.runCommand("python", [ plasmoid.file("", "scripts/knotify.py"), "Notification",  "title",  "clicked", "3000"]);
Actually, it's not the reason because it just starts a new QProcess which needs a new file descriptor, and Plasma (or plasmoidviewer, whatever) is out of free descriptors at that moment. So it's just a "crash initiator", I believe.

The problem is somewhere between service.startOperationCall and plasmoid.dataUpdated. They are called very often. It seems that startOperationCall opens a new descriptor each time and forgets to close it. Something like that. That's why Plasma has no more descriptors in the moment of crash.

Have you tried to reproduce it with the attached plasmoid I specially created for this bug report? It's much smaller that Make Progress plasmoid and should be a good testcase. The crash can be reproduced every time on my system. I hope it could help you. Thanks for attention.

I spent few hours today by looking for the reason of descriptor leak. It seems I have found what's causing it. This knowledge even helped me to make a walk-around for this issue in my plasmoid.

The problem was in the serviceForSource. Each time it had been called, the new instance of Service object is created and registerOperationsScheme is called (which calls setOperationsScheme). It needs a QFile object and lives with it (don't understand why it should live with it, we probably need read-and-forget pattern here). For some reason (buggy Plasma?) the service objects are never freed, so the number of QFile objects increases (btw, the memory leak grows too). At some point Plasma can't open new files and crashes (here is the second bug).

The walk-around is to save created objects and return these instances on further requests. However this fix is not complete: user can actively create and delete progress items and we must create new instances of ServiceProgressProps class. Anyway, this walk-around covers the most of cases and needs to be applied.

To sum up. I think there are two bugs here:
1. Service objects are not freed, i.e. if serviceForSource returns a new object for the same source, older isn't destroyed.
2. When Plasma is out of file descriptors, runCommand makes segfault.

and one question:
Why descriptor is needed for service?
I looked through code of Service::setOperationsScheme and didn't understood FIXME message:
    //FIXME: make KSharedConfig and KConfigSkeleton not braindamaged in 4.2 and then get rid of the
    //       temp file object here
    d->tempFile = new KTemporaryFile;
    d->tempFile->open();

Here d->tempFile is probably a descriptor that lives with a service. It must be deleted right in the end of that function, isn't it?

*** This bug has been confirmed by popular vote. ***

"For some reason (buggy Plasma?) the service objects are never freed"

from the api documentation: "The service is parented to the DataEngine, but may be deleted by the caller when finished with it." I'll change "may be" to "should be", but the meaning should really be clear already: Service objects are created on demand and really belong to the caller.

"The walk-around is to save created objects and return these instances on
further requests"

if you are doing this in the DataEninge, then this will eventually lead to crashes due to dangling pointers being held on to by the various users of the DataEngine's services when one of them deletes a Service (which is not only valid, it's how Services should be used).

if you are caching the Service objects in the Plasmoid, then yes, that's the correct approach.

"Here d->tempFile is probably a descriptor that lives with a service. It must be
deleted right in the end of that function, isn't it?"

no, because that KConfig object is required to make all the KConfigGroup reading/writing work properly. it needs to live as long as the service does. the problem here is that there is no "in memory" KConfigBackend to be used with KConfigBase, which would make the entire thing not require any file access at all beyond reading in the .operations file when the service is created.

In any case, the root of this particular bug is due to holding on to service objects indefinitely; even without the file descriptors it will lead to a growing usage of memory. Fix the plasmoid. :)

Resolution DOWNSTREAM? Wait a minute...

First of all, it's a 100% reproducible crash that was obtained by using scripts only. The main point of all this scripting thing is the high level of security. No matter what you write in your scripts, the background layer should NEVER ever ever crash! The good thing is additional leak protection and check for infinite loops, however, it's not so important as crash-free bindings. As far as I see, this crash haven't been fixed yet.

Secondly, you're wrong that something is holding service objects intentionally. Please, consider the given code a little bit closely. Who is actually holding these objects? Is it the data engine? No, because (in the initial version) it creates objects and returns them without any caching. Is it the plasmoid? No, it always calls serviceForSource, stores service object as local variable in a function and totally forget it after service.startOperationCall. We can't destroy an object in Javascript as in C++ language, however, reference count should be = 0. Don't write "fix the plasmoid" without giving an idea how to fix it, please!

I know it's a complicated bug, but we, KDE people, must fearlessly face it and finally solve it ;).

"The good thing is additional leak protection and check for
infinite loops, however, it's not so important as crash-free bindings"

that's precisely what this bug was: lack of accounting for leak protection and infinite loops. that's something QtScript is supposed to be giving us in future releases (hopefully sooner rather that later).

in 4.5 a temporary file is no longer used for services, so the file handle exhaustion won't happen anymore.

still, if you allocate infinite amounts of memory in your plasmoid we still don't catch that, and can't right now (against, blocking on QtScript). fix the script in the meantime because your users won't like it being terminated either.