From 8d21931e9a00e68a469271d60f34f395d80a88ec Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Fri, 30 Jun 2023 15:14:10 +0200 Subject: [PATCH 01/19] feat: CXSPA-2067 SSR Logging - Trace Context --- .../default-express-server-logger.spec.ts | 174 +++++++++--------- .../loggers/default-express-server-logger.ts | 5 + .../parse-traceparent.spec.ts | 36 ++++ .../w3c-trace-context/parse-traceparent.ts | 31 ++++ .../w3c-trace-context.model.ts | 17 ++ .../optimized-ssr-engine.spec.ts | 116 +++++++++++- .../optimized-engine/optimized-ssr-engine.ts | 35 +++- 7 files changed, 324 insertions(+), 90 deletions(-) create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts diff --git a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.spec.ts b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.spec.ts index 52f8ce642f7..2820daa60a1 100644 --- a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.spec.ts +++ b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.spec.ts @@ -7,7 +7,16 @@ const request = { res: { locals: { cx: { - request: { uuid: 'test', timeReceived: new Date('2023-05-26') }, + request: { + uuid: 'test', + timeReceived: new Date('2023-05-26'), + traceContext: { + version: '00', + traceId: 'd745f6735b44e81c0ae5410cb1fc8a0c', + parentId: '1b527c3828976b39', + traceFlags: '01', + }, + }, }, }, }, @@ -26,60 +35,6 @@ describe('DefaultExpressServerLogger', () => { expect(logger).toBeDefined(); }); - it('should log message', () => { - const logSpy = jest.spyOn(console, 'log').mockImplementation(() => {}); - - logger.log('test', { request: {} as Request }); - - expect(logSpy).toHaveBeenCalledWith( - logger['stringifyWithContext']('test', { request: {} as Request }) - ); - }); - - it('should warn message', () => { - const warnSpy = jest.spyOn(console, 'warn').mockImplementation(() => {}); - - logger.warn('test', { request: {} as Request }); - - expect(warnSpy).toHaveBeenCalledWith( - logger['stringifyWithContext']('test', { request: {} as Request }) - ); - }); - - it('should error message', () => { - const errorSpy = jest - .spyOn(console, 'error') - .mockImplementation(() => {}); - - logger.error('test', { request: {} as Request }); - - expect(errorSpy).toHaveBeenCalledWith( - logger['stringifyWithContext']('test', { request: {} as Request }) - ); - }); - - it('should info message', () => { - const infoSpy = jest.spyOn(console, 'info').mockImplementation(() => {}); - - logger.info('test', { request: {} as Request }); - - expect(infoSpy).toHaveBeenCalledWith( - logger['stringifyWithContext']('test', { request: {} as Request }) - ); - }); - - it('should debug message', () => { - const debugSpy = jest - .spyOn(console, 'debug') - .mockImplementation(() => {}); - - logger.debug('test', { request: {} as Request }); - - expect(debugSpy).toHaveBeenCalledWith( - logger['stringifyWithContext']('test', { request: {} as Request }) - ); - }); - describe('is not dev mode', () => { beforeEach(() => { jest.spyOn(angularCore, 'isDevMode').mockReturnValue(false); @@ -94,7 +49,7 @@ describe('DefaultExpressServerLogger', () => { expect(debugSpy.mock.lastCall).toMatchInlineSnapshot(` [ - "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z"}}}", + "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z","traceContext":{"version":"00","traceId":"d745f6735b44e81c0ae5410cb1fc8a0c","parentId":"1b527c3828976b39","traceFlags":"01"}}}}", ] `); }); @@ -108,7 +63,7 @@ describe('DefaultExpressServerLogger', () => { expect(debugSpy.mock.lastCall).toMatchInlineSnapshot(` [ - "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z"}}}", + "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z","traceContext":{"version":"00","traceId":"d745f6735b44e81c0ae5410cb1fc8a0c","parentId":"1b527c3828976b39","traceFlags":"01"}}}}", ] `); }); @@ -122,23 +77,12 @@ describe('DefaultExpressServerLogger', () => { expect(debugSpy.mock.lastCall).toMatchInlineSnapshot(` [ - "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z"}}}", + "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z","traceContext":{"version":"00","traceId":"d745f6735b44e81c0ae5410cb1fc8a0c","parentId":"1b527c3828976b39","traceFlags":"01"}}}}", ] `); }); it('should info proper shape of the JSON', () => { - const request = { - originalUrl: 'test', - res: { - locals: { - cx: { - request: { uuid: 'test', timeReceived: new Date() }, - }, - }, - }, - } as unknown as Request; - const debugSpy = jest .spyOn(console, 'info') .mockImplementation(() => {}); @@ -147,7 +91,7 @@ describe('DefaultExpressServerLogger', () => { expect(debugSpy.mock.lastCall).toMatchInlineSnapshot(` [ - "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z"}}}", + "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z","traceContext":{"version":"00","traceId":"d745f6735b44e81c0ae5410cb1fc8a0c","parentId":"1b527c3828976b39","traceFlags":"01"}}}}", ] `); }); @@ -161,7 +105,7 @@ describe('DefaultExpressServerLogger', () => { expect(debugSpy.mock.lastCall).toMatchInlineSnapshot(` [ - "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z"}}}", + "{"message":"test","context":{"timestamp":"2023-05-26T00:00:00.000Z","request":{"url":"test","uuid":"test","timeReceived":"2023-05-26T00:00:00.000Z","traceContext":{"version":"00","traceId":"d745f6735b44e81c0ae5410cb1fc8a0c","parentId":"1b527c3828976b39","traceFlags":"01"}}}}", ] `); }); @@ -188,7 +132,13 @@ describe('DefaultExpressServerLogger', () => { "request": { "url": "test", "uuid": "test", - "timeReceived": "2023-05-26T00:00:00.000Z" + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "version": "00", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "parentId": "1b527c3828976b39", + "traceFlags": "01" + } } } }", @@ -212,7 +162,13 @@ describe('DefaultExpressServerLogger', () => { "request": { "url": "test", "uuid": "test", - "timeReceived": "2023-05-26T00:00:00.000Z" + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "version": "00", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "parentId": "1b527c3828976b39", + "traceFlags": "01" + } } } }", @@ -236,7 +192,13 @@ describe('DefaultExpressServerLogger', () => { "request": { "url": "test", "uuid": "test", - "timeReceived": "2023-05-26T00:00:00.000Z" + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "version": "00", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "parentId": "1b527c3828976b39", + "traceFlags": "01" + } } } }", @@ -260,7 +222,13 @@ describe('DefaultExpressServerLogger', () => { "request": { "url": "test", "uuid": "test", - "timeReceived": "2023-05-26T00:00:00.000Z" + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "version": "00", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "parentId": "1b527c3828976b39", + "traceFlags": "01" + } } } }", @@ -284,7 +252,13 @@ describe('DefaultExpressServerLogger', () => { "request": { "url": "test", "uuid": "test", - "timeReceived": "2023-05-26T00:00:00.000Z" + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "version": "00", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "parentId": "1b527c3828976b39", + "traceFlags": "01" + } } } }", @@ -303,7 +277,7 @@ describe('DefaultExpressServerLogger', () => { it('should return message with request', () => { const logMessage = logger['stringifyWithContext']('test', { - request: {} as Request, + request, }); expect(logMessage).toContain('request'); @@ -331,6 +305,12 @@ describe('DefaultExpressServerLogger', () => { { "request": { "timeReceived": 2023-05-26T00:00:00.000Z, + "traceContext": { + "parentId": "1b527c3828976b39", + "traceFlags": "01", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "version": "00", + }, "url": "test", "uuid": "test", }, @@ -342,23 +322,47 @@ describe('DefaultExpressServerLogger', () => { describe('map request', () => { it('should return mapped request', () => { - const request = { + const mappedRequest = logger['mapRequest'](request); + + expect(mappedRequest).toMatchInlineSnapshot(` + { + "timeReceived": 2023-05-26T00:00:00.000Z, + "traceContext": { + "parentId": "1b527c3828976b39", + "traceFlags": "01", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "version": "00", + }, + "url": "test", + "uuid": "test", + } + `); + }); + + it('should return mapped request without traceContext prop if traceparent is not available', () => { + const requestWithoutTraceContext = { originalUrl: 'test', res: { locals: { cx: { - request: { uuid: 'test', timeReceived: new Date() }, + request: { + uuid: 'test', + timeReceived: new Date('2023-05-26'), + }, }, }, }, - } as any; + } as unknown as Request; - const mappedRequest = logger['mapRequest'](request); + const mappedRequest = logger['mapRequest'](requestWithoutTraceContext); - expect(mappedRequest).toEqual({ - url: 'test', - ...request.res?.locals.cx.request, - }); + expect(mappedRequest).toMatchInlineSnapshot(` + { + "timeReceived": 2023-05-26T00:00:00.000Z, + "url": "test", + "uuid": "test", + } + `); }); }); }); diff --git a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts index d6b7fc82b2f..037cade2f0a 100644 --- a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts +++ b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts @@ -16,6 +16,11 @@ import { * Default logger used in SSR (ExpressJS) to enhance logs visible e.g. in monitoring tools e.g. Kibana. * It outputs a JSON with properties "message" and "context", * which contains a "timestamp" and details of the "request" ("url", "uuid", "timeReceived") + * + * The output "context" JSON will contain also a property "traceContext" + * with "traceId", "parentId", "version" and "traceFlags", + * if only the given request has the special header "traceparent" (specifed in + * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header ). */ export class DefaultExpressServerLogger implements ExpressServerLogger { log(message: string, context: ExpressServerLoggerContext): void { diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts new file mode 100644 index 00000000000..7ecbfde6f58 --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts @@ -0,0 +1,36 @@ +import { parseTraceparent } from './parse-traceparent'; + +describe('parseTraceparent', () => { + it('should return null if traceparent is not a string', () => { + const result = parseTraceparent({} as string); + + expect(result).toBeNull(); + }); + + it('should return null if traceparent is not 55 characters long', () => { + const shorterString = '0'.repeat(54); + const longerString = '0'.repeat(56); + + const resultWithShorterString = parseTraceparent(shorterString); + const resultWithLongerString = parseTraceparent(longerString); + + expect(resultWithShorterString).toBeNull(); + expect(resultWithLongerString).toBeNull(); + }); + + it('should parse traceparent correctly', () => { + const traceparent = + '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'; + + const result = parseTraceparent(traceparent); + + expect(result).toMatchInlineSnapshot(` + { + "parentId": "b7ad6b7169203331", + "traceFlags": "01", + "traceId": "0af7651916cd43dd8448eb211c80319c", + "version": "00", + } + `); + }); +}); diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts new file mode 100644 index 00000000000..64ab29f9a5e --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts @@ -0,0 +1,31 @@ +import { W3cTraceContext } from './w3c-trace-context.model'; + +/** + * Maps traceparent header to object with properties version, traceId, spanId and traceFlags. + * + * @param traceparent + * @returns Params of the traceparent header + * + * @see https://www.w3.org/TR/trace-context/#traceparent-header-field-values + */ +export const parseTraceparent = ( + traceparent: string +): W3cTraceContext | null => { + if (typeof traceparent !== 'string' || traceparent.length !== 55) { + return null; + } + + // Specific ranges of the traceparent header parameters calculated based on the official documentation + // See https://www.w3.org/TR/trace-context/#traceparent-header-field-values + const versionRange: [number, number] = [0, 2]; + const traceIdRange: [number, number] = [3, 35]; + const parentIdRange: [number, number] = [36, 52]; + const traceFlagsRange: [number, number] = [53, 55]; + + const version = traceparent.substring(...versionRange); + const traceId = traceparent.substring(...traceIdRange); + const parentId = traceparent.substring(...parentIdRange); + const traceFlags = traceparent.substring(...traceFlagsRange); + + return { version, traceId, parentId, traceFlags }; +}; diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts new file mode 100644 index 00000000000..167c3bb9b29 --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts @@ -0,0 +1,17 @@ +/** + * W3cTraceContext is used for log message in server side rendering. + * It contains values of traceparent header. + * + * @property version - version of traceparent header + * @property traceId - traceId of traceparent header + * @property parentId - spanId of traceparent header + * @property traceFlags - traceFlags of traceparent header + * + * @see https://www.w3.org/TR/trace-context/#traceparent-header-field + */ +export interface W3cTraceContext { + version: string; + traceId: string; + parentId: string; + traceFlags: string; +} diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts index ac97df28ba5..b26aa4425ee 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts @@ -1,6 +1,7 @@ /// import { fakeAsync, flush, tick } from '@angular/core/testing'; +import crypto from 'crypto'; import { Application, Request, Response } from 'express'; import { IncomingHttpHeaders } from 'http'; import { Socket } from 'net'; @@ -1175,9 +1176,120 @@ describe('OptimizedSsrEngine', () => { }); }); + describe('getRequestContext', () => { + let dateSpy: jest.SpyInstance; + let randomUUIDSpy: jest.SpyInstance; + const mockDate = new Date('2023-05-26'); + + beforeEach(() => { + dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); + randomUUIDSpy = jest + .spyOn(crypto, 'randomUUID') + .mockReturnValue('ad90db04-a501-4dc5-9b4e-2cc2ab10d49c'); + }); + + afterEach(() => { + dateSpy.mockReset(); + randomUUIDSpy.mockReset(); + }); + + const headers: Record = { + traceparent: '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01', + }; + const request = { + originalUrl: 'test', + headers, + get: (header: string): string | string[] | null | undefined => { + return headers[header]; + }, + } as unknown as Request; + + it('should receive request context', () => { + const engineRunner = new TestEngineRunner({}); + const result = + engineRunner.optimizedSsrEngine['getRequestContext'](request); + + expect(result).toMatchInlineSnapshot(` + { + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "parentId": "1b527c3828976b39", + "traceFlags": "01", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "version": "00", + }, + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + }); + + it('should receive request context without traceContext if traceparent is missing', () => { + const requestWithoutTraceparentHeader = { + ...request, + get: (_header: string): string | string[] | null | undefined => { + return undefined; + }, + } as unknown as Request; + + const engineRunner = new TestEngineRunner({}); + const result = engineRunner.optimizedSsrEngine['getRequestContext']( + requestWithoutTraceparentHeader + ); + + expect(result).toMatchInlineSnapshot(` + { + "timeReceived": "2023-05-26T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + }); + + it('should add requestContext to the request', fakeAsync(() => { + const requestContext = { + timeReceived: '1970-01-01T00:00:00.500Z', + traceContext: { + parentId: '1b527c3828976b39', + traceFlags: '01', + traceId: 'd745f6735b44e81c0ae5410cb1fc8a0c', + version: '00', + }, + uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', + }; + + const engineRunner = new TestEngineRunner({}); + jest.spyOn(engineRunner.optimizedSsrEngine as any, 'log'); + + engineRunner.request('test', { httpHeaders: headers }); + tick(200); + expect(engineRunner.optimizedSsrEngine['log']).toHaveBeenCalledWith( + 'Rendering started (test)', + true, + expect.objectContaining({ + request: expect.objectContaining({ + res: expect.objectContaining({ + locals: { cx: { request: requestContext } }, + }), + }), + }) + ); + })); + }); + describe('logger option', () => { + let dateSpy: jest.SpyInstance; + + beforeEach(() => { + const mockDate = new Date('2023-05-26'); + dateSpy = jest + .spyOn(global, 'Date') + .mockImplementationOnce(() => mockDate); + }); + + afterEach(() => { + dateSpy.mockReset(); + }); + it('should use ExpressServerLogger if logger is true', () => { - jest.useFakeTimers().setSystemTime(new Date('2023-05-26')); new TestEngineRunner({ logger: true, }); @@ -1201,6 +1313,7 @@ describe('OptimizedSsrEngine', () => { ] `); }); + it('should use the provided logger', () => { new TestEngineRunner({ logger: new MockExpressServerLogger() as ExpressServerLogger, @@ -1222,6 +1335,7 @@ describe('OptimizedSsrEngine', () => { ] `); }); + it('should use the legacy server logger, if logger option not specified', () => { new TestEngineRunner({}); expect(consoleLogSpy.mock.lastCall).toMatchInlineSnapshot(` diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index 8faa7c2f275..af56fc81ff0 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -17,6 +17,7 @@ import { ExpressServerLoggerContext, LegacyExpressServerLogger, } from '../logger'; +import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; import { getLoggableSsrOptimizationOptions } from './get-loggable-ssr-optimization-options'; import { RenderingCache } from './rendering-cache'; import { @@ -254,11 +255,9 @@ export class OptimizedSsrEngine { options: any, callback: SsrCallbackFn ): void { - const requestContext = { - uuid: randomUUID(), - timeReceived: new Date().toISOString(), + options.req.res.locals = { + cx: { request: this.getRequestContext(options.req) }, }; - options.req.res.locals = { cx: { request: requestContext } }; const request: Request = options.req; const response: Response = options.req.res; @@ -485,6 +484,34 @@ export class OptimizedSsrEngine { }); } + /** + * Returns the request context object, which is used to enrich the logs. + * It contains the request's UUID, timestamp and trace context (if available). + * The trace context is parsed from the `traceparent` header, which is specified in + * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header + * for more details. + * @param request - the request object + * @returns the context of the request + * @private + */ + private getRequestContext(request: Request): ExpressServerLoggerContext { + request.headers.traceparent = + '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01'; + const requestContext: ExpressServerLoggerContext = { + uuid: randomUUID(), + timeReceived: new Date().toISOString(), + }; + + const traceparent = request.get('traceparent'); + if (traceparent) { + const traceContext = parseTraceparent(traceparent); + if (traceContext) { + requestContext.traceContext = traceContext; + } + } + return requestContext; + } + //CXSPA-3680 - remove this method in 7.0 private initLogger(ssrOptions: SsrOptimizationOptions | undefined) { if (ssrOptions?.logger === true) { From 11ff1c6f288e237b8545b6538836f90f03998097 Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" Date: Fri, 30 Jun 2023 13:17:53 +0000 Subject: [PATCH 02/19] Add license header --- .../logger/loggers/w3c-trace-context/parse-traceparent.ts | 6 ++++++ .../loggers/w3c-trace-context/w3c-trace-context.model.ts | 6 ++++++ 2 files changed, 12 insertions(+) diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts index 64ab29f9a5e..42177727aca 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts @@ -1,3 +1,9 @@ +/* + * SPDX-FileCopyrightText: 2023 SAP Spartacus team + * + * SPDX-License-Identifier: Apache-2.0 + */ + import { W3cTraceContext } from './w3c-trace-context.model'; /** diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts index 167c3bb9b29..03121ce4b9b 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/w3c-trace-context.model.ts @@ -1,3 +1,9 @@ +/* + * SPDX-FileCopyrightText: 2023 SAP Spartacus team + * + * SPDX-License-Identifier: Apache-2.0 + */ + /** * W3cTraceContext is used for log message in server side rendering. * It contains values of traceparent header. From 2128942f1af17dac2f2affbe5b8bb3c6ec5ecf29 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Fri, 30 Jun 2023 15:27:11 +0200 Subject: [PATCH 03/19] remove testin property --- core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts | 2 -- 1 file changed, 2 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index af56fc81ff0..54763f857a9 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -495,8 +495,6 @@ export class OptimizedSsrEngine { * @private */ private getRequestContext(request: Request): ExpressServerLoggerContext { - request.headers.traceparent = - '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01'; const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), From 4f070d49c1704f8e4ebd49197b158a25508e6e70 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Tue, 8 Aug 2023 11:21:03 +0200 Subject: [PATCH 04/19] adding more secure parser + refactor after review --- .../ng-express-engine-decorator.spec.ts | 2 +- .../invalid-traceparent-format-error.spec.ts | 8 ++++ .../invalid-traceparent-format-error.ts | 8 ++++ .../invalid-traceparent-length-error.spec.ts | 15 ++++++++ .../invalid-traceparent-length-error.ts | 11 ++++++ .../parse-traceparent.spec.ts | 34 ++++++++++++++--- .../w3c-trace-context/parse-traceparent.ts | 38 ++++++++++--------- .../optimized-ssr-engine.spec.ts | 23 +++++------ .../optimized-engine/optimized-ssr-engine.ts | 12 +++--- 9 files changed, 110 insertions(+), 41 deletions(-) create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.spec.ts create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.spec.ts create mode 100644 core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts diff --git a/core-libs/setup/ssr/engine-decorator/ng-express-engine-decorator.spec.ts b/core-libs/setup/ssr/engine-decorator/ng-express-engine-decorator.spec.ts index ac2cb1281a1..a89cac4dc0e 100644 --- a/core-libs/setup/ssr/engine-decorator/ng-express-engine-decorator.spec.ts +++ b/core-libs/setup/ssr/engine-decorator/ng-express-engine-decorator.spec.ts @@ -100,7 +100,7 @@ describe('decorateExpressEngine', () => { req: { protocol: 'https', originalUrl: '/electronics/en/USD/cart', - get: jest.fn(() => 'site.com'), + get: jest.fn(() => {}), app, connection: {}, res: >{ diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.spec.ts new file mode 100644 index 00000000000..438c1dca904 --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.spec.ts @@ -0,0 +1,8 @@ +import { InvalidTraceparentFormatError } from './invalid-traceparent-format-error'; + +describe('InvalidTraceparentFormatError', () => { + it('should be an instance of InstantiationError', () => { + const error = new InvalidTraceparentFormatError(); + expect(error).toBeInstanceOf(InvalidTraceparentFormatError); + }); +}); diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts new file mode 100644 index 00000000000..5a96e986ea1 --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts @@ -0,0 +1,8 @@ +/** + * Error thrown when the traceparent header has an invalid format. + */ +export class InvalidTraceparentFormatError extends Error { + constructor() { + super('Traceparent header has invalid format.'); + } +} diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.spec.ts new file mode 100644 index 00000000000..c0b10ff396c --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.spec.ts @@ -0,0 +1,15 @@ +import { InvalidTraceparentLengthError } from './invalid-traceparent-length-error'; + +describe('InvalidTraceparentFormatError', () => { + it('should be an instance of InstantiationError', () => { + const error = new InvalidTraceparentLengthError(0); + expect(error).toBeInstanceOf(InvalidTraceparentLengthError); + }); + + it('should have the correct message', () => { + const error = new InvalidTraceparentLengthError(20); + expect(error.message).toBe( + `Traceparent header has invalid length: ${20}. Expected 55 characters.` + ); + }); +}); diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts new file mode 100644 index 00000000000..b071831db29 --- /dev/null +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts @@ -0,0 +1,11 @@ +/** + * Error thrown when the traceparent header has an invalid length. + * @param traceparentLength The length of the traceparent header. + */ +export class InvalidTraceparentLengthError extends Error { + constructor(traceparentLength: number) { + super( + `Traceparent header has invalid length: ${traceparentLength}. Expected 55 characters.` + ); + } +} diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts index 7ecbfde6f58..d1ee3b08f88 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts @@ -1,3 +1,5 @@ +import { InvalidTraceparentFormatError } from './errors/invalid-traceparent-format-error'; +import { InvalidTraceparentLengthError } from './errors/invalid-traceparent-length-error'; import { parseTraceparent } from './parse-traceparent'; describe('parseTraceparent', () => { @@ -7,15 +9,37 @@ describe('parseTraceparent', () => { expect(result).toBeNull(); }); - it('should return null if traceparent is not 55 characters long', () => { + it('should throw an error if traceparent is not 55 characters long', () => { const shorterString = '0'.repeat(54); const longerString = '0'.repeat(56); - const resultWithShorterString = parseTraceparent(shorterString); - const resultWithLongerString = parseTraceparent(longerString); + expect(() => parseTraceparent(shorterString)).toThrow( + InvalidTraceparentLengthError + ); + expect(() => parseTraceparent(longerString)).toThrow( + InvalidTraceparentLengthError + ); + }); - expect(resultWithShorterString).toBeNull(); - expect(resultWithLongerString).toBeNull(); + it('should throw an error if traceparent does not match the W3C pattern', () => { + const additionalChar = 'x'; + const unsupportedFormats = [ + `00${additionalChar}-af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01`, + `0-${additionalChar}0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01`, + `00-0af7651916cd43dd8448eb211c80319-${additionalChar}b7ad6b7169203331-01`, + `00-0af7651916cd43dd8448eb211c80319c-b7ad6b716920333-${additionalChar}01`, + `00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331${additionalChar}-1`, + `0010af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01`, + `00-0af7651916cd43dd8448eb211c80319c1b7ad6b7169203331-01`, + `00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331101`, + `0010af7651916cd43dd8448eb211c80319c1b7ad6b7169203331101`, + ]; + + unsupportedFormats.forEach((traceparent) => { + expect(() => parseTraceparent(traceparent)).toThrow( + InvalidTraceparentFormatError + ); + }); }); it('should parse traceparent correctly', () => { diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts index 42177727aca..eca4d4b3026 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts @@ -4,8 +4,18 @@ * SPDX-License-Identifier: Apache-2.0 */ +import { InvalidTraceparentFormatError } from './errors/invalid-traceparent-format-error'; +import { InvalidTraceparentLengthError } from './errors/invalid-traceparent-length-error'; import { W3cTraceContext } from './w3c-trace-context.model'; +const HEXDIGLC = '[0-9a-f]'; // https://www.w3.org/TR/trace-context/#traceparent-header-field-values +const VERSION = HEXDIGLC + '{2}'; // 2 HEXDIGLC +const TRACE_ID = HEXDIGLC + '{32}'; // 32 HEXDIGLC +const PARENT_ID = HEXDIGLC + '{16}'; // 16 HEXDIGLC +const TRACE_FLAGS = HEXDIGLC + '{2}'; // 2 HEXDIGLC +const TRACEPARENT = [VERSION, TRACE_ID, PARENT_ID, TRACE_FLAGS].join('-'); // separated by dashes +const traceparentPattern = new RegExp('^' + TRACEPARENT + '$'); + /** * Maps traceparent header to object with properties version, traceId, spanId and traceFlags. * @@ -14,24 +24,18 @@ import { W3cTraceContext } from './w3c-trace-context.model'; * * @see https://www.w3.org/TR/trace-context/#traceparent-header-field-values */ -export const parseTraceparent = ( - traceparent: string -): W3cTraceContext | null => { - if (typeof traceparent !== 'string' || traceparent.length !== 55) { - return null; - } +export function parseTraceparent( + traceparent: string | undefined | null +): W3cTraceContext | null { + if (typeof traceparent !== 'string') return null; + + if (traceparent.length !== 55) + throw new InvalidTraceparentLengthError(traceparent.length); - // Specific ranges of the traceparent header parameters calculated based on the official documentation - // See https://www.w3.org/TR/trace-context/#traceparent-header-field-values - const versionRange: [number, number] = [0, 2]; - const traceIdRange: [number, number] = [3, 35]; - const parentIdRange: [number, number] = [36, 52]; - const traceFlagsRange: [number, number] = [53, 55]; + if (!traceparentPattern.test(traceparent)) + throw new InvalidTraceparentFormatError(); - const version = traceparent.substring(...versionRange); - const traceId = traceparent.substring(...traceIdRange); - const parentId = traceparent.substring(...parentIdRange); - const traceFlags = traceparent.substring(...traceFlagsRange); + const [version, traceId, parentId, traceFlags] = traceparent.split('-'); return { version, traceId, parentId, traceFlags }; -}; +} diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts index b26aa4425ee..afac1ddfaa0 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts @@ -1179,6 +1179,8 @@ describe('OptimizedSsrEngine', () => { describe('getRequestContext', () => { let dateSpy: jest.SpyInstance; let randomUUIDSpy: jest.SpyInstance; + let headers: Record; + let request: Request; const mockDate = new Date('2023-05-26'); beforeEach(() => { @@ -1186,6 +1188,16 @@ describe('OptimizedSsrEngine', () => { randomUUIDSpy = jest .spyOn(crypto, 'randomUUID') .mockReturnValue('ad90db04-a501-4dc5-9b4e-2cc2ab10d49c'); + headers = { + traceparent: '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01', + }; + request = { + originalUrl: 'test', + headers, + get: (header: string): string | string[] | null | undefined => { + return headers[header]; + }, + } as unknown as Request; }); afterEach(() => { @@ -1193,17 +1205,6 @@ describe('OptimizedSsrEngine', () => { randomUUIDSpy.mockReset(); }); - const headers: Record = { - traceparent: '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01', - }; - const request = { - originalUrl: 'test', - headers, - get: (header: string): string | string[] | null | undefined => { - return headers[header]; - }, - } as unknown as Request; - it('should receive request context', () => { const engineRunner = new TestEngineRunner({}); const result = diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index 54763f857a9..a0e76ae80d8 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -486,7 +486,7 @@ export class OptimizedSsrEngine { /** * Returns the request context object, which is used to enrich the logs. - * It contains the request's UUID, timestamp and trace context (if available). + * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). * The trace context is parsed from the `traceparent` header, which is specified in * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header * for more details. @@ -500,13 +500,11 @@ export class OptimizedSsrEngine { timeReceived: new Date().toISOString(), }; - const traceparent = request.get('traceparent'); - if (traceparent) { - const traceContext = parseTraceparent(traceparent); - if (traceContext) { - requestContext.traceContext = traceContext; - } + const traceContext = parseTraceparent(request.get('traceparent')); + if (traceContext) { + requestContext.traceContext = traceContext; } + return requestContext; } From 4b6a6b9190e633d562c856dd8b9209ff82aaa7da Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" Date: Tue, 8 Aug 2023 09:21:45 +0000 Subject: [PATCH 05/19] Add license header --- .../errors/invalid-traceparent-format-error.ts | 6 ++++++ .../errors/invalid-traceparent-length-error.ts | 6 ++++++ 2 files changed, 12 insertions(+) diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts index 5a96e986ea1..959a3213ffc 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-format-error.ts @@ -1,3 +1,9 @@ +/* + * SPDX-FileCopyrightText: 2023 SAP Spartacus team + * + * SPDX-License-Identifier: Apache-2.0 + */ + /** * Error thrown when the traceparent header has an invalid format. */ diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts index b071831db29..a90251c89d9 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/errors/invalid-traceparent-length-error.ts @@ -1,3 +1,9 @@ +/* + * SPDX-FileCopyrightText: 2023 SAP Spartacus team + * + * SPDX-License-Identifier: Apache-2.0 + */ + /** * Error thrown when the traceparent header has an invalid length. * @param traceparentLength The length of the traceparent header. From acc37abb5b4a3e6414d27dea2c107de70cc9dddd Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Tue, 8 Aug 2023 12:17:59 +0200 Subject: [PATCH 06/19] fixing sonar issues --- .../loggers/w3c-trace-context/parse-traceparent.ts | 10 +++++++--- .../setup/ssr/optimized-engine/optimized-ssr-engine.ts | 2 ++ 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts index eca4d4b3026..e1525069e61 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts @@ -27,13 +27,17 @@ const traceparentPattern = new RegExp('^' + TRACEPARENT + '$'); export function parseTraceparent( traceparent: string | undefined | null ): W3cTraceContext | null { - if (typeof traceparent !== 'string') return null; + if (typeof traceparent !== 'string') { + return null; + } - if (traceparent.length !== 55) + if (traceparent.length !== 55) { throw new InvalidTraceparentLengthError(traceparent.length); + } - if (!traceparentPattern.test(traceparent)) + if (!traceparentPattern.test(traceparent)) { throw new InvalidTraceparentFormatError(); + } const [version, traceId, parentId, traceFlags] = traceparent.split('-'); diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index a0e76ae80d8..a2dba2efb0d 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -495,6 +495,8 @@ export class OptimizedSsrEngine { * @private */ private getRequestContext(request: Request): ExpressServerLoggerContext { + request.headers['traceparent'] = + '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'; const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), From 4ccd1be58942c9789644e260755758d686ee1ced Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Tue, 8 Aug 2023 12:23:38 +0200 Subject: [PATCH 07/19] removing test values --- core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts | 2 -- 1 file changed, 2 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index a2dba2efb0d..a0e76ae80d8 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -495,8 +495,6 @@ export class OptimizedSsrEngine { * @private */ private getRequestContext(request: Request): ExpressServerLoggerContext { - request.headers['traceparent'] = - '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'; const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), From 46a09dec54b589ee46185925d47e0916de20d48b Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Wed, 9 Aug 2023 13:26:52 +0200 Subject: [PATCH 08/19] adding error handling --- .../optimized-ssr-engine.spec.ts | 116 ++++++++++++++++-- .../optimized-engine/optimized-ssr-engine.ts | 44 +++++-- 2 files changed, 138 insertions(+), 22 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts index afac1ddfaa0..e7c575941b7 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts @@ -1211,16 +1211,19 @@ describe('OptimizedSsrEngine', () => { engineRunner.optimizedSsrEngine['getRequestContext'](request); expect(result).toMatchInlineSnapshot(` - { - "timeReceived": "2023-05-26T00:00:00.000Z", - "traceContext": { - "parentId": "1b527c3828976b39", - "traceFlags": "01", - "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", - "version": "00", + [ + { + "timeReceived": "2023-05-26T00:00:00.000Z", + "traceContext": { + "parentId": "1b527c3828976b39", + "traceFlags": "01", + "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", + "version": "00", + }, + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", }, - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - } + null, + ] `); }); @@ -1238,10 +1241,37 @@ describe('OptimizedSsrEngine', () => { ); expect(result).toMatchInlineSnapshot(` - { - "timeReceived": "2023-05-26T00:00:00.000Z", - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - } + [ + { + "timeReceived": "2023-05-26T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + }, + null, + ] + `); + }); + + it('should receive request context without traceContext and an error if traceparent is invalid', () => { + const requestWithoutTraceparentHeader = { + ...request, + get: (_header: string): string | string[] | null | undefined => { + return '00-invalid-traceparent'; + }, + } as unknown as Request; + + const engineRunner = new TestEngineRunner({}); + const result = engineRunner.optimizedSsrEngine['getRequestContext']( + requestWithoutTraceparentHeader + ); + + expect(result).toMatchInlineSnapshot(` + [ + { + "timeReceived": "2023-05-26T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + }, + [Error: Traceparent header has invalid length: 22. Expected 55 characters.], + ] `); }); @@ -1274,6 +1304,66 @@ describe('OptimizedSsrEngine', () => { }) ); })); + + it('should add requestContext to and log error if occurs during parsing traceparent', fakeAsync(() => { + const requestContext = { + timeReceived: '1970-01-01T00:00:00.500Z', + uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', + }; + + const engineRunner = new TestEngineRunner({}); + const loggerErrorSpy = jest.spyOn( + engineRunner.optimizedSsrEngine['logger'], + 'error' + ); + jest.spyOn(engineRunner.optimizedSsrEngine as any, 'log'); + + engineRunner.request('test', { + httpHeaders: { ...headers, traceparent: '00-invalid-traceparent' }, + }); + tick(200); + expect(engineRunner.optimizedSsrEngine['log']).toHaveBeenCalledWith( + 'Rendering started (test)', + true, + expect.objectContaining({ + request: expect.objectContaining({ + res: expect.objectContaining({ + locals: { cx: { request: requestContext } }, + }), + }), + }) + ); + expect(loggerErrorSpy.mock.lastCall).toMatchInlineSnapshot(` + [ + "Traceparent header has invalid length: 22. Expected 55 characters.", + { + "request": { + "app": { + "get": [Function], + }, + "connection": {}, + "get": [Function], + "headers": { + "traceparent": "00-invalid-traceparent", + }, + "originalUrl": "test", + "protocol": "https", + "res": { + "locals": { + "cx": { + "request": { + "timeReceived": "1970-01-01T00:00:00.500Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + }, + }, + }, + "set": [Function], + }, + }, + }, + ] + `); + })); }); describe('logger option', () => { diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index a0e76ae80d8..7ac103bbef6 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -255,9 +255,7 @@ export class OptimizedSsrEngine { options: any, callback: SsrCallbackFn ): void { - options.req.res.locals = { - cx: { request: this.getRequestContext(options.req) }, - }; + this.updateWithRequestContext(options); const request: Request = options.req; const response: Response = options.req.res; @@ -491,21 +489,49 @@ export class OptimizedSsrEngine { * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header * for more details. * @param request - the request object - * @returns the context of the request + * @returns the context of the request and error if occurred during parsing traceparent header * @private */ - private getRequestContext(request: Request): ExpressServerLoggerContext { + private getRequestContext( + request: Request + ): [ExpressServerLoggerContext, Error | null] { + let error: Error | null = null; + // request.headers['traceparent'] = + // '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-0'; const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), }; - const traceContext = parseTraceparent(request.get('traceparent')); - if (traceContext) { - requestContext.traceContext = traceContext; + try { + const traceContext = parseTraceparent(request.get('traceparent')); + if (traceContext) { + requestContext.traceContext = traceContext; + } + } catch (e) { + error = + e instanceof Error + ? e + : new Error('Unexpected error during parsing traceparent header'); } - return requestContext; + return [requestContext, error]; + } + + /** + * Provides the request context returned from `getRequestContext` methods to be available in SSR scope. + * Method handles the error that may occur during parsing traceparent header. + * @param options - the options of the request + * @private + */ + private updateWithRequestContext(options: any) { + const [requestContext, error] = this.getRequestContext(options.req); + options.req.res.locals = { + cx: { request: requestContext }, + }; + if (error) { + this.logger.error(error.message, { request: options.req }); + } } //CXSPA-3680 - remove this method in 7.0 From 1bf0bec3e711d05ad1fe304c3adf062225921c4f Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Thu, 24 Aug 2023 11:50:34 +0200 Subject: [PATCH 09/19] fixing sonar issues --- core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts | 2 -- 1 file changed, 2 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index 7ac103bbef6..06edd2910be 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -496,8 +496,6 @@ export class OptimizedSsrEngine { request: Request ): [ExpressServerLoggerContext, Error | null] { let error: Error | null = null; - // request.headers['traceparent'] = - // '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-0'; const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), From 6d312ec88594f9689457c008609fb453ff8f28ea Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Tue, 5 Sep 2023 09:09:39 +0200 Subject: [PATCH 10/19] refactor after review --- .../logger/loggers/express-server-logger.ts | 2 + .../optimized-engine/optimized-ssr-engine.ts | 106 +++++++++--------- .../ssr/optimized-engine/request-context.ts | 56 +++++++++ 3 files changed, 112 insertions(+), 52 deletions(-) create mode 100644 core-libs/setup/ssr/optimized-engine/request-context.ts diff --git a/core-libs/setup/ssr/logger/loggers/express-server-logger.ts b/core-libs/setup/ssr/logger/loggers/express-server-logger.ts index 5cff6937dd3..191a461022e 100644 --- a/core-libs/setup/ssr/logger/loggers/express-server-logger.ts +++ b/core-libs/setup/ssr/logger/loggers/express-server-logger.ts @@ -6,6 +6,7 @@ import { InjectionToken } from '@angular/core'; import { Request } from 'express'; +import { W3cTraceContext } from './w3c-trace-context/w3c-trace-context.model'; /** * ExpressServerLoggerContext is used for log message in server side rendering. @@ -13,6 +14,7 @@ import { Request } from 'express'; */ export interface ExpressServerLoggerContext { request?: Request; + traceContext?: W3cTraceContext; [_key: string]: any; } diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index 06edd2910be..e1daa88a9b3 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -5,7 +5,6 @@ */ /* webpackIgnore: true */ -import { randomUUID } from 'crypto'; import { Request, Response } from 'express'; import * as fs from 'fs'; import { NgExpressEngineInstance } from '../engine-decorator/ng-express-engine-decorator'; @@ -17,9 +16,9 @@ import { ExpressServerLoggerContext, LegacyExpressServerLogger, } from '../logger'; -import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; import { getLoggableSsrOptimizationOptions } from './get-loggable-ssr-optimization-options'; import { RenderingCache } from './rendering-cache'; +import { getRequestContext } from './request-context'; import { RenderingStrategy, SsrOptimizationOptions, @@ -255,7 +254,10 @@ export class OptimizedSsrEngine { options: any, callback: SsrCallbackFn ): void { - this.updateWithRequestContext(options); + // this.updateWithRequestContext(options); + options.req.res.locals = { + cx: { request: getRequestContext(options.req, this.logger) }, + }; const request: Request = options.req; const response: Response = options.req.res; @@ -482,55 +484,55 @@ export class OptimizedSsrEngine { }); } - /** - * Returns the request context object, which is used to enrich the logs. - * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). - * The trace context is parsed from the `traceparent` header, which is specified in - * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header - * for more details. - * @param request - the request object - * @returns the context of the request and error if occurred during parsing traceparent header - * @private - */ - private getRequestContext( - request: Request - ): [ExpressServerLoggerContext, Error | null] { - let error: Error | null = null; - const requestContext: ExpressServerLoggerContext = { - uuid: randomUUID(), - timeReceived: new Date().toISOString(), - }; - - try { - const traceContext = parseTraceparent(request.get('traceparent')); - if (traceContext) { - requestContext.traceContext = traceContext; - } - } catch (e) { - error = - e instanceof Error - ? e - : new Error('Unexpected error during parsing traceparent header'); - } - - return [requestContext, error]; - } - - /** - * Provides the request context returned from `getRequestContext` methods to be available in SSR scope. - * Method handles the error that may occur during parsing traceparent header. - * @param options - the options of the request - * @private - */ - private updateWithRequestContext(options: any) { - const [requestContext, error] = this.getRequestContext(options.req); - options.req.res.locals = { - cx: { request: requestContext }, - }; - if (error) { - this.logger.error(error.message, { request: options.req }); - } - } + // /** + // * Returns the request context object, which is used to enrich the logs. + // * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). + // * The trace context is parsed from the `traceparent` header, which is specified in + // * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header + // * for more details. + // * @param request - the request object + // * @returns the context of the request and error if occurred during parsing traceparent header + // * @private + // */ + // private getRequestContext( + // request: Request + // ): [ExpressServerLoggerContext, Error | null] { + // let error: Error | null = null; + // const requestContext: ExpressServerLoggerContext = { + // uuid: randomUUID(), + // timeReceived: new Date().toISOString(), + // }; + + // try { + // const traceContext = parseTraceparent(request.get('traceparent')); + // if (traceContext) { + // requestContext.traceContext = traceContext; + // } + // } catch (e) { + // error = + // e instanceof Error + // ? e + // : new Error('Unexpected error during parsing traceparent header'); + // } + + // return [requestContext, error]; + // } + + // /** + // * Provides the request context returned from `getRequestContext` methods to be available in SSR scope. + // * Method handles the error that may occur during parsing traceparent header. + // * @param options - the options of the request + // * @private + // */ + // private updateWithRequestContext(options: any) { + // const [requestContext, error] = this.getRequestContext(options.req); + // options.req.res.locals = { + // cx: { request: requestContext }, + // }; + // if (error) { + // this.logger.error(error.message, { request: options.req }); + // } + // } //CXSPA-3680 - remove this method in 7.0 private initLogger(ssrOptions: SsrOptimizationOptions | undefined) { diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts new file mode 100644 index 00000000000..73ee3933364 --- /dev/null +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -0,0 +1,56 @@ +import { randomUUID } from 'crypto'; +import { Request } from 'express'; +import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; +import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; + +/** + * Returns the request context object, which is used to enrich the logs. + * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). + * The trace context is parsed from the `traceparent` header, which is specified in + * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header + * for more details. + * @param request - the request object + * @returns the context of the request and error if occurred during parsing traceparent header + */ +export const getRequestContext = ( + request: Request, + logger: ExpressServerLogger +): ExpressServerLoggerContext => { + const requestContext: ExpressServerLoggerContext = { + uuid: randomUUID(), + timeReceived: new Date().toISOString(), + }; + + try { + const traceContext = parseTraceparent(request.get('traceparent')); + if (traceContext) { + requestContext.traceContext = traceContext; + } + } catch (e) { + const error = + e instanceof Error + ? e + : new Error('Unexpected error during parsing traceparent header'); + + logger.error(error.message, { + request: { + ...request, + res: { locals: { cx: { request: requestContext } } }, + } as Request, + }); + } + + return requestContext; +}; + +declare module 'express' { + export interface Request { + res: { + locals: { + cx: { + request: ExpressServerLoggerContext; + }; + }; + }; + } +} From 4faaea3551be2cfab90cb076eea3fe736f4882d3 Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" Date: Tue, 5 Sep 2023 07:10:25 +0000 Subject: [PATCH 11/19] Add license header --- core-libs/setup/ssr/optimized-engine/request-context.ts | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index 73ee3933364..c797c4d7d06 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -1,3 +1,9 @@ +/* + * SPDX-FileCopyrightText: 2023 SAP Spartacus team + * + * SPDX-License-Identifier: Apache-2.0 + */ + import { randomUUID } from 'crypto'; import { Request } from 'express'; import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; From a080d01b3c6b88966bd6a8ef2558079519a6c209 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Thu, 7 Sep 2023 09:21:52 +0200 Subject: [PATCH 12/19] move request context logic to the separate file --- .../optimized-engine/optimized-ssr-engine.ts | 7 +- .../ssr/optimized-engine/request-context.ts | 67 +++++++++++++------ 2 files changed, 50 insertions(+), 24 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index e1daa88a9b3..843bae99162 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -18,7 +18,7 @@ import { } from '../logger'; import { getLoggableSsrOptimizationOptions } from './get-loggable-ssr-optimization-options'; import { RenderingCache } from './rendering-cache'; -import { getRequestContext } from './request-context'; +import { preprocessRequestForLogger } from './request-context'; import { RenderingStrategy, SsrOptimizationOptions, @@ -254,10 +254,7 @@ export class OptimizedSsrEngine { options: any, callback: SsrCallbackFn ): void { - // this.updateWithRequestContext(options); - options.req.res.locals = { - cx: { request: getRequestContext(options.req, this.logger) }, - }; + preprocessRequestForLogger(options.req, this.logger); const request: Request = options.req; const response: Response = options.req.res; diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index c797c4d7d06..41f8177157c 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -9,44 +9,73 @@ import { Request } from 'express'; import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; +const getRequestContext = (request: Request) => { + return request.res.locals.cx.request; +}; + +const setRequestContext = ( + request: Request, + context: ExpressServerLoggerContext +) => { + request.res.locals = { + cx: { + request: context, + }, + }; +}; + /** - * Returns the request context object, which is used to enrich the logs. - * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). - * The trace context is parsed from the `traceparent` header, which is specified in - * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header - * for more details. + * Adds the initial request context to the request object. * @param request - the request object - * @returns the context of the request and error if occurred during parsing traceparent header */ -export const getRequestContext = ( - request: Request, - logger: ExpressServerLogger -): ExpressServerLoggerContext => { +const addInitialRequestContext = (request: Request): void => { const requestContext: ExpressServerLoggerContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), }; + setRequestContext(request, requestContext); +}; +/** + * Parses the `traceparent` header and adds the trace context to the request context. + * In case of an error, the error is logged wit the initial request context. + * @param request - the request object + * @param logger - the logger object + * + */ +const addTraceContext = (request: Request, logger: ExpressServerLogger) => { + const context = getRequestContext(request); try { const traceContext = parseTraceparent(request.get('traceparent')); if (traceContext) { - requestContext.traceContext = traceContext; + context.traceContext = traceContext; + setRequestContext(request, context); } } catch (e) { const error = e instanceof Error ? e : new Error('Unexpected error during parsing traceparent header'); - - logger.error(error.message, { - request: { - ...request, - res: { locals: { cx: { request: requestContext } } }, - } as Request, - }); + logger.error(error.message, context); } +}; - return requestContext; +/** + * Prepares and updates a request with the context object, which is used to enrich the logs. + * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). + * The trace context is parsed from the `traceparent` header, which is specified in + * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header + * for more details. + * @param request - the request object + * @param logger - the ExpressServerLogger object. It is used to log the error if occurred during parsing traceparent header + * @returns the context of the request and error if occurred during parsing traceparent header + */ +export const preprocessRequestForLogger = ( + request: Request, + logger: ExpressServerLogger +) => { + addInitialRequestContext(request); + addTraceContext(request, logger); }; declare module 'express' { From 9a793132cebc83589d956fb893e9b6d4780ec132 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Fri, 8 Sep 2023 13:20:08 +0200 Subject: [PATCH 13/19] refactor after review --- .../parse-traceparent.spec.ts | 2 +- .../optimized-ssr-engine.spec.ts | 191 ------------------ .../optimized-engine/optimized-ssr-engine.ts | 50 ----- .../optimized-engine/request-context.spec.ts | 121 +++++++++++ .../ssr/optimized-engine/request-context.ts | 30 +-- 5 files changed, 137 insertions(+), 257 deletions(-) create mode 100644 core-libs/setup/ssr/optimized-engine/request-context.spec.ts diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts index d1ee3b08f88..3af4709842a 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts @@ -23,7 +23,7 @@ describe('parseTraceparent', () => { it('should throw an error if traceparent does not match the W3C pattern', () => { const additionalChar = 'x'; - const unsupportedFormats = [ + const unsupportedFormats: string[] = [ `00${additionalChar}-af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01`, `0-${additionalChar}0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01`, `00-0af7651916cd43dd8448eb211c80319-${additionalChar}b7ad6b7169203331-01`, diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts index e7c575941b7..d3d43f117f2 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.spec.ts @@ -1,7 +1,6 @@ /// import { fakeAsync, flush, tick } from '@angular/core/testing'; -import crypto from 'crypto'; import { Application, Request, Response } from 'express'; import { IncomingHttpHeaders } from 'http'; import { Socket } from 'net'; @@ -1176,196 +1175,6 @@ describe('OptimizedSsrEngine', () => { }); }); - describe('getRequestContext', () => { - let dateSpy: jest.SpyInstance; - let randomUUIDSpy: jest.SpyInstance; - let headers: Record; - let request: Request; - const mockDate = new Date('2023-05-26'); - - beforeEach(() => { - dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); - randomUUIDSpy = jest - .spyOn(crypto, 'randomUUID') - .mockReturnValue('ad90db04-a501-4dc5-9b4e-2cc2ab10d49c'); - headers = { - traceparent: '00-d745f6735b44e81c0ae5410cb1fc8a0c-1b527c3828976b39-01', - }; - request = { - originalUrl: 'test', - headers, - get: (header: string): string | string[] | null | undefined => { - return headers[header]; - }, - } as unknown as Request; - }); - - afterEach(() => { - dateSpy.mockReset(); - randomUUIDSpy.mockReset(); - }); - - it('should receive request context', () => { - const engineRunner = new TestEngineRunner({}); - const result = - engineRunner.optimizedSsrEngine['getRequestContext'](request); - - expect(result).toMatchInlineSnapshot(` - [ - { - "timeReceived": "2023-05-26T00:00:00.000Z", - "traceContext": { - "parentId": "1b527c3828976b39", - "traceFlags": "01", - "traceId": "d745f6735b44e81c0ae5410cb1fc8a0c", - "version": "00", - }, - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - }, - null, - ] - `); - }); - - it('should receive request context without traceContext if traceparent is missing', () => { - const requestWithoutTraceparentHeader = { - ...request, - get: (_header: string): string | string[] | null | undefined => { - return undefined; - }, - } as unknown as Request; - - const engineRunner = new TestEngineRunner({}); - const result = engineRunner.optimizedSsrEngine['getRequestContext']( - requestWithoutTraceparentHeader - ); - - expect(result).toMatchInlineSnapshot(` - [ - { - "timeReceived": "2023-05-26T00:00:00.000Z", - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - }, - null, - ] - `); - }); - - it('should receive request context without traceContext and an error if traceparent is invalid', () => { - const requestWithoutTraceparentHeader = { - ...request, - get: (_header: string): string | string[] | null | undefined => { - return '00-invalid-traceparent'; - }, - } as unknown as Request; - - const engineRunner = new TestEngineRunner({}); - const result = engineRunner.optimizedSsrEngine['getRequestContext']( - requestWithoutTraceparentHeader - ); - - expect(result).toMatchInlineSnapshot(` - [ - { - "timeReceived": "2023-05-26T00:00:00.000Z", - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - }, - [Error: Traceparent header has invalid length: 22. Expected 55 characters.], - ] - `); - }); - - it('should add requestContext to the request', fakeAsync(() => { - const requestContext = { - timeReceived: '1970-01-01T00:00:00.500Z', - traceContext: { - parentId: '1b527c3828976b39', - traceFlags: '01', - traceId: 'd745f6735b44e81c0ae5410cb1fc8a0c', - version: '00', - }, - uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', - }; - - const engineRunner = new TestEngineRunner({}); - jest.spyOn(engineRunner.optimizedSsrEngine as any, 'log'); - - engineRunner.request('test', { httpHeaders: headers }); - tick(200); - expect(engineRunner.optimizedSsrEngine['log']).toHaveBeenCalledWith( - 'Rendering started (test)', - true, - expect.objectContaining({ - request: expect.objectContaining({ - res: expect.objectContaining({ - locals: { cx: { request: requestContext } }, - }), - }), - }) - ); - })); - - it('should add requestContext to and log error if occurs during parsing traceparent', fakeAsync(() => { - const requestContext = { - timeReceived: '1970-01-01T00:00:00.500Z', - uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', - }; - - const engineRunner = new TestEngineRunner({}); - const loggerErrorSpy = jest.spyOn( - engineRunner.optimizedSsrEngine['logger'], - 'error' - ); - jest.spyOn(engineRunner.optimizedSsrEngine as any, 'log'); - - engineRunner.request('test', { - httpHeaders: { ...headers, traceparent: '00-invalid-traceparent' }, - }); - tick(200); - expect(engineRunner.optimizedSsrEngine['log']).toHaveBeenCalledWith( - 'Rendering started (test)', - true, - expect.objectContaining({ - request: expect.objectContaining({ - res: expect.objectContaining({ - locals: { cx: { request: requestContext } }, - }), - }), - }) - ); - expect(loggerErrorSpy.mock.lastCall).toMatchInlineSnapshot(` - [ - "Traceparent header has invalid length: 22. Expected 55 characters.", - { - "request": { - "app": { - "get": [Function], - }, - "connection": {}, - "get": [Function], - "headers": { - "traceparent": "00-invalid-traceparent", - }, - "originalUrl": "test", - "protocol": "https", - "res": { - "locals": { - "cx": { - "request": { - "timeReceived": "1970-01-01T00:00:00.500Z", - "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", - }, - }, - }, - "set": [Function], - }, - }, - }, - ] - `); - })); - }); - describe('logger option', () => { let dateSpy: jest.SpyInstance; diff --git a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts index 843bae99162..088443e77b6 100644 --- a/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts +++ b/core-libs/setup/ssr/optimized-engine/optimized-ssr-engine.ts @@ -481,56 +481,6 @@ export class OptimizedSsrEngine { }); } - // /** - // * Returns the request context object, which is used to enrich the logs. - // * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). - // * The trace context is parsed from the `traceparent` header, which is specified in - // * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header - // * for more details. - // * @param request - the request object - // * @returns the context of the request and error if occurred during parsing traceparent header - // * @private - // */ - // private getRequestContext( - // request: Request - // ): [ExpressServerLoggerContext, Error | null] { - // let error: Error | null = null; - // const requestContext: ExpressServerLoggerContext = { - // uuid: randomUUID(), - // timeReceived: new Date().toISOString(), - // }; - - // try { - // const traceContext = parseTraceparent(request.get('traceparent')); - // if (traceContext) { - // requestContext.traceContext = traceContext; - // } - // } catch (e) { - // error = - // e instanceof Error - // ? e - // : new Error('Unexpected error during parsing traceparent header'); - // } - - // return [requestContext, error]; - // } - - // /** - // * Provides the request context returned from `getRequestContext` methods to be available in SSR scope. - // * Method handles the error that may occur during parsing traceparent header. - // * @param options - the options of the request - // * @private - // */ - // private updateWithRequestContext(options: any) { - // const [requestContext, error] = this.getRequestContext(options.req); - // options.req.res.locals = { - // cx: { request: requestContext }, - // }; - // if (error) { - // this.logger.error(error.message, { request: options.req }); - // } - // } - //CXSPA-3680 - remove this method in 7.0 private initLogger(ssrOptions: SsrOptimizationOptions | undefined) { if (ssrOptions?.logger === true) { diff --git a/core-libs/setup/ssr/optimized-engine/request-context.spec.ts b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts new file mode 100644 index 00000000000..2b89b43ee47 --- /dev/null +++ b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts @@ -0,0 +1,121 @@ +import crypto from 'crypto'; +import { Request } from 'express'; +import { IncomingHttpHeaders } from 'http'; +import { + DefaultExpressServerLogger, + ExpressServerLogger, + ExpressServerLoggerContext, +} from '../logger'; +import * as parser from '../logger/loggers/w3c-trace-context/parse-traceparent'; +import { preprocessRequestForLogger } from './request-context'; + +describe('RequestContext', () => { + let request: Request; + let headers: IncomingHttpHeaders; + let logger: ExpressServerLogger; + let dateSpy: jest.SpyInstance; + let randomUUIDSpy: jest.SpyInstance; + const mockDate = new Date('2023-09-07'); + + beforeEach(() => { + jest.spyOn(console, 'error').mockImplementation(); + dateSpy = jest.spyOn(global, 'Date').mockImplementation(() => mockDate); + randomUUIDSpy = jest + .spyOn(crypto, 'randomUUID') + .mockReturnValue('ad90db04-a501-4dc5-9b4e-2cc2ab10d49c'); + + headers = {}; + request = { + res: { + locals: { + cx: { request: {} as ExpressServerLoggerContext }, + }, + }, + get: (header: string): string | string[] | undefined => { + return headers[header]; + }, + headers, + } as unknown as Request; + logger = new DefaultExpressServerLogger(); + }); + + afterEach(() => { + dateSpy.mockRestore(); + randomUUIDSpy.mockRestore(); + }); + + it('should add initial request context', () => { + preprocessRequestForLogger(request, logger); + expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` + { + "timeReceived": "2023-09-07T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + }); + + it('should add trace context', () => { + request.headers.traceparent = + '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'; + + preprocessRequestForLogger(request, logger); + expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` + { + "timeReceived": "2023-09-07T00:00:00.000Z", + "traceContext": { + "parentId": "b7ad6b7169203331", + "traceFlags": "01", + "traceId": "0af7651916cd43dd8448eb211c80319c", + "version": "00", + }, + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + }); + + it('should add only initial context and log an error if traceparent is invalid', () => { + const invalidTraceparent = 'invalid'; + const loggerErrorSpy = jest.spyOn(logger, 'error'); + + request.headers.traceparent = invalidTraceparent; + preprocessRequestForLogger(request, logger); + expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` + { + "timeReceived": "2023-09-07T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + expect(loggerErrorSpy).toHaveBeenCalledWith( + `Traceparent header has invalid length: ${invalidTraceparent.length}. Expected 55 characters.`, + { + timeReceived: '2023-09-07T00:00:00.000Z', + uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', + } + ); + }); + + it('should add only initial context and log unexpected error if parsing failed for unknown reason', () => { + const invalidTraceparent = 'invalid'; + const loggerErrorSpy = jest.spyOn(logger, 'error'); + + jest.spyOn(parser, 'parseTraceparent').mockImplementationOnce(() => { + // eslint-disable-next-line no-throw-literal + throw { message: 'Unexpected error' }; + }); + request.headers.traceparent = invalidTraceparent; + preprocessRequestForLogger(request, logger); + expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` + { + "timeReceived": "2023-09-07T00:00:00.000Z", + "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", + } + `); + expect(loggerErrorSpy).toHaveBeenCalledWith( + 'Unexpected error during parsing traceparent header', + { + timeReceived: '2023-09-07T00:00:00.000Z', + uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', + } + ); + }); +}); diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index 41f8177157c..b28600501e5 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -9,19 +9,23 @@ import { Request } from 'express'; import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; -const getRequestContext = (request: Request) => { - return request.res.locals.cx.request; +const getRequestContext = (request: Request): ExpressServerLoggerContext => { + return request.res?.locals.cx.request; }; const setRequestContext = ( request: Request, context: ExpressServerLoggerContext ) => { - request.res.locals = { - cx: { - request: context, - }, - }; + if (request.res) { + request.res.locals = { + ...request.res.locals, + cx: { + ...request.res.locals.cx, + request: context, + }, + }; + } }; /** @@ -38,7 +42,7 @@ const addInitialRequestContext = (request: Request): void => { /** * Parses the `traceparent` header and adds the trace context to the request context. - * In case of an error, the error is logged wit the initial request context. + * In case of an error, the error is logged with the initial request context. * @param request - the request object * @param logger - the logger object * @@ -79,13 +83,9 @@ export const preprocessRequestForLogger = ( }; declare module 'express' { - export interface Request { - res: { - locals: { - cx: { - request: ExpressServerLoggerContext; - }; - }; + export interface Locals { + cx: { + request: ExpressServerLoggerContext; }; } } From a49404136df06c50432628c2055294f7024371e2 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Mon, 11 Sep 2023 08:13:50 +0200 Subject: [PATCH 14/19] refactor after review --- core-libs/setup/ssr/optimized-engine/request-context.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index b28600501e5..192c00c2cae 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -10,7 +10,7 @@ import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; const getRequestContext = (request: Request): ExpressServerLoggerContext => { - return request.res?.locals.cx.request; + return request.res?.locals?.cx?.request; }; const setRequestContext = ( From 5676812435ad70190a9ac77891a332be8f43ac94 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Wed, 13 Sep 2023 08:13:30 +0200 Subject: [PATCH 15/19] refactor after review --- .../loggers/default-express-server-logger.ts | 3 +- .../logger/loggers/express-server-logger.ts | 2 - .../parse-traceparent.spec.ts | 2 +- .../w3c-trace-context/parse-traceparent.ts | 8 +- core-libs/setup/ssr/optimized-engine/index.ts | 3 +- .../optimized-engine/request-context.spec.ts | 13 ++- .../ssr/optimized-engine/request-context.ts | 88 ++++++++++++------- 7 files changed, 69 insertions(+), 50 deletions(-) diff --git a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts index 037cade2f0a..db665130751 100644 --- a/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts +++ b/core-libs/setup/ssr/logger/loggers/default-express-server-logger.ts @@ -6,6 +6,7 @@ import { isDevMode } from '@angular/core'; import { Request } from 'express'; +import { getRequestContext } from '../../optimized-engine/request-context'; import { ExpressServerLogger, ExpressServerLoggerContext, @@ -95,7 +96,7 @@ export class DefaultExpressServerLogger implements ExpressServerLogger { protected mapRequest(request: Request): Record { return { url: request.originalUrl, - ...request.res?.locals.cx.request, + ...getRequestContext(request), }; } } diff --git a/core-libs/setup/ssr/logger/loggers/express-server-logger.ts b/core-libs/setup/ssr/logger/loggers/express-server-logger.ts index 191a461022e..5cff6937dd3 100644 --- a/core-libs/setup/ssr/logger/loggers/express-server-logger.ts +++ b/core-libs/setup/ssr/logger/loggers/express-server-logger.ts @@ -6,7 +6,6 @@ import { InjectionToken } from '@angular/core'; import { Request } from 'express'; -import { W3cTraceContext } from './w3c-trace-context/w3c-trace-context.model'; /** * ExpressServerLoggerContext is used for log message in server side rendering. @@ -14,7 +13,6 @@ import { W3cTraceContext } from './w3c-trace-context/w3c-trace-context.model'; */ export interface ExpressServerLoggerContext { request?: Request; - traceContext?: W3cTraceContext; [_key: string]: any; } diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts index 3af4709842a..29602dd808c 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.spec.ts @@ -6,7 +6,7 @@ describe('parseTraceparent', () => { it('should return null if traceparent is not a string', () => { const result = parseTraceparent({} as string); - expect(result).toBeNull(); + expect(result).toBeUndefined(); }); it('should throw an error if traceparent is not 55 characters long', () => { diff --git a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts index e1525069e61..77fbe7ca34f 100644 --- a/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts +++ b/core-libs/setup/ssr/logger/loggers/w3c-trace-context/parse-traceparent.ts @@ -18,17 +18,19 @@ const traceparentPattern = new RegExp('^' + TRACEPARENT + '$'); /** * Maps traceparent header to object with properties version, traceId, spanId and traceFlags. + * Since `traceparent` header may be not attached to the request, the function returns undefined if the header is not provided. + * If the header is provided but has invalid format or length, the function throws an error. * * @param traceparent - * @returns Params of the traceparent header + * @returns Params of the traceparent header. * * @see https://www.w3.org/TR/trace-context/#traceparent-header-field-values */ export function parseTraceparent( traceparent: string | undefined | null -): W3cTraceContext | null { +): W3cTraceContext | undefined { if (typeof traceparent !== 'string') { - return null; + return undefined; } if (traceparent.length !== 55) { diff --git a/core-libs/setup/ssr/optimized-engine/index.ts b/core-libs/setup/ssr/optimized-engine/index.ts index b162debc6c5..6c71a29f6da 100644 --- a/core-libs/setup/ssr/optimized-engine/index.ts +++ b/core-libs/setup/ssr/optimized-engine/index.ts @@ -6,6 +6,7 @@ export * from './optimized-ssr-engine'; export * from './rendering-cache'; -export * from './ssr-optimization-options'; export * from './rendering-strategy-resolver'; export * from './rendering-strategy-resolver-options'; +export { RequestContext, getRequestContext } from './request-context'; +export * from './ssr-optimization-options'; diff --git a/core-libs/setup/ssr/optimized-engine/request-context.spec.ts b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts index 2b89b43ee47..187c79f33bc 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts @@ -49,6 +49,7 @@ describe('RequestContext', () => { expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` { "timeReceived": "2023-09-07T00:00:00.000Z", + "traceContext": undefined, "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", } `); @@ -82,15 +83,13 @@ describe('RequestContext', () => { expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` { "timeReceived": "2023-09-07T00:00:00.000Z", + "traceContext": undefined, "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", } `); expect(loggerErrorSpy).toHaveBeenCalledWith( `Traceparent header has invalid length: ${invalidTraceparent.length}. Expected 55 characters.`, - { - timeReceived: '2023-09-07T00:00:00.000Z', - uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', - } + { request, traceparent: invalidTraceparent } ); }); @@ -107,15 +106,13 @@ describe('RequestContext', () => { expect(request.res?.locals.cx.request).toMatchInlineSnapshot(` { "timeReceived": "2023-09-07T00:00:00.000Z", + "traceContext": undefined, "uuid": "ad90db04-a501-4dc5-9b4e-2cc2ab10d49c", } `); expect(loggerErrorSpy).toHaveBeenCalledWith( 'Unexpected error during parsing traceparent header', - { - timeReceived: '2023-09-07T00:00:00.000Z', - uuid: 'ad90db04-a501-4dc5-9b4e-2cc2ab10d49c', - } + { request, traceparent: invalidTraceparent } ); }); }); diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index 192c00c2cae..ad7b39de4a0 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -6,17 +6,56 @@ import { randomUUID } from 'crypto'; import { Request } from 'express'; -import { ExpressServerLogger, ExpressServerLoggerContext } from '../logger'; +import { ExpressServerLogger } from '../logger'; import { parseTraceparent } from '../logger/loggers/w3c-trace-context/parse-traceparent'; +import { W3cTraceContext } from '../logger/loggers/w3c-trace-context/w3c-trace-context.model'; -const getRequestContext = (request: Request): ExpressServerLoggerContext => { +/** + * RequestContext is used for log message in server side rendering. + * It contains request's UUID, time of receiving the request and the W3C Trace Context if `traceparent` header is available and valid. + */ +export interface RequestContext { + uuid: string; + timeReceived: string; + traceContext?: W3cTraceContext; +} + +/** + * Returns the request context from the request object. + * @param request - the request object + * @returns the context of the request + */ +export const getRequestContext = (request: Request): RequestContext => { return request.res?.locals?.cx?.request; }; -const setRequestContext = ( +/** + * Prepares and updates a request with the context object, which is used to enrich the logs. + * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). + * The trace context is parsed from the `traceparent` header, which is specified in + * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header + * for more details. + * @param request - the request object + * @param logger - the ExpressServerLogger object. It is used to log the error if occurred during parsing traceparent header + * @returns the context of the request and error if occurred during parsing traceparent header + */ +export const preprocessRequestForLogger = ( request: Request, - context: ExpressServerLoggerContext + logger: ExpressServerLogger ) => { + const requestContext: RequestContext = { + ...createInitialRequestContext(), + traceContext: getTraceContext(request, logger), + }; + setRequestContext(request, requestContext); +}; + +/** + * Updates the request object with the request context. + * @param request - the request object + * @param context - the context of the request + */ +const setRequestContext = (request: Request, context: RequestContext) => { if (request.res) { request.res.locals = { ...request.res.locals, @@ -32,12 +71,12 @@ const setRequestContext = ( * Adds the initial request context to the request object. * @param request - the request object */ -const addInitialRequestContext = (request: Request): void => { - const requestContext: ExpressServerLoggerContext = { +const createInitialRequestContext = (): RequestContext => { + const requestContext: RequestContext = { uuid: randomUUID(), timeReceived: new Date().toISOString(), }; - setRequestContext(request, requestContext); + return requestContext; }; /** @@ -47,45 +86,26 @@ const addInitialRequestContext = (request: Request): void => { * @param logger - the logger object * */ -const addTraceContext = (request: Request, logger: ExpressServerLogger) => { - const context = getRequestContext(request); +const getTraceContext = ( + request: Request, + logger: ExpressServerLogger +): W3cTraceContext | undefined => { + const traceparent = request.get('traceparent'); try { - const traceContext = parseTraceparent(request.get('traceparent')); - if (traceContext) { - context.traceContext = traceContext; - setRequestContext(request, context); - } + return parseTraceparent(request.get('traceparent')) ?? undefined; } catch (e) { const error = e instanceof Error ? e : new Error('Unexpected error during parsing traceparent header'); - logger.error(error.message, context); + logger.error(error.message, { request, traceparent }); } }; -/** - * Prepares and updates a request with the context object, which is used to enrich the logs. - * It contains the random request's UUID, time of receiving the context and the W3C Trace Context (if available). - * The trace context is parsed from the `traceparent` header, which is specified in - * the "W3C TraceContext" document. See https://www.w3.org/TR/trace-context/#traceparent-header - * for more details. - * @param request - the request object - * @param logger - the ExpressServerLogger object. It is used to log the error if occurred during parsing traceparent header - * @returns the context of the request and error if occurred during parsing traceparent header - */ -export const preprocessRequestForLogger = ( - request: Request, - logger: ExpressServerLogger -) => { - addInitialRequestContext(request); - addTraceContext(request, logger); -}; - declare module 'express' { export interface Locals { cx: { - request: ExpressServerLoggerContext; + request: RequestContext; }; } } From 5d7c49df7e383e76cc30c21ff47a406bc07046b3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pawe=C5=82=20Fra=C5=9B?= Date: Wed, 13 Sep 2023 14:01:23 +0200 Subject: [PATCH 16/19] Update core-libs/setup/ssr/optimized-engine/request-context.ts Co-authored-by: Krzysztof Platis --- core-libs/setup/ssr/optimized-engine/request-context.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index ad7b39de4a0..e4ebff0753c 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -68,8 +68,9 @@ const setRequestContext = (request: Request, context: RequestContext) => { }; /** - * Adds the initial request context to the request object. + * Creates the initial request context to the request object. * @param request - the request object + * @returns object with a randomly generated UUID and the current time */ const createInitialRequestContext = (): RequestContext => { const requestContext: RequestContext = { From 795982248f6fd43d5a548ff9e266fcc60a2c2456 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pawe=C5=82=20Fra=C5=9B?= Date: Wed, 13 Sep 2023 14:01:38 +0200 Subject: [PATCH 17/19] Update core-libs/setup/ssr/optimized-engine/request-context.ts Co-authored-by: Krzysztof Platis --- core-libs/setup/ssr/optimized-engine/request-context.ts | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index e4ebff0753c..cec80cdfee7 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -81,8 +81,9 @@ const createInitialRequestContext = (): RequestContext => { }; /** - * Parses the `traceparent` header and adds the trace context to the request context. - * In case of an error, the error is logged with the initial request context. + * Parses the `traceparent` header and returns an object with the W3C TraceContext. + * In case when the `traceparent` header is absent or invalid, `undefined` value is returned. + * Only when the `traceparent` header is invalid, additionally an error is logged with the context of the original request and the original raw value of the `traceparent` header. * @param request - the request object * @param logger - the logger object * From 7438cb13173635c5f35a54b19e5aafa34153017b Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Thu, 5 Oct 2023 12:11:50 +0200 Subject: [PATCH 18/19] remove invalid traceparent from logs --- core-libs/setup/ssr/optimized-engine/request-context.spec.ts | 4 ++-- core-libs/setup/ssr/optimized-engine/request-context.ts | 4 +--- 2 files changed, 3 insertions(+), 5 deletions(-) diff --git a/core-libs/setup/ssr/optimized-engine/request-context.spec.ts b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts index 187c79f33bc..1fb767e1a5d 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.spec.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.spec.ts @@ -89,7 +89,7 @@ describe('RequestContext', () => { `); expect(loggerErrorSpy).toHaveBeenCalledWith( `Traceparent header has invalid length: ${invalidTraceparent.length}. Expected 55 characters.`, - { request, traceparent: invalidTraceparent } + { request } ); }); @@ -112,7 +112,7 @@ describe('RequestContext', () => { `); expect(loggerErrorSpy).toHaveBeenCalledWith( 'Unexpected error during parsing traceparent header', - { request, traceparent: invalidTraceparent } + { request } ); }); }); diff --git a/core-libs/setup/ssr/optimized-engine/request-context.ts b/core-libs/setup/ssr/optimized-engine/request-context.ts index cec80cdfee7..9a5d00eb6cc 100644 --- a/core-libs/setup/ssr/optimized-engine/request-context.ts +++ b/core-libs/setup/ssr/optimized-engine/request-context.ts @@ -83,7 +83,6 @@ const createInitialRequestContext = (): RequestContext => { /** * Parses the `traceparent` header and returns an object with the W3C TraceContext. * In case when the `traceparent` header is absent or invalid, `undefined` value is returned. - * Only when the `traceparent` header is invalid, additionally an error is logged with the context of the original request and the original raw value of the `traceparent` header. * @param request - the request object * @param logger - the logger object * @@ -92,7 +91,6 @@ const getTraceContext = ( request: Request, logger: ExpressServerLogger ): W3cTraceContext | undefined => { - const traceparent = request.get('traceparent'); try { return parseTraceparent(request.get('traceparent')) ?? undefined; } catch (e) { @@ -100,7 +98,7 @@ const getTraceContext = ( e instanceof Error ? e : new Error('Unexpected error during parsing traceparent header'); - logger.error(error.message, { request, traceparent }); + logger.error(error.message, { request }); } }; From 5d01b6ad24fcd1a98ec07f13dd677e12e3eb2973 Mon Sep 17 00:00:00 2001 From: Pawel Fras Date: Thu, 5 Oct 2023 12:56:27 +0200 Subject: [PATCH 19/19] Trigger Build