Observing queries

There are two mechanisms here and they are for different jobs. Query logging (useDebug) logs every statement, which makes it a development tool — you cannot leave it on. Query observers are notified around every statement and decide for themselves what is worth reporting, which is what you leave on in production.

If what you actually want is OpenTelemetry spans, that ships as a configuration-driven observer and needs no application code at all — see OpenTelemetry tracing.

Registering an observer

An observer implements Propulsion\Observability\QueryObserver and is notified twice per statement: before it is sent, and after it comes back.

use Propulsion\Observability\QueryExecution;
use Propulsion\Observability\QueryObserver;

final class TracingObserver implements QueryObserver
{
    public function __construct(private readonly Tracer $tracer) {}

    public function queryStarted(QueryExecution $execution): void
    {
        $execution->setAttribute('my.span', $this->tracer->startSpan('db.query'));
    }

    public function queryFinished(QueryExecution $execution): void
    {
        $span = $execution->getAttribute('my.span');
        $span->setAttribute('db.statement', $execution->sql);
        $span->setAttribute('db.duration_ms', $execution->getDurationMilliseconds());

        if ($execution->isFailed()) {
            $span->recordException($execution->getError());
        }

        $span->end();
    }
}

Propulsion::addQueryObserver(new TracingObserver($tracer));

Two methods rather than one after-the-fact callback, because the shape a tracer needs is a span: it has to be open while the statement runs, so whatever the driver and the server do falls inside it. An observer that only cares about the outcome leaves queryStarted() empty.

The same QueryExecution object is handed to both calls, so state that has to span them — the open span above — goes on it with setAttribute(), rather than into a correlation map keyed by an id that would have to be invented.

removeQueryObserver() unregisters one and clearQueryObservers() unregisters all (mostly for test isolation). Registering the same instance twice is a no-op, so a double-registered collector cannot double-count.

What an execution carries

->sql	the statement text, as sent
->source	statement (a prepared statement — nearly all ORM traffic), exec, or query
->connection	the PropulsionPDO it ran on
->boundParams	the values bound before this statement ran, keyed the way PDO keys placeholders — see Bound parameters
->correlationId	whatever Propulsion::getCorrelationId() returned when this execution began, or null — see Correlation id
getDurationSeconds() / getDurationMilliseconds()	monotonic (hrtime), so an NTP step cannot produce a negative duration
getRowCount()	rows affected for statements that change rows; null for a SELECT
isFailed() / getError()	the exception, which is rethrown to the caller either way

getRowCount() is deliberately null for a SELECT: PDO documents rowCount() as unreliable there, and on several drivers answering it means buffering the whole result set — the measurement would change what it measures. If you need the rows themselves, that is a separate, later signal: captured rows.

The shipped collectors

SlowQueryObserver — a slow-query threshold in seconds. Silent until something is actually slow:

use Propulsion\Observability\SlowQueryObserver;

Propulsion::addQueryObserver(new SlowQueryObserver(0.1));             // PSR-3 warning at 100ms
Propulsion::addQueryObserver(new SlowQueryObserver(0.1, $handler));   // or handle it yourself

QueryStatsObserver — counts and totals for a request:

use Propulsion\Observability\QueryStatsObserver;

$stats = new QueryStatsObserver();
Propulsion::addQueryObserver($stats);

// ... at the end of the request ...
$metrics->timing('db.query.total_ms', $stats->getTotalMilliseconds());
$metrics->count('db.query.count', $stats->getCount());
$metrics->count('db.query.failed', $stats->getFailedCount());

Both are collectors, not metrics clients. StatsD and Prometheus both have mature PHP clients, and wrapping one here would pin its version for every consumer — the same reasoning that keeps a Redis driver out of the query cache. OpenTelemetry is the exception, because it is the one backend where the integration is worth owning: OpenTelemetryQueryObserver ships in the box and is configured, not coded.

Correlation id

Propulsion::setCorrelationId(?string $id) sets a request-scoped identifier — something a log aggregator, or a record/replay recorder, can use to group every query one request issued. It lives on Session, the same request-scoped bucket forceMasterConnection already lives in, and Session::reset() clears it, so it never leaks onto a later request sharing this worker process:

Propulsion::setCorrelationId($request->getHeaderLine('X-Request-Id'));
// ... handle the request ...
Propulsion::getSession()->reset();   // clears it, along with everything else request-scoped

