Skip to content

Traces are not being sent correctly together #408

@kulliax

Description

@kulliax

Hi @sjvans ,

we are currently experiencing strange behaviour when it comes to sending otel traces to cls.

Our CAP service sends three requests, but only two of them are logged in spans. I can see that all three requests are sent in our normal log or application behaviour.

When I define DEBUG=telemetry as a variable, I cannot do much with the log because it adds "objects" and "arrays" to the relevant sections.

Edit: Sent too quickly, sorry, I found the log. It seems that the parent is not being filled in here. Below is a comparison of the two logs. The error is not the reason, it is the shortest standalone log. If I comment out one of the logged requests, the missing one is also logged. If I look a little further, I also find standalone commits and queries.

request trace:
Image

time logging:
Image

missed trace in request trace
Image

standalone traces:
Image

not correctly logged
[
  {
    "_index": "otel-v1-apm-span-000543",
    "_id": "f40293dd62de0292",
    "_score": 12.09418,
    "_source": {
      "traceId": "d383208a2974733048596165208e7c83",
      "droppedLinksCount": 0,
      "kind": "SPAN_KIND_CLIENT",
      "droppedEventsCount": 0,
      "traceGroupFields": {
        "endTime": "2026-01-30T09:14:11.964677680Z",
        "durationInNanos": 68677680,
        "statusCode": 2
      },
      "traceGroup": "... - CREATE …",
      "serviceName": "srv-main",
      "parentSpanId": "",
      "spanId": "f40293dd62de0292",
      "traceState": "",
      "name": "... - CREATE …",
      "startTime": "2026-01-30T09:14:11.896Z",
      "links": [],
      "endTime": "2026-01-30T09:14:11.964677680Z",
      "droppedAttributesCount": 0,
      "durationInNanos": 68677680,
      "events": [
        {
          "name": "exception",
          "time": "2026-01-30T09:14:11.964654300Z",
          "attributes": {
            "exception@message": "Error during request to remote service: Failed to load destination.",
            "exception@type": "Error",
            "exception@stacktrace": "Error: Error during request to remote service: Failed to load destination.\n    at module.exports.run (/home/vcap/deps/0/node_modules/@sap/cds/libx/_runtime/remote/utils/client.js:196:31)\n    at process.processTicksAndRejections (node:internal/process/task_queues:105:5)\n    at async RemoteService.on_handler (/home/vcap/deps/0/node_modules/@sap/cds/libx/_runtime/remote/Service.js:278:20)\n    at async next (/home/vcap/deps/0/node_modules/@sap/cds/lib/srv/srv-dispatch.js:57:17)\n    at async RemoteService.handle (/home/vcap/deps/0/node_modules/@sap/cds/lib/srv/srv-dispatch.js:55:10)\n    at ..."
          },
          "droppedAttributesCount": 0
        }
      ],
      "resource.attributes.sap@cf@process@type": "web",
      "span.attributes.code@file@path": "/home/vcap/deps/0/node_modules/@sap/cds/lib/srv/srv-dispatch.js",
      "resource.attributes.sap@cf@source_type": "APP/PROC/WEB",
      "resource.attributes.telemetry@sdk@version": "1.30.1",
      "resource.attributes.service@instance@id": "b2636a79-8b13-4689-4d96-a5f9",
      "resource.attributes.service@name": "srv-main",
      "status.code": 2,
      "resource.attributes.sap@cf@source_id": "0654d79a-45b4-4ea3-a862-70dbd78bb628",
      "resource.attributes.service@version": "3.0.0",
      "resource.attributes.sap@cf@app_name": "proj",
      "span.attributes.code@column@number": 40,
      "span.attributes.code@function@name": "handle",
      "span.attributes.code@namespace": "@sap/cds/lib/srv/srv-dispatch.js",
      "resource.attributes.sap@cf@instance_id": "b2636a79-8b13-4689-4d96-a5f9",
      "resource.attributes.sap@cf@org_id": "7e68da9d-1933-47a0-8830-17c518d55aee",
      "resource.attributes.telemetry@sdk@language": "nodejs",
      "resource.attributes.sap@cf@process@instance_id": "b2636a79-8b13-4689-4d96-a5f9",
      "span.attributes.code@line@number": 38,
      "resource.attributes.sap@cf@space_id": "a0ae6351-ea01-4835-bc26-49110943325f",
      "resource.attributes.sap@cf@org_name": "test",
      "status.message": "Error during request to remote service: Failed to load destination.",
      "instrumentationScope.version": "1.6.0",
      "instrumentationScope.name": "@cap-js/telemetry",
      "resource.attributes.telemetry@sdk@name": "opentelemetry",
      "span.attributes.server@port": 8080,
      "resource.attributes.sap@cf@space_name": "validate",
      "resource.attributes.sap@cf@process@id": "0654d79a-45b4-4ea3-a862-70dbd78bb628",
      "resource.attributes.sap@cf@app_id": "0654d79a-45b4-4ea3-a862-70dbd78bb628"
    }
  }
]

