8230652: Improve verbose output

Reviewed-by: almatvee, asemenyuk, kizune

Author: Andy Herrick

src/jdk.incubator.jpackage/macosx/classes/jdk/incubator/jpackage/internal/MacBaseInstallerBundler.java

@@ -187,7 +187,6 @@ public static String findKey(String keyPrefix, String teamName, String keychainN
                 Log.error(MessageFormat.format(I18N.getString(
                         "error.multiple.certs.found"), key, keychainName));
             }
-            Log.verbose("Using key '" + matchedKey + "'");
             return matchedKey;
         } catch (IOException ioe) {
             Log.verbose(ioe);

src/jdk.incubator.jpackage/macosx/classes/jdk/incubator/jpackage/internal/MacDmgBundler.java

@@ -82,9 +82,6 @@ public Path bundle(Map<String, ? super Object> params,
             if (appLocation != null && prepareConfigFiles(params)) {
                 Path configScript = getConfig_Script(params);
                 if (IOUtils.exists(configScript)) {
-                    Log.verbose(MessageFormat.format(
-                            I18N.getString("message.running-script"),
-                            configScript.toAbsolutePath().toString()));
                     IOUtils.run("bash", configScript);
                 }
 

src/jdk.incubator.jpackage/macosx/classes/jdk/incubator/jpackage/internal/MacPkgBundler.java

@@ -142,9 +142,6 @@ public Path bundle(Map<String, ? super Object> params,
 
                 Path configScript = getConfig_Script(params);
                 if (IOUtils.exists(configScript)) {
-                    Log.verbose(MessageFormat.format(I18N.getString(
-                            "message.running-script"),
-                            configScript.toAbsolutePath().toString()));
                     IOUtils.run("bash", configScript);
                 }
 

src/jdk.incubator.jpackage/share/classes/jdk/incubator/jpackage/internal/Executor.java

@@ -75,6 +75,11 @@ Executor setCommandLine(String... cmdline) {
         return setProcessBuilder(new ProcessBuilder(cmdline));
     }
 
+    Executor setQuiet(boolean v) {
+        quietCommand = v;
+        return this;
+    }
+
     List<String> getOutput() {
         return output;
     }
@@ -84,7 +89,7 @@ Executor executeExpectSuccess() throws IOException {
         if (0 != ret) {
             throw new IOException(
                     String.format("Command %s exited with %d code",
-                            createLogMessage(pb), ret));
+                            createLogMessage(pb, false), ret));
         }
         return this;
     }
@@ -108,7 +113,7 @@ int execute() throws IOException {
             pb.redirectOutput(ProcessBuilder.Redirect.DISCARD);
         }
 
-        Log.verbose(String.format("Running %s", createLogMessage(pb)));
+        Log.verbose(String.format("Running %s", createLogMessage(pb, true)));
         Process p = pb.start();
 
         int code = 0;
@@ -126,47 +131,35 @@ int execute() throws IOException {
             Supplier<Stream<String>> outputStream;
 
             if (writeOutputToFile) {
-                savedOutput = Files.readAllLines(outputFile);
+                output = savedOutput = Files.readAllLines(outputFile);
                 Files.delete(outputFile);
                 outputStream = () -> {
                     if (savedOutput != null) {
                         return savedOutput.stream();
                     }
                     return null;
                 };
-
-                if (Log.isVerbose()) {
-                    outputStream.get().forEach(Log::verbose);
-                }
-
                 if (outputConsumer != null) {
                     outputConsumer.accept(outputStream.get());
                 }
             } else {
                 try (var br = new BufferedReader(new InputStreamReader(
                         p.getInputStream()))) {
-                    // Need to save output if explicitely requested (saveOutput=true) or
-                    // if will be used used by multiple consumers
-                    if ((outputConsumer != null && Log.isVerbose()) || saveOutput) {
+
+                    if ((outputConsumer != null || Log.isVerbose())
+                            || saveOutput) {
                         savedOutput = br.lines().collect(Collectors.toList());
-                        if (saveOutput) {
-                            output = savedOutput;
-                        }
                     } else {
                         savedOutput = null;
                     }
+                    output = savedOutput;
 
                     outputStream = () -> {
                         if (savedOutput != null) {
                             return savedOutput.stream();
                         }
                         return br.lines();
                     };
-
-                    if (Log.isVerbose()) {
-                        outputStream.get().forEach(Log::verbose);
-                    }
-
                     if (outputConsumer != null) {
                         outputConsumer.accept(outputStream.get());
                     }
@@ -188,6 +181,9 @@ int execute() throws IOException {
             if (!writeOutputToFile) {
                 code = p.waitFor();
             }
+            if (!quietCommand) {
+                Log.verbose(pb.command(), getOutput(), code);
+            }
             return code;
         } catch (InterruptedException ex) {
             Log.verbose(ex);
@@ -203,7 +199,7 @@ private int waitForProcess(Process p) throws InterruptedException {
                 return p.exitValue();
             } else {
                 Log.verbose(String.format("Command %s timeout after %d seconds",
-                            createLogMessage(pb), timeout));
+                            createLogMessage(pb, false), timeout));
                 p.destroy();
                 return -1;
             }
@@ -218,9 +214,9 @@ static Executor of(ProcessBuilder pb) {
         return new Executor().setProcessBuilder(pb);
     }
 
-    private static String createLogMessage(ProcessBuilder pb) {
+    private static String createLogMessage(ProcessBuilder pb, boolean quiet) {
         StringBuilder sb = new StringBuilder();
-        sb.append(String.format("%s", pb.command()));
+        sb.append((quiet) ? pb.command().get(0) : pb.command());
         if (pb.directory() != null) {
             sb.append(String.format("in %s", pb.directory().getAbsolutePath()));
         }
@@ -232,6 +228,7 @@ private static String createLogMessage(ProcessBuilder pb) {
     private ProcessBuilder pb;
     private boolean saveOutput;
     private boolean writeOutputToFile;
+    private boolean quietCommand;
     private long timeout = INFINITE_TIMEOUT;
     private List<String> output;
     private Consumer<Stream<String>> outputConsumer;

src/jdk.incubator.jpackage/share/classes/jdk/incubator/jpackage/internal/IOUtils.java

@@ -228,6 +228,7 @@ public static int getProcessOutput(List<String> result, String... args)
         t.start();
 
         int ret = p.waitFor();
+        Log.verbose(pb.command(), list, ret);
 
         result.clear();
         result.addAll(list);

src/jdk.incubator.jpackage/share/classes/jdk/incubator/jpackage/internal/JLinkBundlerHelper.java

@@ -188,15 +188,16 @@ private static void runJLink(Path output, List<Path> modulePath,
         StringWriter writer = new StringWriter();
         PrintWriter pw = new PrintWriter(writer);
 
-        Log.verbose("jlink arguments: " + args);
         int retVal = LazyLoad.JLINK_TOOL.run(pw, pw, args.toArray(new String[0]));
         String jlinkOut = writer.toString();
 
+        args.add(0, "jlink");
+        Log.verbose(args, List.of(jlinkOut), retVal);
+
+
         if (retVal != 0) {
             throw new PackagerException("error.jlink.failed" , jlinkOut);
         }
-
-        Log.verbose("jlink output: " + jlinkOut);
     }
 
     private static String getPathList(List<Path> pathList) {

src/jdk.incubator.jpackage/share/classes/jdk/incubator/jpackage/internal/Log.java

@@ -28,6 +28,7 @@
 import java.io.PrintWriter;
 import java.text.SimpleDateFormat;
 import java.util.Date;
+import java.util.List;
 
 /**
  * Log
@@ -115,6 +116,25 @@ public void verbose(String msg) {
             }
         }
 
+        public void verbose(List<String> strings,
+                List<String> output, int returnCode) {
+            if (verbose) {
+                StringBuffer sb = new StringBuffer("Command:\n   ");
+                for (String s : strings) {
+                    sb.append(" " + s);
+                }
+                verbose(new String(sb));
+                if (output != null && !output.isEmpty()) {
+                    sb = new StringBuffer("Output:");
+                    for (String s : output) {
+                        sb.append("\n    " + s);
+                    }
+                    verbose(new String(sb));
+                }
+                verbose("Returned: " + returnCode + "\n");
+            }
+        }
+
         private String addTimestamp(String msg) {
             SimpleDateFormat sdf = new SimpleDateFormat("HH:mm:ss.SSS");
             Date time = new Date(System.currentTimeMillis());
@@ -173,4 +193,11 @@ public static void verbose(Throwable t) {
            delegate.verbose(t);
         }
     }
+
+    public static void verbose(List<String> strings, List<String> out, int ret) {
+        if (delegate != null) {
+           delegate.verbose(strings, out, ret);
+        }
+    }
+
 }

src/jdk.incubator.jpackage/share/classes/jdk/incubator/jpackage/internal/ToolValidator.java

@@ -94,7 +94,7 @@ ConfigException validate() {
             }
 
             String[] version = new String[1];
-            Executor.of(pb).setOutputConsumer(lines -> {
+            Executor.of(pb).setQuiet(true).setOutputConsumer(lines -> {
                 if (versionParser != null && minimalVersion != null) {
                     version[0] = versionParser.apply(lines);
                     if (minimalVersion.compareTo(version[0]) < 0) {

test/jdk/tools/jpackage/windows/WinL10nTest.java

@@ -95,9 +95,7 @@ public static List<Object[]> data() {
     private final static Stream<String> getLightCommandLine(
             Executor.Result result) {
         return result.getOutput().stream()
-                .filter(s -> s.contains("Running"))
-                .filter(s -> s.contains("light.exe"))
-                .filter(s -> !s.contains("/?"));
+                .filter(s -> s.trim().startsWith("light.exe"));
     }
 
     @Test