diff --git a/__tests__/server/utils/createCircuitBreaker.spec.js b/__tests__/server/utils/createCircuitBreaker.spec.js index e258ee35..42684c4d 100644 --- a/__tests__/server/utils/createCircuitBreaker.spec.js +++ b/__tests__/server/utils/createCircuitBreaker.spec.js @@ -19,6 +19,9 @@ import { getModule } from 'holocron'; import createCircuitBreaker, { setEventLoopDelayThreshold, getEventLoopDelayThreshold, + setEventLoopDelayPercentile, + getEventLoopDelayPercentile, + getEventLoopDelayHistogram, } from '../../../src/server/utils/createCircuitBreaker'; jest.useFakeTimers(); @@ -26,6 +29,10 @@ jest.useFakeTimers(); const asyncFunctionThatMightFail = jest.fn(async () => ({ fallback: false })); const mockCircuitBreaker = createCircuitBreaker(asyncFunctionThatMightFail); +const eventLoopDelayHistogram = getEventLoopDelayHistogram(); +const histogramPercentileSpy = jest.spyOn(eventLoopDelayHistogram, 'percentile'); +const histogramResetSpy = jest.spyOn(eventLoopDelayHistogram, 'reset'); + jest.mock('holocron', () => ({ getModule: jest.fn(() => true), })); @@ -33,10 +40,12 @@ jest.mock('holocron', () => ({ describe('Circuit breaker', () => { const consoleLogSpy = jest.spyOn(console, 'log').mockImplementation(() => 0); const consoleErrorSpy = jest.spyOn(console, 'error').mockImplementation(() => 0); + const consoleWarnSpy = jest.spyOn(console, 'warn').mockImplementation(() => 0); beforeEach(() => { process.env.NODE_ENV = 'production'; setEventLoopDelayThreshold(); + setEventLoopDelayPercentile(); mockCircuitBreaker.close(); jest.clearAllMocks(); }); @@ -45,6 +54,13 @@ describe('Circuit breaker', () => { expect(mockCircuitBreaker).toBeInstanceOf(CircuitBreaker); }); + it('should reset the histogram every 30 seconds', () => { + jest.advanceTimersByTime(30e3 + 10); + expect(histogramResetSpy).toHaveBeenCalledTimes(1); + jest.advanceTimersByTime(30e3 + 10); + expect(histogramResetSpy).toHaveBeenCalledTimes(2); + }); + it('should call the given function', async () => { expect.assertions(2); const input = 'hello, world'; @@ -78,6 +94,14 @@ describe('Circuit breaker', () => { expect(value).toEqual({ fallback: false }); }); + it('should validate against the configured percentile', async () => { + jest.advanceTimersByTime(5e3 + 10); + expect(histogramPercentileSpy).toHaveBeenCalledWith(100); + setEventLoopDelayPercentile(95); + jest.advanceTimersByTime(5e3 + 10); + expect(histogramPercentileSpy).toHaveBeenCalledWith(95); + }); + it('should not open the circuit when threshold not exceeded', async () => { expect.assertions(2); setEventLoopDelayThreshold(250); @@ -111,7 +135,7 @@ describe('Circuit breaker', () => { expect(consoleErrorSpy.mock.calls).toMatchInlineSnapshot(` [ [ - [Error: Opening circuit, event loop delay (0ms) is > eventLoopDelayThreshold (-1ms)], + [Error: Opening circuit, p(100) event loop delay (0ms) is > eventLoopDelayThreshold (-1ms)], ], ] `); @@ -142,12 +166,12 @@ describe('Circuit breaker', () => { }); describe('event loop delay threshold', () => { - it('should set a default value of 30ms', () => { + it('should set a default value of 250ms', () => { setEventLoopDelayThreshold(); expect(getEventLoopDelayThreshold()).toBe(250); }); - it('should set value to 30ms if input is not a number', () => { + it('should set value to 250ms if input is not a number', () => { setEventLoopDelayThreshold('hello, world'); expect(getEventLoopDelayThreshold()).toBe(250); }); @@ -162,4 +186,50 @@ describe('Circuit breaker', () => { expect(getEventLoopDelayThreshold()).toBe(55); }); }); + + describe('event loop delay percentile', () => { + it('should set a default value of 100', () => { + setEventLoopDelayPercentile(); + expect(consoleWarnSpy).not.toHaveBeenCalled(); + expect(getEventLoopDelayPercentile()).toBe(100); + }); + + it('should warn and set value to 100 if input is not a number', () => { + setEventLoopDelayPercentile('hello, world'); + expect(consoleWarnSpy.mock.calls[0][0]).toMatchInlineSnapshot( + '"Event loop percentile must be an integer in range 1-100; given "hello, world". Defaulting to p(100)."' + ); + expect(getEventLoopDelayPercentile()).toBe(100); + }); + + it('should warn and set value to 100 if input less than 1', () => { + setEventLoopDelayPercentile(0); + expect(consoleWarnSpy.mock.calls[0][0]).toMatchInlineSnapshot( + '"Event loop percentile must be an integer in range 1-100; given 0. Defaulting to p(100)."' + ); + expect(getEventLoopDelayPercentile()).toBe(100); + }); + + it('should warn and set value to 100 if input less grater than 100', () => { + setEventLoopDelayPercentile(101); + expect(consoleWarnSpy.mock.calls[0][0]).toMatchInlineSnapshot( + '"Event loop percentile must be an integer in range 1-100; given 101. Defaulting to p(100)."' + ); + expect(getEventLoopDelayPercentile()).toBe(100); + }); + + it('should warn and set value to 100 if input is a float', () => { + setEventLoopDelayPercentile(99.9); + expect(consoleWarnSpy.mock.calls[0][0]).toMatchInlineSnapshot( + '"Event loop percentile must be an integer in range 1-100; given 99.9. Defaulting to p(100)."' + ); + expect(getEventLoopDelayPercentile()).toBe(100); + }); + + it('should set the given value', () => { + setEventLoopDelayPercentile(44); + expect(consoleWarnSpy).not.toHaveBeenCalled(); + expect(getEventLoopDelayPercentile()).toBe(44); + }); + }); }); diff --git a/__tests__/server/utils/onModuleLoad.spec.jsx b/__tests__/server/utils/onModuleLoad.spec.jsx index 1295112c..9def7fe8 100644 --- a/__tests__/server/utils/onModuleLoad.spec.jsx +++ b/__tests__/server/utils/onModuleLoad.spec.jsx @@ -30,7 +30,7 @@ import { setCorsOrigins } from '../../../src/server/plugins/conditionallyAllowCo import { extendRestrictedAttributesAllowList, validateSafeRequestRestrictedAttributes } from '../../../src/server/utils/safeRequest'; import { setConfigureRequestLog } from '../../../src/server/utils/logging/fastifyPlugin'; import { setCreateSsrFetch } from '../../../src/server/utils/createSsrFetch'; -import { getEventLoopDelayThreshold } from '../../../src/server/utils/createCircuitBreaker'; +import { getEventLoopDelayThreshold, getEventLoopDelayPercentile } from '../../../src/server/utils/createCircuitBreaker'; import setupDnsCache from '../../../src/server/utils/setupDnsCache'; import { configurePWA } from '../../../src/server/pwa'; import { setErrorPage } from '../../../src/server/plugins/reactHtml/staticErrorPage'; @@ -374,7 +374,7 @@ describe('onModuleLoad', () => { expect(setErrorPage).toHaveBeenCalledWith(errorPageUrl); }); - it('sets the event loop lag threshold from the root module', () => { + it('sets the event loop delay threshold from the root module', () => { const eventLoopDelayThreshold = 50; expect(getEventLoopDelayThreshold()).not.toBe(eventLoopDelayThreshold); onModuleLoad({ @@ -390,6 +390,22 @@ describe('onModuleLoad', () => { expect(getEventLoopDelayThreshold()).toBe(eventLoopDelayThreshold); }); + it('sets the event loop delay percentile from the root module', () => { + const eventLoopDelayPercentile = 95; + expect(getEventLoopDelayPercentile()).not.toBe(eventLoopDelayPercentile); + onModuleLoad({ + module: { + [CONFIGURATION_KEY]: { + csp, + eventLoopDelayPercentile, + }, + [META_DATA_KEY]: { version: '1.0.14' }, + }, + moduleName: 'some-root', + }); + expect(getEventLoopDelayPercentile()).toBe(eventLoopDelayPercentile); + }); + it('logs when the root module is loaded', () => { onModuleLoad({ module: { [CONFIGURATION_KEY]: { csp }, [META_DATA_KEY]: { version: '1.0.15' } }, diff --git a/docs/api/modules/App-Configuration.md b/docs/api/modules/App-Configuration.md index d215cb2f..303dd704 100644 --- a/docs/api/modules/App-Configuration.md +++ b/docs/api/modules/App-Configuration.md @@ -19,6 +19,7 @@ if (!global.BROWSER) { pwa, createSsrFetch, eventLoopDelayThreshold, + eventLoopDelayPercentile, errorPageUrl, dnsCache, /* Child Module Specific */ @@ -67,6 +68,7 @@ export default MyModule; - [`extendSafeRequestRestrictedAttributes`](#extendsaferequestrestrictedattributes) - [`createSsrFetch`](#createssrfetch) - [`eventLoopDelayThreshold`](#eventloopdelaythreshold) + - [`eventLoopDelayPercentile`](#eventloopdelaypercentile) - [`errorPageUrl`](#errorpageurl) - [`dnsCache`](#dnsCache) - [`validateStateConfig`](#validatestateconfig) @@ -452,7 +454,7 @@ if (!global.BROWSER) { } ``` -The `eventLoopDelayThreshold` directive accepts a number representing the threshold of the event loop delay (in milliseconds) before opening the circuit. Once the circuit is open, it will remain open for 10 seconds and close at that time pending the event loop delay. The default value is `250`. If you desire to disable the event loop delay potion of the circuit breaker, set this value to `Infinity`. The circuit will also open if the error rate exceeds 10%. In practice, `eventLoopDelayThreshold` allows for tuning server side rendering (SSR) of Modules. We may increase request throughput by temporarily disabling SSR at high load through event loop delay monitoring. +The `eventLoopDelayThreshold` directive accepts a number representing the threshold of the event loop delay (in milliseconds) before opening the circuit. Once the circuit is open, it will remain open for 10 seconds and close at that time pending the event loop delay. The default value is `250`. If you desire to disable the event loop delay portion of the circuit breaker, set this value to `Infinity`. The circuit will also open if the error rate exceeds 10%. In practice, `eventLoopDelayThreshold` allows for tuning server side rendering (SSR) of Modules. We may increase request throughput by temporarily disabling SSR at high load through event loop delay monitoring. > This is disabled when NODE_ENV=development @@ -460,6 +462,22 @@ The `eventLoopDelayThreshold` directive accepts a number representing the thresh * [Frank Lloyd Root's `appConfig`](../../../prod-sample/sample-modules/frank-lloyd-root/0.0.0/src/config.js) * Library: [Opossum](https://nodeshift.dev/opossum/) +## `eventLoopDelayPercentile` +**Module Type** +* ✅ Root Module +* 🚫 Child Module + +**Shape** +```js +if (!global.BROWSER) { + Module.appConfig = { + eventLoopDelayPercentile: Number, + }; +} +``` + +The `eventLoopDelayPercentile` directive accepts an integer 1-100 representing the percentile upon which the `eventLoopDelayThreshold` must be crossed before opening the circuit. The default value is `100` which represents the maximum event loop delay. This default will likely change in future major versions as to not base the circuit breaker state on an outlier, but rather a trend. + ## `errorPageUrl` **Module Type** diff --git a/src/server/utils/createCircuitBreaker.js b/src/server/utils/createCircuitBreaker.js index 6aebb5d2..4bddf5c8 100644 --- a/src/server/utils/createCircuitBreaker.js +++ b/src/server/utils/createCircuitBreaker.js @@ -22,12 +22,24 @@ import { registerCircuitBreaker } from '../metrics/circuit-breaker'; const { rootModuleName } = getServerStateConfig(); let eventLoopDelayThreshold = 250; +let eventLoopDelayPercentile = 100; export const setEventLoopDelayThreshold = (n) => { - eventLoopDelayThreshold = Number(n) || 250; + eventLoopDelayThreshold = Number.parseInt(n, 10) || 250; +}; + +// Default to p(100) to avoid breaking change for users expecting max delay +export const setEventLoopDelayPercentile = (n = 100) => { + if (n !== Number.parseInt(n, 10) || n < 1 || n > 100) { + console.warn(`Event loop percentile must be an integer in range 1-100; given ${JSON.stringify(n)}. Defaulting to p(100).`); + eventLoopDelayPercentile = 100; + return; + } + eventLoopDelayPercentile = n; }; export const getEventLoopDelayThreshold = () => eventLoopDelayThreshold; +export const getEventLoopDelayPercentile = () => eventLoopDelayPercentile; const options = { // Do not use a timeout @@ -41,16 +53,27 @@ const options = { const eventLoopDelayHistogram = monitorEventLoopDelay(); eventLoopDelayHistogram.enable(); -const checkMaxEventLoopDelay = async () => { +export const getEventLoopDelayHistogram = () => eventLoopDelayHistogram; + +let histogramResetInterval; +const clearAndResetHistorgramResetInterval = () => { + clearInterval(histogramResetInterval); + // Reset histogram every 30 seconds because it biases lower over time + histogramResetInterval = setInterval(() => eventLoopDelayHistogram.reset(), 30e3); +}; + +const checkEventLoopDelay = async () => { if (process.env.NODE_ENV === 'development') return; // Return if root module is not loaded, as that is where threshold is configured if (!getModule(rootModuleName)) return; // Get event loop delay in milliseconds (from nanoseconds) - const maxEventLoopDelay = eventLoopDelayHistogram.max / 1e6; + const eventLoopDelay = eventLoopDelayHistogram.percentile(eventLoopDelayPercentile) / 1e6; // Open the circuit if event loop delay is greater than threshold - if (maxEventLoopDelay > eventLoopDelayThreshold) { + if (eventLoopDelay > eventLoopDelayThreshold) { eventLoopDelayHistogram.reset(); - throw new Error(`Opening circuit, event loop delay (${maxEventLoopDelay}ms) is > eventLoopDelayThreshold (${eventLoopDelayThreshold}ms)`); + // Resetting interval on circuit open will guarantee at least 10s of data on retry + clearAndResetHistorgramResetInterval(); + throw new Error(`Opening circuit, p(${eventLoopDelayPercentile}) event loop delay (${eventLoopDelay}ms) is > eventLoopDelayThreshold (${eventLoopDelayThreshold}ms)`); } }; @@ -59,8 +82,9 @@ const createCircuitBreaker = (asyncFunctionThatMightFail) => { const breaker = new CircuitBreaker(asyncFunctionThatMightFail, options); // Fallback returns true to indicate fallback behavior is needed breaker.fallback(() => ({ fallback: true })); - // Check the max event loop delay every 5 seconds - breaker.healthCheck(checkMaxEventLoopDelay, 5e3); + // Check the event loop delay every 5 seconds + breaker.healthCheck(checkEventLoopDelay, 5e3); + clearAndResetHistorgramResetInterval(); // Log when circuit breaker opens and closes breaker.on('open', () => console.log(`Circuit breaker [${asyncFunctionThatMightFail.name}] opened`)); breaker.on('close', () => console.log(`Circuit breaker [${asyncFunctionThatMightFail.name}] closed`)); diff --git a/src/server/utils/onModuleLoad.js b/src/server/utils/onModuleLoad.js index 80f830e1..28ccfdab 100644 --- a/src/server/utils/onModuleLoad.js +++ b/src/server/utils/onModuleLoad.js @@ -23,7 +23,7 @@ import readJsonFile from './readJsonFile'; import { extendRestrictedAttributesAllowList, validateSafeRequestRestrictedAttributes } from './safeRequest'; import { setConfigureRequestLog } from './logging/fastifyPlugin'; import { setCreateSsrFetch } from './createSsrFetch'; -import { setEventLoopDelayThreshold } from './createCircuitBreaker'; +import { setEventLoopDelayThreshold, setEventLoopDelayPercentile } from './createCircuitBreaker'; import setupDnsCache from './setupDnsCache'; import { configurePWA } from '../pwa'; import { validatePWAConfig } from './validation'; @@ -71,6 +71,7 @@ export function validateCspIsPresent(csp) { } } +/* eslint complexity: ['error', 12] */ export default function onModuleLoad({ module, moduleName, @@ -86,6 +87,7 @@ export default function onModuleLoad({ extendSafeRequestRestrictedAttributes = {}, createSsrFetch, eventLoopDelayThreshold, + eventLoopDelayPercentile, pwa, errorPageUrl, dnsCache, @@ -128,7 +130,8 @@ export default function onModuleLoad({ extendRestrictedAttributesAllowList(extendSafeRequestRestrictedAttributes); setConfigureRequestLog(configureRequestLog); setCreateSsrFetch(createSsrFetch); - setEventLoopDelayThreshold(eventLoopDelayThreshold); + if (eventLoopDelayThreshold) setEventLoopDelayThreshold(eventLoopDelayThreshold); + if (eventLoopDelayPercentile) setEventLoopDelayPercentile(eventLoopDelayPercentile); configurePWA(validatePWAConfig(pwa, { clientStateConfig: getClientStateConfig(), }));