From 753a7da52948d940edaa41c155b5a9caf704c469 Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 11:41:59 +0100 Subject: [PATCH 01/10] feat: implement first go at system logger --- package.json | 4 ++ src/internal.ts | 5 ++ src/lib/system_logger.ts | 113 +++++++++++++++++++++++++++++++++++++ test/unit/system_logger.js | 75 ++++++++++++++++++++++++ tsconfig.json | 2 +- 5 files changed, 198 insertions(+), 1 deletion(-) create mode 100644 src/internal.ts create mode 100644 src/lib/system_logger.ts create mode 100644 test/unit/system_logger.js diff --git a/package.json b/package.json index 772dec31..4f7eea2e 100644 --- a/package.json +++ b/package.json @@ -9,6 +9,10 @@ "dist/**/*.d.ts", "types/**/*.d.ts" ], + "exports": { + ".": "./dist/main.js", + "./internal": "./dist/internal.js" + }, "scripts": { "build": "tsc", "prepare": "husky install node_modules/@netlify/eslint-config-node/.husky/", diff --git a/src/internal.ts b/src/internal.ts new file mode 100644 index 00000000..bc6a6cc0 --- /dev/null +++ b/src/internal.ts @@ -0,0 +1,5 @@ +// this file is exported as @netlify/functions/internal, +// and only meant for consumption by Netlify Teams. +// While we try to adhere to semver, this file is not considered part of the public API. + +export { systemLogger, LogLevel } from "./lib/system_logger.js" diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts new file mode 100644 index 00000000..ccf37483 --- /dev/null +++ b/src/lib/system_logger.ts @@ -0,0 +1,113 @@ +const systemLogTag = '__nfSystemLog' + +const serializeError = (error: Error): Record => { + const cause = error?.cause instanceof Error ? serializeError(error.cause) : error.cause + + return { + error: error.message, + error_cause: cause, + error_stack: error.stack, + } +} + +export enum LogLevel { + Debug = 1, + Info, + Warn, + Error, +} + +class SystemLogger { + // eslint-disable-next-line no-useless-constructor + constructor( + private readonly fields: Record = {}, + private readonly logLevel = LogLevel.Info, + private readonly samplingRate = 1, + ) {} + + private doLog(logger: typeof console.log, message: string) { + if (this.samplingRate < 1 && Math.random() > this.samplingRate) { + return + } + + logger(systemLogTag, JSON.stringify({ msg: message, fields: this.fields })) + } + + /** + * Alias for .info + */ + log(message: string) { + this.info(message) + } + + info(message: string) { + if (this.logLevel > LogLevel.Info) { + return + } + + this.doLog(console.info, message) + } + + debug(message: string) { + if (this.logLevel > LogLevel.Debug) { + return + } + + this.doLog(console.debug, message) + } + + warn(message: string) { + if (this.logLevel > LogLevel.Warn) { + return + } + + this.doLog(console.warn, message) + } + + error(message: string) { + if (this.logLevel > LogLevel.Error) { + return + } + + this.doLog(console.error, message) + } + + withLogLevel(level: LogLevel) { + return new SystemLogger(this.fields, level, this.samplingRate) + } + + withSamplingRate(rate: number) { + return new SystemLogger(this.fields, this.logLevel, rate) + } + + withFields(fields: Record) { + return new SystemLogger( + { + ...this.fields, + ...fields, + }, + this.logLevel, + this.samplingRate, + ) + } + + withError(error: unknown) { + const fields = error instanceof Error ? serializeError(error) : { error } + + return this.withFields(fields) + } + + withRequest(req: Request) { + // proxy automatically adds the request ID to the logs, + // so we don't need to care about it here + + const debug = req.headers.has('x-nf-debug-logging') + if (debug) { + return this.withLogLevel(LogLevel.Debug) + } + + return this + } +} + +export const systemLogger = new SystemLogger() diff --git a/test/unit/system_logger.js b/test/unit/system_logger.js new file mode 100644 index 00000000..d58742bc --- /dev/null +++ b/test/unit/system_logger.js @@ -0,0 +1,75 @@ +const test = require('ava') + +const { systemLogger, LogLevel } = require('../../dist/internal') + +test('Log Level', (t) => { + const originalLog = console.info + const originalDebug = console.debug + + const infoLogs = [] + const debugLogs = [] + console.info = (...message) => infoLogs.push(message) + console.debug = (...message) => debugLogs.push(message) + + systemLogger.debug('hello!') + t.is(debugLogs.length, 0) + + systemLogger.withLogLevel(LogLevel.Debug).debug('hello!') + t.is(debugLogs.length, 1) + + systemLogger + .withRequest(new Request('https://example.com')) + .debug('hello!') + t.is(debugLogs.length, 1) + + systemLogger + .withRequest(new Request('https://example.com', { headers: { 'x-nf-debug-logging': '1' } })) + .debug('hello!') + t.is(debugLogs.length, 2) + + systemLogger + .withLogLevel(LogLevel.Info) + .debug('hello!') + t.is(debugLogs.length, 2) + + console.info = originalLog + console.debug = originalDebug +}) + +test('Fields', (t) => { + const originalLog = console.info + const logs = [] + console.info = (...message) => logs.push(message) + systemLogger.withError(new Error('boom')).withFields({ foo: 'bar' }).log('hello!') + t.is(logs.length, 1) + t.is(logs[0][0], '__nfSystemLog') + const log = JSON.parse(logs[0][1]) + t.is(log.msg, 'hello!') + t.is(log.fields.foo, 'bar') + t.is(log.fields.error, 'boom') + t.is(log.fields.error_stack.split('\n').length > 2, true) + + console.info = originalLog +}) + +test('Sampling', (t) => { + const originalLog = console.info + const logs = [] + console.info = (...message) => logs.push(message) + let randomValue = 0.5 + const originalRandom = Math.random + Math.random = () => randomValue + + systemLogger.withSamplingRate(0.6).log('hello!') + t.is(logs.length, 1) + + systemLogger.withSamplingRate(0.3).log('hello!') + t.is(logs.length, 1) + + randomValue = 0.2 + systemLogger.withSamplingRate(0.3).log('hello!') + t.is(logs.length, 2) + + Math.random = originalRandom + console.info = originalLog +}) diff --git a/tsconfig.json b/tsconfig.json index e07baa7e..2fb9dfec 100644 --- a/tsconfig.json +++ b/tsconfig.json @@ -11,7 +11,7 @@ // "disableReferencedProjectLoad": true, /* Reduce the number of projects loaded automatically by TypeScript. */ /* Language and Environment */ - "target": "ES2020" /* Set the JavaScript language version for emitted JavaScript and include compatible library declarations. */, + "target": "ES2022" /* Set the JavaScript language version for emitted JavaScript and include compatible library declarations. */, // "lib": [], /* Specify a set of bundled library declaration files that describe the target runtime environment. */ // "jsx": "preserve", /* Specify what JSX code is generated. */ // "experimentalDecorators": true, /* Enable experimental support for TC39 stage 2 draft decorators. */ From 32c4629a477ae4e551605a69e19edf7a0144c670 Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 11:43:18 +0100 Subject: [PATCH 02/10] chore: fix eslint --- src/lib/system_logger.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index ccf37483..da9a50c9 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -10,6 +10,8 @@ const serializeError = (error: Error): Record => { } } +// eslint pretends there's a different enum at the same place - it's wrong! +// eslint-disable-next-line no-shadow export enum LogLevel { Debug = 1, Info, From f985e05f7a6b60620f3a4119968631788f8e46de Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 11:43:53 +0100 Subject: [PATCH 03/10] chore: prettier --- src/internal.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/internal.ts b/src/internal.ts index bc6a6cc0..14ce81c0 100644 --- a/src/internal.ts +++ b/src/internal.ts @@ -2,4 +2,4 @@ // and only meant for consumption by Netlify Teams. // While we try to adhere to semver, this file is not considered part of the public API. -export { systemLogger, LogLevel } from "./lib/system_logger.js" +export { systemLogger, LogLevel } from './lib/system_logger.js' From 0c0edcc3d571a8261a4ca9f9bc8c6ab03c3a90e4 Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 12:12:27 +0100 Subject: [PATCH 04/10] fix: skip request usage on v14 --- test/unit/system_logger.js | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/test/unit/system_logger.js b/test/unit/system_logger.js index d58742bc..0f722868 100644 --- a/test/unit/system_logger.js +++ b/test/unit/system_logger.js @@ -1,8 +1,15 @@ +const { version } = require('process') + const test = require('ava') const { systemLogger, LogLevel } = require('../../dist/internal') test('Log Level', (t) => { + // Request is not available in Node 14 + if (version.startsWith('v14')) { + return t.pass() + } + const originalLog = console.info const originalDebug = console.debug @@ -17,9 +24,7 @@ test('Log Level', (t) => { systemLogger.withLogLevel(LogLevel.Debug).debug('hello!') t.is(debugLogs.length, 1) - systemLogger - .withRequest(new Request('https://example.com')) - .debug('hello!') + systemLogger.withRequest(new Request('https://example.com')).debug('hello!') t.is(debugLogs.length, 1) systemLogger @@ -27,9 +32,7 @@ test('Log Level', (t) => { .debug('hello!') t.is(debugLogs.length, 2) - systemLogger - .withLogLevel(LogLevel.Info) - .debug('hello!') + systemLogger.withLogLevel(LogLevel.Info).debug('hello!') t.is(debugLogs.length, 2) console.info = originalLog From 5d27881521821945f244eaee78d53e50a3e54e0b Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 12:41:58 +0100 Subject: [PATCH 05/10] feat: remove sampling --- src/lib/system_logger.ts | 12 +----------- test/unit/system_logger.js | 22 ---------------------- 2 files changed, 1 insertion(+), 33 deletions(-) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index da9a50c9..317e103b 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -24,14 +24,9 @@ class SystemLogger { constructor( private readonly fields: Record = {}, private readonly logLevel = LogLevel.Info, - private readonly samplingRate = 1, ) {} private doLog(logger: typeof console.log, message: string) { - if (this.samplingRate < 1 && Math.random() > this.samplingRate) { - return - } - logger(systemLogTag, JSON.stringify({ msg: message, fields: this.fields })) } @@ -75,11 +70,7 @@ class SystemLogger { } withLogLevel(level: LogLevel) { - return new SystemLogger(this.fields, level, this.samplingRate) - } - - withSamplingRate(rate: number) { - return new SystemLogger(this.fields, this.logLevel, rate) + return new SystemLogger(this.fields, level) } withFields(fields: Record) { @@ -89,7 +80,6 @@ class SystemLogger { ...fields, }, this.logLevel, - this.samplingRate, ) } diff --git a/test/unit/system_logger.js b/test/unit/system_logger.js index 0f722868..a50e369b 100644 --- a/test/unit/system_logger.js +++ b/test/unit/system_logger.js @@ -54,25 +54,3 @@ test('Fields', (t) => { console.info = originalLog }) - -test('Sampling', (t) => { - const originalLog = console.info - const logs = [] - console.info = (...message) => logs.push(message) - let randomValue = 0.5 - const originalRandom = Math.random - Math.random = () => randomValue - - systemLogger.withSamplingRate(0.6).log('hello!') - t.is(logs.length, 1) - - systemLogger.withSamplingRate(0.3).log('hello!') - t.is(logs.length, 1) - - randomValue = 0.2 - systemLogger.withSamplingRate(0.3).log('hello!') - t.is(logs.length, 2) - - Math.random = originalRandom - console.info = originalLog -}) From 54badea42bcb0de8f24d854288e29431d4c041ed Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 12:45:25 +0100 Subject: [PATCH 06/10] feat: remove log levels --- src/lib/system_logger.ts | 24 ++++-------------------- test/unit/system_logger.js | 12 ++++-------- 2 files changed, 8 insertions(+), 28 deletions(-) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index 317e103b..1400cd83 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -14,8 +14,7 @@ const serializeError = (error: Error): Record => { // eslint-disable-next-line no-shadow export enum LogLevel { Debug = 1, - Info, - Warn, + Log, Error, } @@ -23,26 +22,19 @@ class SystemLogger { // eslint-disable-next-line no-useless-constructor constructor( private readonly fields: Record = {}, - private readonly logLevel = LogLevel.Info, + private readonly logLevel = LogLevel.Log, ) {} private doLog(logger: typeof console.log, message: string) { logger(systemLogTag, JSON.stringify({ msg: message, fields: this.fields })) } - /** - * Alias for .info - */ log(message: string) { - this.info(message) - } - - info(message: string) { - if (this.logLevel > LogLevel.Info) { + if (this.logLevel > LogLevel.Log) { return } - this.doLog(console.info, message) + this.doLog(console.log, message) } debug(message: string) { @@ -53,14 +45,6 @@ class SystemLogger { this.doLog(console.debug, message) } - warn(message: string) { - if (this.logLevel > LogLevel.Warn) { - return - } - - this.doLog(console.warn, message) - } - error(message: string) { if (this.logLevel > LogLevel.Error) { return diff --git a/test/unit/system_logger.js b/test/unit/system_logger.js index a50e369b..8610266f 100644 --- a/test/unit/system_logger.js +++ b/test/unit/system_logger.js @@ -10,12 +10,9 @@ test('Log Level', (t) => { return t.pass() } - const originalLog = console.info const originalDebug = console.debug - const infoLogs = [] const debugLogs = [] - console.info = (...message) => infoLogs.push(message) console.debug = (...message) => debugLogs.push(message) systemLogger.debug('hello!') @@ -32,17 +29,16 @@ test('Log Level', (t) => { .debug('hello!') t.is(debugLogs.length, 2) - systemLogger.withLogLevel(LogLevel.Info).debug('hello!') + systemLogger.withLogLevel(LogLevel.Log).debug('hello!') t.is(debugLogs.length, 2) - console.info = originalLog console.debug = originalDebug }) test('Fields', (t) => { - const originalLog = console.info + const originalLog = console.log const logs = [] - console.info = (...message) => logs.push(message) + console.log = (...message) => logs.push(message) systemLogger.withError(new Error('boom')).withFields({ foo: 'bar' }).log('hello!') t.is(logs.length, 1) t.is(logs[0][0], '__nfSystemLog') @@ -52,5 +48,5 @@ test('Fields', (t) => { t.is(log.fields.error, 'boom') t.is(log.fields.error_stack.split('\n').length > 2, true) - console.info = originalLog + console.log = originalLog }) From 810112e26b190e09ce80ad37115c0da293619b2a Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 12:46:16 +0100 Subject: [PATCH 07/10] feat: remove withRequest --- src/lib/system_logger.ts | 12 ------------ test/unit/system_logger.js | 17 +---------------- 2 files changed, 1 insertion(+), 28 deletions(-) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index 1400cd83..95134602 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -72,18 +72,6 @@ class SystemLogger { return this.withFields(fields) } - - withRequest(req: Request) { - // proxy automatically adds the request ID to the logs, - // so we don't need to care about it here - - const debug = req.headers.has('x-nf-debug-logging') - if (debug) { - return this.withLogLevel(LogLevel.Debug) - } - - return this - } } export const systemLogger = new SystemLogger() diff --git a/test/unit/system_logger.js b/test/unit/system_logger.js index 8610266f..2a1926c7 100644 --- a/test/unit/system_logger.js +++ b/test/unit/system_logger.js @@ -1,15 +1,8 @@ -const { version } = require('process') - const test = require('ava') const { systemLogger, LogLevel } = require('../../dist/internal') test('Log Level', (t) => { - // Request is not available in Node 14 - if (version.startsWith('v14')) { - return t.pass() - } - const originalDebug = console.debug const debugLogs = [] @@ -21,16 +14,8 @@ test('Log Level', (t) => { systemLogger.withLogLevel(LogLevel.Debug).debug('hello!') t.is(debugLogs.length, 1) - systemLogger.withRequest(new Request('https://example.com')).debug('hello!') - t.is(debugLogs.length, 1) - - systemLogger - .withRequest(new Request('https://example.com', { headers: { 'x-nf-debug-logging': '1' } })) - .debug('hello!') - t.is(debugLogs.length, 2) - systemLogger.withLogLevel(LogLevel.Log).debug('hello!') - t.is(debugLogs.length, 2) + t.is(debugLogs.length, 1) console.debug = originalDebug }) From 463b687e2ae2e2f2843b3456f9aedcdd1979098a Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Wed, 17 Jan 2024 12:47:20 +0100 Subject: [PATCH 08/10] chore: prettier --- src/lib/system_logger.ts | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index 95134602..86147455 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -20,10 +20,7 @@ export enum LogLevel { class SystemLogger { // eslint-disable-next-line no-useless-constructor - constructor( - private readonly fields: Record = {}, - private readonly logLevel = LogLevel.Log, - ) {} + constructor(private readonly fields: Record = {}, private readonly logLevel = LogLevel.Log) {} private doLog(logger: typeof console.log, message: string) { logger(systemLogTag, JSON.stringify({ msg: message, fields: this.fields })) From 139158e8c568bc579ac8c332e5ba62918bdfc0fa Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Thu, 18 Jan 2024 13:39:49 +0100 Subject: [PATCH 09/10] fix: remove `exports` --- package.json | 4 ---- 1 file changed, 4 deletions(-) diff --git a/package.json b/package.json index 4f7eea2e..772dec31 100644 --- a/package.json +++ b/package.json @@ -9,10 +9,6 @@ "dist/**/*.d.ts", "types/**/*.d.ts" ], - "exports": { - ".": "./dist/main.js", - "./internal": "./dist/internal.js" - }, "scripts": { "build": "tsc", "prepare": "husky install node_modules/@netlify/eslint-config-node/.husky/", From 1ac73531a1d0edc4a6345b8b3f2a438be4f1bd15 Mon Sep 17 00:00:00 2001 From: Simon Knott Date: Thu, 18 Jan 2024 13:48:34 +0100 Subject: [PATCH 10/10] refactor: make class members explicit --- src/lib/system_logger.ts | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/src/lib/system_logger.ts b/src/lib/system_logger.ts index 86147455..a6cc5046 100644 --- a/src/lib/system_logger.ts +++ b/src/lib/system_logger.ts @@ -19,8 +19,13 @@ export enum LogLevel { } class SystemLogger { - // eslint-disable-next-line no-useless-constructor - constructor(private readonly fields: Record = {}, private readonly logLevel = LogLevel.Log) {} + private readonly fields: Record + private readonly logLevel: LogLevel + + constructor(fields: Record = {}, logLevel = LogLevel.Log) { + this.fields = fields + this.logLevel = logLevel + } private doLog(logger: typeof console.log, message: string) { logger(systemLogTag, JSON.stringify({ msg: message, fields: this.fields }))