ZooKeeper write latency high: read zk_updatelatency, not just avg_latency

The dashboard says ZooKeeper is fine. zk_avg_latency is 2ms. Clients are timing out anyway: distributed locks expiring mid-acquisition, Kafka controllers flapping, HBase regions bouncing. The signal you are missing is zk_updatelatency, the write-specific latency family that 3.6+ exposes separately from the misleading aggregate.

The trap is structural. zk_avg_latency, zk_min_latency, and zk_max_latency from mntr combine reads and writes into one cumulative statistic. Reads are local in-memory lookups, typically sub-millisecond. Writes require a leader round-trip, a ZAB proposal, a quorum ACK, a commit, and an fsync. When read volume dominates, a healthy average masks pathological write latency. These are also server-cumulative statistics since the last srst reset, not sliding windows: a single fsync stall from three hours ago still inflates zk_max_latency.

This is the operator runbook for isolating high write latency in ZooKeeper: read the right metric, then localize the cause across disk, network, GC, and pipeline saturation.

What this means

zk_updatelatency measures the full write round-trip: client request to leader, leader proposes and fsyncs, followers ACK, leader commits and fsyncs, leader responds. Available since ZooKeeper 3.6.0 as zk_avg_updatelatency, zk_min_updatelatency, zk_max_updatelatency, and the percentile breakdowns zk_p50_updatelatency, zk_p95_updatelatency, zk_p99_updatelatency, zk_p999_updatelatency.

Elevation means one of three things, and the rest of this article is about telling them apart:

  • Disk: fsync of the transaction log on the leader, on followers, or both.
  • Network: quorum ACK latency between the leader and followers.
  • Processing: JVM stop-the-world pauses, request queue depth, or pipeline congestion.

The session-timeout math is the practical urgency. Default tickTime is 2000ms and minSessionTimeout is 2 x tickTime = 4000ms. When zk_p99_updatelatency approaches half of that, clients risk expiring mid-write because the same connection carries heartbeats.

flowchart LR
  C([Client write]) --> L[Leader: zxid, txn log write]
  L -->|PROPOSE| Q{Quorum ACK}
  Q -->|reached| CM[Leader: commit, apply]
  CM --> R([Respond to client])
  LD[(Leader fsync)] -. slow .-> L
  FD[(Follower fsync)] -. slow .-> Q
  GC[JVM STW pause] -. stalls all .-> L
  Q -. slow network .-> CM

Common causes

CauseWhat it looks likeFirst thing to check
Transaction log fsync stallzk_p99_fsynctime elevated, zk_p99_updatelatency tracks it 1:1iostat -x 1 5 on the dataLogDir device
Follower quorum ACK latencyzk_p99_quorum_ack_latency elevated on leader, followers’ fsync or GC also elevatedPer-follower zk_fsynctime and zk_jvm_pause_time_ms
GC pause on leader or followerzk_p99_jvm_pause_time_ms spikes, latency spikes rhythmic with GC frequencyjstat -gcutil on the ZK process
Read traffic masking write stallzk_avg_latency flat, zk_p99_updatelatency climbingCompare zk_updatelatency vs zk_readlatency side by side
Cloud storage throttlingfsync latency cliff at a specific time of dayCloud provider IOPS and burst-credit metrics
dataLogDir sharing disk with snapshotsfsync spikes coincident with snapshot creation timestampsdataLogDir config and df on both directories

Quick checks

# Confirm leadership. Writes route through the leader; fsync issues manifest there first.
echo srvr | nc localhost 2181 | grep Mode

# Functional state. "ro" means quorum is lost, not just slow.
echo isro | nc localhost 2181

# Compare read vs write latency (3.6+). If reads are flat and writes spike, the write path is isolated.
echo mntr | nc localhost 2181 | grep -E 'zk_(avg|p99)_(update|read)latency'

# fsync p99. The single most important write-path metric.
echo mntr | nc localhost 2181 | grep -E 'zk_(avg|p99)_fsynctime'

# Quorum ACK latency (leader-only metric).
echo mntr | nc localhost 2181 | grep -E 'zk_.*quorum_ack_latency'

