8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java #21913

matias9927 · 2024-11-05T18:36:01Z

The test DeterministicDump.java fails frequently since it is sensitive to changes in CDS, and with it's current logging, it is very difficult to diagnose the root cause of these failures. The current output looks like this:

[First diff: map file #1 (SharedArchiveFile0.map)]
[ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 [ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 0x00000008005a2000: @@ Symbol            40 [Ljdk/internal/vm/FillerElement;
>0x00000008005a2000:   4c5b0020e72fffff 65746e692f6b646a 2f6d762f6c616e72 6c4572656c6c6946   ../. .[Ljdk/internal/vm/FillerEl
 0x00000008005a2020:   00003b746e656d65                                                      ement;..
 0x00000008005a2028: @@ Symbol            8 [Z

[First diff: map file #2 (SharedArchiveFile1.map)]
[ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 [ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 0x00000008005a2000: @@ Symbol            40 [Ljdk/internal/vm/FillerElement;
>0x00000008005a2000:   4c5b00205d54ffff 65746e692f6b646a 2f6d762f6c616e72 6c4572656c6c6946   ..T] .[Ljdk/internal/vm/FillerEl
 0x00000008005a2020:   00003b746e656d65                                                      ement;..
 0x00000008005a2028: @@ Symbol            8 [Z

Byte #5910530 at line #235268 word #0:
SharedArchiveFile0.map: 4c5b0020e72fffff 
SharedArchiveFile1.map: 4c5b00205d54ffff

This change was verified locally by generating non-deterministic archives and map files.

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-8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java (Sub-task - P4)

Reviewers

Ioi Lam (@iklam - Reviewer) Review applies to 1ba7318b
Calvin Cheung (@calvinccheung - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 21913

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

Using diff file

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

Using Webrev

Link to Webrev Comment

bridgekeeper · 2024-11-05T18:36:50Z

👋 Welcome back matsaave! 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-05T18:37:02Z

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

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java

Reviewed-by: ccheung, iklam

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:

168b18e: 8343958: Remove security manager impl in java.lang.Process and java.lang.Runtime.exec
5ac330b: 8344039: Remove security manager dependency in java.time
1eb38c8: 8343219: Manual clientlibs test failures after SM removal
dde6230: 8343416: CDS dump fails when unregistered class can also be loaded from system modules
ffea980: 8344023: Unnecessary Hashtable usage in LdapClient.defaultBinaryAttrs
5e01c40: 8343981: Remove usage of security manager from Thread and related classes
dbf2346: 8341260: Add Float16 to jdk.incubator.vector
a5f11b5: 8343483: Remove unnecessary @SuppressWarnings annotations (serviceability)
7be7772: 8344112: Remove code to support security manager execution mode from DatagramChannel implementation
bd3fec3: 8344086: Remove security manager dependency in FFM
... and 180 more: https://git.openjdk.org/jdk/compare/5995786dbd69ed11dd1cacb2a3ac86e3e6f43ab7...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-05T18:38:07Z

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

hotspot-runtime

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-05T19:31:59Z

Webrevs

iklam · 2024-11-09T04:28:30Z

Two suggestions:

(1) I think it will be good to print an indicator on the line that differs. Something like

 [First diff: map file #2 (SharedArchiveFile1.map)]
 [ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes] 
 0x00000008005a2cb0:   6f66000ae5fcffff 6c61766f6d655272                                     ......forRemoval
 0x00000008005a2cc0: @@ Symbol            32 java/lang/VersionProps
 0x00000008005a2cc0:   616a00169955ffff 2f676e616c2f6176 506e6f6973726556 0000000073706f72   ..U...java/lang/VersionProps....
 0x00000008005a2ce0: @@ Symbol            24 java_version
>0x00000008005a2ce0:   616a000ca147ffff 69737265765f6176 0000000000006e6f                    ..G...java_version......

(2) Sometimes an object spans over many lines. It will be good to remember the first line of the very last object (the 0x00000008005a2ce0: @@ Symbol in your example). If that line is more than 4 lines above the first diff, then print something like this:

 0x00000008005a2ce0: @@ Symbol            24 java_version
 [....]

before printing the rest of the output.

matias9927 · 2024-11-12T16:13:49Z

Two suggestions:

That's a good idea! I think my example output is a little confusing because there are actually two differences in it. Using your idea, the output would look like this:

[First diff: map file #1 (SharedArchiveFile0.map)]
[ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 0x00000008005a2cb0:   6f66000a8da9ffff 6c61766f6d655272                                     ......forRemoval 
 0x00000008005a2cc0: @@ Symbol            32 java/lang/VersionProps
>0x00000008005a2cc0:   616a0016959bffff 2f676e616c2f6176 506e6f6973726556 0000000073706f72   ......java/lang/ VersionProps....
 0x00000008005a2ce0: @@ Symbol            24 java_version
 0x00000008005a2ce0:   616a000c335cffff 69737265765f6176 0000000000006e6f                    ..\3..java_version......

[First diff: map file #2 (SharedArchiveFile1.map)]
[ro region          0x00000008005a2000 - 0x0000000800ea7058   9457752 bytes]
 0x00000008005a2cb0:   6f66000ae5fcffff 6c61766f6d655272                                     ......forRemoval
 0x00000008005a2cc0: @@ Symbol            32 java/lang/VersionProps
>0x00000008005a2cc0:   616a00169955ffff 2f676e616c2f6176 506e6f6973726556 0000000073706f72   ..U...java/lang/ VersionProps....
 0x00000008005a2ce0: @@ Symbol            24 java_version
 0x00000008005a2ce0:   616a000ca147ffff 69737265765f6176 0000000000006e6f                    ..G...java_version......

Byte #5910530 at line #235510 word #0:
SharedArchiveFile0.map: 616a0016959bffff 
SharedArchiveFile1.map: 616a00169955ffff

I make sure extra lines are printed after the diff but I can include "..." on top of that as well.

iklam

LGTM.

calvinccheung

Looks good. Just one nit.

calvinccheung · 2024-11-13T20:37:25Z

test/lib/jdk/test/lib/cds/CDSArchiveUtils.java

+        long offset = spOffset + cdsFileMapRegionSize * region + spUsedOffset;
+        return readInt(archiveFile, offset, sizetSize);
+    }
+
    // used region size
    public static long usedRegionSizeAligned(File archiveFile, int region) throws Exception {
        long offset = spOffset + cdsFileMapRegionSize * region + spUsedOffset;


Can you just call usedRegionSize like the following?
long used = usedRegionSize(archiveFile, region);

matias9927 · 2024-11-13T23:17:23Z

Thanks for the feedback and reviews @iklam and @calvinccheung !
/integrate

openjdk · 2024-11-13T23:18:31Z

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

0dab920: 8343984: Fix Unsafe address overflow
168b18e: 8343958: Remove security manager impl in java.lang.Process and java.lang.Runtime.exec
5ac330b: 8344039: Remove security manager dependency in java.time
1eb38c8: 8343219: Manual clientlibs test failures after SM removal
dde6230: 8343416: CDS dump fails when unregistered class can also be loaded from system modules
ffea980: 8344023: Unnecessary Hashtable usage in LdapClient.defaultBinaryAttrs
5e01c40: 8343981: Remove usage of security manager from Thread and related classes
dbf2346: 8341260: Add Float16 to jdk.incubator.vector
a5f11b5: 8343483: Remove unnecessary @SuppressWarnings annotations (serviceability)
7be7772: 8344112: Remove code to support security manager execution mode from DatagramChannel implementation
... and 181 more: https://git.openjdk.org/jdk/compare/5995786dbd69ed11dd1cacb2a3ac86e3e6f43ab7...master

Your commit was automatically rebased without conflicts.

openjdk · 2024-11-13T23:18:39Z

@matias9927 Pushed as commit 3b28354.

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

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java

417da7e

openjdk bot added the hotspot-runtime hotspot-runtime-dev@openjdk.org label Nov 5, 2024

matias9927 marked this pull request as ready for review November 5, 2024 18:45

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

Now prints preceding lines and region name

38a1077

Corrected mapping from archive byte to line in mapfile

1ba7318

iklam approved these changes Nov 13, 2024

View reviewed changes

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

calvinccheung approved these changes Nov 13, 2024

View reviewed changes

Calvin comment

b97e068

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

Changed copyright

67d82af

calvinccheung approved these changes Nov 13, 2024

View reviewed changes

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

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

openjdk bot closed this Nov 13, 2024

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

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java #21913

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java #21913

matias9927 commented Nov 5, 2024 •

edited by openjdk bot

Loading

bridgekeeper bot commented Nov 5, 2024

openjdk bot commented Nov 5, 2024 •

edited

Loading

openjdk bot commented Nov 5, 2024

mlbridge bot commented Nov 5, 2024 •

edited

Loading

iklam commented Nov 9, 2024

matias9927 commented Nov 12, 2024 •

edited

Loading

iklam left a comment

calvinccheung left a comment

calvinccheung Nov 13, 2024

matias9927 commented Nov 13, 2024

openjdk bot commented Nov 13, 2024

openjdk bot commented Nov 13, 2024

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java #21913

8339288: Improve diagnostic logging runtime/cds/DeterministicDump.java #21913

Conversation

matias9927 commented Nov 5, 2024 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Nov 5, 2024

openjdk bot commented Nov 5, 2024 • edited Loading

openjdk bot commented Nov 5, 2024

mlbridge bot commented Nov 5, 2024 • edited Loading

Webrevs

iklam commented Nov 9, 2024

matias9927 commented Nov 12, 2024 • edited Loading

iklam left a comment

Choose a reason for hiding this comment

calvinccheung left a comment

Choose a reason for hiding this comment

calvinccheung Nov 13, 2024

Choose a reason for hiding this comment

matias9927 commented Nov 13, 2024

openjdk bot commented Nov 13, 2024

openjdk bot commented Nov 13, 2024

matias9927 commented Nov 5, 2024 •

edited by openjdk bot

Loading

openjdk bot commented Nov 5, 2024 •

edited

Loading

mlbridge bot commented Nov 5, 2024 •

edited

Loading

matias9927 commented Nov 12, 2024 •

edited

Loading