Skip to content
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

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

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 3 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
6 changes: 3 additions & 3 deletions docs/core/logger.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,9 +49,9 @@ 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` |
| **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` |
dreamorosi marked this conversation as resolved.
Show resolved Hide resolved
| **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
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', () => {
dreamorosi marked this conversation as resolved.
Show resolved Hide resolved

// 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', () => {
});

});

});
24 changes: 11 additions & 13 deletions packages/logger/tests/unit/helpers.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,12 +6,19 @@
import { Console } from 'console';
import { ConfigServiceInterface, EnvironmentVariablesService } from '../../src/config';
import { LogFormatter, PowertoolLogFormatter } from '../../src/formatter';
import { ConstructorOptions } from '../../src/types';
import { ConstructorOptions, LogLevelThresholds } from '../../src/types';
import { createLogger, Logger } from './../../src';

describe('Helper: createLogger function', () => {

const ENVIRONMENT_VARIABLES = process.env;
const logLevelThresholds: LogLevelThresholds = {
DEBUG: 8,
INFO: 12,
WARN: 16,
ERROR: 20,
SILENT: 24,
};

beforeEach(() => {
jest.resetModules();
Expand Down Expand Up @@ -83,10 +90,7 @@ describe('Helper: createLogger function', () => {
logLevel: 'WARN',
console: expect.any(Console),
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: true,
persistentLogAttributes: {
Expand Down Expand Up @@ -125,10 +129,7 @@ describe('Helper: createLogger function', () => {
logLevel: 'INFO',
console: expect.any(Console),
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand Down Expand Up @@ -279,10 +280,7 @@ describe('Helper: createLogger function', () => {
logLevel: 'INFO',
console: expect.any(Console),
logLevelThresholds: {
DEBUG: 8,
ERROR: 20,
INFO: 12,
WARN: 16,
...logLevelThresholds
},
logsSampled: false,
persistentLogAttributes: {},
Expand Down