# JVM pause time percentiles.
echo mntr | nc localhost 2181 | grep -E 'zk_.*jvm_pause'

# Pipeline saturation.
echo mntr | nc localhost 2181 | grep -E 'zk_(outstanding_requests|throttled_ops|pending_syncs)'

# fsync warnings from the ZK log (logged above fsync.warningthresholdms, default 1000ms).
grep "fsync-ing the write ahead log" /var/log/zookeeper/zookeeper.log | tail -20

# OS-level disk I/O on the txnlog device. Look for await, svctm, %util near 100.
iostat -x 1 5

# GC pause frequency and duration. Use the JDK of the ZK process if multiple JDKs are installed.
jstat -gcutil $(pgrep -f QuorumPeerMain) 1000 5

Note: since ZooKeeper 3.5.3, four-letter commands must be whitelisted via 4lw.commands.whitelist. If mntr returns empty, that is the cause. srvr is always available; mntr and isro must be explicitly allowed.

How to diagnose it

  1. Identify the leader. All writes route through the leader, so write-path problems manifest there first. Collect primary signals from the leader. echo srvr | nc <host> 2181 | grep Mode returns leader, follower, observer, or standalone.

  2. Read zk_p99_updatelatency, not zk_avg_latency. Compare against zk_p99_readlatency. If reads are flat and writes are spiking, you have isolated the write path. If both are spiking, suspect GC or data-tree issues affecting the whole pipeline.

  3. Correlate zk_p99_updatelatency with zk_p99_fsynctime. They should track together if disk is the cause. If zk_p99_updatelatency is high but zk_p99_fsynctime is normal, the bottleneck is quorum ACK, network, or processing.

  4. On the leader, check zk_p99_quorum_ack_latency. If elevated, followers are slow to ACK proposals. Drill into each follower individually: zk_p99_fsynctime and zk_p99_jvm_pause_time_ms.

  5. Check zk_outstanding_requests. Should be 0 in steady state. A growing queue on the leader with normal fsync indicates a quorum or follower problem, not a disk problem.

  6. Grep the ZK log for fsync warnings. The line format is fsync-ing the write ahead log in SyncThread:X took Yms which will adversely effect operation latency. These appear when fsync exceeds fsync.warningthresholdms (default 1000ms). Seeing them at all means the write path is in trouble.

  7. Check zk_throttled_ops. If incrementing, the pipeline has hit globalOutstandingLimit (default 1000). The server has stopped reading from client sockets and clients are timing out.

  8. Check zk_proposal_count vs zk_commit_count rate. Proposals advancing while commits are stalled means followers cannot ACK fast enough, or quorum is degraded.

Metrics and signals to monitor

SignalWhy it mattersWarning sign
zk_p99_updatelatencyTrue write-path latency, isolates writes from reads>3x rolling p99 baseline; sustained >100ms
zk_p99_readlatencyRead latency, should be sub-millisecondSustained >50ms indicates GC or data-tree issue
zk_p99_fsynctimeTime to fsync the txn log, the critical I/O pathSustained >10ms; >2ms on dedicated SSD is wrong
zk_p99_quorum_ack_latencyLeader-to-follower ACK latencySustained >50ms; should be <5ms p99 on a healthy LAN
zk_p99_jvm_pause_time_msStop-the-world pause time, affects every pathp99 approaching 1333ms (1/3 of minSessionTimeout)
zk_outstanding_requestsPipeline backlog, leading indicatorSustained non-zero
zk_throttled_opsPipeline at globalOutstandingLimitAny non-zero rate
zk_proposal_count / zk_commit_countProposal vs commit throughputProposals advancing, commits stalled
zk_looking_countElection eventsAny increment outside maintenance

Fixes

Fsync stalls (disk I/O)

