Skip to content

adapter: Add emergency logging of arriving statements#37567

Merged
ggevay merged 5 commits into
MaterializeInc:mainfrom
ggevay:statement-arrival-logging
Jul 13, 2026
Merged

adapter: Add emergency logging of arriving statements#37567
ggevay merged 5 commits into
MaterializeInc:mainfrom
ggevay:statement-arrival-logging

Conversation

@ggevay

@ggevay ggevay commented Jul 10, 2026

Copy link
Copy Markdown
Contributor

Motivation

Fixes DB-161, which came from the stack overflow incident.

An emergency diagnostic for statements that repeatedly crash environmentd before they reach the statement log, or before the statement log is written out to persist (which happens only every few seconds).

Description

Adds the internal system var enable_statement_arrival_logging (default OFF). When on, the pgwire and HTTP SQL frontends log every incoming statement and other frontend message at info level as soon as it arrives, before any processing beyond parsing.

  • pgwire logs in advance_ready, before dispatching on the message. (Messages consumed by the COPY subprotocol or the post-error drain loop are not logged.)
  • SQL text is logged with its literals redacted, by parsing it and using the same redacted AST display that the statement log uses. Identifiers and statement structure stay visible, for debuggability. A statement that fails to parse is logged as a placeholder with only its byte length. Consequently, a statement that crashes the parser itself is not captured at all, an accepted tradeoff (the parser's recursion guards make such crashes rare).
  • Extended protocol messages log prepared statement and portal names, so an execute can be connected back to the parse that carried the SQL text, together with the connection id and session UUID. Bind parameter values are data that redaction cannot reach, so only their count is logged.
  • Authentication payloads are never logged. COPY data is logged as its length only. The message match is exhaustive, so a new FrontendMessage variant fails compilation until the author decides how to log it.
  • Even redacted statements reveal schema structure and identifiers (the same exposure as the statement log), which is one of the reasons the flag defaults to off and is not user visible. This is intended only for debugging active incidents.
  • The flag is read through the session's cached catalog snapshot, so the per-message cost while the flag is off is negligible.
  • enable_statement_arrival_logging follows the pattern of enable_internal_statement_logging (a plain internal bool system var, not a feature_flags! entry, since it gates no SQL surface).

Example log lines with the flag on:

INFO mz_pgwire::protocol: statement arrival conn_id=282279413 session_uuid=019f5ce6-... kind="parse" name="s2" sql=SELECT $1::text AS x, '<REDACTED>' AS y
INFO mz_pgwire::protocol: statement arrival conn_id=282279413 session_uuid=019f5ce6-... kind="bind" portal_name="" statement_name="s2" num_params=1
INFO mz_pgwire::protocol: statement arrival conn_id=282279413 session_uuid=019f5ce6-... kind="execute" contents=Execute { portal_name: "", max_rows: 0 }
INFO mz_pgwire::protocol: statement arrival conn_id=282194762 session_uuid=019f5ce6-... kind="query" sql=CREATE CONNECTION polaris TO ICEBERG CATALOG (CATALOG TYPE = 'REST', URL = 'https://catalog.example', CREDENTIAL = '<REDACTED>', WAREHOUSE = 'wh')
INFO mz_pgwire::protocol: statement arrival conn_id=282570067 session_uuid=019f5ce6-... kind="query" sql=<unparseable (25 bytes)>

Verification

No tests added. Verified manually against a local environmentd: simple and extended pgwire protocol, HTTP simple and extended requests, and ALTER SYSTEM SET/RESET turning the logging on and off immediately. Also verified the literal redaction (CREATE SECRET values, inline connection credentials such as ICEBERG CREDENTIAL, string and numeric literals in queries), the placeholder for unparseable statements, and that none of the planted sensitive values appear anywhere in the log.

🤖 Generated with Claude Code

(An alternative would be to add a Debug-level log line instead of a new config flag. I rejected this approach, because turning on Debug logging for the entire envd affects performance badly. We could do it per-crate, but then it just gets too complex. Flipping a simple flag is easier to get right during an incident.)

@ggevay ggevay added the A-ADAPTER Topics related to the ADAPTER layer label Jul 10, 2026
@ggevay ggevay marked this pull request as ready for review July 10, 2026 12:59
@ggevay ggevay requested a review from a team as a code owner July 10, 2026 12:59

@def- def- left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just want to have it documented, are we ok with unredacted secrets/binds here?

@ggevay

ggevay commented Jul 13, 2026

Copy link
Copy Markdown
Contributor Author

I think that's ok here, because we'll use this only in emergencies, i.e. active incidents. @jasonhernandez, what do you think?

Edit: Note that login secrets (like pgwire passwords) are omitted, it's just CREATE SECRET that would get logged. (Plus prepared statement parameters, but that's even less sensitive.)

Edit 2: But I'll make the comment/description in the feature flag more scary, noting the above.

Edit 3: Actually, I've just added more redaction, see second commit.

@ggevay ggevay force-pushed the statement-arrival-logging branch from d0af573 to 8caf725 Compare July 13, 2026 12:15

