Only flush output frequently for ProgressFormatter (#2541)

Co-authored-by: Scott Davis <scott.davis@ticketmaster.com>
Co-authored-by: M.P. Korstanje <rien.korstanje@gmail.com>

CHANGELOG.md

@@ -16,6 +16,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/).
 ### Removed
 
 ### Fixed
+* [Core] Pretty print plugin performance issues; incorrect DataTable format in Gradle console ([#2541](https://github.com/cucumber/cucumber-jvm/pull/2541) Scott Davis)
 
 ## [7.3.2] (2022-04-22)
 

core/src/main/java/io/cucumber/core/plugin/NiceAppendable.java

@@ -11,9 +11,15 @@ final class NiceAppendable implements Appendable {
 
  private static final CharSequence NL = "\n";
  private final Appendable out;
+ private final boolean flushEveryWrite;
 
  public NiceAppendable(Appendable out) {
+ this(out, false);
+ }
+
+ public NiceAppendable(Appendable out, boolean flushEveryWrite) {
  this.out = out;
+ this.flushEveryWrite = flushEveryWrite;
  }
 
  public NiceAppendable println() {
@@ -55,6 +61,10 @@ private void tryFlush() {
  return;
  }
 
+ if (!flushEveryWrite) {
+ return;
+ }
+
  try {
  ((Flushable) out).flush();
  } catch (IOException e) {

core/src/main/java/io/cucumber/core/plugin/PrettyFormatter.java

@@ -181,14 +181,17 @@ private void printError(Result result) {
  }
 
  private void printText(WriteEvent event) {
+ // Prevent interleaving when multiple threads write to System.out
+ StringBuilder builder = new StringBuilder();
  try (BufferedReader lines = new BufferedReader(new StringReader(event.getText()))) {
  String line;
  while ((line = lines.readLine()) != null) {
- out.println(STEP_SCENARIO_INDENT + line);
+ builder.append(String.format(STEP_SCENARIO_INDENT + line + "%n"));
  }
  } catch (IOException e) {
  throw new CucumberException(e);
  }
+ out.append(builder);
  }
 
  private void printEmbedding(EmbedEvent event) {
@@ -230,7 +233,6 @@ private String calculateLocationIndent(TestCase testStep, String prefix) {
  if (padding < 0) {
  return " ";
  }
-
  StringBuilder builder = new StringBuilder(padding);
  for (int i = 0; i < padding; i++) {
  builder.append(" ");

core/src/main/java/io/cucumber/core/plugin/ProgressFormatter.java

@@ -39,7 +39,9 @@ public final class ProgressFormatter implements ConcurrentEventListener, ColorAw
  private boolean monochrome = false;
 
  public ProgressFormatter(OutputStream out) {
- this.out = new NiceAppendable(new UTF8OutputStreamWriter(out));
+ // Configure the NiceAppendable to flush on every append, since the
+ // point of this formatter is to display a progress bar.
+ this.out = new NiceAppendable(new UTF8OutputStreamWriter(out), true);
  }
 
  @Override
@@ -50,22 +52,28 @@ public void setMonochrome(boolean monochrome) {
  @Override
  public void setEventPublisher(EventPublisher publisher) {
  publisher.registerHandlerFor(TestStepFinished.class, this::handleTestStepFinished);
- publisher.registerHandlerFor(TestRunFinished.class, event -> handleTestRunFinished());
+ publisher.registerHandlerFor(TestRunFinished.class, this::handleTestRunFinished);
  }
 
  private void handleTestStepFinished(TestStepFinished event) {
- if (event.getTestStep() instanceof PickleStepTestStep || event.getResult().getStatus().is(Status.FAILED)) {
- if (!monochrome) {
- ANSI_ESCAPES.get(event.getResult().getStatus()).appendTo(out);
- }
- out.append(CHARS.get(event.getResult().getStatus()));
- if (!monochrome) {
- AnsiEscapes.RESET.appendTo(out);
- }
+ boolean isTestStep = event.getTestStep() instanceof PickleStepTestStep;
+ boolean isFailedHookOrTestStep = event.getResult().getStatus().is(Status.FAILED);
+ if (!(isTestStep || isFailedHookOrTestStep)) {
+ return;
  }
+ // Prevent tearing in output when multiple threads write to System.out
+ StringBuilder buffer = new StringBuilder();
+ if (!monochrome) {
+ ANSI_ESCAPES.get(event.getResult().getStatus()).appendTo(buffer);
+ }
+ buffer.append(CHARS.get(event.getResult().getStatus()));
+ if (!monochrome) {
+ AnsiEscapes.RESET.appendTo(buffer);
+ }
+ out.append(buffer);
  }
 
- private void handleTestRunFinished() {
+ private void handleTestRunFinished(TestRunFinished testRunFinished) {
  out.println();
  out.close();
  }

core/src/main/java/io/cucumber/core/plugin/UnusedStepsSummaryPrinter.java

@@ -68,6 +68,8 @@ private void finishReport() {
  String pattern = entry.getValue();
  out.println(format.text(location) + " # " + pattern);
  }
+
+ out.close();
  }
 
  @Override

core/src/test/java/io/cucumber/core/plugin/NiceAppendableTest.java

@@ -0,0 +1,53 @@
+package io.cucumber.core.plugin;
+
+import org.junit.jupiter.api.Test;
+
+import java.io.ByteArrayOutputStream;
+import java.io.IOException;
+import java.io.OutputStreamWriter;
+
+import static io.cucumber.core.plugin.BytesEqualTo.isBytesEqualTo;
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.mockito.Mockito.spy;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
+
+class NiceAppendableTest {
+
+ @Test
+ public void should_flush_every_call_if_configured() throws IOException {
+ ByteArrayOutputStream out = new ByteArrayOutputStream();
+ OutputStreamWriter writer = spy(new OutputStreamWriter(out));
+ NiceAppendable appendable = new NiceAppendable(writer, true);
+
+ appendable
+ .append("First String,")
+ .append("__Second String__", 2, 15)
+ .append("\n")
+ .println("Second line")
+ .println()
+ .close();
+
+ assertThat(out, isBytesEqualTo("First String,Second String\nSecond line\n\n"));
+ verify(writer, times(6)).flush(); // Each method call flushes
+ }
+
+ @Test
+ public void should_not_flush_unless_configured() throws IOException {
+ ByteArrayOutputStream out = new ByteArrayOutputStream();
+ OutputStreamWriter writer = spy(new OutputStreamWriter(out));
+ NiceAppendable appendable = new NiceAppendable(writer);
+
+ appendable
+ .append("First String,")
+ .append("__Second String__", 2, 15)
+ .append("\n")
+ .println("Second line")
+ .println()
+ .close();
+
+ assertThat(out, isBytesEqualTo("First String,Second String\nSecond line\n\n"));
+ verify(writer, times(0)).flush();
+ }
+
+}

core/src/test/java/io/cucumber/core/plugin/ProgressFormatterTest.java

@@ -0,0 +1,85 @@
+package io.cucumber.core.plugin;
+
+import io.cucumber.core.eventbus.EventBus;
+import io.cucumber.core.runtime.TimeServiceEventBus;
+import io.cucumber.plugin.event.HookTestStep;
+import io.cucumber.plugin.event.PickleStepTestStep;
+import io.cucumber.plugin.event.Result;
+import io.cucumber.plugin.event.TestCase;
+import io.cucumber.plugin.event.TestRunFinished;
+import io.cucumber.plugin.event.TestStepFinished;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+
+import java.io.ByteArrayOutputStream;
+import java.time.Clock;
+import java.time.Duration;
+import java.time.Instant;
+import java.util.UUID;
+
+import static io.cucumber.core.plugin.BytesEqualTo.isBytesEqualTo;
+import static io.cucumber.plugin.event.Status.FAILED;
+import static io.cucumber.plugin.event.Status.PASSED;
+import static io.cucumber.plugin.event.Status.UNDEFINED;
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.mockito.Mockito.mock;
+
+class ProgressFormatterTest {
+
+ final EventBus bus = new TimeServiceEventBus(Clock.systemUTC(), UUID::randomUUID);
+ final ByteArrayOutputStream out = new ByteArrayOutputStream();
+ final ProgressFormatter formatter = new ProgressFormatter(out);
+
+ @BeforeEach
+ void setup() {
+ formatter.setEventPublisher(bus);
+ }
+
+ @Test
+ void prints_empty_line_for_empty_test_run() {
+ Result runResult = new Result(PASSED, Duration.ZERO, null);
+ bus.send(new TestRunFinished(Instant.now(), runResult));
+ assertThat(out, isBytesEqualTo("\n"));
+ }
+
+ @Test
+ void print_green_dot_for_passing_step() {
+ Result result = new Result(PASSED, Duration.ZERO, null);
+ bus.send(new TestStepFinished(Instant.now(), mock(TestCase.class), mock(PickleStepTestStep.class), result));
+ bus.send(new TestRunFinished(Instant.now(), result));
+ assertThat(out, isBytesEqualTo(AnsiEscapes.GREEN + "." + AnsiEscapes.RESET + "\n"));
+ }
+
+ @Test
+ void print_yellow_U_for_undefined_step() {
+ Result result = new Result(UNDEFINED, Duration.ZERO, null);
+ bus.send(new TestStepFinished(Instant.now(), mock(TestCase.class), mock(PickleStepTestStep.class), result));
+ bus.send(new TestRunFinished(Instant.now(), result));
+ assertThat(out, isBytesEqualTo(AnsiEscapes.YELLOW + "U" + AnsiEscapes.RESET + "\n"));
+ }
+
+ @Test
+ void print_nothing_for_passed_hook() {
+ Result result = new Result(PASSED, Duration.ZERO, null);
+ bus.send(new TestStepFinished(Instant.now(), mock(TestCase.class), mock(HookTestStep.class), result));
+ bus.send(new TestRunFinished(Instant.now(), result));
+ assertThat(out, isBytesEqualTo("\n"));
+ }
+
+ @Test
+ void print_red_F_for_failed_step() {
+ Result result = new Result(FAILED, Duration.ZERO, null);
+ bus.send(new TestStepFinished(Instant.now(), mock(TestCase.class), mock(PickleStepTestStep.class), result));
+ bus.send(new TestRunFinished(Instant.now(), result));
+ assertThat(out, isBytesEqualTo(AnsiEscapes.RED + "F" + AnsiEscapes.RESET + "\n"));
+ }
+
+ @Test
+ void print_red_F_for_failed_hook() {
+ Result result = new Result(FAILED, Duration.ZERO, null);
+ bus.send(new TestStepFinished(Instant.now(), mock(TestCase.class), mock(HookTestStep.class), result));
+ bus.send(new TestRunFinished(Instant.now(), result));
+ assertThat(out, isBytesEqualTo(AnsiEscapes.RED + "F" + AnsiEscapes.RESET + "\n"));
+ }
+
+}