diff --git a/packages/core/src/domain/configuration/configuration.ts b/packages/core/src/domain/configuration/configuration.ts index d0283fe428..f9fdcd281a 100644 --- a/packages/core/src/domain/configuration/configuration.ts +++ b/packages/core/src/domain/configuration/configuration.ts @@ -63,7 +63,6 @@ export interface Configuration extends TransportConfiguration { // Event limits eventRateLimiterThreshold: number // Limit the maximum number of actions, errors and logs per minutes maxInternalMonitoringMessagesPerPage: number - requestErrorResponseLengthLimit: number // Batch configuration batchBytesLimit: number @@ -108,11 +107,6 @@ export function validateAndBuildConfiguration( eventRateLimiterThreshold: 3000, maxInternalMonitoringMessagesPerPage: 15, - /** - * arbitrary value, byte precision not needed - */ - requestErrorResponseLengthLimit: 32 * ONE_KILO_BYTE, - /** * flush automatically, aim to be lower than ALB connection timeout * to maximize connection reuse. diff --git a/packages/core/test/specHelper.ts b/packages/core/test/specHelper.ts index 06bc7c5f84..9d6f342e34 100644 --- a/packages/core/test/specHelper.ts +++ b/packages/core/test/specHelper.ts @@ -144,15 +144,33 @@ export interface ResponseStubOptions { type?: ResponseType responseText?: string responseTextError?: Error + body?: ReadableStream } function notYetImplemented(): never { throw new Error('not yet implemented') } export class ResponseStub implements Response { - private _bodyUsed = false - - constructor(private options: Readonly) {} + private _body: ReadableStream | undefined + + constructor(private options: Readonly) { + if (this.options.body) { + this._body = this.options.body + } else if (this.options.responseTextError !== undefined) { + this._body = new ReadableStream({ + start: (controller) => { + controller.error(this.options.responseTextError) + }, + }) + } else if (this.options.responseText !== undefined) { + this._body = new ReadableStream({ + start: (controller) => { + controller.enqueue(new TextEncoder().encode(this.options.responseText)) + controller.close() + }, + }) + } + } get status() { return this.options.status ?? 200 @@ -167,19 +185,11 @@ export class ResponseStub implements Response { } get bodyUsed() { - return this._bodyUsed + return this._body ? this._body.locked : false } - text() { - if (this.bodyUsed) { - return Promise.reject(new TypeError("Failed to execute 'text' on 'Response': body stream already read")) - } - this._bodyUsed = true - if (this.options.responseTextError !== undefined) { - return Promise.reject(this.options.responseTextError) - } - - return Promise.resolve(this.options.responseText ?? '') + get body() { + return this._body || null } clone() { @@ -192,6 +202,7 @@ export class ResponseStub implements Response { // Partial implementation, feel free to implement /* eslint-disable @typescript-eslint/member-ordering */ arrayBuffer = notYetImplemented + text = notYetImplemented blob = notYetImplemented formData = notYetImplemented json = notYetImplemented @@ -214,9 +225,6 @@ export class ResponseStub implements Response { get url() { return notYetImplemented() } - get body() { - return notYetImplemented() - } } export type FetchStub = (input: RequestInfo, init?: RequestInit) => FetchStubPromise diff --git a/packages/logs/src/domain/configuration.ts b/packages/logs/src/domain/configuration.ts index ac4f5eb02a..89374ba867 100644 --- a/packages/logs/src/domain/configuration.ts +++ b/packages/logs/src/domain/configuration.ts @@ -1,5 +1,5 @@ import type { Configuration, InitConfiguration } from '@datadog/browser-core' -import { validateAndBuildConfiguration } from '@datadog/browser-core' +import { ONE_KILO_BYTE, validateAndBuildConfiguration } from '@datadog/browser-core' import { buildEnv } from '../boot/buildEnv' import type { LogsEvent } from '../logsEvent.types' @@ -12,8 +12,14 @@ export type HybridInitConfiguration = Omit export interface LogsConfiguration extends Configuration { forwardErrorsToLogs: boolean + requestErrorResponseLengthLimit: number } +/** + * arbitrary value, byte precision not needed + */ +export const DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT = 32 * ONE_KILO_BYTE + export function validateAndBuildLogsConfiguration( initConfiguration: LogsInitConfiguration ): LogsConfiguration | undefined { @@ -26,5 +32,7 @@ export function validateAndBuildLogsConfiguration( ...baseConfiguration, forwardErrorsToLogs: !!initConfiguration.forwardErrorsToLogs, + + requestErrorResponseLengthLimit: DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT, } } diff --git a/packages/logs/src/domain/trackNetworkError.spec.ts b/packages/logs/src/domain/trackNetworkError.spec.ts index f3627fe904..9ca459cedf 100644 --- a/packages/logs/src/domain/trackNetworkError.spec.ts +++ b/packages/logs/src/domain/trackNetworkError.spec.ts @@ -152,10 +152,19 @@ describe('computeXhrResponseData', () => { }) describe('computeFetchResponseText', () => { + let onunhandledrejectionSpy: jasmine.Spy + beforeEach(() => { if (isIE()) { pending('IE does not support the fetch API') } + + onunhandledrejectionSpy = jasmine.createSpy() + window.onunhandledrejection = onunhandledrejectionSpy + }) + + afterEach(() => { + window.onunhandledrejection = null }) it('computes response text from Response objects', (done) => { @@ -185,16 +194,69 @@ describe('computeFetchResponseText', () => { }) }) - it('truncates fetch response text', (done) => { + it('reads a limited amount of bytes from the response', (done) => { + // Creates a response that stream "f" indefinitely, one byte at a time + const cancelSpy = jasmine.createSpy() + const pullSpy = jasmine.createSpy().and.callFake((controller: ReadableStreamDefaultController) => { + controller.enqueue(new TextEncoder().encode('f')) + }) + const response = new ResponseStub({ + body: new ReadableStream({ + pull: pullSpy, + cancel: cancelSpy, + }), + }) + + computeFetchResponseText(response, CONFIGURATION, () => { + expect(pullSpy).toHaveBeenCalledTimes( + // readLimitedAmountOfBytes may read one more byte than necessary to make sure it exceeds the limit + CONFIGURATION.requestErrorResponseLengthLimit + 1 + ) + expect(cancelSpy).toHaveBeenCalledTimes(1) + done() + }) + }) + + it('truncates the response if its size is greater than the limit', (done) => { + const text = 'foobar' computeFetchResponseText( - new ResponseStub({ responseText: 'Lorem ipsum dolor sit amet orci aliquam.' }), - { ...CONFIGURATION, requestErrorResponseLengthLimit: 32 }, - (responseText) => { - expect(responseText).toBe('Lorem ipsum dolor sit amet orci ...') + new ResponseStub({ responseText: text }), + { ...CONFIGURATION, requestErrorResponseLengthLimit: text.length - 1 }, + (responseData) => { + expect(responseData).toBe('fooba...') done() } ) }) + + it('does not truncate the response if its size is equal to the limit', (done) => { + const text = 'foo' + computeFetchResponseText( + new ResponseStub({ responseText: text }), + { ...CONFIGURATION, requestErrorResponseLengthLimit: text.length }, + (responseData) => { + expect(responseData).toBe(text) + done() + } + ) + }) + + it('does not yield an unhandled rejection error if the cancel promise is rejected', (done) => { + // Creates a response that stream "f" indefinitely and fails to be canceled + const response = new ResponseStub({ + body: new ReadableStream({ + pull: (controller) => controller.enqueue(new TextEncoder().encode('f')), + cancel: () => Promise.reject(new Error('foo')), + }), + }) + + computeFetchResponseText(response, CONFIGURATION, () => { + setTimeout(() => { + expect(onunhandledrejectionSpy).not.toHaveBeenCalled() + done() + }) + }) + }) }) describe('computeFetchErrorText', () => { diff --git a/packages/logs/src/domain/trackNetworkError.ts b/packages/logs/src/domain/trackNetworkError.ts index 27cc27e9b7..fd3e943a3c 100644 --- a/packages/logs/src/domain/trackNetworkError.ts +++ b/packages/logs/src/domain/trackNetworkError.ts @@ -7,6 +7,7 @@ import { computeStackTrace, toStackTraceString, monitor, + noop, } from '@datadog/browser-core' import type { LogsConfiguration } from './configuration' @@ -86,13 +87,56 @@ export function computeFetchResponseText( configuration: LogsConfiguration, callback: (responseText?: string) => void ) { - response - .clone() - .text() - .then( - monitor((text) => callback(truncateResponseText(text, configuration))), - monitor((error) => callback(`Unable to retrieve response: ${error as string}`)) + if (!window.TextDecoder) { + // If the browser doesn't support TextDecoder, let's read the whole response then truncate it. + // + // This should only be the case on early versions of Edge (before they migrated to Chromium). + // Even if it could be possible to implement a workaround for the missing TextDecoder API (using + // a Blob and FileReader), we found another issue preventing us from reading only the first + // bytes from the response: contrary to other browsers, when reading from the cloned response, + // if the original response gets canceled, the cloned response is also canceled and we can't + // know about it. In the following illustration, the promise returned by `reader.read()` may + // never be fulfilled: + // + // fetch('/').then((response) => { + // const reader = response.clone().body.getReader() + // readMore() + // function readMore() { + // reader.read().then( + // (result) => { + // if (result.done) { + // console.log('done') + // } else { + // readMore() + // } + // }, + // () => console.log('error') + // ) + // } + // response.body.getReader().cancel() + // }) + response + .clone() + .text() + .then( + monitor((text) => callback(truncateResponseText(text, configuration))), + monitor((error) => callback(`Unable to retrieve response: ${error as string}`)) + ) + } else if (!response.body) { + callback() + } else { + truncateResponseStream( + response.clone().body!, + configuration.requestErrorResponseLengthLimit, + (error, responseText) => { + if (error) { + callback(`Unable to retrieve response: ${(error as unknown) as string}`) + } else { + callback(responseText) + } + } ) + } } function isRejected(request: { status: number; responseType?: string }) { @@ -116,3 +160,84 @@ function format(type: RequestType) { } return 'Fetch' } + +function truncateResponseStream( + stream: ReadableStream, + limit: number, + callback: (error?: Error, responseText?: string) => void +) { + readLimitedAmountOfBytes(stream, limit, (error, bytes, limitExceeded) => { + if (error) { + callback(error) + } else { + let responseText = new TextDecoder().decode(bytes) + if (limitExceeded) { + responseText += '...' + } + callback(undefined, responseText) + } + }) +} + +/** + * Read bytes from a ReadableStream until at least `limit` bytes have been read (or until the end of + * the stream). The callback is invoked with the at most `limit` bytes, and indicates that the limit + * has been exceeded if more bytes were available. + */ +function readLimitedAmountOfBytes( + stream: ReadableStream, + limit: number, + callback: (error?: Error, bytes?: Uint8Array, limitExceeded?: boolean) => void +) { + const reader = stream.getReader() + const chunks: Uint8Array[] = [] + let readBytesCount = 0 + + readMore() + + function readMore() { + reader.read().then( + monitor((result: ReadableStreamReadResult) => { + if (result.done) { + onDone() + return + } + + chunks.push(result.value) + readBytesCount += result.value.length + + if (readBytesCount > limit) { + onDone() + } else { + readMore() + } + }), + monitor((error) => callback(error)) + ) + } + + function onDone() { + reader.cancel().catch( + // we don't care if cancel fails, but we still need to catch the error to avoid reporting it + // as an unhandled rejection + noop + ) + + let completeBuffer: Uint8Array + if (chunks.length === 1) { + // optim: if the response is small enough to fit in a single buffer (provided by the browser), just + // use it directly. + completeBuffer = chunks[0] + } else { + // else, we need to copy buffers into a larger buffer to concatenate them. + completeBuffer = new Uint8Array(readBytesCount) + let offset = 0 + chunks.forEach((chunk) => { + completeBuffer.set(chunk, offset) + offset += chunk.length + }) + } + + callback(undefined, completeBuffer.slice(0, limit), completeBuffer.length > limit) + } +} diff --git a/test/e2e/lib/framework/createTest.ts b/test/e2e/lib/framework/createTest.ts index 658ead0bd7..d8d659620a 100644 --- a/test/e2e/lib/framework/createTest.ts +++ b/test/e2e/lib/framework/createTest.ts @@ -31,6 +31,7 @@ interface TestContext { crossOriginUrl: string serverEvents: EventRegistry bridgeEvents: EventRegistry + servers: Servers } type TestRunner = (testContext: TestContext) => Promise @@ -178,6 +179,7 @@ function createTestContext(servers: Servers): TestContext { crossOriginUrl: servers.crossOrigin.url, serverEvents: new EventRegistry(), bridgeEvents: new EventRegistry(), + servers, } } diff --git a/test/e2e/lib/framework/httpServers.ts b/test/e2e/lib/framework/httpServers.ts index 6070833284..becfd88b31 100644 --- a/test/e2e/lib/framework/httpServers.ts +++ b/test/e2e/lib/framework/httpServers.ts @@ -9,18 +9,23 @@ const MAX_SERVER_CREATION_RETRY = 5 const PORT_MIN = 9200 const PORT_MAX = 9400 -type ServerApp = (req: http.IncomingMessage, res: http.ServerResponse) => void +export type ServerApp = (req: http.IncomingMessage, res: http.ServerResponse) => void -export interface Server { +export type MockServerApp = ServerApp & { + getLargeResponseWroteSize(): number +} + +export interface Server { url: string - bindServerApp(serverApp: ServerApp): void + app: App + bindServerApp(serverApp: App): void waitForIdle(): Promise } export interface Servers { - base: Server - intake: Server - crossOrigin: Server + base: Server + intake: Server + crossOrigin: Server } let serversSingleton: undefined | Servers @@ -41,10 +46,10 @@ export async function waitForServersIdle() { return Promise.all([servers.base.waitForIdle(), servers.crossOrigin.waitForIdle(), servers.intake.waitForIdle()]) } -async function createServer(): Promise { +async function createServer(): Promise> { const server = await instantiateServer() const { address, port } = server.address() as AddressInfo - let serverApp: ServerApp | undefined + let serverApp: App | undefined server.on('request', (req: http.IncomingMessage, res: http.ServerResponse) => { if (serverApp) { @@ -60,9 +65,15 @@ async function createServer(): Promise { }) return { - bindServerApp(newServerApp: ServerApp) { + bindServerApp(newServerApp: App) { serverApp = newServerApp }, + get app() { + if (!serverApp) { + throw new Error('no server app bound') + } + return serverApp + }, url: `http://${address}:${port}`, waitForIdle: createServerIdleWaiter(server), } diff --git a/test/e2e/lib/framework/serverApps/mock.ts b/test/e2e/lib/framework/serverApps/mock.ts index f463f664d2..dcc2ae210e 100644 --- a/test/e2e/lib/framework/serverApps/mock.ts +++ b/test/e2e/lib/framework/serverApps/mock.ts @@ -2,10 +2,13 @@ import * as url from 'url' import cors from 'cors' import express from 'express' import { buildLogs, buildNpm, buildRum, buildRumSlim } from '../sdkBuilds' -import type { Servers } from '../httpServers' +import type { MockServerApp, Servers } from '../httpServers' -export function createMockServerApp(servers: Servers, setup: string) { +const LARGE_RESPONSE_MIN_BYTE_SIZE = 100_000 + +export function createMockServerApp(servers: Servers, setup: string): MockServerApp { const app = express() + let largeResponseBytesWritten = 0 app.use(cors()) app.disable('etag') // disable automatic resource caching @@ -22,6 +25,36 @@ export function createMockServerApp(servers: Servers, setup: string) { res.status(500).send('Server error') }) + app.get('/throw-large-response', (_req, res) => { + res.status(500) + + const chunkText = 'Server error\n'.repeat(50) + let bytesWritten = 0 + let timeoutId: NodeJS.Timeout + + res.on('close', () => { + largeResponseBytesWritten = bytesWritten + clearTimeout(timeoutId) + }) + + function writeMore() { + res.write(chunkText, (error) => { + if (error) { + console.log('Write error', error) + } else { + bytesWritten += chunkText.length + if (bytesWritten < LARGE_RESPONSE_MIN_BYTE_SIZE) { + timeoutId = setTimeout(writeMore, 10) + } else { + res.end() + } + } + }) + } + + writeMore() + }) + app.get('/unknown', (_req, res) => { res.status(404).send('Not found') }) @@ -76,5 +109,9 @@ export function createMockServerApp(servers: Servers, setup: string) { res.header('content-type', 'application/javascript').send(await buildNpm(servers.intake.url)) }) - return app + return Object.assign(app, { + getLargeResponseWroteSize() { + return largeResponseBytesWritten + }, + }) } diff --git a/test/e2e/scenario/logs.scenario.ts b/test/e2e/scenario/logs.scenario.ts index 0c9ff6be19..a48ac1317c 100644 --- a/test/e2e/scenario/logs.scenario.ts +++ b/test/e2e/scenario/logs.scenario.ts @@ -1,3 +1,4 @@ +import { DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT } from '@datadog/browser-logs/cjs/domain/configuration' import { createTest } from '../lib/framework' import { UNREACHABLE_URL } from '../lib/helpers/constants' import { browserExecute, browserExecuteAsync, flushBrowserLogs, withBrowserLogs } from '../lib/helpers/browser' @@ -75,6 +76,50 @@ describe('logs', () => { }) }) + createTest('read only the first bytes of the response') + .withLogs({ forwardErrorsToLogs: true }) + .run(async ({ serverEvents, baseUrl, servers }) => { + await browserExecuteAsync((done) => { + fetch('/throw-large-response').then( + (response) => { + // The body stream needs to be cancelled, else the browser will still download the whole + // response even if it is unused. + response + .body!.getReader() + .cancel() + .catch((error) => console.log(error)) + done(undefined) + }, + (error) => console.log(error) + ) + }) + + await flushEvents() + expect(serverEvents.logs.length).toBe(1) + expect(serverEvents.logs[0].message).toBe(`Fetch error GET ${baseUrl}/throw-large-response`) + expect(serverEvents.logs[0].error?.origin).toBe('network') + + const ellipsisSize = 3 + expect(serverEvents.logs[0].error?.stack?.length).toBe(DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT + ellipsisSize) + + expect(servers.base.app.getLargeResponseWroteSize()).toBeLessThan( + // When reading the request, chunks length are probably not aligning perfectly with the + // response length limit, so it sends few more bytes than necessary. Add a 50% margin of + // error to verify that it's still close to the expected limit. + DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT * 1.5 + ) + expect(servers.base.app.getLargeResponseWroteSize()).toBeGreaterThanOrEqual( + DEFAULT_REQUEST_ERROR_RESPONSE_LENGTH_LIMIT + ) + + await withBrowserLogs((browserLogs) => { + // Some browser report two errors: + // * the server responded with a status of 500 + // * canceling the body stream is reported as a network error (net::ERR_FAILED) + expect(browserLogs.length).toBeGreaterThanOrEqual(1) + }) + }) + createTest('track fetch error') .withLogs({ forwardErrorsToLogs: true }) .run(async ({ serverEvents, baseUrl }) => {