Every QueryExecution built while it is set carries it on ->correlationId, so an observer sees which request a query belongs to without needing request-scoped storage of its own. That matters specifically because the observer registry is process-scoped, not request-scoped: adding and removing an observer per request would mean writing process-wide state from what should be request-scoped code, which is unsafe under a threaded worker runtime — FrankenPHP with worker <n> above 1 shares process statics across every thread with no per-thread isolation. Register one observer at boot and let it read ->correlationId off each execution instead.

Bound parameters

->boundParams is an array of Propulsion\Observability\BoundParameter, keyed the way PDO keys placeholders (1-based position, or :name). Each carries ->value plus, when they are known, ->table and ->column:

// [':p1' => BoundParameter { value: 'a@example.com', table: 'customer', column: 'EMAIL' }]

Values are captured from bindValue(), which is where every ORM value actually is: each runtime call site (DBAdapter::bindValues()/bindValue()) binds individually and then calls execute() with no arguments. Values passed to execute($params) are captured as well — see what is and isn’t captured below.

->table/->column are populated whenever DBAdapter::bindValues() itself knew them, which is essentially always for ORM traffic: BasePeer::buildParams() for an INSERT/UPDATE and Criterion for a SELECT’s WHERE clause both carry table and column all the way through. They are null for a value bound from outside that path — Propulsion::rawQuery(), or hand-written PDO code. That distinction is what lets a consumer redact by real column name rather than by guessing at the placeholder.

->boundParams is also always empty for exec()/query(), which take no parameters by construction.

bindValue() is captured; bindParam() is not

PDO has two ways to attach a value to a placeholder, and the difference between them is the whole reason one is observable and the other isn’t.

bindValue($param, $value) binds by value. The value is read at bind time and copied into the statement there and then. Changing the variable afterwards has no effect on what the statement runs with:

$email = 'a@example.com';
$stmt->bindValue(':email', $email);
$email = 'b@example.com';     // irrelevant — :email was already fixed to a@example.com
$stmt->execute();

bindParam($param, &$var) binds by reference. PDO stores a reference to the variable and reads it at execute() time, which is what makes it useful for re-executing one prepared statement in a loop, and for PDO::PARAM_INPUT_OUTPUT parameters that the driver writes back into:

$stmt = $con->prepare('INSERT INTO tag (name) VALUES (:name)');
$stmt->bindParam(':name', $name);      // bound once, to the variable itself
foreach (['php', 'sql', 'orm'] as $name) {
    $stmt->execute();                  // reads $name fresh on each call
}

Propulsion overrides bindValue() on PropulsionStatement and records what passes through it, which covers every value the ORM itself binds: DBAdapter::bindValues() and DBAdapter::bindValue() — the only paths generated code and ModelCriteria use — bind each parameter individually with bindValue(), then call execute() with no arguments at all.

Values handed straight to execute($params) are captured too, even though no ORM path uses that form. They are overlaid on whatever bindValue() already recorded, rebinding exactly the keys $params names and leaving any other key with what was actually bound for it — the same way PDO’s own execute($params) behaves. Those entries carry a value but no ->table/->column, since nothing on that path knows them.

bindParam() is the one form not captured, and by-reference semantics are the whole reason. Recording the value at bind time would record something that may never be sent — in the loop above it would record php three times — so capturing it correctly would mean deferring the read to execute() time and dereferencing the variable then. That is real machinery for a path that does not occur in Propulsion’s own SQL: nothing in the generated or runtime code binds by reference. execute($params) is the opposite case, and the distinction is worth being precise about — its values are already sitting in an array with nothing to defer, which is why they are captured and bindParam()’s are not.

So one shape has a consequence to know about:

// Captured, with table/column where the ORM path knew them.
$stmt->bindValue(':id', $id, PDO::PARAM_INT);
$stmt->execute();

// Captured, value only.
$stmt->execute([':id' => $id]);

// Observed, but ->boundParams has no entry for :id.
$stmt->bindParam(':id', $id, PDO::PARAM_INT);
$stmt->execute();

Hand-written PDO code that uses bindParam() gets a statement with no reported parameter for it. The statement is still observed — SQL, duration, row count and outcome all arrive — but its values won’t. If you are writing raw SQL against a Propulsion connection and want the values in a recorder or a trace, use bindValue() or pass them to execute(). None of this changes what the database does; it is purely about what an observer can see. bindParam() remains the right choice when you need by-reference semantics or an output parameter — you are trading parameter visibility for it, not correctness.

