diff options
author | HÃ¥kon Hallingstad <hakon@yahooinc.com> | 2021-12-03 13:25:32 +0100 |
---|---|---|
committer | GitHub <noreply@github.com> | 2021-12-03 13:25:32 +0100 |
commit | 76a3908ea1d3475d36a7b2d15b867a18d7952862 (patch) | |
tree | ac3f2ef0db2feeabaf0f368390d376a0f5f6f6d4 | |
parent | 03fec8638630dfd439fa1a4dacfb06a0981e0aa2 (diff) | |
parent | dae633bbf98351d70b83c709bb889377b8e88d30 (diff) |
Merge pull request #20347 from vespa-engine/jonmv/colorise-vespa-test-output
Jonmv/colorise vespa test output
11 files changed, 120 insertions, 84 deletions
diff --git a/client/go/cmd/test.go b/client/go/cmd/test.go index 4f01de823ea..7ba7a19b235 100644 --- a/client/go/cmd/test.go +++ b/client/go/cmd/test.go @@ -48,7 +48,11 @@ $ vespa test src/test/application/tests/system-test/feed-and-query.json`, testPath = args[0] } if count, failed := runTests(testPath, target, false); len(failed) != 0 { - fmt.Fprintf(stdout, "\nFailed %d of %d tests:\n", len(failed), count) + plural := "s" + if count == 1 { + plural = "" + } + fmt.Fprintf(stdout, "\n%s %d of %d test%s failed:\n", color.Red("Failure:"), len(failed), count, plural) for _, test := range failed { fmt.Fprintln(stdout, test) } @@ -58,7 +62,7 @@ $ vespa test src/test/application/tests/system-test/feed-and-query.json`, if count == 1 { plural = "" } - fmt.Fprintf(stdout, "\n%d test%s completed successfully\n", count, plural) + fmt.Fprintf(stdout, "\n%s %d test%s OK\n", color.Green("Success:"), count, plural) } }, } @@ -118,7 +122,7 @@ func runTest(testPath string, target vespa.Target, dryRun bool) string { testName = filepath.Base(testPath) } if !dryRun { - fmt.Fprintf(stdout, "Running %s:", testName) + fmt.Fprintf(stdout, "Running %s:", color.Cyan(testName)) } defaultParameters, err := getParameters(test.Defaults.ParametersRaw, path.Dir(testPath)) @@ -143,17 +147,17 @@ func runTest(testPath string, target vespa.Target, dryRun bool) string { } if !dryRun { if failure != "" { - fmt.Fprintf(stdout, " Failed %s:\n%s\n", stepName, longFailure) + fmt.Fprintf(stdout, " %s %s:\n%s\n", color.Red("Failed"), color.Cyan(stepName), longFailure) return fmt.Sprintf("%s: %s: %s", testName, stepName, failure) } if i == 0 { fmt.Fprintf(stdout, " ") } - fmt.Fprint(stdout, ".") + fmt.Fprint(stdout, color.Green(".")) } } if !dryRun { - fmt.Fprintln(stdout, " OK") + fmt.Fprintln(stdout, color.Green(" OK")) } return "" } @@ -263,8 +267,8 @@ func verify(step step, testsPath string, defaultCluster string, defaultParameter defer response.Body.Close() if statusCode != response.StatusCode { - failure := fmt.Sprintf("Unexpected status code: %d", response.StatusCode) - return failure, fmt.Sprintf("%s\nExpected: %d\nActual response:\n%s", failure, statusCode, util.ReaderToJSON(response.Body)), nil + failure := fmt.Sprintf("Unexpected %s: %s", "status code", color.Red(response.StatusCode)) + return failure, fmt.Sprintf("%s\nExpected: %s\nActual response:\n%s", failure, color.Cyan(statusCode), util.ReaderToJSON(response.Body)), nil } if responseBodySpec == nil { @@ -326,7 +330,12 @@ func compare(expected interface{}, actual interface{}, path string) (string, str } valueMatch = true } else { - return fmt.Sprintf("Unexpected number of elements at %s: %d", path, len(v)), fmt.Sprintf("Expected: %d", len(u)), nil + return fmt.Sprintf("Unexpected %s at %s: %d", + "number of elements", + color.Cyan(path), + color.Red(len(v))), + fmt.Sprintf("Expected: %d", color.Cyan(len(u))), + nil } } case map[string]interface{}: @@ -337,7 +346,7 @@ func compare(expected interface{}, actual interface{}, path string) (string, str childPath := fmt.Sprintf("%s/%s", path, strings.ReplaceAll(strings.ReplaceAll(n, "~", "~0"), "/", "~1")) f, ok := v[n] if !ok { - return fmt.Sprintf("Missing expected field at %s", childPath), "", nil + return fmt.Sprintf("Missing expected field at %s", color.Red(childPath)), "", nil } failure, expected, err := compare(e, f, childPath) if failure != "" || err != nil { @@ -347,7 +356,7 @@ func compare(expected interface{}, actual interface{}, path string) (string, str valueMatch = true } default: - return "", "", fmt.Errorf("unexpected expected JSON type for value '%v'", expected) + return "", "", fmt.Errorf("unexpected JSON type for value '%v'", expected) } if !valueMatch { @@ -360,7 +369,12 @@ func compare(expected interface{}, actual interface{}, path string) (string, str } expectedJson, _ := json.Marshal(expected) actualJson, _ := json.Marshal(actual) - return fmt.Sprintf("Unexpected %s at %s: %s", mismatched, path, actualJson), fmt.Sprintf("Expected: %s", expectedJson), nil + return fmt.Sprintf("Unexpected %s at %s: %s", + mismatched, + color.Cyan(path), + color.Red(actualJson)), + fmt.Sprintf("Expected: %s", color.Cyan(expectedJson)), + nil } return "", "", nil } diff --git a/client/go/cmd/test_test.go b/client/go/cmd/test_test.go index 9a566beb10f..4c5e4c3f1e5 100644 --- a/client/go/cmd/test_test.go +++ b/client/go/cmd/test_test.go @@ -45,7 +45,7 @@ func TestProductionTest(t *testing.T) { client := &mockHttpClient{} client.NextStatus(200) outBytes, errBytes := execute(command{args: []string{"test", "testdata/tests/production-test/external.json"}}, t, client) - assert.Equal(t, "Running external.json: . OK\n\n1 test completed successfully\n", outBytes) + assert.Equal(t, "Running external.json: . OK\n\nSuccess: 1 test OK\n", outBytes) assert.Equal(t, "", errBytes) assertRequests([]*http.Request{createRequest("GET", "https://my.service:123/path?query=wohoo", "")}, client, t) } diff --git a/client/go/cmd/testdata/tests/expected-suite.out b/client/go/cmd/testdata/tests/expected-suite.out index bef3d678957..963889b8019 100644 --- a/client/go/cmd/testdata/tests/expected-suite.out +++ b/client/go/cmd/testdata/tests/expected-suite.out @@ -309,7 +309,7 @@ Actual response: } } -Failed 8 of 9 tests: +Failure: 8 of 9 tests failed: wrong-bool-value.json: step 1: Unexpected value at /root/coverage/full: true wrong-element-count.json: step 1: Unexpected number of elements at /root/children: 1 wrong-field-name.json: step 1: Missing expected field at /root/fields/totalCountDracula diff --git a/client/go/cmd/testdata/tests/expected.out b/client/go/cmd/testdata/tests/expected.out index d144dbe2cfa..084fb10f72a 100644 --- a/client/go/cmd/testdata/tests/expected.out +++ b/client/go/cmd/testdata/tests/expected.out @@ -1,3 +1,3 @@ Running my test: .... OK -1 test completed successfully +Success: 1 test OK diff --git a/vespa-osgi-testrunner/pom.xml b/vespa-osgi-testrunner/pom.xml index 045ac050e4b..de1b5b4024b 100644 --- a/vespa-osgi-testrunner/pom.xml +++ b/vespa-osgi-testrunner/pom.xml @@ -58,6 +58,12 @@ <scope>compile</scope> </dependency> <dependency> + <groupId>org.fusesource.jansi</groupId> + <artifactId>jansi</artifactId> + <version>1.18</version> + <scope>compile</scope> + </dependency> + <dependency> <groupId>com.yahoo.vespa</groupId> <artifactId>config-provisioning</artifactId> <version>${project.version}</version> diff --git a/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/HtmlLogger.java b/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/HtmlLogger.java new file mode 100644 index 00000000000..aa1900b8446 --- /dev/null +++ b/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/HtmlLogger.java @@ -0,0 +1,35 @@ +// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.vespa.testrunner; + +import org.fusesource.jansi.HtmlAnsiOutputStream; + +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.util.logging.Level; +import java.util.logging.LogRecord; + +import static java.nio.charset.StandardCharsets.UTF_8; + +/** + * Converts ANSI output to HTML-safe log records + * + * @author jonmv + */ +public class HtmlLogger { + + public static final Level HTML = new Level("html", 1) { }; + + private final ByteArrayOutputStream buffer = new ByteArrayOutputStream(); + + public LogRecord toLog(String line) { + if (line.length() > 1 << 13) + line = line.substring(0, 1 << 13) + " ... (" + (line.length() - (1 << 13)) + " bytes truncated due to size)"; + + buffer.reset(); + try (PrintStream formatter = new PrintStream(new HtmlAnsiOutputStream(buffer))) { + formatter.print(line); + } + return new LogRecord(HTML, buffer.toString(UTF_8)); + } + +} diff --git a/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/VespaCliTestRunner.java b/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/VespaCliTestRunner.java index 6405904cd91..f131292597c 100644 --- a/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/VespaCliTestRunner.java +++ b/vespa-osgi-testrunner/src/main/java/com/yahoo/vespa/testrunner/VespaCliTestRunner.java @@ -84,13 +84,10 @@ public class VespaCliTestRunner implements TestRunner { try { TestConfig testConfig = TestConfig.fromJson(config); process = testRunProcessBuilder(suite, testConfig).start(); - BufferedReader in = new BufferedReader(new InputStreamReader(process.getInputStream())); - in.lines().forEach(line -> { - if (line.length() > 1 << 13) - line = line.substring(0, 1 << 13) + " ... (this log entry was truncated due to size)"; - log(Level.INFO, line, null); - }); + HtmlLogger htmlLogger = new HtmlLogger(); + BufferedReader in = new BufferedReader(new InputStreamReader(process.getInputStream())); + in.lines().forEach(line -> log(htmlLogger.toLog(line))); status.set(process.waitFor() == 0 ? SUCCESS : process.waitFor() == 3 ? FAILURE : ERROR); } catch (Exception e) { @@ -139,6 +136,10 @@ public class VespaCliTestRunner implements TestRunner { private void log(Level level, String message, Throwable thrown) { LogRecord record = new LogRecord(level, message); record.setThrown(thrown); + log(record); + } + + private void log(LogRecord record) { logger.log(record); log.put(record.getSequenceNumber(), record); } diff --git a/vespa-osgi-testrunner/src/test/java/com/yahoo/vespa/testrunner/HtmlLoggerTest.java b/vespa-osgi-testrunner/src/test/java/com/yahoo/vespa/testrunner/HtmlLoggerTest.java new file mode 100644 index 00000000000..cddb07dc4a6 --- /dev/null +++ b/vespa-osgi-testrunner/src/test/java/com/yahoo/vespa/testrunner/HtmlLoggerTest.java @@ -0,0 +1,32 @@ +// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.vespa.testrunner; + +import org.fusesource.jansi.Ansi; +import org.junit.jupiter.api.Test; + +import java.util.List; +import java.util.logging.LogRecord; + +import static org.junit.jupiter.api.Assertions.assertEquals; + +/** + * @author jonmv + */ +class HtmlLoggerTest { + + @Test + void testConversionToHtml() { + String splitMessage = Ansi.ansi().fg(Ansi.Color.RED).a("</body>Hello!\ncontinued").reset().toString(); + List<String> messages = List.of(splitMessage.split("\n")); + LogRecord html0 = new HtmlLogger().toLog(messages.get(0)); + assertEquals("html", html0.getLevel().getName()); + assertEquals("<span style=\"color: red;\"></body>Hello!</span>", + html0.getMessage()); + + LogRecord html1 = new HtmlLogger().toLog(messages.get(1)); + assertEquals("html", html1.getLevel().getName()); + assertEquals("continued", + html1.getMessage()); + } + +} diff --git a/vespa-testrunner-components/pom.xml b/vespa-testrunner-components/pom.xml index cb84f321f87..4b4b0cfa92c 100644 --- a/vespa-testrunner-components/pom.xml +++ b/vespa-testrunner-components/pom.xml @@ -42,12 +42,6 @@ </dependency> <dependency> - <groupId>org.fusesource.jansi</groupId> - <artifactId>jansi</artifactId> - <version>1.11</version> - </dependency> - - <dependency> <groupId>junit</groupId> <artifactId>junit</artifactId> <scope>test</scope> diff --git a/vespa-testrunner-components/src/main/java/com/yahoo/vespa/hosted/testrunner/TestRunner.java b/vespa-testrunner-components/src/main/java/com/yahoo/vespa/hosted/testrunner/TestRunner.java index 6f12535c317..69296c23fa0 100644 --- a/vespa-testrunner-components/src/main/java/com/yahoo/vespa/hosted/testrunner/TestRunner.java +++ b/vespa-testrunner-components/src/main/java/com/yahoo/vespa/hosted/testrunner/TestRunner.java @@ -3,16 +3,11 @@ package com.yahoo.vespa.hosted.testrunner; import com.google.inject.Inject; import com.yahoo.vespa.defaults.Defaults; -import org.fusesource.jansi.AnsiOutputStream; -import org.fusesource.jansi.HtmlAnsiOutputStream; +import com.yahoo.vespa.testrunner.HtmlLogger; -import java.io.BufferedOutputStream; import java.io.BufferedReader; -import java.io.ByteArrayOutputStream; -import java.io.FileOutputStream; import java.io.IOException; import java.io.InputStreamReader; -import java.io.PrintStream; import java.io.UncheckedIOException; import java.nio.file.Files; import java.nio.file.Path; @@ -30,7 +25,6 @@ import java.util.logging.Logger; import java.util.stream.Collectors; import java.util.stream.Stream; -import static java.nio.charset.StandardCharsets.UTF_8; import static java.util.logging.Level.SEVERE; /** @@ -40,7 +34,6 @@ import static java.util.logging.Level.SEVERE; public class TestRunner implements com.yahoo.vespa.testrunner.TestRunner { private static final Logger logger = Logger.getLogger(TestRunner.class.getName()); - private static final Level HTML = new Level("html", 1) { }; private static final Path vespaHome = Paths.get(Defaults.getDefaults().vespaHome()); private static final String settingsXml = "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n" + "<settings xmlns=\"http://maven.apache.org/SETTINGS/1.0.0\"\n" + @@ -57,7 +50,6 @@ public class TestRunner implements com.yahoo.vespa.testrunner.TestRunner { private final Path artifactsPath; private final Path testPath; - private final Path logFile; private final Path configFile; private final Path settingsFile; private final Function<TestProfile, ProcessBuilder> testBuilder; @@ -69,16 +61,14 @@ public class TestRunner implements com.yahoo.vespa.testrunner.TestRunner { public TestRunner(TestRunnerConfig config) { this(config.artifactsPath(), vespaHome.resolve("tmp/test"), - vespaHome.resolve("logs/vespa/maven.log"), vespaHome.resolve("tmp/config.json"), vespaHome.resolve("tmp/settings.xml"), profile -> mavenProcessFrom(profile, config)); } - TestRunner(Path artifactsPath, Path testPath, Path logFile, Path configFile, Path settingsFile, Function<TestProfile, ProcessBuilder> testBuilder) { + TestRunner(Path artifactsPath, Path testPath, Path configFile, Path settingsFile, Function<TestProfile, ProcessBuilder> testBuilder) { this.artifactsPath = artifactsPath; this.testPath = testPath; - this.logFile = logFile; this.configFile = configFile; this.settingsFile = settingsFile; this.testBuilder = testBuilder; @@ -154,29 +144,17 @@ public class TestRunner implements com.yahoo.vespa.testrunner.TestRunner { } boolean success; - // The AnsiOutputStream filters out ANSI characters, leaving the file contents pure. - try (PrintStream fileStream = new PrintStream(new AnsiOutputStream(new BufferedOutputStream(new FileOutputStream(logFile.toFile())))); - ByteArrayOutputStream logBuffer = new ByteArrayOutputStream(); - PrintStream logPlainFormatter = new PrintStream(new AnsiOutputStream(logBuffer)); - PrintStream logFormatter = new PrintStream(new HtmlAnsiOutputStream(logBuffer))){ + try { writeTestApplicationPom(testProfile); Files.write(configFile, testConfig); Files.write(settingsFile, settingsXml.getBytes()); Process mavenProcess = builder.start(); BufferedReader in = new BufferedReader(new InputStreamReader(mavenProcess.getInputStream())); + HtmlLogger htmlLogger = new HtmlLogger(); in.lines().forEach(line -> { - fileStream.println(line); - logFormatter.print(line); - String message = logBuffer.toString(UTF_8); - if (message.length() > 1 << 13) { - logBuffer.reset(); - logPlainFormatter.print(line); // Avoid HTML since we don't know what we'll strip here. - message = logBuffer.toString(UTF_8).substring(0, 1 << 13) + " ... (this log entry was truncated due to size)"; - } - LogRecord record = new LogRecord(HTML, message); - log.put(record.getSequenceNumber(), record); - logBuffer.reset(); + LogRecord html = htmlLogger.toLog(line); + log.put(html.getSequenceNumber(), html); }); success = mavenProcess.waitFor() == 0; } @@ -185,11 +163,6 @@ public class TestRunner implements com.yahoo.vespa.testrunner.TestRunner { record.setThrown(exception); logger.log(record); log.put(record.getSequenceNumber(), record); - try (PrintStream file = new PrintStream(new FileOutputStream(logFile.toFile(), true))) { - file.println(record.getMessage()); - exception.printStackTrace(file); - } - catch (IOException ignored) { } status = exception instanceof NoTestsException ? Status.FAILURE : Status.ERROR; return; } diff --git a/vespa-testrunner-components/src/test/java/com/yahoo/vespa/hosted/testrunner/TestRunnerTest.java b/vespa-testrunner-components/src/test/java/com/yahoo/vespa/hosted/testrunner/TestRunnerTest.java index b513dfba8b5..2b2c30790c9 100644 --- a/vespa-testrunner-components/src/test/java/com/yahoo/vespa/hosted/testrunner/TestRunnerTest.java +++ b/vespa-testrunner-components/src/test/java/com/yahoo/vespa/hosted/testrunner/TestRunnerTest.java @@ -30,7 +30,6 @@ public class TestRunnerTest { private Path artifactsPath; private Path testPath; - private Path logFile; private Path configFile; private Path settingsFile; @@ -40,31 +39,14 @@ public class TestRunnerTest { Files.createFile(artifactsPath.resolve("my-tests.jar")); Files.createFile(artifactsPath.resolve("my-fat-test.jar")); testPath = tmp.newFolder("testData").toPath(); - logFile = tmp.newFile("maven.log").toPath(); configFile = tmp.newFile("testConfig.json").toPath(); settingsFile = tmp.newFile("settings.xml").toPath(); } @Test - public void ansiCodesAreConvertedToHtml() throws InterruptedException { - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, - __ -> new ProcessBuilder("echo", Ansi.ansi().fg(Ansi.Color.RED).a("Hello!").reset().toString())); - runner.test(SYSTEM_TEST, new byte[0]); - while (runner.getStatus() == TestRunner.Status.RUNNING) { - Thread.sleep(10); - } - Iterator<LogRecord> log = runner.getLog(-1).iterator(); - log.next(); - LogRecord record = log.next(); - assertEquals("<span style=\"color: red;\">Hello!</span>", record.getMessage()); - assertEquals(0, runner.getLog(record.getSequenceNumber()).size()); - assertEquals(TestRunner.Status.SUCCESS, runner.getStatus()); - } - - @Test public void noTestJarIsAFailure() throws InterruptedException, IOException { Files.delete(artifactsPath.resolve("my-tests.jar")); - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, + TestRunner runner = new TestRunner(artifactsPath, testPath, configFile, settingsFile, __ -> new ProcessBuilder("This is a command that doesn't exist, for sure!")); runner.test(SYSTEM_TEST, new byte[0]); while (runner.getStatus() == TestRunner.Status.RUNNING) { @@ -80,7 +62,7 @@ public class TestRunnerTest { @Test public void errorLeadsToError() throws InterruptedException { - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, + TestRunner runner = new TestRunner(artifactsPath, testPath, configFile, settingsFile, __ -> new ProcessBuilder("false")); runner.test(SYSTEM_TEST, new byte[0]); while (runner.getStatus() == TestRunner.Status.RUNNING) { @@ -92,7 +74,7 @@ public class TestRunnerTest { @Test public void failureLeadsToFailure() throws InterruptedException { - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, + TestRunner runner = new TestRunner(artifactsPath, testPath, configFile, settingsFile, __ -> new ProcessBuilder("false")); runner.test(SYSTEM_TEST, new byte[0]); while (runner.getStatus() == TestRunner.Status.RUNNING) { @@ -104,7 +86,7 @@ public class TestRunnerTest { @Test public void filesAreGenerated() throws InterruptedException, IOException { - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, + TestRunner runner = new TestRunner(artifactsPath, testPath, configFile, settingsFile, __ -> new ProcessBuilder("echo", "Hello!")); runner.test(SYSTEM_TEST, "config".getBytes()); while (runner.getStatus() == TestRunner.Status.RUNNING) { @@ -113,12 +95,11 @@ public class TestRunnerTest { assertEquals("config", new String(Files.readAllBytes(configFile))); assertTrue(Files.exists(testPath.resolve("pom.xml"))); assertTrue(Files.exists(settingsFile)); - assertEquals("Hello!\n", new String(Files.readAllBytes(logFile))); } @Test public void runnerCanBeReused() throws InterruptedException, IOException { - TestRunner runner = new TestRunner(artifactsPath, testPath, logFile, configFile, settingsFile, + TestRunner runner = new TestRunner(artifactsPath, testPath, configFile, settingsFile, __ -> new ProcessBuilder("sleep", "0.1")); runner.test(SYSTEM_TEST, "config".getBytes()); assertEquals(TestRunner.Status.RUNNING, runner.getStatus()); |