API calls being counted twice for fastapi sample app

[pranay01]

Bug description

API calls being counted twice for fastapi apps

Expected behavior

API calls shouldn't be counted twice

How to reproduce

1. Instrument a fastAPI app/flask app with Otel
2. Hit any http endpoints 3 times
3. Check metric for number of calls for the same endpoint.

Version information

• Signoz version: v0.5.3

Additional context

Sample video: https://www.loom.com/share/f5f80d162f034e30afff78dab384cd0f

Thank you for your bug report – we love squashing them!

[ankitnayan]

@makeavish you can check if otel-collector is receiving double number of traces or not at metric_name otelcol_receiver_accepted_spans with receiver:otlp at http://testingapp.signoz.io:8887/metrics.

The receiver:jaeger probably shows just hotrod data as it sends data in jaeger format.

[makeavish]

The endpoint metrics are not being captured by Otel metrics collector. The metrics are being calculated by traces.

[ankitnayan]

The endpoint metrics are not being captured by Otel metrics collector. The metrics are being calculated by traces.

correct

[ankitnayan]

@makeavish I have added another branch console-exporter which enables exporting spans to console. This seems to work fine with just 1 SERVER span and 2 internal spans. Maybe something weird happening in otlp-exporter or steps via which it is automatically enabled. Below is the output of console-exporter

[{
    "name": "/ http send",
    "context": {
        "trace_id": "0x647d62c6874903ee8d8629252bb3d5ed",
        "span_id": "0x48f0c558d15342fe",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": "0x83b8f56e52d15286",
    "start_time": "2021-12-23T13:51:25.373201Z",
    "end_time": "2021-12-23T13:51:25.373646Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "http.status_code": 200,
        "type": "http.response.start"
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.8.0",
        "service.name": "FastApiApp"
    }
},
{
    "name": "/ http send",
    "context": {
        "trace_id": "0x647d62c6874903ee8d8629252bb3d5ed",
        "span_id": "0xc2ba5e8507b17b63",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": "0x1efb36baaf7a20f1",
    "start_time": "2021-12-23T13:51:25.374042Z",
    "end_time": "2021-12-23T13:51:25.374231Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "type": "http.response.body"
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.8.0",
        "service.name": "FastApiApp"
    }
},
{
    "name": "/",
    "context": {
        "trace_id": "0x11c48a08fcfc606bc84a76077d1977f9",
        "span_id": "0xfe4f40d33e9c06e9",
        "trace_state": "[]"
    },
    "kind": "SpanKind.SERVER",
    "parent_id": null,
    "start_time": "2021-12-23T13:51:25.372078Z",
    "end_time": "2021-12-23T13:51:25.374445Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {
        "http.scheme": "http",
        "http.host": "::1:5002",
        "net.host.port": 5002,
        "http.flavor": "1.1",
        "http.target": "/",
        "http.url": "http://::1:5002/",
        "http.method": "GET",
        "http.server_name": "localhost:5002",
        "http.user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.93 Safari/537.36",
        "net.peer.ip": "::1",
        "net.peer.port": 54237,
        "http.route": "/",
        "http.status_code": 200
    },
    "events": [],
    "links": [],
    "resource": {
        "telemetry.sdk.language": "python",
        "telemetry.sdk.name": "opentelemetry",
        "telemetry.sdk.version": "1.8.0",
        "service.name": "FastApiApp"
    }
}]

[ankitnayan]

In my case, I get 3 server spans for 1 request. I noticed, 1 spans comes immediately and the 2 other replicas arrive with a delay of a few seconds

[makeavish]

I can see that incase of OTLP exporter we get 6 spans for 1 request.
Looks like an issue with FastAPI auto-instrumentor.

[makeavish]

After using TraceProvider the issue is not there.
Here's the PR: SigNoz/sample-fastAPI-app#2
Also I have raised an issue on official python otel repo regarding this: open-telemetry/opentelemetry-python-contrib#840

[makeavish]

There was no issue in fastAPI otel exporter. Actually, we were instrumenting FastAPI app twice(both automated and semi-automated way).
Closing this issue.