JDK-8130308 : Too low memory usage in TestPromotionFromSurvivorToTenuredAfterMinorGC.java
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 8,9
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2015-07-02
  • Updated: 2022-08-29
  • Resolved: 2015-08-18
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 8 JDK 9 Other
8u361Fixed 9 b81Fixed openjdk8u302Fixed
Related Reports
Relates :  
Relates :  
Description
This test is failing after hs-rt is merged with jdk9/hs, which means we can't sync down jdk9/hs to hs-rt. The test fails every time, only on Solaris x64.

Verifying memory usage in space: TENURED
Allocated objects count: 655360
Desired object size: 16
Actual object size: 16
Expected object size in space: 16
Expected memory usage: 14026192
Actual memory usage: 13075920
Memory usage diff: 950272
Max allowed usage diff: 701312
STDERR:
java.lang.RuntimeException: Actual memory usage should not deviate from expected for more then 701312 (assert failed: 950272 <= 701312)
	at jdk.test.lib.Asserts.error(Asserts.java:444)
	at jdk.test.lib.Asserts.assertTrue(Asserts.java:371)
	at jdk.test.lib.Asserts.assertLessThanOrEqual(Asserts.java:122)
	at jdk.test.lib.Asserts.assertLTE(Asserts.java:101)
	at SurvivorAlignmentTestMain.verifyMemoryUsage(SurvivorAlignmentTestMain.java:333)
	at TestPromotionFromSurvivorToTenuredAfterMinorGC.main(TestPromotionFromSurvivorToTenuredAfterMinorGC.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:502)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:745)

Comments
Fix Request (8u) This stabilizes the tests. Patch does not apply cleanly to 8u and requires minor adjustments. 8u RFR (acked by phh): https://mail.openjdk.java.net/pipermail/jdk8u-dev/2021-March/013485.html, https://mail.openjdk.java.net/pipermail/jdk8u-dev/2021-March/013490.html
02-03-2021

We have suspicious failures in 8u like this, might be worthwhile to backport this testbug fix.
13-01-2021

URL: http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/1facc49c0499 User: lana Date: 2015-09-09 21:33:20 +0000
09-09-2015

URL: http://hg.openjdk.java.net/jdk9/hs-rt/hotspot/rev/1facc49c0499 User: jwilhelm Date: 2015-08-18 17:57:07 +0000
18-08-2015

The fix was simpler than it first seemed. The test actually does a fairly good job of tracking data that is allocated by other threads in the JVM. The sum of anything allocated during the test was included in the expected memory usage at the end. The verification however only looks at what has been promoted to tenured space, since that is what the test is all about, so anything allocated during the test that is still in the survivor area at the end of the test (like the 1MB mentioned above) will not be counted. The proposed solution is to subtract the size of the data in the survivor area from the expected memory usage. Sending a webrev to hotspot-gc-dev now.
17-08-2015

Not really because a sleep based solution doesn't scale. Something we've done in the past: - refactor the test invocation into a separate method, e.g., do_my_test() - add a new test invocation loop, e.g.: for (loop_cnt = 0; loop_cnt < MAX_LOOP_CNT; loop_cnt++) { sleep(1); // give XXX 1 second to stabilize result = do_my_test(); if (result == PASS) { break; } } if (result == FAIL) { // all attempts failed so it's likely something is broken print information about the failures } I've see MAX_LOOP_CNT be 5 or 10 so we don't retry too many times, but...
13-08-2015

I tried to add a sleep for one second at the start of the test. This "fixed" the problem. Is this an acceptable solution?
13-08-2015

Running the test with -XX:+PrintGCDetails shows what happens here. The test does 16 young GCs in a loop to get data promoted from survivors to old. Usually all data in the survivor regions is promoted at the last GC, but with the JImage change (JDK-8080511) there is one meg left in the survivor afterwards. This causes the difference in the expected and actual memory usage and the test failure. This last meg is allocated after the first young GC and copied to the survivor area by the second young GC. This data is clearly not allocated by the test since the test doesn't do anything else than looping and calling young GCs at this point. It looks to me as the test needs to do a better job at tracking data allocated by the rest of the JVM during the test. Adding -XX:+PrintGCDetails made the test pass a few times, so it looks like this is timing dependent. That could explain why we only see this on Solaris, on other platforms the allocation is finished before the test starts. A possible fix, maybe not the nicest one though, could be to add a sleep before starting the test to make sure all boot related allocations etc are done. A better fix would be if the JVM could signal when it's done booting so that the test can wait for that signal. Since this is clearly a test issue I don't think it should be considered a regression. I suggest a new ILW: Low (one test is broken), High (always), High (none) = P4
12-08-2015

When applying the fix for JDK-8080511 to a copy of main from July 2 the test starts to fail.
12-08-2015

ILW = High (regression), High (happens in JPRT), High (none) = P1
06-07-2015

This is a regression, but it's not one that will cause sever problems for the VM. Except for the test that was quarantined I don't expect this to show up in any testing. It also seems likely that the change that caused this unexpected behavior in the heap is in main already. With this in mind I don't think this is a blocker for integration to main.
03-07-2015

Jesper used JDK-8130330 to quarantine this test.
03-07-2015

Not yet. I was hoping to find a machine where I could reproduce this locally instead of sending jprt jobs for each change in main, but I have not had any luck in reproducing it.
02-07-2015

Do we know what changeset in Main_Baseline is interacting badly with the current contents of RT_Baseline?
02-07-2015