8367318: Test vmTestbase/nsk/jdi/MethodEntryRequest/addClassFilter_rt/filter_rt001/TestDescription.java timed out after passing

[plummercj]

Fixed an issue with a race with two events coming in close to the same time, the first of which does not suspend any debuggee threads. More details in the first comment.

Tested by running all vmTestbase/nsk/jdi tests 25x times on all platforms both with and w/o virtual threads. Also ran all tier5 svc tests.

---

Progress

• Change must be properly reviewed (1 review required, with at least 1 Reviewer)
• Change must not contain extraneous whitespace
• Commit message must refer to an issue

Issue

• JDK-8367318: Test vmTestbase/nsk/jdi/MethodEntryRequest/addClassFilter_rt/filter_rt001/TestDescription.java timed out after passing (Bug - P4)

Reviewers

• Alex Menkov (@alexmenkov - Reviewer)
• Serguei Spitsyn (@sspitsyn - Reviewer)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk.git pull/27370/head:pull/27370
$ git checkout pull/27370

Update a local copy of the PR:
$ git checkout pull/27370
$ git pull https://git.openjdk.org/jdk.git pull/27370/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 27370

View PR using the GUI difftool:
$ git pr show -t 27370

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk/pull/27370.diff

Using Webrev

Link to Webrev Comment

[bridgekeeper]

👋 Welcome back cjplummer! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

[plummercj]

The test is dealing with two events. The first event is a MethodExitEvent. The request for it uses SUSPEND_NONE, so the debuggee is not suspended when this event is generated. The second is a BreakpointEvent that is part of the "breakpoint for communication" support. It uses SUSPEND_ALL.

For the MethodExitEvent, the test uses EventHandler.waitForRequestedEvent(), which relies mostly on waitForRequestedEventCommon(). This is where the bug is. It sets up an EventHandler listener, and waits for the listener to be called for the MethodExitEvent.

            while (!isDisconnected() && en.set == null && timeLeft > 0) {
                EventHandler.this.wait(timeLeft);
                timeLeft = timeToFinish - System.currentTimeMillis();
            }

The listener will store the EventSet in en.set and the Event in en.event. The event comes in as expected and the listener does a notifyAll() to wakeup the wait(). The problem is before the wait() actually wakes up, the BreakpointEvent comes in. This is because the MethodExitEvent was delivered with SUSPEND_NONE, so the debuggee has continued on to the breakpoint. This means the listener gets called again, even though the MethodExitEvent was already delivered. The listener clears out the en.set field, and then sees that the BreakpointEvent is not the one that was requested, so it returns but leaves en.set set to null. At this point the wait() above returns. It does the "en.set == null" check, and falls back into another wait() call. This one never wakes up with a notifyAll(), but does time out after 5 minutes. There is no error reported when it times out even though en.set is still null. en.event is still properly set, and this is what waitForRequestedEvent() returns, so in the end the test passes, but only after the extra 5 minute delay.

The fix is pretty simple. In the EventHandler listener, if we already got the event we are looking for, then ignore any others that come in.

Note I also removed the synchronize(EventHandler.this) from the listener. EventHandler.run() already does the same synchronize before calling the listener. I did the same in the listener being used for the "breakoint for communication". I checked all other eventReceived() callbacks, and didn't find any others using this synchronization.

[openjdk]

@plummercj This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8367318: Test vmTestbase/nsk/jdi/MethodEntryRequest/addClassFilter_rt/filter_rt001/TestDescription.java timed out after passing

Reviewed-by: amenkov, sspitsyn

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 190 new commits pushed to the master branch:

• a80ba62: 8357691: File blocked.certs contains bad content when boot jdk 25 is used, sun/security/lib/CheckBlockedCerts.java failing
• b90799c: 8368616: runtime/cds/appcds/aotCache/JavaAgent.java#dynamic fails on non CDS platforms/builds after JDK-8362561
• 8730780: 8368006: Parallel: Skip full regions in dense prefix during Full GC
• ... and 187 more: https://git.openjdk.org/jdk/compare/075ebb4ee592c10879799a68ba79f782ee49b60d...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

[openjdk]

@plummercj The following label will be automatically applied to this pull request:

• serviceability

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

[mlbridge]

Webrevs

• 01: Full - Incremental (1849f079)
• 00: Full (6eac67ab)

[plummercj]

Ping!

[alexmenkov]

The fix looks good.

Note I also removed the synchronize(EventHandler.this) from the listener. EventHandler.run() already does the same synchronize before calling the listener. I did the same in the listener being used for the "breakoint for communication". I checked all other eventReceived() callbacks, and didn't find any others using this synchronization.

I see the same synchronization in the listener for VMDisconnectEvent (starting from line 345 in EventHandler.java)

[plummercj]

I see the same synchronization in the listener for VMDisconnectEvent (starting from line 345 in EventHandler.java)

Ok. I've cleaned that one up now.

[sspitsyn]

Looks good.

[plummercj]

Thank you for the reviews Alex and Serguei!

/integrate

[openjdk]

Going to push as commit 3d97e17.
Since your change was applied there have been 218 commits pushed to the master branch:

• aabf699: 8355339: Test java/io/File/GetCanonicalPath.java failed: The specified network name is no longer available
• 9d71af1: 8367253: RISC-V: refactor dependent cpu extensions
• 63688d8: 8368822: Refactor Float16.valueOf(double)
• ... and 215 more: https://git.openjdk.org/jdk/compare/075ebb4ee592c10879799a68ba79f782ee49b60d...master

Your commit was automatically rebased without conflicts.

[openjdk]

@plummercj Pushed as commit 3d97e17.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.