Observability

Does obfuscation break log redaction?

Log redaction in a node service is often nothing more than a small options object: print objects one level deep, truncate long strings, cap arrays. Those switches are read by the runtime, not by your code, and every one of them means the opposite of itself when it goes missing. We measured what a renamed switch puts into a log line.

The setup

The sample builds a request record of the shape any service logs: a request id and path, an actor with an email address, a session object containing a bearer token and an IP, and a small array of item ids. It then formats that record with util.inspect, which is also what console.log runs for any non-string argument, so this is not a niche API.

The options are the usual defensive set and all are non-default: depth zero so nested objects print as placeholders, a 24-character string cap, a two-element array cap, and single-line output. Node's own defaults are depth two, a 10000-character string cap, a 100-element array cap, and multi-line output at 128 columns.

The unprotected run produced a 54-character line reading { request: [Object], actor: [Object], items: [Array] }, with no token in it. Protection alone across five presets reproduced that exactly.

The token that came back

Renaming depth took the line from 54 characters to 211 and printed the nested objects, including the session. Renaming maxStringLength restored full-length strings. Renaming both, which a pattern scoped to that options object does in one go, produced a 276-character line with the complete bearer token in it and our reported flag moving from token-in-log=false to token-in-log=true.

Nothing else changed. The service still worked, the record was still correct, the log still parsed, and the line was still a single line. The only difference is that a secret is now in a file that is copied to a log aggregator, retained for months, and readable by a much wider group of people than the database it came from.

Two more volume switches behaved the same way once the sample actually exercised them. Renaming the array cap turned a two-element dump into all ten elements. Renaming the line-width and compaction options turned a five-line dump into one line. Neither leaks a secret, but both change log volume and log shape, which is enough to break an ingestion pipeline that parses on line boundaries.

One name, two surfaces, opposite failures

The same file also installs those switches globally, the way a logger bootstrap does, by assigning to util.inspect.defaultOptions. That produced the sharpest contrast of the measurement. The per-call options object accepts an unknown key without comment and quietly reverts to the default. The global defaults object is not extensible, so writing a renamed key to it throws TypeError: Cannot add property _0x1, object is not extensible and takes the process down.

So a single renamed name is silent on one surface and fatal on the other, in the same file, in the same run. Which one you get is decided by the object node hands you rather than by anything about the name.

Renaming the container itself, defaultOptions, is silent again and worse. The assignment lands on a different property, node's real defaults stay in place, and every subsequent log line is formatted at depth two with a 10000-character string cap. Our global line went from 54 characters with no token to 326 characters with the token in it, and nothing anywhere reported a problem.

The control arm that produced the best result of the pass

Every measurement in this series includes a control: names the file owns on both sides, which should be renamed harmlessly because both the write and the read move together. Here the control was the record's own request and id properties, and it did not come back clean.

The reads were fine. The log line was not. It printed { _0x1: [Object], actor: [Object], items: [Array] }, because the formatter prints the object's real property names, and after renaming the real property name is the generated one. Nothing broke in the program; what broke was every dashboard query, alert rule, log parser and saved search keyed on that field name.

That is a general point worth carrying beyond logging. A log line is an output surface, exactly like an HTTP body or an analytics event. Renaming a property nobody outside your file reads is still visible the moment that object is serialised, formatted or dumped, and the readers of that output are the humans and tools that run your on-call rotation.

The switch that makes the logger do more, not less

One option in the set points the other way. Passing getters: true tells the formatter to evaluate accessor properties so their computed values appear in the dump, which is what you want when the interesting state is behind a getter. Renaming it reverted to the default of false and our reported flag went from true to false: the computed value simply stopped appearing.

That is the least harmful result here, and it is a useful counterweight to the rest of the article. Not every renamed switch weakens a protection; some just remove information you were relying on. The common factor is not danger, it is that the runtime silently substitutes its own default and nothing in the program is in a position to notice.

It is also a reminder that redaction is not the only reason to configure a formatter. Truncation, expansion, ordering and numeric separators all change what an operator sees, and all of them are option names in the same object.

Why redaction is a bad thing to trust to a switch

Every result on this page shares one property: the secret was in the record all along, and the only thing keeping it out of the log was a formatting option. That is a thin defence even before anybody protects the file. A different code path, a deeper log level, an exception handler that dumps the whole request context, or a colleague adding a debug line all defeat it just as thoroughly as a rename does.

The stronger posture is to keep the secret out of the object you log. Redact at construction: build the log record from named fields rather than passing the live request object, and replace the token with a fingerprint at the point where the record is made. That approach cannot be undone by a formatter option, because there is nothing left to reveal.

Where you do rely on formatter options, exclude their names. For this area that is depth, maxStringLength, maxArrayLength, breakLength, compact, getters and defaultOptions. Seven names, none of which are yours.

What to check in your own build

Add one assertion to the test suite that already exists for your logger. Format a record containing a known sentinel secret and assert that the sentinel is absent from the output string. It is a two-line test, it uses a string literal rather than a member name, and it fails immediately in a build where the switches have been renamed away.

Then check the shape as well as the content. Assert the field names your alerting depends on are present in a formatted line, which catches the control-arm result above, and assert the line count if your ingestion pipeline is line-oriented.

Both checks belong in the build that produces the protected artifact rather than in a pre-protection unit test run, for the same reason every article in this series ends with: the thing you ship is the thing to test.

Frequently asked questions

Can obfuscation put secrets into my logs?

Member renaming can, if the pattern matches the formatter options that keep them out. In our measurement, renaming the depth and string-length switches took a 54-character log line to 276 characters containing a complete bearer token, with no error anywhere.

Does protection alone change log output?

No. With member renaming off, all five presets reproduced our sample's output byte for byte. The renaming transform is opt-in and scoped by a regular expression you supply.

Why does a missing option reveal more rather than less?

Because the runtime substitutes its own default, and node's defaults are deliberately generous: depth two, a 10000-character string cap and a 100-element array cap. A defensive value is always a departure from that, so losing it always moves toward more output.

What happens when the options are installed globally?

The global defaults object is not extensible, so writing a renamed key to it throws a TypeError and stops the process. Renaming the container name instead is silent: the assignment lands elsewhere, node's real defaults stay, and every later line is formatted at depth two.

Are my own property names safe if only my code reads them?

Not in a log. Our control arm renamed a property the file both writes and reads, which worked correctly everywhere in the program and still changed the field name printed in the log line, so any dashboard query or alert keyed on that name stops matching.

Which names should I exclude?

Depth, maxStringLength, maxArrayLength, breakLength, compact, getters and defaultOptions. If your alerting is keyed on specific field names in logged objects, exclude those too, because the formatter prints the real property names.

What is the more durable fix?

Keep the secret out of the object you log. Build the log record from named fields and replace the token with a fingerprint at construction time, so no formatter option is load-bearing. Then assert in a test that a sentinel secret never appears in a formatted line.

Related reading