8303198: System and Runtime.exit() resilience to logging errors #12770

RogerRiggs · 2023-02-27T15:41:01Z

Consolidate logging and handle exceptions by printing to standard error and ignoring the exception.
Exceptions while logging will not interfere with Runtime.exit.

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-8303198: System and Runtime.exit() resilience to logging errors

Reviewers

David Holmes (@dholmes-ora - Reviewer)
Jaikiran Pai (@jaikiran - Reviewer)
Alan Bateman (@AlanBateman - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 12770

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

Using diff file

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

and ignoring the exception. Exceptions in the logging will not interfere with Runtime.exit processing.

bridgekeeper · 2023-02-27T15:42:48Z

👋 Welcome back rriggs! 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-27T15:46:08Z

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

core-libs

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-02-27T15:50:02Z

Webrevs

01: Full - Incremental (363ccbc2)
00: Full (ed5d16e7)

AlanBateman · 2023-02-27T15:58:33Z

src/java.base/share/classes/java/lang/Shutdown.java

+                System.err.println("Runtime.exit() logging failed: " + throwable.getMessage());
+            } catch (Throwable throwable2) {
+                // Ignore
+            }


The update means that several threads racing to exit may result in more than one message being logged. I don't think that's a big issue but just wanted to make sure that this was deliberate.

Yes, its racy, and intentional, but from a diagnostic view, the developer should know that multiple callers were trying to exit. All but one will hang.
Consolidating the code in a single method is cleaner and with fewer interactions between separate code blocks.

I can't tell if the thread identity will be included in the log the message?

I'm not so sure it is useful to allow competing exit calls to all log their intent. I would have kept the logging itself inside the locked region as per the original code.

The main diagnostic is the logged message with the stack trace. The println version is present as a diagnostic if logging is mis-configured.

If the developer is looking to mitigate calls to Runtime.Exit, then they are advised to check all paths and will appreciate not having to wait for a different thread to win the race.

But does that logging include the thread identity? If multiple threads can race to exit and all log, then the developer/user needs to know which logging came from which thread.

But does that logging include the thread identity? If multiple threads can race to exit and all log, then the developer/user needs to know which logging came from which thread.

That's really up to the Logger and its configuration. If j.u.logging is used then formatters can be configured to put the thread ID into the log records. With 3rd party logging libraries there seems to be several choices, like %t for the thread name.

The main usage for this logging is to be able to find code in tests, plugins, etc. that is calling System.exit and causing the test runner or container to exit. So I think it's less about "which thread" and more about "which code".

System.Logger is a facade for arbitrary user-code, commonly the log4J bridge. I routinely observe log4J throwing SecurityException's from deep within its implementation (since it is only partially implemented to handle the security manager)

jaikiran · 2023-03-01T11:03:39Z

src/java.base/share/classes/java/lang/Shutdown.java

