twisted.internet.gtk2reactor conflicts with subprocess.Popen

[Iven]

I'm using Linux 64bit, Python 2.6.5, pygtk 2.22.0 and twisted 10.0.0. When I'm running the following script, one of the two CPUs will go 100% after subprocess returns(after 5 seconds).

#!/usr/bin/python
#import gtk
from twisted.internet import gtk2reactor
gtk2reactor.install()
from twisted.internet import reactor
import subprocess
subprocess.Popen(['sleep', '5'])
#gtk.main()
reactor.run()

If I use gtk.main() instead of reactor.run(), there will be no problem, so I wonder if it is a bug of twisted?

[teratorn]

FWIW, this doesn't happen here with Linux/32-bit, Python 2.6.5, pygtk 2.17.0, gtk 2.20.1, Twisted 10.0.0

[teratorn]

Nor on Linux/64-bit, Python 2.6.5, pygtk 2.17.0, gtk 2.20.1, Twisted 10.0.0

[Jean-Paul Calderone]

The first release of Twisted which claims to be compatible with the subprocess module at all is 10.1. So perhaps this is invalid. Please try with 10.1 or later and report the results. Also, if you still have a problem on 10.1 or later, please add these lines to the beginning of your example and report the extra output:

from twisted.python.log import startLogging
from sys import stdout
startLogging(stdout)

Also, there's #4286, but it should only matter when running on Python 2.5.

[Jean-Paul Calderone]

Please re-open with more details if this turns out to be a problem on 10.1 or later. (Closing as a duplicate of the ticket which implemented the Popen/reactor compatibility

in 10.1, #733.)

[Iven]

Thing goes the same on 10.1, Ubuntu 10.10 32bit, pygtk 2.21.0, gtk 2.22.0. Here is the log: 2010-10-05 14:45:37+0800 [-] Log opened. 2010-10-05 14:45:37+0800 [-] using set_wakeup_fd ^{C2010-10-05 14:45:54+0800 [-] Received SIGINT, shutting down.}

[Jean-Paul Calderone]

I tried to reproduce this in a 32bit Ubuntu 10.04 VM and wasn't able to.

[Thijs Triemstra]

can't reproduce it on osx 10.5.8 with python2.5 and twisted 10.1 either.

>>> gtk.gtk_version
(2, 14, 8)
>>> gtk.pygtk_version
(2, 15, 0)

[Iven]

I've reproduced it on Ubuntu 10.10 64-bit on another machine, maybe it's a problem with the newer version softwares? I'll try 10.04 later.

[Iven]

I can't reproduce it on Ubuntu 10.04 on the same machine. I think you should reproduce it on newer pygtk and gtk. Ubuntu 10.10 is on the way.

[Jean-Paul Calderone]

#4829 was a duplicate of this.

[Antoine Martin]

I've just fired the test-case above (rather than the one in #4829) and I can reproduce this 100% on both the latest Fedora (14) and Ubuntu (10.10), and probably most other distros too.

Any suggestions for a workaround would be much appreciated. At the moment I get lots of user complaints of the form: "your application is buggy/crap" because of this.

[Jean-Paul Calderone]

Here's an strace of the demo after it starts hogging the CPU:

poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7, events=POLLIN}, {fd=3, events=POLLIN}], 4, 29) = 1 ([{fd=7, revents=POLLIN}])
read(7, 0, 1)                           = -1 EFAULT (Bad address)
gettimeofday({1296137620, 466729}, NULL) = 0
read(8, 0x8fcc438, 4096)                = -1 EAGAIN (Resource temporarily unavailable)
gettimeofday({1296137620, 466835}, NULL) = 0

This happens in a perpetual loop.

The EFAULT on fd 7 looks pretty suspect, but it's also not clear why the process keeps trying to read from fd 8.

So, I don't really know what's going on here. It still looks like a gtk2 bug to me, though.

[Antoine Martin]

I've collected similar straces before.

Aren't those fds the stdin and/or stdout of the subprocess? And since that's terminated... there's nothing there, right?

If I wrap Popen, wouldn't it be possible to force the reactor (gtk in this case) to stop polling on those (closed?) fds somehow?

[Jean-Paul Calderone]

I don't think so. The way Popen is used in this example, the child stdio is inherited directly from the parent. It doesn't pass through the parent process at all, and nothing in the reactor monitors it.

7 is created by a pipe call. 8 created by a socket(PF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) call and then connected to localhost port 6010... ie, X11.

[Jean-Paul Calderone]

If it helps at all, reactor.run(installSignalHandlers=False) appears to eliminate the CPU issue. Of course, this breaks reactor.spawnProcess, but if you're using Popen then it's possible you don't care much about that.

This workaround suggests it's an interaction between Twisted's signal handling and glib/gtk/pygtk's signal handling that causes the problem.

[Antoine Martin]

Actually, I am using reactor.spawnProcess... so that doesn't help me :(

FYI: I've created a bug on gnome's bugzilla: ​bug 640738 (which also points back here)

[Antoine Martin]

I've just tried and it looks like my problem is finally solved! (no CPU usage) - simply by using your suggestion: reactor.run(installSignalHandlers=False) - thank you so much!

In what way does it break reactor.spawnProcess? All the calls to reactor.spawnProcess seem to work as expected... so far. I won't be rushing a bugfix release out just yet, but this looks promising.

[Jean-Paul Calderone]

In what way does it break reactor.spawnProcess?

Without a SIGCHLD handler installed, Twisted won't notice when child processes exit, and won't reap them. They'll remain zombies and the ProcessProtocol.processEnded and ProcessProtocol.processExited callbacks will never be invoked.

[Jean-Paul Calderone]

This code from pygtk probably has something to do with the bug:

#ifdef HAVE_PYSIGNAL_SETWAKEUPFD
    PySignalWatchSource *real_source = (PySignalWatchSource *)source;
    GPollFD *poll_fd = &real_source->fd;
    int data_size = 0;
    if (poll_fd->revents & G_IO_IN)
        data_size = read(poll_fd->fd, 0, 1);
#endif

I don't know of any way that read(poll_fd->fd, 0, 1) could ever do anything except fail with EINVAL. There is also no error checking after this call, so no one ever notices the read fails. This is from ​http://git.gnome.org/browse/pygtk/tree/gtk/gtk.override, pygtk_main_watch_check.

[Antoine Martin]

They'll remain zombies

That would be a major problem for me, but strangely enough that is not what I am seeing. When the child terminates, I get a nice:

twisted.internet.error.ProcessDone
A process has ended without apparent errors: process finished with exit code 0.

My code is a bit more complex as it extends the protocol.ProcessProtocol via a HiddenSpawnedProcess wrapper (to workaround the shell window popup issue on win32), but eventually it ends up calling reactor.spawnProcess from the HiddenSpawnedProcess.startProcess override function... And you're saying that this should not work properly since I run it with reactor.run(installSignalHandlers=False)? But it does.. How odd!

I'll post your findings to gnome.org as I think they should at least comment on that.

[Jean-Paul Calderone]

That would be a major problem for me, but strangely enough that is not what I am seeing.

I suppose that means installSignalHandlers=False is broken right now and isn't actually preventing the signal handler from being installed. I don't know what it is doing, then, that it manages to fix this behavior.

[Antoine Martin]

The ​pygtk patch you posted works for me, so I am closing this bug as invalid since there's nothing wrong with twisted.(the strange installSignalHandlers=False behaviour is a separate issue)

Thanks again for everything!

[Jean-Paul Calderone]

The ​upstream bug report has been closed as fixed.