Bugs item #1634739, was opened at 2007-01-13 16:46 Message generated for change (Comment added) made by astrand You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1634739&group_id=5470
Please note that this message will contain a full copy of the comment thread, including the initial issue submission, for this request, not just the latest update. Category: Python Library Group: Python 2.5 Status: Open Resolution: None Priority: 5 Private: No Submitted By: Florent Rougon (frougon) Assigned to: Nobody/Anonymous (nobody) Summary: Problem running a subprocess Initial Comment: Hello, I have a problem running a subprocess from Python (see below). I first ran into it with the subprocess module, but it's also triggered by a simple os.fork() followed by os.execvp(). So, what is the problem, exactly? I have written the exact same minimal program in C and in Python, which uses fork() and execvp() in the most straightforward way to run the following command: transcode -i /tmp/file.mpg -c 100-101 -o snapshot -y im,null -F png (whose effect is to extract the 100th frame of /tmp/file.mpg and store it into snapshot.png) The C program runs fast with no error, while the one in Python takes from 60 to 145 times longer (!), and triggers error messages from transcode. This shouldn't happen, since both programs are merely calling transcode in the same way to perform the exact same thing. Experiments ------------ 1. First, I run the C program (extract_frame) twice on a first .mpg file (MPEG 2 PS) [the first time fills the block IO cache], and store the output in extract_frame.output: % time ./extract_frame >extract_frame.output 2>&1 ./extract_frame > extract_frame.output 2>& 1 0.82s user 0.33s system 53% cpu 2.175 total % time ./extract_frame >extract_frame.output 2>&1 ./extract_frame > extract_frame.output 2>& 1 0.79s user 0.29s system 96% cpu 1.118 total Basically, this takes 1 or 2 seconds. extract_frame.output is attached. Second, I run the Python program (extract_frame.py) on the same .mpg file, and store the output in extract_frame.py.output: % time ./extract_frame.py >extract_frame.py.output 2>&1 ./extract_frame.py > extract_frame.py.output 2>& 1 81.59s user 25.98s system 66% cpu 2:42.51 total This takes more than 2 *minutes*, not seconds! (of course, the system is idle for all tests) In extract_frame.py.output, the following error message appears quickly after the process is started: failed to write Y plane of frame(demuxer.c) write program stream packet: Broken pipe which is in fact composed of two error messages, the second one starting at "(demuxer.c)". Once these messages are printed, the transcode subprocesses[1] seem to hang (with relatively high CPU usage), but eventually complete, after 2 minutes or so. There are no such error messages in extract_frame.output. 2. Same test with another .mpg file. As far as time is concerned, we have the same problem: [C program] % time ./extract_frame >extract_frame.output2 2>&1 ./extract_frame > extract_frame.output2 2>& 1 0.73s user 0.28s system 43% cpu 2.311 total [Python program] % time ./extract_frame.py >extract_frame.py.output2 2>&1 ./extract_frame.py > extract_frame.py.output2 2>& 1 92.84s user 12.20s system 76% cpu 2:18.14 total We also get the first error message in extract_frame.py.output2: failed to write Y plane of frame when running extract_frame.py, but this time, we do *not* have the second error message: (demuxer.c) write program stream packet: Broken pipe All this is reproducible with Python 2.3, 2.4 and 2.5 (Debian packages in sarge for 2.3 and 2.4, vanilla Python 2.5). % python2.5 -c 'import sys; print sys.version; print "%x" % sys.hexversion' 2.5 (r25:51908, Jan 5 2007, 17:35:09) [GCC 3.3.5 (Debian 1:3.3.5-13)] 20500f0 % transcode --version transcode v1.0.2 (C) 2001-2003 Thomas Oestreich, 2003-2004 T. Bitterberg I'd hazard that Python is tweaking some process or threading parameter that is inherited by subprocesses and disturbs transcode, which doesn't happen when calling fork() and execvp() from a C program, but am unfortunately unable to precisely diagnose the problem. Many thanks for considering. Regards, Florent [1] Plural because the transcode process spawns several childs: tcextract, tcdemux, etc. ---------------------------------------------------------------------- >Comment By: Peter Åstrand (astrand) Date: 2007-01-13 23:14 Message: Logged In: YES user_id=344921 Originator: NO The first thing to check is if the subprocesses have different sets up file descriptors when you launch them from Python and C, respectively. On Linux, do /proc/$thepid/fd in both cases and compare the output. Does it matter if you use close_fds=1? ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:52 Message: Logged In: YES user_id=310088 Originator: YES File Added: extract_frame.py.output2 ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:52 Message: Logged In: YES user_id=310088 Originator: YES File Added: extract_frame.py.output ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:51 Message: Logged In: YES user_id=310088 Originator: YES File Added: extract_frame.output2 ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:50 Message: Logged In: YES user_id=310088 Originator: YES File Added: extract_frame.output ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:49 Message: Logged In: YES user_id=310088 Originator: YES File Added: extract_frame.py ---------------------------------------------------------------------- Comment By: Florent Rougon (frougon) Date: 2007-01-13 16:49 Message: Logged In: YES user_id=310088 Originator: YES File Added: Makefile ---------------------------------------------------------------------- You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1634739&group_id=5470 _______________________________________________ Python-bugs-list mailing list Unsubscribe: http://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com
