Skip to content

fix(trace): record failed request durations, print request start times - #42191

Open
John Hill (unlikelyzero) wants to merge 3 commits into
microsoft:mainfrom
unlikelyzero:har-failed-request-duration
Open

fix(trace): record failed request durations, print request start times#42191
John Hill (unlikelyzero) wants to merge 3 commits into
microsoft:mainfrom
unlikelyzero:har-failed-request-duration

Conversation

@unlikelyzero

Copy link
Copy Markdown
Contributor

Summary

  • Record a duration for failed and route.abort()ed requests when tracing — the failure path previously left HAR time at -1, so traces never knew when such requests ended. Gated on the trace-only _monotonicTime field; user-exported HAR files are unaffected.
  • Add a Start column to trace requests (same clock and format as the trace actions Time column) and a start: line to trace request <id>, so request/action overlap is readable directly from CLI output.

Fixes #42172

Failure is the only HAR entry finish path that computes no timings, so
failed and route.abort()ed requests kept `time` at its -1 default and
traces never recorded when such requests ended. Derive the duration from
the entry's monotonic start timestamp instead. Gated on the trace-only
`_monotonicTime` field, so user-exported HAR files are unaffected and
keep the spec-defined value.

With this, every request in a trace has a complete lifetime, and
`trace requests` prints a real duration where it previously showed '-'.
`trace actions` prints each action's relative start time, but
`trace requests` printed only durations, so whether a request was still
in flight when an action ran was not derivable from CLI output. Print
each request's start from `_monotonicTime`, which the trace model
adjusts by the same clock delta as action times, using the same
timestamp format as the actions Time column so the two tables correlate
directly. The `request <id>` detail view gains a matching `start:` line.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good, those are just nit picks

Comment thread packages/playwright-core/src/tools/skills/playwright-trace/SKILL.md Outdated
Comment thread packages/playwright-core/src/server/har/harTracer.ts Outdated
Comment thread packages/playwright-core/src/tools/trace/traceRequests.ts Outdated
Comment thread packages/playwright-core/src/server/har/harTracer.ts Outdated
@unlikelyzero

Copy link
Copy Markdown
Contributor Author

Pavel Feldman (@pavelfeldman) addressed!

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Improves Playwright trace tooling by making network request timing comparable to action timing in CLI output, and by ensuring failed/aborted requests have a recorded duration in trace HAR data (trace-only fields).

Changes:

  • Record harEntry.time for failed/aborted requests when trace-only _monotonicTime is present.
  • Add request start timestamps to trace requests and trace request <id> output.
  • Extend MCP and tracing tests to cover request start/duration behavior.

Reviewed changes

Copilot reviewed 6 out of 6 changed files in this pull request and generated 3 comments.

Show a summary per file
File Description
tests/mcp/trace-cli.spec.ts Adds assertions for request start timestamps and aborted request durations in trace CLI output.
tests/mcp/trace-cli-fixtures.ts Introduces an aborted request scenario to exercise trace request timing output.
tests/library/tracing.spec.ts Adds trace-level assertions that failures include _monotonicTime and a non-negative duration.
packages/playwright-core/src/tools/trace/traceRequests.ts Prints request start timestamps in list/detail views using the trace action clock.
packages/playwright-core/src/tools/skills/playwright-trace/SKILL.md Updates CLI skill docs to mention request start time output.
packages/playwright-core/src/server/har/harTracer.ts Computes harEntry.time on request failure when trace-only monotonic timestamps exist.
Suppressed comments (1)

packages/playwright-core/src/tools/trace/traceRequests.ts:99

  • Same truthy check issue as above: if _monotonicTime is 0, the start: line will be omitted even though the timestamp is known.
  if (r._monotonicTime)
    console.log(`    start:     ${formatTimestamp(r._monotonicTime, model.startTime)}`);

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment on lines +412 to +413
if (harEntry._monotonicTime && harEntry.time === -1)
harEntry.time = monotonicTime() - harEntry._monotonicTime;
const { events } = await parseTraceRaw(testInfo.outputPath('trace1.zip'));
const requestEvent = events.find(e => e.type === 'resource-snapshot' && !!e.snapshot.response._failureText);
expect(requestEvent).toBeTruthy();
expect(requestEvent.snapshot._monotonicTime).toBeGreaterThan(0);
const size = r.response._transferSize! > 0 ? r.response._transferSize! : r.response.bodySize;
const route = formatRouteStatus(r);
console.log(` ${(ordinal + '.').padStart(4)} ${r.request.method.padEnd(8)} ${status.padEnd(8)} ${name.padEnd(45)} ${msToString(r.time).padStart(10)} ${bytesToString(size).padStart(8)} ${route.padEnd(10)}`);
const start = r._monotonicTime ? formatTimestamp(r._monotonicTime, model.startTime) : '-';
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

trace CLI: request timing cannot be correlated with actions

3 participants