bugmake - Bugs: bug #44555, "make" fails to use...

 
 

bug #44555: "make" fails to use parallelism

Submitted by:  None
Submitted on:  Mon 16 Mar 2015 07:33:02 PM UTC  
 
Severity:  3 - Normal Item Group:  Bug
Status:  Fixed Privacy:  Public
Assigned to:  Paul D. Smith <psmith> Open/Closed:  Closed
Component Version:  4.2 Operating System:  POSIX-Based
Fixed Release:  4.2 Triage Status:  Medium Effort

Add a New Comment (Rich Markup)
   

You are not logged in

Please log in, so followups can be emailed to you.

 

( Jump to the original submission)

Sun 13 Mar 2016 06:27:04 AM UTC, comment #15:

vfork fix pushed to git.  Thanks for the report.

Paul D. Smith <psmith>
Project AdministratorIn charge of this item.
Thu 13 Aug 2015 04:35:20 AM UTC, comment #14:

This has become off-topic for the current bug report and anyway it was discussed exhaustively back then; details are in mail archives. But in any case, whether you agree or disagree after reading, it's water well past the bridge by now.

Anonymous
Thu 13 Aug 2015 04:11:02 AM UTC, comment #13:

"The new feature allowing for pattern-rules...added a lot of complexity and had some performance impacts"

Why then was it pushed, given that it changed a convention of file-order vs. best-fit order?

Anonymous
Wed 12 Aug 2015 11:30:45 AM UTC, comment #12:

