RFR: 8320699: Add parameter to skip progress logging of OutputAnalyzer
David Holmes
dholmes at openjdk.org
Sat Nov 25 00:08:04 UTC 2023
On Fri, 24 Nov 2023 17:13:30 GMT, Jaikiran Pai <jpai at openjdk.org> wrote:
>> Tests using ProcessTools.executeProcess gets the following output written to stdout:
>> [2023-11-24T09:58:16.797540608Z] Gathering output for process 2517117
>> [2023-11-24T09:58:23.070781345Z] Waiting for completion for process 2517117
>> [2023-11-24T09:58:23.071045055Z] Waiting for completion finished for process 2517117
>>
>> This might be good for some use cases and debugging, but some tests spawns a large number of processes and for those this output fills up the log files.
>>
>> I propose that we add a way to turn of this output for tests where we find this output to be too noisy.
>
> Perhaps this would help improve/fix the log flooding:
>
>
> diff --git a/test/lib/jdk/test/lib/process/OutputBuffer.java b/test/lib/jdk/test/lib/process/OutputBuffer.java
> index 3741ccbe2ff..02aedf29f6a 100644
> --- a/test/lib/jdk/test/lib/process/OutputBuffer.java
> +++ b/test/lib/jdk/test/lib/process/OutputBuffer.java
> @@ -120,6 +120,7 @@ public String get() {
> private final StreamTask outTask;
> private final StreamTask errTask;
> private final Process p;
> + private volatile Integer processExitCode; // null represents process hasn't yet exited
>
> private final void logProgress(String state) {
> System.out.println("[" + Instant.now().toString() + "] " + state
> @@ -146,14 +147,18 @@ public String getStderr() {
>
> @Override
> public int getExitValue() {
> + Integer exitCode = this.processExitCode;
> + if (exitCode != null) {
> + return exitCode;
> + }
> try {
> logProgress("Waiting for completion");
> boolean aborted = true;
> try {
> - int result = p.waitFor();
> + processExitCode = exitCode = p.waitFor();
> logProgress("Waiting for completion finished");
> aborted = false;
> - return result;
> + return exitCode;
> } finally {
> if (aborted) {
> logProgress("Waiting for completion FAILED");
>
>
> Other than a quick local test run, I haven't tested it for anything else. It did improve the situation in one of my test and it now only logs it once. In the setup that you are seeing this large amount of logging, would you be able to see if this change helps there too?
@jaikiran that looks like a good fix to me. It doesn't make sense to keep repeating the logging on every `getExitValue` call. Good find!
-------------
PR Comment: https://git.openjdk.org/jdk/pull/16807#issuecomment-1826150703
More information about the core-libs-dev
mailing list