jdk icon indicating copy to clipboard operation
jdk copied to clipboard

8313306: More sensible memory reservation logging

Open SoniaZaldana opened this issue 1 year ago • 12 comments

This PR implements more specialized logs for virtual memory APIs in the “os” namespace. It uses “os” and “map” as log tags using unified JVM logging as introduced in JEP 158 (https://openjdk.org/jeps/158).

As far as testing is concerned, I have added a regression test to verify the logging is working accordingly.


Progress

  • [x] Change must be properly reviewed (1 review required, with at least 1 Reviewer)
  • [x] Change must not contain extraneous whitespace
  • [x] Commit message must refer to an issue

Issue

  • JDK-8313306: More sensible memory reservation logging (Enhancement - P4)

Reviewers

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 17356

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

Using diff file

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

Webrev

Link to Webrev Comment

SoniaZaldana avatar Jan 10 '24 21:01 SoniaZaldana

:wave: 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.

bridgekeeper[bot] avatar Jan 10 '24 21:01 bridgekeeper[bot]

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

openjdk[bot] avatar Jan 10 '24 21:01 openjdk[bot]

@SoniaZaldana this pull request can not be integrated into master due to one or more merge conflicts. To resolve these merge conflicts and update this pull request you can run the following commands in the local repository for your personal fork:

git checkout JDK-8313306
git fetch https://git.openjdk.org/jdk.git master
git merge FETCH_HEAD
# resolve conflicts and follow the instructions given by git merge
git commit -m "Merge master"
git push

openjdk[bot] avatar Jan 31 '24 15:01 openjdk[bot]

I will ping the SAP folks to test this on all of their platforms, especially AIX since we don't have any builds there.

tstuefe avatar Feb 16 '24 06:02 tstuefe

Breaks AIX build: os_aix.cpp:1626:5: error: unknown type name 'ErrorPreserver'; did you mean 'ErrnoPreserver'?

New test is failing on linux PPC64le: TestMemoryAllocationLogging.java#testUncommitFailed

 exitValue = 139

java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [139]
	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:521)
	at TestMemoryAllocationLogging.runTestWithOptions(TestMemoryAllocationLogging.java:202)
	at TestMemoryAllocationLogging.main(TestMemoryAllocationLogging.java:195)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1575)

TheRealMDoerr avatar Feb 17 '24 09:02 TheRealMDoerr

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

8313306: More sensible memory reservation logging

Reviewed-by: dholmes, stuefe, coleenp

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

  • 7734466c4627c51b2c24b4b4dbf6db4184607aa3: 8325871: Move StringTable and SymbolTable rehashing calls
  • 9e98118f289e98ca9f3be2a274e0ddf8822aaa7c: 8328177: Move LDFLAGS_JDK[LIB/EXE] to JdkNativeCompilation.gmk
  • f3af91815a662b195938b26962a8670a4a692220: 8327945: Inline HasScavengableOops
  • fb390d202c8bbbbb87ba48fd01387feb35a1b768: 8327839: Crash with unboxing and widening primitive conversion in switch
  • 86f17447362483162a5983c270e0b530d8d99354: 8328248: Convert javax/swing/JSlider/6587742/bug6587742.java applet test to main
  • 7baec6622254fc21e315b974a213605a7605daac: 8328168: Epsilon: Premature OOM when allocating object larger than uncommitted heap size
  • c342188fd978dd94e7788fb0fb0345fd8c0eaa9a: 8328074: Add jcheck whitespace checking for assembly files
  • 3c70f26b2f3fa9bc143e2506af30f9b1daf20022: 8328112: Remove CardTable::_guard_region
  • 48717d63cc58f693f0917e61eafd672cd6af02ed: 8326333: jshell <TAB> completion on arrays is incomplete
  • ece4124f25f676da9bf2d1b7fd8e4394dd7d31af: 8328247: Remove redundant dir for tests converted from applet to main
  • ... and 434 more: https://git.openjdk.org/jdk/compare/628cd8a489fd54db18204c3bbaf4339d7ab5e9d6...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.

As you do not have Committer status in this project an existing Committer must agree to sponsor your change. Possible candidates are the reviewers of this PR (@dholmes-ora, @tstuefe, @coleenp) but any other Committer may sponsor as well.

➡️ To flag this PR as ready for integration with the above commit message, type /integrate in a new comment. (Afterwards, your sponsor types /sponsor in a new comment to perform the integration).

openjdk[bot] avatar Feb 20 '24 15:02 openjdk[bot]

Breaks AIX build: os_aix.cpp:1626:5: error: unknown type name 'ErrorPreserver'; did you mean 'ErrnoPreserver'?

New test is failing on linux PPC64le: TestMemoryAllocationLogging.java#testUncommitFailed

 exitValue = 139

java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [139]
	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:521)
	at TestMemoryAllocationLogging.runTestWithOptions(TestMemoryAllocationLogging.java:202)
	at TestMemoryAllocationLogging.main(TestMemoryAllocationLogging.java:195)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1575)

Hi @TheRealMDoerr, any chance you could share the *.jtr file with me so I can take a closer look at the PPC64le failure? Thanks for running the tests!

