ASGI request errors not propagating to root trace #305
Description
It seems that the collector's AWS X-Ray exporter is mishandling the interpretation of the root trace's status for ASGI spans.
Given an instrumented FastAPI application:
import fastapi
from opentelemetry import trace
from opentelemetry.exporter.otlp.trace_exporter import OTLPSpanExporter
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import (
ConsoleSpanExporter,
SimpleExportSpanProcessor,
)
from opentelemetry.sdk.extension.aws.trace import AwsXRayIdsGenerator
from opentelemetry import propagators
from opentelemetry.sdk.extension.aws.trace.propagation.aws_xray_format import AwsXRayFormat
propagators.set_global_textmap(AwsXRayFormat())
# ALT: sanity check using console span exporter
# trace.set_tracer_provider(
# TracerProvider(ids_generator=AwsXRayIdsGenerator())
# )
# trace.get_tracer_provider().add_span_processor(
# SimpleExportSpanProcessor(ConsoleSpanExporter())
# )
# using OTLP exporter with XRay support
otlp_exporter = OTLPSpanExporter(endpoint="localhost:55680", insecure=True)
span_processor = SimpleExportSpanProcessor(otlp_exporter)
trace.set_tracer_provider(TracerProvider(active_span_processor=span_processor, ids_generator=AwsXRayIdsGenerator()))
app = fastapi.FastAPI()
@app.get("/")
async def hello():
return {"message": "hello world"}
FastAPIInstrumentor.instrument_app(app)i'm running AWS OTel Collector version: v0.6.0 in a docker container locally and then invoking the application this way:
uvicorn fastapi_example_instrumented_xray:app --reload
Using the console span exporter, i see three spans for an HTTP 404, two having status UNSET and the third as ERROR:
{
"name": "GET asgi.http.send",
"context": {
"trace_id": "0x600a0aa3734259d834dd1315e74cf9ea",
"span_id": "0x6d02afce8b99ef53",
"trace_state": "[]"
},
"kind": "SpanKind.INTERNAL",
"parent_id": "0x7ab7d27035511c5b",
"start_time": "2021-01-21T23:13:39.569816Z",
"end_time": "2021-01-21T23:13:39.570079Z",
"status": {
"status_code": "ERROR"
},
"attributes": {
"http.status_code": 404,
"type": "http.response.start"
},
"events": [],
"links": [],
"resource": {
"telemetry.sdk.language": "python",
"telemetry.sdk.name": "opentelemetry",
"telemetry.sdk.version": "0.17b0"
}
}
{
"name": "GET asgi.http.send",
"context": {
"trace_id": "0x600a0aa3734259d834dd1315e74cf9ea",
"span_id": "0xb7f5be18d868f596",
"trace_state": "[]"
},
"kind": "SpanKind.INTERNAL",
"parent_id": "0x7ab7d27035511c5b",
"start_time": "2021-01-21T23:13:39.570549Z",
"end_time": "2021-01-21T23:13:39.570620Z",
"status": {
"status_code": "UNSET"
},
"attributes": {
"type": "http.response.body"
},
"events": [],
"links": [],
"resource": {
"telemetry.sdk.language": "python",
"telemetry.sdk.name": "opentelemetry",
"telemetry.sdk.version": "0.17b0"
}
}
{
"name": "GET asgi",
"context": {
"trace_id": "0x600a0aa3734259d834dd1315e74cf9ea",
"span_id": "0x7ab7d27035511c5b",
"trace_state": "[]"
},
"kind": "SpanKind.SERVER",
"parent_id": null,
"start_time": "2021-01-21T23:13:39.569437Z",
"end_time": "2021-01-21T23:13:39.570793Z",
"status": {
"status_code": "UNSET"
},
"attributes": {
"component": "http",
"http.scheme": "http",
"http.host": "127.0.0.1:8000",
"net.host.port": 8000,
"http.flavor": "1.1",
"http.target": "/invalid",
"http.url": "http://127.0.0.1:8000/invalid",
"http.method": "GET",
"http.server_name": "localhost:8000",
"http.user_agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:84.0) Gecko/20100101 Firefox/84.0",
"net.peer.ip": "127.0.0.1",
"net.peer.port": 60934
},
"events": [],
"links": [],
"resource": {
"telemetry.sdk.language": "python",
"telemetry.sdk.name": "opentelemetry",
"telemetry.sdk.version": "0.17b0"
}
}
But using the collector with the X-Ray exporter, X-Ray is showing the trace as a 200/OK result with fault and error as "false"
{
"Id": "1-600a088a-109dbb153757333fdada5f70",
"Duration": 0.106,
"LimitExceeded": false,
"Segments": [
{
"Id": "f405f8dc0560a892",
"Document": {
"id": "f405f8dc0560a892",
"name": "127.0.0.1:8000",
"start_time": 1611270282.307393,
"trace_id": "1-600a088a-109dbb153757333fdada5f70",
"end_time": 1611270282.4130836,
"fault": false,
"error": false,
"http": {
"request": {
"url": "http://127.0.0.1:8000/invalid",
"method": "GET",
"user_agent": "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:84.0) Gecko/20100101 Firefox/84.0",
"client_ip": "127.0.0.1"
},
"response": {
"status": 200,
"content_length": 0
}
},
"aws": {
"xray": {
"auto_instrumentation": false,
"sdk_version": "0.17b0",
"sdk": "opentelemetry for python"
}
},
"metadata": {
"default": {
"otel.resource.telemetry.sdk.name": "opentelemetry",
"http.flavor": "1.1",
"net.host.port": "",
"otel.resource.telemetry.sdk.language": "python",
"otel.resource.telemetry.sdk.version": "0.17b0"
}
},
"subsegments": [
{
"id": "b1bab769fcb3a95f",
"name": "GET asgi.http.send",
"start_time": 1611270282.307856,
"end_time": 1611270282.3082073,
"fault": false,
"error": true,
"http": {
"request": {},
"response": {
"status": 404,
"content_length": 0
}
},
"aws": {
"xray": {
"auto_instrumentation": false,
"sdk_version": "0.17b0",
"sdk": "opentelemetry for python"
}
},
"metadata": {
"default": {
"type": "http.response.start"
}
}
},
{
"id": "ba50a1de9e723e58",
"name": "GET asgi.http.send",
"start_time": 1611270282.3615057,
"end_time": 1611270282.3615806,
"fault": false,
"error": false,
"aws": {
"xray": {
"auto_instrumentation": false,
"sdk_version": "0.17b0",
"sdk": "opentelemetry for python"
}
},
"metadata": {
"default": {
"type": "http.response.body"
}
}
}
]
}
}
]
}So it seems to me that the X-Ray exporter is not correctly interpreting the trace status based on the 3 ASGI spans.