8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt #14817

plummercj · 2023-07-10T20:17:21Z

After JDK-8308232, both the test and the debuggee shared the same waittime of 5 minutes. The test would wait up to 5 minutes for the expected prompt, but the debuggee would also in some cases wait 5 minutes before generating the prompt, which sometimes was just a bit too late. Before JDK-8308232, the debuggee would wait at most 2 minutes before generating the prompt, so it was always generated in time.

The main issue is that after the while loop checks that there are still uninterrupted threads remaining, the last of the threads is interrupted before the wait() call is made. This means wait() won't return until it times out, and by then it is too late, and the test side has already timed out waiting for the prompt.

The fix is to widen the synchronized block so the count of not interrupted threads remains correct until wait() is entered. The other choice was to refetch the count after entering the synchronized block, which is what I did for the initial fix, but widening seems a better choice so no refetch is needed.

For details see https://bugs.openjdk.org/browse/JDK-8310551?focusedCommentId=14594838&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-14594838

Tested with 300 runs each on linux-x64 and linux-aarch64 with -Xcomp options that reproduced the issue, and then again with no options.

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-8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt (Bug - P4)

Reviewers

Kevin Walls (@kevinjwalls - Committer)
Serguei Spitsyn (@sspitsyn - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 14817

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

Using diff file

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

Webrev

Link to Webrev Comment

…nutes.

bridgekeeper · 2023-07-10T20:18:23Z

👋 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.

openjdk · 2023-07-10T20:19:46Z

@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 · 2023-07-10T22:44:22Z

Webrevs

…ed to refetch the notInterrupted count.

kevinjwalls

Yes that look like a more normal sync/wait/notify block.

sspitsyn

Looks good.
Thanks,
Serguei

openjdk · 2023-07-12T20:10:23Z

@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:

8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt

Reviewed-by: kevinw, 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 46 new commits pushed to the master branch:

2e12a12: 8281658: Add a security category to the java -XshowSettings option
43099a8: 8311647: Memory leak in Java_jdk_internal_org_jline_terminal_impl_jna_linux_CLibraryImpl_ttyname_1r
c7c6d47: 6355567: AdobeMarkerSegment causes failure to read valid JPEG
af7f95e: 8310070: Test: javax/net/ssl/DTLS/DTLSWontNegotiateV10.java timed out
c710e71: 8311102: Write annotations in the classfile dumped by SA
61932f4: 8244289: fatal error: Possible safepoint reached by thread that does not allow it
8c9d091: 8308047: java/util/concurrent/ScheduledThreadPoolExecutor/BasicCancelTest.java timed out and also had jcmd pipe errors
b587fc5: 8312013: avoid UnixConstants.java.template warning: 'linux' is not defined on AIX
135f64e: 8311583: tableswitch broken by JDK-8310577
6895deb: 8311536: JFR TestNativeMemoryUsageEvents fails in huge pages configuration
... and 36 more: https://git.openjdk.org/jdk/compare/63f32fbe9771b8200f707ed5d1d0e6555ad90f8b...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.

…ry for notInterrupted to be atomic.

dholmes-ora · 2023-07-13T05:06:44Z

test/hotspot/jtreg/vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001a.java

@@ -83,7 +83,7 @@ static void breakHere () {}
    private JdbArgumentHandler argumentHandler;
    private Log log;

-    public static final AtomicInteger notInterrupted = new AtomicInteger(numThreads);
+    public static volatile int notInterrupted = numThreads;


Nit: If always accessed under lock this does not need to be volatile.

It's also read outside the lock by the debugger side of the test using JDI -> JDWP -> JVMTI. My guess is there is so much other synchronization going on that it probably doesn't need volatile, but technically I think it should have it.

viktorklang-ora · 2023-07-13T09:46:30Z

test/hotspot/jtreg/vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001a.java

-        while (notInterrupted.get() > 0 && System.currentTimeMillis() - startTime <= waitTime) {
-            synchronized (waitnotify) {
+        synchronized (waitnotify) {
+            while (notInterrupted > 0 && System.currentTimeMillis() - startTime <= waitTime) {


@plummercj I'd use a monotonic clock like System.nanoTime() for things like this since the system clock can be changed to anything at any time.

I'd use a monotonic clock like System.nanoTime() for things like this since the system clock can be changed to anything at any time.

We have 100's of uses of System.currentTimeMillis() in our tests. I think changing them should be handled by a separate effort.

plummercj · 2023-07-14T05:14:55Z

@kevinjwalls and @sspitsyn can you please review the latest changes. Thanks!

sspitsyn

The latest simplification looks good.
Thanks,
Serguei

plummercj · 2023-07-14T18:38:16Z

Thanks Serguei and Kevin!

/integrate

openjdk · 2023-07-14T18:39:36Z

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

0d2196f: 8311992: Test java/lang/Thread/virtual/JfrEvents::testVirtualThreadPinned failed
f3b96f6: 8311862: RISC-V: small improvements to shift immediate instructions
a63f865: 8311946: add support for libgraal specific jtreg tests
167d1c1: 8311986: Disable runtime/os/TestTracePageSizes.java for ShenandoahGC
7539cc0: 8303134: JFR: Missing stack trace during chunk rotation stress
d1fa1a8: 8311825: Duplicate qualified enum constants not detected
4676b40: 8312049: runtime/logging/ClassLoadUnloadTest can be improved
bbb7ce5: 8311038: Incorrect exhaustivity computation
2e12a12: 8281658: Add a security category to the java -XshowSettings option
43099a8: 8311647: Memory leak in Java_jdk_internal_org_jline_terminal_impl_jna_linux_CLibraryImpl_ttyname_1r
... and 44 more: https://git.openjdk.org/jdk/compare/63f32fbe9771b8200f707ed5d1d0e6555ad90f8b...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-07-14T18:39:45Z

@plummercj Pushed as commit c84866a.

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

Use 200ms delay rather than rely on "waittime", which is usually 5 mi…

bb9b2fc

…nutes.

openjdk bot changed the title ~~8310551~~ 8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt Jul 10, 2023

openjdk bot added the serviceability serviceability-dev@openjdk.org label Jul 10, 2023

plummercj added 2 commits July 10, 2023 22:36

Alternate fix. Don't call wait() if all threads have been interrupted.

b70be06

Improve comment.

87b7bc3

plummercj marked this pull request as ready for review July 10, 2023 22:38

openjdk bot added the rfr Pull request is ready for review label Jul 10, 2023

Different approach to fix. Widen synchronized block so there is no ne…

41325e5

…ed to refetch the notInterrupted count.

kevinjwalls approved these changes Jul 12, 2023

View reviewed changes

sspitsyn approved these changes Jul 12, 2023

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Jul 12, 2023

Suggestion from David. Widen synchronized block so it is not necessar…

c250388

…ry for notInterrupted to be atomic.

dholmes-ora reviewed Jul 13, 2023

View reviewed changes

viktorklang-ora reviewed Jul 13, 2023

View reviewed changes

sspitsyn approved these changes Jul 14, 2023

View reviewed changes

kevinjwalls approved these changes Jul 14, 2023

View reviewed changes

openjdk bot added the integrated Pull request has been integrated label Jul 14, 2023

openjdk bot closed this Jul 14, 2023

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jul 14, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt #14817

8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt #14817

plummercj commented Jul 10, 2023 •

edited by openjdk bot

Loading

bridgekeeper bot commented Jul 10, 2023

openjdk bot commented Jul 10, 2023

mlbridge bot commented Jul 10, 2023 •

edited

Loading

kevinjwalls left a comment

sspitsyn left a comment

openjdk bot commented Jul 12, 2023 •

edited

Loading

dholmes-ora Jul 13, 2023

plummercj Jul 13, 2023

viktorklang-ora Jul 13, 2023

plummercj Jul 13, 2023

plummercj commented Jul 14, 2023

sspitsyn left a comment

plummercj commented Jul 14, 2023

openjdk bot commented Jul 14, 2023

openjdk bot commented Jul 14, 2023

8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt #14817

8310551: vmTestbase/nsk/jdb/interrupt/interrupt001/interrupt001.java timed out due to missing prompt #14817

Conversation

plummercj commented Jul 10, 2023 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

Webrev

bridgekeeper bot commented Jul 10, 2023

openjdk bot commented Jul 10, 2023

mlbridge bot commented Jul 10, 2023 • edited Loading

Webrevs

kevinjwalls left a comment

Choose a reason for hiding this comment

sspitsyn left a comment

Choose a reason for hiding this comment

openjdk bot commented Jul 12, 2023 • edited Loading

dholmes-ora Jul 13, 2023

Choose a reason for hiding this comment

plummercj Jul 13, 2023

Choose a reason for hiding this comment

viktorklang-ora Jul 13, 2023

Choose a reason for hiding this comment

plummercj Jul 13, 2023

Choose a reason for hiding this comment

plummercj commented Jul 14, 2023

sspitsyn left a comment

Choose a reason for hiding this comment

plummercj commented Jul 14, 2023

openjdk bot commented Jul 14, 2023

openjdk bot commented Jul 14, 2023

plummercj commented Jul 10, 2023 •

edited by openjdk bot

Loading

mlbridge bot commented Jul 10, 2023 •

edited

Loading

openjdk bot commented Jul 12, 2023 •

edited

Loading