Skip to content

feat(logger): add silent log level to suppress the emission of all logs #1347

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 5 commits into from
Mar 3, 2023
Merged

feat(logger): add silent log level to suppress the emission of all logs #1347

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
13e3780
feat(logger): add silent log level to suppress the emission of all logs
shdq Feb 28, 2023
c45b21a
test: cleanup
shdq Feb 28, 2023
697d785
docs(logger): update text and formatting, add comments
shdq Mar 1, 2023
b9ce817
docs(logger): update table formatting
shdq Mar 1, 2023
2aaa3d8
docs(logger): add section about silencing logs
shdq Mar 3, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 18 additions & 7 deletions docs/core/logger.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,12 +46,12 @@ The library requires two settings. You can set them as environment variables, or

These settings will be used across all logs emitted:

| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter |
|-------------------------|------------------------------------------------------------------------------------------------------------------|---------------------------------|---------------------|--------------------------------|--------------------|-----------------------|
| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline`| `serviceName` |
| **Logging level** | Sets how verbose Logger should be | `LOG_LEVEL` | `info` |`DEBUG`, `INFO`, `WARN`, `ERROR`| `ERROR` | `logLevel` |
| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware. | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` |
| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting. | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` |
| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter |
|-------------------------|------------------------------------------------------------------------------------------------------------------|---------------------------------|---------------------|-------------------------------------------|--------------------|-----------------------|
| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline`| `serviceName` |
| **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | `LOG_LEVEL` | `info` |`DEBUG`, `INFO`, `WARN`, `ERROR`, `SILENT` | `ERROR` | `logLevel` |
| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` |
| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` |

#### Example using AWS Serverless Application Model (SAM)

