bmake: Hide noisy spam behind debug options

[cem]

Summary

Noisy spam from every bmake job-unwinding after a failed build obfuscates
the actual failure. If you want this spam, add '-dj' to your make flags
(DEBUG_JOB).

Test Plan

1. Insert a typo in a kernel file. 2.

make -sj1000 buildkernel

[bdrewery]

Wow. Be sure to get buyin from sjg@ or it may get dropped by accident.

contrib/bmake/main.c

2063

This is quite useful information to give up by default

[cem]

contrib/bmake/main.c

2063

I think it's potentially useful for debugging Make, especially around the initial failure, but I don't think it's useful for the typical failure to compile/assemble/transform source files into object files.

With -j32 or -j64 builds, you get 64-128 useless lines of the form "[empty line]" + "make[3]: stopped in /usr/home/conrad/src/freebsd/sys/modules" which obscure the actual error. I.e., this is an output-scales-with-j spam.

The output can be selectively re-enabled with '-dC' to debug make itself or Makefile logic.

[lwhsu]

This is nice. I'm not sure if using -s would make things harder when we need to check flags, but can get rid of 'make[N]: stopped in /foo/bar' is really helpful.

Do you think it makes sense if we keep this message which shows the CWD form the process directly hits the error:

/usr/home/lwhsu/freebsd-src/contrib/bmake/suff.c:2676:1: error: expected '}'
^
/usr/home/lwhsu/freebsd-src/contrib/bmake/suff.c:2670:1: note: to match this '{'
{
^
1 error generated.
*** [suff.o] Error code 1

make: stopped in /usr/home/lwhsu/freebsd-src/usr.bin/bmake

while suppressing these messages from other processes?

A failure has been detected in another branch of the parallel make

make[2]: stopped in /usr/home/lwhsu/freebsd-src/usr.bin/bmake/tests/execution

[sjg]

Do you have an example of resulting output?

The first 'stopped' message is vital output and needing to turn on -dj to get it would be completely unacceptable.
As for the "failure elsewhere" noise, I agree,

[sjg]

If the build log is 6Gb (because the build took 10hrs before it failed), the extra noise at the end is the least of your problems.
Needing to redo that job to have any clue as to when and why it failed is not an option.
So again, if make is exiting due to an error token, by all means keep quiet, but otherwise noise is better than silence.

[sjg]

In D25346#558961, @lwhsu wrote:

This is nice. I'm not sure if using -s would make things harder when we need to check flags, but can get rid of 'make[N]: stopped in /foo/bar' is really helpful.

Not in my world; 2000+ developers can produce a lot of "what did I do wrong" mails, we want make to spew all the info available.
Supressing the windup from the higher levels, is useful, but the initial output is vital.

Do you think it makes sense if we keep this message which shows the CWD form the process directly hits the error:

/usr/home/lwhsu/freebsd-src/contrib/bmake/suff.c:2676:1: error: expected '}'
^
/usr/home/lwhsu/freebsd-src/contrib/bmake/suff.c:2670:1: note: to match this '{'
{
^
1 error generated.
*** [suff.o] Error code 1

make: stopped in /usr/home/lwhsu/freebsd-src/usr.bin/bmake

while suppressing these messages from other processes?

A failure has been detected in another branch of the parallel make

make[2]: stopped in /usr/home/lwhsu/freebsd-src/usr.bin/bmake/tests/execution

[sjg]

All in all the approach here looks wrong.
Let me ponder/poke...

contrib/bmake/main.c

1821

In the case where output is to be supressed, I'd think all of Fatal() should be skipped.
You want it from the initial failure, but the rest add little value

[sjg]

I think the following is sufficient:

`monosdiff -r 3239be1e752e bmake/job.c

• a/bmake/job.c Mon Jun 08 16:21:00 2020 -0700

+++ b/bmake/job.c Thu Jun 18 21:39:44 2020 -0700
@@ -1058,10 +1058,11 @@

    meta_job_error(job, job->node, job->flags, WEXITSTATUS(status));
}

#endif

• (void)printf("*** [%s] Error code %d%s\n",
• job->node->name,
• WEXITSTATUS(status),
• (job->flags & JOB_IGNERR) ? " (ignored)" : "");

+ if (!dieQuietly(job->node, -1))
+ (void)printf("*** [%s] Error code %d%s\n",
+ job->node->name,
+ WEXITSTATUS(status),
+ (job->flags & JOB_IGNERR) ? " (ignored)" : "");

if (job->flags & JOB_IGNERR) {
    WAIT_STATUS(status) = 0;
} else {

@@ -3039,6 +3040,8 @@

/* And put the stopper back */
while (write(tokenWaitJob.outPipe, &tok, 1) == -1 && errno == EAGAIN)
    continue;

+ if (dieQuietly(NULL, 1))
+ exit(2);

   Fatal("A failure has been detected in another branch of the parallel make");
}

diff -r 3239be1e752e bmake/main.c

• a/bmake/main.c Mon Jun 08 16:21:00 2020 -0700

+++ b/bmake/main.c Thu Jun 18 21:39:44 2020 -0700
@@ -1889,6 +1889,8 @@
Finish(int errors)

/* number of errors encountered in Make_Make */

{
+ if (dieQuietly(NULL, -1))
+ exit(2);

Fatal("%d error%s", errors, errors == 1 ? "" : "s");

}

@@ -2041,6 +2043,27 @@

return 0;

}

+/*
+ * Return true if we should die without noise.
+ * For example our failing child was a sub-make
+ * or failure happend elsewhere.
+ */
+int
+dieQuietly(GNode *gn, int bf)
+{
+ static int quietly = -1;
+
+ if (quietly < 0) {
+ if (DEBUG(JOB))
+ quietly = 0;
+ else if (bf >= 0)
+ quietly = bf;
+ else if (gn)
+ quietly = ((gn->type & (OP_MAKE|OP_SUBMAKE)) != 0);
+ }
+ return quietly;
+}
+
void
PrintOnError(GNode *gn, const char *s)
{
@@ -2048,6 +2071,10 @@

char tmp[64];
char *cp;

+ /* we generally want to keep quiet if a sub-make died */
+ if (dieQuietly(gn, -1))
+ return;
+

if (s)
   printf("%s", s);

diff -r 3239be1e752e bmake/make.h

• a/bmake/make.h Mon Jun 08 16:21:00 2020 -0700

+++ b/bmake/make.h Thu Jun 18 21:39:44 2020 -0700
@@ -505,6 +505,7 @@
Boolean Make_Run(Lst);
char * Check_Cwd_Cmd(const char *);
void Check_Cwd(const char **);
+int dieQuietly(GNode *, int);
void PrintOnError(GNode *, const char *);
void Main_ExportMAKEFLAGS(Boolean);
Boolean Main_SetObjdir(const char *, ...) MAKE_ATTR_PRINTFLIKE(1, 2);
paced text`

[cem]

Obviated at least in part by r363117.