SoniaZaldana avatar Feb 20 '24 16:02 SoniaZaldana

Do you need more than the System.err output?

 stdout: [[0.002s][debug][os,map] Reserved [0x00007fffb1960000 - 0x00007fffb1970000), (65536 bytes)
[0.002s][debug][os,map] Committed [0x00007fffb1960000 - 0x00007fffb1970000), (65536 bytes)
[0.004s][debug][os,map] Committed [0x00007fffaec10000 - 0x00007fffaec40000), (196608 bytes)
[0.005s][debug][os,map] Reserved [0x00007fff90a40000 - 0x00007fff9fa40000), (251658240 bytes)
[0.005s][debug][os,map] Committed [0x00007fff97e00000 - 0x00007fff98000000), (2097152 bytes)
[0.005s][debug][os,map] Reserved [0x00007fffae2c0000 - 0x00007fffae2e0000), (131072 bytes)
[0.005s][debug][os,map] Committed [0x00007fffae2c0000 - 0x00007fffae2d0000), (65536 bytes)
[0.005s][debug][os,map] Committed [0x00007fff90a40000 - 0x00007fff90c40000), (2097152 bytes)
[0.005s][debug][os,map] Reserved [0x00007fffae1d0000 - 0x00007fffae2c0000), (983040 bytes)
[0.005s][debug][os,map] Committed [0x00007fffae1d0000 - 0x00007fffae1e0000), (65536 bytes)
[0.006s][debug][os,map] Committed [0x00007fff98670000 - 0x00007fff98870000), (2097152 bytes)
[0.006s][debug][os,map] Reserved [0x00007fffae0e0000 - 0x00007fffae1d0000), (983040 bytes)
[0.006s][debug][os,map] Committed [0x00007fffae0e0000 - 0x00007fffae0f0000), (65536 bytes)
[0.019s][debug][os,map] Reserved [0x00000000fe000000 - 0x0000000100000000), (33554432 bytes)
[0.019s][debug][os,map] Reserved [0x00007fffaeba0000 - 0x00007fffaebb0000), (65536 bytes)
[0.019s][debug][os,map] Reserved [0x00007fffac0f0000 - 0x00007fffac100000), (65536 bytes)
[0.019s][debug][os,map] Reserved [0x00007fffac070000 - 0x00007fffac0f0000), (524288 bytes)
[0.019s][debug][os,map] Reserved [0x00007fffac060000 - 0x00007fffac070000), (65536 bytes)
[0.020s][debug][os,map] Reserved [0x00007fff8d640000 - 0x00007fff8f640000), (33554432 bytes)
[0.020s][debug][os,map] Committed [0x00007fff8d640000 - 0x00007fff8f640000), (33554432 bytes)
[0.035s][debug][os,map] Reserved [0x0000000800000000 - 0x0000000841000000), (1090519040 bytes)
[0.035s][debug][os,map] Released [0x0000000800000000 - 0x0000000841000000), (1090519040 bytes)
[0.035s][debug][os,map] reserve_between (range [0x0000000100000000-0x0001000000000000), size 0x41000000, alignment 0x100000000, randomize: 1)
[0.035s][trace][os,map] before reserve, 32 Points: 40 32120 1814 30964 2929 30001 3184 29643 4112 27899 5148 26897 6884 26456 7802 24834 8193 23633 9418 23061 10247 22165 11949 20547 12790 19711 14147 18647 14746 17802 15828 17381 
[0.035s][trace][os,map] result: 0x0000002900000000 range [0x0000000100000000-0x0001000000000000), size 0x41000000, alignment 0x100000000, randomize: 1
[0.035s][debug][os,map] successfully attached at 0x0000002900000000
[0.155s][debug][os,map] Committed [0x0000002901040000 - 0x0000002901050000), (65536 bytes)
[0.155s][debug][os,map] Reserved [0x00007fff6c000000 - 0x00007fff70000000), (67108864 bytes)
[0.155s][debug][os,map] Committed [0x00007fff6c000000 - 0x00007fff6c010000), (65536 bytes)
[0.194s][debug][os,map] Committed [0x00007fff7db40000 - 0x00007fff7db70000), (196608 bytes)
[0.195s][debug][os,map] Committed [0x00007fff7d940000 - 0x00007fff7d970000), (196608 bytes)
[0.196s][debug][os,map] Committed [0x00007fff7d740000 - 0x00007fff7d770000), (196608 bytes)
[0.196s][debug][os,map] Committed [0x00007fff7d540000 - 0x00007fff7d570000), (196608 bytes)
[0.196s][debug][os,map] Committed [0x00007fff7d340000 - 0x00007fff7d370000), (196608 bytes)
[0.196s][debug][os,map] Committed [0x00007fff7cf40000 - 0x00007fff7cf70000), (196608 bytes)
[0.197s][debug][os,map] Committed [0x00007fff7cb40000 - 0x00007fff7cb70000), (196608 bytes)
[0.234s][debug][os,map] Committed [0x00007fff7c940000 - 0x00007fff7c970000), (196608 bytes)
[0.245s][debug][os,map] Committed [0x00007fff6c010000 - 0x00007fff6c020000), (65536 bytes)
[0.246s][debug][os,map] Committed [0x00007fff7c740000 - 0x00007fff7c770000), (196608 bytes)
[0.252s][debug][os,map] Committed [0x00007fff6c400000 - 0x00007fff6c410000), (65536 bytes)
[0.252s][debug][os,map] Committed [0x0000002901000000 - 0x0000002901010000), (65536 bytes)
Tester execution...
[0.263s][debug][os,map] Committed [0x00007fff6c020000 - 0x00007fff6c030000), (65536 bytes)
[0.338s][debug][os,map] Committed [0x00007fff6c030000 - 0x00007fff6c040000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff7c340000 - 0x00007fff7c370000), (196608 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98000000 - 0x00007fff98010000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98010000 - 0x00007fff98020000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98020000 - 0x00007fff98030000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98030000 - 0x00007fff98040000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98040000 - 0x00007fff98050000), (65536 bytes)
[0.351s][debug][os,map] Committed [0x00007fff98050000 - 0x00007fff98060000), (65536 bytes)
[0.362s][debug][os,map] Committed [0x00007fff98060000 - 0x00007fff98070000), (65536 bytes)
[0.370s][debug][os,map] Reserved [0x00007fff7c330000 - 0x00007fff7c340000), (65536 bytes)
];