Expand Down Expand Up @@ -81,7 +81,7 @@ Your Logger will include the following keys to your structured logging (default

| Key | Example | Note |
|-----------------------------|------------------------------------------------------------------------------------------------------------------|---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| **level**: `string` | `INFO` | Logging level set for the Lambda function"s invocation |
| **level**: `string` | `INFO` | Logging level set for the Lambda function's invocation |
| **message**: `string` | `Query performed to DynamoDB` | A descriptive, human-readable representation of this log item |
| **sampling_rate**: `float` | `0.1` | When enabled, it prints all the logs of a percentage of invocations, e.g. 10% |
| **service**: `string` | `serverlessAirline` | A unique name identifier of the service this Lambda function belongs to, by default `service_undefined` |
Expand Down Expand Up @@ -555,6 +555,17 @@ For example, by setting the "sample rate" to `0.5`, roughly 50% of your lambda i
}
```

### Silencing logs

The `SILENT` log level provides a simple and efficient way to suppress all log messages without the need to modify your code. When you set this log level, all log messages, regardless of their severity, will be silenced.

This feature is useful when you want to have your code instrumented to produce logs, but due to some requirement or business decision, you prefer to not emit them.

By setting the log level to `SILENT`, which can be done either through the `logLevel` constructor option or by using the `LOG_LEVEL` environment variable, you can easily suppress all logs as needed.

!!! note
Use the `SILENT` log level with care, as it can make it more challenging to monitor and debug your application. Therefore, we advise using this log level judiciously.

### Custom Log formatter (Bring Your Own Formatter)

You can customize the structure (keys and values) of your log items by passing a custom log formatter, an object that implements the `LogFormatter` abstract class.
Expand Down
2 changes: 2 additions & 0 deletions packages/logger/src/Logger.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -130,11 +130,13 @@ class Logger extends Utility implements ClassThatLogs {

private logLevel?: Uppercase<LogLevel>;

// Log levels are in ascending order from the most verbose to the least verbose (no logs)
private readonly logLevelThresholds: LogLevelThresholds = {
DEBUG: 8,
INFO: 12,
WARN: 16,
ERROR: 20,
SILENT: 24,
};

private logsSampled: boolean = false;
Expand Down
3 changes: 2 additions & 1 deletion packages/logger/src/types/Log.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,8 +2,9 @@ type LogLevelDebug = 'DEBUG';
type LogLevelInfo = 'INFO';
type LogLevelWarn = 'WARN';
type LogLevelError = 'ERROR';
type LogLevelSilent = 'SILENT';

type LogLevel = LogLevelDebug | Lowercase<LogLevelDebug> | LogLevelInfo | Lowercase<LogLevelInfo> | LogLevelWarn | Lowercase<LogLevelWarn> | LogLevelError | Lowercase<LogLevelError>;
type LogLevel = LogLevelDebug | Lowercase<LogLevelDebug> | LogLevelInfo | Lowercase<LogLevelInfo> | LogLevelWarn | Lowercase<LogLevelWarn> | LogLevelError | Lowercase<LogLevelError> | LogLevelSilent | Lowercase<LogLevelSilent>;

type LogLevelThresholds = {
[key in Uppercase<LogLevel>]: number;
Expand Down
127 changes: 62 additions & 65 deletions packages/logger/tests/unit/Logger.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ import {
import { createLogger, Logger } from '../../src';
import { EnvironmentVariablesService } from '../../src/config';
import { PowertoolLogFormatter } from '../../src/formatter';
import { ClassThatLogs, LogJsonIndent, ConstructorOptions } from '../../src/types';
import { ClassThatLogs, LogJsonIndent, ConstructorOptions, LogLevelThresholds } from '../../src/types';
import { Context } from 'aws-lambda';
import { Console } from 'console';

Expand All @@ -22,6 +22,13 @@ describe('Class: Logger', () => {
const ENVIRONMENT_VARIABLES = process.env;
const context = dummyContext.helloworldContext;
const event = dummyEvent.Custom.CustomEvent;
const logLevelThresholds: LogLevelThresholds = {
DEBUG: 8,
INFO: 12,
WARN: 16,
ERROR: 20,
SILENT: 24,
};

beforeEach(() => {
dateSpy.mockClear();
Expand Down Expand Up @@ -60,9 +67,7 @@ describe('Class: Logger', () => {
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
if (logger[methodOfLogger]) {
logger[methodOfLogger]('foo');
}
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(debugPrints ? 1 : 0);
Expand All @@ -87,9 +92,7 @@ describe('Class: Logger', () => {
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
if (logger[methodOfLogger]) {
logger[methodOfLogger]('foo');
}
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(infoPrints ? 1 : 0);
Expand All @@ -114,9 +117,7 @@ describe('Class: Logger', () => {
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
if (logger[methodOfLogger]) {
logger[methodOfLogger]('foo');
}
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(warnPrints ? 1 : 0);
Expand All @@ -141,9 +142,7 @@ describe('Class: Logger', () => {
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
if (logger[methodOfLogger]) {
logger[methodOfLogger]('foo');
}
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(errorPrints ? 1 : 0);
Expand All @@ -159,6 +158,41 @@ describe('Class: Logger', () => {

});

test('when the Logger\'s log level is SILENT, it DOES NOT print to stdout', () => {

// Prepare
const logger: Logger = createLogger({
logLevel: 'SILENT',
});
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(0);
});

test('when the Logger\'s log level is set through LOG_LEVEL env variable, it DOES print to stdout', () => {

// Prepare
process.env.LOG_LEVEL = methodOfLogger.toUpperCase();
const logger = new Logger();
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();

// Act
logger[methodOfLogger]('foo');

// Assess
expect(consoleSpy).toBeCalledTimes(1);
expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({
level: methodOfLogger.toUpperCase(),
message: 'foo',
service: 'hello-world',
timestamp: '2016-06-20T12:08:10.000Z',
xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793',
}));
});
});

describe('Feature: sample rate', () => {
Expand All @@ -169,7 +203,7 @@ describe('Class: Logger', () => {

// Prepare
const logger: Logger = createLogger({
logLevel: 'ERROR',
logLevel: 'SILENT',
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I changed to the highest log level when it doesn't print to stdout from any method and still prints when the sample rate is 1.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you please elaborate on this one? Not sure I'm following

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test case consists of two tests: testing with and w/o sample rate.

For the first one, it is needed to show that no logs emit with the higher log level. The error log level was used to show that it doesn't print to stdout from all methods and is ignored on the error method:

expect(consoleSpy).toBeCalledTimes(method === 'error' ? 1 : 0)

Now we have silence as the highest level, so I changed to it.

The second one test that all logs emit with sample rate for every method even with the highest log level.

I pointed out this, because this is a dynamic set of tests, and it wasn't obvious to me what is "higher" level means in the description, and why it uses a particular log level. So I thought it worth mentioning in the review.

sampleRateValue: 0,
});
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();
Expand All @@ -180,14 +214,14 @@ describe('Class: Logger', () => {
}

// Assess
expect(consoleSpy).toBeCalledTimes(method === 'error' ? 1 : 0);
expect(consoleSpy).toBeCalledTimes(0);
});

test('when the Logger\'s log level is higher and the current Lambda invocation IS sampled for logging, it DOES print to stdout', () => {

// Prepare
const logger: Logger = createLogger({
logLevel: 'ERROR',
logLevel: 'SILENT',
sampleRateValue: 1,
});
const consoleSpy = jest.spyOn(logger['console'], methodOfLogger).mockImplementation();
Expand Down Expand Up @@ -630,10 +664,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand Down Expand Up @@ -1396,10 +1427,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand All @@ -1422,10 +1450,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: true,
persistentLogAttributes: {},
Expand All @@ -1448,10 +1473,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: true,
persistentLogAttributes: {},
Expand Down Expand Up @@ -1512,10 +1534,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand All @@ -1538,10 +1557,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {
Expand All @@ -1566,10 +1582,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: true,
persistentLogAttributes: {},
Expand All @@ -1592,10 +1605,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'ERROR',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand Down Expand Up @@ -1641,10 +1651,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand All @@ -1667,10 +1674,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {
Expand Down Expand Up @@ -1700,10 +1704,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {
Expand Down Expand Up @@ -1746,10 +1747,7 @@ describe('Class: Logger', () => {
logFormatter: expect.any(PowertoolLogFormatter),
logLevel: 'DEBUG',
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand Down Expand Up @@ -1980,5 +1978,4 @@ describe('Class: Logger', () => {
});

});

});
Loading