[Twisted-Python] git clone with spawnProcess() can prevent socket data flow, any clue why?

Hi I am getting a weird problem where git cloning with reactor.spawnProcess() fails for some repositories. It appears as if Twisted blocks reading from the server socket that git packs should come on. I originally got the problem with buildbot, but I have has isolated the problem further to Twisted. The following program can be used to reproduce the problem: #!/usr/bin/python from twisted.internet import reactor, protocol class ProcessPrinter(protocol.ProcessProtocol): def connectionMade(self): print "::connectionMade" def outReceived(self, data): print "::outReceived" print data def errReceived(self, data): print "::errReceived" print data def processEnded(self, status_object): print "::processEnded" print "exit code %d" % status_object.value.exitCode reactor.stop() def spawn_after_run(): argv = ['/usr/bin/git', 'clone', 'git://git.gnome.org/gimp'] reactor.spawnProcess(ProcessPrinter(), argv[0], argv) reactor.callLater(0, spawn_after_run); reactor.run(); If a debugger is attached to the spawned git process, it can be seen that the process blocks on read() on the socket that is supposed to be fed with git packs from the server. I have done a tcpdump of the traffic between my computer and the git server, and there *is* successful communication going on. More specifically, the git client receives the refs the server has, and sends the refs it wants, which is acknowledged by the server, but for some reason it still eventually blocks on read(). Curiously enough, if the program is changed to clone e.g. 'git://git.gnome.org/gegl' instead of 'git://git.gnome.org/gimp', it works! The GIMP repo is much bigger than the GEGL one, which might be the trigger for the bug, but I don't understand why it would matter. I see this problem on Fedora 13 x86_64, both with the distro version Twisted 0.8.2, and with the latest stable release Twisted 10.1.0. My personal guess is that it has something to do with how spawnProcess() manages the fds or the child process. Does anyone have any guess of what is going on? Can you reproduce it on other systems? Thanks in advance for any input. Regards, Martin

