Skip to content

Commit

Permalink
Initial error reporting test listener that mirrors failed suite's out…
Browse files Browse the repository at this point in the history
…put.
  • Loading branch information
dweiss committed Jan 7, 2020
1 parent 405d227 commit 14dd5a5
Show file tree
Hide file tree
Showing 5 changed files with 368 additions and 0 deletions.
5 changes: 5 additions & 0 deletions buildSrc/build.gradle
Original file line number Diff line number Diff line change
@@ -1,3 +1,8 @@

// Make sure the build environment is consistent.
apply from: file('../gradle/validation/check-environment.gradle')

dependencies {
implementation gradleApi()
implementation localGroovy()
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,215 @@
package org.apache.lucene.gradle;

This comment has been minimized.

Copy link
@madrob

madrob Jan 7, 2020

Contributor

License header


import java.io.Closeable;
import java.io.IOException;
import java.io.PrintStream;
import java.io.UncheckedIOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.Map;
import java.util.Objects;
import java.util.concurrent.ConcurrentHashMap;
import org.gradle.api.internal.tasks.testing.logging.FullExceptionFormatter;
import org.gradle.api.internal.tasks.testing.logging.TestExceptionFormatter;
import org.gradle.api.logging.Logger;
import org.gradle.api.logging.Logging;
import org.gradle.api.tasks.testing.TestDescriptor;
import org.gradle.api.tasks.testing.TestListener;
import org.gradle.api.tasks.testing.TestOutputEvent;
import org.gradle.api.tasks.testing.TestOutputListener;
import org.gradle.api.tasks.testing.TestResult;
import org.gradle.api.tasks.testing.logging.TestLogging;

/**
* An error reporting listener that queues test output streams and displays them
* on failure.
* <p>
* Heavily inspired by Elasticsearch's ErrorReportingTestListener (ASL 2.0 licensed).
*/
public class ErrorReportingTestListener implements TestOutputListener, TestListener {
private static final Logger LOGGER = Logging.getLogger(ErrorReportingTestListener.class);

private final TestExceptionFormatter formatter;
private final Map<TestKey, OutputHandler> outputHandlers = new ConcurrentHashMap<>();
private final Path spillDir;

public ErrorReportingTestListener(TestLogging testLogging, Path spillDir) {
this.formatter = new FullExceptionFormatter(testLogging);
this.spillDir = spillDir;
}

@Override
public void onOutput(TestDescriptor testDescriptor, TestOutputEvent outputEvent) {
TestDescriptor suite = testDescriptor.getParent();

// Check if this is output from the test suite itself (e.g. afterTest or beforeTest)
if (testDescriptor.isComposite()) {
suite = testDescriptor;
}

handlerFor(suite).write(outputEvent);
}

@Override
public void beforeSuite(TestDescriptor suite) {
// noop.
}

@Override
public void beforeTest(TestDescriptor testDescriptor) {
// Noop.
}

@Override
public void afterSuite(final TestDescriptor suite, TestResult result) {
TestKey key = TestKey.of(suite);
try {
// if the test suite failed, report all captured output
if (Objects.equals(result.getResultType(), TestResult.ResultType.FAILURE)) {
reportFailure(suite, outputHandlers.get(key));
}
} catch (IOException e) {
throw new UncheckedIOException("Error reading test suite output", e);
} finally {
OutputHandler writer = outputHandlers.remove(key);
if (writer != null) {
try {
writer.close();
} catch (IOException e) {
LOGGER.error("Failed to close test suite's event writer for: " + key, e);
}
}
}
}

private void reportFailure(TestDescriptor suite, OutputHandler outputHandler) throws IOException {
if (outputHandler != null) {
synchronized (this) {
System.out.println("");
System.out.println(suite.getClassName() + " > test suite's output copied below:");
outputHandler.copyTo(System.out);
}
}
}

@Override
public void afterTest(TestDescriptor testDescriptor, TestResult result) {
// Include test failure exception stacktrace(s) in test output log.
if (result.getResultType() == TestResult.ResultType.FAILURE) {
if (testDescriptor.getParent() != null) {
if (result.getExceptions().size() > 0) {
String message = formatter.format(testDescriptor, result.getExceptions());
handlerFor(testDescriptor.getParent()).write(message);
}
}
}
}

private OutputHandler handlerFor(TestDescriptor suite) {
return outputHandlers.computeIfAbsent(TestKey.of(suite), (key) -> new OutputHandler());
}

public static class TestKey {
private final String key;

private TestKey(String key) {
this.key = key;
}

public static TestKey of(TestDescriptor d) {
StringBuilder key = new StringBuilder();
key.append(d.getClassName());
key.append("::");
key.append(d.getName());
key.append("::");
key.append(d.getParent() == null ? "-" : d.getParent().toString());
return new TestKey(key.toString());
}

@Override
public boolean equals(Object o) {
return o != null &&
o.getClass() == this.getClass() &&
Objects.equals(((TestKey) o).key, key);
}

@Override
public int hashCode() {
return key.hashCode();
}

@Override
public String toString() {
return key;
}
}

private class OutputHandler implements Closeable {
// Max single-line buffer before automatic wrap occurs.
private static final int MAX_LINE_WIDTH = 1024 * 4;

private final SpillWriter buffer;

// internal stream.
private final PrefixedWriter sint;
// stdout
private final PrefixedWriter sout;
// stderr
private final PrefixedWriter serr;

// last used stream (so that we can flush it properly and prefixes are not screwed up).
private PrefixedWriter last;

public OutputHandler() {
buffer = new SpillWriter(() -> {
try {
return Files.createTempFile(spillDir, "spill-", ".tmp");
} catch (IOException e) {
throw new UncheckedIOException(e);
}
});

sint = new PrefixedWriter(" > ", buffer, MAX_LINE_WIDTH);
sout = new PrefixedWriter(" 1> ", buffer, MAX_LINE_WIDTH);
serr = new PrefixedWriter(" 2> ", buffer, MAX_LINE_WIDTH);
last = sint;
}

public void write(TestOutputEvent event) {
write((event.getDestination() == TestOutputEvent.Destination.StdOut ? sout : serr), event.getMessage());
}

public void write(String message) {
write(sint, message);
}

private void write(PrefixedWriter out, String message) {
try {
if (out != last) {
last.completeLine();
last = out;
}
out.write(message);
} catch (IOException e) {
throw new UncheckedIOException("Unable to write to test output.", e);
}
}

public void copyTo(PrintStream out) throws IOException {
flush();
buffer.copyTo(out);
out.println();
}

public void flush() throws IOException {
sout.completeLine();
serr.completeLine();
buffer.flush();
}

@Override
public void close() throws IOException {
buffer.close();
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,65 @@
package org.apache.lucene.gradle;

import java.io.IOException;
import java.io.Writer;

/**
* Prefixes every new line with a given string, synchronizing multiple streams to emit consistent lines.
*/
public class PrefixedWriter extends Writer {
Writer sink;

private final static char LF = '\n';
private final String prefix;
private final StringBuilder lineBuffer = new StringBuilder();
private final int maxLineLength;

public PrefixedWriter(String prefix, Writer sink, int maxLineLength) {
super(sink);
this.sink = sink;
this.prefix = prefix;
this.maxLineLength = maxLineLength;
}

@Override
public void write(int c) throws IOException {
if (lineBuffer.length() == maxLineLength || c == LF) {
sink.write(prefix);
sink.write(lineBuffer.toString());
sink.write(LF);

lineBuffer.setLength(0);
if (c != LF) {
lineBuffer.append((char) c);
}
} else {
lineBuffer.append((char) c);

This comment has been minimized.

Copy link
@madrob

madrob Jan 7, 2020

Contributor

Our use of write(String) goes through write(char[], int, int) and eventually makes its way here where we will be appending a single character at a time. I've seen this turn into a performance bottleneck in other places before, much better to try and process bigger chunks at a time if we can.

This comment has been minimized.

Copy link
@dweiss

dweiss Jan 8, 2020

Author Contributor

Correct. I didn't want to expand it to keep it simple but you're right that we should.

}
}

@Override
public void write(char[] cbuf, int off, int len) throws IOException {
for (int i = off; i < off + len; i++) {
write(cbuf[i]);
}
}

@Override
public void flush() throws IOException {
// don't pass flushes.
}

@Override
public void close() throws IOException {
throw new UnsupportedOperationException();
}

/**
* Complete the current line (emit LF if not at the start of the line already).
*/
public void completeLine() throws IOException {
if (lineBuffer.length() > 0) {
write(LF);
}
}
}
73 changes: 73 additions & 0 deletions buildSrc/src/main/java/org/apache/lucene/gradle/SpillWriter.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,73 @@
package org.apache.lucene.gradle;

import java.io.IOException;
import java.io.PrintStream;
import java.io.Reader;
import java.io.StringWriter;
import java.io.Writer;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.function.Supplier;

public class SpillWriter extends Writer {
private final static int MAX_BUFFERED = 2 * 1024;
private final StringWriter buffer = new StringWriter(MAX_BUFFERED);

private final Supplier<Path> spillPathSupplier;
private Writer spill;
private Path spillPath;

public SpillWriter(Supplier<Path> spillPathSupplier) {
this.spillPathSupplier = spillPathSupplier;
}

@Override
public void write(char[] cbuf, int off, int len) throws IOException {
getSink(len).write(cbuf, off, len);
}

private Writer getSink(int expectedWriteChars) throws IOException {
if (spill == null) {
if (buffer.getBuffer().length() + expectedWriteChars <= MAX_BUFFERED) {
return buffer;
}

spillPath = spillPathSupplier.get();
spill = Files.newBufferedWriter(spillPath, StandardCharsets.UTF_8);
spill.append(buffer.getBuffer());
buffer.getBuffer().setLength(0);
}

return spill;
}

@Override
public void flush() throws IOException {
getSink(0).flush();
}

@Override
public void close() throws IOException {
buffer.close();
if (spill != null) {
spill.close();
Files.delete(spillPath);
}
}

public void copyTo(PrintStream ps) throws IOException {
if (spill != null) {
flush();
char [] buf = new char [MAX_BUFFERED];
try (Reader reader = Files.newBufferedReader(spillPath, StandardCharsets.UTF_8)) {
int len;
while ((len = reader.read(buf)) >= 0) {
ps.print(new String(buf, 0, len));
}
}
} else {
ps.append(buffer.getBuffer());
}
}
}
10 changes: 10 additions & 0 deletions gradle/testing/defaults-tests.gradle
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import org.apache.tools.ant.taskdefs.condition.Os
import org.gradle.api.tasks.testing.logging.*
import org.apache.lucene.gradle.ErrorReportingTestListener

def verboseModeHookInstalled = false

Expand Down Expand Up @@ -71,6 +72,9 @@ allprojects {
testsTmpDir.mkdirs()
}

// Disable HTML report generation. The reports are big and slow to generate.
reports.html.enabled = false

// Set up logging.
if (verboseMode) {
testLogging {
Expand All @@ -92,6 +96,12 @@ allprojects {
showCauses true
showStackTraces true
}

// Set up custom test output handler.
def spillDir = getTemporaryDir().toPath()
def listener = new ErrorReportingTestListener(test.testLogging, spillDir)
addTestOutputListener(listener)
addTestListener(listener)
}

doFirst {
Expand Down

0 comments on commit 14dd5a5

Please sign in to comment.