The most common and most impactful cause. Confirm with zk_p99_fsynctime and iostat -x.

  • Verify dataLogDir is set to a dedicated device, not defaulting to dataDir. Snapshot I/O competing with txnlog fsync is a documented misconfiguration that produces intermittent write spikes.
  • Verify cloud storage IOPS. AWS gp2/gp3 burst credit exhaustion produces sudden latency cliffs when credits run out. Provisioned IOPS should match sustained write rate, not burst.
  • Verify no colocated workload is hammering the same disk: backups, monitoring agents, log shippers, adjacent databases.
  • On dedicated SSD, p99 fsync should be <2ms. Anything above that is contention or hardware degradation.
  • Filesystem tuning: data=writeback for the txnlog partition is acceptable because ZK calls fsync explicitly and has its own crash recovery via log plus snapshot replay. This is a partition-level change; benchmark before and after on representative load.

Quorum ACK latency

Elevated zk_p99_quorum_ack_latency on the leader means followers are slow to ACK. Drill into each follower:

  • zk_p99_fsynctime per follower. Followers also fsync before ACKing.
  • zk_p99_jvm_pause_time_ms per follower. A follower in a long GC pause stalls quorum.
  • Network RTT between the leader and each follower.
  • zk_pending_syncs on the leader. Should be 0.

syncLimit x tickTime (default 5 x 2000ms = 10 seconds) is the wall. If quorum ACK latency approaches that, the follower will be ejected and quorum is at risk.

GC pauses

zk_p99_jvm_pause_time_ms is the signal. GC pauses are rhythmic and elevate both read and write latency simultaneously, which distinguishes them from disk-only stalls.

  • Enable GC logging if it is not already on: -Xlog:gc*:file=/var/log/zookeeper/gc.log:time,uptime,level,tags:filecount=5,filesize=100m.
  • Disable Transparent Huge Pages. THP can make GC pauses 2 to 10 times worse. This is a system-wide change requiring root: echo never > /sys/kernel/mm/transparent_hugepage/enabled. Persist via systemd tuned profile or rc.local, and reboot-validate.
  • Use G1GC (default on JDK 9+) or ZGC on JDK 15+ for sub-millisecond pauses.
  • Size heap to the data tree. Track zk_znode_count and zk_approximate_data_size and project runway.

Pipeline saturation

zk_outstanding_requests growing and zk_throttled_ops incrementing means writes are arriving faster than they can be processed.

  • Identify the burst source: reconnection storm, watch storm, client bug, downstream service scale event.
  • globalOutstandingLimit (default 1000) can be raised for headroom, but the root cause is throughput exceeding capacity, not the limit being too low.
  • For write-heavy consumers (Kafka with ZK, HBase), consider splitting the workload across separate ensembles. Modern Kafka (3.3+) uses KRaft mode and no longer requires ZooKeeper.

Prevention

  • Monitor zk_p99_updatelatency and zk_p99_fsynctime as primary write-path signals. Do not alert on zk_avg_latency alone.
  • Dedicated device for dataLogDir. This is the single most impactful configuration change for write-path stability.
  • Verify autopurge is configured. The default in some distributions is autopurge.purgeInterval = 0 (disabled), which leads to slow disk exhaustion. Configure autopurge.purgeInterval and autopurge.snapRetainCount.
  • Alert on >3x rolling p99 baseline for zk_p99_updatelatency, not on absolute thresholds alone. Workload baselines vary widely.
  • Alert on any increment of zk_looking_count outside maintenance windows.
  • Capacity-test failover regularly. Controlled chaos testing validates both the system and the monitoring.

How Netdata helps

Netdata’s per-second collection captures write-path dynamics that one-minute scrapers miss: the difference between seeing the fsync stall and seeing only its downstream latency.

  • zk_p99_updatelatency and zk_p99_fsynctime collected per-second let you see an fsync stall as it forms, before the proposal pipeline backs up.
  • ML anomaly detection flags latency baseline deviations without forcing you to hand-tune absolute thresholds for workloads with very different baselines.
  • Correlating zk_updatelatency with zk_fsynctime, zk_quorum_ack_latency, and zk_jvm_pause_time_ms in one view localizes the cause to disk, network, or GC in seconds.
  • Per-node dashboards make leader-vs-follower comparison immediate, which aggregate or sampled views hide.
  • zk_outstanding_requests, zk_throttled_ops, and zk_pending_syncs surface pipeline saturation before clients time out.
  • The same per-second stream lets you watch the post-fix recovery, confirming that the change actually moved the metric.