RSS regression with 1.1.0.CR1 and GraalVM 19.3.0

[johnaohara]

Describe the bug
Report by Harald Reinmüller on zulip;

I just rerun my utilisation-tests with Quarkus 1.1.0.CR1 and GraalVM 19.3.0 Java 8 and noted that the memory footprint grow up from RSS 24MB to RSS 74MB for my simple demo project (JAX-RS + JSONB) and from RSS 45MB to RSS 100MB for my advanced demo project (JAX-RS + JPA).

Confirmed in the RSS test suite; regression occurred in nightly test on 2019-12-05

[geoand]

Do we have data from other days? Can we pinpoint when things increased so much?

[haraldatbmw]

Two plots out of my test-suite:

• Quarkus 1.0.1.Final with GraalVM 19.2.1
  https://github.com/rmh78/quarkus-performance/blob/master/plots/quarkus-native-simple_1.0.1.Final.png

• Quarkus 1.1.0.CR1 with GraalVM 19.3.0 (Java8)
  https://github.com/rmh78/quarkus-performance/blob/master/plots/quarkus-native-simple_1.1.0.CR1_GraalVM19.3.0.png

[johnaohara]

Yes, just looking through to pinpoint .

@haraldatbmw ty for the data points

[johnaohara]

commit 0be78a68 causes the startup RSS to go from 25.9MB to 97.1MB

[johnaohara]

There is now a large anon block of memory allocated;

00002b640ec3f000 49172 49172 49172 rw--- [ anon ]

[gastaldi]

Sounds like a regression in GraalVM

[emmanuelbernard]

Can you open an issue @johnaohara to the GraalVM team? Let's have conversations early.

[johnaohara]

Graal Issue opened: oracle/graal#1984

[emmanuelbernard]

Ah looks like you guys are in the right track (graal issue discussion). I thought about it last night too. Probably a netty buffer which means our old way of keeping it in check is no longer recognized when run under 19.3 CC @stuartwdouglas

[jaikiran]

Hello @johnaohara Is there a set of steps to consistently reproduce this using that getting-started quickstart? My experiments so far, using a docker build (through the Dockerfile.native) for 19.2 and 19.3 haven't shown any major difference in the RSS size of the application? I didn't fire any requests against the application. Just booted it up and waited a few minutes before checking the pmap output.

[johnaohara]

@jaikiran Which platform are you testing on? To reproduce;

Build against 19.3.0

1. checkout quarkus at commit 0be78a6
2. build the getting-started quickstart on the development branch of quarkus-quickstarts
3. export GRAALVM_HOME=/path/to/graal-19.3.0
4. mvn package -Pnative -DskipTests
5. ./target/getting-started-1.0-SNAPSHOT-runner -Xmx2m

You should see the process taking ~63MB of memory

Build against 19.2.1

1. checkout quarkus at commit 64d8612
2. build the getting-started quickstart on the development branch of quarkus-quickstarts
3. export GRAALVM_HOME=/path/to/graal-19.2.1
4. mvn package -Pnative -DskipTests
5. ./target/getting-started-1.0-SNAPSHOT-runner -Xmx2m

You should see the process taking ~14MB of memory.

Those numbers are at startup without sending any requests

Yesterday I spent time tracing out calls to allocate native memory. So far I have not found netty allocating any native memory, but I have found this;

**** java.nio.DirectByteBuffer.<init>
**** Address: 23874613
**** Capacity: 2147483647
Invoking constructor of DirectByteBuffer
java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:163)
com.oracle.svm.core.c.CTypeConversionSupportImpl.asByteBuffer(CTypeConversionSupportImpl.java:149)
org.graalvm.nativeimage.c.type.CTypeConversion.asByteBuffer(CTypeConversion.java:276)
com.oracle.svm.jni.functions.JNIFunctions.NewStringUTF(JNIFunctions.java:442)
com.oracle.svm.core.jdk.JNIPlatformNativeLibrarySupport.nativeNewStringPlatform(JNIPlatformNativeLibrarySupport.java:-1)
com.oracle.svm.core.jdk.JNIPlatformNativeLibrarySupport.initializeEncoding(JNIPlatformNativeLibrarySupport.java:88)
com.oracle.svm.core.jdk.JNIPlatformNativeLibrarySupport.loadJavaLibrary(JNIPlatformNativeLibrarySupport.java:53)
com.oracle.svm.core.posix.PosixNativeLibrarySupport.loadJavaLibrary(PosixNativeLibraryFeature.java:121)
com.oracle.svm.core.posix.PosixNativeLibrarySupport.initializeBuiltinLibraries(PosixNativeLibraryFeature.java:101)
com.oracle.svm.core.graal.snippets.CEntryPointSnippets.initializeIsolate(CEntryPointSnippets.java:252)

I will spend some time this afternoon verifying that this is the cause of the increase in memory.

[johnaohara]

Building getting started quickstart with #6574 and 19.3.1, the startup RSS is now the same as building with 19.2.1

Build Version	RSS (KB)
RSS_REGRESSION-graalvm-ce-19.2.1	17216
RSS_REGRESSION-graalvm-ce-java8-19.3.0.2	94716
RSS_REGRESSION-graalvm-ce-java11-19.3.0.2	86480
RSS_REGRESSION-graalvm-ce-java11-19.3.1	17140
RSS_REGRESSION-graalvm-ce-java8-19.3.1	17232

[geoand]

@gsmet should we continue with the dual version approach or bump to 19.3.1 in light of the results that @johnaohara posted?

It's probably too late for the latter...

[haraldatbmw]

@johnaohara I can confirm that the memory usage is in the range it was before.
I think this issue can be closed.

Quarkus 1.2.0.CR1 with GraalVM 19.3.1

Quarkus 1.0.1.Final with GraalVM 19.2.1

[gsmet]

We can close this one, everything is OK with 19.3.1.

Thanks @johnaohara and @haraldatbmw .