Captured rows

Returned rows need an observer to opt in, because of a timing problem the two-callback shape alone cannot solve: for find()/findOne(), rows are fetched by the caller, after PropulsionStatement::execute() has already returned — queryFinished() fires strictly before any row exists to report. So this is a separate, later signal, on a separate interface:

use Propulsion\Observability\QueryExecution;
use Propulsion\Observability\RowCapturingQueryObserver;

final class CassetteObserver implements RowCapturingQueryObserver
{
    public function queryStarted(QueryExecution $execution): void
    {
        $execution->requestRowCapture(100);   // ask, or rowsCaptured() never fires
    }

    public function queryFinished(QueryExecution $execution): void
    {
    }

    public function rowsCaptured(QueryExecution $execution): void
    {
        $cassette->record(
            $execution->sql,
            $execution->boundParams,
            $execution->getCapturedRows(),
            $execution->getColumnNames(),
            $execution->isRowsTruncated(),
        );
    }
}

• Ask first, in queryStarted(). An observer that never calls requestRowCapture() never gets rowsCaptured() called, and costs nothing extra on the fetch() hot path either — the same “free when unused” shape every observer here has.
• Capped, by default at 100 rows. More than one observer can ask; the largest request wins. Past the cap, isRowsTruncated() is true and the rows past it are simply not there — there is no partial count, because a recorder needs to know its capture is incomplete, not by how much.
• Fires once, after the result set is exhausted or closed — whichever comes first among the cursor naturally running out, an explicit closeCursor(), the statement being re-execute()’d without having been exhausted, or the statement’s own destructor.
• Column names are attached once, and only for a list-shaped row (PDO::FETCH_NUM, what the ORM’s own default formatter uses). An associative or object row already carries its own names, so nothing extra is captured there.
• Rows are handed over exactly as fetched — a numeric array for the default formatter, but an object, an associative array or a scalar for a caller using a different fetch mode.
• No redaction happens here. A consumer that needs to scrub PII or secrets out of bound values or returned rows does that on its own side, with whatever discipline it already applies elsewhere. Propulsion’s job is to expose what actually happened.
• rowsCaptured() says nothing about duration or success. Keep using queryFinished() for that.

Bound parameters and captured rows exist because this is what a recorder needs, and quioteframework/replay-propulsion is the shipped consumer — it turns them into a cassette’s effects ledger, redacted by real column name.

Things to know

• An observer must not throw. One that does is caught, logged at error level and skipped. That matters more than it looks: an exception out of queryFinished() would replace the exception the statement itself was reporting, turning a database error into a mystifying observer stack trace.
• Observers are process-scoped and survive Session::reset(). They are bootstrap wiring — a tracer that silently stopped tracing at the request boundary would be worse than one that was never installed, because nothing would say so. The corollary under a persistent worker: reset a QueryStatsObserver per request, or it reports totals since the worker booted.
• Everything is observed, including bookkeeping. Liveness pings (SELECT 1), savepoints and the ORM’s own metadata queries all go through the same seam. Filter on ->sql or ->source in the observer if that is noise for your backend.
• Persistent connections see nothing from prepared statements. PDO refuses a custom statement class under PDO::ATTR_PERSISTENT, which is the same reason dropped-connection detection does not work there. exec() and query() are still observed.
• Cost when unused is one array check per statement — no QueryExecution is constructed for an application with no observers registered.

Where the hook sits, and why that matters

Instrumentation lives on PropulsionStatement::execute(), plus PropulsionPDO::exec() and ::query().

The first one is the load-bearing choice. Essentially all ORM traffic prepares a statement and executes it — the generated Peer and ModelCriteria paths all do — so a hook on exec()/query() alone would measure almost nothing while looking like it worked. This codebase has made exactly that mistake before: dropped-connection detection lived there for years and saw almost no real traffic, which is why PropulsionStatement exists at all. A live test asserts that a generated query class’s find(), count() and save() are all seen, specifically so it cannot regress unnoticed.

Related

• OpenTelemetry tracing — the shipped span exporter, turned on from configuration.
• Logging — useDebug query logging, the development-time counterpart.
• Connection resilience — the other feature built on the same statement seam.
• Running under a persistent worker — what is process-scoped and what has to be reset per request.
• Record, replay & regression tests — the Quiote-side consumer of bound parameters and captured rows.