Skip to content

Commit 113be08

Browse files
committed
refactor(telemetry): use child spans for phase timing instead of manual measurement
Replace performance.now() markers and setPhaseTimingAttributes with cli.command.exec and cli.command.render child spans. Span durations are the idiomatic way to measure phases — they appear in the trace waterfall and don't require custom attributes. Updated the 'Command Phase Breakdown' dashboard widget to query span.duration grouped by span.op instead of custom phase.* attributes.
1 parent 6bb93aa commit 113be08

File tree

2 files changed

+21
-54
lines changed

2 files changed

+21
-54
lines changed

src/lib/command.ts

Lines changed: 21 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -60,11 +60,7 @@ import {
6060
parseLogLevel,
6161
setLogLevel,
6262
} from "./logger.js";
63-
import {
64-
setArgsContext,
65-
setFlagContext,
66-
setPhaseTimingAttributes,
67-
} from "./telemetry.js";
63+
import { setArgsContext, setFlagContext, withTracing } from "./telemetry.js";
6864

6965
/**
7066
* Parse a string input as a number.
@@ -526,8 +522,6 @@ export function buildCommand<
526522
flags: Record<string, unknown>,
527523
...args: unknown[]
528524
) {
529-
const phaseStart = performance.now();
530-
531525
applyLoggingFlags(
532526
flags[LOG_LEVEL_KEY] as LogLevelName | undefined,
533527
flags.verbose as boolean
@@ -579,9 +573,6 @@ export function buildCommand<
579573
throw err;
580574
};
581575

582-
// End of pre-command phase (flag parsing, context setup)
583-
const preEnd = performance.now();
584-
585576
// Iterate the generator using manual .next() instead of for-await-of
586577
// so we can capture the return value (done: true result). The return
587578
// value carries the final `hint` — for-await-of discards it.
@@ -595,30 +586,28 @@ export function buildCommand<
595586
throw new AuthError("not_authenticated");
596587
}
597588

598-
const generator = originalFunc.call(
599-
this,
600-
cleanFlags as FLAGS,
601-
...(args as unknown as ARGS)
589+
// Execution phase: core command logic, API calls, org/project resolution
590+
const returned = await withTracing(
591+
"exec",
592+
"cli.command.exec",
593+
async () => {
594+
const generator = originalFunc.call(
595+
this,
596+
cleanFlags as FLAGS,
597+
...(args as unknown as ARGS)
598+
);
599+
let result = await generator.next();
600+
while (!result.done) {
601+
handleYieldedValue(stdout, result.value, cleanFlags, renderer);
602+
result = await generator.next();
603+
}
604+
return result.value as CommandReturn | undefined;
605+
}
602606
);
603-
let result = await generator.next();
604-
while (!result.done) {
605-
handleYieldedValue(stdout, result.value, cleanFlags, renderer);
606-
result = await generator.next();
607-
}
608-
609-
// End of execution phase (core command logic + API calls)
610-
const execEnd = performance.now();
611-
612-
// Generator completed successfully — finalize with hint.
613-
const returned = result.value as CommandReturn | undefined;
614-
writeFinalization(stdout, returned?.hint, cleanFlags.json, renderer);
615607

616-
// Record phase timing on the active span
617-
const renderEnd = performance.now();
618-
setPhaseTimingAttributes({
619-
preMs: preEnd - phaseStart,
620-
execMs: execEnd - preEnd,
621-
renderMs: renderEnd - execEnd,
608+
// Render phase: output finalization
609+
await withTracing("render", "cli.command.render", () => {
610+
writeFinalization(stdout, returned?.hint, cleanFlags.json, renderer);
622611
});
623612
} catch (err) {
624613
// Finalize before error handling to close streaming state

src/lib/telemetry.ts

Lines changed: 0 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -615,28 +615,6 @@ export function setArgsContext(args: readonly unknown[]): void {
615615
});
616616
}
617617

618-
/**
619-
* Set phase timing attributes on the active span.
620-
*
621-
* Records how long each phase of command execution took, enabling
622-
* dashboard breakdown of pre-command (flag parsing, context setup),
623-
* execution (core logic + API calls), and render (output formatting) phases.
624-
*
625-
* @param phases - Timing data for each command phase in milliseconds
626-
*/
627-
export function setPhaseTimingAttributes(phases: {
628-
preMs: number;
629-
execMs: number;
630-
renderMs: number;
631-
}): void {
632-
const span = Sentry.getActiveSpan();
633-
if (span) {
634-
span.setAttribute("phase.pre_ms", Math.round(phases.preMs));
635-
span.setAttribute("phase.exec_ms", Math.round(phases.execMs));
636-
span.setAttribute("phase.render_ms", Math.round(phases.renderMs));
637-
}
638-
}
639-
640618
/**
641619
* Wrap an operation with a Sentry span for tracing.
642620
*

0 commit comments

Comments
 (0)