Skip to content

Commit 7d0f17d

Browse files
dreamorosidreamorosi
committed
chore: add advanced tests logger
1 parent 22115fc commit 7d0f17d

File tree

7 files changed

+268
-8
lines changed

7 files changed

+268
-8
lines changed

‎packages/logger/package.json‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,10 @@
6262
"types": [
6363
"lib/cjs/types/index.d.ts",
6464
"lib/esm/types/index.d.ts"
65+
],
66+
"correlationId": [
67+
"lib/cjs/correlationId.d.ts",
68+
"lib/esm/correlationId.d.ts"
6569
]
6670
}
6771
},

‎packages/logger/tests/e2e/advancedUses.test.FunctionCode.ts‎

Lines changed: 63 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,63 @@
1+
import { Logger } from '@aws-lambda-powertools/logger';
2+
import {
3+
correlationPaths,
4+
search,
5+
} from '@aws-lambda-powertools/logger/correlationId';
6+
import { injectLambdaContext } from '@aws-lambda-powertools/logger/middleware';
7+
import type { Context } from 'aws-lambda';
8+
import middy from 'middy5';
9+
10+
const logger = new Logger({
11+
logLevel: 'DEBUG',
12+
logBufferOptions: {
13+
enabled: true,
14+
flushOnErrorLog: true,
15+
},
16+
correlationIdSearchFn: search,
17+
});
18+
19+
logger.debug('a never buffered debug log');
20+
21+
export const handlerManual = async (event: unknown) => {
22+
logger.addContext({} as Context); // we want only the cold start value
23+
logger.setCorrelationId(event, correlationPaths.EVENT_BRIDGE);
24+
25+
logger.debug('a buffered debug log');
26+
logger.info('an info log');
27+
try {
28+
throw new Error('ops');
29+
} catch (error) {
30+
logger.error('Uncaught error detected, flushing log buffer before exit', {
31+
error,
32+
});
33+
} finally {
34+
logger.clearBuffer();
35+
}
36+
};
37+
38+
export const handlerMiddy = middy()
39+
.use(
40+
injectLambdaContext(logger, {
41+
correlationIdPath: correlationPaths.EVENT_BRIDGE,
42+
flushBufferOnUncaughtError: true,
43+
})
44+
)
45+
.handler(async () => {
46+
logger.debug('a buffered debug log');
47+
logger.info('an info log');
48+
throw new Error('ops');
49+
});
50+
51+
class Lambda {
52+
@logger.injectLambdaContext({
53+
correlationIdPath: correlationPaths.EVENT_BRIDGE,
54+
flushBufferOnUncaughtError: true,
55+
})
56+
public async handler(_event: unknown, _context: Context) {
57+
logger.debug('a buffered debug log');
58+
logger.info('an info log');
59+
throw new Error('ops');
60+
}
61+
}
62+
const lambda = new Lambda();
63+
export const handlerDecorator = lambda.handler.bind(lambda);

‎packages/logger/tests/e2e/advancedUses.test.ts‎

