From c816af234cc57ac774123936a5c67953ebf93147 Mon Sep 17 00:00:00 2001 From: Alex Kamaev Date: Mon, 4 Sep 2023 16:46:00 +0400 Subject: [PATCH] should log concurrent requests (closes #7977) --- src/api/request-hooks/request-logger.ts | 8 +++-- .../request-paused-event-based.ts | 2 +- .../regression/gh-7977/pages/index.html | 19 ++++++++++++ .../fixtures/regression/gh-7977/test.js | 30 +++++++++++++++++++ .../gh-7977/testcafe-fixtures/index.js | 21 +++++++++++++ .../testcafe-fixtures/requestCounter.js | 12 ++++++++ 6 files changed, 89 insertions(+), 3 deletions(-) create mode 100644 test/functional/fixtures/regression/gh-7977/pages/index.html create mode 100644 test/functional/fixtures/regression/gh-7977/test.js create mode 100644 test/functional/fixtures/regression/gh-7977/testcafe-fixtures/index.js create mode 100644 test/functional/fixtures/regression/gh-7977/testcafe-fixtures/requestCounter.js diff --git a/src/api/request-hooks/request-logger.ts b/src/api/request-hooks/request-logger.ts index 3da73c6b4de..2cf8cd61ff9 100644 --- a/src/api/request-hooks/request-logger.ts +++ b/src/api/request-hooks/request-logger.ts @@ -80,6 +80,10 @@ class RequestLoggerImplementation extends RequestHook { throw new APIError('RequestLogger', RUNTIME_ERRORS.requestHookConfigureAPIError, 'RequestLogger', 'Cannot stringify the response body because it is not logged. Specify { logResponseBody: true } in log options.'); } + private static _getInternalRequestKey ({ requestId, sessionId }: any): string { + return `${sessionId}:${requestId}`; + } + public async onRequest (event: RequestEvent): Promise { const loggedReq: LoggedRequest = { id: event._requestInfo.requestId, @@ -98,11 +102,11 @@ class RequestLoggerImplementation extends RequestHook { if (this._options.logRequestBody) loggedReq.request.body = this._options.stringifyRequestBody ? event._requestInfo.body.toString() : event._requestInfo.body; - this._internalRequests[loggedReq.id] = loggedReq; + this._internalRequests[RequestLoggerImplementation._getInternalRequestKey(event._requestInfo)] = loggedReq; } public async onResponse (event: ResponseEvent): Promise { - const loggedReq = this._internalRequests[event.requestId]; + const loggedReq = this._internalRequests[RequestLoggerImplementation._getInternalRequestKey(event)]; // NOTE: If the 'clear' method is called during a long running request, // we should not save a response part - request part has been already removed. diff --git a/src/native-automation/request-hooks/event-factory/request-paused-event-based.ts b/src/native-automation/request-hooks/event-factory/request-paused-event-based.ts index 74c628c9313..ccb541adb91 100644 --- a/src/native-automation/request-hooks/event-factory/request-paused-event-based.ts +++ b/src/native-automation/request-hooks/event-factory/request-paused-event-based.ts @@ -121,7 +121,7 @@ export default class RequestPausedEventBasedEventFactory extends BaseRequestHook statusCode: this._event.responseStatusCode || StatusCodes.OK, headers: convertToOutgoingHttpHeaders(this._event.responseHeaders), body: this._responseBody, - sessionId: '', + sessionId: this._sessionId, requestId: this._event.requestId, isSameOriginPolicyFailed: false, }); diff --git a/test/functional/fixtures/regression/gh-7977/pages/index.html b/test/functional/fixtures/regression/gh-7977/pages/index.html new file mode 100644 index 00000000000..3ddb1e54726 --- /dev/null +++ b/test/functional/fixtures/regression/gh-7977/pages/index.html @@ -0,0 +1,19 @@ + + + + + gh-7977 + + + + + + diff --git a/test/functional/fixtures/regression/gh-7977/test.js b/test/functional/fixtures/regression/gh-7977/test.js new file mode 100644 index 00000000000..70a3f4571cb --- /dev/null +++ b/test/functional/fixtures/regression/gh-7977/test.js @@ -0,0 +1,30 @@ +const createTestCafe = require('../../../../../lib'); +const { onlyInNativeAutomation } = require('../../../utils/skip-in'); +const path = require('path'); +const expect = require('chai').expect; + +const EXPECTED_REQUEST_COUNT = 300; + +let testcafe = null; + +describe('[Regression](GH-7977)', function () { + onlyInNativeAutomation('Should log all concurrent requests', function () { + return createTestCafe('127.0.0.1', 1335, 1336) + .then(tc => { + testcafe = tc; + }) + .then(() => { + return testcafe.createRunner() + .browsers(`chrome:headless`) + .concurrency(3) + .src(path.join(__dirname, './testcafe-fixtures/index.js')) + .run(); + }) + .then(() => { + return testcafe.close(); + }) + .then(() => { + expect(require('./testcafe-fixtures/requestCounter').get()).eql(EXPECTED_REQUEST_COUNT); + }); + }); +}); diff --git a/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/index.js b/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/index.js new file mode 100644 index 00000000000..83ad6a35cc0 --- /dev/null +++ b/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/index.js @@ -0,0 +1,21 @@ +import { RequestLogger } from 'testcafe'; + +const logger = new RequestLogger(/api\/data/, { + logResponseBody: true, + logRequestHeaders: true, + stringifyResponseBody: true, +}); + +fixture `Concurrent request loggers` + .page `http://localhost:3000/fixtures/regression/gh-7977/pages/index.html` + .requestHooks(logger); + +for (let i = 0; i < 3; i++) { + test(`send multiple requests - ${i}`, async t => { + await t.click('button'); + + require('./requestCounter').add(logger.requests.filter(r => !!r.response.body).length); + }); +} + + diff --git a/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/requestCounter.js b/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/requestCounter.js new file mode 100644 index 00000000000..6920871ecd7 --- /dev/null +++ b/test/functional/fixtures/regression/gh-7977/testcafe-fixtures/requestCounter.js @@ -0,0 +1,12 @@ +let count = 0; + +const requestCounter = { + add (value) { + count += value; + }, + get () { + return count; + }, +}; + +module.exports = requestCounter;