TheRealMDoerr avatar Feb 20 '24 17:02 TheRealMDoerr

Hi @TheRealMDoerr, I think I've sorted out the errors you reported. Root cause for the linux ppc64le failure was in the test set up.

Could you possibly run the tests again when you have a chance?

Thank you for your help!

SoniaZaldana avatar Mar 13 '24 14:03 SoniaZaldana

The build issue is resolved. Thanks. However, the tests are still failing:

linux ppc64le:

 stdout: [[0.003s][debug][os,map] Reserved [0x00007fff8c9b0000 - 0x00007fff8c9c0000), (65536 bytes)
[0.003s][debug][os,map] Committed [0x00007fff8c9b0000 - 0x00007fff8c9c0000), (65536 bytes)
[0.005s][debug][os,map] Committed [0x00007fff89c60000 - 0x00007fff89c90000), (196608 bytes)
[0.006s][debug][os,map] Reserved [0x00007fff6cae0000 - 0x00007fff7bae0000), (251658240 bytes)
[0.006s][debug][os,map] Committed [0x00007fff73ea0000 - 0x00007fff740a0000), (2097152 bytes)
[0.006s][debug][os,map] Reserved [0x00007fff89310000 - 0x00007fff89330000), (131072 bytes)
[0.006s][debug][os,map] Committed [0x00007fff89310000 - 0x00007fff89320000), (65536 bytes)
[0.006s][debug][os,map] Committed [0x00007fff6cae0000 - 0x00007fff6cce0000), (2097152 bytes)
[0.007s][debug][os,map] Reserved [0x00007fff89220000 - 0x00007fff89310000), (983040 bytes)
[0.007s][debug][os,map] Committed [0x00007fff89220000 - 0x00007fff89230000), (65536 bytes)
[0.007s][debug][os,map] Committed [0x00007fff74710000 - 0x00007fff74910000), (2097152 bytes)
[0.007s][debug][os,map] Reserved [0x00007fff89130000 - 0x00007fff89220000), (983040 bytes)
[0.007s][debug][os,map] Committed [0x00007fff89130000 - 0x00007fff89140000), (65536 bytes)
[0.018s][debug][os,map] Reserved [0x00000000fe000000 - 0x0000000100000000), (33554432 bytes)
[0.018s][debug][os,map] Reserved [0x00007fff89bf0000 - 0x00007fff89c00000), (65536 bytes)
[0.018s][debug][os,map] Reserved [0x00007fff88020000 - 0x00007fff88030000), (65536 bytes)
[0.018s][debug][os,map] Reserved [0x00007fff6adb0000 - 0x00007fff6ae30000), (524288 bytes)
[0.018s][debug][os,map] Reserved [0x00007fff88010000 - 0x00007fff88020000), (65536 bytes)
[0.019s][debug][os,map] Reserved [0x00007fff68780000 - 0x00007fff6a780000), (33554432 bytes)
[0.019s][debug][os,map] Committed [0x00007fff68780000 - 0x00007fff6a780000), (33554432 bytes)
[0.028s][debug][os,map] Reserved [0x0000000800000000 - 0x0000000841000000), (1090519040 bytes)
[0.028s][debug][os,map] Released [0x0000000800000000 - 0x0000000841000000), (1090519040 bytes)
[0.028s][debug][os,map] reserve_between (range [0x0000000100000000-0x0001000000000000), size 0x41000000, alignment 0x100000000, randomize: 1)
[0.028s][trace][os,map] before reserve, 32 Points: 924 32540 1921 31403 2814 29709 3540 29572 4922 27763 5745 27375 7008 25987 7234 25189 8712 24283 9722 23243 10454 22384 11262 21339 12639 20284 13632 19431 15333 17843 16186 17283 
[0.028s][trace][os,map] result: 0x0000039d00000000 range [0x0000000100000000-0x0001000000000000), size 0x41000000, alignment 0x100000000, randomize: 1
[0.028s][debug][os,map] successfully attached at 0x0000039d00000000
[0.096s][debug][os,map] Committed [0x0000039d01040000 - 0x0000039d01050000), (65536 bytes)
[0.096s][debug][os,map] Reserved [0x00007fff48000000 - 0x00007fff4c000000), (67108864 bytes)
[0.097s][debug][os,map] Committed [0x00007fff48000000 - 0x00007fff48010000), (65536 bytes)
[0.118s][debug][os,map] Committed [0x00007fff58c30000 - 0x00007fff58c60000), (196608 bytes)
[0.118s][debug][os,map] Committed [0x00007fff58a30000 - 0x00007fff58a60000), (196608 bytes)
[0.119s][debug][os,map] Committed [0x00007fff58830000 - 0x00007fff58860000), (196608 bytes)
[0.119s][debug][os,map] Committed [0x00007fff58630000 - 0x00007fff58660000), (196608 bytes)
[0.120s][debug][os,map] Committed [0x00007fff58430000 - 0x00007fff58460000), (196608 bytes)
[0.120s][debug][os,map] Committed [0x00007fff58030000 - 0x00007fff58060000), (196608 bytes)
[0.120s][debug][os,map] Committed [0x00007fff2fc00000 - 0x00007fff2fc30000), (196608 bytes)
[0.145s][debug][os,map] Committed [0x00007fff2fa00000 - 0x00007fff2fa30000), (196608 bytes)
[0.152s][debug][os,map] Committed [0x00007fff48010000 - 0x00007fff48020000), (65536 bytes)
[0.152s][debug][os,map] Committed [0x00007fff2f800000 - 0x00007fff2f830000), (196608 bytes)
[0.156s][debug][os,map] Committed [0x00007fff48400000 - 0x00007fff48410000), (65536 bytes)
[0.157s][debug][os,map] Committed [0x0000039d01000000 - 0x0000039d01010000), (65536 bytes)
Tester execution...
[0.164s][debug][os,map] Committed [0x00007fff48020000 - 0x00007fff48030000), (65536 bytes)
[0.217s][debug][os,map] Committed [0x00007fff48030000 - 0x00007fff48040000), (65536 bytes)
[0.231s][debug][os,map] Committed [0x00007fff2f400000 - 0x00007fff2f430000), (196608 bytes)
[0.231s][debug][os,map] Committed [0x00007fff740a0000 - 0x00007fff740b0000), (65536 bytes)
[0.231s][debug][os,map] Committed [0x00007fff740b0000 - 0x00007fff740c0000), (65536 bytes)
[0.231s][debug][os,map] Committed [0x00007fff740c0000 - 0x00007fff740d0000), (65536 bytes)
[0.231s][debug][os,map] Committed [0x00007fff740d0000 - 0x00007fff740e0000), (65536 bytes)
[0.245s][debug][os,map] Committed [0x00007fff740e0000 - 0x00007fff740f0000), (65536 bytes)
[0.249s][debug][os,map] Reserved [0x00007fff58020000 - 0x00007fff58030000), (65536 bytes)
[0.250s][trace][os,map] Kernel rejected 0xffffffffffffffff, offered 0x000fffff8ca20000.
[0.250s][info ][os,map] Attempt to reserve [0xffffffffffffffff - 0x000000000000ffff), (65536 bytes) failed
[0.250s][debug][os,map] Uncommitted [0x00007fff89c60000 - 0x00007fff89c90000), (196608 bytes)
[0.250s][debug][os,map] Committed [0x00007fff89c60000 - 0x00007fff89c90000), (196608 bytes)
[0.251s][debug][os,map] Uncommitted [0x00007fff89c60000 - 0x00007fff89c90000), (196608 bytes)
[0.251s][debug][os,map] Uncommitted [0x00007fff58830000 - 0x00007fff58860000), (196608 bytes)
];
 stderr: []
 exitValue = 0

