How to convert OpenTracing’s trace error logs to Otel’s exception span events?

[paulgrav]

Open Tracing has its own conventions for creating error logs.

https://github.com/opentracing/opentracing-python/blob/e2543115c1a9fbb4a49e600f862d54ff4f45f703/opentracing/span.py#L222

span.set_tag(tags.ERROR, True)
span.log_kv({
  logs.EVENT: tags.ERROR,
  logs.MESSAGE: str(exc_val),
  logs.ERROR_OBJECT: exc_val,
  logs.ERROR_KIND: exc_type,
  logs.STACK: exc_tb,
})

Without changing the tracing library, is there an easy way to have those logs converted to span events that conform to OpenTelemetry’s Semantic Conventions for Exceptions ?

Background

We have numerous Python apps that are instrumented with Jaeger and OpenTracing. Those apps emit their traces to an OpenTelemetry collector that exports the traces to ElasticAPM. The ElasticAPM exporter is unable to ingest the exception SpanEvents because they don’t conform to Otel’s semantic conventions.

[srikanthccv]

This should help you https://github.com/open-telemetry/opentelemetry-python/tree/main/shim/opentelemetry-opentracing-shim.

[paulgrav]

The shim covers the scenario where we migrate the tracer from Jaeger to Open Telemetry whilst reducing the amount of code we’d have to change? It doesn’t cover the scenario where we keep Jaeger?

[srikanthccv]

I didn't understand what you meant by keeping Jaeger. Jaeger uses opentracing and shim helps with applications which are already instrumented using OpenTracing to start using OpenTelemetry with a minimal changes.

[codeboten]

Just confirming the following is the flow of your data:

OpenTracing -> Jaeger Export -> Jaeger Receiver -> OpenTelemetry Collector -> Elastic exporter -> ElasticAPM

If so, there may be a bug from in the Jaeger Receiver on the collector side where it's not translating errors correctly from OpenTracing?

[paulgrav]

That is indeed the flow. I had a look at the translation code in the collector repo and couldn’t find any code that performed any span log/event translation. I assumed it was a missing feature, perhaps deliberate.

[srikanthccv]

Thrift - https://github.com/open-telemetry/opentelemetry-collector/blob/main/translator/trace/jaeger/jaegerthrift_to_traces.go#L148

Proto - https://github.com/open-telemetry/opentelemetry-collector/blob/main/translator/trace/jaeger/jaegerproto_to_traces.go#L320

[paulgrav]

@lonewolf3739 Yeah, those are the files I was looking in. I can’t see anything there (my understanding of Golang is weak) that translates/renames SpanEvent error attributes.

Here is an example Python script, docker-compose.yaml file, and otel config. I’ve removed the Elastic exporter from the equation because I don’t believe the problem lies with the Elastic exporter.

docker-compose.yaml:

version: "3.7"
services:
  otel:
    image: otel/opentelemetry-collector-contrib:0.27.0
    ports:
      - "6831:6831/udp"
    volumes:
      - "./otel.yaml:/etc/otel/config.yaml"

otel.yaml:

receivers:
  jaeger:
    protocols:
      grpc:
      thrift_binary:
      thrift_compact:
      thrift_http:

exporters:
  logging:
    logLevel: debug

service:
  pipelines:
    traces:
      receivers: [jaeger]
      exporters: [logging]

app.py:

# pip install jaeger-client
import time
from jaeger_client import Config

if __name__ == "__main__":
    config = Config(
        config={ # usually read from some yaml config
            'sampler': {
                'type': 'const',
                'param': 1,
            },
            'logging': True,
        },
        service_name='your-app-name',
        validate=True,
    )
    # this call also sets opentracing.tracer
    tracer = config.initialize_tracer()

    scope = tracer.start_active_span('foo')
    try:
        with scope:
            raise ValueError("error msg")
    except ValueError:
        pass
    finally:
        scope.close()

    time.sleep(2)   # yield to IOLoop to flush the spans - https://github.com/jaegertracing/jaeger-client-python/issues/50
    tracer.close()  # flush any buffered spans

Actual results (from docker-compose):

otel_1  | Events:
otel_1  | SpanEvent #0
otel_1  |      -> Name: error msg
otel_1  |      -> Timestamp: 2021-05-22 08:13:38.680589 +0000 UTC
otel_1  |      -> DroppedAttributesCount: 0
otel_1  |      -> Attributes:
otel_1  |          -> event: STRING(error)
otel_1  |          -> stack: STRING(  File "app.py", line 22, in <module>
otel_1  |     raise ValueError("error msg")
otel_1  | )
otel_1  |          -> error.object: STRING(error msg)
otel_1  |          -> error.kind: STRING(<class 'ValueError'>)
otel_1  | 

Expected/desired results (from docker-compose):

otel_1  |     -> Attributes:
otel_1  |         -> event: STRING(error)
otel_1  |         -> exception.stacktrace: STRING(  File "app.py", line 22, in <module>
otel_1  |    raise ValueError("error msg")
otel_1  |)
otel_1  |         -> exception.message: STRING(error msg)
otel_1  |         -> exception.type: STRING(<class 'ValueError'>)

[srikanthccv]

I am saying it is not the bug with collector.

Here is how OpenTracing and OpenTelemetry collect and format the exception/error.

OpenTracing - https://github.com/opentracing/opentracing-python/blob/e2543115c1a9fbb4a49e600f862d54ff4f45f703/opentracing/span.py#L221-L233

OpenTelemetry- https://github.com/open-telemetry/opentelemetry-python/blob/main/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py#L802-L827

Originally I recommended you use the shim package but I don't see if you are using the opentelemetry opentracing-shim package yet. If you use you may still see the error because shim doesn't seem override the __exit__ and _on_error methods. In that case you can either send a patch (if interested) to update the shim package to make them compatible or create an issue and wait for someone to pick and fix the bug. If your vendor expects the telemetry data in OTEL format you should start using the shim package and slowly migrate everything.

[srikanthccv]

There exists an issue already to update the shim to to map errors from logs #1848.

[srikanthccv]

This is fixed in #1878