Given the grand total of 11 open() system calls, I'm guessing you used strace without the -f and -F options (noting that ISTR 4.2.1 reverts to use of vfork)?
BTW timings on linux are more elegantly handled by prefixing the "time" builtin. Wallclock-only can be gotten by forcing use of /usr/bin/time: % type -a time time is a shell keyword time is /usr/bin/time % time sleep 3 real 0m3.022s user 0m0.001s sys 0m0.001s % \time -f %E sleep 3 0:03.00 David On Fri, Jul 22, 2016 at 2:19 AM, Gardell, Steven <sgard...@sonusnet.com> wrote: > Thanks for the suggestions. I have captured a bunch more data and hence > the delay. First I have started by reproducing the behavior with 4.2.1: > > > > gmake realclean >& cleanlog.txt > > /usr/bin/gmake-4.2.1 -j32 -Otarget dirsparallel=all release >& > gmake421dpa32.log; date > > Tue Jul 19 11:24:47 EDT 2016 > > Tue Jul 19 20:43:17 EDT 2016 > > gmake realclean >& cleanlog.txt > > /usr/bin/gmake-4.2.1 -j32 -Onone dirsparallel=all release > & > gmake421dpn32.log ; date > > Tue Jul 19 21:01:48 EDT 2016 > > Tue Jul 19 22:05:40 EDT 2016 > > > > Essentially the same as 4.1. This –Otarget run is not just “a little > slower,” it is pathologically slow. The 9 hour build time is slower than if > I had run the > > build with no parallelization whatsoever. (The –Onone time is a bit faster > than what I see doing parallelization at just the leaf level) > > > > Our build is a relatively straight-forward “choreographed” build as > followed: > > > > Top-Level Makefile > > Makefile.libs – This is a list of directories containing C++ > code getting built into different relocatable libraries (one per dir) > > (sub-directory Makefiles) > > Mikefile.bins – This is a list of directories that link > executables > > (sub-directory Makefiles) > > > > There are O(120) libraries to build, each of which ranges from 10-50 > objects. There are about 30 executables to build. What “dirsparallel=all” > does is to turn on parallel make for Makefile.libs, Makefile.dirs, etc. The > actual build is more complicated, having codegen, unit test, lint, and > packaging activities, but it follows this simple model. > > > > The defining characteristic here is a wide fan-out. There are a large > number of relatively simple and brief makefiles. There will therefore be a > few “middle management” makefiles that are waiting on children to complete > (I imagine each of these occupies a make job??). > > > > I have confirmed that my count of “g++” invocations is exactly the same > for the two runs (4403) > > > > The TMPDIR variable was not set. I set it to /tmp to insure that it is on > a physical device. (The build and our home directories are NFS mounted) The > total elapsed time for the “-Otarget” run was then 6 hours. This is enough > of a reduction to be a little suspicious, but not much more. > > > > I ran with strace for both the “none” case and the “target” case. The > summaries are attached. Unfortunately, I don’t think there is a smoking gun > here. > > > > I have also run the “-Otrace” case at a few different job-levels: > > > > j8 – 6:34 > > j32 – 6:00 > > j256 – 9:49 > > > > *From:* David Boyce [mailto:david.s.bo...@gmail.com] > *Sent:* Sunday, July 17, 2016 5:03 PM > *To:* Gardell, Steven <sgard...@sonusnet.com> > *Cc:* psm...@gnu.org; Bug-make@gnu.org > > *Subject:* Re: Parallel builds across makefiles > > > > A couple of suggestions: > > > > 1. Check your value of TMPDIR if any. All -O is doing is redirecting > output into a temp file and dumping it later. Effectively it turns command > "foo" into "foo > $TMPDIR/blah; cat $TMPDIR/blah; unlink $TMPDIR/blah". > This is why it seems almost impossible for it to slow things down > appreciably, and a slow temp dir device might be one explanation. Along > similar lines you could try "TMPDIR=/tmp make ..." > > > > 2. Try strace. It has a mode which will timestamp each system call and > another which prints a table of system calls used and how much time it > took. One of these will probably be instructive, especially when compared > with the same without -O. > > > > David > > > > On Sun, Jul 17, 2016 at 12:22 PM, Gardell, Steven <sgard...@sonusnet.com> > wrote: > > No I have not gotten to 4.2.1 yet. > > I have experimented using j values ranging from 16 to 64. The majority of > the testing is with -Otarget. But I have tried all of them. > > -----Original Message----- > From: Paul Smith [mailto:psm...@gnu.org] > Sent: Sunday, July 17, 2016 3:14 PM > To: Gardell, Steven <sgard...@sonusnet.com>; Bug-make@gnu.org > Subject: Re: Parallel builds across makefiles > > On Sun, 2016-07-17 at 15:48 +0000, Gardell, Steven wrote: > > OK. Thanks! I will try the latest version. > > > > FWIW, I am measuring is total wall clock time to complete the build. > > (date; gmake... ; date) This goes up substantially with all sync modes > > other than "none" if gmake has parallel invocations of sub-makes going > > (e.g. "gmake -f SomeOtherMakefile"). When I am only parallelizing > > individual makefiles (with ACE, these tend to be simple lists of files > > to compile), then the behavior is as promised by the documentation. > > Assuming you determine the behavior exists even in version 4.2.1, please > provide more details. What level of -j are you using? Which sync mode are > you using? Do you get the same behavior even with lower levels of -j, if > yours is very large? > > _______________________________________________ > Bug-make mailing list > Bug-make@gnu.org > https://lists.gnu.org/mailman/listinfo/bug-make > > >
_______________________________________________ Bug-make mailing list Bug-make@gnu.org https://lists.gnu.org/mailman/listinfo/bug-make
