open-telemetry / opentelemetry-python-contrib

OpenTelemetry instrumentation for Python modules
https://opentelemetry.io
Apache License 2.0
736 stars 607 forks source link

Automatic Instrumentation does not work with pex/zipapp python code #1994

Open kuza55 opened 1 year ago

kuza55 commented 1 year ago

Describe your environment

Python 3.10.12

Steps to reproduce Describe exactly how to reproduce the error. Include a code sample if applicable.

Clone this repo: https://github.com/kuza55/pants_debug_otel/tree/main

Then run

OTEL_TRACES_EXPORTER=console OTEL_METRICS_EXPORTER=console OTEL_LOGS_EXPORTER=console OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED=true opentelemetry-instrument python3 dist/src/no_configuration.pex

What is the expected behavior? What did you expect to see?

I expected to see the same output as when I run the command on the python file directly

{
    "body": "baz 325",
    "severity_number": "<SeverityNumber.WARN: 13>",
    "severity_text": "WARNING",
    "attributes": {
        "otelSpanID": "71d54e8b2fde38fe",
        "otelTraceID": "fa86a02c2114d8df845e35c4e9817e0b",
        "otelTraceSampled": true,
        "otelServiceName": "unknown_service"
    },
    "dropped_attributes": 0,
    "timestamp": "2023-10-10T19:29:45.543345Z",
    "trace_id": "0xfa86a02c2114d8df845e35c4e9817e0b",
    "span_id": "0x71d54e8b2fde38fe",
    "trace_flags": 1,
    "resource": "BoundedAttributes({'telemetry.sdk.language': 'python', 'telemetry.sdk.name': 'opentelemetry', 'telemetry.sdk.version': '1.20.0', 'telemetry.auto.version': '0.41b0', 'service.name': 'unknown_service'}, maxlen=None)"
}
{
    "resource_metrics": [
        {
            "resource": {
                "attributes": {
                    "telemetry.sdk.language": "python",
                    "telemetry.sdk.name": "opentelemetry",
                    "telemetry.sdk.version": "1.20.0",
                    "telemetry.auto.version": "0.41b0",
                    "service.name": "unknown_service"
                },
                "schema_url": ""
            },
            "scope_metrics": [],
            "schema_url": ""
        }
    ]
}
{
    "name": "bar",
    "context": {
        "trace_id": "0xfa86a02c2114d8df845e35c4e9817e0b",
        "span_id": "0x71d54e8b2fde38fe",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": "0xd561f1c55aece97e",
    "start_time": "2023-10-10T19:29:45.543308Z",
    "end_time": "2023-10-10T19:29:45.543496Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {},
    "events": [],
    "links": [],
    "resource": {
        "attributes": {
            "telemetry.sdk.language": "python",
            "telemetry.sdk.name": "opentelemetry",
            "telemetry.sdk.version": "1.20.0",
            "telemetry.auto.version": "0.41b0",
            "service.name": "unknown_service"
        },
        "schema_url": ""
    }
}
{
    "name": "foo",
    "context": {
        "trace_id": "0xfa86a02c2114d8df845e35c4e9817e0b",
        "span_id": "0xd561f1c55aece97e",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": null,
    "start_time": "2023-10-10T19:29:45.543230Z",
    "end_time": "2023-10-10T19:29:45.543512Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {},
    "events": [],
    "links": [],
    "resource": {
        "attributes": {
            "telemetry.sdk.language": "python",
            "telemetry.sdk.name": "opentelemetry",
            "telemetry.sdk.version": "1.20.0",
            "telemetry.auto.version": "0.41b0",
            "service.name": "unknown_service"
        },
        "schema_url": ""
    }
}

What is the actual behavior? What did you see instead?

WARNING:root:baz 425

Note: the logging integration is being executed inside the pex file, which is why we see any output at all

Additional context

It seems like I can configure all the exporters/etc from code inside my python code and it will work, but I would much rather just reuse the existing auto-instrumentation code, either through the binary wrapper as-is, or by calling a python function that does all the setup for me.

kuza55 commented 1 year ago

After digging a bit more, it seems like adding this line to the top of my program fixes the issue, but I am not clear on whether this is a stable situation:

from opentelemetry.instrumentation.auto_instrumentation import sitecustomize

bobthemighty commented 1 year ago

Is it possible that pants isn't detecting the instrumentor as a dependency. and so it isn't showing up in the pex? If so, you can explicitly add it as a dependency to your BUILD, as you did with the logging lib and otel exporter.

kuza55 commented 1 year ago

The issue is that opentelemetry-instrument is trying to inject this code at runtime via sitecustomize, but pex is built to be hermetic and not allow code injection like this.

FWIW, I also found a bug on this from the pex side that required a bunch of workaround: https://github.com/pantsbuild/pex/issues/2065

I don't fundamentally have an opinion here on what should happen (and importing sitecustomize is working for me), but I would like some sort of supported solution that hopefully doesn't require too much configuration/code.

MrMegaMango commented 1 month ago

But unused import won't pass cicd linter, is there a better way?