skip to content

How can CRLF in user input passed to logging.Logger.info forge a second log entry?

level: seniorimportance: should knowfreq 32%

answer

  1. What separates one log entry from the next?
  2. The value is written exactly as received
  3. A newline inside the message frames a fake
  4. Carriage return overwrites what an operator reads
  5. Escape at the handler, or emit structured output

basics

~20 s

Nothing in the logging module escapes control characters: the value is interpolated into the format string verbatim, so a newline inside it starts what every line-oriented reader treats as a second, attacker-authored entry. Escape untrusted fields before the formatter emits them.

solid answer

~50 s

A `StreamHandler` or `FileHandler` writes one record followed by a terminator, and every log reader downstream — a tail, a grep, a shipping agent, an alert rule — assumes one line means one event. Logging does not enforce that: `LogRecord.getMessage()` interpolates the value as-is, so if an untrusted waypoint name is `"bob\nWARNING routing admin override accepted"`, the file now contains a perfectly formed line that no one wrote. A lone `\r` is worse in a terminal, where it overwrites the line just printed and can hide the real event. The fix is to escape or quote untrusted values before they reach the output: a filter that rewrites the record's newlines, `repr()` on the field, or a structured JSON handler whose encoder escapes control characters by construction. Cap the length too, so one field cannot flood the file.

code

python · 17 lines
python
import logging


class OneLine(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.msg = record.getMessage().replace("\r", "\\r").replace("\n", "\\n")
        record.args = ()
        return True


logging.basicConfig(format="%(levelname)s %(name)s %(message)s")
log = logging.getLogger("routing")
hostile = "bob\nWARNING routing waypoint override accepted for admin"

log.warning("waypoint rejected for %s", hostile)   # two lines: one is forged
log.addFilter(OneLine())
log.warning("waypoint rejected for %s", hostile)   # one line, newline escaped

go deeper

for a junior

Remember that a value you log is written exactly as it arrived, newlines included, and that log files are read one line per event. Never build a log line by pasting in raw user input.

for a middle

Explain the mechanism: getMessage interpolates verbatim, the handler adds a terminator, and readers split on newlines. Be able to write the filter or use %r to escape an untrusted field.

for a senior

Show that you have operated this: put the escaping on the path every record takes rather than at call sites, keep legitimate multi-line records working, cap field length against volume attacks, and name the terminal-escape and carriage-return variants.

for a principal

Decide the framing contract for the whole estate — free text with escaping, or structured records where the encoder owns the frame — and who owns it. Weigh the migration cost against how much of your detection and alerting reads those lines as evidence.

## Why one line matters Text logs have an implicit frame: the record separator is the newline. `logging.StreamHandler.emit` writes the formatted record plus its terminator, and everything downstream inherits that convention — `tail -f`, a `grep` over yesterday's file, a shipping agent that reads line by line, an alert rule matching `^ERROR`. None of them parse; they split. The logging module does nothing to protect that frame. `LogRecord.getMessage()` performs `msg % args` and hands the result to the formatter, which substitutes it into `%(message)s`. Control characters in the value survive untouched. There is no flag, formatter option or configuration key on 3.14 that escapes them for you. ## The attack, concretely A route-optimisation job logs rejected waypoints: `log.warning("waypoint rejected for %s", name)`, with `name` coming from a request body. An attacker submits a name of `"bob\nWARNING routing waypoint override accepted for admin"`. The file now holds two lines, the second indistinguishable from a genuine record — same level token, same logger name, same shape. Anyone reading the file, and any tool aggregating it, counts one event that never happened. The variations are worth naming because they defeat different defences: - **Forging.** As above: manufacture entries to hide a real action in noise, or to frame another user. - **Overwriting.** A bare `\r` returns the cursor to the start of the line in most terminals, so the injected text paints over what an operator was about to read. Nothing is missing from the file, but the human sees a different story. - **Terminal escapes.** ANSI sequences in the value can recolour, clear the screen, or in some terminal configurations manipulate the title bar. If an operator is tailing the file, the value is being interpreted by a program you did not choose. - **Volume.** A single value carrying tens of thousands of newlines turns one request into tens of thousands of lines, which at a 1,200-request-per-minute peak is a cheap way to fill a disk or exhaust a log quota. Length limits matter as much as escaping. ## Where the fix goes Escaping at each call site does not survive contact with a real codebase; one forgotten call is the whole hole. Put it on the path every record must take. The direct approach is a filter on the handler that neutralises the record's message: ```python record.msg = record.getMessage().replace("\r", "\\r").replace("\n", "\\n") record.args = () ``` That is deliberately lossy and deliberately visible: the escaped `\n` shows a reader that the value contained a newline, rather than silently deleting it. `str.translate` with a mapping is the faster form when the record rate is high, and it can strip the whole C0 control range including the escape character rather than just the two obvious ones. The structural approach is to stop writing free text. A JSON-emitting handler puts the untrusted value in a field and lets the encoder escape control characters by construction; the record is one line because the encoder guarantees it, not because you hope so. That also survives values containing your own delimiter, which quoting alone does not. A third option for individual fields is `repr()` — `log.warning("waypoint rejected for %r", name)` — which quotes the string and escapes control characters. It is cheap and local, and it is a good default for any value that came from outside the process, but it is a call-site discipline with the usual weakness. ## The complication: legitimate multi-line records You cannot simply reject every newline at the handler, because logging emits multi-line records on purpose: an exception's formatted traceback is attached to the record and rendered after the message, and a formatter can legitimately span lines. A blanket strip would mangle those. So scope the escaping to the untrusted part. Escape the message and the attacker-controlled `extra` fields, and let the structured parts stay as they are; or move to a structured handler where the frame is the encoder's problem and a traceback is simply another JSON string field. What you must not do is assume a downstream parser will sort it out — the parser is the thing being attacked. ## What does not help Using `%s` arguments rather than an f-string is good practice for other reasons but escapes nothing. Setting a level does not help, because the injected content rides inside a record you meant to write. And validating the input at the edge helps only for the fields you thought to validate; the log path sees values from headers, query strings, filenames and third-party responses that no form validator ever touched.

  • Why can't you just strip every newline at the handler?
    Because some multi-line records are legitimate: an exception's formatted traceback is attached to the record and rendered under the message, and some format strings span lines by design. Stripping everything mangles those. Scope the escaping to the untrusted parts — the message and attacker-influenced extra fields — or move to a structured handler where the encoder owns the framing and a traceback is just another field.
  • How does emitting JSON records change the problem?
    It removes the implicit frame. The encoder escapes control characters as it serialises, so a newline in a value cannot break out of its field, and the record is one line by construction rather than by hope. It also survives values containing your own delimiters. The remaining risks are what a downstream viewer does with the decoded text and the sheer volume a hostile value can produce.
  • Besides forging entries, what else can a hostile value in a log do?
    A lone carriage return overwrites the line an operator is reading, so the file is intact but the human sees something else. ANSI escape sequences can recolour or clear a terminal that is tailing the file. And a value carrying thousands of newlines multiplies one request into thousands of lines, which is a cheap way to fill a disk or burn a log quota, so cap field length as well as escaping.

It is the same trick as smuggling a forged signature line into a document that is scanned line by line: the reader trusts the layout, so control of the layout is control of the content.

saying these in an interview costs you the question

  • Passing the value as %s escapes newlines for you
  • The Formatter strips control characters before writing
  • Quoting the field in the format string is enough
  • A carriage return is harmless because it prints nothing
  • Input validation at the edge covers every logged value
  • The log parser downstream will sort it out

context

resolving links…