Lines changed: 173 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,173 @@
1+
import { join } from 'node:path';
2+
import {
3+
TestInvocationLogs,
4+
TestStack,
5+
invokeFunction,
6+
} from '@aws-lambda-powertools/testing-utils';
7+
import { afterAll, beforeAll, describe, expect, it } from 'vitest';
8+
import { LoggerTestNodejsFunction } from '../helpers/resources.js';
9+
import {
10+
RESOURCE_NAME_PREFIX,
11+
SETUP_TIMEOUT,
12+
STACK_OUTPUT_LOG_GROUP,
13+
TEARDOWN_TIMEOUT,
14+
TEST_CASE_TIMEOUT,
15+
} from './constants.js';
16+
17+
/**
18+
* In this e2e test for Logger, we test a number of advanced use cases:
19+
* - Log buffering enabled with flush on error (both manually on logger.error and automatically on uncaught error)
20+
* - Correlation ID injection (both manually and automatically)
21+
*
22+
* The test is split into three cases:
23+
* - Manual instrumentation
24+
* - Middy middleware
25+
* - Decorator
26+
*/
27+
describe('Logger E2E - Advanced uses', () => {
28+
const testStack = new TestStack({
29+
stackNameProps: {
30+
stackNamePrefix: RESOURCE_NAME_PREFIX,
31+
testName: 'Advanced',
32+
},
33+
});
34+
35+
// Location of the lambda function code
36+
const lambdaFunctionCodeFilePath = join(
37+
__dirname,
38+
'advancedUses.test.FunctionCode.ts'
39+
);
40+
41+
const invocationCount = 2;
42+
const invocationLogs = new Map<string, TestInvocationLogs[]>();
43+
const manualCase = 'Manual';
44+
const middyCase = 'Middy';
45+
const decoratorCase = 'Decorator';
46+
47+
beforeAll(async () => {
48+
invocationLogs.set(manualCase, []);
49+
invocationLogs.set(middyCase, []);
50+
invocationLogs.set(decoratorCase, []);
51+
for (const caseKey of invocationLogs.keys()) {
52+
new LoggerTestNodejsFunction(
53+
testStack,
54+
{
55+
entry: lambdaFunctionCodeFilePath,
56+
handler: `handler${caseKey}`,
57+
},
58+
{
59+
logGroupOutputKey: STACK_OUTPUT_LOG_GROUP,
60+
nameSuffix: caseKey,
61+
createAlias: true,
62+
}
63+
);
64+
}
65+
66+
await testStack.deploy();
67+
68+
for (const caseKey of invocationLogs.keys()) {
69+
const functionArn = testStack.findAndGetStackOutputValue(caseKey);
70+
const logs = await invokeFunction({
71+
functionName: functionArn,
72+
times: invocationCount,
73+
invocationMode: 'SEQUENTIAL',
74+
payload: [
75+
{
76+
id: 1,
77+
},
78+
{
79+
id: 2,
80+
},
81+
],
82+
});
83+
invocationLogs.set(caseKey, logs);
84+
}
85+
}, SETUP_TIMEOUT);
86+
87+
it.each([
88+
{
89+
caseKey: manualCase,
90+
},
91+
{
92+
caseKey: middyCase,
93+
},
94+
{
95+
caseKey: decoratorCase,
96+
},
97+
])(
98+
'$caseKey instrumentation',
99+
({ caseKey }) => {
100+
for (let i = 0; i < invocationCount; i++) {
101+
const isFirstInvocation = i === 0;
102+
// Get log messages of the i-th invocation
103+
const fnLogs = invocationLogs.get(caseKey)?.at(i)?.getFunctionLogs();
104+
if (!fnLogs || fnLogs.length === 0) {
105+
throw new Error(`Failed to get logs for ${caseKey} invocation ${i}`);
106+
}
107+
// When using decorator & middleware, we are actually throwing an error
108+
// which is logged by the runtime, so we need to filter out the logs that are
109+
// not JSON formatted
110+
const logs = fnLogs.filter((log) => {
111+
try {
112+
JSON.parse(log);
113+
return true;
114+
} catch (error) {
115+
return false;
116+
}
117+
});
118+
119+
if (isFirstInvocation) {
120+
// Logs outside of the function handler are only present on the first invocation
121+
expect(TestInvocationLogs.parseFunctionLog(logs[0])).toEqual(
122+
expect.objectContaining({
123+
level: 'DEBUG',
124+
message: 'a never buffered debug log',
125+
})
126+
);
127+
}
128+
// Since we have an extra log (above) on the first invocation, we need to
129+
// adjust the index of the logs we are checking
130+
const logIndexOffset = isFirstInvocation ? 1 : 0;
131+
const correlationId = i + 1;
132+
expect(
133+
TestInvocationLogs.parseFunctionLog(logs[0 + logIndexOffset])
134+
).toEqual(
135+
expect.objectContaining({
136+
level: 'INFO',
137+
message: 'an info log',
138+
correlation_id: correlationId,
139+
})
140+
);
141+
expect(
142+
TestInvocationLogs.parseFunctionLog(logs[1 + logIndexOffset])
143+
).toEqual(
144+
expect.objectContaining({
145+
level: 'DEBUG',
146+
message: 'a buffered debug log',
147+
correlation_id: correlationId,
148+
})
149+
);
150+
expect(
151+
TestInvocationLogs.parseFunctionLog(logs.at(-1) as string)
152+
).toEqual(
153+
expect.objectContaining({
154+
level: 'ERROR',
155+
message: 'Uncaught error detected, flushing log buffer before exit',
156+
correlation_id: correlationId,
157+
error: expect.objectContaining({
158+
name: 'Error',
159+
message: 'ops',
160+
}),
161+
})
162+
);
163+
}
164+
},
165+
TEST_CASE_TIMEOUT
166+
);
167+
168+
afterAll(async () => {
169+
if (!process.env.DISABLE_TEARDOWN) {
170+
await testStack.destroy();
171+
}
172+
}, TEARDOWN_TIMEOUT);
173+
});

