RFR: 7903441: System.out and System.err messages are missing in jtr file when a test times out in agentvm mode

Jaikiran Pai jpai at openjdk.org
Wed May 10 11:55:57 UTC 2023


Can I please get a review of this change which proposes to fix the issue reported in https://bugs.openjdk.org/browse/CODETOOLS-7903441?

As noted in that issue, when a test timeouts when run in the agent vm mode, it has been noticed that the System.out/System.err messages that were written by the test are lost and not present in the .jtr file of that test.

There are 2 parts to this issue and this PR thus has 2 separate commits to help review this.

Agent VM test execution involves communicating between processes - the jtreg process (a.k.a `Agent`) and the process that is executing the test case (a.k.a `AgentServer`), through sockets. One part of this communication involves sending across the System.out and System.err generated messages from the `AgentServer` VM to the `Agent`. As part of https://bugs.openjdk.org/browse/CODETOOLS-7902198, work was done to help send across these messages in a timely fashion. One part of that change involves converting the byte oriented messages into characters. This is done using a `CharsetDecoder` which decodes `ByteBuffer` contents to a `CharBuffer`. Once the decoded content lands into the `charBuffer` it stays in that buffer until either the OutputStream is closed or the `charBuffer` capacity has been reached. Even a `flush()` call doesn't push out these decoded characters into the target/underlying OutputStream and that results in lost messages. The commit https://github.com/openjdk/jtreg/com
 mit/578e103dcb911c07c59007138e62a78c3abba6d7 in this PR addresses that by making sure `flush()` operation on the `OutputStream` does indeed flush the decoded characters to the underlying stream, thus allowing it to reach the other process.

In the current jtreg code, the compile action and main action implementation on the `AgentServer` side both use `autoFlush=true` for `System.err` but not for `System.out`, I couldn't find an explanation why `System.out` explicitly sets `autoFlush=false`. The additional commit https://github.com/openjdk/jtreg/commit/1d08b7656d46c124730c6844fefc595804266d36 in this PR addresses this by setting `System.out` as `autoFlush=true`. Auto-flush is defined by `java.io.PrintStream` as:

> Optionally, a {@code PrintStream} can be created so as to flush automatically; this means that the {@code flush} method of the underlying output stream is automatically invoked after a byte array is written, one of the {@code println} methods is invoked, or a newline character or byte ({@code '\n'}) is written.

This change should reduce the chances of a message being lost when written to `System.out` in agent VM mode. In my opinion, tests that use `System.out` (and `System.err`) would ideally want this auto-flush behaviour to match what they get out of regular `System.out` instance when running as a regular application. 

I tested these changes against the reproducer that's attached to the JBS issue and it now correctly logs the System.out and System.err messages and are available in the .jtr file on timeout. I've run `tier1`, `tier2` and `tier3` tests with a jtreg version which contains this fix and the tests completed without any related failures/regressions. I'm in the process of trying to trigger a test that is known to timeout (like the reproducer in the JBS issue) on our CI system to make sure the logs are indeed now available in the .jtr file.

-------------

Commit messages:
 - 7903441: autoFlush System.out that's used by the compile and main actions
 - 7903441: Flush the decoded characters when flush() is called

Changes: https://git.openjdk.org/jtreg/pull/155/files
 Webrev: https://webrevs.openjdk.org/?repo=jtreg&pr=155&range=00
  Issue: https://bugs.openjdk.org/browse/CODETOOLS-7903441
  Stats: 14 lines in 3 files changed: 11 ins; 0 del; 3 mod
  Patch: https://git.openjdk.org/jtreg/pull/155.diff
  Fetch: git fetch https://git.openjdk.org/jtreg.git pull/155/head:pull/155

PR: https://git.openjdk.org/jtreg/pull/155


More information about the jtreg-dev mailing list