Spring boot runtime metrics #13078

zeitlinger · 2025-01-21T13:21:01Z

zeitlinger · 2025-01-22T12:25:44Z

@jeanbisutti can you help me with the native failures:

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)
       [...]

numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small. - should we increase the buffer?
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)
 [email protected]/jdk.internal.misc.Unsafe.park(Unsafe.java:56)
 [email protected]/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:269)
 [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1763)
 [email protected]/java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:435)
 io.opentelemetry.sdk.logs.export.BatchLogRecordProcessor$Worker.run(BatchLogRecordProcessor.java:246)
 [email protected]/java.lang.Thread.runWith(Thread.java:1596)
 [email protected]/java.lang.Thread.run(Thread.java:1583)

jeanbisutti · 2025-01-22T17:30:27Z

@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 · 2025-01-22T21:05:03Z

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

I haven't seen that log before.

zeitlinger · 2025-01-27T17:11:12Z

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

zeitlinger · 2025-01-28T11:18:01Z

@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 · 2025-01-28T14:00:55Z

...mmon/src/main/java/io/opentelemetry/spring/smoketest/AbstractOtelSpringStarterSmokeTest.java

@@ -209,6 +209,11 @@ void shouldSendTelemetry() {
        OtelSpringStarterSmokeTestController.METER_SCOPE_NAME,
        OtelSpringStarterSmokeTestController.TEST_HISTOGRAM,
        AbstractIterableAssert::isNotEmpty);
