RFR: 8320699: Add parameter to skip progress logging of OutputAnalyzer
Jaikiran Pai
jpai at openjdk.org
Fri Nov 24 17:04:05 UTC 2023
On Fri, 24 Nov 2023 10:34:02 GMT, Stefan Karlsson <stefank 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.
Hello Stefan, I agree with David that I have found these logs to be useful - it shows that process launched by the test hasn't yet finished and is being waited upon. The log message when written will have a timestamp and can then also help to quickly understand how long it could have taken for this process to complete.
> Right now I much more annoyed by the log files filling up with thousands upon thousands lines of noise, making it harder to actually find the status of the test.
This I agree with. It's a co-incidence that just this week when I was looking at some test logs I happened to see such large amount of unexpected logging (not thousands, but large enough). For example:
[2023-11-24T11:47:54.557561Z] Waiting for completion for process 24909
[2023-11-24T11:47:54.557873Z] Waiting for completion finished for process 24909
[2023-11-24T11:47:54.612609Z] Waiting for completion for process 24909
[2023-11-24T11:47:54.612682Z] Waiting for completion finished for process 24909
[2023-11-24T11:47:54.614500Z] Waiting for completion for process 24909
[2023-11-24T11:47:54.614542Z] Waiting for completion finished for process 24909
[2023-11-24T11:47:54.640945Z] Waiting for completion for process 24909
[2023-11-24T11:47:54.641115Z] Waiting for completion finished for process 24909
I wonder if something else is going on here, because looking at these logs messages it says that it has finished waiting for a process 24909, yet it keeps repeating those messages. I would have expected it to stop logging after the first:
Waiting for completion finished for process 24909
I haven't yet had a chance to look at the code to see if there's some bug which is contributing to this extensive logging.
-------------
PR Comment: https://git.openjdk.org/jdk/pull/16807#issuecomment-1825923223
More information about the core-libs-dev
mailing list