Skip to content

OTel: span start and end times given as epoch milliseconds, a Date or [seconds, nanoseconds] are misread #612

Closed

Description

@brycebaril

Summary

A span's start or end time given as epoch milliseconds, a Date or an [seconds, nanoseconds] pair is misread. The agent only reads a performance.now() value correctly. The OpenTelemetry API's TimeInput allows all four, for tracer.startSpan(name, { startTime }) and span.end(endTime).

Affected versions

Seen in the source of node-v24.x-nsolid-v6.x at 8b50e4a772, and the same lines are in 6.3.8 (node-v24.21.0-nsolid-v6.3.8).

Where

  • lib/internal/otel/trace.js:298 (startSpan): options.startTime || now() passes the caller's time on unchanged. end() does the same at lines 115-116: isTimeInput(endTime) ? endTime : now().
  • src/nsolid/nsolid_trace.cc:49 and :69 (Span::add_prop): every start and end gets performance_process_start_timestamp added, so only a performance.now() value comes out right.
  • src/nsolid/nsolid_api.cc:2440 and :2445 (SlowPushSpanDataDouble): DCHECK(args[3]->IsNumber()), then As<Number>(). A Date or an array fails the check in a debug build, and a release build reads it as a number without one.
  • agents/otlp/src/otlp_common.cc:582: the duration is static_cast<uint64_t>((s.end - s.start) * 1e6), so an end before the start wraps to a huge duration.

Actual

  • startTime: Date.now() is exported decades in the future: the process start plus the epoch. With the default end, the duration is negative and wraps.
  • startTime: new Date() or startTime: [seconds, nanoseconds] (what @opentelemetry/core's hrTime() returns) reaches the binding as something other than a number: an abort in a debug build, a garbage time in a release one.
  • span.end() with any of those has the same problems.

Reproduced

Not run yet; found by reading the code. With NSOLID_TRACING_ENABLED=1:

const api = require('@opentelemetry/api');
const nsolid = require('nsolid');
nsolid.otel.register(api);
const tracer = api.trace.getTracer('repro');
tracer.startSpan('epoch-ms', { startTime: Date.now() }).end();
tracer.startSpan('date', { startTime: new Date() }).end();
tracer.startSpan('hrtime', { startTime: [Math.floor(Date.now() / 1000), 0] }).end();

Suggested fix

Convert every TimeInput in startSpan and end() to the scale the native side expects, as the JS SDK does:

  • [seconds, nanoseconds] and Date become epoch milliseconds;
  • a number below the time origin is a performance.now() value;
  • anything else is epoch milliseconds;
  • then subtract the same origin Span::add_prop adds.

Fall back to now() for anything else, so nothing but a number reaches the binding.

Span events in #609 take numbers the other way round, as epoch milliseconds, with no performance.now() case. One conversion shared by spans and events would fix both.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    P2Medium priorityType: BugbugSomething isn't workinglaunch: stretchStretch goal for the N|Solid 7.0 release

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions