-
Notifications
You must be signed in to change notification settings - Fork 1k
Duplicated metrics warnings on the logs when running Besu on OpenTelemetry mode #9653
Description
Hello, friends!
I've been playing around with Besu and trying to use OpenTelemetry to collect metrics and expose them through Grafana. So far it's great, most of it works wonders.
Thing is that, recently, I noticed that I started getting some warning logs on the nodes once I set metrics to OTel, here are some I extracted from my running Besu instnace:
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument transactions has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_queue_length_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_active_threads_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_pool_size_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_completed_tasks_total has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_submitted_tasks_total has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_queue_length_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_active_threads_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_pool_size_current has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_completed_tasks_total has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument bfttimerexecutor_qbft_submitted_tasks_total has recorded multiple values for the same attributes: {}
[REDACTED] | PeriodicMetricReader-1 | WARN | AsynchronousMetricsStorage | Instrument task has recorded multiple values for the same attributes: {taskName="GetHeadersFromPeerByHashTask"}
I tried setting Besu to DEBUG mode but found no extra info related to the issue. Also did some research, I suppose it's something related to Besu's threads all producing the same metrics at a short range of time, OTel then later tries to collect those and finds that the metrics are duplicated since multiple threads produced that same metrics, thus giving us those warnings we see just above. That's my guess but, of course, not really sure if that's it...
Other than that, I also found those logs that show right when Besu starts, not sure if related to that specific issue but might be worth taking a look at:
[REDACTED] | main | INFO | OpenTelemetrySystem | Starting OpenTelemetry metrics system
WARNING: A terminally deprecated method in sun.misc.Unsafe has been called
WARNING: sun.misc.Unsafe::objectFieldOffset has been called by io.opentelemetry.internal.shaded.jctools.util.UnsafeAccess (file:/opt/besu/lib/opentelemetry-sdk-trace-1.47.0.jar)
WARNING: Please consider reporting this to the maintainers of class io.opentelemetry.internal.shared.jctools.util.UnsafeAccess
WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release
Do you guys have any idea on what could be causing this? Is it something on Besu's side or something related to our OTel configs? Maybe a bug on Besu?
Expected behavior:
Besu should expose metrics to OTel just fine with no warnings
Actual behavior:
Besu does expose metrics to OTel but still gives me those warnings related to duplicated metrics
Frequency:
The warning logs show around every 60 seconds, which is the time OTel is set to collect Besu's metrics
Versions and technical setup
Besu version: 26.1.0 (also reproduced on 25.12.0 and 25.8.0)
Network: QBFT, 4 validator nodes, Docker Compose
Relevant Besu flags:
--metrics-enabled=true
--metrics-protocol=opentelemetry
OTel environment variables set on each node:
OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector:4317
OTEL_EXPORTER_OTLP_PROTOCOL=grpc
OTEL_SERVICE_NAME=besu-node<N>
Reproducing
To make it easier to reproduce, I put together a minimal Docker Compose setup where the issue is consistently happening: https://github.com/jake-smith754/besu-otel-issue
It's a 4-node QBFT network with OpenTelemetry already configured as metrics provider. No extra setup needed, just run the commands:
git clone https://github.com/jake-smith754/besu-otel-issue
cd besu-otel-issue
docker compose up -d
docker compose logs -f node1The AsynchronousMetricStorage warnings should start appearing within the first minute or so.
Thanks a lot in advance, friends!