java.lang.RuntimeException: 'mmap failed: \\[0x.* - 0x.*\\), \\(.* bytes\\) errno=' missing from stdout/stderr
	at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:371)
	at TestMemoryAllocationLogging.checkExpectedLogMessages(TestMemoryAllocationLogging.java:208)
	at TestMemoryAllocationLogging.main(TestMemoryAllocationLogging.java:196)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1575)

AIX:

 stdout: [[0.007s][trace][os,map] shm-allocated succeeded: [0x0a00010000000000 - 0x0a0001000f000000), (251658240 bytes) (3840 64K pages)
[0.007s][debug][os,map] Reserved [0x0a00010000000000 - 0x0a0001000f000000), (251658240 bytes)
[0.007s][debug][os,map] Committed [0x0a00010007410000 - 0x0a00010007610000), (2097152 bytes)
[0.007s][trace][os,map] shm-allocated succeeded: [0x0a00010010000000 - 0x0a00010010010000), (65536 bytes) (1 64K pages)
[0.007s][debug][os,map] Reserved [0x0a00010010000000 - 0x0a00010010010000), (65536 bytes)
[0.007s][debug][os,map] Committed [0x0a00010010000000 - 0x0a00010010010000), (65536 bytes)
[0.008s][debug][os,map] Committed [0x0a00010000000000 - 0x0a00010000200000), (2097152 bytes)
[0.008s][trace][os,map] shm-allocated succeeded: [0x0a00010020000000 - 0x0a000100200f0000), (983040 bytes) (15 64K pages)
[0.008s][debug][os,map] Reserved [0x0a00010020000000 - 0x0a000100200f0000), (983040 bytes)
[0.008s][debug][os,map] Committed [0x0a00010020000000 - 0x0a00010020010000), (65536 bytes)
[0.009s][debug][os,map] Committed [0x0a00010007bf0000 - 0x0a00010007df0000), (2097152 bytes)
[0.009s][trace][os,map] shm-allocated succeeded: [0x0a00010030000000 - 0x0a000100300f0000), (983040 bytes) (15 64K pages)
[0.009s][debug][os,map] Reserved [0x0a00010030000000 - 0x0a000100300f0000), (983040 bytes)
[0.009s][debug][os,map] Committed [0x0a00010030000000 - 0x0a00010030010000), (65536 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x00000000f0000000 - 0x00000000f2000000), (33554432 bytes) (512 64K pages)
[0.017s][debug][os,map] Reserved [0x00000000f0000000 - 0x00000000f2000000), (33554432 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x0a00010040000000 - 0x0a00010040010000), (65536 bytes) (1 64K pages)
[0.017s][debug][os,map] Reserved [0x0a00010040000000 - 0x0a00010040010000), (65536 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x0a00010050000000 - 0x0a00010050010000), (65536 bytes) (1 64K pages)
[0.017s][debug][os,map] Reserved [0x0a00010050000000 - 0x0a00010050010000), (65536 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x0a00010060000000 - 0x0a00010060080000), (524288 bytes) (8 64K pages)
[0.017s][debug][os,map] Reserved [0x0a00010060000000 - 0x0a00010060080000), (524288 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x0a00010070000000 - 0x0a00010070010000), (65536 bytes) (1 64K pages)
[0.017s][debug][os,map] Reserved [0x0a00010070000000 - 0x0a00010070010000), (65536 bytes)
[0.017s][trace][os,map] shm-allocated succeeded: [0x0a00010080000000 - 0x0a00010082000000), (33554432 bytes) (512 64K pages)
[0.017s][debug][os,map] Reserved [0x0a00010080000000 - 0x0a00010082000000), (33554432 bytes)
[0.017s][debug][os,map] Committed [0x0a00010080000000 - 0x0a00010082000000), (33554432 bytes)
[0.024s][debug][os,map] reserve_between (range [0x0000000000000000-0x0000000100000000), size 0x40000000, alignment 0x1000000, randomize: 1)
[0.024s][debug][os,map] reserve_between (range [0x0000000100000000-0x0000000800000000), size 0x40000000, alignment 0x1000000, randomize: 1)
[0.024s][trace][os,map] before reserve, 32 Points: 16 38 92 71 24 52 9 29 46 2 22 5 95 65 31 73 85 6 60 43 19 49 56 83 89 79 59 39 34 68 14 76 
[0.024s][info ][os,map] Wish address 0x0000000200000000 is too close to the BRK segment.
[0.024s][trace][os,map] Failed to attach at 0x0000000200000000
[0.024s][trace][os,map] shm-allocated succeeded: [0x0000000360000000 - 0x00000003a0000000), (1073741824 bytes) (16384 64K pages)
[0.024s][trace][os,map] result: 0x0000000360000000 range [0x0000000100000000-0x0000000800000000), size 0x40000000, alignment 0x1000000, randomize: 1
[0.024s][debug][os,map] successfully attached at 0x0000000360000000
[0.026s][debug][os,map] Committed [0x0000000360040000 - 0x0000000360050000), (65536 bytes)
[0.026s][trace][os,map] shm-allocated succeeded: [0x0a00010090000000 - 0x0a00010094000000), (67108864 bytes) (1024 64K pages)
[0.026s][debug][os,map] Reserved [0x0a00010090000000 - 0x0a00010094000000), (67108864 bytes)
[0.026s][debug][os,map] Committed [0x0a00010090000000 - 0x0a00010090010000), (65536 bytes)
[0.037s][debug][os,map] Committed [0x0a00010090010000 - 0x0a00010090020000), (65536 bytes)
[0.039s][debug][os,map] Committed [0x0a00010090020000 - 0x0a00010090030000), (65536 bytes)
[0.041s][debug][os,map] Committed [0x0a00010090030000 - 0x0a00010090040000), (65536 bytes)
[0.044s][debug][os,map] Committed [0x0a00010090040000 - 0x0a00010090050000), (65536 bytes)
[0.047s][debug][os,map] Committed [0x0a00010090050000 - 0x0a00010090060000), (65536 bytes)
[0.049s][debug][os,map] Committed [0x0a00010090060000 - 0x0a00010090070000), (65536 bytes)
[0.051s][debug][os,map] Committed [0x0a00010090070000 - 0x0a00010090080000), (65536 bytes)
[0.053s][debug][os,map] Committed [0x0a00010090080000 - 0x0a00010090090000), (65536 bytes)
[0.055s][debug][os,map] Committed [0x0a00010090090000 - 0x0a000100900a0000), (65536 bytes)
[0.058s][debug][os,map] Committed [0x0a000100900a0000 - 0x0a000100900b0000), (65536 bytes)
[0.060s][debug][os,map] Committed [0x0a000100900b0000 - 0x0a000100900c0000), (65536 bytes)
[0.061s][debug][os,map] Committed [0x0a000100900c0000 - 0x0a000100900d0000), (65536 bytes)
[0.064s][debug][os,map] Committed [0x0a000100900d0000 - 0x0a000100900e0000), (65536 bytes)
[0.064s][debug][os,map] Committed [0x0000000360050000 - 0x0000000360060000), (65536 bytes)
[0.065s][debug][os,map] Committed [0x0a000100900e0000 - 0x0a000100900f0000), (65536 bytes)
[0.068s][debug][os,map] Committed [0x0a000100900f0000 - 0x0a00010090100000), (65536 bytes)
[0.069s][debug][os,map] Committed [0x0a00010090100000 - 0x0a00010090110000), (65536 bytes)
[0.071s][debug][os,map] Committed [0x0a00010090110000 - 0x0a00010090120000), (65536 bytes)
[0.073s][debug][os,map] Committed [0x0a00010090120000 - 0x0a00010090130000), (65536 bytes)
[0.075s][debug][os,map] Committed [0x0a00010090130000 - 0x0a00010090140000), (65536 bytes)
[0.077s][debug][os,map] Committed [0x0a00010090140000 - 0x0a00010090150000), (65536 bytes)
[0.080s][debug][os,map] Committed [0x0a00010090150000 - 0x0a00010090160000), (65536 bytes)
[0.082s][debug][os,map] Committed [0x0a00010090160000 - 0x0a00010090170000), (65536 bytes)
[0.084s][debug][os,map] Committed [0x0a00010090170000 - 0x0a00010090180000), (65536 bytes)
[0.114s][debug][os,map] Committed [0x0a00010090180000 - 0x0a00010090190000), (65536 bytes)
[0.118s][debug][os,map] Committed [0x0a00010090190000 - 0x0a000100901a0000), (65536 bytes)
[0.124s][debug][os,map] Committed [0x0a000100901a0000 - 0x0a000100901b0000), (65536 bytes)
[0.127s][debug][os,map] Committed [0x0000000360060000 - 0x0000000360070000), (65536 bytes)
[0.171s][debug][os,map] Committed [0x0a000100901b0000 - 0x0a000100901c0000), (65536 bytes)
[0.173s][debug][os,map] Committed [0x0a000100901c0000 - 0x0a000100901d0000), (65536 bytes)
[0.177s][debug][os,map] Committed [0x0a000100901d0000 - 0x0a000100901e0000), (65536 bytes)
[0.180s][debug][os,map] Committed [0x0a000100901e0000 - 0x0a000100901f0000), (65536 bytes)
[0.186s][debug][os,map] Committed [0x0a000100901f0000 - 0x0a00010090200000), (65536 bytes)
[0.191s][debug][os,map] Committed [0x0a00010090200000 - 0x0a00010090210000), (65536 bytes)
[0.194s][debug][os,map] Committed [0x0a00010090210000 - 0x0a00010090220000), (65536 bytes)
[0.237s][debug][os,map] Committed [0x0a00010090220000 - 0x0a00010090230000), (65536 bytes)
[0.241s][debug][os,map] Committed [0x0a00010090230000 - 0x0a00010090240000), (65536 bytes)
[0.250s][debug][os,map] Committed [0x0a00010090240000 - 0x0a00010090250000), (65536 bytes)
[0.253s][debug][os,map] Committed [0x0a00010090250000 - 0x0a00010090260000), (65536 bytes)
[0.256s][debug][os,map] Committed [0x0a00010090260000 - 0x0a00010090270000), (65536 bytes)
[0.258s][debug][os,map] Committed [0x0000000360070000 - 0x0000000360080000), (65536 bytes)
[0.259s][debug][os,map] Committed [0x0a00010090270000 - 0x0a00010090280000), (65536 bytes)
[0.261s][debug][os,map] Committed [0x0a00010090280000 - 0x0a00010090290000), (65536 bytes)
[0.262s][debug][os,map] Committed [0x0a00010090290000 - 0x0a000100902a0000), (65536 bytes)
[0.265s][debug][os,map] Committed [0x0a000100902a0000 - 0x0a000100902b0000), (65536 bytes)
[0.270s][debug][os,map] Committed [0x0a000100902b0000 - 0x0a000100902c0000), (65536 bytes)
[0.272s][debug][os,map] Committed [0x0a000100902c0000 - 0x0a000100902d0000), (65536 bytes)
[0.279s][debug][os,map] Committed [0x0a000100902d0000 - 0x0a000100902e0000), (65536 bytes)
[0.283s][debug][os,map] Committed [0x0a000100902e0000 - 0x0a000100902f0000), (65536 bytes)
[0.284s][debug][os,map] Committed [0x0a000100902f0000 - 0x0a00010090300000), (65536 bytes)
[0.287s][debug][os,map] Committed [0x0a00010090300000 - 0x0a00010090310000), (65536 bytes)
[0.292s][debug][os,map] Committed [0x0a00010090310000 - 0x0a00010090320000), (65536 bytes)
[0.295s][debug][os,map] Committed [0x0a00010090320000 - 0x0a00010090330000), (65536 bytes)
[0.302s][debug][os,map] Committed [0x0a00010090330000 - 0x0a00010090340000), (65536 bytes)
[0.310s][debug][os,map] Committed [0x0a00010090340000 - 0x0a00010090350000), (65536 bytes)
[0.324s][debug][os,map] Committed [0x0a00010090350000 - 0x0a00010090360000), (65536 bytes)
[0.335s][debug][os,map] Committed [0x0000000360020000 - 0x0000000360030000), (65536 bytes)
[0.343s][debug][os,map] Committed [0x0a00010090360000 - 0x0a00010090370000), (65536 bytes)
[0.362s][debug][os,map] Committed [0x0a00010090370000 - 0x0a00010090380000), (65536 bytes)
[0.367s][debug][os,map] Committed [0x0a00010090380000 - 0x0a00010090390000), (65536 bytes)
[0.372s][debug][os,map] Committed [0x0a00010090390000 - 0x0a000100903a0000), (65536 bytes)
[0.377s][debug][os,map] Committed [0x0a000100903a0000 - 0x0a000100903b0000), (65536 bytes)
[0.388s][debug][os,map] Committed [0x0a000100903b0000 - 0x0a000100903c0000), (65536 bytes)
[0.405s][debug][os,map] Committed [0x0a000100903c0000 - 0x0a000100903d0000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007610000 - 0x0a00010007620000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007620000 - 0x0a00010007630000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007630000 - 0x0a00010007640000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007640000 - 0x0a00010007650000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007650000 - 0x0a00010007660000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007660000 - 0x0a00010007670000), (65536 bytes)
[0.409s][debug][os,map] Committed [0x0a00010007670000 - 0x0a00010007680000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007680000 - 0x0a00010007690000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007690000 - 0x0a000100076a0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076a0000 - 0x0a000100076b0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076b0000 - 0x0a000100076c0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076c0000 - 0x0a000100076d0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076d0000 - 0x0a000100076e0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076e0000 - 0x0a000100076f0000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a000100076f0000 - 0x0a00010007700000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007700000 - 0x0a00010007710000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007710000 - 0x0a00010007720000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007720000 - 0x0a00010007730000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007730000 - 0x0a00010007740000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007740000 - 0x0a00010007750000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007750000 - 0x0a00010007760000), (65536 bytes)
[0.410s][debug][os,map] Committed [0x0a00010007760000 - 0x0a00010007770000), (65536 bytes)
[0.419s][debug][os,map] Committed [0x0a000100903d0000 - 0x0a000100903e0000), (65536 bytes)
[0.426s][debug][os,map] Committed [0x0a000100903e0000 - 0x0a000100903f0000), (65536 bytes)
[0.428s][debug][os,map] Committed [0x0000000360030000 - 0x0000000360040000), (65536 bytes)
[0.434s][debug][os,map] Committed [0x0a000100903f0000 - 0x0a00010090400000), (65536 bytes)
[0.440s][debug][os,map] Committed [0x0a00010090400000 - 0x0a00010090410000), (65536 bytes)
[0.444s][debug][os,map] Committed [0x0a00010090500000 - 0x0a00010090510000), (65536 bytes)
[0.444s][debug][os,map] Committed [0x0000000360000000 - 0x0000000360010000), (65536 bytes)
[0.449s][debug][os,map] Committed [0x0a00010090410000 - 0x0a00010090420000), (65536 bytes)
Tester execution...
[0.452s][debug][os,map] Committed [0x0a00010090420000 - 0x0a00010090430000), (65536 bytes)
[0.455s][debug][os,map] Committed [0x0a00010090430000 - 0x0a00010090440000), (65536 bytes)
[0.460s][debug][os,map] Committed [0x0a00010090440000 - 0x0a00010090450000), (65536 bytes)
[0.463s][debug][os,map] Committed [0x0a00010090450000 - 0x0a00010090460000), (65536 bytes)
[0.469s][debug][os,map] Committed [0x0a00010090460000 - 0x0a00010090470000), (65536 bytes)
[0.473s][debug][os,map] Committed [0x0a00010090470000 - 0x0a00010090480000), (65536 bytes)
[0.478s][debug][os,map] Committed [0x0a00010090480000 - 0x0a00010090490000), (65536 bytes)
[0.482s][debug][os,map] Committed [0x0a00010090490000 - 0x0a000100904a0000), (65536 bytes)
[0.485s][debug][os,map] Committed [0x0a000100904a0000 - 0x0a000100904b0000), (65536 bytes)
[0.486s][debug][os,map] Committed [0x0000000360010000 - 0x0000000360020000), (65536 bytes)
[0.492s][debug][os,map] Committed [0x0a000100904b0000 - 0x0a000100904c0000), (65536 bytes)
[0.507s][debug][os,map] Committed [0x0a000100904c0000 - 0x0a000100904d0000), (65536 bytes)
[0.513s][debug][os,map] Committed [0x0a000100904d0000 - 0x0a000100904e0000), (65536 bytes)
[0.546s][debug][os,map] Committed [0x0a000100904e0000 - 0x0a000100904f0000), (65536 bytes)
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/openjdk-jdk-dev-aix_ppc64-dbg/jdk/src/hotspot/os/aix/os_aix.cpp:2023), pid=13369790, tid=258
#  Error: guarantee((vmi)) failed
#
# JRE version: OpenJDK Runtime Environment (23.0) (fastdebug build 23-internal-adhoc.sapmachine.jdk)
# Java VM: OpenJDK 64-Bit Server VM (fastdebug 23-internal-adhoc.sapmachine.jdk, mixed mode, tiered, compressed oops, compressed class ptrs, g1 gc, aix-ppc64)
# CreateCoredumpOnCrash turned off, no core file dumped
#
Unsupported internal testing APIs have been used.