@def- def- left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Iceberg credentials still make it through apparently:

CREATE CONNECTION polaris TO ICEBERG CATALOG (
    CATALOG TYPE = 'REST',
    URL = 'https://catalog.example',
    CREDENTIAL = 'client-id:sk_live_abc123',
    WAREHOUSE = 'warehouse'
);

@ggevay ggevay force-pushed the statement-arrival-logging branch 2 times, most recently from 515ac96 to 87cf79c Compare July 13, 2026 18:37
@ggevay

ggevay commented Jul 13, 2026

Copy link
Copy Markdown
Contributor Author

Thanks @def-, I've added that as well now. So, the full list is "secret", "password", "credential", "token".

@ggevay ggevay requested review from jasonhernandez and mtabebe July 13, 2026 18:39

@jasonhernandez jasonhernandez left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can merge this - we'll need to be careful with its use given where this sits in processing queries.

@mtabebe mtabebe left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One question, but the change looks fine for me for what we are trying to accomplish

Comment thread src/adapter/src/client.rs
}

/// Reports whether `enable_statement_arrival_logging` is on.
pub async fn statement_arrival_logging_enabled(&mut self) -> bool {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we need to look at this in the catalog on every call why can't we just check the DynCfg?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess it means we don't need a restart to pick it up?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's no live dyncfg handle (ConfigSet) available in the frontends or SessionClient today. The only way to read a dyncfg from pgwire is get_system_vars(), which is a coordinator round-trip per call. The catalog snapshot, by contrast, is served from the session's snapshot cache, so in the steady state the check is just a Weak::upgrade plus an atomic revision check, with no round-trip.

(On the restart question: neither mechanism needs one, both dyncfgs and system vars are runtime-updatable. The snapshot is simply the cheapest config handle we already have at this spot.)

Comment thread src/adapter/src/client.rs Outdated
@ggevay ggevay force-pushed the statement-arrival-logging branch from edf5deb to 3da7989 Compare July 13, 2026 19:18
@ggevay

ggevay commented Jul 13, 2026

Copy link
Copy Markdown
Contributor Author

I've added one more commit that changes the redaction: We now redact the same way as the statement log: by calling to_ast_string_redacted. The cost of this is that we need to parse to do the redaction, so we lose debugging coverage for parser crashes, but this is deemed an acceptable tradeoff. (slack thread)

(Another drawback, shared with the statement log, is that the statement often won't be a copy-pasteable repro, because the redaction is not mindful of the types of literals and stuff, so the redacted statement often has syntax errors, see https://github.com/MaterializeInc/database-issues/issues/8796. But I guess in the LLM-era those syntax errors are not hard to fix up.)

ggevay and others added 5 commits July 13, 2026 21:57
Add the internal system var enable_statement_arrival_logging (default
off). When on, the pgwire and HTTP SQL frontends log every incoming
statement and other frontend message at info level as soon as it
arrives, before any processing.

This is an emergency diagnostic for statements that repeatedly crash
environmentd before they reach the statement log, or before the
statement log is written out to persist. Extended protocol messages log
prepared statement and portal names plus bind parameters, so an execute
can be connected back to the parse that carried the SQL text, together
with the connection id. Authentication payloads are never logged. COPY
data is logged as its length only. The logged SQL is not redacted,
which is one of the reasons the flag defaults to off.

The flag is read through the session's cached catalog snapshot, so the
per-message cost while the flag is off is negligible.

See https://linear.app/materializeinc/issue/DB-161/can-we-log-redacted-sql-early-at-debug-level-to-aid-panic

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Statement text or bind parameters that might contain a sensitive value
are replaced by a placeholder. We sniff for the keywords "secret" and
"password" (case-insensitively), since precise redaction would require
parsing, and arrival logging runs before parsing on purpose. Bind
parameters are also redacted when the prepared statement they refer to
trips the check.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The CREATE CONNECTION options CREDENTIAL and SESSION TOKEN accept
inline sensitive values but contain neither "secret" nor "password".

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Instead of the keyword-based skipping of possibly sensitive statements,
parse the arriving SQL and log it with its literals redacted, using the
same redaction as the statement log. Statements that fail to parse are
logged as a placeholder with only their byte length. Since logging now
requires parsing, a statement that crashes the parser is not captured
at all anymore, an accepted tradeoff. Bind parameter values are data
that redaction cannot reach, so only their count is logged now.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Fix a stale doc comment that still described the keyword-based
redaction. Stop logging CopyFail's client-supplied message. Distinguish
too-large statements from unparseable ones in the placeholder.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@ggevay ggevay force-pushed the statement-arrival-logging branch from 8891550 to 8ce6f96 Compare July 13, 2026 19:58
@ggevay ggevay enabled auto-merge (squash) July 13, 2026 19:59
@ggevay ggevay merged commit e4df997 into MaterializeInc:main Jul 13, 2026
123 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

A-ADAPTER Topics related to the ADAPTER layer

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants