My Logger Documented Four Environment Variables. None of Them Worked.
I shipped a logging library with a LOG_LEVEL environment variable. The README documented it. A dedicated docs page documented it with examples and runtime-specific caveats. There were unit tests covering it, and they passed on every CI run for just under thirteen months.
Nothing called the function.
Here’s the command that found it. One line, run against the last 1.x tag:
$ git grep loadConfigFromEnvironment v1.1.21 -- src/
v1.1.21:src/utils/config.ts:22:export function loadConfigFromEnvironment(): Partial<LoggerConfig> {
That’s the whole result. One hit, and it’s the definition of the function itself. Exported, documented, tested, and reachable by exactly nobody.
The function was fine
That’s the part that took me a minute to accept. There was no bug in it. Given a process.env, it did the right thing:
export function loadConfigFromEnvironment(): Partial<LoggerConfig> {
const config: Partial<LoggerConfig> = {};
if (typeof process !== 'undefined' && process.env) {
const env = process.env;
if (env.LOG_LEVEL) {
config.level = stringToLogLevel(env.LOG_LEVEL);
}
// ...LOG_FORMAT, LOG_TIMESTAMP, LOG_COLOR
}
return config;
}
Clean. Reasonable. Correct. And createLogger() never called it, so a user could set LOG_LEVEL=debug, restart their process, and get exactly the same output they got before.
The tests found this function the same way a unit test finds anything: by importing it directly. tests/config.test.ts referenced loadConfigFromEnvironment eleven times across eight assertions. Every one of them passed. Not a single one of them proved a user could reach it, because none of them went through the public entry point.
That’s the failure mode. A unit test that imports the unit is testing the unit. It’s not testing whether the unit is wired up.
It wasn’t the only one
While I was in there I checked LoggerConfig.transports, declared right in the public type at src/core/types.ts:70:
transports?: TransportConfig[];
TypeScript happily accepted a transports array. Autocomplete offered it. And NodeLogger ignored it completely, because the Node adapter built its own hardcoded Winston transport list and never looked at the config field:
const logger = winston.createLogger({
transports: [
new winston.transports.Console({ /* ... */ }),
],
});
So you could pass transports: [{ type: 'file', options: { filename: 'app.log' } }], get no type error, get no runtime warning, and get no file. The type system confirmed your configuration was valid. The runtime threw it away.
Two different features, same shape. Declared in the public surface, absent from the code path that runs.
What the fix actually cost
I wired it up in 2.0.0 and the breaking-change note is longer than most of the feature work:
LOG_LEVEL, LOG_FORMAT, LOG_TIMESTAMP and LOG_COLOR now take effect, so a process with any of them already set logs differently after upgrading without any code change, and they override configuration passed to createLogger().
Read that carefully. Turning on a documented feature is a breaking change when the feature has been off long enough. Somebody out there has LOG_LEVEL=debug sitting in a .env from a project they set up last year, inherited by a service that has been logging at info this whole time because the variable did nothing. They upgrade a minor version, and now their logs are ten times bigger.
There’s a nastier one buried in the same note. The old boolean parsing was env.LOG_TIMESTAMP.toLowerCase() === 'true', so LOG_TIMESTAMP=1 evaluated to false. Anybody who wrote 1 and expected true was wrong twice over, first because the parse was strict about the literal string, and second because nothing read the result anyway. The new parser accepts true, 1, yes, on and false, 0, no, off, which means LOG_TIMESTAMP=1 flips from false to true across the upgrade.
Nobody could have hit that in practice. The feature was dead. But the moment it goes live, every one of those latent misconfigurations wakes up at once.
How this happens
Four things worth stealing from this:
- Grep your own exports for call sites.
git grep <exportName> -- src/on any function you believe is load-bearing. If the only hit is the definition, you found one. - A unit test proves a unit works, not that it runs. At least one test per feature should enter through the same door a user does.
- A declared field on a public type is a promise. If the runtime ignores it, the type system is lying to your users with full IDE autocomplete support.
- Turning on a dead documented feature is a breaking change. Version it like one, and write the note that tells people their existing environment now means something.
The library is at 2.5.2 now and the environment variables work. That sentence should not have taken thirteen months to become true.
Sources
- logan-logger-ts — the repo, if you want the diffs
- The 2.0.0 commit — where the wiring finally happened, breaking-change note and all
- treering — the language-neutral spec and conformance fixtures that drive the library through its public API
- The Twelve-Factor App: Config — the case for environment-based configuration, which works better when you read the environment
I’d appreciate a follow. You can subscribe with your email below. The emails go out once a week, or you can find me on Mastodon at @[email protected].