Skip to content

Commit 8c8d6b2

Browse files
authored
feat(logger): refresh sample rate calculation before each invocation (#3672)
1 parent 270115e commit 8c8d6b2

File tree

7 files changed

+53
-7
lines changed

7 files changed

+53
-7
lines changed

Diff for: docs/core/logger.md

+3-4
Original file line numberDiff line numberDiff line change
@@ -634,7 +634,7 @@ Once a child logger is created, the logger and its parent will act as separate i
634634

635635
### Sampling debug logs
636636

637-
Use sampling when you want to dynamically change your log level to **DEBUG** based on a **percentage of your concurrent/cold start invocations**.
637+
Use sampling when you want to dynamically change your log level to **DEBUG** based on a **percentage of your invocations**.
638638

639639
You can use values ranging from `0` to `1` (100%) when setting the `sampleRateValue` constructor option or `POWERTOOLS_LOGGER_SAMPLE_RATE` env var.
640640

@@ -643,10 +643,9 @@ You can use values ranging from `0` to `1` (100%) when setting the `sampleRateVa
643643

644644
This feature takes into account transient issues where additional debugging information can be useful.
645645

646-
Sampling decision happens at the Logger initialization. This means sampling may happen significantly more or less than depending on your traffic patterns, for example a steady low number of invocations and thus few cold starts.
646+
Sampling decision happens at the Logger initialization. When using the `injectLambdaContext` method either as a decorator or middleware, the sampling decision is refreshed at the beginning of each Lambda invocation for you, except for cold starts.
647647

648-
!!! note
649-
Open a [feature request](https://github.com/aws-powertools/powertools-lambda-typescript/issues/new?assignees=&labels=type%2Ffeature-request%2Ctriage&projects=aws-powertools%2F7&template=feature_request.yml&title=Feature+request%3A+TITLE) if you want Logger to calculate sampling for every invocation
648+
If you're not using either of these, you'll need to manually call the `refreshSamplingRate()` function at the start of your handler to refresh the sampling decision for each invocation.
650649

651650
=== "handler.ts"
652651

Diff for: examples/snippets/logger/logSampling.ts

+2
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,8 @@ export const handler = async (
1010
_event: unknown,
1111
_context: unknown
1212
): Promise<void> => {
13+
// Refresh sample rate calculation on runtime, only when not using injectLambdaContext
14+
logger.refreshSampleRateCalculation();
1315
// This log item (equal to log level 'ERROR') will be printed to standard output
1416
// in all Lambda invocations
1517
logger.error('This is an ERROR log');

Diff for: packages/commons/src/Utility.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@
5151
* ```
5252
*/
5353
export class Utility {
54-
private coldStart = true;
54+
protected coldStart = true;
5555
private readonly defaultServiceName: string = 'service_undefined';
5656

5757
/**

Diff for: packages/logger/src/Logger.ts

+6-1
Original file line numberDiff line numberDiff line change
@@ -419,6 +419,7 @@ class Logger extends Utility implements LoggerInterface {
419419
context,
420420
callback
421421
) {
422+
loggerRef.refreshSampleRateCalculation();
422423
Logger.injectLambdaContextBefore(loggerRef, event, context, options);
423424

424425
let result: unknown;
@@ -493,9 +494,13 @@ class Logger extends Utility implements LoggerInterface {
493494
* This method allows recalculating the initial sampling decision for changing
494495
* the log level to DEBUG based on a sample rate value used during initialization,
495496
* potentially yielding a different outcome.
497+
*
498+
* This only works for warm starts, because we don't to avoid double sampling.
496499
*/
497500
public refreshSampleRateCalculation(): void {
498-
this.setInitialSampleRate(this.powertoolsLogData.sampleRateValue);
501+
if (!this.coldStart) {
502+
this.setInitialSampleRate(this.powertoolsLogData.sampleRateValue);
503+
}
499504
}
500505

501506
/**

Diff for: packages/logger/src/middleware/middy.ts

+3
Original file line numberDiff line numberDiff line change
@@ -87,6 +87,9 @@ const injectLambdaContext = (
8787
if (isResetStateEnabled) {
8888
setCleanupFunction(request);
8989
}
90+
91+
logger.refreshSampleRateCalculation();
92+
9093
Logger.injectLambdaContextBefore(
9194
logger,
9295
request.event,

Diff for: packages/logger/tests/unit/injectLambdaContext.test.ts

+35
Original file line numberDiff line numberDiff line change
@@ -184,4 +184,39 @@ describe('Inject Lambda Context', () => {
184184
})
185185
);
186186
});
187+
188+
it('refreshes sample rate calculation before each invocation using decorator for warm start only', async () => {
189+
// Prepare
190+
const logger = new Logger({ sampleRateValue: 0.5 });
191+
const refreshSpy = vi.spyOn(logger, 'refreshSampleRateCalculation');
192+
193+
class Lambda {
194+
@logger.injectLambdaContext()
195+
public async handler(_event: unknown, _context: Context): Promise<void> {
196+
logger.info('test');
197+
}
198+
}
199+
const lambda = new Lambda();
200+
// Act
201+
await lambda.handler({}, {} as Context);
202+
203+
// Assess
204+
expect(refreshSpy).toHaveBeenCalledTimes(1);
205+
});
206+
207+
it('refreshes sample rate calculation before each invocation using middleware for warm start only', async () => {
208+
// Prepare
209+
const logger = new Logger({ sampleRateValue: 0.5 });
210+
const refreshSpy = vi.spyOn(logger, 'refreshSampleRateCalculation');
211+
212+
const handler = middy(async () => {
213+
logger.info('Hello, world!');
214+
}).use(injectLambdaContext(logger));
215+
216+
// Act
217+
await handler(event, context);
218+
219+
// Assess
220+
expect(refreshSpy).toHaveBeenCalledTimes(1);
221+
});
187222
});

Diff for: packages/logger/tests/unit/sampling.test.ts

+3-1
Original file line numberDiff line numberDiff line change
@@ -129,13 +129,15 @@ describe('Log sampling', () => {
129129
expect(logger.getLevelName()).toBe(LogLevel.INFO);
130130
});
131131

132-
it('when sample rate calculation is refreshed, it respects probability sampling and change log level to DEBUG ', () => {
132+
it('when sample rate calculation is refreshed, it respects probability sampling and change log level to DEBUG when not in coldStart ', () => {
133133
// Prepare
134134
const logger = new Logger({
135135
logLevel: LogLevel.ERROR,
136136
sampleRateValue: 0.1, // 10% probability
137137
});
138138

139+
logger.getColdStart(); // Set coldStart to false
140+
139141
let logLevelChangedToDebug = 0;
140142
const numOfIterations = 1000;
141143
const minExpected = numOfIterations * 0.05; // Min expected based on 5% probability

0 commit comments

Comments
 (0)