Spring boot runtime metrics

[zeitlinger]

Fixes #12812

[zeitlinger]

@jeanbisutti can you help me with the native failures:

1. not sure in this is transient:

Failures (1):
  JUnit Jupiter:OtelSpringStarterSmokeTest:shouldSendTelemetry()
    MethodSource [className = 'io.opentelemetry.spring.smoketest.OtelSpringStarterSmokeTest', methodName = 'shouldSendTelemetry', methodParameterTypes = '']
    => org.awaitility.core.ConditionTimeoutException: Assertion condition defined as a Lambda expression in io.opentelemetry.instrumentation.testing.InstrumentationTestRunner
Expecting actual not to be empty within 10 seconds.
       org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:119)
       org.awaitility.core.AssertionCondition.await(AssertionCondition.java:31)
       org.awaitility.core.ConditionFactory.until(ConditionFactory.java:1006)
       org.awaitility.core.ConditionFactory.untilAsserted(ConditionFactory.java:790)
       [...]
     Caused by: org.awaitility.core.DeadlockException: Deadlocked threads detected:


       org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:159)
       [...]

2. numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small. - should we increase the buffer?

3. thread started: this if for JFR - I'll try @PreDestry for this

The web application [ROOT] appears to have started a thread named [BatchLogRecordProcessor_WorkerThread-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.headers.Pthread.pthread_cond_timedwait(Pthread.java)
 org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixParker.park0(PosixPlatformThreads.java:379)
 org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixParker.park(PosixPlatformThreads.java:354)
 org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.parkCurrentPlatformOrCarrierThread(PlatformThreads.java:1001)
 java.base@21.0.6/jdk.internal.misc.Unsafe.park(Unsafe.java:56)
 java.base@21.0.6/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:269)
 java.base@21.0.6/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1763)
 java.base@21.0.6/java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435)
 io.opentelemetry.sdk.logs.export.BatchLogRecordProcessor$Worker.run(BatchLogRecordProcessor.java:246)
 java.base@21.0.6/java.lang.Thread.runWith(Thread.java:1596)
 java.base@21.0.6/java.lang.Thread.run(Thread.java:1583)

[jeanbisutti]

@zeitlinger About 1., it seems an awaitility issue. Does the problem only appear with the new changes? Perhaps it may be worth to do something like

opentelemetry-java-instrumentation/testing-common/src/main/java/io/opentelemetry/instrumentation/testing/InstrumentationTestRunner.java

Line 125 in edbd9aa

// awaitility is doing a jmx call that is not implemented in GraalVM:

But I am not sure today it would be a good thing to do. It would require some further investigations.

About 2., numLogsCapturedBeforeOtelInstall default value is high: 1 000 logs. I suspect that the warning is related to something specific to the test.

About 3., it seems related to Tomcat searching memory leaks. With the full log we could know if it really comes from Tomcat. It does not seem possible to stop the BatchLogRecordProcessor thread. Surprised it could be JFR related. @jack-berg, would you know if some users have already reported the following log?

appears to have started a thread named [BatchLogRecordProcessor_WorkerThread-1] but has failed to stop it.

Native tests of this PR are failing during the native compilation step:

[native-image-plugin] Native Image written to: /home/runner/work/opentelemetry-java-instrumentation/opentelemetry-java-instrumentation/smoke-tests-otel-starter/spring-boot-3.2/build/native/nativeTestCompile

[Incubating] Problems report is available at: file:///home/runner/work/opentelemetry-java-instrumentation/opentelemetry-java-instrumentation/build/reports/problems/problems-report.html

I would try to focus on the JMX or JFR metrics for a GraalVM native execution. GraalVM supports some JFR events, but not all of them. So, not sure that all the JFR metrics can work today in the native mode.

[jack-berg]

@jack-berg, would you know if some users have already reported the following log?

I haven't seen that log before.

[zeitlinger]

we also have com.oracle.svm.core.jdk.UnsupportedFeatureError: ThreadMXBean methods - see oracle/graal#6101

[zeitlinger]

@jeanbisutti turned out that all prior errors were just a side effect of a jmx issue which is resolved now

can you take a look again?

[jeanbisutti]

@roberttoyonaga If you have time, it would be great if you could have a look at this PR.

[roberttoyonaga]

I think that GraalVM Native Image would work fine with Threads::java8Callback. Native Image implements some ThreadMXBean functionality, notably all the functionality needed by Threads::java8Callback (see here and here). Although, Threads::java9AndNewerCallback still won't work with Native Image since we don't support ThreadMXBean#getAllThreadIds() or ThreadMXBean.getThreadInfo() yet.

[zeitlinger]

I tried JMX - and ran into #13078 (comment)

[zeitlinger]

@jeanbisutti now I get this - do you have an idea?

Error: Value not yet available for AnalysisField<Enum.hash -> HotSpotResolvedJavaFieldImpl<java.lang.Enum.hash int:16>, accessed: true, read: true, written: true, folded: true>
Error: Value not yet available for AnalysisField<Enum.name -> HotSpotResolvedJavaFieldImpl<java.lang.Enum.name String:20>, accessed: true, read: true, written: true, folded: true>
Error: Value not yet available for AnalysisField<Enum.ordinal -> HotSpotResolvedJavaFieldImpl<java.lang.Enum.ordinal int:12>, accessed: true, read: true, written: true, folded: true>

Maybe we should split this PR to leave out naive image initially - and then add native image incrementally (JFR as last step)

wdyt?

[jeanbisutti]

These error messages are not very detailed ones 😅

You could create a first PR with only what works today with a JVM and a native image application.

Another option may be to exclude the RuntimeMetricsAutoConfiguration for native image applications. It's perhaps possible to exclude this autoconfiguration during the Spring AOT processing step. It might be possible by implementing the BeanRegistrationExcludeFilter interface and referencing the implementation in a org.springframework.beans.factory.aot.BeanRegistrationExcludeFilter property of the aot.factories file.

Example:

• https://github.com/spring-projects/spring-boot/blob/4c7b8ef57bc5c7557efbbb81e82aa31bde1284dc/spring-boot-project/spring-boot-autoconfigure/src/main/resources/META-INF/spring/aot.factories#L13
• https://github.com/spring-projects/spring-boot/blob/4c7b8ef57bc5c7557efbbb81e82aa31bde1284dc/spring-boot-project/spring-boot-autoconfigure/src/main/java/org/springframework/boot/autoconfigure/SharedMetadataReaderFactoryContextInitializer.java#L80

[jeanbisutti]

@zeitlinger Do you agree to close this one?

[zeitlinger]

Yes

[zeitlinger]

closing in favor of #13173