I ran with -cf. By my read there are millions of open() calls here: gmake-4.2.1: *** [Makefile:333: release] Error 1 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 93.92 48988.895003 281029 174320 42047 wait4 3.56 1857.549713 8133 228409 47431 futex 1.12 582.114172 10 59230554 48886748 stat 0.81 421.206442 11 37319045 29591972 open 0.40 209.945060 3 71120290 3458259 lstat 0.06 33.636522 2 13616492 4796 read 0.02 11.818771 1 8065605 14388 close
And: % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 93.82 53268.050950 302081 176337 41624 wait4 3.18 1805.057765 7853 229844 48664 futex 1.06 599.730842 8 71119946 3458260 lstat 0.94 532.243350 14 37295656 29590966 open 0.73 416.897838 7 59083695 48774860 stat 0.09 50.603194 4 13780850 4946 read 0.04 21.309529 3 8034030 14388 close I am happy to run with any other settings that anyone might suggest since I have the environment that is demonstrating the behavior. From: David Boyce [mailto:david.s.bo...@gmail.com] Sent: Monday, July 25, 2016 11:54 AM To: Gardell, Steven <sgard...@sonusnet.com> Cc: psm...@gnu.org; Bug-make@gnu.org Subject: Re: Parallel builds across makefiles 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<mailto: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<mailto:david.s.bo...@gmail.com>] Sent: Sunday, July 17, 2016 5:03 PM To: Gardell, Steven <sgard...@sonusnet.com<mailto:sgard...@sonusnet.com>> Cc: psm...@gnu.org<mailto:psm...@gnu.org>; Bug-make@gnu.org<mailto: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<mailto: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<mailto:psm...@gnu.org>] Sent: Sunday, July 17, 2016 3:14 PM To: Gardell, Steven <sgard...@sonusnet.com<mailto:sgard...@sonusnet.com>>; Bug-make@gnu.org<mailto: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<mailto: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
