Bug 1360764 - Print compiler warnings at end of the build; r?froydnj The way it works today, compiler warnings are logged to build output twice. The compiler's raw output is logged. Then, if mach's compiler warning parser detects a warning, a structured log message with info about that warning is printed as well. Because of the order in which callbacks fire, mach's warning message is delivered to the logger first. So build output looks something like: 0:04.63 Warning: -Wsign-compare in /home/gps/src/firefox/security/nss/lib/dev/ckhelper.c: comparison of integers of different signs: 'CK_ULONG' (aka 'unsigned long') and 'int' 0:04.63 /home/gps/src/firefox/security/nss/lib/dev/ckhelper.c:135:45: warning: comparison of integers of different signs: 'CK_ULONG' (aka 'unsigned long') and 'int' [-Wsign-compare] 0:04.63 (obj_template[i].ulValueLen == -1)) { 0:04.63 ~~~~~~~~~~~~~~~~~~~~~~~~~~ ^ ~~ That first line is our structured message formatted to plain text. Subsequent lines are Clang. The output here is redundant. But having the structured compiler warning in the JSON logs is nice so downstream systems don't have to reinvent the parsing wheel. Also today, at the end of a clobber build we print a count of the total number of compiler warnings. Compiler warnings represent potential bugs. So we want to encourage people to look at them. However, with build system output often spanning several hundred lines and compiler warnings scattered in no deterministic order because build system execution is non-deterministic, it is easy to lose sight of compiler warnings as they go by in build output. And, it can be difficult to find a warning in files you care about because you don't know where in the log to look for that file. This commit attempts to improve the visibility of compiler warnings by printing a sorted list of warnings at the end of the build. The list of warnings it prints are only those seen during the current build operation. We /could/ print a list of all warnings in the persisted database. But I think this would be annoying, particularly for incremental or partial builds. The structured log message previously emitted at compiler invocation time has been removed. So now the build backend output doesn't have a redundant "Warning: " line summarizing the warning next to the compiler output itself. This is less confusing. That structured log message has been reborn at the end of the build and reformatted slightly. If there are any consumers assuming that the log entry near this structured message is compiler output itself, they will break. I don't think any such consumers exist. It is also possible the structured log may not contain warning messages if a process exit occurs. I'm fine with this: if the `mach` process dies, we have bigger problems to worry about. The new output looks something like this: 18:07.97 warning: gfx/angle/src/compiler/translator/util.cpp:216:15 [-Wimplicit-fallthrough] unannotated fall-through between switch labels 18:07.97 warning: gfx/angle/src/compiler/translator/util.cpp:225:15 [-Wimplicit-fallthrough] unannotated fall-through between switch labels 18:07.97 warning: gfx/angle/src/compiler/translator/util.cpp:234:15 [-Wimplicit-fallthrough] unannotated fall-through between switch labels 18:07.97 warning: gfx/cairo/libpixman/src/pixman-bits-image.c:268:32 [-Wshift-negative-value] shifting a negative signed value is undefined 18:07.97 warning: gfx/cairo/libpixman/src/pixman-linear-gradient.c:395:6 [-Wunreachable-code] code will never be executed 18:07.97 warning: gfx/cairo/libpixman/src/pixman-x86.c:80:5 [-Wexpansion-to-defined] macro expansion producing 'defined' has undefined behavior Note the sorting of files, including by line number and column. If we wanted to, we could even print that line. But that's for another day (especially since compilers themselves tend to do this already). This change has the potential to annoy people. That's because instead of the parsed warning summary lines being spread out over the build (where they tend not to be noticed), they will be lumped at the end of the build log, which people do tend to notice. In my build, I have ~363 warnings/lines. Some could perceive this as excessive and redundant. But the recourse for this is simple: eliminate compiler warnings. My hope is that by having the compiler warnings exposed clearly at the end of the build log that people will notice them and will take action to eliminate them. Sunlight is a disinfectant. MozReview-Commit-ID: 9VHXsPhAYmr

--- a/python/mozbuild/mozbuild/mach_commands.py
+++ b/python/mozbuild/mozbuild/mach_commands.py
@@ -253,20 +253,16 @@ class BuildOutputManager(LoggingMixin):
             return
 
         self.footer.clear()
         self.footer.draw()
 
     def on_line(self, line):
         warning, state_changed, relevant = self.monitor.on_line(line)
 
-        if warning:
-            self.log(logging.INFO, 'compiler_warning', warning,
-                'Warning: {flag} in {filename}: {message}')
-
         if relevant:
             self.log(logging.INFO, 'build_output', {'line': line}, '{line}')
         elif state_changed:
             have_handler = hasattr(self, 'handler')
             if have_handler:
                 self.handler.acquire()
             try:
                 self.refresh()
@@ -462,16 +458,35 @@ class Build(MachCommandBase):
                         line_handler=output.on_line, log=False, print_directory=False,
                         allow_parallel=False, ensure_exit_code=False, num_jobs=jobs,
                         silent=not verbose)
 
                 self.log(logging.WARNING, 'warning_summary',
                     {'count': len(monitor.warnings_database)},
                     '{count} compiler warnings present.')
 
+            # Print the collected compiler warnings. This is redundant with
+            # inline output from the compiler itself. However, unlike inline
+            # output, this list is sorted and grouped by file, making it
+            # easier to triage output.
+            for warning in sorted(monitor.instance_warnings):
+                path = mozpath.normsep(warning['filename'])
+                if path.startswith(self.topsrcdir):
+                    path = path[len(self.topsrcdir) + 1:]
+
+                warning['normpath'] = path
+
+                if warning['column'] is not None:
+                    self.log(logging.WARNING, 'compiler_warning', warning,
+                             'warning: {normpath}:{line}:{column} [{flag}] '
+                             '{message}')
+                else:
+                    self.log(logging.WARNING, 'compiler_warning', warning,
+                             'warning: {normpath}:{line} [{flag}] {message}')
+
             monitor.finish(record_usage=status==0)
 
         high_finder, finder_percent = monitor.have_high_finder_usage()
         if high_finder:
             print(FINDER_SLOW_MESSAGE % finder_percent)
 
         ccache_end = monitor.ccache_stats()