|
From: | David Boyce |
Subject: | Re: Parallel builds across makefiles |
Date: | Mon, 25 Jul 2016 13:43:12 -0700 |
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:address@hidden]
Sent: Monday, July 25, 2016 11:54 AM
To: Gardell, Steven <address@hidden>
Cc: address@hidden; address@hidden
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 <address@hidden> 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:address@hidden]
Sent: Sunday, July 17, 2016 5:03 PM
To: Gardell, Steven <address@hidden>
Cc: address@hidden; address@hidden
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 <address@hidden> 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:address@hidden]
Sent: Sunday, July 17, 2016 3:14 PM
To: Gardell, Steven <address@hidden>; address@hidden
Subject: Re: Parallel builds across makefilesOn 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
address@hidden
https://lists.gnu.org/mailman/listinfo/bug-make
[Prev in Thread] | Current Thread | [Next in Thread] |