[GR-58613] Improve mx build output.

PullRequest: mx/1841

java/com.oracle.mxtool.compilerserver/src/com/oracle/mxtool/compilerserver/CompilerDaemon.java

@@ -28,6 +28,7 @@
 import java.io.IOException;
 import java.io.InputStreamReader;
 import java.io.OutputStreamWriter;
+import java.io.PrintWriter;
 import java.net.InetAddress;
 import java.net.ServerSocket;
 import java.net.Socket;
@@ -45,6 +46,7 @@ public abstract class CompilerDaemon {
     // These values are used in mx.py so keep in sync.
     public static final String REQUEST_HEADER_COMPILE = "MX DAEMON/COMPILE: ";
     public static final String REQUEST_HEADER_SHUTDOWN = "MX DAEMON/SHUTDOWN";
+    public static final String RESPONSE_DONE = "MX DAEMON/DONE:";
 
     /**
      * The deamon will shut down after receiving this many requests with an unrecognized header.
@@ -122,7 +124,7 @@ private static void usage() {
     abstract Compiler createCompiler();
 
     interface Compiler {
-        int compile(String[] args) throws Exception;
+        int compile(String[] args, PrintWriter out) throws Exception;
     }
 
     public class Connection implements Runnable {
@@ -164,21 +166,27 @@ public void run() {
                         String[] args = commandLine.split("\u0000");
                         logf("%sCompiling %s%n", prefix, String.join(" ", args));
 
-                        int result = compiler.compile(args);
-                        if (result != 0 && args.length != 0 && args[0].startsWith("GET / HTTP")) {
-                            // GR-52712
-                            System.err.printf("%sFailing compilation received on %s%n", prefix, connectionSocket);
+                        int result;
+                        PrintWriter log = new PrintWriter(output);
+                        try {
+                            result = compiler.compile(args, log);
+                            if (result != 0 && args.length != 0 && args[0].startsWith("GET / HTTP")) {
+                                // GR-52712
+                                System.err.printf("%sFailing compilation received on %s%n", prefix, connectionSocket);
+                            }
+                        } finally {
+                            log.flush();
                         }
                         logf("%sResult = %d%n", prefix, result);
 
-                        output.write(result + "\n");
+                        output.write(RESPONSE_DONE + result + "\n");
                     } else {
                         int unrecognizedRequestCount = unrecognizedRequests.incrementAndGet();
                         System.err.printf("%sUnrecognized request %d (len=%d): \"%s\"%n", prefix, unrecognizedRequestCount, request.length(), printable(request));
                         if (unrecognizedRequestCount > MAX_UNRECOGNIZED_REQUESTS) {
                             shutdown(String.format("%sReceived %d unrecognized requests: ", prefix, unrecognizedRequestCount));
                         }
-                        output.write("-1\n");
+                        output.write(RESPONSE_DONE + "-1\n");
                     }
                 } finally {
                     // close IO streams, then socket

java/com.oracle.mxtool.compilerserver/src/com/oracle/mxtool/compilerserver/ECJDaemon.java

@@ -30,8 +30,8 @@
 public class ECJDaemon extends CompilerDaemon {
 
     private final class ECJCompiler implements Compiler {
-        public int compile(String[] args) throws Exception {
-            boolean result = (Boolean) compileMethod.invoke(null, args, new PrintWriter(System.out), new PrintWriter(System.err), null);
+        public int compile(String[] args, PrintWriter out) throws Exception {
+            boolean result = (Boolean) compileMethod.invoke(null, args, out, out, null);
             return result ? 0 : -1;
         }
     }

java/com.oracle.mxtool.compilerserver/src/com/oracle/mxtool/compilerserver/JavacDaemon.java

@@ -24,14 +24,15 @@
  */
 package com.oracle.mxtool.compilerserver;
 
+import java.io.PrintWriter;
 import java.lang.reflect.Method;
 
 public class JavacDaemon extends CompilerDaemon {
 
     private final class JavacCompiler implements Compiler {
-        public int compile(String[] args) throws Exception {
+        public int compile(String[] args, PrintWriter out) throws Exception {
             final Object receiver = javacMainClass.getDeclaredConstructor().newInstance();
-            int result = (Integer) compileMethod.invoke(receiver, (Object) args);
+            int result = (Integer) compileMethod.invoke(receiver, args, out);
             if (result != 0 && result != 1) {
                 // @formatter:off
                 /*
@@ -56,7 +57,7 @@ public int compile(String[] args) throws Exception {
 
     JavacDaemon() throws Exception {
         this.javacMainClass = Class.forName("com.sun.tools.javac.Main");
-        this.compileMethod = javacMainClass.getMethod("compile", String[].class);
+        this.compileMethod = javacMainClass.getMethod("compile", String[].class, PrintWriter.class);
     }
 
     @Override

src/mx/_impl/build/report.py

@@ -0,0 +1,122 @@
+#
+# ----------------------------------------------------------------------------------------------------
+#
+# Copyright (c) 2024, 2024, Oracle and/or its affiliates. All rights reserved.
+# DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+#
+# This code is free software; you can redistribute it and/or modify it
+# under the terms of the GNU General Public License version 2 only, as
+# published by the Free Software Foundation.
+#
+# This code is distributed in the hope that it will be useful, but WITHOUT
+# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+# FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+# version 2 for more details (a copy is included in the LICENSE file that
+# accompanied this code).
+#
+# You should have received a copy of the GNU General Public License version
+# 2 along with this work; if not, write to the Free Software Foundation,
+# Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+#
+# Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+# or visit www.oracle.com if you need additional information or have any
+# questions.
+#
+# ----------------------------------------------------------------------------------------------------
+#
+
+import html
+import os
+import time
+
+from .. import mx
+
+def write_task_report(f, task):
+    f.write('\n<div class="task">\n')
+    f.write(f'    <h2>{task.name}</h2>\n')
+    f.write(f'    <p class="result {task.status}">{task.statusInfo}</p>\n')
+    l = str(task._log).strip()
+    if l:
+        f.write('        <span class="log"><pre>\n')
+        f.write(html.escape(l))
+        f.write('\n        </pre></span>\n')
+    f.write('</div>\n')
+
+def write_style(f):
+    f.write('''
+    <style>
+        .header dt { font-weight: bold; }
+        .success:before { content: "success"; color: green; }
+        .failed:before { content: "failed"; color: red; }
+        .skipped:before { content: "skipped"; margin-right: 2em; color: blue; }
+        .log:before { content: "build log:"; }
+        .log pre { border: 1px inset; padding: 5px; max-height: 350px; overflow: auto; }
+    </style>
+    ''')
+
+class BuildReport:
+    def __init__(self, cmd_args):
+        self.tasks = []
+        self.properties = {}
+        if cmd_args:
+            self.properties['arguments'] = " ".join(cmd_args)
+
+    def set_tasks(self, tasks):
+        self.tasks = tasks
+
+    def add_info(self, key, value):
+        self.properties[key] = value
+
+    def _write_header(self, f):
+        f.write('<h1>mx build report</h1>\n<dl class="header">\n')
+        for k in self.properties:
+            f.write(f"    <dt>{k}</dt>\n")
+            v = self.properties[k]
+            if isinstance(v, list):
+                f.write("        <dd>\n")
+                for i in v:
+                    f.write(f"            {html.escape(str(i))}<br/>\n")
+                f.write("        </dd>\n")
+            else:
+                f.write(f"        <dd>{html.escape(str(v))}</dd>\n")
+        f.write('</dl>\n')
+
+    def _write_report(self, filename):
+        allSkipped = True
+        for t in self.tasks:
+            if t.status != "skipped":
+                allSkipped = False
+                break
+        if allSkipped:
+            # don't bother writing a build log if there was nothing to do
+            return
+        with open(filename, 'w', encoding='utf-8') as f:
+            f.write('<!DOCTYPE html>\n')
+            f.write('<html>\n')
+            f.write('<body>\n')
+            self._write_header(f)
+            for t in self.tasks:
+                if t.status is not None:
+                    # only report on tasks that were started
+                    write_task_report(f, t)
+            write_style(f)
+            f.write('</body>\n')
+            f.write('</html>\n')
+        mx.log(f"mx build log written to {filename}")
+
+    def __enter__(self):
+        self.properties['started'] = time.strftime("%Y-%m-%d %H:%M:%S")
+        return self
+
+    def __exit__(self, exc_type, exc_value, traceback):
+        self.properties['finished'] = time.strftime("%Y-%m-%d %H:%M:%S")
+
+        reportDir = mx.primary_suite().get_output_root(jdkDependent=False)
+        mx.ensure_dir_exists(reportDir)
+        base_name = time.strftime("buildlog-%Y%m%d-%H%M%S")
+        reportFile = os.path.join(reportDir, base_name + ".html")
+        reportIdx = 0
+        while os.path.exists(reportFile):
+            reportIdx += 1
+            reportFile = os.path.join(reportDir, f'{base_name}_{reportIdx}.html')
+        self._write_report(reportFile)

src/mx/_impl/build/tasks/__init__.py

@@ -30,10 +30,11 @@
     "BuildTask",
     "NoOpTask",
     "Task",
+    "TaskAbortException",
     "TaskSequence"
 ]
 
 from .build import Buildable, BuildTask
-from .task import Task
+from .task import Task, TaskAbortException
 from .noop import NoOpTask
 from .sequence import TaskSequence

src/mx/_impl/build/tasks/build.py

@@ -181,10 +181,13 @@ def _timestamp(self) -> str:
         return ''
 
     def logBuild(self, reason: Optional[str] = None) -> None:
+        timestamp = self._timestamp()
+        if self.args.build_logs == 'oneline':
+            self.log(f'{timestamp}{self}...', echo=True, log=False)
         if reason:
-            log(self._timestamp() + f'{self}... [{reason}]')
+            self.log(f'{timestamp}{self}... [{reason}]')
         else:
-            log(self._timestamp() + f'{self}...')
+            self.log(f'{timestamp}{self}...')
 
     def logBuildDone(self, duration: float) -> None:
         timestamp = self._timestamp()
@@ -193,13 +196,15 @@ def logBuildDone(self, duration: float) -> None:
             # Strip hours if 0
             if durationStr.startswith('0:'):
                 durationStr = durationStr[2:]
-            log(timestamp + f'{self} [duration: {duration}]')
+            self.log(f'{timestamp}{self} [duration: {duration}]', echo=True)
 
     def logClean(self) -> None:
-        log(f'Cleaning {self.name}...')
+        self.log(f'Cleaning {self.name}...')
 
     def logSkip(self, reason: Optional[str] = None) -> None:
+        self.status = "skipped"
         if reason:
+            self.statusInfo = reason
             logv(f'[{reason} - skipping {self.name}]')
         else:
             logv(f'[skipping {self.name}]')

src/mx/_impl/build/tasks/task.py

@@ -28,17 +28,22 @@
 from __future__ import annotations
 from abc import ABCMeta, abstractmethod
 from argparse import Namespace
+from threading import Lock
 from typing import Dict, Optional, MutableSequence
 
 from ..daemon import Daemon
 from ..suite import Dependency
-from ...support.logging import nyi
+from ... import mx
+from ...support.logging import nyi, setLogTask
 from ...support.processes import Process
 
-__all__ = ["Task"]
+__all__ = ["Task", "TaskAbortException"]
 
 Args = Namespace
 
+class TaskAbortException(Exception):
+    pass
+
 class Task(object, metaclass=ABCMeta):
     """A task executed during a build."""
 
@@ -48,6 +53,8 @@ class Task(object, metaclass=ABCMeta):
     parallelism: int
     proc: Optional[Process]
 
+    consoleLock = Lock()
+
     def __init__(self, subject: Dependency, args: Args, parallelism: int):
         """
         :param subject: the dependency for which this task is executed
@@ -59,6 +66,13 @@ def __init__(self, subject: Dependency, args: Args, parallelism: int):
         self.parallelism = parallelism
         self.deps = []
         self.proc = None
+        self.subprocs = []
+        self._log = mx.LinesOutputCapture()
+        self._echoImportant = not hasattr(args, 'build_logs') or args.build_logs in ["important", "full"]
+        self._echoAll = hasattr(args, 'build_logs') and args.build_logs == "full"
+        self._exitcode = 0
+        self.status = None
+        self.statusInfo = ""
 
     def __str__(self) -> str:
         return nyi('__str__', self)
@@ -70,6 +84,70 @@ def __repr__(self) -> str:
     def name(self) -> str:
         return self.subject.name
 
+    def enter(self):
+        self.status = "running"
+        setLogTask(self)
+
+    def leave(self):
+        if self.status == "running":
+            self.status = "success"
+        setLogTask(None)
+
+    def abort(self, code):
+        self._exitcode = code
+        self.status = "failed"
+        raise TaskAbortException(code)
+
+    def log(self, msg, echo=False, log=True, important=True, replace=False):
+        """
+        Log output for this build task.
+
+        Whether the output also goes to the console depends on the `--build-logs` option:
+        * In `silent`, `oneline` and `interactive` mode, only messages with `echo=True` are printed.
+        * In `full` mode, all messages are printed.
+        * In `important` mode, only messages with `important=True` are printed.
+
+        `log=False` can be used to only do output, without including it in the log. This is useful
+        in combination with `echo=True` to print a shorter summary of information that's already in
+        the log in a more detailed form.
+
+        `replace=True` replaces the last logged line. This is useful for status output, e.g. download progress.
+        """
+        if log:
+            if replace:
+                del self._log.lines[-1]
+            self._log(msg)
+        if echo or self._echoAll or (important and self._echoImportant):
+            with Task.consoleLock:
+                print(msg.rstrip())
+
+    def getLastLogLine(self):
+        for line in reversed(self._log.lines):
+            if line.strip():
+                return line
+        return None
+
+    def addSubproc(self, p):
+        self.subprocs += [p]
+
+    def cancelSubprocs(self):
+        from ...support.processes import _is_process_alive, _kill_process
+        from signal import SIGTERM
+        for p in self.subprocs:
+            if not _is_process_alive(p):
+                continue
+            if mx.is_windows():
+                p.terminate()
+            else:
+                _kill_process(p.pid, SIGTERM)
+
+    @property
+    def exitcode(self):
+        if self._exitcode != 0:
+            return self._exitcode
+        else:
+            return self.proc.exitcode
+
     @property
     def build_time(self):
         return getattr(self.subject, "build_time", 1)