[Bug]: flamegraph is confused by some traces

[bobrik]

What happened?

Ad a Jaeger user, I want to see representative flamegraph representation of a trace. Unfortunately, it is misleading.

Steps to reproduce

1. Load the following json:

bug.json

{
    "data": [
        {
            "traceID": "0014a21066967d7c",
            "spans": [
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "ad55f46b6e407452",
                    "flags": 3,
                    "operationName": "request_logic",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "d523c4890747823a"
                        }
                    ],
                    "startTime": 1666977689604828,
                    "duration": 43187,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "c27b2c5411baf3b6",
                    "flags": 3,
                    "operationName": "rewrite",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "56cd2ecf981d0918"
                        }
                    ],
                    "startTime": 1666977689712349,
                    "duration": 38771,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "d523c4890747823a",
                    "flags": 3,
                    "operationName": "request",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "05bd7c4d934a00f0"
                        }
                    ],
                    "startTime": 1666977689604569,
                    "duration": 161560,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "c3cd43544ecbc87c",
                    "flags": 3,
                    "operationName": "fetch",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "7d521297961cdc67"
                        }
                    ],
                    "startTime": 1666977689710544,
                    "duration": 53289,
                    "tags": [],
                    "logs": [],
                    "processID": "p4",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "38ce0caa9e4b3d22",
                    "flags": 3,
                    "operationName": "upstream_ttfb",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "206bd72c0bbf060d"
                        }
                    ],
                    "startTime": 1666977689751315,
                    "duration": 9377,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "7f70e28c238aa159",
                    "flags": 3,
                    "operationName": "upstream_ttfb",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "1ccad7dc6c81c815"
                        }
                    ],
                    "startTime": 1666977689650676,
                    "duration": 112750,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "021209054d6c3f1b",
                    "flags": 3,
                    "operationName": "request",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "206bd72c0bbf060d"
                        }
                    ],
                    "startTime": 1666977689752371,
                    "duration": 2968,
                    "tags": [],
                    "logs": [],
                    "processID": "p3",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "7d521297961cdc67",
                    "flags": 3,
                    "operationName": "request_context",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "c9179afc072b179d"
                        }
                    ],
                    "startTime": 1666977689652183,
                    "duration": 111950,
                    "tags": [],
                    "logs": [],
                    "processID": "p4",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "0a1a3ac8a681da9c",
                    "flags": 3,
                    "operationName": "http_request",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "1ccad7dc6c81c815"
                        }
                    ],
                    "startTime": 1666977689650841,
                    "duration": 112685,
                    "tags": [],
                    "logs": [],
                    "processID": "p4",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "abfa22088cbfe8dc",
                    "flags": 3,
                    "operationName": "request_logic",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "c27b2c5411baf3b6"
                        }
                    ],
                    "startTime": 1666977689712395,
                    "duration": 38639,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "206bd72c0bbf060d",
                    "flags": 3,
                    "operationName": "upstream",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "56cd2ecf981d0918"
                        }
                    ],
                    "startTime": 1666977689751295,
                    "duration": 10840,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "56cd2ecf981d0918",
                    "flags": 3,
                    "operationName": "request",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "c3cd43544ecbc87c"
                        }
                    ],
                    "startTime": 1666977689711999,
                    "duration": 53300,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "ed8c4a2564960938",
                    "flags": 3,
                    "operationName": "request",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "0014a21066967d7c"
                        },
                        {
                            "refType": "FOLLOWS_FROM",
                            "traceID": "b9906ed48bad4c78",
                            "spanID": "b9906ed48bad4c78"
                        }
                    ],
                    "startTime": 1666977689603563,
                    "duration": 162488,
                    "tags": [],
                    "logs": [],
                    "processID": "p2",
                    "warnings": [
                        "invalid parent span IDs=0014a21066967d7c; skipping clock skew adjustment"
                    ]
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "1ccad7dc6c81c815",
                    "flags": 3,
                    "operationName": "upstream",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "d523c4890747823a"
                        }
                    ],
                    "startTime": 1666977689650664,
                    "duration": 113907,
                    "tags": [],
                    "logs": [],
                    "processID": "p1",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "05bd7c4d934a00f0",
                    "flags": 3,
                    "operationName": "upstream_ttfb",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "ed8c4a2564960938"
                        }
                    ],
                    "startTime": 1666977689604361,
                    "duration": 159975,
                    "tags": [],
                    "logs": [],
                    "processID": "p2",
                    "warnings": null
                },
                {
                    "traceID": "0014a21066967d7c",
                    "spanID": "c9179afc072b179d",
                    "flags": 3,
                    "operationName": "code",
                    "references": [
                        {
                            "refType": "CHILD_OF",
                            "traceID": "0014a21066967d7c",
                            "spanID": "0a1a3ac8a681da9c"
                        }
                    ],
                    "startTime": 1666977689651704,
                    "duration": 112592,
                    "tags": [],
                    "logs": [],
                    "processID": "p4",
                    "warnings": [
                        "clock skew adjustment disabled; not applying calculated delta of -816.5µs"
                    ]
                }
            ],
            "processes": {
                "p1": {
                    "serviceName": "logic-proxy",
                    "tags": []
                },
                "p2": {
                    "serviceName": "eyeball-facing-service",
                    "tags": []
                },
                "p3": {
                    "serviceName": "cache",
                    "tags": []
                },
                "p4": {
                    "serviceName": "customer-code",
                    "tags": []
                }
            },
            "warnings": null
        }
    ],
    "total": 0,
    "limit": 0,
    "offset": 0,
    "errors": null
}

2. Open it in Jaeger and see the following perfectly normal trace timeline:

3. Switch to flamegraph view and see the following:

You can see that request_logic, which appears twice in the trace, is only shown once in the flamegraph.

The customer-code service that takes up a sizable chunk of time is also barely represented off to the side.

Expected behavior

Flamegraph shows all spans, they are organized in a logical way.

Relevant log output

No response

Screenshot

No response

Additional context

No response

Jaeger backend version

v1.39.0

SDK

No response

Pipeline

No response

Stogage backend

No response

Operating system

No response

Deployment model

No response

Deployment configs

No response

[bobrik]

I also made grafana/pyroscope#1671, since we're mostly using what pyroscope provides.

[Rperry2174]

Thanks for reporting and providing info to reproduce @bobrik Pyroscope team will take a look into this and fix