This post explains a simple way to enhance the use of console.log() in a nodejs http server, with an example for SvelteKit. Of course one may use dedicated logger tools too.
Nodejs http/tcp servers handle several requests simultaneously. When it comes to logging, it is useful to preprend each log message with an identifier of the current request (requestId, userId or whatever data related to the request).
Let's name this information contextualData.
The obvious and easy way is to pass the contextual data from function to function, so that we can call console.log(contextualData, xxx) from any file in the code.
Simple and easy at the beginning, less simple as the app grows and awful with a huge codebase.
Any other way ?
Indeed, AsyncLocalStorage is a relatively new and unknown Nodejs API that provides exactly what we need : a storage (similar to localStorage in the browser) that lives in the context of the request.
Step 1 : using AsyncLocalStorage
using this API is pretty straightforward. Let's have a look at the exact same documentation example, including my own comments :
import http from 'node:http';
// import AsyncLocalStorage API
import { AsyncLocalStorage } from 'node:async_hooks';
// new instance
const asyncLocalStorage = new AsyncLocalStorage();
// this function shows how to retrieve the context
// and preprend it to console.log() messages
function logWithId(msg) {
const id = asyncLocalStorage.getStore();
console.log(`${id !== undefined ? id : '-'}:`, msg);
}
let idSeq = 0; // the contextual data of this example
http.createServer((req, res) => {
// .run(context, callback) runs the callback and makes 'context'
// available when calling .getStore() from inside the callback
// for this example, idSeq is incremented on each request
asyncLocalStorage.run(idSeq++, () => {
// starting from here, contextualData is defined
logWithId('start');
// Imagine any chain of async operations here
setImmediate(() => {
logWithId('finish');
res.end();
});
// until here
});
}).listen(8080);
http.get('http://localhost:8080');
http.get('http://localhost:8080');
// Prints:
// 0: start
// 1: start
// 0: finish
// 1: finish
Next step is to rewrite console.log() so that it automatically preprends messages with the context when available.
Step 2 : rewriting console.log()
Let's take an example with a static prefix :
let _log = null // pointer to console.log base function
const setConsolePrefix = (prefix) => {
// singleton
if (_log)
return
// keep a pointer to the system console.log function
_log = console.log
// rewrite console.log function with prefix
console.log = () => {
let args = Array.from(arguments)
if (prefix)
// insert prefix as the first argument
args.unshift(prefix)
// call system console.log function with updated arguments
_log.apply(console, log, args)
}
// anywhere in the code
setConsolePrefix("Pulp Fiction:")
// later in the code
console.log("It's Zed's")
console.log("Who's Zed ?")
// prints :
// Pulp Fiction: It's Zed's
// Pulp Fiction: Who's Zed ?
Straightforward too.
Putting things together
Now let's put things together and encapsulate this feature in a Context.js file :
import { AsyncLocalStorage } from "async_hooks"
export const context = new AsyncLocalStorage()
var __log = null
export function setContextualConsole(){
// singleton
if (__log)
return
__log = console.log
console.log = function(){
let args = Array.from(arguments)
// retrieve a contextual prefix instead of a static prefix
const contextualPrefix = context.getStore()
if (contextualPrefix)
args.unshift(contextualPrefix )
__log.apply(console, args)
}
}
Using in Sveltekit
In Sveltekit, the right place to use it is the handle() function, that is defined in hooks.ts. In our example, the contextual data is the very same seqId as in Nodejs AsyncLocalStorage documentation example :
import {context, setContextualConsole} from 'Context'
// our contextual data
let seqId = 0
export async function handle({ event, resolve }) {
seqId++
// use our new 'context-ready' console.log
setContextualConsole()
return await context.run(seqId, async()=>{
// starting from here, console.log(xxx) prints 'seqId xxx'
const response = await resolve(event)
// until here
return response
})
}
Using in nodejs HttpServer
same with a bare nodejs httpServer :
import http from 'node:http'
import {context, setContextualConsole} from './Context.js'
// our contextual data
let seqId = 0
http.createServer((req, res) => {
seqId++
// use our 'context-ready' console
setContextualConsole()
context.run(seqId, ()=>{
// context available from here...
console.log('start')
// the timeout simulates request processing time
// so that we get simultaneous requests for this example
setTimeout(()=>{
console.log('end')
// ... to here
res.end()
}, 10)
})
}).listen(80)
http.get('http://localhost')
http.get('http://localhost')
// prints :
// 1 start
// 2 start
// 1 end
// 2 end
That's it !
The contextual data may be an object, an array or any data that needs to be stored during the request handling.
In SvelteKit, my advice is to use this trick only for logging purposes : it should not replace event.locals.
Top comments (0)