diff --git a/packages/plugin-aws-lambda/src/index.js b/packages/plugin-aws-lambda/src/index.js index cc27c54e54..c79296e9dd 100644 --- a/packages/plugin-aws-lambda/src/index.js +++ b/packages/plugin-aws-lambda/src/index.js @@ -1,5 +1,11 @@ const bugsnagInFlight = require('@bugsnag/in-flight') const BugsnagPluginBrowserSession = require('@bugsnag/plugin-browser-session') +const LambdaTimeoutApproaching = require('./lambda-timeout-approaching') + +// JS timers use a signed 32 bit integer for the millisecond parameter. SAM's +// "local invoke" has a bug that means it exceeds this amount, resulting in +// warnings. See https://github.com/aws/aws-sam-cli/issues/2519 +const MAX_TIMER_VALUE = Math.pow(2, 31) - 1 const BugsnagPluginAwsLambda = { name: 'awsLambda', @@ -32,14 +38,14 @@ const BugsnagPluginAwsLambda = { } return { - createHandler ({ flushTimeoutMs = 2000 } = {}) { - return wrapHandler.bind(null, client, flushTimeoutMs) + createHandler ({ flushTimeoutMs = 2000, lambdaTimeoutNotifyMs = 1000 } = {}) { + return wrapHandler.bind(null, client, flushTimeoutMs, lambdaTimeoutNotifyMs) } } } } -function wrapHandler (client, flushTimeoutMs, handler) { +function wrapHandler (client, flushTimeoutMs, lambdaTimeoutNotifyMs, handler) { let _handler = handler if (handler.length > 2) { @@ -49,6 +55,38 @@ function wrapHandler (client, flushTimeoutMs, handler) { } return async function (event, context) { + let lambdaTimeout + + // Guard against the "getRemainingTimeInMillis" being missing. This should + // never happen but could when unit testing + if (typeof context.getRemainingTimeInMillis === 'function' && + lambdaTimeoutNotifyMs > 0 + ) { + const timeoutMs = context.getRemainingTimeInMillis() - lambdaTimeoutNotifyMs + + if (timeoutMs <= MAX_TIMER_VALUE) { + lambdaTimeout = setTimeout(function () { + const handledState = { + severity: 'warning', + unhandled: true, + severityReason: { type: 'log' } + } + + const event = client.Event.create( + new LambdaTimeoutApproaching(context.getRemainingTimeInMillis()), + true, + handledState, + 'aws lambda plugin', + 0 + ) + + event.context = context.functionName || 'Lambda timeout approaching' + + client._notify(event) + }, timeoutMs) + } + } + client.addMetadata('AWS Lambda context', context) if (client._config.autoTrackSessions) { @@ -72,6 +110,10 @@ function wrapHandler (client, flushTimeoutMs, handler) { throw err } finally { + if (lambdaTimeout) { + clearTimeout(lambdaTimeout) + } + try { await bugsnagInFlight.flush(flushTimeoutMs) } catch (err) { diff --git a/packages/plugin-aws-lambda/src/lambda-timeout-approaching.js b/packages/plugin-aws-lambda/src/lambda-timeout-approaching.js new file mode 100644 index 0000000000..ad48611bca --- /dev/null +++ b/packages/plugin-aws-lambda/src/lambda-timeout-approaching.js @@ -0,0 +1,10 @@ +module.exports = class LambdaTimeoutApproaching extends Error { + constructor (remainingMs) { + const message = `Lambda will timeout in ${remainingMs}ms` + + super(message) + + this.name = 'LambdaTimeoutApproaching' + this.stack = [] + } +} diff --git a/packages/plugin-aws-lambda/test/index.test.ts b/packages/plugin-aws-lambda/test/index.test.ts index 301c660616..0532d8ccaa 100644 --- a/packages/plugin-aws-lambda/test/index.test.ts +++ b/packages/plugin-aws-lambda/test/index.test.ts @@ -24,6 +24,16 @@ const createClient = (events: EventDeliveryPayload[], sessions: SessionDeliveryP return client } +const DEFAULT_REMAINING_MS = 250 +let getRemainingTimeInMillis: jest.MockedFunction<() => number> + +beforeEach(() => { + getRemainingTimeInMillis = jest.fn() + .mockReturnValueOnce(DEFAULT_REMAINING_MS) + .mockReturnValueOnce(DEFAULT_REMAINING_MS / 2) + .mockImplementationOnce(() => { throw new Error('unexpected call to "getRemainingTimeInMillis"') }) +}) + describe('plugin: aws lambda', () => { it('has a name', () => { expect(BugsnagPluginAwsLambda.name).toBe('awsLambda') @@ -514,4 +524,215 @@ describe('plugin: aws lambda', () => { expect(events).toHaveLength(0) expect(sessions).toHaveLength(0) }) + + it('notifies when it is close to timing out (async)', async () => { + const events: EventDeliveryPayload[] = [] + const sessions: SessionDeliveryPayload[] = [] + + const client = createClient(events, sessions) + + const handler = async (event: any, context: any) => new Promise(resolve => { + setTimeout(() => resolve('xyz'), DEFAULT_REMAINING_MS + 100) + }) + + const event = { very: 'eventy' } + const context = { extremely: 'contextual', getRemainingTimeInMillis } + + const plugin = client.getPlugin('awsLambda') + + if (!plugin) { + throw new Error('Plugin was not loaded!') + } + + const bugsnagHandler = plugin.createHandler() + const wrappedHandler = bugsnagHandler(handler) + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(0) + + expect(await wrappedHandler(event, context)).toBe('xyz') + + expect(events).toHaveLength(1) + expect(events[0].events).toHaveLength(1) + expect(events[0].events[0].errors).toHaveLength(1) + expect(events[0].events[0].context).toBe('Lambda timeout approaching') + + const expectedError = { + errorClass: 'LambdaTimeoutApproaching', + errorMessage: `Lambda will timeout in ${DEFAULT_REMAINING_MS / 2}ms`, + stacktrace: [], + type: 'nodejs' + } + + expect(events[0].events[0].errors[0]).toEqual(expectedError) + + expect(sessions).toHaveLength(1) + }) + + it('notifies when it is close to timing out (callback)', async () => { + const events: EventDeliveryPayload[] = [] + const sessions: SessionDeliveryPayload[] = [] + + const client = createClient(events, sessions) + + const handler = (event: any, context: any, callback: any) => new Promise(resolve => { + setTimeout(() => callback(null, 'xyz'), DEFAULT_REMAINING_MS + 100) + }) + + const event = { very: 'eventy' } + const context = { extremely: 'contextual', getRemainingTimeInMillis } + + const plugin = client.getPlugin('awsLambda') + + if (!plugin) { + throw new Error('Plugin was not loaded!') + } + + const bugsnagHandler = plugin.createHandler() + const wrappedHandler = bugsnagHandler(handler) + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(0) + + expect(await wrappedHandler(event, context)).toBe('xyz') + + expect(events).toHaveLength(1) + expect(events[0].events).toHaveLength(1) + expect(events[0].events[0].errors).toHaveLength(1) + expect(events[0].events[0].context).toBe('Lambda timeout approaching') + + const expectedError = { + errorClass: 'LambdaTimeoutApproaching', + errorMessage: `Lambda will timeout in ${DEFAULT_REMAINING_MS / 2}ms`, + stacktrace: [], + type: 'nodejs' + } + + expect(events[0].events[0].errors[0]).toEqual(expectedError) + + expect(sessions).toHaveLength(1) + }) + + it('uses the function name as the event context when present', async () => { + const events: EventDeliveryPayload[] = [] + const sessions: SessionDeliveryPayload[] = [] + + const client = createClient(events, sessions) + + const handler = async (event: any, context: any) => new Promise(resolve => { + setTimeout(() => resolve('xyz'), DEFAULT_REMAINING_MS + 100) + }) + + const event = { very: 'eventy' } + const context = { functionName: 'MyCoolAndGoodLambdaFunction', getRemainingTimeInMillis } + + const plugin = client.getPlugin('awsLambda') + + if (!plugin) { + throw new Error('Plugin was not loaded!') + } + + const bugsnagHandler = plugin.createHandler() + const wrappedHandler = bugsnagHandler(handler) + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(0) + + expect(await wrappedHandler(event, context)).toBe('xyz') + + expect(events).toHaveLength(1) + expect(events[0].events[0].errors[0].errorClass).toBe('LambdaTimeoutApproaching') + expect(events[0].events[0].errors[0].errorMessage).toBe(`Lambda will timeout in ${DEFAULT_REMAINING_MS / 2}ms`) + expect(events[0].events[0].errors[0].stacktrace).toHaveLength(0) + expect(events[0].events[0].context).toBe('MyCoolAndGoodLambdaFunction') + + expect(sessions).toHaveLength(1) + }) + + it('allows the "lambdaTimeoutNotifyMs" to be changed', async () => { + // With 6 seconds remaining and a resolve timeout of 500ms, the timeout + // warning will never be triggered unless the custom "lambdaTimeoutNotifyMs" + // takes effect + const superLongWaitMs = 6000 + const resolveTimeoutMs = 500 + const lambdaTimeoutNotifyMs = superLongWaitMs - (resolveTimeoutMs / 2) + + getRemainingTimeInMillis = jest.fn() + .mockReturnValueOnce(superLongWaitMs) + .mockReturnValueOnce(superLongWaitMs - lambdaTimeoutNotifyMs) + .mockImplementationOnce(() => { throw new Error('unexpected call to "getRemainingTimeInMillis"') }) + + const events: EventDeliveryPayload[] = [] + const sessions: SessionDeliveryPayload[] = [] + + const client = createClient(events, sessions) + + const handler = async (event: any, context: any) => new Promise(resolve => { + setTimeout(() => resolve('xyz'), resolveTimeoutMs) + }) + + const event = { very: 'eventy' } + const context = { extremely: 'contextual', getRemainingTimeInMillis } + + const plugin = client.getPlugin('awsLambda') + + if (!plugin) { + throw new Error('Plugin was not loaded!') + } + + const bugsnagHandler = plugin.createHandler({ lambdaTimeoutNotifyMs }) + const wrappedHandler = bugsnagHandler(handler) + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(0) + + expect(await wrappedHandler(event, context)).toBe('xyz') + + expect(events).toHaveLength(1) + expect(events[0].events).toHaveLength(1) + expect(events[0].events[0].errors).toHaveLength(1) + expect(events[0].events[0].context).toBe('Lambda timeout approaching') + + const expectedError = { + errorClass: 'LambdaTimeoutApproaching', + errorMessage: `Lambda will timeout in ${resolveTimeoutMs / 2}ms`, + stacktrace: [], + type: 'nodejs' + } + + expect(events[0].events[0].errors[0]).toEqual(expectedError) + + expect(sessions).toHaveLength(1) + }) + + it('does not notify if "lambdaTimeoutNotifyMs" is 0', async () => { + const events: EventDeliveryPayload[] = [] + const sessions: SessionDeliveryPayload[] = [] + + const client = createClient(events, sessions) + + const handler = async (event: any, context: any) => new Promise(resolve => { + setTimeout(() => resolve('xyz'), 100) + }) + + const event = { very: 'eventy' } + const context = { extremely: 'contextual', getRemainingTimeInMillis } + + const plugin = client.getPlugin('awsLambda') + + if (!plugin) { + throw new Error('Plugin was not loaded!') + } + + const bugsnagHandler = plugin.createHandler({ lambdaTimeoutNotifyMs: 0 }) + const wrappedHandler = bugsnagHandler(handler) + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(0) + + expect(await wrappedHandler(event, context)).toBe('xyz') + + expect(events).toHaveLength(0) + expect(sessions).toHaveLength(1) + }) }) diff --git a/packages/plugin-aws-lambda/types/bugsnag-plugin-aws-lambda.d.ts b/packages/plugin-aws-lambda/types/bugsnag-plugin-aws-lambda.d.ts index 231a06cc68..5b0b0e1a3f 100644 --- a/packages/plugin-aws-lambda/types/bugsnag-plugin-aws-lambda.d.ts +++ b/packages/plugin-aws-lambda/types/bugsnag-plugin-aws-lambda.d.ts @@ -10,6 +10,7 @@ export type BugsnagPluginAwsLambdaHandler = (handler: AsyncHandler|CallbackHandl export interface BugsnagPluginAwsLambdaConfiguration { flushTimeoutMs?: number + lambdaTimeoutNotifyMs?: number } export interface BugsnagPluginAwsLambdaResult {