cockroachdb / cockroachdb/cockroach
obs/ash: attribute write-path / commit IO to sessions (raft log sync, apply, storage engine)
- Dominant language
- Go
- Stars
- 32.5k
- Forks
- 4.1k
- PR merge metrics
- PR metrics pending
Description
**Is your feature request related to a problem? Please describe.**
Active Session History (ASH) classifies each sample with a `work_event_type` (CPU/IO/NETWORK/LOCK/ADMISSION/OTHER). For write-heavy workloads it attributes almost nothing to `IO`, even when the cluster is heavily IO-bound. The dominant write cost — WAL fsync, flush/compaction, raft log append, and state-machine apply — happens on goroutines that either carry no workload identity or live below the ASH instrumentation boundary, so it never surfaces as `WorkIO`.
This is by design today (ASH labels are best-effort, per-region resource hints, not on-CPU/off-CPU observations), but the result is that ASH is a good *wait/latency* map and an incomplete *IO resource* map for the write path.
**Evidence** (v26.2.1, 3-node n2-standard-8, `kv --read-percent=0`, ~23.5k ops/s, ~5 min steady window):
| signal | value |
|---|---|
| ASH `IO` (`KVEval`) share | **0.6%** |
| ASH `OTHER` (`RaftProposalWait`) | 43% |
| ASH `NETWORK` (`DistSenderRemote`) | 47% |
| `storage_disk_write_bytes` | 56 GB |
| `storage_disk_write_time` | 427 s (of ~930 node-seconds) |
| `storage_wal_fsync_latency` sum | 614 s |
So ~45–66% of node wall-time was genuinely in disk IO, but ASH reported 0.6% IO. The *latency* of that work does surface — as `RaftProposalWait` and `DistSenderRemote` (the request goroutines waiting for commit/replication) — but the *resource* (the fsync/apply) is attributed to neither IO nor the originating session.
**Describe the solution you'd like**
Attribute write-path / commit IO so it shows up in ASH (ideally as `WorkIO`, tied to the originating workload where feasible). The gap has two layers with different tractability:
1. *Reachable but uninstrumented CRDB code.* The raft log append + sync path ([`pkg/kv/kvserver/logstore/logstore.go`](https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/logstore/logstore.go), `CommitNoSyncWait` → the `SyncWaiterLoop` in [`sync_waiter.go`](https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/logstore/sync_waiter.go)) and the state-machine apply path have no `ash.SetWorkState` calls. The blocker here is not the dependency boundary but **attribution**: with non-blocking sync (`kv.raft_log.non_blocking_synchronization.enabled`, default true) the durable write is performed/awaited by a shared `SyncWaiterLoop` goroutine, async and batched across many ranges/workloads, while the originating request sits in `RaftProposalWait`. There is no single session to stamp the sample with.
2. *Below the ASH boundary (Pebble).* The fsync syscall, memtable flushes, and compactions run inside the Pebble library, which sits below `pkg/obs/ash` in the dependency graph and cannot call `SetWorkState` without a lower-level hook.
Suggested first step: instrument the `SyncWaiterLoop` / apply path with coarse attribution — even a shared "raft/commit IO" bucket (un-attributed to a specific workload) would make write IO visible in ASH and is far better than 0.6%. A Pebble-side sync/commit-pipeline hook would be the more complete, longer-term option.
**Describe alternatives you've considered**
- *Relabel `RaftProposalWait` as `IO`.* Rejected: it's a composite distributed-commit wait (local fsync + network replication + follower fsync + apply/scheduling), often dominated by the slowest follower's network+disk, not local IO. Relabeling would mislabel a wait and still miss the real fsync, which is on different goroutines.
- *Rely on `/_status/vars` + storage dashboards for write IO.* Works (that's how the gap was measured), but it can't attribute IO to a workload/session the way ASH is meant to.
**Additional context**
Related ASH IO/category accuracy gaps observed in the same experiment (smaller; folding in here rather than filing separately):
- **`KVEval` is hard-tagged `WorkIO` regardless of block-cache hit/miss** ([`replica_evaluate.go`](https://github.com/cockroachdb/cockroach/blob/master/pkg/kv/kvserver/replica_evaluate.go), `ash.WorkIO, "KVEval"`). In `kv95` and an analytical hash-join workload, reads were served **99.7–99.9% from the block cache with 0 disk-read bytes**, yet that (CPU/memory) work is reported as IO. Pebble knows hit-vs-miss; ASH doesn't consult it. Because the label is fixed for the whole region, fixing this likely needs post-hoc or split labeling.
- **`RaftProposalWait` is bucketed `OTHER`.** It's the #1 write-path wait; a dedicated `COMMIT`/`REPLICATION` `work_event_type` would make the wait-class view far more legible than lumping it with backpressure/lease/commit-wait/rate-limit.
Measurement note for anyone reproducing: the cluster ASH view fans out and caps results at `obs.ash.response_limit` (default 10000/node). Under dense load the most-recent samples span only seconds, so historical windowed queries against `crdb_internal.cluster_active_session_history` can silently return empty; the per-node virtual table is uncapped.
Jira issue: CRDB-64948
Contributor guide
Research direction
Start in pkg/kv/kvserver/logstore/logstore.go at CommitNoSyncWait and follow the SyncWaiterLoop in sync_waiter.go, then inspect the state-machine apply path and existing ASH instrumentation. Account for non-blocking, shared, batched synchronization and the Pebble dependency boundary. Done means the write-path IO is visible in ASH with an explicitly coarse attribution, without relabeling RaftProposalWait.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- databases, distributed-systems, observability-sre
- Issue type
- Feature
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Quiet
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100