8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. #12751

lmesnik · 2023-02-24T22:15:18Z

The solution proposed by Stefan K

The startProcess() might wait forever for the expected line if the process exits (failed to start). It makes sense to just fail earlier in such cases.

The fix also move
'output = new OutputAnalyzer(this.process);'
in method xrun() to be able to try to print them in waitFor is failed/interrupted.

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-8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed.

Reviewers

David Holmes (@dholmes-ora - Reviewer)
Roger Riggs (@RogerRiggs - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 12751

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

Using diff file

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

…s exit before linePredicate is printed.

bridgekeeper · 2023-02-24T22:16:39Z

👋 Welcome back lmesnik! 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-02-24T22:19:18Z

@lmesnik The following labels will be automatically applied to this pull request:

core-libs
hotspot-runtime

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

mlbridge · 2023-02-24T22:22:51Z

Webrevs

dcubed-ojdk · 2023-02-24T22:36:10Z

I fixed a typo in the bug's synopsis line so you'll need to update the PR's title.
Use "/issue JDK-8303133" as the quickest way to set it.

lmesnik · 2023-02-24T22:41:37Z

/issue JDK-8303133
Thanks

openjdk · 2023-02-24T22:42:00Z

@lmesnik This issue is referenced in the PR title - it will now be updated.

test/lib/jdk/test/lib/process/ProcessTools.java

test/lib/jdk/test/lib/thread/ProcessThread.java

dholmes-ora

I have a number of issues with the changes. I think you have basically addressed the problem of waiting forever if no predicate line was forthcoming, but I think you have introduced a race with normal termination of the process.

dholmes-ora · 2023-02-27T04:43:53Z

test/lib/jdk/test/lib/process/ProcessTools.java

+                boolean succeeded = Utils.waitForCondition(() -> {
+                    //Fail if process finished before printed expected string
+                    if (!p.isAlive()) {
+                        latch.countDown();


This countdown serves no purpose. The latch is used to coordinate the current thread and the stream pumper thread: the current thread calls await and the streamPumper calls countDown. Here the current thread is not going to call await and it doesn't need to countDown to release itself.

dholmes-ora · 2023-02-27T04:54:57Z

test/lib/jdk/test/lib/process/ProcessTools.java

-                    if (!latch.await(Utils.adjustTimeout(timeout), unit)) {
-                        throw new TimeoutException();
+                // Every second check if process is still alive
+                boolean succeeded = Utils.waitForCondition(() -> {


This use of waitForCondition with a sleep time of zero confused me quite a bit. Now I realize that you are putting waitForCondition into a potential busy-poll loop, but then you introduce the one-second timed await as part of the condition, thus effectively checking the condition once a second. This seems somewhat convoluted compared to just using a sleep time of 1000ms and changing the await to a call to getCount() > 0.

Using await() is more effective than checking every second. However, might be it is not essential for multi-process synchronization.

dholmes-ora · 2023-02-27T04:57:17Z

test/lib/jdk/test/lib/process/ProcessTools.java

+                    //Fail if process finished before printed expected string
+                    if (!p.isAlive()) {
+                        latch.countDown();
+                        throw new RuntimeException("Started process " + name + " is not alive.");


This seems problematic. The process has terminated but you don't know why - it may have completed normally and produced all the output such that the await below would return immediately with true, but you are now going to throw an exception. ???

Thanks! You are right, we need to check first if the line has been printed.
However, there is an interesting question the process can exit before streams are read and the latch is set to zero. The documentation says that linePredicate should detect if the process is warmed-up. So it is not expected that it should exit right after the start.

Yes there remains a race, if the process exits but the streamPumper has not yet had the chance to call countDown then we would again throw the exception. Perhaps all we can do is give a little extra time after detecting a dead process?

if (!p.isAlive()) { if (latch.getCount() > 0) { // Give some extra time for the StreamPumper to run after the process completed Thread.sleep(1000); if (latch.getCount() > 0) { throw new RuntimeException("Started process " + name + " but it terminated without the expected output"); } }

dholmes-ora · 2023-02-27T05:11:24Z

test/lib/jdk/test/lib/thread/ProcessThread.java

-            this.process = ProcessTools.startProcess(name, processBuilder, waitfor);
-            // Release when process is started
-            latch.countDown();
+            String name = Thread.currentThread().getName();


The original code passes the name of the ProcessRunnable to startProcess, not the name of the current thread. It is not obvious/apparent that they are the same. But if they are then it is cheaper to use name than do a dynamic query on the current thread.

Thanks! Fixed, it is a mistake.

dholmes-ora · 2023-02-27T22:48:46Z

test/lib/jdk/test/lib/process/ProcessTools.java

-                        throw new RuntimeException("Started process " + name + " is not alive.");
+                        // Give some extra time for the StreamPumper to run after the process completed
+                        Thread.sleep(1000);
+                        if (latch.getCount() > 0) {


Nit: we use > 0 here but != 0 above.

let use > in all places

dholmes-ora · 2023-02-27T22:51:05Z

test/lib/jdk/test/lib/process/ProcessTools.java

+                        // Give some extra time for the StreamPumper to run after the process completed
+                        Thread.sleep(1000);
+                        if (latch.getCount() > 0) {
+                            throw new RuntimeException("Started process " + name + " is not alive.");


Nit: the message is not very informative - we expect the process to die, the problem is it died before giving the necessary output. Suggestion:

"Started process " + name + "terminated before producing the expected output"

dholmes-ora

This seems okay to me now. Thanks.

openjdk · 2023-02-28T02:44:13Z

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

8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed.

Reviewed-by: dholmes, rriggs

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 36 new commits pushed to the master branch:

50dc041: 8303227: JniObjWithEnv should be NullablePointer compliant
61e8867: 8302040: Port fdlibm sqrt to Java
6423065: 8303261: JFR: jdk/jfr/api/consumer/streaming/TestJVMCrash.java doesn't retry
dc5ea6a: 8303350: Fix mistyped {@code}
4a415ad: 8303351: [IR Framework] Add missing cpu feature avx512bw after JDK-8302681
30302d1: 8303250: Call ct_max_alignment_constraint using the base class
e144783: 8299817: [s390] AES-CTR mode intrinsic fails with multiple short update() calls
5feb13b: 8301701: java/net/DatagramSocket/DatagramSocketMulticasting.java should be hardened
1e3c9fd: 8026369: javac potentially ambiguous overload warning needs an improved scheme
14a014d: 8302124: HotSpot Style Guide should permit noreturn attribute
... and 26 more: https://git.openjdk.org/jdk/compare/b4ea80731c6c0a0328a9801590ba5b081f08c3bd...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.

lmesnik · 2023-02-28T02:48:39Z

@dholmes-ora, Thank you for your comments.

lmesnik · 2023-03-01T00:49:18Z

/integrate

openjdk · 2023-03-01T00:50:44Z

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

65da2c5: 8303412: Update linux_x64-to-linux_aarch64 cross compilation devkit at Oracle
7e47d51: 8282319: java.util.Locale method to stream available Locales
8815175: 8303216: Prefer ArrayList to LinkedList in sun.net.httpserver.ServerImpl
a10d5ac: 8303130: Document required Accessibility permissions on macOS
50dc041: 8303227: JniObjWithEnv should be NullablePointer compliant
61e8867: 8302040: Port fdlibm sqrt to Java
6423065: 8303261: JFR: jdk/jfr/api/consumer/streaming/TestJVMCrash.java doesn't retry
dc5ea6a: 8303350: Fix mistyped {@code}
4a415ad: 8303351: [IR Framework] Add missing cpu feature avx512bw after JDK-8302681
30302d1: 8303250: Call ct_max_alignment_constraint using the base class
... and 30 more: https://git.openjdk.org/jdk/compare/b4ea80731c6c0a0328a9801590ba5b081f08c3bd...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-03-01T00:51:06Z

@lmesnik Pushed as commit 1fdaf25.

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

dholmes-ora · 2023-03-01T04:20:39Z

We are seeing large numbers of failures after this change was integrated, so it will likely need to be backed out.

8303133: Update ProcessTols.startProcess(...) to exit early if proces…

71dad3c

…s exit before linePredicate is printed.

openjdk bot added the rfr Pull request is ready for review label Feb 24, 2023

openjdk bot added hotspot-runtime hotspot-runtime-dev@openjdk.org core-libs core-libs-dev@openjdk.org labels Feb 24, 2023

openjdk bot changed the title ~~8303133: Update ProcessTols.startProcess(...) to exit early if process exit before linePredicate is printed.~~ 8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. Feb 24, 2023

RogerRiggs reviewed Feb 24, 2023

View reviewed changes

test/lib/jdk/test/lib/process/ProcessTools.java Outdated Show resolved Hide resolved

test/lib/jdk/test/lib/process/ProcessTools.java Outdated Show resolved Hide resolved

RogerRiggs reviewed Feb 24, 2023

View reviewed changes

test/lib/jdk/test/lib/thread/ProcessThread.java Show resolved Hide resolved

updated to always check if process is alive.

890dcc3

dholmes-ora suggested changes Feb 27, 2023

View reviewed changes

lmesnik added 2 commits February 27, 2023 10:44

fixed conditions.

5b7e389

added some extra time to dead process.

0277045

dholmes-ora reviewed Feb 27, 2023

View reviewed changes

lmesnik added 2 commits February 27, 2023 23:04

message improved

6f1bf8a

latch != updated

5ecb004

dholmes-ora approved these changes Feb 28, 2023

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Feb 28, 2023

RogerRiggs approved these changes Feb 28, 2023

View reviewed changes

openjdk bot added the integrated Pull request has been integrated label Mar 1, 2023

openjdk bot closed this Mar 1, 2023

openjdk bot removed the ready Pull request is ready to be integrated label Mar 1, 2023

openjdk bot removed the rfr Pull request is ready for review label Mar 1, 2023

lmesnik deleted the 8303133 branch June 5, 2024 20:53

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. #12751

8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. #12751

lmesnik commented Feb 24, 2023 •

edited by openjdk bot

Loading

bridgekeeper bot commented Feb 24, 2023

openjdk bot commented Feb 24, 2023

mlbridge bot commented Feb 24, 2023 •

edited

Loading

dcubed-ojdk commented Feb 24, 2023

lmesnik commented Feb 24, 2023

openjdk bot commented Feb 24, 2023

dholmes-ora left a comment

dholmes-ora Feb 27, 2023

dholmes-ora Feb 27, 2023

lmesnik Feb 27, 2023

dholmes-ora Feb 27, 2023

lmesnik Feb 27, 2023

dholmes-ora Feb 27, 2023 •

edited

Loading

dholmes-ora Feb 27, 2023

lmesnik Feb 27, 2023

dholmes-ora Feb 27, 2023

lmesnik Feb 27, 2023

dholmes-ora Feb 27, 2023

dholmes-ora left a comment

openjdk bot commented Feb 28, 2023 •

edited

Loading

lmesnik commented Feb 28, 2023

lmesnik commented Mar 1, 2023

openjdk bot commented Mar 1, 2023

openjdk bot commented Mar 1, 2023

dholmes-ora commented Mar 1, 2023

8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. #12751

8303133: Update ProcessTools.startProcess(...) to exit early if process exit before linePredicate is printed. #12751

Conversation

lmesnik commented Feb 24, 2023 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Feb 24, 2023

openjdk bot commented Feb 24, 2023

mlbridge bot commented Feb 24, 2023 • edited Loading

Webrevs

dcubed-ojdk commented Feb 24, 2023

lmesnik commented Feb 24, 2023

openjdk bot commented Feb 24, 2023

dholmes-ora left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dholmes-ora Feb 27, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dholmes-ora left a comment

Choose a reason for hiding this comment

openjdk bot commented Feb 28, 2023 • edited Loading

lmesnik commented Feb 28, 2023

lmesnik commented Mar 1, 2023

openjdk bot commented Mar 1, 2023

openjdk bot commented Mar 1, 2023

dholmes-ora commented Mar 1, 2023

lmesnik commented Feb 24, 2023 •

edited by openjdk bot

Loading

mlbridge bot commented Feb 24, 2023 •

edited

Loading

dholmes-ora Feb 27, 2023 •

edited

Loading

openjdk bot commented Feb 28, 2023 •

edited

Loading