8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose #22331

SoniaZaldana · 2024-11-22T18:53:28Z

Hi folks,

This PR addresses 8344013.

Sometimes the writing to xmlStream is mixed from several threads, and therefore the xmlStream tag stack can end up in a bad state. When this occurs, the VM crashes in xmlStream::pop_tag with assert(false) failed: bad tag in log.

In this case, running java -XX:+LogCompilation -XX:CompileCommand="log,*.*" -XX:+CITimeVerbose -Xcomp -Xbatch -version , xmlStream::pop_tag is expecting to pop the tag task but finds phase instead.

I found the issue stems from 8330157. The problematic code is in the destructor for TracePhase.

Note how the constructor adds the phase tag.

However, in the destructor, if we return early, we don’t pop that tag, leading to the xmlStream tag stack to end up in a bad state. With this patch, I made sure we pop the tag even if we return early.

Cheers,
Sonia

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-8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose (Bug - P4)

Reviewers

Christian Hagedorn (@chhagedorn - Reviewer)
Damon Fenacci (@dafedafe - Committer) Review applies to 2725d240

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 22331

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

Using diff file

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

Using Webrev

Link to Webrev Comment

bridgekeeper · 2024-11-22T18:54:31Z

👋 Welcome back szaldana! 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 · 2024-11-22T18:55:16Z

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

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose

Reviewed-by: chagedorn, dfenacci

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

6da3ecd: 8344960: RISC-V: fix TestFloatConversionsVectorNaN for COH and AlignVector
9291abc: 8342074: Fix runtime/Thread/TestAlwaysPreTouchStacks.java to be flagless or accept VM flags
0054bbe: 8343756: CAN_SHOW_REGISTERS_ON_ASSERT for Windows
3a625f3: 8344628: Test TestEnableJVMCIProduct.java run with virtual thread intermittent fails
25dd51e: 8344222: Remove calls to SecurityManager and doPrivileged in java.net.HttpURLConnection, java.net.HttpConnectSocketImpl, and javax.net.HttpsURLConnection after JEP 486 integration
9793e73: 8344853: Parallel: Improve comments in psParallelCompact
57d35f9: 8344382: RISC-V: CASandCAEwithNegExpected fails with Zacas
0105203: 8337660: C2: basic blocks with only BoxLock nodes are wrongly treated as empty
4e68d66: 8344954: Linker tests fails on BE platforms after JDK-8340205
ca81ab5: 8344994: Remove most uses of RuntimePermission checks in java.desktop
... and 49 more: https://git.openjdk.org/jdk/compare/13987b4244614d594dc8f94c288eddb6239a066f...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 · 2024-11-22T18:56:00Z

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

hotspot-compiler

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 · 2024-11-22T19:31:34Z

Webrevs

chhagedorn

Looks good to me. Can you also add a regression test for it? Since this already triggers with --version, you can just create a hello world like test and run with the mentioned flags.

Just a side note:

Note how the constructor adds the phase tag.

You can directly insert the permalink (in the non-blame view) such that the code is inlined in the PR for easier reading :-)

jdk/src/hotspot/share/opto/compile.cpp

Line 4327 in 6f622da

    
           _log->begin_head("phase name='%s' nodes='%d' live='%d'", phase_name(), _compile->unique(), _compile->live_nodes());

dafedafe

Looks good to me (C1 seems to already have this check). Thanks for fixing this.

SoniaZaldana · 2024-11-25T15:32:41Z

Thanks for the reviews @chhagedorn @dafedafe! I added a regression test.

chhagedorn

Thanks for adding the test! Two minor comments, otherwise, looks good.

chhagedorn · 2024-11-25T20:20:39Z

test/hotspot/jtreg/compiler/debug/TestLogStackAssert.java

+ * @bug 8344013
+ * @requires vm.debug == true & vm.compiler2.enabled
+ * @summary Verify the xmlStream log stack is not left in a bad state
+ * @library /test/lib /


Not required and can be removed.

Suggested change

* @library /test/lib /

chhagedorn · 2024-11-25T20:21:49Z

test/hotspot/jtreg/compiler/debug/TestLogStackAssert.java

+ * @requires vm.debug == true & vm.compiler2.enabled
+ * @summary Verify the xmlStream log stack is not left in a bad state
+ * @library /test/lib /
+ * @run main/othervm -XX:+LogCompilation -XX:CompileCommand=log,*.* -XX:+CITimeVerbose -Xcomp -Xbatch compiler.debug.TestLogStackAssert


-Xbatch is implied by -Xcomp.

Suggested change

* @run main/othervm -XX:+LogCompilation -XX:CompileCommand=log,*.* -XX:+CITimeVerbose -Xcomp -Xbatch compiler.debug.TestLogStackAssert

* @run main/othervm -XX:+LogCompilation -XX:CompileCommand=log,*.* -XX:+CITimeVerbose -Xcomp compiler.debug.TestLogStackAssert

SoniaZaldana · 2024-11-26T19:43:33Z

/integrate

openjdk · 2024-11-26T19:44:10Z

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