‎packages/testing/src/TestInvocationLogs.ts‎

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ import type { FunctionLog } from './types.js';
44
const CloudWatchLogKeywords = {
55
END: 'END RequestId',
66
INIT_START: 'INIT_START',
7+
INIT_REPORT: 'INIT_REPORT',
78
REPORT: 'REPORT RequestId',
89
START: 'START RequestId',
910
XRAY: 'XRAY TraceId',
@@ -99,13 +100,15 @@ class TestInvocationLogs {
99100
}
100101

101102
/**
102-
* Return the index of the log that contains `INIT_START`
103-
* @param logs
104-
* @returns {number} index of the log that contains `INIT_START`
103+
* Return the index of the log that contains `INIT_START` or `INIT_REPORT`
104+
*
105+
* @param logs - Array of logs
105106
*/
106107
public static getInitLogIndex(logs: string[]): number {
107-
return logs.findIndex((log) =>
108-
log.startsWith(CloudWatchLogKeywords.INIT_START)
108+
return logs.findIndex(
109+
(log) =>
110+
log.startsWith(CloudWatchLogKeywords.INIT_START) ||
111+
log.startsWith(CloudWatchLogKeywords.INIT_REPORT)
109112
);
110113
}
111114

‎packages/testing/src/resources/TestNodejsFunction.ts‎

Lines changed: 13 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
import { randomUUID } from 'node:crypto';
2-
import { CfnOutput, type CfnResource, Duration } from 'aws-cdk-lib';
3-
import { Tracing } from 'aws-cdk-lib/aws-lambda';
2+
import { CfnOutput, Duration } from 'aws-cdk-lib';
3+
import { Alias, Tracing } from 'aws-cdk-lib/aws-lambda';
44
import { NodejsFunction, OutputFormat } from 'aws-cdk-lib/aws-lambda-nodejs';
55
import { LogGroup, RetentionDays } from 'aws-cdk-lib/aws-logs';
66
import type { TestStack } from '../TestStack.js';
@@ -56,8 +56,18 @@ class TestNodejsFunction extends NodejsFunction {
5656
logGroup,
5757
});
5858

59+
let outputValue = this.functionName;
60+
if (extraProps.createAlias) {
61+
const dev = new Alias(this, 'dev', {
62+
aliasName: 'dev',
63+
version: this.currentVersion,
64+
provisionedConcurrentExecutions: 1,
65+
});
66+
outputValue = dev.functionArn;
67+
}
68+
5969
new CfnOutput(this, extraProps.nameSuffix, {
60-
value: this.functionName,
70+
value: outputValue,
6171
});
6272
}
6373
}

‎packages/testing/src/setupEnv.ts‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -377,3 +377,4 @@ if (
377377
process.env._HANDLER = 'index.handler';
378378
process.env.POWERTOOLS_SERVICE_NAME = 'hello-world';
379379
process.env.AWS_XRAY_LOGGING_LEVEL = 'silent';
380+
process.env.AWS_LAMBDA_INITIALIZATION_TYPE = 'on-demand';

‎packages/testing/src/types.ts‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,12 @@ interface ExtraTestProps {
1919
* @default 'CJS'
2020
*/
2121
outputFormat?: 'CJS' | 'ESM';
22+
/**
23+
* Whether to create an alias for the function.
24+
*
25+
* @default false
26+
*/
27+
createAlias?: boolean;
2228
}
2329

2430
type TestDynamodbTableProps = Omit<

0 commit comments

Comments
 (0)