diff --git a/packages/pwa-kit-react-sdk/CHANGELOG.md b/packages/pwa-kit-react-sdk/CHANGELOG.md index 020339a534..c4fd88a56e 100644 --- a/packages/pwa-kit-react-sdk/CHANGELOG.md +++ b/packages/pwa-kit-react-sdk/CHANGELOG.md @@ -2,6 +2,7 @@ - Fix the performance logging so that it'll capture all SSR queries, even those that result in errors [#2486](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2486) - Created an opentelemetry server for SSR tracer intialization [#2617](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2617) - Created opentelemetry.js file with utility functions to log OTel spans and metrics [#2705] (https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2705) +- Update performance.js with usage of opentelemetry spans and add cleanups [#2722](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2722) ## v3.10.0 (May 22, 2025) - Fix the performance logging util to use the correct delimiter for the server-timing header. [#2225](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2295) diff --git a/packages/pwa-kit-react-sdk/setup-jest.js b/packages/pwa-kit-react-sdk/setup-jest.js index 2d94d3e2b1..7fe54bd88b 100644 --- a/packages/pwa-kit-react-sdk/setup-jest.js +++ b/packages/pwa-kit-react-sdk/setup-jest.js @@ -40,4 +40,20 @@ jest.mock('@salesforce/pwa-kit-runtime/utils/ssr-config', () => { // The global performance object is available in production // environments for both the server and the client. // It's just the jest environment that this is not available -global.performance = performance +if (global.performance) { + // global.performance exists but is missing methods from perf_hooks in jest + if (typeof performance.mark === 'function' && !global.performance.mark) { + global.performance.mark = performance.mark.bind(performance) + } + if (typeof performance.measure === 'function' && !global.performance.measure) { + global.performance.measure = performance.measure.bind(performance) + } + if (typeof performance.clearMarks === 'function' && !global.performance.clearMarks) { + global.performance.clearMarks = performance.clearMarks.bind(performance) + } + if (typeof performance.clearMeasures === 'function' && !global.performance.clearMeasures) { + global.performance.clearMeasures = performance.clearMeasures.bind(performance) + } +} else { + global.performance = performance +} diff --git a/packages/pwa-kit-react-sdk/src/ssr/server/opentelemetry-server.js b/packages/pwa-kit-react-sdk/src/ssr/server/opentelemetry-server.js index 51708d0182..4b9207c31b 100644 --- a/packages/pwa-kit-react-sdk/src/ssr/server/opentelemetry-server.js +++ b/packages/pwa-kit-react-sdk/src/ssr/server/opentelemetry-server.js @@ -11,7 +11,7 @@ import {B3Propagator} from '@opentelemetry/propagator-b3' import {Resource} from '@opentelemetry/resources' import {propagation} from '@opentelemetry/api' import logger from '../../utils/logger-instance' -import {getServiceName, OTEL_CONFIG} from '../../utils/opentelemetry' +import {getServiceName, getOTELConfig} from '../../utils/opentelemetry-config' let provider = null @@ -27,7 +27,7 @@ export const initializeServerTracing = (options = {}) => { const { serviceName = options.serviceName || getServiceName(), serviceVersion, - enabled = OTEL_CONFIG.enabled + enabled = getOTELConfig().enabled } = options // If tracing is disabled, return null without initializing diff --git a/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.js b/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.js index 780b600a3d..3a2041be80 100644 --- a/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.js +++ b/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.js @@ -8,6 +8,7 @@ /** * @module progressive-web-sdk/ssr/server/react-rendering */ +import {initializeServerTracing, isServerTracingInitialized} from './opentelemetry-server' import path from 'path' import React from 'react' @@ -122,6 +123,11 @@ export const getLocationSearch = (req, opts = {}) => { export const render = async (req, res, next) => { const includeServerTimingHeader = '__server_timing' in req.query const shouldTrackPerformance = includeServerTimingHeader || process.env.SERVER_TIMING + + if (!isServerTracingInitialized() && shouldTrackPerformance) { + initializeServerTracing() + } + res.__performanceTimer = new PerformanceTimer({enabled: shouldTrackPerformance}) res.__performanceTimer.mark(PERFORMANCE_MARKS.total, 'start') const AppConfig = getAppConfig() @@ -222,6 +228,11 @@ export const render = async (req, res, next) => { // Here, we use Express's convention to invoke error middleware. // Note, we don't have an error handling middleware yet! This is calling the // default error handling middleware provided by Express + + if (res.__performanceTimer) { + res.__performanceTimer.cleanup() + } + return next(e) } @@ -244,6 +255,8 @@ export const render = async (req, res, next) => { res.set('Cache-Control', NO_CACHE) } + res.__performanceTimer.cleanup() + if (redirectUrl) { res.redirect(routerContext.status || 302, redirectUrl) } else { diff --git a/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.test.js b/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.test.js index 664613c593..d61217e91b 100644 --- a/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.test.js +++ b/packages/pwa-kit-react-sdk/src/ssr/server/react-rendering.test.js @@ -739,6 +739,50 @@ describe('The Node SSR Environment', () => { 'max-age=0, nocache, nostore, must-revalidate' ) } + }, + { + description: `Performance timer cleanup is called during rendering`, + req: {url: '/pwa/', query: {__server_timing: '1'}}, + mocks: () => { + // Mock PerformanceTimer to spy on cleanup + const PerformanceTimer = jest.requireActual('../../utils/performance').default + const originalCleanup = PerformanceTimer.prototype.cleanup + const cleanupSpy = jest.fn(originalCleanup) + PerformanceTimer.prototype.cleanup = cleanupSpy + + // Store the spy for assertions + global.performanceCleanupSpy = cleanupSpy + }, + assertions: (res) => { + expect(res.statusCode).toBe(200) + expect(global.performanceCleanupSpy).toHaveBeenCalled() + expect(global.performanceCleanupSpy).toHaveBeenCalledTimes(1) + + // Clean up global + delete global.performanceCleanupSpy + } + }, + { + description: `Performance timer cleanup is called even when rendering throws an error`, + req: {url: '/unknown-error/'}, // This URL causes an error + mocks: () => { + // Mock PerformanceTimer to spy on cleanup + const PerformanceTimer = jest.requireActual('../../utils/performance').default + const originalCleanup = PerformanceTimer.prototype.cleanup + const cleanupSpy = jest.fn(originalCleanup) + PerformanceTimer.prototype.cleanup = cleanupSpy + + // Store the spy for assertions + global.performanceCleanupSpyError = cleanupSpy + }, + assertions: (res) => { + expect(res.statusCode).toBe(500) + expect(global.performanceCleanupSpyError).toHaveBeenCalled() + expect(global.performanceCleanupSpyError).toHaveBeenCalledTimes(1) + + // Clean up global + delete global.performanceCleanupSpyError + } } ] diff --git a/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.js b/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.js new file mode 100644 index 0000000000..196777c58a --- /dev/null +++ b/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.js @@ -0,0 +1,21 @@ +/* + * Copyright (c) 2025, Salesforce, Inc. + * All rights reserved. + * SPDX-License-Identifier: BSD-3-Clause + * For full license text, see the LICENSE file in the repo root or https://opensource.org/licenses/BSD-3-Clause + */ + +const DEFAULT_SERVICE_NAME = 'pwa-kit-react-sdk' + +// Only call this function in the server context +// This wrapper function is necessary because if the config is in the top-level code +// process will be undefined as it gets executed in the browser context and will throw an uncaught error. +export const getOTELConfig = () => { + return { + serviceName: process.env.OTEL_SERVICE_NAME || DEFAULT_SERVICE_NAME, + enabled: process.env.OTEL_SDK_ENABLED === 'true', + b3TracingEnabled: process.env.OTEL_B3_TRACING_ENABLED === 'true' + } +} + +export const getServiceName = () => getOTELConfig().serviceName diff --git a/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.test.js b/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.test.js new file mode 100644 index 0000000000..1fc37daf98 --- /dev/null +++ b/packages/pwa-kit-react-sdk/src/utils/opentelemetry-config.test.js @@ -0,0 +1,146 @@ +/* + * Copyright (c) 2025, Salesforce, Inc. + * All rights reserved. + * SPDX-License-Identifier: BSD-3-Clause + * For full license text, see the LICENSE file in the repo root or https://opensource.org/licenses/BSD-3-Clause + */ + +import {getOTELConfig, getServiceName} from './opentelemetry-config' + +// Mock the module to reset cache between tests +const mockModule = () => { + jest.resetModules() + return require('./opentelemetry-config') +} + +describe('OpenTelemetry Config', () => { + const originalEnv = process.env + + beforeEach(() => { + // Reset environment variables + process.env = {...originalEnv} + + // Clear module cache to reset _cachedConfig + jest.resetModules() + }) + + afterEach(() => { + // Restore original environment + process.env = originalEnv + }) + + describe('getOTELConfig', () => { + describe('serviceName', () => { + test('should return service name when OTEL_SERVICE_NAME is set', () => { + process.env.OTEL_SERVICE_NAME = 'custom-service' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.serviceName).toBe('custom-service') + }) + + test('should return default service name when OTEL_SERVICE_NAME is not set', () => { + delete process.env.OTEL_SERVICE_NAME + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.serviceName).toBe('pwa-kit-react-sdk') + }) + + test('should return default service name when OTEL_SERVICE_NAME is empty string', () => { + process.env.OTEL_SERVICE_NAME = '' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.serviceName).toBe('pwa-kit-react-sdk') + }) + }) + + describe('enabled', () => { + test('should return enabled when OTEL_SDK_ENABLED is "true"', () => { + process.env.OTEL_SDK_ENABLED = 'true' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.enabled).toBe(true) + }) + + test('should return disabled when OTEL_SDK_ENABLED is not set', () => { + delete process.env.OTEL_SDK_ENABLED + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.enabled).toBe(false) + }) + + test('should return disabled when OTEL_SDK_ENABLED is "false"', () => { + process.env.OTEL_SDK_ENABLED = 'false' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.enabled).toBe(false) + }) + + test('should return disabled when OTEL_SDK_ENABLED is any non-"true" value', () => { + const nonTrueValues = ['yes', '1', 'True', 'TRUE', 'on', 'enabled', ''] + + nonTrueValues.forEach((value) => { + process.env.OTEL_SDK_ENABLED = value + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.enabled).toBe(false) + }) + }) + }) + + describe('b3TracingEnabled', () => { + test('should return enabled when OTEL_B3_TRACING_ENABLED is "true"', () => { + process.env.OTEL_B3_TRACING_ENABLED = 'true' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.b3TracingEnabled).toBe(true) + }) + + test('should return disabled when OTEL_B3_TRACING_ENABLED is not set', () => { + delete process.env.OTEL_B3_TRACING_ENABLED + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.b3TracingEnabled).toBe(false) + }) + + test('should return disabled when OTEL_B3_TRACING_ENABLED is "false"', () => { + process.env.OTEL_B3_TRACING_ENABLED = 'false' + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.b3TracingEnabled).toBe(false) + }) + + test('should return disabled when OTEL_B3_TRACING_ENABLED is any non-"true" value', () => { + const nonTrueValues = ['yes', '1', 'True', 'TRUE', 'on', 'enabled', ''] + + nonTrueValues.forEach((value) => { + process.env.OTEL_B3_TRACING_ENABLED = value + + const {getOTELConfig} = mockModule() + const config = getOTELConfig() + + expect(config.b3TracingEnabled).toBe(false) + }) + }) + }) + }) +}) diff --git a/packages/pwa-kit-react-sdk/src/utils/opentelemetry.js b/packages/pwa-kit-react-sdk/src/utils/opentelemetry.js index faaa188b00..381a23669c 100644 --- a/packages/pwa-kit-react-sdk/src/utils/opentelemetry.js +++ b/packages/pwa-kit-react-sdk/src/utils/opentelemetry.js @@ -8,20 +8,12 @@ import {trace, context, SpanStatusCode} from '@opentelemetry/api' import {hrTimeToMilliseconds, hrTimeToTimeStamp} from '@opentelemetry/core' import logger from './logger-instance' - -const DEFAULT_SERVICE_NAME = 'pwa-kit-react-sdk' - -export const OTEL_CONFIG = { - serviceName: process.env.OTEL_SERVICE_NAME || DEFAULT_SERVICE_NAME, - enabled: process.env.OTEL_SDK_ENABLED === 'true', - b3TracingEnabled: process.env.OTEL_B3_TRACING_ENABLED === 'true' -} - -export const getServiceName = () => OTEL_CONFIG.serviceName +import {getOTELConfig, getServiceName} from './opentelemetry-config' const logSpanData = (span, event = 'start', res = null) => { const spanContext = span.spanContext() const startTime = span.startTime + const endTime = event === 'start' ? startTime : span.endTime const duration = event === 'start' ? 0 : hrTimeToMilliseconds(span.duration) @@ -44,7 +36,7 @@ const logSpanData = (span, event = 'start', res = null) => { links: [], start_time: startTime, end_time: endTime, - forwardTrace: OTEL_CONFIG.b3TracingEnabled + forwardTrace: getOTELConfig().b3TracingEnabled } // Inject B3 headers into response if available diff --git a/packages/pwa-kit-react-sdk/src/utils/opentelemetry.test.js b/packages/pwa-kit-react-sdk/src/utils/opentelemetry.test.js index 0337eba7d7..7d17c4b294 100644 --- a/packages/pwa-kit-react-sdk/src/utils/opentelemetry.test.js +++ b/packages/pwa-kit-react-sdk/src/utils/opentelemetry.test.js @@ -103,13 +103,6 @@ describe('OpenTelemetry Utilities', () => { opentelemetryUtils = require('./opentelemetry') }) - describe('getServiceName', () => { - test('should return the service name from config', () => { - const serviceName = opentelemetryUtils.getServiceName() - expect(serviceName).toBe('pwa-kit-react-sdk') - }) - }) - describe('createSpan', () => { test('should create a span successfully', () => { const result = opentelemetryUtils.createSpan('test-span', { diff --git a/packages/pwa-kit-react-sdk/src/utils/performance.js b/packages/pwa-kit-react-sdk/src/utils/performance.js index 75e5709d9e..b118b03688 100644 --- a/packages/pwa-kit-react-sdk/src/utils/performance.js +++ b/packages/pwa-kit-react-sdk/src/utils/performance.js @@ -5,6 +5,8 @@ * For full license text, see the LICENSE file in the repo root or https://opensource.org/licenses/BSD-3-Clause */ import logger from './logger-instance' +import {createChildSpan, endSpan, logPerformanceMetric} from './opentelemetry' + export const PERFORMANCE_MARKS = { total: 'ssr.total', renderToString: 'ssr.render-to-string', @@ -32,11 +34,10 @@ export default class PerformanceTimer { } constructor(options = {}) { this.enabled = options.enabled || false - this.marks = { - start: new Map(), - end: new Map() - } this.metrics = [] + this.spans = new Map() + this.spanTimeouts = new Map() + this.maxSpanDuration = options.maxSpanDuration || 30000 // 30 seconds default } /** @@ -61,15 +62,13 @@ export default class PerformanceTimer { } /** - * A utility function to format and log the performance metrics. - * - * @function - * @private + * Logs all performance metrics */ log() { + // Log each metric once with the standardized format this.metrics.forEach((metric) => { - logger.info(`${metric.name} - ${metric.duration}ms ${metric.detail || ''}`, { - namespace: 'performance' + logPerformanceMetric(metric.name, metric.duration, { + 'performance.detail': metric.detail || '' }) }) } @@ -78,50 +77,150 @@ export default class PerformanceTimer { * This is a utility function to create performance marks. * The data will be used in console logs and the http response header `server-timing`. * - * @function - * @private + * @param {string} name - Unique identifier for the performance measurement. + * Must be the same for both start and end marks of a pair. E.g. 'ssr.render-to-string' + * + * @param {string} type - Mark type, either 'start' or 'end'. 'start' creates spans and browser marks, + * 'end' completes measurement and cleanup. + * + * @param {Object} [options={}] - Optional configuration object + * @param {string|Object} [options.detail=''] - Additional metadata for the mark + * included in logs and tracing attributes. */ mark(name, type, options = {}) { - if (!this.enabled) { + const {detail = ''} = options + if (!this.enabled || !name || !type) { return } - if (!name) { - logger.warn('Performance mark cannot be created because the name is undefined.', { - namespace: 'performance' - }) + if (type !== this.MARKER_TYPES.START && type !== this.MARKER_TYPES.END) { + logger.warn('Invalid mark type', {type, name, namespace: 'PerformanceTimer.mark'}) return } - if (type !== this.MARKER_TYPES.START && type !== this.MARKER_TYPES.END) { - logger.warn( - 'Performance mark cannot be created because the type must be either "start" or "end".', - { - namespace: 'performance' + try { + performance.mark(`${name}.${type}`, { + detail: detail + }) + + // Only create spans for 'start' events and store them for later use + if (type === this.MARKER_TYPES.START) { + if (!this.spans.has(name)) { + const span = createChildSpan(name, { + performance_mark: name, + performance_type: type, + performance_detail: detail + }) + if (span) { + this.spans.set(name, span) + + // Set up automatic cleanup for orphaned spans + const timeoutId = setTimeout(() => { + this._cleanupOrphanedSpan(name, 'timeout') + }, this.maxSpanDuration) + this.spanTimeouts.set(name, timeoutId) + } + } else { + logger.warn('Span already exists', {name, namespace: 'PerformanceTimer.mark'}) } - ) - return - } + } else if (type === this.MARKER_TYPES.END) { + const startMark = `${name}.${this.MARKER_TYPES.START}` + const endMark = `${name}.${this.MARKER_TYPES.END}` - const timestamp = performance.now() - const isEnd = type === this.MARKER_TYPES.END - const storage = isEnd ? this.marks.end : this.marks.start - storage.set(name, { - name, - timestamp, - detail: options.detail - }) + try { + const measure = performance.measure(name, startMark, endMark) - if (isEnd) { - const startMark = this.marks.start.get(name) - if (startMark) { - const measurement = { - name, - duration: timestamp - startMark.timestamp, - detail: options.detail + // Add the metric to the metrics array for Server-Timing header + this.metrics.push({ + name, + duration: measure.duration, + detail: detail + }) + + // End the corresponding span if it exists and clear timeout + const span = this.spans.get(name) + if (span) { + endSpan(span) + this.spans.delete(name) + + // Clear the timeout since span completed normally + const timeoutId = this.spanTimeouts.get(name) + if (timeoutId) { + clearTimeout(timeoutId) + this.spanTimeouts.delete(name) + } + } + + // Clear the marks + performance.clearMarks(startMark) + performance.clearMarks(endMark) + performance.clearMeasures(name) + } catch (error) { + logger.warn('Failed to measure performance mark', { + name, + error: error.message, + startMark, + endMark, + namespace: 'PerformanceTimer.mark' + }) } - this.metrics.push(measurement) + } + } catch (error) { + if (error.name === 'SyntaxError') { + logger.warn('Invalid performance mark name', {name, error: error.message}) + } else { + logger.error('Error creating performance mark', { + name, + type, + error: error.message, + stack: error.stack, + namespace: 'PerformanceTimer.mark' + }) } } } + + /** + * Helper method to clean up a specific orphaned span + * @private + */ + _cleanupOrphanedSpan(name, reason = 'manual') { + const span = this.spans.get(name) + if (span) { + logger.warn('Cleaning up orphaned span', { + name, + error: 'Deleting orphaned span (reason: ' + reason + ' cleanup)', + namespace: 'PerformanceTimer._cleanupOrphanedSpan' + }) + this.spans.delete(name) + endSpan(span) + } + + // Clear the timeout + const timeoutId = this.spanTimeouts.get(name) + if (timeoutId) { + clearTimeout(timeoutId) + this.spanTimeouts.delete(name) + } + } + + /** + * Clean up all orphaned spans and clear all timeouts + * Call this when the timer is no longer needed or when you want to force cleanup + */ + cleanup() { + // Clean up any orphaned spans + this.spans.forEach((span, name) => { + this._cleanupOrphanedSpan(name, 'manual_cleanup') + }) + + // Clear any remaining timeouts + this.spanTimeouts.forEach((timeoutId) => { + clearTimeout(timeoutId) + }) + this.spanTimeouts.clear() + + // Clear metrics as well + this.metrics = [] + } } diff --git a/packages/pwa-kit-react-sdk/src/utils/performance.test.js b/packages/pwa-kit-react-sdk/src/utils/performance.test.js index 6ffdf7d964..b7760fe3a0 100644 --- a/packages/pwa-kit-react-sdk/src/utils/performance.test.js +++ b/packages/pwa-kit-react-sdk/src/utils/performance.test.js @@ -1,15 +1,23 @@ -/** - * @jest-environment node - */ /* - * Copyright (c) 2024, Salesforce, Inc. + * Copyright (c) 2025, Salesforce, Inc. * All rights reserved. * SPDX-License-Identifier: BSD-3-Clause * For full license text, see the LICENSE file in the repo root or https://opensource.org/licenses/BSD-3-Clause */ -// The @jest-environment comment block *MUST* be the first line of the file for the tests to pass. -// That conflicts with the monorepo header rule, so we must disable the rule! -/* eslint-disable header/header */ + +jest.mock('./opentelemetry', () => ({ + createChildSpan: jest.fn((name, attributes) => ({ + spanContext: () => ({ + traceId: 'test-trace-id', + spanId: 'test-span-id' + }), + name, + attributes, + end: jest.fn() + })), + endSpan: jest.fn(), + logPerformanceMetric: jest.fn() +})) import PerformanceTimer from './performance' @@ -17,21 +25,21 @@ describe('PerformanceTimer', () => { test('is disabled by default', () => { const timer = new PerformanceTimer() timer.mark('test', 'start') - expect(timer.marks.start.size).toBe(0) + expect(timer.spans.size).toBe(0) }) test('can be enabled', () => { const timer = new PerformanceTimer({enabled: true}) timer.mark('test', 'start') - expect(timer.marks.start.size).toBe(1) + expect(timer.spans.size).toBe(1) + expect(timer.spans.has('test')).toBe(true) }) - test('marks can be added for both types', () => { + test('spans are removed when the end mark is added', () => { const timer = new PerformanceTimer({enabled: true}) timer.mark('test', 'start') timer.mark('test', 'end') - expect(timer.marks.start.size).toBe(1) - expect(timer.marks.end.size).toBe(1) + expect(timer.spans.size).toBe(0) }) test('measurements are created when a pair of marks is added', () => { @@ -42,4 +50,449 @@ describe('PerformanceTimer', () => { expect(timer.metrics[0].name).toBe('test') expect(parseFloat(timer.metrics[0].duration)).toBeGreaterThan(0) }) + + test('handles multiple measurements', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test1', 'end') + timer.mark('test2', 'start') + timer.mark('test2', 'end') + + expect(timer.metrics).toHaveLength(2) + expect(timer.metrics[0].name).toBe('test1') + expect(timer.metrics[1].name).toBe('test2') + expect(timer.spans.size).toBe(0) + }) + + test('handles string detail correctly', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start', {detail: 'test detail'}) + timer.mark('test', 'end', {detail: 'end detail'}) + + expect(timer.metrics).toHaveLength(1) + expect(timer.metrics[0].detail).toBe('end detail') + }) + + test('buildServerTimingHeader returns empty string for no metrics', () => { + const timer = new PerformanceTimer({enabled: true}) + expect(timer.buildServerTimingHeader()).toBe('') + }) + + test('buildServerTimingHeader formats metrics correctly', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test1', 'end') + timer.mark('test2', 'start') + timer.mark('test2', 'end') + + const header = timer.buildServerTimingHeader() + expect(header).toMatch(/test1;dur=\d+\.\d+/) + expect(header).toMatch(/test2;dur=\d+\.\d+/) + expect(header).toContain(', ') + }) + + test('handles end mark without start mark gracefully', () => { + const timer = new PerformanceTimer({enabled: true}) + + // This should not throw, but should log a warning + expect(() => { + timer.mark('test', 'end') + }).not.toThrow() + + expect(timer.metrics).toHaveLength(0) + expect(timer.spans.size).toBe(0) + }) + + test('handles start mark without end mark', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start') + + expect(timer.spans.size).toBe(1) + expect(timer.metrics).toHaveLength(0) + }) + + test('ignores marks when disabled', () => { + const timer = new PerformanceTimer({enabled: false}) + timer.mark('test', 'start') + timer.mark('test', 'end') + + expect(timer.spans.size).toBe(0) + expect(timer.metrics).toHaveLength(0) + }) + + test('ignores marks with empty name', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('', 'start') + timer.mark(null, 'start') + timer.mark(undefined, 'start') + + expect(timer.spans.size).toBe(0) + expect(timer.metrics).toHaveLength(0) + }) + + test('ignores marks with empty type', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', '') + timer.mark('test', null) + timer.mark('test', undefined) + + expect(timer.spans.size).toBe(0) + expect(timer.metrics).toHaveLength(0) + }) + + test('creates spans only for start marks', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test2', 'start') + + expect(timer.spans.size).toBe(2) + expect(timer.spans.has('test1')).toBe(true) + expect(timer.spans.has('test2')).toBe(true) + }) + + test('does not create duplicate spans for same name', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start') + timer.mark('test', 'start') // Duplicate + + expect(timer.spans.size).toBe(1) + expect(timer.spans.has('test')).toBe(true) + }) + + test('works with default options', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start') // No options parameter + timer.mark('test', 'end') + + expect(timer.metrics).toHaveLength(1) + expect(timer.metrics[0].detail).toBe('') + }) + + test('preserves detail from end mark in metrics', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start', {detail: 'start detail'}) + timer.mark('test', 'end', {detail: 'end detail'}) + + expect(timer.metrics).toHaveLength(1) + expect(timer.metrics[0].detail).toBe('end detail') + }) + + describe('cleanup functionality', () => { + test('cleanup clears all spans', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test2', 'start') + timer.mark('test3', 'start') + + expect(timer.spans.size).toBe(3) + + timer.cleanup() + + expect(timer.spans.size).toBe(0) + }) + + test('cleanup clears all timeouts', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test2', 'start') + + expect(timer.spanTimeouts.size).toBe(2) + + timer.cleanup() + + expect(timer.spanTimeouts.size).toBe(0) + }) + + test('cleanup clears all metrics', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test1', 'start') + timer.mark('test1', 'end') + timer.mark('test2', 'start') + timer.mark('test2', 'end') + + expect(timer.metrics).toHaveLength(2) + + timer.cleanup() + + expect(timer.metrics).toHaveLength(0) + }) + + test('cleanup works when there are no spans/timeouts/metrics', () => { + const timer = new PerformanceTimer({enabled: true}) + + expect(() => { + timer.cleanup() + }).not.toThrow() + + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + expect(timer.metrics).toHaveLength(0) + }) + }) + + describe('timeout and orphaned span handling', () => { + beforeEach(() => { + jest.useFakeTimers() + }) + + afterEach(() => { + jest.useRealTimers() + }) + + test('orphaned spans are cleaned up after maxSpanDuration', () => { + const timer = new PerformanceTimer({enabled: true, maxSpanDuration: 1000}) + const cleanupSpy = jest.spyOn(timer, '_cleanupOrphanedSpan') + + timer.mark('test', 'start') + + expect(timer.spans.size).toBe(1) + expect(timer.spanTimeouts.size).toBe(1) + + // Fast forward time to trigger timeout + jest.advanceTimersByTime(1001) + + expect(cleanupSpy).toHaveBeenCalledWith('test', 'timeout') + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + }) + + test('timeouts are cleared when spans end normally', () => { + const timer = new PerformanceTimer({enabled: true, maxSpanDuration: 1000}) + const cleanupSpy = jest.spyOn(timer, '_cleanupOrphanedSpan') + + timer.mark('test', 'start') + timer.mark('test', 'end') + + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + + // Fast forward time - should not trigger cleanup since span ended normally + jest.advanceTimersByTime(1001) + + expect(cleanupSpy).not.toHaveBeenCalled() + }) + + test('multiple spans can have independent timeouts', () => { + const timer = new PerformanceTimer({enabled: true, maxSpanDuration: 1000}) + const cleanupSpy = jest.spyOn(timer, '_cleanupOrphanedSpan') + + timer.mark('test1', 'start') + timer.mark('test2', 'start') + timer.mark('test3', 'start') + + expect(timer.spans.size).toBe(3) + expect(timer.spanTimeouts.size).toBe(3) + + // End one span normally + timer.mark('test2', 'end') + expect(timer.spans.size).toBe(2) + expect(timer.spanTimeouts.size).toBe(2) + + // Trigger timeouts for remaining spans + jest.advanceTimersByTime(1001) + + expect(cleanupSpy).toHaveBeenCalledTimes(2) + expect(cleanupSpy).toHaveBeenCalledWith('test1', 'timeout') + expect(cleanupSpy).toHaveBeenCalledWith('test3', 'timeout') + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + }) + + test('cleanup clears all timeouts to prevent them from firing', () => { + const timer = new PerformanceTimer({enabled: true, maxSpanDuration: 1000}) + const cleanupSpy = jest.spyOn(timer, '_cleanupOrphanedSpan') + + timer.mark('test1', 'start') + timer.mark('test2', 'start') + + // Cleanup before timeouts fire + timer.cleanup() + + // Fast forward time - timeouts should not fire since they were cleared + jest.advanceTimersByTime(1001) + + // _cleanupOrphanedSpan should only be called from cleanup, not from timeouts + expect(cleanupSpy).toHaveBeenCalledTimes(2) + expect(cleanupSpy).toHaveBeenCalledWith('test1', 'manual_cleanup') + expect(cleanupSpy).toHaveBeenCalledWith('test2', 'manual_cleanup') + }) + }) + + describe('error handling and edge cases', () => { + test('handles performance.measure errors gracefully', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock performance.measure to throw an error + const originalMeasure = performance.measure + performance.measure = jest.fn().mockImplementation(() => { + throw new Error('Measure failed') + }) + + timer.mark('test', 'start') + + expect(() => { + timer.mark('test', 'end') + }).not.toThrow() + + expect(timer.metrics).toHaveLength(0) + // The span is still there because cleanup only happens on successful measure + expect(timer.spans.size).toBe(1) + + // Restore original method + performance.measure = originalMeasure + }) + + test('handles SyntaxError in performance.mark gracefully', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock performance.mark to throw a SyntaxError + const originalMark = performance.mark + performance.mark = jest.fn().mockImplementation(() => { + const error = new Error('Invalid mark name') + error.name = 'SyntaxError' + throw error + }) + + expect(() => { + timer.mark('test', 'start') + }).not.toThrow() + + expect(timer.spans.size).toBe(0) + + // Restore original method + performance.mark = originalMark + }) + + test('handles generic errors in performance.mark gracefully', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock performance.mark to throw a generic error + const originalMark = performance.mark + performance.mark = jest.fn().mockImplementation(() => { + throw new Error('Generic error') + }) + + expect(() => { + timer.mark('test', 'start') + }).not.toThrow() + + expect(timer.spans.size).toBe(0) + + // Restore original method + performance.mark = originalMark + }) + + test('handles invalid mark types', () => { + const timer = new PerformanceTimer({enabled: true}) + + timer.mark('test', 'invalid-type') + timer.mark('test', 'middle') + timer.mark('test', 'pause') + + expect(timer.spans.size).toBe(0) + expect(timer.metrics).toHaveLength(0) + }) + + test('_cleanupOrphanedSpan handles spans without timeouts', () => { + const timer = new PerformanceTimer({enabled: true}) + timer.mark('test', 'start') + + // Manually remove timeout to simulate edge case + timer.spanTimeouts.delete('test') + + expect(() => { + timer._cleanupOrphanedSpan('test', 'manual') + }).not.toThrow() + + expect(timer.spans.size).toBe(0) + }) + + test('_cleanupOrphanedSpan handles non-existent spans', () => { + const timer = new PerformanceTimer({enabled: true}) + + expect(() => { + timer._cleanupOrphanedSpan('nonexistent', 'manual') + }).not.toThrow() + }) + + test('handles createChildSpan returning null', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock createChildSpan to return null + const {createChildSpan} = jest.requireMock('./opentelemetry') + createChildSpan.mockReturnValueOnce(null) + + timer.mark('test', 'start') + + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + }) + + test('handles performance.clearMarks and performance.clearMeasures errors', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock performance methods that might throw + const originalClearMarks = performance.clearMarks + const originalClearMeasures = performance.clearMeasures + + performance.clearMarks = jest.fn().mockImplementation(() => { + throw new Error('ClearMarks failed') + }) + performance.clearMeasures = jest.fn().mockImplementation(() => { + throw new Error('ClearMeasures failed') + }) + + timer.mark('test', 'start') + + expect(() => { + timer.mark('test', 'end') + }).not.toThrow() + + // Restore methods + performance.clearMarks = originalClearMarks + performance.clearMeasures = originalClearMeasures + }) + + test('handles span cleanup when performance.measure fails', () => { + const timer = new PerformanceTimer({enabled: true}) + + // Mock performance.measure to throw an error + const originalMeasure = performance.measure + performance.measure = jest.fn().mockImplementation(() => { + throw new Error('Measure failed') + }) + + timer.mark('test', 'start') + timer.mark('test', 'end') // This will fail but span remains + + expect(timer.spans.size).toBe(1) + + // Cleanup should remove the orphaned span + timer.cleanup() + + expect(timer.spans.size).toBe(0) + expect(timer.spanTimeouts.size).toBe(0) + + // Restore original method + performance.measure = originalMeasure + }) + }) + + describe('constructor options', () => { + test('accepts custom maxSpanDuration', () => { + const timer = new PerformanceTimer({enabled: true, maxSpanDuration: 5000}) + expect(timer.maxSpanDuration).toBe(5000) + }) + + test('uses default maxSpanDuration when not provided', () => { + const timer = new PerformanceTimer({enabled: true}) + expect(timer.maxSpanDuration).toBe(30000) + }) + + test('handles empty options object', () => { + const timer = new PerformanceTimer({}) + expect(timer.enabled).toBe(false) + expect(timer.maxSpanDuration).toBe(30000) + }) + }) }) diff --git a/packages/template-retail-react-app/CHANGELOG.md b/packages/template-retail-react-app/CHANGELOG.md index de2886a8b5..a8923b9e68 100644 --- a/packages/template-retail-react-app/CHANGELOG.md +++ b/packages/template-retail-react-app/CHANGELOG.md @@ -5,6 +5,7 @@ - Updated 6 new languages [#2495](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2495) - Fix Einstein event tracking for `addToCart` event [#2558](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2558) - Update latest translations for all languages [#2616](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2616) +- Bundlesize update [#2722](https://github.com/SalesforceCommerceCloud/pwa-kit/pull/2722) ## v6.1.0 (May 22, 2025) diff --git a/packages/template-retail-react-app/package.json b/packages/template-retail-react-app/package.json index 9ca5e072e2..9770d7d371 100644 --- a/packages/template-retail-react-app/package.json +++ b/packages/template-retail-react-app/package.json @@ -104,7 +104,7 @@ }, { "path": "build/vendor.js", - "maxSize": "328 kB" + "maxSize": "340 kB" } ] }