[HackTuah]

The credential-masking Logger filter could be killed by ordinary log events, and the way it failed was the worst available: OTP removes a primary filter that raises, permanently, and carries on. Every line written after that point was unmasked, and nothing anywhere said so.

Found on a running server, twice, including at boot. Never by a test.

Logger - error: {removed_failing_filter,trinity_redaction}

Two defects, not one

Improper chardata, which the slice was opened for

redact_msg({format, args}) when is_list(args) caught {:string, iolist}, because an iolist is a list, and Enum.map/2 raises FunctionClauseError on an improper list. OTP chardata is routinely improper. The event from the live log, | and all:

msg: {:string, ["Exqlite.Connection", 32, 40, "#PID<0.810.0> (\"db_conn_2\")",
                ") failed to connect: " | "** (Exqlite.Error) database is locked"]}

A db_connection disconnect produces one. So does an Exqlite.Error at boot.

Binaries that are not valid UTF-8, which the property found

redact/1 runs Regex.replace/3 on any binary, and that raises on invalid UTF-8. The property failed after 92 successful runs.

I had this hypothesis at the start of the session and threw it away on a bad test. I checked redact/1 against a single 8-byte invalid binary, saw it return, and concluded UTF-8 was not the problem. Three hand-picked inputs are not a population, and the check I wrote for a claim about all binaries used one binary.

It is the more serious of the two. Raw bytes are the shape key material most often takes, so the filter raised on exactly the input class most likely to be a secret, and failed in the direction that disabled redaction entirely.

The fix

• {:string, chardata} is flattened rather than walked, which handles improper tails, nesting, charlists and codepoints in one step. The clause sits before {format, args}, which would otherwise catch it.
• redact_list/1 replaces Enum.map/2 wherever a list may be improper, keeping the shape and redacting the tail rather than walking off the end of it.
• An invalid binary is replaced rather than matched, keeping its byte size so the line still says something.
• filter/2 wraps its own work and degrades to an event whose content is withheld, keeping only metadata that cannot carry a credential. Losing a line's detail is recoverable; running unfiltered is not.
• Trinity.Application.verify_log_redaction!/0 reads the primary filters from the logger and refuses to boot without this one. The previous install_log_redaction/0 swallowed every error including a failure to install, so an application that could not redact its logs started anyway and said nothing.

The test that matters is end to end

Everything else calls filter/2 directly, and that is not how it dies: OTP calls it, OTP catches the raise, OTP removes it. So one test logs improper chardata through the real logger and asserts the filter is still installed afterwards.

Red against the pre-fix module, restored from HEAD and re-run:

 10) test AC5: logging improper chardata through OTP itself leaves the filter installed
     OTP removed the filter after logging improper chardata. This is the exact failure seen on the
     running server: {removed_failing_filter, trinity_redaction}.

A companion test asserts the line OTP did log was masked, so "still installed" cannot be satisfied by a filter that no longer redacts.

A note for the next property written here

StreamData's own chardata/0 generates proper lists only. A property written the obvious way would have gone on passing while the filter died in production. The generator in this slice builds improper tails deliberately.

Confirmed on a running server

Which is how both of this session's defects were found, so the fix is confirmed the same way rather than only in the suite:

$ grep -c "removed_failing_filter" demo125.log
0
reached approval_wait: true
final answer rendered: true

Against a pre-fix run of the same script where the filter was removed at boot.

mix gate ; echo "EXIT=$?"
prod_check: PASS
3625 mods/funs, found no issues.
trinity.names: OK over 649 tracked files
Result: 846 passed (17 properties, 829 tests), 18 excluded
trinity.coverage: 042 80.31% vs 005 80.31%: OK
EXIT=0

For the reviewer

1. [REDACTED-BINARY n bytes] is a judgement call worth confirming. An invalid binary is now replaced outright, which makes a legitimately binary log payload disappear. I think that is right for a filter whose job is to stop key material reaching disk; NOTES.md records the alternative.
2. verify_log_redaction!/0 raises at boot. Confirm that refusing to start is what you want over starting with a loud warning.