1288431 - Aggregate compiler error messages and display after compilation finishes.

Status: NEW

(Firefox Build System :: General, defect)

Description

[Nika Layzell [:nika] (ni? for response)]

When building, especially with icecc causing me to be running 100+ builds concurrently, it can be quite difficult to find the error which caused my build to fail after the build finishes running. I get the make error, but have to scroll back through hundreds of lines of log before I can find the error which actually caused the build to fail.

It would be great if we could collect the error messages as they are logged, and re-log them at the end of the build if it fails, such that the errors become much easier to find.

Comment 1

[Mike Hommey [:glandium] OoO until Jun 18]

I thought about the same thing yesterday when I saw yet another bug report about a build failure that didn't include the actual error, because, as usual, it's well before what remains in the terminal after the build ends.

Comment 2

[Gregory Szorc [:gps]]

We have code at https://hg.mozilla.org/mozilla-unified/file/251fccc1f62b/python/mozbuild/mozbuild/controller/building.py#l154 that looks at every line of output from the build backend and attempts to make sense of it. That's how we collect compiler warnings.

Parsing errors with make with concurrent processes is a bit difficult because output from multiple processes is interleaved. Modern versions of make do have an option for preventing the process output interleaving. But it does so at the expense of buffering command output until it has finished. This confuses things like our PGO link process invocations, which emit output every few minutes to prevent automation from killing the job because it thinks it has stalled.

Also, make error messages are often localized. So parsing them could be problematic. GNU make just doesn't have good machine-readable output like modern build systems do :/

Comment 3

[(not currently active) Ted Mielczarek]

Presumably we could do this by wrapping the compiler invocation with a Python script, at the expense of having another layer there.

Comment 4

[Gregory Szorc [:gps]]

I've also wanted to wrap the compiler invocation so we can use psutil to capture resource metrics. This will allow us to do things like find out which source files take the most CPU, memory, etc. So I'm not opposed to adding another layer of indirection. Keep in mind we already wrap cl.exe on Windows to parse /showIncludes.

Comment 5

[Mike Hommey [:glandium] OoO until Jun 18]

Note that we don't wrap the compiler on Windows when using sccache (but sccache is a wrapper already). That is, we're not adding another layer in that case.

Comment 6

[Nicholas Nethercote [inactive]]

There was a dev-platform thread last year about how people extract compile errors from build output (https://groups.google.com/forum/#!topic/mozilla.dev.platform/8WjCTcTr3Oc). People had a range of ways of doing it, mostly using either scripts or their editors to look for "error:" lines or similar.

One downside of only displaying them after compilation finishes is that you have to wait for compilation to finish. To get around this, I have the following arrangement:

> I deal with this by using a bash alias that calls |mach build| and
> pipes the output to file. I can then use Vim's quicklists feature to
> jump directly to errors in the file. But sometimes I just want to
> eyeball the errors directly in the terminal, so in my alias I also
> have a post-build step that greps the output file for the first five
> error messages.

(The point of piping the output to file is that I can start fixing errors as soon as they appear, which can be some time before |mach build| terminates.)

So this bug would provide a nicer (and probably more reliable) way of doing the post-build step.

Comment 7

[Kris Maglione [:kmag]]

My thought was rather than aggregating errors, I'd like to see the entire output of the failed jobs when the build finishes. `tee`ing the output of each job to a predictable location and then retrieving it on failure would probably also solve the interleaving issue.

(In reply to Nicholas Nethercote [:njn] from comment #6)
> One downside of only displaying them after compilation finishes is that you
> have to wait for compilation to finish.

I tend to wind up pausing the build as soon as I see an error, and scrolling to try to find it and fix it, while I wait for the rest of the tasks to finish.

But `mach build` already has a persistent status line at the bottom of the screen, and it would be nice if it could somehow show information about errors that have occurred so far in the build.

Comment 8

[Gregory Szorc [:gps]]

It is definitely possible to print a count of compiler warnings in the progress bar. Please file a new bug for that!

Relevant code is at https://hg.mozilla.org/mozilla-central/file/ea693af1b5fb/python/mozbuild/mozbuild/mach_commands.py#l129 and https://hg.mozilla.org/mozilla-central/file/ea693af1b5fb/python/mozbuild/mozbuild/mach_commands.py#l258 if you want to take a stab at it. Basically, you need to update a warning count on the footer object in that line handler callback and then print that value in the footer.

Comment 9

[Mike Hommey [:glandium] OoO until Jun 18]

(In reply to Kris Maglione [:kmag] (busy; behind on reviews) from comment #7)
> My thought was rather than aggregating errors, I'd like to see the entire
> output of the failed jobs when the build finishes. `tee`ing the output of
> each job to a predictable location and then retrieving it on failure would
> probably also solve the interleaving issue.

Run mach show-log after a mach build ;)

Comment 10

[Mike Hommey [:glandium] OoO until Jun 18]

(In reply to Gregory Szorc [:gps] from comment #8)
> It is definitely possible to print a count of compiler warnings in the
> progress bar. Please file a new bug for that!

Note this bug is about errors, not warnings. And yes, errors are a PITA to find in the build output. Especially on automation logs.

Comment 11

[Gregory Szorc [:gps]]

Finding errors in automation logs is also a PITA. Given other benefits (comment #4), I think we should wrap certain processes and save output of failed processes to <tmpdir>/<uuid>.json then have a build cleanup step iterate, grab stats (once inplemented), and print output of failed commands.

One caveat is Python process overhead. It sucks on all platforms. Especially on Windows. But we can compile host Rust binaries now, so...