Pretty print plugin performance issues

[vkuzel]

Pretty print plugin is slow, because:

• Calls flush method on every printed line.
• Use unbuffered output stream.

Combination of previous points results in poor performance. In my situation the plugin doubles the run time.

Single thread

When running Cucumber tests in a single thread, the bottleneck is in the OutputStreamWriter.flush() method.

Multi-threading

When running Cucumber tests in multiple threads, the bottleneck is still in the flush() method. Because printing is called from synchronised SynchronizedEventBus.send() method, a thread has to wait for flush() in other threads, which subsequently kills performance gains from multi-threaded solution.

Expected behaviour

Performance of the NiceAppendable class should be improved to be close to running tests without the plugin. A good idea may be not to flush on every line.

• Version: io.cucumber:cucumber-java:7.2.3
• Tests executed from IntelliJ IDEA 2021.3.2
• Build tool: Gradle 5.3.1
• OS: macOS Monterey 12.1

[mpkorstanje]

Very interesting. I'll have to take a good look.

[mpkorstanje]

When a plugin doesn't write to a file, it defaults to standard out. For this the NiceAppendable provides:

• "Real time" output to System.out by flushing every append
• "Real time" output to System.out by flushing every line.
• Wrapping of exceptions

The first is important important for the progress formatter which only outputs dots. Not flushing immediately would hide the progress indication in the buffer.

The second is important for the pretty formatter. It doesn't need a flush after every append, but the information for each step should be flushed. However the pretty formatter doesn't need to flush every append and I would expect that the underlying print stream already flushes on new lines.

The third is important for the rerun and unused steps formatters. However neither cares about timely output.

So after confirming that the System.out PrintStream flushes automatically on new lines I think we can remove flushing from the NiceAppendable and only explicitly flush in the progress formatter.

[mpkorstanje]

I noticed that Gradle seems to be adding a newline every time cucumber-jvm flushes the output stream. It is a common pattern with text output to flush only when a newline character is appended to the output stream. Do you accept pull requests? I tried to fix this in cucumber-jvm using 3 different methods, and they all worked and took me about 30 seconds each to implement.

Possible Fixes:

1. In DataTableFormatter.java, write to a StringBuilder and then call `appender.append(...)` only once for the entire DataTable.

2. In NiceAppendable.java, only call `tryFlush()` if the text being appended ends in a newline character.

3. Stop flushing at all in NiceAppendable.java, and just use default buffering and flushing.

In issue 2481 it is reported that pretty print is slow because Calls flush method on every printed line.. It seems that flushing less frequently would solve both performance and the display defect. Is this something that could be considered?

Thanks!

@scottadav

1. Would be a good option regardless to ensure multiple concurrent writes to System.out don't cause our output to interleave with others.
   2&3. Yes. With the exception of the progress formatter.

[scottadav]

Pull request submitted. Thanks for the help!

[scottadav]

I submitted separate pull requests. You can choose either one or both.

• 2537 fixes Datatables output by the pretty formatter are displayed incorrectly by gradle #2536 directly, by only making one write for the entire datatable
• 2541 fixes this issue by removing the "flush on every write" behavior for PrettyFormatter, as well as all the other formatters except for ProgressFormatter (which truly needs it). It also fixes Datatables output by the pretty formatter are displayed incorrectly by gradle #2536 as a side-benefit, because that defect was caused by frequent flushing of the output buffer combined with additional Gradle behavior.

[mpkorstanje]

@vkuzel #2541 should be released in a few minutes. Would you mind giving it a try?