9458a43: 8318416: Superscript marks should use consistent font style
c5de307: 8344992: Remove Security Manager dependencies from java.security.cert API and implementations
65c98e5: 8344420: Remove Security Manager dependencies from javax.security package
2465526: 8344821: Test CheckDefaultArchiveFile.java fails if classes_coh.jsa is not present
d752f19: 8343427: Class file load hook crashes on archived classes from multi-release JARs
f1b5a6e: 8344565: SM cleanup in jdk/internal and java/lang package private classes
d8a2337: 8344895: SM cleanup of module java.xml
c329f97: 8345015: Remove unused method lookup_time_t_function
86d527f: 8344949: javax.security.auth.Subject.SecureSet.writeObject does not do a security check anymore
f0b72f7: 8342380: Implement JEP 498: Warn upon Use of Memory-Access Methods in sun.misc.Unsafe
... and 61 more: https://git.openjdk.org/jdk/compare/13987b4244614d594dc8f94c288eddb6239a066f...master

Your commit was automatically rebased without conflicts.

openjdk · 2024-11-26T19:44:16Z

@SoniaZaldana Pushed as commit 3689f39.

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

tstuefe · 2024-12-12T04:26:51Z

Very good. Thank you for fixing.

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose

2725d24

openjdk bot added the hotspot-compiler hotspot-compiler-dev@openjdk.org label Nov 22, 2024

SoniaZaldana marked this pull request as ready for review November 22, 2024 19:26

openjdk bot added the rfr Pull request is ready for review label Nov 22, 2024

chhagedorn reviewed Nov 25, 2024

View reviewed changes

dafedafe approved these changes Nov 25, 2024

View reviewed changes

Adding regression test

66778c8

chhagedorn approved these changes Nov 25, 2024

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Nov 25, 2024

Changes based on feedback

f55e9ea

openjdk bot removed the ready Pull request is ready to be integrated label Nov 25, 2024

chhagedorn approved these changes Nov 26, 2024

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Nov 26, 2024

openjdk bot added the integrated Pull request has been integrated label Nov 26, 2024

openjdk bot closed this Nov 26, 2024

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Nov 26, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose #22331

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose #22331

Uh oh!

SoniaZaldana commented Nov 22, 2024 •

edited by openjdk bot

Loading

Uh oh!

bridgekeeper bot commented Nov 22, 2024

Uh oh!

openjdk bot commented Nov 22, 2024 •

edited

Loading

Uh oh!

openjdk bot commented Nov 22, 2024

Uh oh!

mlbridge bot commented Nov 22, 2024 •

edited

Loading

Uh oh!

chhagedorn left a comment

Uh oh!

dafedafe left a comment

Uh oh!

SoniaZaldana commented Nov 25, 2024

Uh oh!

chhagedorn left a comment

Uh oh!

chhagedorn Nov 25, 2024

Uh oh!

chhagedorn Nov 25, 2024

Uh oh!

SoniaZaldana commented Nov 26, 2024

Uh oh!

openjdk bot commented Nov 26, 2024

Uh oh!

openjdk bot commented Nov 26, 2024

Uh oh!

tstuefe commented Dec 12, 2024

Uh oh!

Uh oh!

	* @run main/othervm -XX:+LogCompilation -XX:CompileCommand=log,. -XX:+CITimeVerbose -Xcomp -Xbatch compiler.debug.TestLogStackAssert
	* @run main/othervm -XX:+LogCompilation -XX:CompileCommand=log,. -XX:+CITimeVerbose -Xcomp compiler.debug.TestLogStackAssert

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose #22331

8344013: "bad tag in log" assert with +LogCompilation +CITimeVerbose #22331

Uh oh!

Conversation

SoniaZaldana commented Nov 22, 2024 • edited by openjdk bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Progress

Issue

Reviewers

Reviewing

Uh oh!

bridgekeeper bot commented Nov 22, 2024

Uh oh!

openjdk bot commented Nov 22, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

openjdk bot commented Nov 22, 2024

Uh oh!

mlbridge bot commented Nov 22, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Webrevs

Uh oh!

chhagedorn left a comment

Choose a reason for hiding this comment

Uh oh!

dafedafe left a comment

Choose a reason for hiding this comment

Uh oh!

SoniaZaldana commented Nov 25, 2024

Uh oh!

chhagedorn left a comment

Choose a reason for hiding this comment

Uh oh!

chhagedorn Nov 25, 2024

Choose a reason for hiding this comment

Uh oh!

chhagedorn Nov 25, 2024

Choose a reason for hiding this comment

Uh oh!

SoniaZaldana commented Nov 26, 2024

Uh oh!

openjdk bot commented Nov 26, 2024

Uh oh!

openjdk bot commented Nov 26, 2024

Uh oh!

tstuefe commented Dec 12, 2024

Uh oh!

Uh oh!

SoniaZaldana commented Nov 22, 2024 •

edited by openjdk bot

Loading

openjdk bot commented Nov 22, 2024 •

edited

Loading

mlbridge bot commented Nov 22, 2024 •

edited

Loading