rare gmake jobserver hangs, lost SIGCHLD?

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

rare gmake jobserver hangs, lost SIGCHLD?

Don Lewis-5
I have ALLOW_MAKE_JOBS=yes in poudriere.conf on my package build machine
so that large ports like chromium will build more quickly at the end of
the poudriere run when they are the last ports to build.  A downside of
this is that the load average can get pretty high (in the 40's) earlier
in the poudriere run, but I've got plenty of RAM and swap so that
doesn't seem to cause any obvious problems.

My package build box has an AMD FX-8320E Eight-Core Processor, but I'm
breaking in a Ryzen 7 1700X replacement.  Both run 12.0-CURRENT, which
is updated on an irregular basis every month or so.  I generally build a
set of ~1700 ports for three different jails, and the average poudriere
run probably builds about 500 ports on average.

Starting in December 2016, I've seen three build runaway failures on
different ports.  The first two are on my older machine, the last on the
Ryzen.  The one thing they all have in common is that there are one or
more gmake processes in a wait state and they have a number of zombified
child processes:

December 2016 - 10-STABLE jail:
USER   PID %CPU %MEM   VSZ  RSS TT  STAT STARTED    TIME COMMAND
root 76087  0.0  0.0  9132 1336  0  I+J   8:51AM 0:00.04 /usr/bin/make -C /usr/p
orts/multimedia/gstreamer-plugins-good build
root 76113  0.0  0.0 14680 1896  0  I+J   8:51AM 0:00.01 - gmake -f Makefile -j8
 DESTDIR=/wrkdirs/usr/ports/multimedia/gstreamer-plugins-good/work/stage all
root 76129  0.0  0.0 14680 1916  0  I+J   8:51AM 0:00.01 |-- gmake -C videofilte
r
root 76148  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.59 | `-- <defunct>
root 76156  0.0  0.0 14680 1968  0  I+J   8:51AM 0:00.01 |-- gmake -C audiofx
root 76625  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.34 | `-- <defunct>
root 76164  0.0  0.0 14680 1912  0  I+J   8:51AM 0:00.01 |-- gmake -C audioparse
rs
root 78664  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.43 | `-- <defunct>
root 77796  0.0  0.0 14680 1948  0  I+J   8:51AM 0:00.01 |-- gmake -C debugutils
root 78663  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.00 | `-- <defunct>
root 78193  0.0  0.0 14680 1920  0  I+J   8:51AM 0:00.01 |-- gmake -C deinterlac
e
root 78232  0.0  0.0 14680 1952  0  I+J   8:51AM 0:00.01 | `-- gmake all-am
root 78566  0.0  0.0     0    0  0  Z+J   8:51AM 0:01.45 |   `-- <defunct>
root 78681  0.0  0.0 14680 1940  0  I+J   8:51AM 0:00.01 |-- gmake -C effectv
root 78819  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.28 | `-- <defunct>
root 78830  0.0  0.0 14680 1916  0  I+J   8:51AM 0:00.01 |-- gmake -C equalizer
root 78834  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.43 | `-- <defunct>
root 78952  0.0  0.0 14680 1912  0  I+J   8:51AM 0:00.01 `-- gmake -C flv
root 79075  0.0  0.0     0    0  0  Z+J   8:51AM 0:00.00   `-- <defunct>

September 2017 - 12-CURRENT jail:
USER   PID %CPU %MEM   VSZ   RSS TT  STAT STARTED    TIME COMMAND
root  8279  0.0  0.0 10832     0  1  IW+J -       0:00.00 /usr/bin/make -C /usr/
ports/editors/openoffice-devel build
root  8550  0.0  0.0 24852     0  1  IW+J -       0:00.00 - perl -S /wrkdirs/usr
/ports/editors/openoffice-devel/work/aoo-4.2.0/main/solenv/bin/build.pl --all -P
2 -- -P4
root 64577  0.0  0.0 24852     0  1  IW+J -       0:00.00 `-- perl -S /wrkdirs/u
sr/ports/editors/openoffice-devel/work/aoo-4.2.0/main/solenv/bin/build.pl --all
-P2 -- -P4
root 64578  0.0  0.0 11700     0  1  IW+J -       0:00.00   `-- dmake -P4
root 64583  0.0  0.0 12688     0  1  IW+J -       0:00.00     `-- /usr/local/bin
/bash -c cd .. && gmake  -r -j4   && gmake  -r deliverlog
root 64584  0.0  0.1 53556 44532  1  I+J  20:32   0:29.23       `-- gmake -r -j4
root 30217  0.0  0.0     0     0  1  Z+J  20:49   0:00.01         |-- <defunct>
root 30220  0.0  0.0     0     0  1  Z+J  20:49   0:00.01         |-- <defunct>
root 30234  0.0  0.0     0     0  1  Z+J  20:49   0:00.01         |-- <defunct>
root 30236  0.0  0.0     0     0  1  Z+J  20:49   0:00.01         `-- <defunct>


USER     PID %CPU %MEM   VSZ   RSS TT  STAT STARTED    TIME COMMAND
nobody 43355  0.0  0.0 10500  1596  1  I+J  11:09   0:00.05 /usr/bin/make -C /usr/ports/lang/rust build
nobody 43444  0.0  0.1 46368 36944  1  I+J  11:09   0:07.20 - /usr/local/bin/python2.7 /wrkdirs/usr/ports/lang/rust/work/rustc-1.23.0-src/x.py build --verbose --config ./config.toml --jobs 7
nobody 71768  0.0  0.0 25436 11536  1  I+J  11:10   0:00.21 `-- /wrkdirs/usr/ports/lang/rust/work/rustc-1.23.0-src/build/bootstrap/debug/bootstrap build --verbose --config ./config.toml --jobs 7
nobody  9694  0.0  0.0 23260 13172  1  I+J  11:14   0:00.01   `-- cmake --build . --target install --config Release -- -j 7
nobody  9746  0.0  0.0 11976  2412  1  I+J  11:14   0:00.01     `-- /usr/local/bin/gmake -j 7 install
nobody  9784  0.0  0.0 12624  3292  1  I+J  11:14   0:00.08       `-- /usr/local/bin/gmake -f CMakeFiles/Makefile2 all
nobody  9539  0.0  0.0 11976  2404  1  I+J  11:16   0:00.02         |-- /usr/local/bin/gmake -f lib/DebugInfo/CodeView/CMakeFiles/LLVMDebugInfoCodeView.dir/build.make lib/DebugInfo/CodeView/CMakeFiles/LLVMDebugInfoCodeView.dir/build
nobody 10364  0.0  0.0     0     0  1  Z+J  11:17   0:02.12         | `-- <defunct>
nobody 10119  0.0  0.0 11908  2264  1  I+J  11:14   0:00.01         |-- /usr/local/bin/gmake -f lib/TableGen/CMakeFiles/LLVMTableGen.dir/build.make lib/TableGen/CMakeFiles/LLVMTableGen.dir/build
nobody 10231  0.0  0.0     0     0  1  Z+J  11:14   0:00.95         | `-- <defunct>
nobody 10420  0.0  0.0 12020  2524  1  I+J  11:14   0:00.02         |-- /usr/local/bin/gmake -f lib/MC/MCParser/CMakeFiles/LLVMMCParser.dir/build.make lib/MC/MCParser/CMakeFiles/LLVMMCParser.dir/build
nobody  9353  0.0  0.0     0     0  1  Z+J  11:16   0:00.86         | `-- <defunct>
nobody 10667  0.0  0.0 12476  2800  1  I+J  11:14   0:00.03         |-- /usr/local/bin/gmake -f lib/Support/CMakeFiles/LLVMSupport.dir/build.make lib/Support/CMakeFiles/LLVMSupport.dir/build
nobody 10766  0.0  0.0     0     0  1  Z+J  11:14   0:04.21         | `-- <defunct>
nobody 10726  0.0  0.0 12120  2576  1  I+J  11:14   0:00.03         |-- /usr/local/bin/gmake -f utils/TableGen/CMakeFiles/obj.llvm-tblgen.dir/build.make utils/TableGen/CMakeFiles/obj.llvm-tblgen.dir/build
nobody  9446  0.0  0.0     0     0  1  Z+J  11:16   0:03.01         | `-- <defunct>
nobody 10743  0.0  0.0 12140  2652  1  I+J  11:14   0:00.04         |-- /usr/local/bin/gmake -f lib/MC/CMakeFiles/LLVMMC.dir/build.make lib/MC/CMakeFiles/LLVMMC.dir/build
nobody 10795  0.0  0.0     0     0  1  Z+J  11:14   0:02.35         | `-- <defunct>
nobody 10790  0.0  0.0 12412  2828  1  I+J  11:17   0:00.05         `-- /usr/local/bin/gmake -f lib/DebugInfo/PDB/CMakeFiles/LLVMDebugInfoPDB.dir/build.make lib/DebugInfo/PDB/CMakeFiles/LLVMDebugInfoPDB.dir/build
nobody 17155  0.0  0.0     0     0  1  Z+J  11:17   0:00.01           `-- <defunct>


At least the first and third failures sound like the potential deadlock
described in the GNU make jobserver algorithm description here:
http://make.mad-scientist.net/papers/jobserver-implementation/
The description of the algorithm will make more sense if you renumber
the sub-steps under step 4 from 1-5 to a-e.

What happens if we enter the read() in step 4e, and between the time we
check the fd for validity and the time the read sees there is no data
and goes to sleep if a SIGCHLD arrives and closes fd?  Is that even
possible or is the SIGCHLD delivery deferred until the sycall goes to
sleep?

Could we sometimes lose the SIGCHLD?  It looks like losing duplicate
signals should be OK and receiving one per child should not be
necessary.  If multiple children exit after step 4a, as long as SIGCHLD
is delivered at least once before step 4e, then the handler should close
the duplicate fd and step 4e should get EBADF.

The cited document says that the deadlock can occur only if two
instances of make run into this problem.  Because of that I'm suspicious
that this failure is actually more common.  If I watch top during a
poudriere run, I often see long stretches of time when the count of
zombie processes is in the mid single digits.

I haven't yet dug into the code, but I thought I should share my
observations to date.

_______________________________________________
[hidden email] mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: rare gmake jobserver hangs, lost SIGCHLD?

Joerg Sonnenberger-2
On Tue, Feb 13, 2018 at 10:46:32AM -0800, Don Lewis wrote:
> Starting in December 2016, I've seen three build runaway failures on
> different ports.

https://savannah.gnu.org/bugs/?49014 might be your problem.

Joerg
_______________________________________________
[hidden email] mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: rare gmake jobserver hangs, lost SIGCHLD?

Don Lewis-5
On 13 Feb, Joerg Sonnenberger wrote:
> On Tue, Feb 13, 2018 at 10:46:32AM -0800, Don Lewis wrote:
>> Starting in December 2016, I've seen three build runaway failures on
>> different ports.
>
> https://savannah.gnu.org/bugs/?49014 might be your problem.

Thanks!  That looks promising.

_______________________________________________
[hidden email] mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: rare gmake jobserver hangs, lost SIGCHLD?

Rodney W. Grimes-4
In reply to this post by Joerg Sonnenberger-2
> On Tue, Feb 13, 2018 at 10:46:32AM -0800, Don Lewis wrote:
> > Starting in December 2016, I've seen three build runaway failures on
> > different ports.
>
> https://savannah.gnu.org/bugs/?49014 might be your problem.

And given you said Ryzen earlier there is also this issue just found
and fixed:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=225584

> Joerg
--
Rod Grimes                                                 [hidden email]
_______________________________________________
[hidden email] mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: rare gmake jobserver hangs, lost SIGCHLD?

Don Lewis-5
On 13 Feb, Rodney W. Grimes wrote:
>> On Tue, Feb 13, 2018 at 10:46:32AM -0800, Don Lewis wrote:
>> > Starting in December 2016, I've seen three build runaway failures on
>> > different ports.
>>
>> https://savannah.gnu.org/bugs/?49014 might be your problem.
>
> And given you said Ryzen earlier there is also this issue just found
> and fixed:
> https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=225584

Yes, I tested that patch and found that it got rid of several different
semi-random port build failures.  I just happened to get this
gmake-related build runaway on my first poudriere run after applying the
VM patch.

_______________________________________________
[hidden email] mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[hidden email]"