How to debug OTLP trace exporter transient error

[manuel-koch]

We are using OpenTelemetry to export tracing spans to Grafana/Tempo (grafana/agent:v0.29.0) within a k8s cluster.

opentelemetry-api                      1.15.0
opentelemetry-exporter-otlp-proto-http 1.15.0
opentelemetry-exporter-prometheus      1.12.0rc1
opentelemetry-propagator-b3            1.15.0
opentelemetry-proto                    1.15.0
opentelemetry-sdk                      1.15.0
opentelemetry-semantic-conventions     0.36b0

For some unknown reason we see lots of log messages in our service like

{
"timestamp": "....", "level": "WARNING",
"message": "Transient error Internal Server Error encountered while exporting span batch, retrying in 32s.",
"logger": "opentelemetry.exporter.otlp.proto.http.trace_exporter"
}

Such logs follow a request log message ( which seem to indicate a server error 500 on Gafana/Tempo side ) like the following

{
"timestamp": "....", "level": "DEBUG",
"message": "http://grafana-agent-traces.tempo.svc.cluster.local:4318 \"POST /v1/traces HTTP/1.1\" 500 143",
"logger": "urllib3.connectionpool"
}

Eventually the trace spans seem to get exported successfully though, but due to the (synchronous) retries during the span export the overall performance of our service is degraded.

How could we find more info regarding the root cause of this transient error ?
I.e. the logged error ( although caused by a request error ) does not print the request status code of the underlying error.
Is there a way to get more info about the error ?
I tried to set envvar OTEL_LOG_LEVEL=DEBUG but this does not result in any more log output for this error.
I tried to align Grafana/Tempo POD logs with our service POD logs but could not find any logs in Grafana/Tempo that correspond to the service warning logs.

[srikanthccv]

The response reason already shows the readable message for the error, and it says it received Internal Server Error

opentelemetry-python/exporter/opentelemetry-exporter-otlp-proto-http/src/opentelemetry/exporter/otlp/proto/http/trace_exporter/__init__.py

Lines 158 to 162 in 2e14fe1

	_logger.warning(
	"Transient error %s encountered while exporting span batch, retrying in %ss.",
	resp.reason,
	delay,
	)

Understanding the root cause involves debugging the server side that sent the Internal server error. You probably want to spend time debugging the sever what's the reason because you mention it eventually succeeds, so the problem is not SDK. How can SDK help more than its current state of showing messages when it sees transient error to find the root cause?

[manuel-koch]

Monkey patched Open Telemetry lib to see response message from Tempo in case of 500 status, see https://github.com/grafana/tempo/issues/2237

[ocelotl]

@manuel-koch is there something else from the OTel Python side that can be discussed here? If not, let's close this discussion, please. ✌️

[manuel-koch]

I'm fine with closing the issue.