# An error report file with more information is saved as:
# /output_openjdk23_dev_dbgU_rs6000_64/jtreg_hotspot_tier1_work/JTwork/scratch/11/hs_err_pid13369790.log
#
# If you would like to submit a bug report, please visit:
#   https://bugreport.java.com/bugreport/crash.jsp
#
];
 stderr: []
 exitValue = 1

java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:521)
	at TestMemoryAllocationLogging.runTestWithOptions(TestMemoryAllocationLogging.java:202)
	at TestMemoryAllocationLogging.main(TestMemoryAllocationLogging.java:195)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1575)

We also hit "assert(is_aligned_to(addr, os::vm_page_size())) failed: addr 0x0000000000000001 not aligned to vm_page_size (65536)" in runtime/os/TestMemoryAllocationLogging.java#testAttemptedReserveFailed.

TheRealMDoerr avatar Mar 14 '24 08:03 TheRealMDoerr

@SoniaZaldana About the AIX bug, this is the VMA accounting we do in AIX. It is highly likely that it complains about the sequence of invalid operations you throw as a test to the JVM. My proposal would be to disable this test for AIX and just let the AIX guys sort this out. After all, this is not a real issue. It may also be that in the future we don't need this bookkeeping anymore, there had been discussions around that with Joachim.

For testAttemptedReserveFailed, I would do:

  • reserve anywere
  • then attempt reserve at the same address

