-
Notifications
You must be signed in to change notification settings - Fork 16
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.
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: add system logger #457
Changes from 3 commits
753a7da
32c4629
f985e05
0c0edcc
5d27881
54badea
810112e
463b687
139158e
1ac7353
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -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' |
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,115 @@ | ||
const systemLogTag = '__nfSystemLog' | ||
|
||
const serializeError = (error: Error): Record<string, unknown> => { | ||
const cause = error?.cause instanceof Error ? serializeError(error.cause) : error.cause | ||
|
||
return { | ||
error: error.message, | ||
error_cause: cause, | ||
error_stack: error.stack, | ||
} | ||
} | ||
|
||
// 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, | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The edge functions logger has a simpler "Debug/Log/Error" hierarchy here. Since log levels were introduced there only very recently, we can still change what's being used here. I picked those levels because they match the Go levels. @eduardoboucas do you see any value in having an additional There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. No strong opinions. I personally don't feel the need for extra levels, and it's not clear to me when we'd use If we do it, do we make There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Then let's stick with Debug/Log/Error for now - we can always add the additional levels in the future.
That's the current impl, yes. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Oops, missed that part! |
||
Info, | ||
Warn, | ||
Error, | ||
} | ||
|
||
class SystemLogger { | ||
// eslint-disable-next-line no-useless-constructor | ||
constructor( | ||
private readonly fields: Record<string, unknown> = {}, | ||
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) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I've added support for sampling here, because I feel like it's a useful thing for collecting metrics without increasing the log volume too much. The more I think about it, though, the more I feel like the sampling rate should be set on a per-log basis, instead of on a per-logger basis. @eduardoboucas curious what you think - is it useful to have sampling built-in to the logger? If yes, should we also add it to the edge functions logger? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think this adds unnecessary complexity at this point. |
||
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<string, unknown>) { | ||
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) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Edge-Utils only has a |
||
// 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() |
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -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 | ||
}) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nice way to gate the internal stuff I like!