Skip to content

fix(observability): order TRA logs by request time + monotonic sequence (SDK-6164)#55

Closed
harshit-browserstack wants to merge 1 commit into
nightwatchjs:mainfrom
harshit-browserstack:sdk-6164-tra-log-ordering
Closed

fix(observability): order TRA logs by request time + monotonic sequence (SDK-6164)#55
harshit-browserstack wants to merge 1 commit into
nightwatchjs:mainfrom
harshit-browserstack:sdk-6164-tra-log-ordering

Conversation

@harshit-browserstack
Copy link
Copy Markdown
Contributor

SDK-6164 — TRA log timestamp ordering

Problem. Logs reach Test Observability but the Logs tab renders them out of order. The backend orders log events by their timestamp, and two emitters produced timestamps that didn't reflect emission order:

  1. createHttpLogEvent stamped HTTP logs with the response-received time (httpResponse[0]). A slow request therefore sorted after logs that were emitted while it was still in flight.
  2. No LogCreated event carried a tiebreaker, so logs sharing the same millisecond had a non-deterministic order.

Fix.

  • Stamp HTTP logs with the request-issued time (httpRequest[0]). duration_ms is still measured request→response, so no metric regresses.
  • Add a per-process monotonic sequence (new src/utils/logSequence.js) to every LogCreated event (TEST_LOG, HTTP, TEST_SCREENSHOT) so the backend can sort by (timestamp, sequence).

Verification. A standalone emission-boundary repro (stubbing helper.uploadEventData) shows the server-sorted (timestamp, sequence) order now equals emission order — inversion=false, tie=false. Added test/src/test-observability/logOrdering.js (4 cases) covering request-time stamping, post-sort ordering, same-ms tiebreaking, and the shared cross-kind sequence. All pass; eslint clean.

⚠️ Cross-team dependency: the sequence field is inert until the TRA backend adds it as a secondary sort key (timestamp, sequence). Fix #1 (request-time stamping) takes effect immediately since the backend already sorts by timestamp. The sequence tiebreaker needs the backend change to have any effect — tracked as a follow-up.

🤖 Generated with Claude Code

SDK-6164: logs reach Test Observability but the Logs tab renders them
out of order because the backend sorts by the event timestamp.

- createHttpLogEvent stamped HTTP logs with the response-received time
  (httpResponse[0]), so a slow request sorted after logs emitted while it
  was in flight. Stamp with the request-issued time (httpRequest[0]) instead;
  duration_ms is still measured request->response.
- No LogCreated event carried a tiebreaker, so same-millisecond logs had a
  non-deterministic order. Add a per-process monotonic `sequence` (new
  src/utils/logSequence.js) to every log event (TEST_LOG, HTTP, TEST_SCREENSHOT)
  so the backend can sort by (timestamp, sequence).

Adds test/src/test-observability/logOrdering.js (4 cases) covering both.

Note: the `sequence` tiebreaker is inert until the TRA backend adds it as a
secondary sort key — tracked as a cross-team follow-up.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@harshit-browserstack
Copy link
Copy Markdown
Contributor Author

Closing — this targeted the public upstream by mistake. Re-opening within the BrowserStack fork.

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.

1 participant