+    // runtime metrics
+    testing.waitAndAssertMetrics(


It seems to verify a thread-based runtime metric.

It may be worth to also verify that JMX-based and JFR-based runtime metrics work with the OpenTelemetry starter in both non-native and native modes.

added @jeanbisutti

@zeitlinger

I have not noticed assertions for JFR-based runtime metrics (io.opentelemetry.runtime-telemetry-java17 instrumentation scope). Could you please add them?

Also, could you please add more assertions for JMX-based runtime metrics (jvm.cpu.time, ...)? It woud be great to check one metric by MXBean used.

This way, we would be more confident that things work well in native mode!

I have not noticed assertions for JFR-based runtime metrics (io.opentelemetry.runtime-telemetry-java17 instrumentation scope). Could you please add them?

it's here:

opentelemetry-java-instrumentation/smoke-tests-otel-starter/spring-boot-3/src/test/java/io/opentelemetry/spring/smoketest/OtelSpringStarterSmokeTest.java

Lines 26 to 32 in 7d45b5b

protected void assertAdditionalMetrics() {

// JFR based metrics

testing.waitAndAssertMetrics(

"io.opentelemetry.runtime-telemetry-java17",

"jvm.cpu.limit",

AbstractIterableAssert::isNotEmpty);

}

Also, could you please add more assertions for JMX-based runtime metrics (jvm.cpu.time, ...

here's one:

opentelemetry-java-instrumentation/smoke-tests-otel-starter/spring-boot-common/src/main/java/io/opentelemetry/spring/smoketest/AbstractOtelSpringStarterSmokeTest.java

Lines 220 to 224 in 7d45b5b

// JMX based metrics

testing.waitAndAssertMetrics(

"io.opentelemetry.runtime-telemetry-java8",

"jvm.memory.used",

AbstractIterableAssert::isNotEmpty);

or do you want to have one for each JMX bean?

I would suggest to test one metric by MXBean used to verify that the MXBean can be acessible in the native mode:

opentelemetry-java-instrumentation/instrumentation/runtime-telemetry/runtime-telemetry-java8/library/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/internal/CpuMethods.java

Line 33 in e9227c3

OperatingSystemMXBean osBean = ManagementFactory.getOperatingSystemMXBean();

opentelemetry-java-instrumentation/instrumentation/runtime-telemetry/runtime-telemetry-java8/library/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/internal/ExperimentalBufferPools.java

Line 36 in e9227c3

ManagementFactory.getPlatformMXBeans(BufferPoolMXBean.class);

opentelemetry-java-instrumentation/instrumentation/runtime-telemetry/runtime-telemetry-java8/library/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/internal/ExperimentalMemoryPools.java

Line 33 in e9227c3

return registerObservers(openTelemetry, ManagementFactory.getMemoryPoolMXBeans());

I would aslo suggest to check a runtime metric for each JFR event used: https://github.com/search?q=repo%3Aopen-telemetry%2Fopentelemetry-java-instrumentation%20EVENT_NAME&type=code

jeanbisutti · 2025-01-29T13:44:34Z

...ary/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java17/RuntimeMetrics.java

@@ -101,7 +101,7 @@ private JfrRuntimeMetrics(OpenTelemetry openTelemetry, Predicate<JfrFeature> fea
            recordingStream.onEvent(handler.getEventName(), handler);
          });
      recordingStream.onMetadata(event -> startUpLatch.countDown());
-      Thread daemonRunner = new Thread(() -> recordingStream.start());
+      Thread daemonRunner = new Thread(recordingStream::start, "JFR-Metrics-Runner");


Perhaps mentioned OpenTelemetry in the thread name?

jeanbisutti · 2025-01-29T13:44:55Z

.../main/java/io/opentelemetry/instrumentation/runtimemetrics/java17/RuntimeMetricsBuilder.java

@@ -31,6 +24,10 @@ public final class RuntimeMetricsBuilder {

  private boolean disableJmx = false;
  private boolean enableExperimentalJmxTelemetry = false;
+  private Consumer<Runnable> shutdownHook =
+      runnable -> {
+        Runtime.getRuntime().addShutdownHook(new Thread(runnable, "RuntimeMetricsShutdownHook"));


Perhaps mentioned OpenTelemetry in the thread name?

jeanbisutti · 2025-01-29T13:51:14Z

smoke-tests-otel-starter/spring-boot-3/build.gradle.kts

@@ -66,6 +66,9 @@ graalvmNative {
    // Workaround for https://github.com/junit-team/junit5/issues/3405
    buildArgs.add("--initialize-at-build-time=org.junit.platform.launcher.core.LauncherConfig")
    buildArgs.add("--initialize-at-build-time=org.junit.jupiter.engine.config.InstantiatingConfigurationParameterConverter")
+
+    // enable JFR - see https://www.graalvm.org/22.0/reference-manual/native-image/JFR/


This documentation if for an old GraalVM version.

The last one:

Suggested change

// enable JFR - see https://www.graalvm.org/22.0/reference-manual/native-image/JFR/

// enable JFR - see https://www.graalvm.org/latest/reference-manual/native-image/debugging-and-diagnostics/JFR/

jeanbisutti · 2025-01-29T14:13:01Z

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

roberttoyonaga · 2025-01-29T15:31:58Z

...rary/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/RuntimeMetrics.java

+  /**
+   * Create and start {@link RuntimeMetrics}.
+   *
+   * <p>Listens for select JFR events, extracts data, and records to various metrics. Recording will


I think this javadoc should be adjusted. JFR recording and metrics are only with JDK17+. This is because the JFR streaming feature only was introduced in JDK 14.

roberttoyonaga · 2025-01-29T15:32:56Z

...c/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/RuntimeMetricsBuilder.java

+
+  public void startFromInstrumentationConfig(InstrumentationConfig config) {
+    /*
+    By default, don't use any JFR metrics. May change this once semantic conventions are updated.


I think this comment should not mention JFR, since JFR is only used with JFR streaming in Java 17.

roberttoyonaga · 2025-01-29T15:35:38Z

...rary/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/RuntimeMetrics.java

+    return new RuntimeMetricsBuilder(openTelemetry);
+  }
+
+  /** Stop recording JFR events. */


Same with this javadoc

roberttoyonaga · 2025-01-29T16:20:29Z

...va8/library/src/main/java/io/opentelemetry/instrumentation/runtimemetrics/java8/Threads.java

+  private static boolean useThreads() {
+    // GraalVM native image does not support ThreadMXBean yet
+    // see https://github.com/oracle/graal/issues/6101
+    return !isJava9OrNewer() || System.getProperty("org.graalvm.nativeimage.imagecode") != null;


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 requested a review from a team as a code owner January 21, 2025 13:21

zeitlinger self-assigned this Jan 21, 2025

github-actions bot added the test native This label can be applied to PRs to trigger them to run native tests label Jan 21, 2025

zeitlinger force-pushed the spring-boot-runtime-metrics branch from c0de41a to b3c0f10 Compare January 28, 2025 08:25

jeanbisutti reviewed Jan 28, 2025

View reviewed changes

zeitlinger added 9 commits January 28, 2025 19:02

spring boot runtime metrics for java 17+

246f6d5

spring boot runtime metrics for java 8

bff57c8

spring boot runtime metrics for java 8

6272b79

fix native

84035a2

use spring shutdown hook

91da814

disable threads

6e0fbcf

disable threads

aa94747

test more metric types

7d45b5b

add metadata

ab2439a

zeitlinger force-pushed the spring-boot-runtime-metrics branch from 55b2482 to ab2439a Compare January 28, 2025 18:10

zeitlinger added 2 commits January 29, 2025 13:28

fix jfr and native image

9e36ec9

fix jfr and native image

a130e3d

jeanbisutti mentioned this pull request Jan 29, 2025

Document how to enable JFR with native images #13122

Open

jeanbisutti reviewed Jan 29, 2025

View reviewed changes

roberttoyonaga reviewed Jan 29, 2025

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Spring boot runtime metrics #13078

Spring boot runtime metrics #13078

zeitlinger commented Jan 21, 2025

zeitlinger commented Jan 22, 2025

jeanbisutti commented Jan 22, 2025

jack-berg commented Jan 22, 2025

zeitlinger commented Jan 27, 2025

zeitlinger commented Jan 28, 2025

jeanbisutti Jan 28, 2025

zeitlinger Jan 28, 2025

jeanbisutti Jan 29, 2025

zeitlinger Jan 29, 2025

zeitlinger Jan 29, 2025

jeanbisutti Jan 29, 2025

jeanbisutti Jan 29, 2025

jeanbisutti Jan 29, 2025

jeanbisutti Jan 29, 2025

jeanbisutti commented Jan 29, 2025

roberttoyonaga Jan 29, 2025

roberttoyonaga Jan 29, 2025

roberttoyonaga Jan 29, 2025

roberttoyonaga Jan 29, 2025 •

edited

Loading

	protected void assertAdditionalMetrics() {
	// JFR based metrics
	testing.waitAndAssertMetrics(
	"io.opentelemetry.runtime-telemetry-java17",
	"jvm.cpu.limit",
	AbstractIterableAssert::isNotEmpty);
	}

	// JMX based metrics
	testing.waitAndAssertMetrics(
	"io.opentelemetry.runtime-telemetry-java8",
	"jvm.memory.used",
	AbstractIterableAssert::isNotEmpty);

	// enable JFR - see https://www.graalvm.org/22.0/reference-manual/native-image/JFR/
	// enable JFR - see https://www.graalvm.org/latest/reference-manual/native-image/debugging-and-diagnostics/JFR/

Spring boot runtime metrics #13078

Are you sure you want to change the base?

Spring boot runtime metrics #13078

Conversation

zeitlinger commented Jan 21, 2025

zeitlinger commented Jan 22, 2025

jeanbisutti commented Jan 22, 2025

jack-berg commented Jan 22, 2025

zeitlinger commented Jan 27, 2025

zeitlinger commented Jan 28, 2025

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jeanbisutti commented Jan 29, 2025

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

roberttoyonaga Jan 29, 2025 • edited Loading

Choose a reason for hiding this comment

roberttoyonaga Jan 29, 2025 •

edited

Loading