On 08/28/2010 09:34 AM, Martin Nordholts wrote:
Hi
I am getting a weird problem where git cloning with reactor.spawnProcess() fails for some repositories. It appears as if Twisted blocks reading from the server socket that git packs should come on.
Started to debug this myself in Twisted, and it turns out that if I disable _setupChild() in twisted.internet.process.Process, the sample program that clones GIMP with spawnProcess() works as expected. --- Twisted-10.1.0-orig/twisted/internet/process.py +++ Twisted-10.1.0/twisted/internet/process.py @@ -619,6 +619,9 @@ class Process(_BaseProcess): original. """ + # Don't do this.. + return + debug = self.debug_child if debug: errfd = sys.stderr I'll see if I can pinpoint the bug... / Martin

On Sat, 2010-08-28 at 11:31 +0200, Martin Nordholts wrote:
I'll see if I can pinpoint the bug...
If you can reproduce this with a Python program you launch, rather than git, that would be ideal. I assume you've tested this by running git without twisted, on the command-line, just to make sure the problem doesn't occur there?

On 08/28/2010 03:32 PM, Itamar Turner-Trauring wrote:
On Sat, 2010-08-28 at 11:31 +0200, Martin Nordholts wrote:
I'll see if I can pinpoint the bug...
If you can reproduce this with a Python program you launch, rather than git, that would be ideal.
I assume you've tested this by running git without twisted, on the command-line, just to make sure the problem doesn't occur there?
Yes, I can clone fine if I don't use Twisted, and I think it worked fine to clone with Twisted when I ran git-daemon myself. It when cloning from a local repo copy with file:// in Twisted instead of from git://git.gnome.org. Just out of curiosity, can you reproduce the problem on your machine? Does my test-program ever return for you? / Martin

Hi Martin, I tried your code just for the curiosity and it seems to work here. Are you sure it doesn't work? Cloning the Gimp repository takes ages here (half an hour - well, for a ~200MB compressed repository it isn't that bad given my connection speed now), but it eventually finishes. The error output handling behaves somewhat weird, but definitely Twisted doesn't seem to "block" git from doing it's job, at least not here. See the output of your script here: http://paste.org/21833 Tested on Python 2.6.1/Twisted 8.2.0/OSX 10.6. Cheers, Petr Martin Nordholts wrote:
On 08/28/2010 03:32 PM, Itamar Turner-Trauring wrote:
On Sat, 2010-08-28 at 11:31 +0200, Martin Nordholts wrote:
I'll see if I can pinpoint the bug...
If you can reproduce this with a Python program you launch, rather than git, that would be ideal.
I assume you've tested this by running git without twisted, on the command-line, just to make sure the problem doesn't occur there?
Yes, I can clone fine if I don't use Twisted, and I think it worked fine to clone with Twisted when I ran git-daemon myself. It when cloning from a local repo copy with file:// in Twisted instead of from git://git.gnome.org.
Just out of curiosity, can you reproduce the problem on your machine? Does my test-program ever return for you?
/ Martin
_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

On 08/28/2010 05:02 PM, Petr Mifek wrote:
Hi Martin,
I tried your code just for the curiosity and it seems to work here. Are you sure it doesn't work?
Hi, Thanks for testing the code. Interesting that it works for you. I hope we can understand why when we've found out why the bug is happening for me in the first place. Yes I'm sure it doesn't work :) During my debugging now, the lack of heavy incoming network traffic shows early on if things works as they should. I've also inspected the process with GNU gdb and seen that the process makes no progress, and buildbot builds for GIMP times out on the git build step. Regards, Martin

Interesting. Also you can check this file (given you started the clone on a directory with the sample script where no "gimp" subdir exists) ls -l ./gimp/.git/objects/pack/tmp_pack_* There should be one such file and it should grow up to ~175MB during the cloning. BTW your git version? Here it is: $ git --version git version 1.7.0.3 Petr Martin Nordholts wrote:
On 08/28/2010 05:02 PM, Petr Mifek wrote:
Hi Martin,
I tried your code just for the curiosity and it seems to work here. Are you sure it doesn't work?
Hi,
Thanks for testing the code. Interesting that it works for you. I hope we can understand why when we've found out why the bug is happening for me in the first place.
Yes I'm sure it doesn't work :) During my debugging now, the lack of heavy incoming network traffic shows early on if things works as they should. I've also inspected the process with GNU gdb and seen that the process makes no progress, and buildbot builds for GIMP times out on the git build step.
Regards, Martin
_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

On 08/28/2010 06:00 PM, Petr Mifek wrote:
Interesting. Also you can check this file (given you started the clone on a directory with the sample script where no "gimp" subdir exists)
ls -l ./gimp/.git/objects/pack/tmp_pack_*
There should be one such file and it should grow up to ~175MB during the cloning.
BTW your git version? Here it is:
$ git --version git version 1.7.0.3
I never get any gimp dir created at all, presumably because it never gets any data to put in the dir. I guess git doesn't create the dir until it has things to put there. I have git version 1.7.2.2 / Martin

Yes, here when git does connect but receives nothing, it doesn't make the directory. So your the sample script hangs at you with only ::connectionMade in output? Does suppressing the git's output to stderr help? (a -q modifier to git clone)? Petr Martin Nordholts wrote:
On 08/28/2010 06:00 PM, Petr Mifek wrote:
Interesting. Also you can check this file (given you started the clone on a directory with the sample script where no "gimp" subdir exists)
ls -l ./gimp/.git/objects/pack/tmp_pack_*
There should be one such file and it should grow up to ~175MB during the cloning.
BTW your git version? Here it is:
$ git --version git version 1.7.0.3
I never get any gimp dir created at all, presumably because it never gets any data to put in the dir. I guess git doesn't create the dir until it has things to put there.
I have git version 1.7.2.2
/ Martin
_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

On 08/28/2010 06:54 PM, Petr Mifek wrote:
Yes, here when git does connect but receives nothing, it doesn't make the directory. So your the sample script hangs at you with only
::connectionMade
in output? Does suppressing the git's output to stderr help? (a -q modifier to git clone)?
No I get more output than that, I get: martin@ltop:~/source/temp$ ./git-clone-gimp.py childFDs {0: 'w', 1: 'r', 2: 'r'} [0] w readFD=7, writeFD=8 [1] r readFD=9, writeFD=10 [2] r readFD=11, writeFD=14 fdmap {0: 7, 1: 10, 2: 14} helpers {0: 8, 1: 9, 2: 11} ::connectionMade starting _setupChild fdmap {0: 7, 1: 10, 2: 14} os.dup2(7,0) os.dup2(10,1) os.dup2(14,2) ::errReceived old [7, 10, 14] ::outReceived Cloning into gimp... A -q argument did, as expected, not help. / Martin

Does 'tcpdump' show any git activity when you run your program, Martin? Once I had a problem like yours, and in my case it was caused by git not using the HTTP proxy within my company's LAN. C

On Sun, 2010-08-29 at 08:55 +0100, Carlos Valiente wrote:
Does 'tcpdump' show any git activity when you run your program, Martin? Once I had a problem like yours, and in my case it was caused by git not using the HTTP proxy within my company's LAN.
I notice the original code doesn't pass os.environ to the sub-process... maybe doing so would help?

On 07:34 am, enselic@gmail.com wrote:
Hi
I am getting a weird problem where git cloning with reactor.spawnProcess() fails for some repositories. It appears as if Twisted blocks reading from the server socket that git packs should come on.
I originally got the problem with buildbot, but I have has isolated the problem further to Twisted. The following program can be used to reproduce the problem:
[snip]
I see this problem on Fedora 13 x86_64, both with the distro version Twisted 0.8.2, and with the latest stable release Twisted 10.1.0. My personal guess is that it has something to do with how spawnProcess() manages the fds or the child process.
Does anyone have any guess of what is going on? Can you reproduce it on other systems?
Thanks in advance for any input.
The git process gets all the way through the gimp checkout on my system, Ubuntu 9.10, with either Twisted 8.2.0 or current trunk@HEAD. Jean-Paul
participants (5)
-
Carlos Valiente
-
exarkun@twistedmatrix.com
-
Itamar Turner-Trauring
-
Martin Nordholts
-
Petr Mifek