Skip to content

create optimized cu logger #1182

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

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
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
4 changes: 3 additions & 1 deletion .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -11,4 +11,6 @@ ao-cache
# terraform
.terraform
.terragrunt-cache
terraform/*.plan
terraform/*.plan

benchmark.js
156 changes: 64 additions & 92 deletions servers/cu/src/domain/logger.js
Original file line number Diff line number Diff line change
@@ -1,128 +1,100 @@
import pino from 'pino'
import { watchFile } from 'node:fs'
import { readFile } from 'node:fs/promises'
import { resolve } from 'node:path'

import { tap, trim } from 'ramda'
import { z } from 'zod'
import winston from 'winston'

const { createLogger: createWinstonLogger, transports, format } = winston

function capitalize (str) {
if (!str) return ''
return str.charAt(0).toUpperCase() + str.slice(1).toLowerCase()
export const logLevels = z.enum(["fatal", "error", "warn", "info", "debug", "trace"])

/**
* Wrap a pino logger so that it can be used as a callable function.
* Downstream code can then do:
*
* const logger = _logger.child('some-child')
* logger('message %s', arg)
*
* This helper binds key methods (like info, child, etc.) to the original logger.
*/
function makeCallableLogger(logger) {
function callableLogger(...args) {
return logger.info(...args)
}
callableLogger.info = logger.info.bind(logger)
callableLogger.error = logger.error.bind(logger)
callableLogger.warn = logger.warn.bind(logger)
callableLogger.debug = logger.debug.bind(logger)
if (typeof logger.trace === 'function') {
callableLogger.trace = logger.trace.bind(logger)
}
callableLogger.child = function (...childArgs) {
const childLogger = logger.child(...childArgs)
return makeCallableLogger(childLogger)
}
return callableLogger
}

export const logLevels = z.enum(Object.keys(winston.config.npm.levels))

/**
* Create a Pino logger that mimics the behavior of the previous winston logger.
*
* Options:
* - MODE: runtime mode (e.g. 'development', 'production')
* - LOG_CONFIG_PATH: an optional path to a file containing a new log level
* - DEFAULT_LOG_LEVEL: the fallback log level (e.g. 'info')
* - name: a string used as the logger's root name.
*
* The returned logger is callable (delegating to info()) and supports a .child() method.
*/
export const createLogger = ({ MODE, LOG_CONFIG_PATH = '', DEFAULT_LOG_LEVEL, name: rootName }) => {
let level = DEFAULT_LOG_LEVEL
LOG_CONFIG_PATH = LOG_CONFIG_PATH && resolve(LOG_CONFIG_PATH)
if (LOG_CONFIG_PATH) {
LOG_CONFIG_PATH = resolve(LOG_CONFIG_PATH)
}

const root = createWinstonLogger({
levels: winston.config.npm.levels,
format: format.combine(
format.timestamp(),
format.splat(),
format.printf(({ level, name = rootName, message, timestamp }) =>
`${timestamp} ${name} [${level}]: ${message}`)
),
transports: MODE !== 'production'
? [new transports.Console()]
/**
* TODO: add 'production' transports for separate log levels
*/
: [new transports.Console()],
// Use pino.destination(1) for asynchronous output for better performance.
const dest = pino.destination(1)
const root = pino({
level,
silent: level === 'off'
})
const originalChild = root.child.bind(root)
name: rootName,
timestamp: pino.stdTimeFunctions.isoTime
}, dest)

/**
* Track all loggers spawned, so that we may dynamically update
* their log level
*/
// Track all loggers so we can update their level dynamically.
const loggers = [root]

let prev = null
async function checkConfig (cur) {
async function checkConfig(cur) {
let newLevel = ''

if (!cur || !prev || cur.mtimeMs !== prev.mtimeMs) {
newLevel = await readFile(LOG_CONFIG_PATH, 'utf-8')
.then(trim)
.catch(() => '')
try {
newLevel = await readFile(LOG_CONFIG_PATH, 'utf-8').then(str => str.trim())
} catch (err) {
newLevel = ''
}
}

/**
* Set level to the default if a new Level is not found
*/
if (!newLevel) newLevel = DEFAULT_LOG_LEVEL

if (level !== newLevel) {
/**
* Technically not an error, but lowest log level,
* and so will always be logged
*/
root.error(`Logger Configuration Change: updating log level "${level}" -> "${newLevel}"`)
level = newLevel
/**
* Change the level of each child logger
*/
loggers.forEach((l) => { l.level = level })
loggers.forEach(logger => { logger.level = newLevel })
}

prev = cur
}
/**
* Dynamically update the log level based on an optional config file
*/
if (LOG_CONFIG_PATH) {
checkConfig()
watchFile(LOG_CONFIG_PATH, { persistent: false }, checkConfig)
}

function log (name) {
const logger = originalChild({ name })

loggers.push(logger)
/**
* For terseness and backwards compatibility
*/
logger.child = (child) => log(`${name}:${child}`)

const logTap = (level) => (note, ...rest) =>
tap((...args) => logger[level](note, ...rest, ...args))
/**
* Default tap is at the 'info' level,
* for terseness and backwards compatibility
*/
logger.tap = logTap('info')
/**
* tapInfo, tapDebug, ...
*/
Object.keys(root.levels)
.forEach((level) => { logger[`tap${capitalize(level)}`] = logTap(level) })

/**
* By wrapping the Winston logger in a Proxy, we're able to invoke the
* logger as a function (defaults to 'info' level) -- a more terse and
* functional style.
*
* This also makes this logger backwards compatible with the previous
* logger implementation, but now with the addition log levels
*/
return new Proxy((...args) => { logger.info(...args) }, {
get: (_, field) => {
const value = logger[field]
if (typeof value === 'function') return value.bind(logger)
return value
}
})
function log(name) {
const childLogger = root.child({ name })
loggers.push(childLogger)
childLogger.child = (child) => log(`${name}:${child}`)
return makeCallableLogger(childLogger)
}

return log(rootName)
}

/**
* Create a test logger (for use in test mode)
*/
export const createTestLogger = ({ name, silent = !process.env.DEBUG }) =>
createLogger({ name, MODE: 'test', DEFAULT_LOG_LEVEL: silent ? 'off' : 'debug' })
1 change: 0 additions & 1 deletion servers/cu/src/logger.js
Original file line number Diff line number Diff line change
@@ -1,5 +1,4 @@
import { hostname } from 'node:os'

import { createLogger } from './domain/logger.js'
import { config } from './config.js'

Expand Down
Loading