that will fail, but this should not assert, since the address in question is valid for attaching, its just occupied.

Other than that, to move this forward, I would reduce the tests for any remaining errors. You have done a lot more than your due diligence to get this running.

tstuefe avatar Mar 14 '24 08:03 tstuefe

Thanks for the update! The failures on PPC64 are gone.

TheRealMDoerr avatar Mar 18 '24 10:03 TheRealMDoerr

/integrate

SoniaZaldana avatar Mar 18 '24 14:03 SoniaZaldana

@SoniaZaldana Your change (at version 8d2ef122ecb2a5a1330d019225f36daf0da9e708) is now ready to be sponsored by a Committer.

openjdk[bot] avatar Mar 18 '24 14:03 openjdk[bot]

/sponsor

tstuefe avatar Mar 19 '24 15:03 tstuefe

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

  • f140eb4c3a47e1479d62fe1eef16bbbea92892bc: 8297879: javadoc link to preview JEP 1000 has grouping character comma
  • 5f2a92d954ce485d372c3cb3e5118556b1d076c3: 8328244: Convert javax/swing/JSlider/6742358/bug6742358.java applet test to main
  • 2094ff3c7ad829355bf13760d9a19b37649b3517: 8328279: Convert java/awt/Cursor/CursorOverlappedPanelsTest test to main
  • db4842c9d9696af311762cb9c809952c55b34623: 8328364: Remove redundant fields in 'BOTConstants'
  • c01095c0c9d4de1995d079be3356468196d9a25e: 8328262: Convert javax/swing/JSplitPane/8132123/bug8132123.java applet test to main
  • f1c69ccadb83306d1bb4860ff460a253af99643c: 8289822: G1: Make concurrent mark code owner of TAMSes
  • 5b6b514441fcbbaa210e2cad08ce2704fdf38191: 8325362: Allow to create a simple in-memory input JavaFileObject
  • c59c41aa6e28ab1dc59e6051f85e3e9ade251b07: 8326941: Remove StringUTF16::isBigEndian
  • 6eea5d675566adca3fca88639008c6c0221450a4: 8325187: JVMTI GetThreadState says virtual thread is JVMTI_THREAD_STATE_INTERRUPTED when it no longer is
  • 053ff76e14046f796f6e10a9cb2ede1f1ae22ed6: 8308660: C2 compilation hits 'node must be dead' assert
  • ... and 458 more: https://git.openjdk.org/jdk/compare/628cd8a489fd54db18204c3bbaf4339d7ab5e9d6...master

Your commit was automatically rebased without conflicts.

openjdk[bot] avatar Mar 19 '24 15:03 openjdk[bot]

@tstuefe @SoniaZaldana Pushed as commit 3b305d502b84b7f1cfa378a9c274ef0b9ee52524.

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

openjdk[bot] avatar Mar 19 '24 15:03 openjdk[bot]