Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
Martin Aspeli wrote at 2008-7-4 00:56 +0100: > >Benji York wrote: > >Parallisation can offer huge (!) speed increases, but it can also be >hard to debug tests. I'd be tempted to let single threaded by the >default, safe choice, and let people opt into parallisation only when >they know what they are doing. Most test runs are quite quick anyway. +1 > ... >Oh, and please don't get rid of any tear-down. +1 -- Dieter ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
On Fri, Jul 4, 2008 at 4:49 PM, Marius Gedminas <[EMAIL PROTECTED]> wrote: > Here are the results: > >time# tests >realusersystem reported > old test runner 3m16.033s 2m44.670s 0m2.832s6895 > zope.testing trunk 2m27.816s 1m58.971s 0m2.196s6890 > new test runner -j0 2m37.322s 2m5.808s0m2.944s6890 > new test runner -j1 2m32.249s 1m58.847s 0m2.652s6890 > new test runner -j2 2m22.287s 3m51.214s 0m13.457s 584 > new test runner -j3 2m20.560s 3m46.990s 0m12.613s 584 > new test runner -j4 2m30.026s 3m43.198s 0m13.241s 584 I figured out why the total test count went down so much for -j2: the branch inherited a bug from the trunk that skips the unit test "layer" if it is run in a subprocess. I'll take a crack at fixing that. -- Benji York Senior Software Engineer Zope Corporation ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
On Fri, Jul 4, 2008 at 6:43 PM, Marius Gedminas <[EMAIL PROTECTED]> wrote: > On Fri, Jul 04, 2008 at 05:44:12PM -0400, Benji York wrote: >> There's no appreciable bookkeeping for the parallelization, so I don't >> know where the CPU time is going. > > Every layer is spawned in a separate subprocess, right? That means 36 > new Python processes with the associated startup cost, plus the module > import cost, plus some test result marshalling through plain-text Unix > pipes. Two seconds of startup cost per subprocess would nicely account > for the one extra minute of user time if there are over 30 subprocesses. The number of subprocesses is the same as for the trunk, the only change is that they can be spawned in parallel. Wait! The Zope 3 test layers can all be torn down! Therefore there aren't *any* subprocesses spawned normally. Ok, that makes more sense. (time passes) OK, I did a check out of the Zope 3 trunk and was able to duplicate your results. (And wow, the trunk seems to be in bad shape -- lots of tests failing. I guess it's fallen into disrepair since being broken out into subprojects.) > My crude measurements (time ./test.py --list-tests > /dev/null) indicate > the time needed to import everything is closer to 4 seconds, but that's > importing everything -- importing just the things needed for a single > layer may reduce that to two seconds on average. A possible enhancement would be to reuse subprocesses if they are asked to run layers that can be torn down. That way for a very tear-down friendly set of tests like Zope 3's, the minimum number of processes would be started. We could also use fork to eliminate some of the start-up cost, but that's not real attractive, being un-Windows-friendly. -- Benji York Senior Software Engineer Zope Corporation ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
On Fri, Jul 04, 2008 at 05:44:12PM -0400, Benji York wrote: > On Fri, Jul 4, 2008 at 4:49 PM, Marius Gedminas <[EMAIL PROTECTED]> wrote: > > I tried this in a Zope 3.4 checkout I had handy on a Core 2 Duo machine > > (1.8 GHz, running 64-bit Ubuntu Hardy). One test module could not be > > loaded, which explains the slightly lower number of tests reported: > > > Here are the results: > > > >time# tests > >realusersystem reported > > old test runner 3m16.033s 2m44.670s 0m2.832s6895 > > zope.testing trunk 2m27.816s 1m58.971s 0m2.196s6890 > > new test runner -j0 2m37.322s 2m5.808s0m2.944s6890 > > new test runner -j1 2m32.249s 1m58.847s 0m2.652s6890 > > new test runner -j2 2m22.287s 3m51.214s 0m13.457s 584 > > new test runner -j3 2m20.560s 3m46.990s 0m12.613s 584 > > new test runner -j4 2m30.026s 3m43.198s 0m13.241s 584 > > I'm really curious why you didn't see more improvement. I wish one of the system-wide profilers (oprofile, sysprof) had support for extracting Python tracebacks out of C-level stack frames... > > Zope 3 appears to be composed of a multitude of small tests. If my > > numbers are correct, the advantage of using both CPU cores is almost > > completely negated by the extra bookkeeping that the test runner has to > > do. > > There's no appreciable bookkeeping for the parallelization, so I don't > know where the CPU time is going. Every layer is spawned in a separate subprocess, right? That means 36 new Python processes with the associated startup cost, plus the module import cost, plus some test result marshalling through plain-text Unix pipes. Two seconds of startup cost per subprocess would nicely account for the one extra minute of user time if there are over 30 subprocesses. My crude measurements (time ./test.py --list-tests > /dev/null) indicate the time needed to import everything is closer to 4 seconds, but that's importing everything -- importing just the things needed for a single layer may reduce that to two seconds on average. > > "Test-module import failures" is printed several times. test -j4 > > printed that message 37 times! test -j1 only did it once. -j2 and -j3 > > also did that a bit often (once per layer?) > > Interesting. I'll investigate. It corroborates my theory that each subprocess imports all the test modules. Marius Gedminas -- H.323 has much in common with other ITU-T standards - it features a complex binary wire protocol, a nightmarish implementation, and a bulk that can be used to fell medium-to-large predatory animals. -- Anthony Baxter signature.asc Description: Digital signature ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
On Fri, Jul 4, 2008 at 4:49 PM, Marius Gedminas <[EMAIL PROTECTED]> wrote: > I tried this in a Zope 3.4 checkout I had handy on a Core 2 Duo machine > (1.8 GHz, running 64-bit Ubuntu Hardy). One test module could not be > loaded, which explains the slightly lower number of tests reported: > Here are the results: > >time# tests >realusersystem reported > old test runner 3m16.033s 2m44.670s 0m2.832s6895 > zope.testing trunk 2m27.816s 1m58.971s 0m2.196s6890 > new test runner -j0 2m37.322s 2m5.808s0m2.944s6890 > new test runner -j1 2m32.249s 1m58.847s 0m2.652s6890 > new test runner -j2 2m22.287s 3m51.214s 0m13.457s 584 > new test runner -j3 2m20.560s 3m46.990s 0m12.613s 584 > new test runner -j4 2m30.026s 3m43.198s 0m13.241s 584 I'm really curious why you didn't see more improvement. > At the end of the experiment I discovered that I have CPU frequency > scaling enabled. It only scales down to 1.6 GHz and quickly jumps back > up to 1.87 GHz. > > I find the speedup by switching to a modern test runner somewhat > unexpected. Can those 5 missing tests really account for 45 seconds? > > Zope 3 appears to be composed of a multitude of small tests. If my > numbers are correct, the advantage of using both CPU cores is almost > completely negated by the extra bookkeeping that the test runner has to > do. There's no appreciable bookkeeping for the parallelization, so I don't know where the CPU time is going. > Visual ogling of my CPU usage applet shows that -j0/1 use only one > CPU, while -j2 and above use only one CPU for the first test layer > (zope.app.apidoc.testing.APIDocLayer) and then use both CPUs for the > rest. Bug? Long story short: it made the changes to the code much less invasive to do that way. > The total number of tests is misreported when you have -jN with N > 1. I haven't seen that symptom, but I'll try to reproduce it by running the 3.4 tests. > "Test-module import failures" is printed several times. test -j4 > printed that message 37 times! test -j1 only did it once. -j2 and -j3 > also did that a bit often (once per layer?) Interesting. I'll investigate. > As far as I can understand, the granularity of the test distribution to > CPUs is a test layer? Right. > If so, that's rather unfortunate for my application, which has only > two layers (unit and functional). Especially given the quirk that the > first test layer is run on one CPU while the other idles. If the need is great enough, you can always introduce an arbitrary number of layers. Also, once this code is working properly, I (or someone else) might look into changing the granularity to the level of individual tests. -- Benji York Senior Software Engineer Zope Corporation ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Re: Test runner: layers, subprocesses, and tear down
On Fri, Jul 04, 2008 at 11:50:34AM -0400, Benji York wrote: > On Thu, Jul 3, 2008 at 5:22 PM, Benji York <[EMAIL PROTECTED]> wrote: > > I'm working on making the zope.testing test runner run tests in > > parallelized subprocesses. The option will likely be spelled -j N, > > where N is the maximum number of processes. > > The branch > (svn+ssh://svn.zope.org/repos/main/zope.testing/branches/benji-parallelize-subprocesses) > is feature complete. I basically did a very simple transformation that > resulted in the runner spawning subprocesses in threads, several at a > time, instead of spawning them serially. The patch is less than 250 > lines. Any critiques of the changes would be appreciated. I'll try to take a look. > I found that to eliminate nearly all CPU idle time, I had to use -j4 on > my two core laptop. > > For a particular test corpus on a 4 core machine -j1 (the default) takes > about 7 minutes -j6 takes about 2 minutes 20 seconds. I tried this in a Zope 3.4 checkout I had handy on a Core 2 Duo machine (1.8 GHz, running 64-bit Ubuntu Hardy). One test module could not be loaded, which explains the slightly lower number of tests reported: Test-module import failures: Module: zope.app.twisted.ftp.tests.test_zopetrial Traceback (most recent call last): File "/home/mg/src/ivija-zope-3.4/Zope3.4/src/zope/app/twisted/ftp/tests/test_zopetrial.py", line 37, in ? orig_configure_logging = zope.testing.testrunner.configure_logging AttributeError: 'module' object has no attribute 'configure_logging' Here are the results: time# tests realusersystem reported old test runner 3m16.033s 2m44.670s 0m2.832s6895 zope.testing trunk 2m27.816s 1m58.971s 0m2.196s6890 new test runner -j0 2m37.322s 2m5.808s0m2.944s6890 new test runner -j1 2m32.249s 1m58.847s 0m2.652s6890 new test runner -j2 2m22.287s 3m51.214s 0m13.457s 584 new test runner -j3 2m20.560s 3m46.990s 0m12.613s 584 new test runner -j4 2m30.026s 3m43.198s 0m13.241s 584 At the end of the experiment I discovered that I have CPU frequency scaling enabled. It only scales down to 1.6 GHz and quickly jumps back up to 1.87 GHz. I find the speedup by switching to a modern test runner somewhat unexpected. Can those 5 missing tests really account for 45 seconds? Zope 3 appears to be composed of a multitude of small tests. If my numbers are correct, the advantage of using both CPU cores is almost completely negated by the extra bookkeeping that the test runner has to do. Visual ogling of my CPU usage applet shows that -j0/1 use only one CPU, while -j2 and above use only one CPU for the first test layer (zope.app.apidoc.testing.APIDocLayer) and then use both CPUs for the rest. Bug? The total number of tests is misreported when you have -jN with N > 1. "Test-module import failures" is printed several times. test -j4 printed that message 37 times! test -j1 only did it once. -j2 and -j3 also did that a bit often (once per layer?) As far as I can understand, the granularity of the test distribution to CPUs is a test layer? If so, that's rather unfortunate for my application, which has only two layers (unit and functional). Especially given the quirk that the first test layer is run on one CPU while the other idles. Marius Gedminas P.S. Zope 3 is such a sweet little thing! All the tests finish in 3 minutes! Heaven. -- The planning fallacy is that people think they can plan, ha ha. -- Eliezer Yudkowsky, http://www.overcomingbias.com/2007/09/planning-fallac.html signature.asc Description: Digital signature ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