-            System.err.println("Runtime.exit() log finder failed with: " + throwable.getMessage());
+            try {
+                // Exceptions from the Logger are printed but do not prevent exit
+                System.err.println("Runtime.exit() logging failed: " + throwable.getMessage());


Hello Roger, do you think including the exit code in this System.err.println message would be useful too? That would then mean that if the Logger failed for whatever reason, this fallback message would at least include the exit code to provide some hints on what might have triggered the exit.

Including the status is simple enough, but has little/nothing to do with why the logging call failed.

Agreed - the exit code in the System.err.println fallback would merely be a last resort to provide some possible hint on what code might have triggered an exit.

RogerRiggs · 2023-03-03T02:32:16Z

Are there any more comments?

plummercj · 2023-03-03T02:49:01Z

Are you going to remove VMOutOfMemoryException001.java from the problem list?

RogerRiggs · 2023-03-03T02:52:03Z

Are you going to remove VMOutOfMemoryException001.java from the problem list?

I'll do that a separate PR to avoid mixing the issues and solutions.
This change is not only to address JDK-8303057.

dholmes-ora · 2023-03-03T04:11:10Z

If this gets integrated then JDK-8303057 should be closed as a duplicate, at which point the entry in the ProblemList gets orphaned. If JDK-8303057 is to be closed as a duplicate of this issue, then this issue should update the ProblemList. Otherwise you need a new issue just to do the PL update (it would make no sense for JDK-8303057 to be hijacked for that).

dholmes-ora

I still have my doubts about the actual logging strategy and the usefulness of doing it outside the lock, but won't press it. The main thing is that logRuntimeExit can not throw an exception.

Thanks.

openjdk · 2023-03-03T04:14:53Z

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

8303198: System and Runtime.exit() resilience to logging errors

Reviewed-by: dholmes, jpai, alanb

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

cbdc7a6: 8303481: CancelRequestTest assertTrue failing with AssertionError due to java.util.concurrent.CompletionException: java.io.EOFException: EOF reached while reading
8bf084c: 8303499: [s390x] ProblemList StressStackOverflow
ff364c1: 8301622: ProcessTools.java compilation gets ThreadDeath deprecation warning
df9aad0: 8297955: LDAP CertStore should use LdapName and not String for DNs
d23a8bf: 8297753: AArch64: Add optimized rules for vector compare with zero on NEON
339ca88: 8303539: javadoc typos in Attr
e1745bc: 8303473: Add implied {@code} in java.lang.invoke.MethodHandles
c961a91: 8143900: OptimizeStringConcat has an opaque dependency on Integer.sizeTable field
35003b5: 8302830: AArch64: Fix the mismatch between cas.m4 and aarch64.ad
f3abc40: 8302783: Improve CRC32C intrinsic with crypto pmull on AArch64
... and 66 more: https://git.openjdk.org/jdk/compare/a43931b79cb25d218e8f9b4d4f3a106f59cb2d37...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.

jaikiran

Thank you Roger. The changes look good to me.

AlanBateman

I think this looks okay. The main goal is to make it easy to identify the code that is calling System.exit and this seems as robust as it can be. The issue of racing exits can be looked at again, if it turns out to be interesting.

RogerRiggs · 2023-03-03T16:13:24Z

/integrate

openjdk · 2023-03-03T16:14:55Z

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

80739e1: 8279619: [JVMCI] improve EncodedSpeculationReason
7449e1c: 8299807: newStringNoRepl should avoid copying arrays for ASCII compatible charsets
c6de66c: 8303516: HFAs with nested structs/unions/arrays not handled correctly on AArch64
cbdc7a6: 8303481: CancelRequestTest assertTrue failing with AssertionError due to java.util.concurrent.CompletionException: java.io.EOFException: EOF reached while reading
8bf084c: 8303499: [s390x] ProblemList StressStackOverflow
ff364c1: 8301622: ProcessTools.java compilation gets ThreadDeath deprecation warning
df9aad0: 8297955: LDAP CertStore should use LdapName and not String for DNs
d23a8bf: 8297753: AArch64: Add optimized rules for vector compare with zero on NEON
339ca88: 8303539: javadoc typos in Attr
e1745bc: 8303473: Add implied {@code} in java.lang.invoke.MethodHandles
... and 69 more: https://git.openjdk.org/jdk/compare/a43931b79cb25d218e8f9b4d4f3a106f59cb2d37...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-03-03T16:15:09Z

@RogerRiggs Pushed as commit 379f206.

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

Consolidate logging and handle exceptions by printing to standard error

ed5d16e

and ignoring the exception. Exceptions in the logging will not interfere with Runtime.exit processing.

openjdk bot changed the title ~~8303198~~ 8303198: System and Runtime.exit() resilience to logging errors Feb 27, 2023

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

openjdk bot added the core-libs core-libs-dev@openjdk.org label Feb 27, 2023

AlanBateman reviewed Feb 27, 2023

View reviewed changes

jaikiran reviewed Mar 1, 2023

View reviewed changes

Add exit status to output when the logging fails with an exception.

363ccbc

dholmes-ora approved these changes Mar 3, 2023

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Mar 3, 2023

jaikiran approved these changes Mar 3, 2023

View reviewed changes

AlanBateman approved these changes Mar 3, 2023

View reviewed changes

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

openjdk bot closed this Mar 3, 2023

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

RogerRiggs deleted the 8303198-guard-exit-logging branch December 11, 2023 17:24

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8303198: System and Runtime.exit() resilience to logging errors #12770

8303198: System and Runtime.exit() resilience to logging errors #12770

RogerRiggs commented Feb 27, 2023 •

edited by openjdk bot

Loading

bridgekeeper bot commented Feb 27, 2023

openjdk bot commented Feb 27, 2023

mlbridge bot commented Feb 27, 2023 •

edited

Loading

AlanBateman Feb 27, 2023

RogerRiggs Feb 27, 2023

dholmes-ora Feb 27, 2023

RogerRiggs Feb 27, 2023

dholmes-ora Feb 28, 2023

AlanBateman Feb 28, 2023

ChrisHegarty Mar 1, 2023

jaikiran Mar 1, 2023

RogerRiggs Mar 1, 2023

jaikiran Mar 1, 2023

RogerRiggs commented Mar 3, 2023

plummercj commented Mar 3, 2023

RogerRiggs commented Mar 3, 2023

dholmes-ora commented Mar 3, 2023

dholmes-ora left a comment

openjdk bot commented Mar 3, 2023 •

edited

Loading

jaikiran left a comment

AlanBateman left a comment

RogerRiggs commented Mar 3, 2023

openjdk bot commented Mar 3, 2023

openjdk bot commented Mar 3, 2023

8303198: System and Runtime.exit() resilience to logging errors #12770

8303198: System and Runtime.exit() resilience to logging errors #12770

Conversation

RogerRiggs commented Feb 27, 2023 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Feb 27, 2023

openjdk bot commented Feb 27, 2023

mlbridge bot commented Feb 27, 2023 • edited Loading

Webrevs

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

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

RogerRiggs commented Mar 3, 2023

plummercj commented Mar 3, 2023

RogerRiggs commented Mar 3, 2023

dholmes-ora commented Mar 3, 2023

dholmes-ora left a comment

Choose a reason for hiding this comment

openjdk bot commented Mar 3, 2023 • edited Loading

jaikiran left a comment

Choose a reason for hiding this comment

AlanBateman left a comment

Choose a reason for hiding this comment

RogerRiggs commented Mar 3, 2023

openjdk bot commented Mar 3, 2023

openjdk bot commented Mar 3, 2023

RogerRiggs commented Feb 27, 2023 •

edited by openjdk bot

Loading

mlbridge bot commented Feb 27, 2023 •

edited

Loading

openjdk bot commented Mar 3, 2023 •

edited

Loading