search

open-telemetry / opentelemetry-java-instrumentation

OpenTelemetry auto-instrumentation and instrumentation libraries for Java
https://opentelemetry.io
Apache License 2.0
1.99k stars 868 forks source link

Metrics get exposed to opentelemetry-collector with zero values via otlp grpc #3568

Closed goto1134 closed 3 years ago

goto1134 commented 3 years ago

Describe the bug Opentelemetry metrics are exposed to opentelemetry-collector from java-instrumentation with zero values.

Steps to reproduce Instrument a java-project with metrics otlp exporter Setup opentelemetry-collector with the following config:

receivers:
  otlp:
    protocols:
      grpc:

exporters:
  prometheus:
    endpoint: "0.0.0.0:8889"
  logging:
    logLevel: debug

processors:
  batch:

service:
  pipelines:
    metrics:
      receivers: [otlp]
      processors: [batch]
      exporters: [logging, prometheus]

What did you expect to see? all metrics get exposed to the prometheus endpoint with non-zero values What did you see instead? all metcics get exposed to prometheus, but all of them are zeros

# HELP runtime_jvm_gc_count The number of collections that have occurred for a given JVM garbage collector.
# TYPE runtime_jvm_gc_count counter
runtime_jvm_gc_count 0
# HELP runtime_jvm_gc_time Time spent in a given JVM garbage collector in milliseconds.
# TYPE runtime_jvm_gc_time counter
runtime_jvm_gc_time 0
# HELP runtime_jvm_memory_area Bytes of a given JVM memory area.
# TYPE runtime_jvm_memory_area gauge
runtime_jvm_memory_area 0
# HELP runtime_jvm_memory_pool Bytes of a given JVM memory pool.
# TYPE runtime_jvm_memory_pool gauge
runtime_jvm_memory_pool 0

What version are you using? opentelemetry-java-instrumentation: 1.3.1 opentelemetry-collector: 0.29.0

Environment Compiler: "AdoptOpenJDK 15.0.0" OS: "Mac OS Big Sur"

Additional context When I setup metrics exporter to logging, I see non-zero values in logs.

As I see in logs, all the metrics are received by the collector as zeros:

2021-07-14T10:37:23.678Z    DEBUG   loggingexporter/logging_exporter.go:63  ResourceMetrics #0
Resource labels:
     -> host.arch: STRING(x86_64)
     -> host.name: STRING(macbook-a.efanov)
     -> os.description: STRING(Mac OS X 10.16)
     -> os.type: STRING(darwin)
     -> process.command_line: STRING(/Users/RenameMe/.sdkman/candidates/java/15.0.0.hs-adpt:bin:java -javaagent:engine-server/agents/opt/opentelemetry/opentelemetry-javaagent-all.jar -Dopentelemetry-agent-path=/Users/RenameMe/Projects/tinkoff/helicopter-engine/engine-server/agents/opt/opentelemetry/opentelemetry-javaagent-all.jar -XX:TieredStopAtLevel=1 -Xverify:none -Dspring.output.ansi.enabled=always -javaagent:/Users/RenameMe/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/211.7628.21/IntelliJ IDEA.app/Contents/lib/idea_rt.jar=52677:/Users/RenameMe/Library/Application Support/JetBrains/Toolbox/apps/IDEA-U/ch-0/211.7628.21/IntelliJ IDEA.app/Contents/bin -Dcom.sun.management.jmxremote -Dspring.jmx.enabled=true -Dspring.liveBeansView.mbeanDomain -Dspring.application.admin.enabled=true -Dfile.encoding=UTF-8)
     -> process.executable.path: STRING(/Users/RenameMe/.sdkman/candidates/java/15.0.0.hs-adpt:bin:java)
     -> process.pid: INT(21370)
     -> process.runtime.description: STRING(AdoptOpenJDK OpenJDK 64-Bit Server VM 15+36)
     -> process.runtime.name: STRING(OpenJDK Runtime Environment)
     -> process.runtime.version: STRING(15+36)
     -> service.name: STRING(helicopter-engine)
     -> telemetry.auto.version: STRING(1.3.1)
     -> telemetry.sdk.language: STRING(java)
     -> telemetry.sdk.name: STRING(opentelemetry)
     -> telemetry.sdk.version: STRING(1.3.0)
InstrumentationLibraryMetrics #0
InstrumentationLibrary io.opentelemetry.javaagent.shaded.instrumentation.runtimemetrics.MemoryPools 
Metric #0
Descriptor:
     -> Name: runtime.jvm.memory.pool
     -> Description: Bytes of a given JVM memory pool.
     -> Unit: By
     -> DataType: DoubleSum
     -> IsMonotonic: false
     -> AggregationTemporality: AGGREGATION_TEMPORALITY_CUMULATIVE
DoubleDataPoints #0
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #1
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #2
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #3
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #4
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #5
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #6
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #7
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #8
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #9
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #10
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #11
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #12
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #13
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #14
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #15
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #16
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
DoubleDataPoints #17
StartTimestamp: 2021-07-14 10:32:23.065571 +0000 UTC
Timestamp: 2021-07-14 10:37:23.497083 +0000 UTC
Value: 0.000000
Metric #1
Descriptor:
     -> Name: runtime.jvm.memory.area
     -> Description: Bytes of a given JVM memory area.
     -> Unit: By
     -> DataType: DoubleSum
     -> IsMonotonic: false
     -> AggregationTemporality: AGGREGATION_TEMPORALITY_CUMULATIVE
goto1134 commented 3 years ago

I tried to use the legacy endpoint and got the same behaviour

mateuszrzeszutek commented 3 years ago

Can you try running your application with -Dotel.metrics.exporter=logging? We'll see what data the javaagent actually sends.

jkwatson commented 3 years ago

I suspect this issue is due to the java exporter emitting OTLP/proto v0.9.0, and the collector still only supporting v0.7.0

goto1134 commented 3 years ago

@mateuszrzeszutek

Can you try running your application with -Dotel.metrics.exporter=logging? We'll see what data the javaagent actually sends.

Yes, the data logged by java-instrumentation is correct!

@jkwatson

I suspect this issue is due to the java exporter emitting OTLP/proto v0.9.0, and the collector still only supporting v0.7.0

Ok, then I will open an issue there to migrate!

Maybe opentelemetry-java and opentelemetry-java-instrumentation should migrate to the new grpc protobuf version only after the collector updates? Or maybe there should be a compatibility table somewhere in these projects documentation?

bogdandrutu commented 3 years ago

Indeed right now the Java emits 0.9.0 , and the collector just started to add support for 0.8.0 (work in progress), once that is done we should be able to no longer see 0 values there.

goto1134 commented 3 years ago

the current issue on migration is here

laurit commented 3 years ago

Closing as underlying collector issue was closed.