sql,obs: crdb_contention_activity records at most one sample for a long-blocked waiter
C-bugA-sql-observabilityT-observabilityO-agent
**Describe the problem**
The `information_schema.crdb_contention_activity` view (added by the open
`contention-activity-view` PR, cockroachlabs/cockroach#3470) surfaces **at most
one — often zero — row for a request blocked on a contended lock**, regardless
of how long it waits. In a demo, a reader blocked for minutes produced a single
sample.
**Root cause**
A request blocked on a lock held by a live transaction is recorded in ASH as
`work_event = 'LockWait'` — the event the view filters on, and the only one
carrying the `range_id`/`table_id`/`index_id`/`blocking_stmt_fingerprint_id`
labels — **only for the initial liveness-push delay (~100ms)**. It then
escalates to synchronously pushing the lock holder's transaction and, for the
*entire remaining wait*, is sampled as `TxnPushWait`, which the view neither
matches (`work_event IN ('LatchWait','LockWait')`) nor labels (`labels ? 'range_id'`).
Mechanically, the push runs on the waiter's own goroutine
(`intentresolver.MaybePushTransactions` → `db.Run`), so `maybeInterceptReq`
registers `TxnPushWait` on top of the still-present `LockWait` on that
goroutine's work-state stack, and the sampler only reads the top of the stack.
**To Reproduce**
1. Single-node cluster; `SET CLUSTER SETTING obs.ash.labels.enabled = true`,
`obs.ash.labels.kv_sync_wait.enabled = true`, `obs.ash.sample_interval = '1s'`.
2. Session A: `BEGIN; UPDATE t SET v=v+1 WHERE k=1;` (hold, don't commit).
3. Session B: `SELECT * FROM t WHERE k=1 FOR UPDATE;` (blocks).
4. While B is blocked (verified via `crdb_internal.cluster_locks`), query
`crdb_internal.cluster_active_session_history` for `work_event='LockWait'`.
At 1s sampling: 0 `LockWait` samples over a 90s block. At 10ms sampling over an
~8s block, on the same goroutine:
| work_event | samples | carry `range_id` |
|---|---|---|
| LockWait | 10 | 10 |
| TxnPushWait | 782 | 0 |
| TxnQueryWait | 782 | 0 |
**Expected behavior**
A request blocked on a lock for its whole wait should be represented in
`crdb_contention_activity` for the duration of the wait, not by a single
transient sample.
**Fix options**
- **Option A (recommended, less invasive): don't let a lock-wait-nested push mask
the `LockWait`.** In `maybeInterceptReq`, if the current goroutine already
holds a `WorkLock`/`LockWait` state, skip registering the nested `TxnPushWait`.
The labeled `LockWait` stays top-of-stack for the whole wait and the view works
unchanged. Tradeoff: lock-driven pushes no longer appear as `TxnPushWait`.
- **Option B: label the push.** Attach the contention labels to
`TxnPushWait`/`TxnQueryWait` and add them to the view filter. More invasive —
the push batch is re-stamped as the `WORKLOAD_ID_INTENT_RESOLUTION` *system*
workload and coalesces multiple pushees, so there is no single lock identity at
the push site.
**Caveats**
- Topology (predicted, not yet verified): in a multi-node cluster where the
pushee's txn-record range is remote, the waiter's goroutine stays in `LockWait`
for the whole wait (the push is an RPC; `TxnPushWait` appears on the remote
node). So this is likely a single-node / co-located-range artifact — common in
demos and small clusters.
- Test gap: the PR's logictest inserts synthetic ASH rows with labels; it never
drives the real lock-wait → work-state path, so it cannot catch this.
Epic CRDB-65143
1 条评论