correctly logged
{
    "_index": "otel-v1-apm-span-000543",
    "_id": "2e943a66ca55dce3",
    "_score": 10.791862,
    "_source": {
      "traceId": "71cd0248a2a1e4f0f411284efd6b9157",
      "droppedLinksCount": 0,
      "kind": "SPAN_KIND_CLIENT",
      "droppedEventsCount": 0,
      "traceGroupFields": {
        "endTime": "2026-01-30T09:14:12.015334410Z",
        "durationInNanos": 348334410,
        "statusCode": 2
      },
      "traceGroup": "POST",
      "serviceName": "srv-main",
      "parentSpanId": "4ac1f88711283b4d",
      "spanId": "2e943a66ca55dce3",
      "traceState": "",
      "name": "... - CREATE …",
      "startTime": "2026-01-30T09:14:11.679Z",
      "links": [],
      "endTime": "2026-01-30T09:14:11.856653088Z",
      "droppedAttributesCount": 0,
      "durationInNanos": 177653088,
      "events": [],
      "resource.attributes.sap@cf@process@type": "web",
      "span.attributes.code@file@path": "/home/vcap/deps/0/node_modules/@sap/cds/lib/srv/srv-dispatch.js",
      "span.attributes.sap@tenancy@tenant_id": "f0dd37fc-ce38-4762-b6fa-e3d90d64c603",
      "resource.attributes.sap@cf@source_type": "APP/PROC/WEB",
      "resource.attributes.telemetry@sdk@version": "1.30.1",
      "resource.attributes.service@instance@id": "b2636a79-8b13-4689-4d96-a5f9",
      "resource.attributes.service@name": "srv-main",
      "status.code": 1,
      "resource.attributes.sap@cf@source_id": "0654d79a-45b4-4ea3-a862-70dbd78bb628",
      "resource.attributes.service@version": "3.0.0",
      "resource.attributes.sap@cf@app_name": "proj",
      "span.attributes.code@column@number": 40,
      "span.attributes.http@target": "/odata/v4/proj/...",
      "span.attributes.url@path": "/odata/v4/proj/...",
      "span.attributes.code@function@name": "handle",
      "span.attributes.code@namespace": "@sap/cds/lib/srv/srv-dispatch.js",
      "resource.attributes.sap@cf@instance_id": "b2636a79-8b13-4689-4d96-a5f9",
      "resource.attributes.sap@cf@org_id": "7e68da9d-1933-47a0-8830-17c518d55aee",
      "resource.attributes.telemetry@sdk@language": "nodejs",
      "resource.attributes.sap@cf@process@instance_id": "b2636a79-8b13-4689-4d96-a5f9",
      "span.attributes.code@line@number": 38,
      "resource.attributes.sap@cf@space_id": "a0ae6351-ea01-4835-bc26-49110943325f",
      "resource.attributes.sap@cf@org_name": "test",
      "instrumentationScope.version": "1.6.0",
      "instrumentationScope.name": "@cap-js/telemetry",
      "resource.attributes.telemetry@sdk@name": "opentelemetry",
      "span.attributes.server@port": 8080,
      "resource.attributes.sap@cf@space_name": "validate",
      "resource.attributes.sap@cf@process@id": "0654d79a-45b4-4ea3-a862-70dbd78bb628",
      "resource.attributes.sap@cf@app_id": "0654d79a-45b4-4ea3-a862-70dbd78bb628"
    }
  }

versions:
@sap/cds: 9.6.4
@sap/cds-compiler: 6.6.2
@sap/cds-dk: 9.6.1
@sap/cds-dk (global): 9.6.1
@sap/cds-fiori: 2.1.1
@sap/cds-mtxs: 3.6.1
@cap-js/asyncapi: 1.0.3
@cap-js/cds-test: 0.4.1
@cap-js/cds-typer: 0.37.0
@cap-js/cds-types: 0.15.0
@cap-js/db-service: 2.8.1
@cap-js/hana: 2.5.1
@cap-js/openapi: 1.3.1
@cap-js/sqlite: 2.1.2
@cap-js/telemetry: 1.6.0
@sap/eslint-plugin-cds: 4.1.0
Node.js: v22.13.1

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions