RFR: 7903188: Log time spent waiting to acquire exclusive access lock

[Alan Bateman]

On Wed, 19 Jun 2024 09:39:04 GMT, Jaikiran Pai <jpai at openjdk.org> wrote:

> Can I please get a review of this change which proposes to implement the enhancement requested in https://bugs.openjdk.org/browse/CODETOOLS-7903188?
> 
> jtreg supports the ability to sequentially execute tests, instead of concurrently, for tests belonging to a pre-configured `exclusiveAccess.dirs` directory. The `MainAction` and `ShellAction` before launching the test, first acquire a lock. The lock acquisition can be time consuming and depends on how long an already running test from that directory takes to complete. This lock acquisiton time isn't reported anywhere in the jtreg action's `section` in the report. Because of this, it sometimes makes it difficult to determine where the unaccounted time is spent.
> 
> The change in this PR prints out how long it took to acquire a exclusive access before launching the test. It's only printed if the test was configured with exclusiveAccess. The reported message will look like:
> 
> 
> #section:main
> ----------messages:(7/230)----------
> command: main Test
> reason: User specified action: run main Test 
> started: Wed Jun 19 14:45:21 IST 2024
> exclusiveAccess wait time (seconds): 20.289
> Mode: othervm
> finished: Wed Jun 19 14:45:21 IST 2024
> elapsed time (seconds): 0.123
> 
> 
> An existing self test has been updated to verify this change. All existing tests continue to pass with this change.

#section:main
----------messages:(7/230)----------
command: main Test
reason: User specified action: run main Test 
started: Wed Jun 19 14:45:21 IST 2024
exclusiveAccess wait time (seconds): 20.289
Mode: othervm
finished: Wed Jun 19 14:45:21 IST 2024
elapsed time (seconds): 0.123


I wonder if "exclusiveAccess wait time ..." could be printed before the "started ..." line. That is, the waiting happens before the test starts so would be confusing to have a "wait" log message between "started" and "finished".

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

PR Comment: https://git.openjdk.org/jtreg/pull/208#issuecomment-2179961496