Bisecting between 3.81 and current Git HEAD will not be very productive.  3.81 was released almost 10 years ago.  There have been many performance regressions, and many performance improvements over that time.  It's likely that some of the regressions are related to new features, and so it's not possible to just remove those changes (I know, for example, that the new feature allowing for pattern rules to match most specifically rather than "first rule matches" added a lot of complexity and had some performance impacts, especially if you have lots of pattern rules--I had an idea just the other day that might simplify this but I'd need to play with it).

Rather than spend time bisecting it's much, much better to spend time looking at the current behavior of Git HEAD with perf tools and discover what is slow in your build environment.  Reports like that can, hopefully, be addressed.

Paul D. Smith <psmith>
Project AdministratorIn charge of this item.
Wed 12 Aug 2015 04:51:59 AM UTC, comment #11:

Following up on Jeff's comment, there are multiple performance regressions after make 3.81. The fork/vfork is the most significant one, but not the only one. These perf regressions are serious problems and upgrading from 3.81 would still cost a small fortune in build farm capacity.

I will attempt to bisect the git tree and find the culprits for rest of the perf problems, but I encourage also someone more familiar with the code to take a closer look.

Atte Peltomaki <koston>
Tue 11 Aug 2015 05:01:23 PM UTC, comment #10:

OK, I'll put it back for the next release.

Paul D. Smith <psmith>
Project AdministratorIn charge of this item.
Tue 11 Aug 2015 04:15:16 PM UTC, comment #9:

While it doesn't account for the full 2.5+ minutes difference, "strace -c"'s summary of syscalls shows that vfork() in a good version of make is less than .02s, while fork() (show as clone()) in a bad version is about 75s (547us/call), a difference which becomes worse as the memory size of make increases (this is why having a lot of dependency information, as in my generated makefile, is relevant).  Furthermore, the total number of clone() syscalls is higher, I believe because more of them are interrupted by SIGCHLD.

Slow trace:
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 99.97   78.092824         547    142754     47753 clone
  0.02    0.018415           0    105026           wait4
  0.01    0.004928           0    200005           rt_sigprocmask

Fast trace:
 74.59    0.013843           0    100334      5333 vfork
  7.51    0.001394           0    200005           rt_sigprocmask
  7.19    0.001335           0    110296           wait4

Jeff Epler <jepler>
Tue 11 Aug 2015 09:48:34 AM UTC, comment #8:

I see absolutely the same results as noted.

And there is NO DOUBT that the fork/vfork is to blame!

I tested today on any single commit since 3.75(over 1000 versions!), and every single one of those versions up to 94735f0ad7f67c56afa1513381c73e8f62cd44fc (3.82+156, i.e. the 156th commit after 3.82) had almost identical results, where at that version it suddenly bloated to those tedious time-frames noted by others.

To summarize: bring back vfork()!

Anonymous
Mon 10 Aug 2015 01:08:25 PM UTC, comment #7:

(I am the original bug submitter and poster of the early anonymous comments)

Is there additional information I can furnish to help in the resolution of this bug?

Were you able to reproduce the problem with the script back in comment #2?

Jeff Epler <jepler>
Thu 02 Jul 2015 04:12:37 PM UTC, comment #6:

I can confirm the bug report and that reverting 94735f0 solves the problem. For us this is a very critical problem, since build times are increased so drastically.

Atte Peltomaki <koston>
Mon 30 Mar 2015 03:17:34 PM UTC, comment #5:

Well, I don't want to move back to vfork() "just because it works", without understanding the situation better.  The reasons we switched away from vfork() (portability and correctness) are still issues.  I will need to investigate this more deeply to decide what the right way forward is before committing a fix.

Paul D. Smith <psmith>
Project AdministratorIn charge of this item.
Mon 30 Mar 2015 02:41:21 PM UTC, comment #4:

We've now deployed our patched GNU make with the patch from comment #2 and the results are positive--the performance regression seen in GNU make 4.x is fixed.

Is there any additional information I can provide to allow you to incorporate this fix in GNU make, or to help you find an alternative fix that is more acceptable to you?

On each system I've tested, the script in comment #2 clearly demonstrates the performance regression, even if I don't have any understanding of why it causes a performance regression.

Anonymous
Tue 17 Mar 2015 08:41:52 PM UTC, comment #3:

To reply to a few points I didn't specifically address in my last comment:

  • make isn't actually dropping into single-job mode, as can be seen from "make --debug=j", but for some reason it's having trouble starting as many jobs as requested.
  • no, -O/--output-sync is not required to observe the problem
  • I didn't spot anything that looked relevant in --trace
  • like the Makefile generated by mkmk.sh, our build is nonrecursive.

Having no make step that takes appreciable CPU time is a lot like our case, where frequently ccache hit rates exceed 95% (multiple developers share ccache via nfs and work with substantially-similar source trees)

Anonymous
Tue 17 Mar 2015 07:56:06 PM UTC, comment #2:

I share your surprise that fork vs vfork could possibly have an important performance impact, but
*it's what git bisect told me
*testing immediately before the commit, I did not encounter the problem
*testing at the tip of master with the commit reverted, I did not encounter the problem

I believe I have created a standalone test which captures what is going on for us.

"mkmk.sh" creates a lot of dummy .c and .h files and also prints a Makefile on its stdout.  Like our software build systems, there are a lot of object files all with a lot of dependencies. (I had originally written some paragraphs describing our build system, but a runnable Makefile has got to be worth a thousand words of description)

With make.git at 4.1-11-ga80a8b8, "make -j10" typically takes about 3 minutes.  With the attached patch applied, "make -j10" typically takes about 11s.  If the only time consumed was by 'sleep .01', at 10x parallelism, it would ideally take 5s.  Fully serialized, it would take 500s.

Increasing NI/NJ (number of sources and number of includes) and the number of repetitions of '@mkdir .' all seem to make the problem worse.

$ mkmk.sh > Makefile
$ rm -f *.o default
$ time make.bad -j12 ;# 4.1-11-ga80a8b8
real        2m58.167s
user        0m2.536s
sys        2m55.375s
$ rm -f *.o default
$ time make.good -j12 ;# patch applied
real        0m10.869s
user        0m2.120s
sys        0m1.564s
$ rm -f *.o default
$ time /usr/bin/make -j10 ;# debian make 3.81
real        0m10.727s
user        0m2.244s
sys        0m1.404s

I agree we're getting into weird territory here.  It could be libc or kernel specific.  As I mentioned initially, we're on Debian 7.8.

Linux parrot 3.2.0-4-amd64 #1 SMP Debian 3.2.57-3 x86_64 GNU/Linux
GNU C Library (Debian EGLIBC 2.13-38+deb7u8) stable release version 2.13, by Roland McGrath et al.

I also tested on a digitalocean.com virtual server instance with 12 threads and Ubuntu 14.10 (linux 3.16, glibc 2.19) and got 36s vs 6m19 wall time (also at -j10 parallelism)

I also tested on an atlantic.net virtual server instance with 1 thread and Debian Testing (linux 3.18, libc 2.19) and got 1m16 vs 4m52 wall time (also at -j10 parallelism)

So whatever's going on, it affects a range of libc and kernel versions too.  (however, I did just copy the make.good and make.bad binaries, so it could still be something that is specific to the debian 7 build environment)

(file #33381, file #33382)

Anonymous
Mon 16 Mar 2015 08:44:59 PM UTC, comment #1:

How do you know that it falls back to one job at a time?  Does make actually print out the message it usually does when it gives up on parallelism?

Or, do you just observe the build taking a long time and watch the commands being invoked, and see that they are running one at a time?  Or, are you going by output only?

Is your build environment using a recursive make model, or does it use only one invocation of make?

If you run make with the --trace flag, does it show anything different between the "good" and "bad" runs?

I assume you are not enabling the new output sync mode when you invoke make?

I find it very bizarre that the change from fork() to vfork() would cause this behavior... the commit you mention literally does nothing but switch from vfork() to fork() (and the associated config changes).  In general it should never be the case that this change causes problems (it can cause problems to go from fork() to vfork(), of course, depending on what you do after you fork).

Paul D. Smith <psmith>
Project AdministratorIn charge of this item.
Mon 16 Mar 2015 07:33:02 PM UTC, original submission:

I maintain the build system for a commercial software product.  Developers build the system on Debian 7

We recently upgraded from 3.81 to 4.1.  Unfortunately, this version of make frequently fails to use the requested level of parallelism, falling back to one job at a time.

Unfortunately, I haven't been able to distill this down to a test case that runs independent of our development environment, so I have no testcase to submit.  But what I know is:

  • the project has about 6000 object files
  • developer desktops are 6 cores / 12 threads
  • we request -j15 -l26 parallelism
  • thanks to make parallelism + ccache, a full build is <2minutes
    • but is >10 minutes when this bug bites
  • we consistently reproduce the problem by:

        git checkout branch1; make clean; make
        git checkout branch2; make

  • it's important not to clean before the second build
  • some headers have been removed in branch2 compared to branch1; we have a rule 'include/%.h:; echo $@: missing or removed' so that the build proceeds in this case (we do not use gcc -MP because we found that parsing all those additional lines had a measurable impact on the time of a do-nothing make)
  • we use gcc-generated dependency information
  • we autogenerate some header files by having the main Makefile depend on those header files
  • The problem does not occur if this one commit is reverted:

        94735f0 Remove use of vfork().

Anonymous

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #33381:  mkmk.sh added by None (826B - application/x-shellscript)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by jepler (Posted a comment)
  • -email is unavailable- added by koston (Posted a comment)
  • -email is unavailable- added by psmith (Posted a comment)
  •  

    Do you think this task is very important?
    If so, you can add your encouragement to it.
    This task has 0 encouragements so far.

    Only logged-in users can vote.

     

     

     

    Follow 7 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2016-03-13 psmith Assigned toNone => psmith
        Open/ClosedOpen => Closed
        Fixed ReleaseNone => 4.2
        Triage StatusNone => Medium Effort
    2016-03-13 psmith StatusNone => Fixed
    2015-03-17 None Attached File- => Added mkmk.sh, #33381
        Attached File- => Added 0001-Fix-paralellism-by-reverting-to-use-of-vfork.patch, #33382

    Back to the top


    Powered by Savane 3.4