doc: design for reporting database time to SQL clients

[tonydu-mz]

Add a design document for reporting database time to SQL clients.

Motivation

The Console SQL Shell reports one number, Returned in 148ms. It is a client-side
round trip, and it is correct: calculateCommandDuration
(console/src/platform/shell/timings.ts:28-50) subtracts two performance.now()
stamps. It is also unable to answer the question users actually ask, which is how
much of that time was Materialize.

The gap is not Console-specific. A psql user and a dbt run are equally unable to
separate their latency from ours.

Design doc only. No behaviour change, no code.

Description

Report database time: how long Materialize worked on a statement. Clients opt in
via a session variable and receive it as a notice with a dedicated SQLSTATE, so this
is a platform capability rather than a Console feature. The Console renders it beside
the round trip it already shows:

Returned in 148ms · 12ms database time

Why not time to first row. The adapter already records
time_to_first_row_seconds (src/adapter/src/client.rs:2222-2229) and discards the
per-request value, which makes it the tempting choice. It is the wrong quantity: a
query returning 100,000 rows can reach its first row in 2ms and then occupy the
server for hundreds of milliseconds streaming the rest. It ships in the payload for
diagnosis, not as the headline number.

Where a statement finishes is not one moment. Row-returning statements end when
the last row is accepted by the transport. Writes are the interesting case: they only
stage at their completion message (add_transaction_ops at
src/adapter/src/coord/sequencer.rs:948, returning immediately at :974), and the
durable commit runs afterwards (src/pgwire/src/protocol.rs:1355-1359,
src/environmentd/src/http/sql.rs:1596-1603). Anchoring a write to its completion
message would report staging cost only, so an INSERT that spent most of its time in
group commit would render 2ms database time. Writes in an implicit transaction
therefore emit after the commit. In an explicit transaction the commit belongs to
COMMIT, which reports it.

Delivery. Every site queues via Session::add_notice and flushes explicitly,
rather than sending a BackendMessage directly. Session::notice_filter
(src/adapter/src/session.rs:558) is private to mz_adapter and only runs on the
queue path, so a direct send would bypass client_min_messages and could not fix it
from mz_pgwire. The pre-existing statement-scoped flushes cannot carry the value,
because all five run before it exists.

A stated limitation. Both transports flush inside the row loop and await the
socket (protocol.rs:2655; sql.rs:1218-1219, whose comment describes the intent as
"so a slow client applies real backpressure"), so client backpressure lands inside
the measured interval. Database time therefore degrades toward round-trip time
exactly when the network is slow. Excluding socket waits would mean instrumenting
around every flush, a materially larger change than the one clock read this design
needs. This version ships the last-row anchor and states the limitation in the
tooltip and the docs rather than implying a precision it does not have.

Cursors are likewise outside the guarantee: execute_started is stamped once and
resumption does not re-stamp (protocol.rs:1768-1779), so a FETCH that exhausts a
stream reports elapsed time spanning client round trips. The Console is unaffected
(Fetch is rejected on HTTP and WebSocket, sql.rs:1516-1520) but psql and dbt use
cursors, so the docs must say so.

Interval start, settled by measurement. The interval excludes parse and bind.
Production telemetry over six hours puts parse at 0.050ms and bind at 0.032ms
mean; the PromQL is inlined in the doc. Against the 12ms worked example that is about
0.7%, at the edge of the Shell's 0.1ms display quantum.

Verification

No code, so no tests. What was verified instead:

• Every file:line citation resolves in-range, and each load-bearing one was
  content-checked against the tree.
• Every mechanism claim was traced through the call path rather than read at the
  cited line: that the value is in scope at each emission point, that each frame is
  reached by the statements it claims to cover, and that cancellation, error, and
  PortalSuspended paths correctly emit nothing.
• The paths that emit nothing are named rather than assumed absent: EmptyQuery,
  COPY ... FROM STDIN, and a replayed PortalState::Completed all bypass
  command_complete!, and a terminating SUBSCRIBE reaches the read emission
  point through send_rows, which is why emission is guarded on statement type.
• The parse and bind figures come from production telemetry queried on 2026-08-25,
  not from inference.

The plan opens with an MVP that is not code and explicitly gates PR 1, since two of
its possible outcomes would change the design rather than confirm it.

Design review requested from @MaterializeInc/adapter. The Console and docs scopes are
affected by later PRs in the plan, not by this one.

[linear-code]

CS-218

[SangJunBak]

At first glance, I like the idea of using notices to tell the Console what the timings are. We do a similar pattern with the "query insights / plan insights" feature.

I think it'd be nice to derive the timings from our statement logging feature, but we may miss missed recording due to decreased configured sampling. It seems feasible to use your method of collection, but it still doesn't seem to speak the whole truth due to the edge cases you mentioned in the doc (e.g. DDL, excluding parse/bind).

However for the purposes of not misleading initial customers with slow query times caused by the browser, we could probably move forward with this "best effort/ approximate" approach since the cost of computation and implementing should be low. In the future, we could maybe extend this with our existing statement logging feature especially since it contains more coarse grained timing information, similar to Cockroach's execution breakdown UI:

I think future work for reviewing this design doc would be to look closely at the correctness of the timings and how similar they are to if you were to do \timing in psql, the postgreql client. A prototype would help too!

[tonydu-mz]

Yah, i can totally build out a prototype if we think directionally this is the right way to do thing. The statement logging is only possible get to a state where we feel comfortable with not having to sample

[tonydu-mz]

quick corrections

DDL is covered. The exclusions are SUBSCRIBE, COPY, MCP, an empty query on pgwire, and intermediate FETCHes. DDL, SET, and transaction control all go through command_complete! and report a number. Writes are covered too, though they needed their own anchor: a write only stages at its completion message and the durable commit happens afterwards, so a write in an implicit transaction emits after the commit or an INSERT would report ~2ms of a 350ms operation.

Parse and bind are measured, not assumed small. Across prod us-east-1 over six hours, parse averages 0.050ms and bind 0.032ms. Against the doc's 12ms worked xample that's ~0.7%, which is at the edge of the Shell's 0.1ms display quantum. The PromQL is inlined in the Alternatives section.

[jdonelson]

If we wanted to estimate it from the client side, we could send a ping over the ws connection and use that as an estimate for network latency. We'd then subtract that number from the reported time on the SQL query response. It would be an educated guess instead of an accurate measurement, but it would be something. We could label it with that caveat in the UI. It would be a pretty easy lift from a LOE perspective, I think.