The other day I came across the solution to a number of problems I’d had in the past.
I imagine it’s probably obvious to anyone who’s been doing JavaScript for a while, but since it took a while to dawn on me I thought I’d try and save someone else the wait, even if it’s only one. And it’ll provide the rest of you with a good laugh too.
I don’t know what this pattern is officially called, so I’ve dubbed it the ‘singleton file’ - you can import it everywhere, but it only creates a single object which everything ends up using.
The problem
The problem I was having was with services like logging, which need to be available before most of the modules are started. At first I tried doing this with an initLogging function, similar to most services. However, when the system was starting up and all the modules were being imported some of the module code was being run before the logging setup was done.
The solution
The solution isn’t really that cunning, but it works very well (for me at least): you make the actual logger ‘object’ an export from the module.
Defining the logging module
I’m using the Winston logging system in most of my things. I like the look of the Serilog/structured logging stuff but it’s been too much hassle to get working for now. The logging module I use currently looks a bit like the code below. Warning - it’s a bit long.
import { createLogger, transports, format } from 'winston';
// Allow the logging level to be controlled at start time
let level = process.env.LOG_LEVEL;
if (process.env.NODE_ENV !== "test") {
console.info(`Logging at ${level} level.`)
}
// This is the format for lines to be printed to console. The format varies
// depending on the environment.
const consoleLineFormat = format.printf(({ level, message, label, timestamp }) => {
if (process.env.NODE_ENV === "production") {
return `[${label}] ${level}: ${message}`;
} else {
return `${timestamp} [${label}] ${level}: ${message}`;
}
});
let consoleFormat;
if (process.env.NODE_ENV === "production") {
// Heroku captures info like timestamp anyway, don't duplicate it.
consoleFormat = format.combine(
format.splat(),
consoleLineFormat
);
} else {
// Put more information in the dev logs
consoleFormat = format.combine(
format.splat(),
format.colorize(),
format.timestamp(),
consoleLineFormat
);
}
// For file logs, use JSON
const fileFormat = format.combine(
format.splat(),
format.json(),
format.timestamp()
)
// Create the base logger; everything else comes from this.
// We always log to console; exceptions are always logged, regardless
// of the level that's set.
const base_logger = createLogger({
level: 'info',
transports: [
new transports.Console({ level: level, format: consoleFormat })
],
exceptionHandlers: [
new transports.Console({ format: consoleFormat })
]
});
// For development, also log to files. No point in that for Heroku.
if (process.env.NODE_ENV === "development") {
base_logger
.add(new transports.File({ filename: 'combined.log', level: 'debug', format: fileFormat }))
.add(new transports.File({ filename: 'errors.log', level: 'error', format: fileFormat }));
}
// 'parentLogger' is exported to the other modules. They use the 'child'
// function to create a local logger, tagged with the module name.
export const parentLogger = Object();
type childOptions = {
module: string;
}
parentLogger.child = function(opts: childOptions) {
return base_logger.child({ label: opts.module });
}
Apologies for the length of that - I did try to take bits out, but all of it’s there for a reason and I thought it might be useful to people.
Using the logging module
Luckily, actually using it is simple.
import { parentLogger } from "./logger";
const logger = parentLogger.child({ module: "events" })
That’s it. Now the local code simply uses logger.info, or whatever level you want. It’s logger in every module, so I don’t have to remember any other name.
Why it works
If I’m honest, I haven’t investigated this in detail. I imagine it’s because Node doesn’t let modules start running until the modules they’re importing have completed the initial run-through - otherwise it would be a nightmare to use dependencies. If anyone knows for sure, or knows different, please do let me know.
That’s it. Hope that helps someone!
Oh - and in case you're wondering, the image is totally unrelated to the story. I couldn't find a suitable post image, so I went with "cute puppy" instead.
Oldest comments (1)
The one adjustment I would make is maintain a variable in the file for the logger, and create a factory that creates the instance. Then when it's called, check if the variable was populated and only create the logger if it has not been. This will give you a singleton factory to verify when exactly the code executes.