On Fri, 24 Nov 2023 17:13:30 GMT, Jaikiran Pai <[email protected]> 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
