From 4217e9f6d53d5882071d342e4cc99cf879726682 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Tue, 3 Oct 2023 20:43:41 -0500 Subject: [PATCH 01/15] fix: support proxy correlation timeout notifications and additional proxy data --- packages/proxy/lib/http/index.ts | 1 + .../proxy/lib/http/response-middleware.ts | 18 ++- packages/proxy/lib/http/util/prerequests.ts | 63 ++++++++-- packages/proxy/lib/types.ts | 14 ++- .../unit/http/response-middleware.spec.ts | 20 +++ .../test/unit/http/util/prerequests.spec.ts | 106 ++++++++++++++-- .../server/lib/browsers/cdp_automation.ts | 3 + packages/server/lib/cloud/protocol.ts | 6 +- .../test/unit/browsers/cdp_automation_spec.ts | 38 +++--- packages/types/src/protocol.ts | 9 ++ system-tests/__snapshots__/protocol_spec.js | 117 +++++++++++++++--- .../lib/protocol-stubs/protocolStub.ts | 8 +- .../protocolStubWithBeforeSpecError.ts | 3 +- .../protocolStubWithBeforeTestError.ts | 3 +- .../protocolStubWithNonFatalError.ts | 3 +- .../protocolStubWithRuntimeError.ts | 3 +- system-tests/test/protocol_spec.js | 2 +- 17 files changed, 354 insertions(+), 63 deletions(-) diff --git a/packages/proxy/lib/http/index.ts b/packages/proxy/lib/http/index.ts index f6436f9391b9..85d96a1e802a 100644 --- a/packages/proxy/lib/http/index.ts +++ b/packages/proxy/lib/http/index.ts @@ -427,5 +427,6 @@ export class Http { setProtocolManager (protocolManager: ProtocolManagerShape) { this.protocolManager = protocolManager + this.preRequests.setProtocolManager(protocolManager) } } diff --git a/packages/proxy/lib/http/response-middleware.ts b/packages/proxy/lib/http/response-middleware.ts index 641c76d846a9..7077e51fc04d 100644 --- a/packages/proxy/lib/http/response-middleware.ts +++ b/packages/proxy/lib/http/response-middleware.ts @@ -691,6 +691,13 @@ const MaybeEndWithEmptyBody: ResponseMiddleware = function () { this.protocolManager.responseEndedWithEmptyBody({ requestId, isCached: this.incomingRes.statusCode === 304, + timings: { + cdpClientSideEventTime: this.req.browserPreRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: this.req.browserPreRequest.cdpServerSideEventReceivedTime, + proxyReceivedTime: this.req.browserPreRequest.proxyReceivedTime, + cdpLagTime: this.req.browserPreRequest.cdpLagTime, + correlationTime: this.req.browserPreRequest.correlationTime, + }, }) } @@ -797,15 +804,24 @@ const MaybeRemoveSecurity: ResponseMiddleware = function () { const GzipBody: ResponseMiddleware = async function () { if (this.protocolManager && this.req.browserPreRequest?.requestId) { - const requestId = getOriginalRequestId(this.req.browserPreRequest.requestId) + const preRequest = this.req.browserPreRequest + const requestId = getOriginalRequestId(preRequest.requestId) const span = telemetry.startSpan({ name: 'gzip:body:protocol-notification', parentSpan: this.resMiddlewareSpan, isVerbose }) + const resultingStream = this.protocolManager.responseStreamReceived({ requestId, responseHeaders: this.incomingRes.headers, isAlreadyGunzipped: this.isGunzipped, responseStream: this.incomingResStream, res: this.res, + timings: { + cdpClientSideEventTime: preRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: preRequest.cdpServerSideEventReceivedTime, + proxyReceivedTime: preRequest.proxyReceivedTime, + cdpLagTime: preRequest.cdpLagTime, + correlationTime: preRequest.correlationTime, + }, }) if (resultingStream) { diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 2062d66967be..9f982d8795e0 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -1,7 +1,9 @@ import type { CypressIncomingRequest, BrowserPreRequest, + BrowserPreRequestWithTimings, } from '@packages/proxy' +import type { ProtocolManagerShape } from '@packages/types' import Debug from 'debug' const debug = Debug('cypress:proxy:http:util:prerequests') @@ -19,17 +21,20 @@ process.once('exit', () => { debug('metrics: %o', metrics) }) -export type GetPreRequestCb = (browserPreRequest?: BrowserPreRequest) => void +export type GetPreRequestCb = (browserPreRequest?: BrowserPreRequestWithTimings) => void type PendingRequest = { ctxDebug callback: GetPreRequestCb timeout: NodeJS.Timeout + timedOut?: boolean + proxyReceivedTime: number } type PendingPreRequest = { browserPreRequest: BrowserPreRequest - timestamp: number + cdpClientSideEventTime: number + cdpServerSideEventReceivedTime: number } /** @@ -82,9 +87,10 @@ export class PreRequests { pendingPreRequests = new QueueMap() pendingRequests = new QueueMap() sweepIntervalTimer: NodeJS.Timeout + protocolManager?: ProtocolManagerShape constructor ( - requestTimeout = 500, + requestTimeout = 1000 * 2, // 10 seconds sweepInterval = 1000 * 10, ) { @@ -103,8 +109,8 @@ export class PreRequests { this.sweepIntervalTimer = setInterval(() => { const now = Date.now() - this.pendingPreRequests.removeMatching(({ timestamp, browserPreRequest }) => { - if (timestamp + this.sweepInterval < now) { + this.pendingPreRequests.removeMatching(({ cdpServerSideEventReceivedTime, browserPreRequest }) => { + if (cdpServerSideEventReceivedTime + this.sweepInterval < now) { debugVerbose('timed out unmatched pre-request: %o', browserPreRequest) metrics.unmatchedPreRequests++ @@ -123,8 +129,30 @@ export class PreRequests { if (pendingRequest) { debugVerbose('Incoming pre-request %s matches pending request. %o', key, browserPreRequest) - clearTimeout(pendingRequest.timeout) - pendingRequest.callback(browserPreRequest) + if (!pendingRequest.timedOut) { + clearTimeout(pendingRequest.timeout) + pendingRequest.callback({ + ...browserPreRequest, + cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, + proxyReceivedTime: pendingRequest.proxyReceivedTime, + cdpLagTime: browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime, + correlationTime: Math.max(browserPreRequest.cdpServerSideEventReceivedTime - pendingRequest.proxyReceivedTime, 0), + }) + + return + } + + this.protocolManager?.responseStreamTimedOut({ + requestId: browserPreRequest.requestId, + timings: { + cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, + proxyReceivedTime: pendingRequest.proxyReceivedTime, + cdpLagTime: browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime, + correlationTime: Math.max(browserPreRequest.cdpServerSideEventReceivedTime - pendingRequest.proxyReceivedTime, 0), + }, + }) return } @@ -132,7 +160,8 @@ export class PreRequests { debugVerbose('Caching pre-request %s to be matched later. %o', key, browserPreRequest) this.pendingPreRequests.push(key, { browserPreRequest, - timestamp: Date.now(), + cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, }) } @@ -143,6 +172,8 @@ export class PreRequests { } get (req: CypressIncomingRequest, ctxDebug, callback: GetPreRequestCb) { + const proxyReceivedTime = performance.now() + performance.timeOrigin + metrics.proxyRequestsReceived++ const key = `${req.method}-${req.proxiedUrl}` const pendingPreRequest = this.pendingPreRequests.shift(key) @@ -150,7 +181,14 @@ export class PreRequests { if (pendingPreRequest) { metrics.immediatelyMatchedRequests++ ctxDebug('Incoming request %s matches known pre-request: %o', key, pendingPreRequest) - callback(pendingPreRequest.browserPreRequest) + callback({ + ...pendingPreRequest.browserPreRequest, + cdpClientSideEventTime: pendingPreRequest.cdpClientSideEventTime, + cdpServerSideEventReceivedTime: pendingPreRequest.cdpServerSideEventReceivedTime, + proxyReceivedTime, + cdpLagTime: pendingPreRequest.cdpServerSideEventReceivedTime - pendingPreRequest.cdpClientSideEventTime, + correlationTime: Math.max(pendingPreRequest.cdpServerSideEventReceivedTime - proxyReceivedTime, 0), + }) return } @@ -158,14 +196,19 @@ export class PreRequests { const pendingRequest: PendingRequest = { ctxDebug, callback, + proxyReceivedTime: performance.now() + performance.timeOrigin, timeout: setTimeout(() => { ctxDebug('Never received pre-request for request %s after waiting %sms. Continuing without one.', key, this.requestTimeout) metrics.unmatchedRequests++ - this.pendingRequests.removeExact(key, pendingRequest) + pendingRequest.timedOut = true callback() }, this.requestTimeout), } this.pendingRequests.push(key, pendingRequest) } + + setProtocolManager (protocolManager: ProtocolManagerShape) { + this.protocolManager = protocolManager + } } diff --git a/packages/proxy/lib/types.ts b/packages/proxy/lib/types.ts index 20384ee211e6..936b1b6c7aa9 100644 --- a/packages/proxy/lib/types.ts +++ b/packages/proxy/lib/types.ts @@ -10,7 +10,7 @@ export type CypressIncomingRequest = Request & { proxiedUrl: string abort: () => void requestId: string - browserPreRequest?: BrowserPreRequest + browserPreRequest?: BrowserPreRequestWithTimings body?: string responseTimeout?: number followRedirect?: boolean @@ -60,8 +60,20 @@ export type BrowserPreRequest = { resourceType: ResourceType originalResourceType: string | undefined errorHandled?: boolean + cdpClientSideEventTime: number + cdpServerSideEventReceivedTime: number } +export type ProxyTimings = { + cdpClientSideEventTime: number + cdpServerSideEventReceivedTime: number + proxyReceivedTime: number + cdpLagTime: number + correlationTime: number +} + +export type BrowserPreRequestWithTimings = BrowserPreRequest & ProxyTimings + /** * Notification that the browser has received a response for a request for which a pre-request may have been emitted. */ diff --git a/packages/proxy/test/unit/http/response-middleware.spec.ts b/packages/proxy/test/unit/http/response-middleware.spec.ts index d0f9dc075b09..f2ac7c060324 100644 --- a/packages/proxy/test/unit/http/response-middleware.spec.ts +++ b/packages/proxy/test/unit/http/response-middleware.spec.ts @@ -1827,6 +1827,11 @@ describe('http/response-middleware', function () { req: { browserPreRequest: { requestId: '123', + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: 2, + proxyReceivedTime: 3, + cdpLagTime: 4, + correlationTime: 5, }, }, incomingRes: { @@ -1840,6 +1845,11 @@ describe('http/response-middleware', function () { sinon.match(function (actual) { expect(actual.requestId).to.equal('123') expect(actual.isCached).to.equal(true) + expect(actual.timings.cdpClientSideEventTime).to.equal(1) + expect(actual.timings.cdpServerSideEventReceivedTime).to.equal(2) + expect(actual.timings.proxyReceivedTime).to.equal(3) + expect(actual.timings.cdpLagTime).to.equal(4) + expect(actual.timings.correlationTime).to.equal(5) return true }), @@ -2259,6 +2269,11 @@ describe('http/response-middleware', function () { req: { browserPreRequest: { requestId: '123', + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: 2, + proxyReceivedTime: 3, + cdpLagTime: 4, + correlationTime: 5, }, }, res, @@ -2278,6 +2293,11 @@ describe('http/response-middleware', function () { expect(actual.isAlreadyGunzipped).to.equal(true) expect(actual.responseStream).to.equal(stream) expect(actual.res).to.equal(res) + expect(actual.timings.cdpClientSideEventTime).to.equal(1) + expect(actual.timings.cdpServerSideEventReceivedTime).to.equal(2) + expect(actual.timings.proxyReceivedTime).to.equal(3) + expect(actual.timings.cdpLagTime).to.equal(4) + expect(actual.timings.correlationTime).to.equal(5) return true }), diff --git a/packages/proxy/test/unit/http/util/prerequests.spec.ts b/packages/proxy/test/unit/http/util/prerequests.spec.ts index f325e539ecf8..112d65d389b5 100644 --- a/packages/proxy/test/unit/http/util/prerequests.spec.ts +++ b/packages/proxy/test/unit/http/util/prerequests.spec.ts @@ -2,9 +2,12 @@ import { PreRequests } from '@packages/proxy/lib/http/util/prerequests' import { BrowserPreRequest, CypressIncomingRequest } from '@packages/proxy' import { expect } from 'chai' import sinon from 'sinon' +import { performance } from 'perf_hooks' +import { ProtocolManagerShape } from '@packages/types' describe('http/util/prerequests', () => { let preRequests: PreRequests + let protocolManager: ProtocolManagerShape function expectPendingCounts (pendingRequests: number, pendingPreRequests: number) { expect(preRequests.pendingRequests.length).to.eq(pendingRequests, 'wrong number of pending requests') @@ -13,6 +16,11 @@ describe('http/util/prerequests', () => { beforeEach(() => { preRequests = new PreRequests(10) + protocolManager = { + responseStreamTimedOut: sinon.stub(), + } as any + + preRequests.setProtocolManager(protocolManager) }) afterEach(() => { @@ -21,11 +29,40 @@ describe('http/util/prerequests', () => { it('synchronously matches a pre-request that existed at the time of the request', () => { // should match in order - preRequests.addPending({ requestId: '1234', url: 'foo', method: 'WRONGMETHOD' } as BrowserPreRequest) - const secondPreRequest = { requestId: '1234', url: 'foo', method: 'GET' } as BrowserPreRequest + preRequests.addPending({ + requestId: '1234', + url: 'foo', + method: 'WRONGMETHOD', + headers: {}, + resourceType: 'xhr', + originalResourceType: undefined, + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: 2, + }) + + const secondPreRequest: BrowserPreRequest = { + requestId: '1234', + url: 'foo', + method: 'GET', + headers: {}, + resourceType: 'xhr', + originalResourceType: undefined, + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin + 10000, + } preRequests.addPending(secondPreRequest) - preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET' } as BrowserPreRequest) + preRequests.addPending({ + requestId: '1234', + url: 'foo', + method: 'GET', + headers: {}, + resourceType: 'xhr', + originalResourceType: undefined, + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: 2, + }) + expectPendingCounts(0, 3) const cb = sinon.stub() @@ -33,8 +70,19 @@ describe('http/util/prerequests', () => { preRequests.get({ proxiedUrl: 'foo', method: 'GET' } as CypressIncomingRequest, () => {}, cb) const { args } = cb.getCall(0) - - expect(args[0]).to.eq(secondPreRequest) + const arg = args[0] + + expect(arg.requestId).to.eq(secondPreRequest.requestId) + expect(arg.url).to.eq(secondPreRequest.url) + expect(arg.method).to.eq(secondPreRequest.method) + expect(arg.headers).to.deep.eq(secondPreRequest.headers) + expect(arg.resourceType).to.eq(secondPreRequest.resourceType) + expect(arg.originalResourceType).to.eq(secondPreRequest.originalResourceType) + expect(arg.cdpClientSideEventTime).to.eq(secondPreRequest.cdpClientSideEventTime) + expect(arg.cdpServerSideEventReceivedTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime) + expect(arg.proxyReceivedTime).to.be.a('number') + expect(arg.cdpLagTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime - secondPreRequest.cdpClientSideEventTime) + expect(arg.correlationTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime - arg.proxyReceivedTime) expectPendingCounts(0, 2) }) @@ -50,20 +98,52 @@ describe('http/util/prerequests', () => { preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET' } as BrowserPreRequest) }) - it('invokes a request callback after a timeout if no pre-request occurs', (done) => { - const cb = (preRequest) => { - expect(preRequest).to.be.undefined - expectPendingCounts(0, 0) - done() - } + it('invokes a request callback after a timeout if no pre-request occurs', async () => { + let cb + const cbPromise = new Promise((resolve) => { + cb = (preRequest) => { + expect(preRequest).to.be.undefined + + // we should have keep the pending request to eventually be correlated later, but don't block the body in the meantime + expectPendingCounts(1, 0) + + resolve() + } + }) preRequests.get({ proxiedUrl: 'foo', method: 'GET' } as CypressIncomingRequest, () => {}, cb) + + await cbPromise + + const browserPreRequest: BrowserPreRequest = { + requestId: '1234', + url: 'foo', + method: 'GET', + headers: {}, + resourceType: 'xhr', + originalResourceType: undefined, + cdpClientSideEventTime: 1, + cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin + 10000, + } + + preRequests.addPending(browserPreRequest) + + expectPendingCounts(0, 0) + + const arg = (protocolManager.responseStreamTimedOut as any).getCall(0).args[0] + + expect(arg.requestId).to.eq(browserPreRequest.requestId) + expect(arg.timings.cdpClientSideEventTime).to.eq(browserPreRequest.cdpClientSideEventTime) + expect(arg.timings.cdpServerSideEventReceivedTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime) + expect(arg.timings.proxyReceivedTime).to.be.a('number') + expect(arg.timings.cdpLagTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime) + expect(arg.timings.correlationTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime - arg.timings.proxyReceivedTime) }) // https://github.com/cypress-io/cypress/issues/17853 it('eventually discards pre-requests that don\'t match requests', (done) => { preRequests = new PreRequests(10, 200) - preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET' } as BrowserPreRequest) + preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET', cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin } as BrowserPreRequest) // preRequests garbage collects pre-requests that never matched up with an incoming request after around // 2 * requestTimeout. We verify that it's gone (and therefore not leaking memory) by sending in a request @@ -71,7 +151,7 @@ describe('http/util/prerequests', () => { setTimeout(() => { const cb = (preRequest) => { expect(preRequest).to.be.undefined - expectPendingCounts(0, 0) + expectPendingCounts(1, 0) done() } diff --git a/packages/server/lib/browsers/cdp_automation.ts b/packages/server/lib/browsers/cdp_automation.ts index 818e81942140..f466cc663e15 100644 --- a/packages/server/lib/browsers/cdp_automation.ts +++ b/packages/server/lib/browsers/cdp_automation.ts @@ -7,6 +7,7 @@ import type ProtocolMapping from 'devtools-protocol/types/protocol-mapping' import { cors, uri } from '@packages/network' import debugModule from 'debug' import { URL } from 'url' +import { performance } from 'perf_hooks' import type { ResourceType, BrowserPreRequest, BrowserResponseReceived } from '@packages/proxy' import type { CDPClient, ProtocolManagerShape, WriteVideoFrame } from '@packages/types' @@ -237,6 +238,8 @@ export class CdpAutomation implements CDPClient { headers: params.request.headers, resourceType: normalizeResourceType(params.type), originalResourceType: params.type, + cdpClientSideEventTime: params.wallTime * 1000, + cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin, } this.automation.onBrowserPreRequest?.(browserPreRequest) diff --git a/packages/server/lib/cloud/protocol.ts b/packages/server/lib/cloud/protocol.ts index e7bf72d3b0e5..478a5d887207 100644 --- a/packages/server/lib/cloud/protocol.ts +++ b/packages/server/lib/cloud/protocol.ts @@ -13,7 +13,7 @@ import pkg from '@packages/root' import env from '../util/env' import type { Readable } from 'stream' -import type { ProtocolManagerShape, AppCaptureProtocolInterface, CDPClient, ProtocolError, CaptureArtifact, ProtocolErrorReport, ProtocolCaptureMethod, ProtocolManagerOptions, ResponseStreamOptions, ResponseEndedWithEmptyBodyOptions } from '@packages/types' +import type { ProtocolManagerShape, AppCaptureProtocolInterface, CDPClient, ProtocolError, CaptureArtifact, ProtocolErrorReport, ProtocolCaptureMethod, ProtocolManagerOptions, ResponseStreamOptions, ResponseEndedWithEmptyBodyOptions, ResponseStreamTimedOutOptions } from '@packages/types' const routes = require('./routes') @@ -223,6 +223,10 @@ export class ProtocolManager implements ProtocolManagerShape { return this.invokeSync('responseStreamReceived', { isEssential: false }, options) } + responseStreamTimedOut (options: ResponseStreamTimedOutOptions): void { + this.invokeSync('responseStreamTimedOut', { isEssential: false }, options) + } + canUpload (): boolean { return !!this._protocol && !!this._archivePath && !!this._db } diff --git a/packages/server/test/unit/browsers/cdp_automation_spec.ts b/packages/server/test/unit/browsers/cdp_automation_spec.ts index 9021b9b63d92..741d42e627df 100644 --- a/packages/server/test/unit/browsers/cdp_automation_spec.ts +++ b/packages/server/test/unit/browsers/cdp_automation_spec.ts @@ -109,20 +109,23 @@ context('lib/browsers/cdp_automation', () => { url: 'https://www.google.com', headers: {}, }, + wallTime: 100.100100, } this.onFn .withArgs('Network.requestWillBeSent') .yield(browserPreRequest) - expect(this.automation.onBrowserPreRequest).to.have.been.calledWith({ - requestId: browserPreRequest.requestId, - method: browserPreRequest.request.method, - url: browserPreRequest.request.url, - headers: browserPreRequest.request.headers, - resourceType: browserPreRequest.type, - originalResourceType: browserPreRequest.type, - }) + const arg = this.automation.onBrowserPreRequest.getCall(0).args[0] + + expect(arg.requestId).to.eq(browserPreRequest.requestId) + expect(arg.method).to.eq(browserPreRequest.request.method) + expect(arg.url).to.eq(browserPreRequest.request.url) + expect(arg.headers).to.eq(browserPreRequest.request.headers) + expect(arg.resourceType).to.eq(browserPreRequest.type) + expect(arg.originalResourceType).to.eq(browserPreRequest.type) + expect(arg.cdpClientSideEventTime).to.eq(100100.100) + expect(arg.cdpServerSideEventReceivedTime).to.be.a('number') }) it('removes # from a url', function () { @@ -134,20 +137,23 @@ context('lib/browsers/cdp_automation', () => { url: 'https://www.google.com/foo#', headers: {}, }, + wallTime: 100.100100, } this.onFn .withArgs('Network.requestWillBeSent') .yield(browserPreRequest) - expect(this.automation.onBrowserPreRequest).to.have.been.calledWith({ - requestId: browserPreRequest.requestId, - method: browserPreRequest.request.method, - url: 'https://www.google.com/foo', // we only care about the url - headers: browserPreRequest.request.headers, - resourceType: browserPreRequest.type, - originalResourceType: browserPreRequest.type, - }) + const arg = this.automation.onBrowserPreRequest.getCall(0).args[0] + + expect(arg.requestId).to.eq(browserPreRequest.requestId) + expect(arg.method).to.eq(browserPreRequest.request.method) + expect(arg.url).to.eq('https://www.google.com/foo') + expect(arg.headers).to.eq(browserPreRequest.request.headers) + expect(arg.resourceType).to.eq(browserPreRequest.type) + expect(arg.originalResourceType).to.eq(browserPreRequest.type) + expect(arg.cdpClientSideEventTime).to.eq(100100.100) + expect(arg.cdpServerSideEventReceivedTime).to.be.a('number') }) it('ignore events with data urls', function () { diff --git a/packages/types/src/protocol.ts b/packages/types/src/protocol.ts index d3247c82d637..255c7d87fc49 100644 --- a/packages/types/src/protocol.ts +++ b/packages/types/src/protocol.ts @@ -2,6 +2,7 @@ import type { Database } from 'better-sqlite3' import type ProtocolMapping from 'devtools-protocol/types/protocol-mapping' import type { IncomingHttpHeaders } from 'http' import type { Readable } from 'stream' +import type { ProxyTimings } from '@packages/proxy' type Commands = ProtocolMapping.Commands type Command = Commands[T] @@ -31,6 +32,7 @@ export interface AppCaptureProtocolCommon { resetTest (testId: string): void responseEndedWithEmptyBody: (options: ResponseEndedWithEmptyBodyOptions) => void responseStreamReceived (options: ResponseStreamOptions): Readable | undefined + responseStreamTimedOut (options: ResponseStreamTimedOutOptions): void } export interface AppCaptureProtocolInterface extends AppCaptureProtocolCommon { @@ -97,6 +99,7 @@ type Response = { export type ResponseEndedWithEmptyBodyOptions = { requestId: string isCached: boolean + timings: ProxyTimings } export type ResponseStreamOptions = { @@ -105,4 +108,10 @@ export type ResponseStreamOptions = { isAlreadyGunzipped: boolean responseStream: Readable res: Response + timings: ProxyTimings +} + +export type ResponseStreamTimedOutOptions = { + requestId: string + timings: ProxyTimings } diff --git a/system-tests/__snapshots__/protocol_spec.js b/system-tests/__snapshots__/protocol_spec.js index dd54a9389164..da115420d1a8 100644 --- a/system-tests/__snapshots__/protocol_spec.js +++ b/system-tests/__snapshots__/protocol_spec.js @@ -4923,7 +4923,8 @@ exports['e2e events'] = ` "resetTest": [ "r3" ], - "responseEndedWithEmptyBody": [] + "responseEndedWithEmptyBody": [], + "responseStreamTimedOut": [] } ` @@ -6531,37 +6532,94 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "responseEndedWithEmptyBody": [ { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } } - ] + ], + "responseStreamTimedOut": [] } ` @@ -8169,20 +8227,49 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "responseEndedWithEmptyBody": [ { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } }, { "requestId": "Any.Number", - "isCached": true + "isCached": true, + "timings": { + "cdpClientSideEventTime": "Any.Number", + "cdpServerSideEventReceivedTime": "Any.Number", + "proxyReceivedTime": "Any.Number", + "cdpLagTime": "Any.Number", + "correlationTime": "Any.Number" + } } - ] + ], + "responseStreamTimedOut": [] } ` diff --git a/system-tests/lib/protocol-stubs/protocolStub.ts b/system-tests/lib/protocol-stubs/protocolStub.ts index 3cdca28a2ac4..c0b1b3a95323 100644 --- a/system-tests/lib/protocol-stubs/protocolStub.ts +++ b/system-tests/lib/protocol-stubs/protocolStub.ts @@ -1,6 +1,6 @@ import path from 'path' import fs from 'fs-extra' -import type { AppCaptureProtocolInterface, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions } from '@packages/types' +import type { AppCaptureProtocolInterface, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions, ResponseStreamTimedOutOptions } from '@packages/types' import type { Readable } from 'stream' const getFilePath = (filename) => { @@ -29,6 +29,7 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { pageLoading: [], resetTest: [], responseEndedWithEmptyBody: [], + responseStreamTimedOut: [], } private cdpClient: any private scriptToEvaluateId: any @@ -54,6 +55,7 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { this.events.urlChanged = [] this.events.pageLoading = [] this.events.responseEndedWithEmptyBody = [] + this.events.responseStreamTimedOut = [] } connectToBrowser = async (cdpClient) => { @@ -159,6 +161,10 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { this.events.responseEndedWithEmptyBody.push(options) } + responseStreamTimedOut (options: ResponseStreamTimedOutOptions): void { + this.events.responseStreamTimedOut.push(options) + } + resetTest (testId: string): void { this.resetEvents() diff --git a/system-tests/lib/protocol-stubs/protocolStubWithBeforeSpecError.ts b/system-tests/lib/protocol-stubs/protocolStubWithBeforeSpecError.ts index 4826cf33e0ea..3281e114cd0c 100644 --- a/system-tests/lib/protocol-stubs/protocolStubWithBeforeSpecError.ts +++ b/system-tests/lib/protocol-stubs/protocolStubWithBeforeSpecError.ts @@ -1,4 +1,4 @@ -import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions } from '@packages/types' +import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions, ResponseStreamTimedOutOptions } from '@packages/types' import type { Readable } from 'stream' export class AppCaptureProtocol implements AppCaptureProtocolInterface { @@ -37,4 +37,5 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { pageLoading (input: any): void {} resetTest (testId: string): void {} responseEndedWithEmptyBody: (options: ResponseEndedWithEmptyBodyOptions) => {} + responseStreamTimedOut: (options: ResponseStreamTimedOutOptions) => {} } diff --git a/system-tests/lib/protocol-stubs/protocolStubWithBeforeTestError.ts b/system-tests/lib/protocol-stubs/protocolStubWithBeforeTestError.ts index d4b120eb0e5e..b9a36e943b76 100644 --- a/system-tests/lib/protocol-stubs/protocolStubWithBeforeTestError.ts +++ b/system-tests/lib/protocol-stubs/protocolStubWithBeforeTestError.ts @@ -1,4 +1,4 @@ -import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions } from '@packages/types' +import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions, ResponseStreamTimedOutOptions } from '@packages/types' import type { Readable } from 'stream' export class AppCaptureProtocol implements AppCaptureProtocolInterface { @@ -45,4 +45,5 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { responseEndedWithEmptyBody (options: ResponseEndedWithEmptyBodyOptions) { //throw new Error('error in responseEndedWithEmptyBody') } + responseStreamTimedOut: (options: ResponseStreamTimedOutOptions) => {} } diff --git a/system-tests/lib/protocol-stubs/protocolStubWithNonFatalError.ts b/system-tests/lib/protocol-stubs/protocolStubWithNonFatalError.ts index b0c641c0f55a..b0c809100066 100644 --- a/system-tests/lib/protocol-stubs/protocolStubWithNonFatalError.ts +++ b/system-tests/lib/protocol-stubs/protocolStubWithNonFatalError.ts @@ -1,4 +1,4 @@ -import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions } from '@packages/types' +import type { AppCaptureProtocolInterface, CDPClient, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions, ResponseStreamTimedOutOptions } from '@packages/types' import type { Readable } from 'stream' export class AppCaptureProtocol implements AppCaptureProtocolInterface { @@ -37,4 +37,5 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { pageLoading (input: any): void {} resetTest (testId: string): void {} responseEndedWithEmptyBody: (options: ResponseEndedWithEmptyBodyOptions) => {} + responseStreamTimedOut: (options: ResponseStreamTimedOutOptions) => {} } diff --git a/system-tests/lib/protocol-stubs/protocolStubWithRuntimeError.ts b/system-tests/lib/protocol-stubs/protocolStubWithRuntimeError.ts index 57be916d6800..2bbb432b2fb0 100644 --- a/system-tests/lib/protocol-stubs/protocolStubWithRuntimeError.ts +++ b/system-tests/lib/protocol-stubs/protocolStubWithRuntimeError.ts @@ -1,4 +1,4 @@ -import type { AppCaptureProtocolInterface, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions } from '@packages/types' +import type { AppCaptureProtocolInterface, ResponseEndedWithEmptyBodyOptions, ResponseStreamOptions, ResponseStreamTimedOutOptions } from '@packages/types' import type { Readable } from 'stream' export class AppCaptureProtocol implements AppCaptureProtocolInterface { @@ -39,4 +39,5 @@ export class AppCaptureProtocol implements AppCaptureProtocolInterface { return Promise.resolve() } responseEndedWithEmptyBody: (options: ResponseEndedWithEmptyBodyOptions) => {} + responseStreamTimedOut: (options: ResponseStreamTimedOutOptions) => {} } diff --git a/system-tests/test/protocol_spec.js b/system-tests/test/protocol_spec.js index 9e89523dbc67..a1d9ec3ddfb7 100644 --- a/system-tests/test/protocol_spec.js +++ b/system-tests/test/protocol_spec.js @@ -10,7 +10,7 @@ const { // source: https://www.myintervals.com/blog/2009/05/20/iso-8601-date-validation-that-doesnt-suck/ const isoDateRegex = /"([\+-]?\d{4}(?!\d{2}\b))((-?)((0[1-9]|1[0-2])(\3([12]\d|0[1-9]|3[01]))?|W([0-4]\d|5[0-2])(-?[1-7])?|(00[1-9]|0[1-9]\d|[12]\d{2}|3([0-5]\d|6[1-6])))([T\s]((([01]\d|2[0-3])((:?)[0-5]\d)?|24\:?00)([\.,]\d+(?!:))?)?(\17[0-5]\d([\.,]\d+)?)?([zZ]|([\+-])([01]\d|2[0-3]):?([0-5]\d)?)?)?)?"/g -const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g +const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId|cdpClientSideEventTime|cdpServerSideEventReceivedTime|proxyReceivedTime|cdpLagTime|correlationTime)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g const pathRegex = /"(name|absoluteFile)": "\/[^"]+"/g const componentSpecPathRegex = /"(url|message)": "(http:\/\/localhost:2121\/__cypress\/iframes\/index.html\?specPath=)(.*)(\/protocol\/src\/components\/)(.*)"/g From 057e693f4171ed3b20abcf09f9cbad7a560ed9c0 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Wed, 4 Oct 2023 14:02:46 -0500 Subject: [PATCH 02/15] rename --- .../proxy/lib/http/response-middleware.ts | 20 +-- packages/proxy/lib/http/util/prerequests.ts | 48 +++---- packages/proxy/lib/types.ts | 14 +- .../unit/http/response-middleware.spec.ts | 40 +++--- .../test/unit/http/util/prerequests.spec.ts | 38 +++--- .../server/lib/browsers/cdp_automation.ts | 4 +- .../test/unit/browsers/cdp_automation_spec.ts | 8 +- system-tests/__snapshots__/protocol_spec.js | 120 +++++++++--------- system-tests/test/protocol_spec.js | 2 +- 9 files changed, 147 insertions(+), 147 deletions(-) diff --git a/packages/proxy/lib/http/response-middleware.ts b/packages/proxy/lib/http/response-middleware.ts index 7077e51fc04d..65ea33d3b61a 100644 --- a/packages/proxy/lib/http/response-middleware.ts +++ b/packages/proxy/lib/http/response-middleware.ts @@ -692,11 +692,11 @@ const MaybeEndWithEmptyBody: ResponseMiddleware = function () { requestId, isCached: this.incomingRes.statusCode === 304, timings: { - cdpClientSideEventTime: this.req.browserPreRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: this.req.browserPreRequest.cdpServerSideEventReceivedTime, - proxyReceivedTime: this.req.browserPreRequest.proxyReceivedTime, - cdpLagTime: this.req.browserPreRequest.cdpLagTime, - correlationTime: this.req.browserPreRequest.correlationTime, + cdpRequestWillBeSentTimestamp: this.req.browserPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: this.req.browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp: this.req.browserPreRequest.proxyRequestReceivedTimestamp, + cdpLagTimestamp: this.req.browserPreRequest.cdpLagTimestamp, + proxyRequestCorrelationTimestamp: this.req.browserPreRequest.proxyRequestCorrelationTimestamp, }, }) } @@ -816,11 +816,11 @@ const GzipBody: ResponseMiddleware = async function () { responseStream: this.incomingResStream, res: this.res, timings: { - cdpClientSideEventTime: preRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: preRequest.cdpServerSideEventReceivedTime, - proxyReceivedTime: preRequest.proxyReceivedTime, - cdpLagTime: preRequest.cdpLagTime, - correlationTime: preRequest.correlationTime, + cdpRequestWillBeSentTimestamp: preRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: preRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp: preRequest.proxyRequestReceivedTimestamp, + cdpLagTimestamp: preRequest.cdpLagTimestamp, + proxyRequestCorrelationTimestamp: preRequest.proxyRequestCorrelationTimestamp, }, }) diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 9f982d8795e0..6240b641f5be 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -28,13 +28,13 @@ type PendingRequest = { callback: GetPreRequestCb timeout: NodeJS.Timeout timedOut?: boolean - proxyReceivedTime: number + proxyRequestReceivedTimestamp: number } type PendingPreRequest = { browserPreRequest: BrowserPreRequest - cdpClientSideEventTime: number - cdpServerSideEventReceivedTime: number + cdpRequestWillBeSentTimestamp: number + cdpRequestWillBeSentReceivedTimestamp: number } /** @@ -109,8 +109,8 @@ export class PreRequests { this.sweepIntervalTimer = setInterval(() => { const now = Date.now() - this.pendingPreRequests.removeMatching(({ cdpServerSideEventReceivedTime, browserPreRequest }) => { - if (cdpServerSideEventReceivedTime + this.sweepInterval < now) { + this.pendingPreRequests.removeMatching(({ cdpRequestWillBeSentReceivedTimestamp, browserPreRequest }) => { + if (cdpRequestWillBeSentReceivedTimestamp + this.sweepInterval < now) { debugVerbose('timed out unmatched pre-request: %o', browserPreRequest) metrics.unmatchedPreRequests++ @@ -133,11 +133,11 @@ export class PreRequests { clearTimeout(pendingRequest.timeout) pendingRequest.callback({ ...browserPreRequest, - cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, - proxyReceivedTime: pendingRequest.proxyReceivedTime, - cdpLagTime: browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime, - correlationTime: Math.max(browserPreRequest.cdpServerSideEventReceivedTime - pendingRequest.proxyReceivedTime, 0), + cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, + cdpLagTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationTimestamp: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), }) return @@ -146,11 +146,11 @@ export class PreRequests { this.protocolManager?.responseStreamTimedOut({ requestId: browserPreRequest.requestId, timings: { - cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, - proxyReceivedTime: pendingRequest.proxyReceivedTime, - cdpLagTime: browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime, - correlationTime: Math.max(browserPreRequest.cdpServerSideEventReceivedTime - pendingRequest.proxyReceivedTime, 0), + cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, + cdpLagTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationTimestamp: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), }, }) @@ -160,8 +160,8 @@ export class PreRequests { debugVerbose('Caching pre-request %s to be matched later. %o', key, browserPreRequest) this.pendingPreRequests.push(key, { browserPreRequest, - cdpClientSideEventTime: browserPreRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: browserPreRequest.cdpServerSideEventReceivedTime, + cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, }) } @@ -172,7 +172,7 @@ export class PreRequests { } get (req: CypressIncomingRequest, ctxDebug, callback: GetPreRequestCb) { - const proxyReceivedTime = performance.now() + performance.timeOrigin + const proxyRequestReceivedTimestamp = performance.now() + performance.timeOrigin metrics.proxyRequestsReceived++ const key = `${req.method}-${req.proxiedUrl}` @@ -183,11 +183,11 @@ export class PreRequests { ctxDebug('Incoming request %s matches known pre-request: %o', key, pendingPreRequest) callback({ ...pendingPreRequest.browserPreRequest, - cdpClientSideEventTime: pendingPreRequest.cdpClientSideEventTime, - cdpServerSideEventReceivedTime: pendingPreRequest.cdpServerSideEventReceivedTime, - proxyReceivedTime, - cdpLagTime: pendingPreRequest.cdpServerSideEventReceivedTime - pendingPreRequest.cdpClientSideEventTime, - correlationTime: Math.max(pendingPreRequest.cdpServerSideEventReceivedTime - proxyReceivedTime, 0), + cdpRequestWillBeSentTimestamp: pendingPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp, + cdpLagTimestamp: pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationTimestamp: Math.max(pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - proxyRequestReceivedTimestamp, 0), }) return @@ -196,7 +196,7 @@ export class PreRequests { const pendingRequest: PendingRequest = { ctxDebug, callback, - proxyReceivedTime: performance.now() + performance.timeOrigin, + proxyRequestReceivedTimestamp: performance.now() + performance.timeOrigin, timeout: setTimeout(() => { ctxDebug('Never received pre-request for request %s after waiting %sms. Continuing without one.', key, this.requestTimeout) metrics.unmatchedRequests++ diff --git a/packages/proxy/lib/types.ts b/packages/proxy/lib/types.ts index 936b1b6c7aa9..0a90b7183dd8 100644 --- a/packages/proxy/lib/types.ts +++ b/packages/proxy/lib/types.ts @@ -60,16 +60,16 @@ export type BrowserPreRequest = { resourceType: ResourceType originalResourceType: string | undefined errorHandled?: boolean - cdpClientSideEventTime: number - cdpServerSideEventReceivedTime: number + cdpRequestWillBeSentTimestamp: number + cdpRequestWillBeSentReceivedTimestamp: number } export type ProxyTimings = { - cdpClientSideEventTime: number - cdpServerSideEventReceivedTime: number - proxyReceivedTime: number - cdpLagTime: number - correlationTime: number + cdpRequestWillBeSentTimestamp: number + cdpRequestWillBeSentReceivedTimestamp: number + proxyRequestReceivedTimestamp: number + cdpLagTimestamp: number + proxyRequestCorrelationTimestamp: number } export type BrowserPreRequestWithTimings = BrowserPreRequest & ProxyTimings diff --git a/packages/proxy/test/unit/http/response-middleware.spec.ts b/packages/proxy/test/unit/http/response-middleware.spec.ts index f2ac7c060324..5d81d63d154f 100644 --- a/packages/proxy/test/unit/http/response-middleware.spec.ts +++ b/packages/proxy/test/unit/http/response-middleware.spec.ts @@ -1827,11 +1827,11 @@ describe('http/response-middleware', function () { req: { browserPreRequest: { requestId: '123', - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: 2, - proxyReceivedTime: 3, - cdpLagTime: 4, - correlationTime: 5, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: 2, + proxyRequestReceivedTimestamp: 3, + cdpLagTimestamp: 4, + proxyRequestCorrelationTimestamp: 5, }, }, incomingRes: { @@ -1845,11 +1845,11 @@ describe('http/response-middleware', function () { sinon.match(function (actual) { expect(actual.requestId).to.equal('123') expect(actual.isCached).to.equal(true) - expect(actual.timings.cdpClientSideEventTime).to.equal(1) - expect(actual.timings.cdpServerSideEventReceivedTime).to.equal(2) - expect(actual.timings.proxyReceivedTime).to.equal(3) - expect(actual.timings.cdpLagTime).to.equal(4) - expect(actual.timings.correlationTime).to.equal(5) + expect(actual.timings.cdpRequestWillBeSentTimestamp).to.equal(1) + expect(actual.timings.cdpRequestWillBeSentReceivedTimestamp).to.equal(2) + expect(actual.timings.proxyRequestReceivedTimestamp).to.equal(3) + expect(actual.timings.cdpLagTimestamp).to.equal(4) + expect(actual.timings.proxyRequestCorrelationTimestamp).to.equal(5) return true }), @@ -2269,11 +2269,11 @@ describe('http/response-middleware', function () { req: { browserPreRequest: { requestId: '123', - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: 2, - proxyReceivedTime: 3, - cdpLagTime: 4, - correlationTime: 5, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: 2, + proxyRequestReceivedTimestamp: 3, + cdpLagTimestamp: 4, + proxyRequestCorrelationTimestamp: 5, }, }, res, @@ -2293,11 +2293,11 @@ describe('http/response-middleware', function () { expect(actual.isAlreadyGunzipped).to.equal(true) expect(actual.responseStream).to.equal(stream) expect(actual.res).to.equal(res) - expect(actual.timings.cdpClientSideEventTime).to.equal(1) - expect(actual.timings.cdpServerSideEventReceivedTime).to.equal(2) - expect(actual.timings.proxyReceivedTime).to.equal(3) - expect(actual.timings.cdpLagTime).to.equal(4) - expect(actual.timings.correlationTime).to.equal(5) + expect(actual.timings.cdpRequestWillBeSentTimestamp).to.equal(1) + expect(actual.timings.cdpRequestWillBeSentReceivedTimestamp).to.equal(2) + expect(actual.timings.proxyRequestReceivedTimestamp).to.equal(3) + expect(actual.timings.cdpLagTimestamp).to.equal(4) + expect(actual.timings.proxyRequestCorrelationTimestamp).to.equal(5) return true }), diff --git a/packages/proxy/test/unit/http/util/prerequests.spec.ts b/packages/proxy/test/unit/http/util/prerequests.spec.ts index 112d65d389b5..f757bcd66107 100644 --- a/packages/proxy/test/unit/http/util/prerequests.spec.ts +++ b/packages/proxy/test/unit/http/util/prerequests.spec.ts @@ -36,8 +36,8 @@ describe('http/util/prerequests', () => { headers: {}, resourceType: 'xhr', originalResourceType: undefined, - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: 2, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: 2, }) const secondPreRequest: BrowserPreRequest = { @@ -47,8 +47,8 @@ describe('http/util/prerequests', () => { headers: {}, resourceType: 'xhr', originalResourceType: undefined, - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin + 10000, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin + 10000, } preRequests.addPending(secondPreRequest) @@ -59,8 +59,8 @@ describe('http/util/prerequests', () => { headers: {}, resourceType: 'xhr', originalResourceType: undefined, - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: 2, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: 2, }) expectPendingCounts(0, 3) @@ -78,11 +78,11 @@ describe('http/util/prerequests', () => { expect(arg.headers).to.deep.eq(secondPreRequest.headers) expect(arg.resourceType).to.eq(secondPreRequest.resourceType) expect(arg.originalResourceType).to.eq(secondPreRequest.originalResourceType) - expect(arg.cdpClientSideEventTime).to.eq(secondPreRequest.cdpClientSideEventTime) - expect(arg.cdpServerSideEventReceivedTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime) - expect(arg.proxyReceivedTime).to.be.a('number') - expect(arg.cdpLagTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime - secondPreRequest.cdpClientSideEventTime) - expect(arg.correlationTime).to.eq(secondPreRequest.cdpServerSideEventReceivedTime - arg.proxyReceivedTime) + expect(arg.cdpRequestWillBeSentTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp) + expect(arg.proxyRequestReceivedTimestamp).to.be.a('number') + expect(arg.cdpLagTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - secondPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.proxyRequestCorrelationTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.proxyRequestReceivedTimestamp) expectPendingCounts(0, 2) }) @@ -122,8 +122,8 @@ describe('http/util/prerequests', () => { headers: {}, resourceType: 'xhr', originalResourceType: undefined, - cdpClientSideEventTime: 1, - cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin + 10000, + cdpRequestWillBeSentTimestamp: 1, + cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin + 10000, } preRequests.addPending(browserPreRequest) @@ -133,17 +133,17 @@ describe('http/util/prerequests', () => { const arg = (protocolManager.responseStreamTimedOut as any).getCall(0).args[0] expect(arg.requestId).to.eq(browserPreRequest.requestId) - expect(arg.timings.cdpClientSideEventTime).to.eq(browserPreRequest.cdpClientSideEventTime) - expect(arg.timings.cdpServerSideEventReceivedTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime) - expect(arg.timings.proxyReceivedTime).to.be.a('number') - expect(arg.timings.cdpLagTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime - browserPreRequest.cdpClientSideEventTime) - expect(arg.timings.correlationTime).to.eq(browserPreRequest.cdpServerSideEventReceivedTime - arg.timings.proxyReceivedTime) + expect(arg.timings.cdpRequestWillBeSentTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.timings.cdpRequestWillBeSentReceivedTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp) + expect(arg.timings.proxyRequestReceivedTimestamp).to.be.a('number') + expect(arg.timings.cdpLagTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.timings.proxyRequestCorrelationTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.timings.proxyRequestReceivedTimestamp) }) // https://github.com/cypress-io/cypress/issues/17853 it('eventually discards pre-requests that don\'t match requests', (done) => { preRequests = new PreRequests(10, 200) - preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET', cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin } as BrowserPreRequest) + preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET', cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin } as BrowserPreRequest) // preRequests garbage collects pre-requests that never matched up with an incoming request after around // 2 * requestTimeout. We verify that it's gone (and therefore not leaking memory) by sending in a request diff --git a/packages/server/lib/browsers/cdp_automation.ts b/packages/server/lib/browsers/cdp_automation.ts index f466cc663e15..7a2f67ac0f27 100644 --- a/packages/server/lib/browsers/cdp_automation.ts +++ b/packages/server/lib/browsers/cdp_automation.ts @@ -238,8 +238,8 @@ export class CdpAutomation implements CDPClient { headers: params.request.headers, resourceType: normalizeResourceType(params.type), originalResourceType: params.type, - cdpClientSideEventTime: params.wallTime * 1000, - cdpServerSideEventReceivedTime: performance.now() + performance.timeOrigin, + cdpRequestWillBeSentTimestamp: params.wallTime * 1000, + cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin, } this.automation.onBrowserPreRequest?.(browserPreRequest) diff --git a/packages/server/test/unit/browsers/cdp_automation_spec.ts b/packages/server/test/unit/browsers/cdp_automation_spec.ts index 741d42e627df..45a99b99a2cb 100644 --- a/packages/server/test/unit/browsers/cdp_automation_spec.ts +++ b/packages/server/test/unit/browsers/cdp_automation_spec.ts @@ -124,8 +124,8 @@ context('lib/browsers/cdp_automation', () => { expect(arg.headers).to.eq(browserPreRequest.request.headers) expect(arg.resourceType).to.eq(browserPreRequest.type) expect(arg.originalResourceType).to.eq(browserPreRequest.type) - expect(arg.cdpClientSideEventTime).to.eq(100100.100) - expect(arg.cdpServerSideEventReceivedTime).to.be.a('number') + expect(arg.cdpRequestWillBeSentTimestamp).to.eq(100100.100) + expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.be.a('number') }) it('removes # from a url', function () { @@ -152,8 +152,8 @@ context('lib/browsers/cdp_automation', () => { expect(arg.headers).to.eq(browserPreRequest.request.headers) expect(arg.resourceType).to.eq(browserPreRequest.type) expect(arg.originalResourceType).to.eq(browserPreRequest.type) - expect(arg.cdpClientSideEventTime).to.eq(100100.100) - expect(arg.cdpServerSideEventReceivedTime).to.be.a('number') + expect(arg.cdpRequestWillBeSentTimestamp).to.eq(100100.100) + expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.be.a('number') }) it('ignore events with data urls', function () { diff --git a/system-tests/__snapshots__/protocol_spec.js b/system-tests/__snapshots__/protocol_spec.js index da115420d1a8..a607fef8e410 100644 --- a/system-tests/__snapshots__/protocol_spec.js +++ b/system-tests/__snapshots__/protocol_spec.js @@ -6534,88 +6534,88 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } } ], @@ -8229,44 +8229,44 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } }, { "requestId": "Any.Number", "isCached": true, "timings": { - "cdpClientSideEventTime": "Any.Number", - "cdpServerSideEventReceivedTime": "Any.Number", - "proxyReceivedTime": "Any.Number", - "cdpLagTime": "Any.Number", - "correlationTime": "Any.Number" + "cdpRequestWillBeSentTimestamp": "Any.Number", + "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", + "proxyRequestReceivedTimestamp": "Any.Number", + "cdpLagTimestamp": "Any.Number", + "proxyRequestCorrelationTimestamp": "Any.Number" } } ], diff --git a/system-tests/test/protocol_spec.js b/system-tests/test/protocol_spec.js index a1d9ec3ddfb7..e2a2fd54ca2f 100644 --- a/system-tests/test/protocol_spec.js +++ b/system-tests/test/protocol_spec.js @@ -10,7 +10,7 @@ const { // source: https://www.myintervals.com/blog/2009/05/20/iso-8601-date-validation-that-doesnt-suck/ const isoDateRegex = /"([\+-]?\d{4}(?!\d{2}\b))((-?)((0[1-9]|1[0-2])(\3([12]\d|0[1-9]|3[01]))?|W([0-4]\d|5[0-2])(-?[1-7])?|(00[1-9]|0[1-9]\d|[12]\d{2}|3([0-5]\d|6[1-6])))([T\s]((([01]\d|2[0-3])((:?)[0-5]\d)?|24\:?00)([\.,]\d+(?!:))?)?(\17[0-5]\d([\.,]\d+)?)?([zZ]|([\+-])([01]\d|2[0-3]):?([0-5]\d)?)?)?)?"/g -const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId|cdpClientSideEventTime|cdpServerSideEventReceivedTime|proxyReceivedTime|cdpLagTime|correlationTime)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g +const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId|cdpRequestWillBeSentTimestamp|cdpRequestWillBeSentReceivedTimestamp|proxyRequestReceivedTimestamp|cdpLagTimestamp|proxyRequestCorrelationTimestamp)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g const pathRegex = /"(name|absoluteFile)": "\/[^"]+"/g const componentSpecPathRegex = /"(url|message)": "(http:\/\/localhost:2121\/__cypress\/iframes\/index.html\?specPath=)(.*)(\/protocol\/src\/components\/)(.*)"/g From 3ceac4c839ed4e4f5bf9431d220c590d8fc46bc0 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Wed, 4 Oct 2023 15:09:36 -0500 Subject: [PATCH 03/15] rename --- .../proxy/lib/http/response-middleware.ts | 8 ++-- packages/proxy/lib/http/util/prerequests.ts | 12 ++--- packages/proxy/lib/types.ts | 4 +- .../unit/http/response-middleware.spec.ts | 16 +++---- .../test/unit/http/util/prerequests.spec.ts | 8 ++-- system-tests/__snapshots__/protocol_spec.js | 48 +++++++++---------- system-tests/test/protocol_spec.js | 2 +- 7 files changed, 49 insertions(+), 49 deletions(-) diff --git a/packages/proxy/lib/http/response-middleware.ts b/packages/proxy/lib/http/response-middleware.ts index 65ea33d3b61a..c1e534ceaa14 100644 --- a/packages/proxy/lib/http/response-middleware.ts +++ b/packages/proxy/lib/http/response-middleware.ts @@ -695,8 +695,8 @@ const MaybeEndWithEmptyBody: ResponseMiddleware = function () { cdpRequestWillBeSentTimestamp: this.req.browserPreRequest.cdpRequestWillBeSentTimestamp, cdpRequestWillBeSentReceivedTimestamp: this.req.browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, proxyRequestReceivedTimestamp: this.req.browserPreRequest.proxyRequestReceivedTimestamp, - cdpLagTimestamp: this.req.browserPreRequest.cdpLagTimestamp, - proxyRequestCorrelationTimestamp: this.req.browserPreRequest.proxyRequestCorrelationTimestamp, + cdpLagDuration: this.req.browserPreRequest.cdpLagDuration, + proxyRequestCorrelationDuration: this.req.browserPreRequest.proxyRequestCorrelationDuration, }, }) } @@ -819,8 +819,8 @@ const GzipBody: ResponseMiddleware = async function () { cdpRequestWillBeSentTimestamp: preRequest.cdpRequestWillBeSentTimestamp, cdpRequestWillBeSentReceivedTimestamp: preRequest.cdpRequestWillBeSentReceivedTimestamp, proxyRequestReceivedTimestamp: preRequest.proxyRequestReceivedTimestamp, - cdpLagTimestamp: preRequest.cdpLagTimestamp, - proxyRequestCorrelationTimestamp: preRequest.proxyRequestCorrelationTimestamp, + cdpLagDuration: preRequest.cdpLagDuration, + proxyRequestCorrelationDuration: preRequest.proxyRequestCorrelationDuration, }, }) diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 6240b641f5be..0761432f1799 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -136,8 +136,8 @@ export class PreRequests { cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, - cdpLagTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, - proxyRequestCorrelationTimestamp: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), + cdpLagDuration: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationDuration: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), }) return @@ -149,8 +149,8 @@ export class PreRequests { cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, - cdpLagTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, - proxyRequestCorrelationTimestamp: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), + cdpLagDuration: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationDuration: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), }, }) @@ -186,8 +186,8 @@ export class PreRequests { cdpRequestWillBeSentTimestamp: pendingPreRequest.cdpRequestWillBeSentTimestamp, cdpRequestWillBeSentReceivedTimestamp: pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp, proxyRequestReceivedTimestamp, - cdpLagTimestamp: pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingPreRequest.cdpRequestWillBeSentTimestamp, - proxyRequestCorrelationTimestamp: Math.max(pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - proxyRequestReceivedTimestamp, 0), + cdpLagDuration: pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationDuration: Math.max(pendingPreRequest.cdpRequestWillBeSentReceivedTimestamp - proxyRequestReceivedTimestamp, 0), }) return diff --git a/packages/proxy/lib/types.ts b/packages/proxy/lib/types.ts index 0a90b7183dd8..f23badaf71f0 100644 --- a/packages/proxy/lib/types.ts +++ b/packages/proxy/lib/types.ts @@ -68,8 +68,8 @@ export type ProxyTimings = { cdpRequestWillBeSentTimestamp: number cdpRequestWillBeSentReceivedTimestamp: number proxyRequestReceivedTimestamp: number - cdpLagTimestamp: number - proxyRequestCorrelationTimestamp: number + cdpLagDuration: number + proxyRequestCorrelationDuration: number } export type BrowserPreRequestWithTimings = BrowserPreRequest & ProxyTimings diff --git a/packages/proxy/test/unit/http/response-middleware.spec.ts b/packages/proxy/test/unit/http/response-middleware.spec.ts index 5d81d63d154f..6adfa1ba472c 100644 --- a/packages/proxy/test/unit/http/response-middleware.spec.ts +++ b/packages/proxy/test/unit/http/response-middleware.spec.ts @@ -1830,8 +1830,8 @@ describe('http/response-middleware', function () { cdpRequestWillBeSentTimestamp: 1, cdpRequestWillBeSentReceivedTimestamp: 2, proxyRequestReceivedTimestamp: 3, - cdpLagTimestamp: 4, - proxyRequestCorrelationTimestamp: 5, + cdpLagDuration: 4, + proxyRequestCorrelationDuration: 5, }, }, incomingRes: { @@ -1848,8 +1848,8 @@ describe('http/response-middleware', function () { expect(actual.timings.cdpRequestWillBeSentTimestamp).to.equal(1) expect(actual.timings.cdpRequestWillBeSentReceivedTimestamp).to.equal(2) expect(actual.timings.proxyRequestReceivedTimestamp).to.equal(3) - expect(actual.timings.cdpLagTimestamp).to.equal(4) - expect(actual.timings.proxyRequestCorrelationTimestamp).to.equal(5) + expect(actual.timings.cdpLagDuration).to.equal(4) + expect(actual.timings.proxyRequestCorrelationDuration).to.equal(5) return true }), @@ -2272,8 +2272,8 @@ describe('http/response-middleware', function () { cdpRequestWillBeSentTimestamp: 1, cdpRequestWillBeSentReceivedTimestamp: 2, proxyRequestReceivedTimestamp: 3, - cdpLagTimestamp: 4, - proxyRequestCorrelationTimestamp: 5, + cdpLagDuration: 4, + proxyRequestCorrelationDuration: 5, }, }, res, @@ -2296,8 +2296,8 @@ describe('http/response-middleware', function () { expect(actual.timings.cdpRequestWillBeSentTimestamp).to.equal(1) expect(actual.timings.cdpRequestWillBeSentReceivedTimestamp).to.equal(2) expect(actual.timings.proxyRequestReceivedTimestamp).to.equal(3) - expect(actual.timings.cdpLagTimestamp).to.equal(4) - expect(actual.timings.proxyRequestCorrelationTimestamp).to.equal(5) + expect(actual.timings.cdpLagDuration).to.equal(4) + expect(actual.timings.proxyRequestCorrelationDuration).to.equal(5) return true }), diff --git a/packages/proxy/test/unit/http/util/prerequests.spec.ts b/packages/proxy/test/unit/http/util/prerequests.spec.ts index f757bcd66107..1ff360bcc90a 100644 --- a/packages/proxy/test/unit/http/util/prerequests.spec.ts +++ b/packages/proxy/test/unit/http/util/prerequests.spec.ts @@ -81,8 +81,8 @@ describe('http/util/prerequests', () => { expect(arg.cdpRequestWillBeSentTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentTimestamp) expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp) expect(arg.proxyRequestReceivedTimestamp).to.be.a('number') - expect(arg.cdpLagTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - secondPreRequest.cdpRequestWillBeSentTimestamp) - expect(arg.proxyRequestCorrelationTimestamp).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.proxyRequestReceivedTimestamp) + expect(arg.cdpLagDuration).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - secondPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.proxyRequestCorrelationDuration).to.eq(secondPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.proxyRequestReceivedTimestamp) expectPendingCounts(0, 2) }) @@ -136,8 +136,8 @@ describe('http/util/prerequests', () => { expect(arg.timings.cdpRequestWillBeSentTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentTimestamp) expect(arg.timings.cdpRequestWillBeSentReceivedTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp) expect(arg.timings.proxyRequestReceivedTimestamp).to.be.a('number') - expect(arg.timings.cdpLagTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp) - expect(arg.timings.proxyRequestCorrelationTimestamp).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.timings.proxyRequestReceivedTimestamp) + expect(arg.timings.cdpLagDuration).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp) + expect(arg.timings.proxyRequestCorrelationDuration).to.eq(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - arg.timings.proxyRequestReceivedTimestamp) }) // https://github.com/cypress-io/cypress/issues/17853 diff --git a/system-tests/__snapshots__/protocol_spec.js b/system-tests/__snapshots__/protocol_spec.js index a607fef8e410..5d85bd7468db 100644 --- a/system-tests/__snapshots__/protocol_spec.js +++ b/system-tests/__snapshots__/protocol_spec.js @@ -6537,8 +6537,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6548,8 +6548,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6559,8 +6559,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6570,8 +6570,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6581,8 +6581,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6592,8 +6592,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6603,8 +6603,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -6614,8 +6614,8 @@ exports['component events - experimentalSingleTabRunMode: true'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } } ], @@ -8232,8 +8232,8 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -8243,8 +8243,8 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -8254,8 +8254,8 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } }, { @@ -8265,8 +8265,8 @@ exports['component events - experimentalSingleTabRunMode: false'] = ` "cdpRequestWillBeSentTimestamp": "Any.Number", "cdpRequestWillBeSentReceivedTimestamp": "Any.Number", "proxyRequestReceivedTimestamp": "Any.Number", - "cdpLagTimestamp": "Any.Number", - "proxyRequestCorrelationTimestamp": "Any.Number" + "cdpLagDuration": "Any.Number", + "proxyRequestCorrelationDuration": "Any.Number" } } ], diff --git a/system-tests/test/protocol_spec.js b/system-tests/test/protocol_spec.js index e2a2fd54ca2f..8ac73046544a 100644 --- a/system-tests/test/protocol_spec.js +++ b/system-tests/test/protocol_spec.js @@ -10,7 +10,7 @@ const { // source: https://www.myintervals.com/blog/2009/05/20/iso-8601-date-validation-that-doesnt-suck/ const isoDateRegex = /"([\+-]?\d{4}(?!\d{2}\b))((-?)((0[1-9]|1[0-2])(\3([12]\d|0[1-9]|3[01]))?|W([0-4]\d|5[0-2])(-?[1-7])?|(00[1-9]|0[1-9]\d|[12]\d{2}|3([0-5]\d|6[1-6])))([T\s]((([01]\d|2[0-3])((:?)[0-5]\d)?|24\:?00)([\.,]\d+(?!:))?)?(\17[0-5]\d([\.,]\d+)?)?([zZ]|([\+-])([01]\d|2[0-3]):?([0-5]\d)?)?)?)?"/g -const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId|cdpRequestWillBeSentTimestamp|cdpRequestWillBeSentReceivedTimestamp|proxyRequestReceivedTimestamp|cdpLagTimestamp|proxyRequestCorrelationTimestamp)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g +const numberRegex = /"(wallClockDuration|fnDuration|afterFnDuration|lifecycle|duration|timestamp|createdAtTimestamp|updatedAtTimestamp|x|y|top|left|topCenter|leftCenter|requestId|cdpRequestWillBeSentTimestamp|cdpRequestWillBeSentReceivedTimestamp|proxyRequestReceivedTimestamp|cdpLagDuration|proxyRequestCorrelationDuration)": \"?(0|[1-9]\d*)(\.\d+)?\"?/g const pathRegex = /"(name|absoluteFile)": "\/[^"]+"/g const componentSpecPathRegex = /"(url|message)": "(http:\/\/localhost:2121\/__cypress\/iframes\/index.html\?specPath=)(.*)(\/protocol\/src\/components\/)(.*)"/g From 3564cfc1aa9690b89ce7e2a222ff5840468d7a72 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 08:51:35 -0500 Subject: [PATCH 04/15] Update packages/proxy/lib/http/util/prerequests.ts --- packages/proxy/lib/http/util/prerequests.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 0761432f1799..7ea339d6d356 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -90,9 +90,9 @@ export class PreRequests { protocolManager?: ProtocolManagerShape constructor ( - requestTimeout = 1000 * 2, + requestTimeout = 2000, // 10 seconds - sweepInterval = 1000 * 10, + sweepInterval = 10000, ) { // If a request comes in and we don't have a matching pre-request after this timeout, // we invoke the request callback to tell the server to proceed (we don't want to block From 44fc07d12052cd8262fca7f5117fe0b56a3c0548 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 10:08:49 -0500 Subject: [PATCH 05/15] fix build --- packages/proxy/lib/types.ts | 9 +-------- packages/types/src/index.ts | 2 ++ packages/types/src/protocol.ts | 2 +- packages/types/src/proxy.ts | 7 +++++++ 4 files changed, 11 insertions(+), 9 deletions(-) create mode 100644 packages/types/src/proxy.ts diff --git a/packages/proxy/lib/types.ts b/packages/proxy/lib/types.ts index f23badaf71f0..94f73165441a 100644 --- a/packages/proxy/lib/types.ts +++ b/packages/proxy/lib/types.ts @@ -1,5 +1,6 @@ import type { Readable } from 'stream' import type { Request, Response } from 'express' +import type { ProxyTimings } from '@packages/types' import type { ResourceType } from '@packages/net-stubbing' import type { BackendRoute } from '@packages/net-stubbing/lib/server/types' @@ -64,14 +65,6 @@ export type BrowserPreRequest = { cdpRequestWillBeSentReceivedTimestamp: number } -export type ProxyTimings = { - cdpRequestWillBeSentTimestamp: number - cdpRequestWillBeSentReceivedTimestamp: number - proxyRequestReceivedTimestamp: number - cdpLagDuration: number - proxyRequestCorrelationDuration: number -} - export type BrowserPreRequestWithTimings = BrowserPreRequest & ProxyTimings /** diff --git a/packages/types/src/index.ts b/packages/types/src/index.ts index 5ba54eda0e31..e3e5fb57c6f7 100644 --- a/packages/types/src/index.ts +++ b/packages/types/src/index.ts @@ -43,3 +43,5 @@ export * from './git' export * from './video' export * from './protocol' + +export * from './proxy' diff --git a/packages/types/src/protocol.ts b/packages/types/src/protocol.ts index 255c7d87fc49..f6737c7e1454 100644 --- a/packages/types/src/protocol.ts +++ b/packages/types/src/protocol.ts @@ -2,7 +2,7 @@ import type { Database } from 'better-sqlite3' import type ProtocolMapping from 'devtools-protocol/types/protocol-mapping' import type { IncomingHttpHeaders } from 'http' import type { Readable } from 'stream' -import type { ProxyTimings } from '@packages/proxy' +import type { ProxyTimings } from '@packages/types' type Commands = ProtocolMapping.Commands type Command = Commands[T] diff --git a/packages/types/src/proxy.ts b/packages/types/src/proxy.ts new file mode 100644 index 000000000000..7100b59a7375 --- /dev/null +++ b/packages/types/src/proxy.ts @@ -0,0 +1,7 @@ +export type ProxyTimings = { + cdpRequestWillBeSentTimestamp: number + cdpRequestWillBeSentReceivedTimestamp: number + proxyRequestReceivedTimestamp: number + cdpLagDuration: number + proxyRequestCorrelationDuration: number +} From 561448fe5881fb3bb8de5f568730cd9b0973ebd7 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 10:59:48 -0500 Subject: [PATCH 06/15] Update packages/server/lib/browsers/cdp_automation.ts --- packages/server/lib/browsers/cdp_automation.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/server/lib/browsers/cdp_automation.ts b/packages/server/lib/browsers/cdp_automation.ts index 7a2f67ac0f27..6255de775972 100644 --- a/packages/server/lib/browsers/cdp_automation.ts +++ b/packages/server/lib/browsers/cdp_automation.ts @@ -238,6 +238,8 @@ export class CdpAutomation implements CDPClient { headers: params.request.headers, resourceType: normalizeResourceType(params.type), originalResourceType: params.type, + // wallTime is in seconds: https://vanilla.aslushnikov.com/?Network.TimeSinceEpoch + // normalize to milliseconds to be comparable to everything else we're gathering cdpRequestWillBeSentTimestamp: params.wallTime * 1000, cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin, } From 9581c1f795772798725207a36bfe803b09da02c2 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 11:36:56 -0500 Subject: [PATCH 07/15] fix ts --- cli/CHANGELOG.md | 1 + packages/proxy/lib/http/util/prerequests.ts | 24 +++++++++---------- .../server/lib/browsers/webkit-automation.ts | 2 ++ 3 files changed, 14 insertions(+), 13 deletions(-) diff --git a/cli/CHANGELOG.md b/cli/CHANGELOG.md index 83c36686124b..6a105cc05ab8 100644 --- a/cli/CHANGELOG.md +++ b/cli/CHANGELOG.md @@ -8,6 +8,7 @@ _Released 10/03/2023 (PENDING)_ - Fixed an issue where requests were correlated in the wrong order in the proxy. This could cause an issue where the wrong request is used for `cy.intercept` or assets (e.g. stylesheets or images) may not properly be available in Test Replay. Addressed in [#27892](https://github.com/cypress-io/cypress/pull/27892). - Fixed an issue where a crashed Chrome renderer can cause the Test Replay recorder to hang. Addressed in [#27909](https://github.com/cypress-io/cypress/pull/27909). - Fixed an issue where multiple responses yielded from calls to `cy.wait()` would sometimes be out of order. Fixes [#27337](https://github.com/cypress-io/cypress/issues/27337). +- Fixed an issue where requests were timing out in the proxy. This could cause an issue where the wrong request is used for `cy.intercept` or assets (e.g. stylesheets or images) may not properly be available in Test Replay. Addressed in [#27976](https://github.com/cypress-io/cypress/pull/27976) ## 13.3.0 diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 7ea339d6d356..a5617561c91b 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -90,7 +90,7 @@ export class PreRequests { protocolManager?: ProtocolManagerShape constructor ( - requestTimeout = 2000, + requestTimeout = 1, // 10 seconds sweepInterval = 10000, ) { @@ -128,16 +128,20 @@ export class PreRequests { const pendingRequest = this.pendingRequests.shift(key) if (pendingRequest) { + const timings = { + cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, + cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, + proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, + cdpLagDuration: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, + proxyRequestCorrelationDuration: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), + } + debugVerbose('Incoming pre-request %s matches pending request. %o', key, browserPreRequest) if (!pendingRequest.timedOut) { clearTimeout(pendingRequest.timeout) pendingRequest.callback({ ...browserPreRequest, - cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, - cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, - proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, - cdpLagDuration: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, - proxyRequestCorrelationDuration: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), + ...timings, }) return @@ -145,13 +149,7 @@ export class PreRequests { this.protocolManager?.responseStreamTimedOut({ requestId: browserPreRequest.requestId, - timings: { - cdpRequestWillBeSentTimestamp: browserPreRequest.cdpRequestWillBeSentTimestamp, - cdpRequestWillBeSentReceivedTimestamp: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp, - proxyRequestReceivedTimestamp: pendingRequest.proxyRequestReceivedTimestamp, - cdpLagDuration: browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - browserPreRequest.cdpRequestWillBeSentTimestamp, - proxyRequestCorrelationDuration: Math.max(browserPreRequest.cdpRequestWillBeSentReceivedTimestamp - pendingRequest.proxyRequestReceivedTimestamp, 0), - }, + timings, }) return diff --git a/packages/server/lib/browsers/webkit-automation.ts b/packages/server/lib/browsers/webkit-automation.ts index daa9e95e13e1..e089df2a7bca 100644 --- a/packages/server/lib/browsers/webkit-automation.ts +++ b/packages/server/lib/browsers/webkit-automation.ts @@ -222,6 +222,8 @@ export class WebKitAutomation { headers: request.headers(), resourceType: normalizeResourceType(request.resourceType()), originalResourceType: request.resourceType(), + cdpRequestWillBeSentTimestamp: request.timing().requestStart, + cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin, } debug('received request %o', { browserPreRequest }) From 4239e3cc4f50124457468edf1078593069354368 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 11:58:50 -0500 Subject: [PATCH 08/15] oops --- packages/proxy/lib/http/util/prerequests.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index a5617561c91b..1d4409391346 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -90,7 +90,7 @@ export class PreRequests { protocolManager?: ProtocolManagerShape constructor ( - requestTimeout = 1, + requestTimeout = 2000, // 10 seconds sweepInterval = 10000, ) { From bcfedefef0559232c3729f21b830ba654c36be3f Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Thu, 5 Oct 2023 13:05:29 -0500 Subject: [PATCH 09/15] fix tests --- packages/server/test/unit/browsers/cdp_automation_spec.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/server/test/unit/browsers/cdp_automation_spec.ts b/packages/server/test/unit/browsers/cdp_automation_spec.ts index 45a99b99a2cb..e239eea1442c 100644 --- a/packages/server/test/unit/browsers/cdp_automation_spec.ts +++ b/packages/server/test/unit/browsers/cdp_automation_spec.ts @@ -124,7 +124,7 @@ context('lib/browsers/cdp_automation', () => { expect(arg.headers).to.eq(browserPreRequest.request.headers) expect(arg.resourceType).to.eq(browserPreRequest.type) expect(arg.originalResourceType).to.eq(browserPreRequest.type) - expect(arg.cdpRequestWillBeSentTimestamp).to.eq(100100.100) + expect(arg.cdpRequestWillBeSentTimestamp).to.be.closeTo(100100.100, 0.001) expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.be.a('number') }) @@ -152,7 +152,7 @@ context('lib/browsers/cdp_automation', () => { expect(arg.headers).to.eq(browserPreRequest.request.headers) expect(arg.resourceType).to.eq(browserPreRequest.type) expect(arg.originalResourceType).to.eq(browserPreRequest.type) - expect(arg.cdpRequestWillBeSentTimestamp).to.eq(100100.100) + expect(arg.cdpRequestWillBeSentTimestamp).to.be.closeTo(100100.100, 0.001) expect(arg.cdpRequestWillBeSentReceivedTimestamp).to.be.a('number') }) From 373c04fde8bd2f4e66804f7e209a116aee0e7ece Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Mon, 9 Oct 2023 10:27:54 -0500 Subject: [PATCH 10/15] figure out download problem --- packages/proxy/lib/http/index.ts | 4 ++ packages/proxy/lib/http/util/prerequests.ts | 36 +++++++++++++ packages/proxy/lib/network-proxy.ts | 4 ++ packages/server/lib/automation/automation.ts | 2 +- packages/server/lib/browsers/chrome.ts | 2 + packages/server/lib/browsers/electron.ts | 1 + packages/server/lib/browsers/utils.ts | 52 +++++++++++++++++++ .../server/lib/browsers/webkit-automation.ts | 9 ++++ packages/server/lib/project-base.ts | 6 ++- packages/server/lib/server-base.ts | 4 ++ system-tests/test/downloads_spec.ts | 44 ++++++++++------ 11 files changed, 145 insertions(+), 19 deletions(-) diff --git a/packages/proxy/lib/http/index.ts b/packages/proxy/lib/http/index.ts index 85d96a1e802a..890f08b78000 100644 --- a/packages/proxy/lib/http/index.ts +++ b/packages/proxy/lib/http/index.ts @@ -425,6 +425,10 @@ export class Http { this.preRequests.removePending(requestId) } + addPendingNoPreRequest (url: string) { + this.preRequests.addPendingNoPreRequest(url) + } + setProtocolManager (protocolManager: ProtocolManagerShape) { this.protocolManager = protocolManager this.preRequests.setProtocolManager(protocolManager) diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 1d4409391346..982ac76d20a7 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -37,6 +37,10 @@ type PendingPreRequest = { cdpRequestWillBeSentReceivedTimestamp: number } +type PendingNoPreRequest = { + timestamp: number +} + /** * Data structure that organizes items with duplicated keys into queues. */ @@ -86,6 +90,7 @@ export class PreRequests { sweepInterval: number pendingPreRequests = new QueueMap() pendingRequests = new QueueMap() + pendingNoPreRequests = new QueueMap() sweepIntervalTimer: NodeJS.Timeout protocolManager?: ProtocolManagerShape @@ -119,6 +124,10 @@ export class PreRequests { return true }) + + this.pendingNoPreRequests.removeMatching(({ timestamp }) => { + return timestamp + this.sweepInterval >= now + }) }, this.sweepInterval) } @@ -163,6 +172,23 @@ export class PreRequests { }) } + addPendingNoPreRequest (url: string) { + const key = `GET-${url}` + const pendingRequest = this.pendingRequests.shift(key) + + if (pendingRequest) { + debugVerbose('Handling %s without a CDP prerequest', key) + clearTimeout(pendingRequest.timeout) + pendingRequest.callback() + + return + } + + this.pendingNoPreRequests.push(key, { + timestamp: Date.now(), + }) + } + removePending (requestId: string) { this.pendingPreRequests.removeMatching(({ browserPreRequest }) => { return (browserPreRequest.requestId.includes('-retry-') && !browserPreRequest.requestId.startsWith(`${requestId}-`)) || (!browserPreRequest.requestId.includes('-retry-') && browserPreRequest.requestId !== requestId) @@ -191,6 +217,16 @@ export class PreRequests { return } + const pendingNoPreRequests = this.pendingNoPreRequests.shift(key) + + if (pendingNoPreRequests) { + metrics.immediatelyMatchedRequests++ + ctxDebug('Incoming request %s matches known no-pre-request', key) + callback() + + return + } + const pendingRequest: PendingRequest = { ctxDebug, callback, diff --git a/packages/proxy/lib/network-proxy.ts b/packages/proxy/lib/network-proxy.ts index a604614739a9..e4436b712639 100644 --- a/packages/proxy/lib/network-proxy.ts +++ b/packages/proxy/lib/network-proxy.ts @@ -17,6 +17,10 @@ export class NetworkProxy { this.http.removePendingBrowserPreRequest(requestId) } + addPendingNoBrowserPreRequest (url: string) { + this.http.addPendingNoPreRequest(url) + } + handleHttpRequest (req, res) { const span = telemetry.startSpan({ name: 'network:proxy:handleHttpRequest', diff --git a/packages/server/lib/automation/automation.ts b/packages/server/lib/automation/automation.ts index b1101a505ca4..53d4bbf0f94f 100644 --- a/packages/server/lib/automation/automation.ts +++ b/packages/server/lib/automation/automation.ts @@ -14,7 +14,7 @@ export class Automation { private cookies: Cookies private screenshot: { capture: (data: any, automate: any) => any } - constructor (cyNamespace?: string, cookieNamespace?: string, screenshotsFolder?: string | false, public onBrowserPreRequest?: OnBrowserPreRequest, public onRequestEvent?: OnRequestEvent, public onRequestServedFromCache?: (requestId: string) => void, public onRequestFailed?: (requestId: string) => void) { + constructor (cyNamespace?: string, cookieNamespace?: string, screenshotsFolder?: string | false, public onBrowserPreRequest?: OnBrowserPreRequest, public onRequestEvent?: OnRequestEvent, public onRequestServedFromCache?: (requestId: string) => void, public onRequestFailed?: (requestId: string) => void, public onDownloadLinkClicked?: (downloadUrl: string) => void) { this.requests = {} // set the middleware diff --git a/packages/server/lib/browsers/chrome.ts b/packages/server/lib/browsers/chrome.ts index e3a11b10067c..cfdfe981367f 100644 --- a/packages/server/lib/browsers/chrome.ts +++ b/packages/server/lib/browsers/chrome.ts @@ -501,6 +501,8 @@ export = { options.onError(err) }) + await utils.handleDownloadLinksViaCDP(pageCriClient, automation) + if (!browserCriClient) throw new Error('Missing browserCriClient in attachListeners') debug('attaching listeners to chrome %o', { url, options }) diff --git a/packages/server/lib/browsers/electron.ts b/packages/server/lib/browsers/electron.ts index b105e6e20954..33aed67a3866 100644 --- a/packages/server/lib/browsers/electron.ts +++ b/packages/server/lib/browsers/electron.ts @@ -307,6 +307,7 @@ export = { cdpSocketServer?.attachCDPClient(cdpAutomation), videoApi && recordVideo(cdpAutomation, videoApi), this._handleDownloads(win, options.downloadsFolder, automation), + await utils.handleDownloadLinksViaCDP(pageCriClient, automation), ]) } diff --git a/packages/server/lib/browsers/utils.ts b/packages/server/lib/browsers/utils.ts index 3353b881973c..5a5100c28c29 100644 --- a/packages/server/lib/browsers/utils.ts +++ b/packages/server/lib/browsers/utils.ts @@ -6,6 +6,8 @@ import * as errors from '../errors' import * as plugins from '../plugins' import { getError } from '@packages/errors' import * as launcher from '@packages/launcher' +import type { Automation } from '../automation' +import type { CriClient } from './cri-client' const path = require('path') const debug = require('debug')('cypress:server:browsers:utils') @@ -362,6 +364,52 @@ const throwBrowserNotFound = function (browserName, browsers: FoundBrowser[] = [ return errors.throwErr('BROWSER_NOT_FOUND_BY_NAME', browserName, formatBrowsersToOptions(browsers)) } +const handleDownloadLinksViaCDP = async (criClient: CriClient, automation: Automation) => { + await criClient.send('Runtime.enable') + await criClient.send('Runtime.addBinding', { + name: 'cypressDownloadLinkClicked', + }) + + await criClient.on('Runtime.bindingCalled', async (data) => { + if (data.name === 'cypressDownloadLinkClicked') { + const url = data.payload + + await automation.onDownloadLinkClicked?.(url) + } + }) + + await criClient.send('Page.addScriptToEvaluateOnNewDocument', { + source: `(${listenForDocumentDownload.toString()})()`, + }) +} + +const listenForDocumentDownload = () => { + // @ts-expect-error + if (window.navigation) { + // @ts-expect-error + window.navigation.addEventListener('navigate', (event) => { + if (typeof event.downloadRequest === 'string') { + // @ts-expect-error + window.cypressDownloadLinkClicked(event.destination.url) + } + }) + } else { + document.addEventListener('click', (event) => { + if (event.target instanceof HTMLAnchorElement && typeof event.target.download === 'string') { + // @ts-expect-error + window.cypressDownloadLinkClicked(event.target.href) + } + }) + + document.addEventListener('keydown', (event) => { + if (event.target instanceof HTMLAnchorElement && event.key === 'Enter' && typeof event.target.download === 'string') { + // @ts-expect-error + window.cypressDownloadLinkClicked(event.target.href) + } + }) + } +} + export = { extendLaunchOptionsFromPlugins, @@ -396,6 +444,10 @@ export = { throwBrowserNotFound, + handleDownloadLinksViaCDP, + + listenForDocumentDownload, + writeExtension (browser, isTextTerminal, proxyUrl, socketIoRoute) { debug('writing extension') diff --git a/packages/server/lib/browsers/webkit-automation.ts b/packages/server/lib/browsers/webkit-automation.ts index e089df2a7bca..28492bd55f43 100644 --- a/packages/server/lib/browsers/webkit-automation.ts +++ b/packages/server/lib/browsers/webkit-automation.ts @@ -7,6 +7,7 @@ import type { RunModeVideoApi } from '@packages/types' import path from 'path' import mime from 'mime' import { cookieMatches, CyCookieFilter } from '../automation/util' +import utils from './utils' const debug = Debug('cypress:server:browsers:webkit-automation') @@ -108,6 +109,14 @@ export class WebKitAutomation { this.page = await newContext.newPage() this.context = this.page.context() + await this.page.addInitScript({ + content: `(${utils.listenForDocumentDownload.toString()})()`, + }) + + await this.context.exposeBinding('cypressDownloadLinkClicked', (source, downloadUrl) => { + this.automation.onDownloadLinkClicked?.(downloadUrl) + }) + this.handleRequestEvents() if (options.downloadsFolder) this.handleDownloadEvents(options.downloadsFolder) diff --git a/packages/server/lib/project-base.ts b/packages/server/lib/project-base.ts index f9ac70da24e9..44db4d99edc7 100644 --- a/packages/server/lib/project-base.ts +++ b/packages/server/lib/project-base.ts @@ -338,7 +338,11 @@ export class ProjectBase extends EE { this.server.removeBrowserPreRequest(requestId) } - this._automation = new Automation(namespace, socketIoCookie, screenshotsFolder, onBrowserPreRequest, onRequestEvent, onRequestServedFromCache, onRequestFailed) + const onDownloadLinkClicked = (downloadUrl: string) => { + this.server.addPendingNoBrowserPreRequest(downloadUrl) + } + + this._automation = new Automation(namespace, socketIoCookie, screenshotsFolder, onBrowserPreRequest, onRequestEvent, onRequestServedFromCache, onRequestFailed, onDownloadLinkClicked) const ios = this.server.startWebsockets(this.automation, this.cfg, { onReloadBrowser: options.onReloadBrowser, diff --git a/packages/server/lib/server-base.ts b/packages/server/lib/server-base.ts index 78cfbd7a9d6d..05790b706c35 100644 --- a/packages/server/lib/server-base.ts +++ b/packages/server/lib/server-base.ts @@ -499,6 +499,10 @@ export class ServerBase { this.socket.toDriver('request:event', eventName, data) } + addPendingNoBrowserPreRequest (downloadUrl: string) { + this.networkProxy.addPendingNoBrowserPreRequest(downloadUrl) + } + _createHttpServer (app): DestroyableHttpServer { const svr = http.createServer(httpUtils.lenientOptions, app) diff --git a/system-tests/test/downloads_spec.ts b/system-tests/test/downloads_spec.ts index ec6c3bbd1200..57749f0eaeec 100644 --- a/system-tests/test/downloads_spec.ts +++ b/system-tests/test/downloads_spec.ts @@ -1,6 +1,6 @@ import path from 'path' -import systemTests, { expect } from '../lib/system-tests' +import systemTests, { BrowserName, expect } from '../lib/system-tests' import Fixtures from '../lib/fixtures' import { fs } from '@packages/server/lib/util/fs' @@ -53,24 +53,34 @@ describe('e2e downloads', () => { expect(exists, `Expected ${filePath} not to exist, but it does`).to.be.false }) - it('does not trash downloads between runs if trashAssetsBeforeRuns: false', async function () { - await systemTests.exec(this, { - project: 'downloads', - spec: 'download_csv.cy.ts', - }) + const browsers: BrowserName[] = ['chrome', 'electron', 'firefox', 'webkit'] - // this run should _not_ trash the downloads from the above run - await systemTests.exec(this, { - project: 'downloads', - spec: 'simple_passing.cy.ts', - config: { - trashAssetsBeforeRuns: false, - }, - }) + browsers.forEach((browser) => { + it(`does not trash downloads between runs if trashAssetsBeforeRuns: false - ${browser}`, async function () { + await systemTests.exec(this, { + browser, + project: 'downloads', + spec: 'download_csv.cy.ts', + config: { + experimentalWebKitSupport: true, + }, + }) - const filePath = path.join(downloadsProject, 'cypress', 'downloads', 'records.csv') - const exists = await fs.pathExists(filePath) + // this run should _not_ trash the downloads from the above run + await systemTests.exec(this, { + browser, + project: 'downloads', + spec: 'simple_passing.cy.ts', + config: { + experimentalWebKitSupport: true, + trashAssetsBeforeRuns: false, + }, + }) + + const filePath = path.join(downloadsProject, 'cypress', 'downloads', 'records.csv') + const exists = await fs.pathExists(filePath) - expect(exists, `Expected ${filePath} to exist, but it does not`).to.be.true + expect(exists, `Expected ${filePath} to exist, but it does not`).to.be.true + }) }) }) From a9e4a85c5cb9098b4ed635b1709ed9326f871b3d Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Mon, 9 Oct 2023 12:33:35 -0500 Subject: [PATCH 11/15] fix tests --- packages/server/lib/browsers/chrome.ts | 4 ++-- packages/server/test/unit/browsers/chrome_spec.js | 4 ++++ 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/packages/server/lib/browsers/chrome.ts b/packages/server/lib/browsers/chrome.ts index cfdfe981367f..f5a11c449b19 100644 --- a/packages/server/lib/browsers/chrome.ts +++ b/packages/server/lib/browsers/chrome.ts @@ -501,8 +501,6 @@ export = { options.onError(err) }) - await utils.handleDownloadLinksViaCDP(pageCriClient, automation) - if (!browserCriClient) throw new Error('Missing browserCriClient in attachListeners') debug('attaching listeners to chrome %o', { url, options }) @@ -519,6 +517,8 @@ export = { await pageCriClient.send('Page.enable') + await utils.handleDownloadLinksViaCDP(pageCriClient, automation) + await options['onInitializeNewBrowserTab']?.() await Promise.all([ diff --git a/packages/server/test/unit/browsers/chrome_spec.js b/packages/server/test/unit/browsers/chrome_spec.js index 4aa4aeef440b..987afc4c8313 100644 --- a/packages/server/test/unit/browsers/chrome_spec.js +++ b/packages/server/test/unit/browsers/chrome_spec.js @@ -10,6 +10,7 @@ const utils = require(`../../../lib/browsers/utils`) const chrome = require(`../../../lib/browsers/chrome`) const { fs } = require(`../../../lib/util/fs`) const { BrowserCriClient } = require('../../../lib/browsers/browser-cri-client') +const { expect } = require('chai') const openOpts = { onError: () => {}, @@ -59,6 +60,7 @@ describe('lib/browsers/chrome', () => { sinon.stub(launch, 'launch').resolves(this.launchedBrowser) sinon.stub(utils, 'getProfileDir').returns('/profile/dir') sinon.stub(utils, 'ensureCleanCache').resolves('/profile/dir/CypressCache') + sinon.stub(utils, 'handleDownloadLinksViaCDP').resolves() this.readJson = sinon.stub(fs, 'readJson') this.readJson.withArgs('/profile/dir/Default/Preferences').rejects({ code: 'ENOENT' }) @@ -86,6 +88,8 @@ describe('lib/browsers/chrome', () => { expect(this.pageCriClient.send).to.have.been.calledWith('Page.setDownloadBehavior') expect(this.pageCriClient.send).to.have.been.calledWith('Network.enable') expect(this.pageCriClient.send).to.have.been.calledWith('Fetch.enable') + + expect(utils.handleDownloadLinksViaCDP).to.be.calledOnce }) }) From 6d90619f9c020dc7337cd05ad3fd81ea05e7fd27 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Mon, 9 Oct 2023 18:15:02 -0500 Subject: [PATCH 12/15] clean up code --- packages/proxy/lib/http/index.ts | 4 +- packages/proxy/lib/http/util/prerequests.ts | 18 ++++----- packages/proxy/lib/network-proxy.ts | 4 +- .../test/unit/http/util/prerequests.spec.ts | 37 ++++++++++++++++++- packages/server/lib/browsers/utils.ts | 19 +++++++--- packages/server/lib/project-base.ts | 2 +- packages/server/lib/server-base.ts | 4 +- .../test/unit/browsers/electron_spec.js | 9 +++++ 8 files changed, 74 insertions(+), 23 deletions(-) diff --git a/packages/proxy/lib/http/index.ts b/packages/proxy/lib/http/index.ts index 890f08b78000..433881759c05 100644 --- a/packages/proxy/lib/http/index.ts +++ b/packages/proxy/lib/http/index.ts @@ -425,8 +425,8 @@ export class Http { this.preRequests.removePending(requestId) } - addPendingNoPreRequest (url: string) { - this.preRequests.addPendingNoPreRequest(url) + addPendingUrlWithoutPreRequest (url: string) { + this.preRequests.addPendingUrlWithoutPreRequest(url) } setProtocolManager (protocolManager: ProtocolManagerShape) { diff --git a/packages/proxy/lib/http/util/prerequests.ts b/packages/proxy/lib/http/util/prerequests.ts index 982ac76d20a7..ee2dc2cf3e1a 100644 --- a/packages/proxy/lib/http/util/prerequests.ts +++ b/packages/proxy/lib/http/util/prerequests.ts @@ -37,7 +37,7 @@ type PendingPreRequest = { cdpRequestWillBeSentReceivedTimestamp: number } -type PendingNoPreRequest = { +type PendingUrlWithoutPreRequest = { timestamp: number } @@ -90,7 +90,7 @@ export class PreRequests { sweepInterval: number pendingPreRequests = new QueueMap() pendingRequests = new QueueMap() - pendingNoPreRequests = new QueueMap() + pendingUrlsWithoutPreRequests = new QueueMap() sweepIntervalTimer: NodeJS.Timeout protocolManager?: ProtocolManagerShape @@ -125,7 +125,7 @@ export class PreRequests { return true }) - this.pendingNoPreRequests.removeMatching(({ timestamp }) => { + this.pendingUrlsWithoutPreRequests.removeMatching(({ timestamp }) => { return timestamp + this.sweepInterval >= now }) }, this.sweepInterval) @@ -172,7 +172,7 @@ export class PreRequests { }) } - addPendingNoPreRequest (url: string) { + addPendingUrlWithoutPreRequest (url: string) { const key = `GET-${url}` const pendingRequest = this.pendingRequests.shift(key) @@ -184,7 +184,7 @@ export class PreRequests { return } - this.pendingNoPreRequests.push(key, { + this.pendingUrlsWithoutPreRequests.push(key, { timestamp: Date.now(), }) } @@ -217,11 +217,11 @@ export class PreRequests { return } - const pendingNoPreRequests = this.pendingNoPreRequests.shift(key) + const pendingUrlWithoutPreRequests = this.pendingUrlsWithoutPreRequests.shift(key) - if (pendingNoPreRequests) { + if (pendingUrlWithoutPreRequests) { metrics.immediatelyMatchedRequests++ - ctxDebug('Incoming request %s matches known no-pre-request', key) + ctxDebug('Incoming request %s matches known pending url without pre request', key) callback() return @@ -232,7 +232,7 @@ export class PreRequests { callback, proxyRequestReceivedTimestamp: performance.now() + performance.timeOrigin, timeout: setTimeout(() => { - ctxDebug('Never received pre-request for request %s after waiting %sms. Continuing without one.', key, this.requestTimeout) + ctxDebug('Never received pre-request or url without pre-request for request %s after waiting %sms. Continuing without one.', key, this.requestTimeout) metrics.unmatchedRequests++ pendingRequest.timedOut = true callback() diff --git a/packages/proxy/lib/network-proxy.ts b/packages/proxy/lib/network-proxy.ts index e4436b712639..2702b059a1f7 100644 --- a/packages/proxy/lib/network-proxy.ts +++ b/packages/proxy/lib/network-proxy.ts @@ -17,8 +17,8 @@ export class NetworkProxy { this.http.removePendingBrowserPreRequest(requestId) } - addPendingNoBrowserPreRequest (url: string) { - this.http.addPendingNoPreRequest(url) + addPendingUrlWithoutPreRequest (url: string) { + this.http.addPendingUrlWithoutPreRequest(url) } handleHttpRequest (req, res) { diff --git a/packages/proxy/test/unit/http/util/prerequests.spec.ts b/packages/proxy/test/unit/http/util/prerequests.spec.ts index 1ff360bcc90a..309727358fe4 100644 --- a/packages/proxy/test/unit/http/util/prerequests.spec.ts +++ b/packages/proxy/test/unit/http/util/prerequests.spec.ts @@ -9,9 +9,10 @@ describe('http/util/prerequests', () => { let preRequests: PreRequests let protocolManager: ProtocolManagerShape - function expectPendingCounts (pendingRequests: number, pendingPreRequests: number) { + function expectPendingCounts (pendingRequests: number, pendingPreRequests: number, pendingWithoutPreRequests = 0) { expect(preRequests.pendingRequests.length).to.eq(pendingRequests, 'wrong number of pending requests') expect(preRequests.pendingPreRequests.length).to.eq(pendingPreRequests, 'wrong number of pending prerequests') + expect(preRequests.pendingUrlsWithoutPreRequests.length).to.eq(pendingWithoutPreRequests, 'wrong number of pending without prerequests') } beforeEach(() => { @@ -87,6 +88,26 @@ describe('http/util/prerequests', () => { expectPendingCounts(0, 2) }) + it('synchronously matches a request without a pre-request that existed at the time of the request', () => { + // should match in order + preRequests.addPendingUrlWithoutPreRequest('foo') + preRequests.addPendingUrlWithoutPreRequest('foo') + preRequests.addPendingUrlWithoutPreRequest('foo') + + expectPendingCounts(0, 0, 3) + + const cb = sinon.stub() + + preRequests.get({ proxiedUrl: 'foo', method: 'GET' } as CypressIncomingRequest, () => {}, cb) + + const { args } = cb.getCall(0) + const arg = args[0] + + expect(arg).to.be.undefined + + expectPendingCounts(0, 0, 2) + }) + it('synchronously matches a pre-request added after the request', (done) => { const cb = (preRequest) => { expect(preRequest).to.include({ requestId: '1234', url: 'foo', method: 'GET' }) @@ -98,6 +119,17 @@ describe('http/util/prerequests', () => { preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET' } as BrowserPreRequest) }) + it('synchronously matches a request without a pre-request added after the request', (done) => { + const cb = (preRequest) => { + expect(preRequest).to.be.undefined + expectPendingCounts(0, 0) + done() + } + + preRequests.get({ proxiedUrl: 'foo', method: 'GET' } as CypressIncomingRequest, () => {}, cb) + preRequests.addPendingUrlWithoutPreRequest('foo') + }) + it('invokes a request callback after a timeout if no pre-request occurs', async () => { let cb const cbPromise = new Promise((resolve) => { @@ -144,6 +176,7 @@ describe('http/util/prerequests', () => { it('eventually discards pre-requests that don\'t match requests', (done) => { preRequests = new PreRequests(10, 200) preRequests.addPending({ requestId: '1234', url: 'foo', method: 'GET', cdpRequestWillBeSentReceivedTimestamp: performance.now() + performance.timeOrigin } as BrowserPreRequest) + preRequests.addPendingUrlWithoutPreRequest('bar') // preRequests garbage collects pre-requests that never matched up with an incoming request after around // 2 * requestTimeout. We verify that it's gone (and therefore not leaking memory) by sending in a request @@ -151,7 +184,7 @@ describe('http/util/prerequests', () => { setTimeout(() => { const cb = (preRequest) => { expect(preRequest).to.be.undefined - expectPendingCounts(1, 0) + expectPendingCounts(1, 0, 0) done() } diff --git a/packages/server/lib/browsers/utils.ts b/packages/server/lib/browsers/utils.ts index 5a5100c28c29..86cc1c9a25a9 100644 --- a/packages/server/lib/browsers/utils.ts +++ b/packages/server/lib/browsers/utils.ts @@ -9,6 +9,15 @@ import * as launcher from '@packages/launcher' import type { Automation } from '../automation' import type { CriClient } from './cri-client' +declare global { + interface Window { + navigation?: { + addEventListener: (event: string, listener: (event: any) => void) => void + } + cypressDownloadLinkClicked: (url: string) => void + } +} + const path = require('path') const debug = require('debug')('cypress:server:browsers:utils') const getPort = require('get-port') @@ -364,6 +373,9 @@ const throwBrowserNotFound = function (browserName, browsers: FoundBrowser[] = [ return errors.throwErr('BROWSER_NOT_FOUND_BY_NAME', browserName, formatBrowsersToOptions(browsers)) } +// Chromium browsers and webkit do not give us pre requests for download links but they still go through the proxy. +// We need to notify the proxy when they are clicked so that we can resolve the pending request waiting to be +// correlated in the proxy. const handleDownloadLinksViaCDP = async (criClient: CriClient, automation: Automation) => { await criClient.send('Runtime.enable') await criClient.send('Runtime.addBinding', { @@ -383,27 +395,24 @@ const handleDownloadLinksViaCDP = async (criClient: CriClient, automation: Autom }) } +// The most efficient way to do this is to listen for the navigate event. However, this is only available in chromium browsers (after 102). +// For older versions and for webkit, we need to listen for click events on anchor tags with the download attribute. const listenForDocumentDownload = () => { - // @ts-expect-error if (window.navigation) { - // @ts-expect-error window.navigation.addEventListener('navigate', (event) => { if (typeof event.downloadRequest === 'string') { - // @ts-expect-error window.cypressDownloadLinkClicked(event.destination.url) } }) } else { document.addEventListener('click', (event) => { if (event.target instanceof HTMLAnchorElement && typeof event.target.download === 'string') { - // @ts-expect-error window.cypressDownloadLinkClicked(event.target.href) } }) document.addEventListener('keydown', (event) => { if (event.target instanceof HTMLAnchorElement && event.key === 'Enter' && typeof event.target.download === 'string') { - // @ts-expect-error window.cypressDownloadLinkClicked(event.target.href) } }) diff --git a/packages/server/lib/project-base.ts b/packages/server/lib/project-base.ts index 821e04f354f8..129a38908316 100644 --- a/packages/server/lib/project-base.ts +++ b/packages/server/lib/project-base.ts @@ -339,7 +339,7 @@ export class ProjectBase extends EE { } const onDownloadLinkClicked = (downloadUrl: string) => { - this.server.addPendingNoBrowserPreRequest(downloadUrl) + this.server.addPendingUrlWithoutPreRequest(downloadUrl) } this._automation = new Automation(namespace, socketIoCookie, screenshotsFolder, onBrowserPreRequest, onRequestEvent, onRequestServedFromCache, onRequestFailed, onDownloadLinkClicked) diff --git a/packages/server/lib/server-base.ts b/packages/server/lib/server-base.ts index 05790b706c35..cf23c711ddec 100644 --- a/packages/server/lib/server-base.ts +++ b/packages/server/lib/server-base.ts @@ -499,8 +499,8 @@ export class ServerBase { this.socket.toDriver('request:event', eventName, data) } - addPendingNoBrowserPreRequest (downloadUrl: string) { - this.networkProxy.addPendingNoBrowserPreRequest(downloadUrl) + addPendingUrlWithoutPreRequest (downloadUrl: string) { + this.networkProxy.addPendingUrlWithoutPreRequest(downloadUrl) } _createHttpServer (app): DestroyableHttpServer { diff --git a/packages/server/test/unit/browsers/electron_spec.js b/packages/server/test/unit/browsers/electron_spec.js index 10a09998feed..4e7ec86c602f 100644 --- a/packages/server/test/unit/browsers/electron_spec.js +++ b/packages/server/test/unit/browsers/electron_spec.js @@ -13,6 +13,7 @@ const savedState = require(`../../../lib/saved_state`) const { Automation } = require(`../../../lib/automation`) const { BrowserCriClient } = require('../../../lib/browsers/browser-cri-client') const electronApp = require('../../../lib/util/electron-app') +const utils = require('../../../lib/browsers/utils') const ELECTRON_PID = 10001 @@ -67,6 +68,7 @@ describe('lib/browsers/electron', () => { sinon.stub(Windows, 'installExtension').returns() sinon.stub(Windows, 'removeAllExtensions').returns() sinon.stub(electronApp, 'getRemoteDebuggingPort').resolves(1234) + sinon.stub(utils, 'handleDownloadLinksViaCDP').resolves() // mock CRI client during testing this.pageCriClient = { @@ -347,6 +349,13 @@ describe('lib/browsers/electron', () => { }) }) + it('handles download links via cdp', function () { + return electron._launch(this.win, this.url, this.automation, this.options, undefined, undefined, { attachCDPClient: sinon.stub() }) + .then(() => { + expect(utils.handleDownloadLinksViaCDP).to.be.calledWith(this.pageCriClient, this.automation) + }) + }) + it('registers onRequest automation middleware and calls show when requesting to be focused', function () { sinon.spy(this.automation, 'use') From f5781f38fa31ca9ccc5a60efa4564020b762ba8f Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Tue, 10 Oct 2023 10:05:01 -0500 Subject: [PATCH 13/15] PR comments --- packages/server/lib/browsers/utils.ts | 6 +++--- packages/server/lib/browsers/webkit-automation.ts | 2 +- .../projects/downloads/cypress/e2e/download_csv.cy.ts | 6 ++++-- 3 files changed, 8 insertions(+), 6 deletions(-) diff --git a/packages/server/lib/browsers/utils.ts b/packages/server/lib/browsers/utils.ts index 86cc1c9a25a9..b6f246b28ff9 100644 --- a/packages/server/lib/browsers/utils.ts +++ b/packages/server/lib/browsers/utils.ts @@ -391,13 +391,13 @@ const handleDownloadLinksViaCDP = async (criClient: CriClient, automation: Autom }) await criClient.send('Page.addScriptToEvaluateOnNewDocument', { - source: `(${listenForDocumentDownload.toString()})()`, + source: `(${listenForDownload.toString()})()`, }) } // The most efficient way to do this is to listen for the navigate event. However, this is only available in chromium browsers (after 102). // For older versions and for webkit, we need to listen for click events on anchor tags with the download attribute. -const listenForDocumentDownload = () => { +const listenForDownload = () => { if (window.navigation) { window.navigation.addEventListener('navigate', (event) => { if (typeof event.downloadRequest === 'string') { @@ -455,7 +455,7 @@ export = { handleDownloadLinksViaCDP, - listenForDocumentDownload, + listenForDownload, writeExtension (browser, isTextTerminal, proxyUrl, socketIoRoute) { debug('writing extension') diff --git a/packages/server/lib/browsers/webkit-automation.ts b/packages/server/lib/browsers/webkit-automation.ts index 28492bd55f43..d06ea86311b3 100644 --- a/packages/server/lib/browsers/webkit-automation.ts +++ b/packages/server/lib/browsers/webkit-automation.ts @@ -110,7 +110,7 @@ export class WebKitAutomation { this.context = this.page.context() await this.page.addInitScript({ - content: `(${utils.listenForDocumentDownload.toString()})()`, + content: `(${utils.listenForDownload.toString()})()`, }) await this.context.exposeBinding('cypressDownloadLinkClicked', (source, downloadUrl) => { diff --git a/system-tests/projects/downloads/cypress/e2e/download_csv.cy.ts b/system-tests/projects/downloads/cypress/e2e/download_csv.cy.ts index 740cad2cfb51..df8486047cbd 100644 --- a/system-tests/projects/downloads/cypress/e2e/download_csv.cy.ts +++ b/system-tests/projects/downloads/cypress/e2e/download_csv.cy.ts @@ -6,7 +6,9 @@ describe('downloads', () => { }) it('downloads cvs file', () => { - // wait 600ms after the click to wait/finish the download of the file - cy.get('[data-cy=download-csv]').click().wait(600) + // Note that we don't wait for the download here. If we ever need to do a wait here to ensure that the download happens, + // we need to make sure that wait is smaller than the proxy correlation timeout. Otherwise, we may be papering over a bug + // in the proxy correlation logic. + cy.get('[data-cy=download-csv]').click() }) }) From 3c85e4369985ec508949032f0b6d2327db2056e4 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Tue, 10 Oct 2023 12:04:09 -0500 Subject: [PATCH 14/15] PR comments --- packages/server/lib/cloud/protocol.ts | 2 +- .../downloads/cypress/e2e/downloads.cy.ts | 12 +++-- system-tests/test/downloads_spec.ts | 45 +++++++------------ 3 files changed, 27 insertions(+), 32 deletions(-) diff --git a/packages/server/lib/cloud/protocol.ts b/packages/server/lib/cloud/protocol.ts index 478a5d887207..d24bcec201b4 100644 --- a/packages/server/lib/cloud/protocol.ts +++ b/packages/server/lib/cloud/protocol.ts @@ -20,7 +20,7 @@ const routes = require('./routes') const debug = Debug('cypress:server:protocol') const debugVerbose = Debug('cypress-verbose:server:protocol') -const CAPTURE_ERRORS = !process.env.CYPRESS_LOCAL_PROTOCOL_PATH +const CAPTURE_ERRORS = process.env.CYPRESS_LOCAL_PROTOCOL_PATH const DELETE_DB = !process.env.CYPRESS_LOCAL_PROTOCOL_PATH // Timeout for upload diff --git a/system-tests/projects/downloads/cypress/e2e/downloads.cy.ts b/system-tests/projects/downloads/cypress/e2e/downloads.cy.ts index aeba6baa966e..1f5ccdaeb626 100644 --- a/system-tests/projects/downloads/cypress/e2e/downloads.cy.ts +++ b/system-tests/projects/downloads/cypress/e2e/downloads.cy.ts @@ -8,19 +8,25 @@ describe('downloads', () => { it('handles csv file download', () => { cy.get('[data-cy=download-csv]').click() cy - .readFile(`${Cypress.config('downloadsFolder')}/records.csv`) + // Note that this timeout is less than the proxy correlation timeout. It needs to be less than that timeout + // to ensure that we don't paper over a bug in the proxy correlation logic. + .readFile(`${Cypress.config('downloadsFolder')}/records.csv`, { timeout: 1000 }) .should('contain', '"Joe","Smith"') }) it('handles zip file download', () => { cy.get('[data-cy=download-zip]').click() // not worth adding a dependency to read contents, just ensure it's there - cy.readFile(`${Cypress.config('downloadsFolder')}/files.zip`) + // Note that this timeout is less than the proxy correlation timeout. It needs to be less than that timeout + // to ensure that we don't paper over a bug in the proxy correlation logic. + cy.readFile(`${Cypress.config('downloadsFolder')}/files.zip`, { timeout: 1000 }) }) it('handles xlsx file download', () => { cy.get('[data-cy=download-xlsx]').click() // not worth adding a dependency to read contents, just ensure it's there - cy.readFile(`${Cypress.config('downloadsFolder')}/people.xlsx`) + // Note that this timeout is less than the proxy correlation timeout. It needs to be less than that timeout + // to ensure that we don't paper over a bug in the proxy correlation logic. + cy.readFile(`${Cypress.config('downloadsFolder')}/people.xlsx`, { timeout: 1000 }) }) }) diff --git a/system-tests/test/downloads_spec.ts b/system-tests/test/downloads_spec.ts index 57749f0eaeec..ec95c1594acb 100644 --- a/system-tests/test/downloads_spec.ts +++ b/system-tests/test/downloads_spec.ts @@ -1,6 +1,6 @@ import path from 'path' -import systemTests, { BrowserName, expect } from '../lib/system-tests' +import systemTests, { expect } from '../lib/system-tests' import Fixtures from '../lib/fixtures' import { fs } from '@packages/server/lib/util/fs' @@ -10,7 +10,6 @@ describe('e2e downloads', () => { systemTests.setup() systemTests.it('handles various file downloads', { - browser: '!webkit', // TODO(webkit): fix+unskip (implement downloads support) project: 'downloads', spec: 'downloads.cy.ts', }) @@ -53,34 +52,24 @@ describe('e2e downloads', () => { expect(exists, `Expected ${filePath} not to exist, but it does`).to.be.false }) - const browsers: BrowserName[] = ['chrome', 'electron', 'firefox', 'webkit'] - - browsers.forEach((browser) => { - it(`does not trash downloads between runs if trashAssetsBeforeRuns: false - ${browser}`, async function () { - await systemTests.exec(this, { - browser, - project: 'downloads', - spec: 'download_csv.cy.ts', - config: { - experimentalWebKitSupport: true, - }, - }) + it('does not trash downloads between runs if trashAssetsBeforeRuns: false', async function () { + await systemTests.exec(this, { + project: 'downloads', + spec: 'download_csv.cy.ts', + }) - // this run should _not_ trash the downloads from the above run - await systemTests.exec(this, { - browser, - project: 'downloads', - spec: 'simple_passing.cy.ts', - config: { - experimentalWebKitSupport: true, - trashAssetsBeforeRuns: false, - }, - }) + // this run should _not_ trash the downloads from the above run + await systemTests.exec(this, { + project: 'downloads', + spec: 'simple_passing.cy.ts', + config: { + trashAssetsBeforeRuns: false, + }, + }) - const filePath = path.join(downloadsProject, 'cypress', 'downloads', 'records.csv') - const exists = await fs.pathExists(filePath) + const filePath = path.join(downloadsProject, 'cypress', 'downloads', 'records.csv') + const exists = await fs.pathExists(filePath) - expect(exists, `Expected ${filePath} to exist, but it does not`).to.be.true - }) + expect(exists, `Expected ${filePath} to exist, but it does not`).to.be.true }) }) From 934c08f7be75f43b87ebdecdb888af8046c90056 Mon Sep 17 00:00:00 2001 From: Ryan Manuel Date: Tue, 10 Oct 2023 13:20:34 -0500 Subject: [PATCH 15/15] Update packages/server/lib/cloud/protocol.ts --- packages/server/lib/cloud/protocol.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/server/lib/cloud/protocol.ts b/packages/server/lib/cloud/protocol.ts index d24bcec201b4..478a5d887207 100644 --- a/packages/server/lib/cloud/protocol.ts +++ b/packages/server/lib/cloud/protocol.ts @@ -20,7 +20,7 @@ const routes = require('./routes') const debug = Debug('cypress:server:protocol') const debugVerbose = Debug('cypress-verbose:server:protocol') -const CAPTURE_ERRORS = process.env.CYPRESS_LOCAL_PROTOCOL_PATH +const CAPTURE_ERRORS = !process.env.CYPRESS_LOCAL_PROTOCOL_PATH const DELETE_DB = !process.env.CYPRESS_LOCAL_PROTOCOL_PATH // Timeout for upload