Skip to content

Commit 218ecf1

Browse files
dreamorosidreamorosi
committed
test: advanced logger use case
1 parent e7c141e commit 218ecf1

File tree

7 files changed

+275
-9
lines changed

7 files changed

+275
-9
lines changed

‎packages/commons/src/Utility.ts‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,10 @@
5151
* ```
5252
*/
5353
export class Utility {
54-
#initializationType: 'unknown' | 'on-demand' | 'provisioned-concurrency';
54+
readonly #initializationType:
55+
| 'unknown'
56+
| 'on-demand'
57+
| 'provisioned-concurrency';
5558
protected coldStart = true;
5659
protected readonly defaultServiceName: string = 'service_undefined';
5760

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

‎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/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)