TestJlmRemoteMemoryNoAuth intermittently fails with 'Peak Usage used memory smaller than Current Usage used memory'

[Mesbah-Alam]

TestJlmRemoteMemoryNoAuth test intermittently fails with Peak Usage used memory smaller than Current Usage used memory.

We should revisit the unstable test to check its validity.

Example:

https://ci.adoptopenjdk.net/view/Test_system/job/openjdk12_hs_systemtest_x86-64_windows/71/tapResults/

CL1 stderr Exception in thread "main" java.lang.AssertionError: Peak Usage used memory smaller than Current Usage used memory
CL1 stderr 	at org.junit.Assert.fail(Assert.java:88)
CL1 stderr 	at net.adoptopenjdk.test.jlm.resources.MemoryData.checkPeakAndCurrentMemoryUsage(MemoryData.java:521)
CL1 stderr 	at net.adoptopenjdk.test.jlm.resources.MemoryData.writeData(MemoryData.java:182)
CL1 stderr 	at net.adoptopenjdk.test.jlm.remote.MemoryProfiler.getStatsViaProxy(MemoryProfiler.java:183)
CL1 stderr 	at net.adoptopenjdk.test.jlm.remote.MemoryProfiler.main(MemoryProfiler.java:110)
STF 11:07:08.791 - **FAILED** Process CL1 ended with exit code (1) and not the expected exit code/s (0)

[Mesbah-Alam]

5x Grinder passed 100%: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/1660/console

[Mesbah-Alam]

Summary of what the failing test is doing:

1. Given a list of instantiated MemoryPoolMXBean objects, the test invokes the java.lang.management.MemoryPoolMXBean.getUsage() API to get the "current usage" value; and then it invokes java.lang.management.MemoryPoolMXBean.getPeakUsage() to get the "peak usage" value.
2. It then performs the following validation:

long peakUsageUsed = peak_usage.getUsed();
		long currentUsageUsed = current_usage.getUsed();

		if (peakUsageUsed < currentUsageUsed) {
			Message.logErr("  Peak usage smaller than current usage here:");
			Message.logErr("  Memory Pool:              " + poolName);
			Message.logErr("  Memory Type:              " + poolType);
			Message.logErr("  Peak Usage:               " + peak_usage.toString());
			Message.logErr("  Current Usage:            " + current_usage.toString());
			Assert.fail("Peak Usage used memory smaller than Current Usage used memory");
		}

So, intermittently, on various platforms, this validation is failing.

Question is - whether or not this failure indicates something wrong with what we are testing - i.e., the JLM API of the SDK under test.

Java doc for java.lang.management.MemoryPoolMXBean.getUsage()

Returns an estimate of the memory usage of this memory pool. This method returns null if this memory pool is not valid (i.e. no longer exists).

This method requests the Java virtual machine to make a best-effort estimate of the current memory usage of this memory pool. For some memory pools, this method may be an expensive operation that requires some computation to determine the estimate. An implementation should document when this is the case.

This method is designed for use in monitoring system memory usage and detecting low memory condition.

Javadoc for java.lang.management.MemoryPoolMXBean.getPeakUsage()

Returns the peak memory usage of this memory pool since the Java virtual machine was started or since the peak was reset. This method returns null if this memory pool is not valid (i.e. no longer exists).

FYI..
@lumpfish @JasonFengJ9

[pshipton]

@LinHu2016 can you please take a look. Any relation to eclipse-openj9/openj9#5324?

[LinHu2016]

@pshipton I will take a look the issue, Thanks

[LinHu2016]

base on example (https://ci.adoptopenjdk.net/view/Test_system/job/openjdk12_hs_systemtest_x86-64_windows/71/tapResults/), the error is for OpenJDK hotspot G1, please provide the error case on OpenJ9, Thanks

CL1 stderr j> 2019/06/10 11:07:07.499 Peak usage smaller than current usage here:
CL1 stderr j> 2019/06/10 11:07:07.500 Memory Pool: G1 Old Gen
CL1 stderr j> 2019/06/10 11:07:07.501 Memory Type: Heap memory
CL1 stderr j> 2019/06/10 11:07:07.501 Peak Usage: init = 118489088(115712K) used = 12219608(11933K) committed = 118489088(115712K) max = 268435456(262144K)
CL1 stderr j> 2019/06/10 11:07:07.502 Current Usage: init = 118489088(115712K) used = 12241080(11954K) committed = 50331648(49152K) max = 268435456(262144K)
CL1 stderr Exception in thread "main" java.lang.AssertionError: Peak Usage used memory smaller than Current Usage used memory
CL1 stderr at org.junit.Assert.fail(Assert.java:88)
CL1 stderr at net.adoptopenjdk.test.jlm.resources.MemoryData.checkPeakAndCurrentMemoryUsage(MemoryData.java:521)
CL1 stderr at net.adoptopenjdk.test.jlm.resources.MemoryData.writeData(MemoryData.java:182)
CL1 stderr at net.adoptopenjdk.test.jlm.remote.MemoryProfiler.getStatsViaProxy(MemoryProfiler.java:183)
CL1 stderr at net.adoptopenjdk.test.jlm.remote.MemoryProfiler.main(MemoryProfiler.java:110)

[Mesbah-Alam]

@LinHu2016 : The error is intermittent. Started a Grinder for OpenJ9 here: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/1664/console

[LinHu2016]

Hi @Mesbah-Alam，Could you please share test code or point the test src code location? if it has the issue on both Hotspot and OpenJ9, sounds like issue is on JCL or testing code.

[Mesbah-Alam]

@LinHu2016 ,

The problem arises here: https://github.com/AdoptOpenJDK/openjdk-systemtest/blob/5d351a3f33c6e792c646b7a08539778c8a56caac/openjdk.test.jlm/src/test.jlm/net/adoptopenjdk/test/jlm/resources/MemoryData.java#L521

The actual test class is https://github.com/AdoptOpenJDK/openjdk-systemtest/blob/master/openjdk.test.jlm/src/test.jlm/net/adoptopenjdk/test/jlm/TestJlmRemoteMemoryNoAuth.java

[LinHu2016]

another thought it might relate nonheap memory pool(such as codecache?), wait the grinder to catch the issue on OpenJ9 for investigating the details.

[LinHu2016]

@LinHu2016 : The error is intermittent. Started a Grinder for OpenJ9 here: https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/1664/console

@Mesbah-Alam the Grinder failed to run the tests.