fix(observability): stamp HTTP logs with request-issue time (SDK-6164)

[harshit-browserstack]

Summary

createHttpLogEvent stamps each LogCreated / HTTP event with httpResponse[0] — the instant the response landed — so HTTP logs render out of order in the Test Observability Logs tab. A request that takes 5s carries a timestamp 5s after it was issued, and therefore sorts after every log line the test wrote while it was still in flight.

This PR stamps the event with httpRequest[0] (request-issued) instead. One field; duration_ms is unaffected.

Linked ticket: BrowserStack SDK-6164
Target package release: @nightwatch/browserstack@3.11.4 (patch — bug fix, no API change)

Opened on the BrowserStack fork per SDK PR-target policy (internal repo / BrowserStack fork, never the public upstream). Supersedes the public-upstream attempts nightwatchjs#55 and nightwatchjs#62, both closed for that reason. The plugin repo carries no PR template, so the headings below follow the BrowserStack SDK template.

TRA Link

N/A — this is a plugin-side code change, not a BStackAutomation test run, so there is no regression TRA build for it. Jira: https://browserstack.atlassian.net/browse/SDK-6164

Details

Root cause

Nightwatch builds every httpOutput entry as [isoTimestamp, message, params] at the moment that line is logged:

// nightwatch/lib/utils/logger/index.js
const d = new Date();
const timeIso = d.toISOString();
instance.commandOutput.push([timeIso, lodashEscape(message), lodashEscape(inspectObject(params))]);

logRequest() runs before the request is sent (lib/http/request.js, right after createHttpRequest()); logResponse() runs from onRequestComplete. So httpResponse[0] is request-issue time plus the entire round trip.

The plugin used that value as the log's own timestamp:

{
  test_run_uuid: test_run_uuid,
  timestamp: httpResponse[0],   // response-received, not request-issued
  kind: 'HTTP',
  http_response: {
    ...
    duration_ms: new Date(httpResponse[0]).getTime() - new Date(httpRequest[0]).getTime(),
  }
}

The line dates to the original HTTP-log implementation (f9827994, Apr 2023) and carries no rationale — duration_ms was added separately later (c39e842d). Nothing else in the plugin reads a log event's timestamp.

Fix

Stamp with httpRequest[0].

• duration_ms is computed from httpRequest[0] and httpResponse[0] independently, so it still spans request → response. No metric changes.
• Aligns the HTTP emitter with createScreenshotLogEvent, which already stamps with the command's startTime rather than a completion time.
• Additive and behaviour-preserving for every other event type.

Scope — what this PR deliberately does NOT include

SDK-6164 also proposes a monotonic sequence tiebreaker so logs sharing the same millisecond order deterministically. That half is intentionally left out:

• Whether the Logs tab can order on a sequence field is a TRA backend question. The backend sort logic lives in no SDK-side repo, and the internal read endpoint (api/v1/testRuns/<id>/consolidatedLogs) returns 401 Unauthorized Access! with the credentials available here, so the stored/served order could not be read back to confirm it.
• Sending sequence today would be inert until the backend adopts it as a secondary sort key, and the gRPC LogCreatedEventRequest.LogEntry proto has no sequence field, so the Binary/gRPC flow could not carry it for other SDKs.

Tracked as a cross-team follow-up. This PR stands on its own: it makes the HTTP log's timestamp mean what it claims to mean, which is correct regardless of that decision.

How Has This Been Tested?

• Unit — npm test: 94 passing, 0 failing. Adds test/src/test-observability/createHttpLogEvent.js (4 cases): request-time stamping, duration_ms still 5000ms across the span, issue-order preserved for a slow-then-fast request pair, and the non-Request/Response guard.
  • With BROWSERSTACK_USERNAME / BROWSERSTACK_ACCESS_KEY exported, 12 tests in test/src/utils/helper.js fail because they assert env-derived getters return literals. Those same 12 fail identically on unmodified origin/main (78 passing / 12 failing vs. 82 / 12 here — i.e. +4 new tests, no new failures). Pre-existing and unrelated.
• Lint — npm run eslint: clean.
• Live collector — a LogCreated batch posted to https://collector-observability.browserstack.com/api/v1/batch was accepted (200 {"success":true}) carrying request-issued timestamps.

Screenshots (if appropriate):

N/A — no UI change in this repo. The customer-visible effect is log ordering in the Test Observability Logs tab, captured in the SDK-6164 ticket.

Types of changes

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Refactor (code change that does not change external functionality)

Checklist:

• I've resolved all linter issues
• My change requires a change to the documentation. — N/A, internal timestamp semantics, no documented behaviour changes
• I have updated the documentation accordingly. — N/A per above