Classloader warnings after updating to Java 21

Elastic Observability APM
1

After updating our JVM (and updated compile level) from Java 17 to 21 our logs are spammed with classloader warnings.

Here is the startup log of the agent:

2024-06-25 09:24:17,810 [Attach Listener] INFO  co.elastic.apm.agent.util.JmxUtils - Found JVM-specific OperatingSystemMXBean interface: com.sun.management.OperatingSystemMXBean
2024-06-25 09:24:17,888 [Attach Listener] INFO  co.elastic.apm.agent.util.JmxUtils - Found JVM-specific ThreadMXBean interface: com.sun.management.ThreadMXBean
2024-06-25 09:24:17,918 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - Starting Elastic APM 1.50.0 as *** (0.0.1-SNAPSHOT) on Java 21.0.3 Runtime version: 21.0.3+9-LTS VM version: 21.0.3+9-LTS (Eclipse Adoptium) Linux 6.1.85+
2024-06-25 09:24:17,919 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - environment: 'NL-DEV' (source: /configuration/elasticapm.properties)
2024-06-25 09:24:17,919 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - config_file: '/configuration/elasticapm.properties' (source: Environment Variables)
2024-06-25 09:24:17,920 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - plugins_dir: '/home/appuser/apm-plugins' (source: Environment Variables)
2024-06-25 09:24:17,920 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - activation_method: 'PROGRAMMATIC_SELF_ATTACH' (source: Attachment configuration)
2024-06-25 09:24:17,920 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - secret_token: 'XXXX' (source: /configuration/elasticapm.properties)
2024-06-25 09:24:17,920 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - server_urls: '****' (source: /configuration/elasticapm.properties)
2024-06-25 09:24:17,921 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - application_packages: '****' (source: /configuration/elasticapm.properties)
2024-06-25 09:24:17,921 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - profiling_inferred_spans_enabled: 'true' (source: Attachment configuration)
2024-06-25 09:24:17,921 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - profiling_inferred_spans_logging_enabled: 'false' (source: Attachment configuration)
2024-06-25 09:24:17,922 [Attach Listener] INFO  co.elastic.apm.agent.configuration.StartupInfo - profiling_inferred_spans_lib_directory: '/home/appuser/' (source: Attachment configuration)
2024-06-25 09:24:27,286 [Attach Listener] INFO  co.elastic.apm.agent.bci.bytebuddy.ErrorLoggingListener - org.springframework.web.context.support.GenericWebApplicationContext refers to a missing class.
2024-06-25 09:24:29,011 [Attach Listener] INFO  co.elastic.apm.agent.impl.ElasticApmTracer - Tracer switched to RUNNING state
2024-06-25 09:24:29,432 [elastic-apm-server-healthcheck] INFO  co.elastic.apm.agent.report.ApmServerHealthChecker - Elastic APM server is available: {  "build_date": "2021-12-18T19:59:06Z",  "build_sha": "24fe620eeff5a19e2133c940c7e5ce1ceddb1445",  "publish_ready": true,  "version": "7.16.2"}

After that we see this logging every couple of seconds:

[63.187s][warning][jni,resolve] Re-registering of platform native method: jdk.internal.loader.NativeLibraries.load(Ljdk/internal/loader/NativeLibraries$NativeLibraryImpl;Ljava/lang/String;ZZ)Z from code in a different classloader
[63.246s][warning][jni,resolve] Re-registering of platform native method: jdk.internal.loader.NativeLibraries.load(Ljdk/internal/loader/NativeLibraries$NativeLibraryImpl;Ljava/lang/String;ZZ)Z from code in a different classloader
[68.251s][warning][jni,resolve] Re-registering of platform native method: jdk.internal.loader.NativeLibraries.load(Ljdk/internal/loader/NativeLibraries$NativeLibraryImpl;Ljava/lang/String;ZZ)Z from code in a different classloader
[68.298s][warning][jni,resolve] Re-registering of platform native method: jdk.internal.loader.NativeLibraries.load(Ljdk/internal/loader/NativeLibraries$NativeLibraryImpl;Ljava/lang/String;ZZ)Z from code in a different classloader
[73.302s][warning][jni,resolve] Re-registering of platform native method: jdk.internal.loader.NativeLibraries.load(Ljdk/internal/loader/NativeLibraries$NativeLibraryImpl;Ljava/lang/String;ZZ)Z from code in a different classloader

Turning profiling off (profiling_inferred_spans_enabled=false) removes the logging, so it's caused by the profiler. I've already tried setting profiling_inferred_spans_logging_enabled to false after finding WARNING: Install JVM debug symbols to improve profile accuracy · Issue #1789 · elastic/apm-agent-java · GitHub but that did not help.

2

Seems related to this JDK issue to me:
https://bugs.openjdk.org/browse/JDK-8239593

Could you try the provided workaround of adding the -Xlog:jni+resolve=off jvm command line flag?

3

That does remove the logging. Any idea why this is suddenly necessary with Java 21?

4

Might be a regression of the linked JDK issue or an intended change of behaviour. I reproduced the issue myself, it started appearing with Java 20, Java 19 was still fine.

5

I did a bit more investigation on what actually causes the warning:
Async-Profiler 1.8.8 (which is used for the inferred spans feature) hooks onto the NativeLibraries.load call to detect other JNI-libraries being loaded at runtime. Here is the code performing this hooking, which unfortunatley cannot be disabled using any configuration option, so the only remaining option is to silence the warning logs via the option provided earlier.

1 Like