ZooKeeper slow startup: snapshot load and txnlog replay taking minutes

A ZooKeeper node you just restarted is not answering client requests. The process is up, the port is listening, but mntr hangs or returns nothing useful, and dependent services are logging connection failures and session timeouts. Your dashboard shows zk_uptime climbing past one, two, five minutes with no leader participation, or your health checks have already paged because the node looks dead.

This is the snapshot/recovery stall. On startup, ZooKeeper does not serve traffic until it has reconstructed its in-memory data tree. It deserializes the latest fuzzy snapshot from dataDir, then replays every transaction recorded in the transaction log since that snapshot’s zxid. For a small tree with a tidy log directory, this is sub-second. For a large tree, or a tree paired with months of un-purged transaction logs, it can take minutes. During that window the node is effectively offline even though the JVM is running.

The playbook is explicit about this pattern: “On restart, loading snapshot + replaying txnlog can take minutes, during which the node appears dead,” and “Recovery time scales with snapshot size plus log volume; a bounded tree and working autopurge keep it fast.” This article covers how to tell a genuine recovery stall from a hung process, how to estimate how long recovery will take, and how to shrink the window.

What this means

ZooKeeper is a replicated state machine that keeps its entire data tree in JVM heap. Durability comes from two on-disk artifacts: a write-ahead transaction log (dataLogDir/version-2/log.<zxid>, fsync’d on every write) and periodic fuzzy snapshots (dataDir/version-2/snapshot.<zxid>). Snapshots are taken without pausing the request pipeline, so they are only consistent when combined with the transaction log entries that follow them.

Recovery is a strict two-phase sequence:

1. Snapshot deserialization. Read the most recent snapshot file and rebuild the in-memory DataTree. Cost scales with snapshot file size, which tracks zk_znode_count and zk_approximate_data_size. This phase is CPU- and allocation-bound.
2. Transaction log replay. Open every log.<zxid> file newer than the snapshot’s zxid and apply each transaction in order. Cost scales with the number of transactions accumulated since the last snapshot. This phase is CPU- and I/O-bound.

Only after both phases complete does the node enter leader election (or rejoin as a follower) and start serving clients. Until then, shallow liveness checks can be misleading. The playbook calls out that a node can return imok to ruok while it is still loading, and that isro and mntr are the checks that actually reflect serving state.

flowchart TD
  A[Process start] --> B[Deserialize latest snapshot]
  B --> C{Snapshot valid?}
  C -- no --> X[Fail to start
check zk_snapshot_error_count (3.9+)]
  C -- yes --> D[Replay log.zxid files
newer than snapshot]
  D --> E[Enter LOOKING
leader election]
  E --> F[LEADING or FOLLOWING
serve clients]
  B -. "scales with snapshot size" .-> T1[recovery wall-clock]
  D -. "scales with txnlog volume" .-> T1

The diagnostic insight: the two phases have different root causes. A long phase one means your data tree is too big. A long phase two means autopurge is off or broken and transaction logs have accumulated. The fix for each is different.

ZooKeeper 3.6+ exposes these phases as Summary metrics: the startup cost as a whole (dbinittime), snapshot load (startup_snap_load_time), transaction replay (startup_txns_load_time, plus startup_txns_loaded for the count) — all visible via mntr (zk_dbinittime, zk_startup_snap_load_time, zk_startup_txns_load_time, zk_startup_txns_loaded) and the Prometheus endpoint.

Common causes

Quick checks

Run these read-only. They tell you whether the node is still recovering, how big the tree is, and whether logs have accumulated.

# Is the process up and how long has it had to recover?
echo mntr | nc localhost 2181 | grep zk_uptime

# Shallow liveness vs. functional state. ruok may lie during recovery.
echo ruok | nc localhost 2181
echo isro | nc localhost 2181

# Current role. Empty or looking means recovery + election not finished.
echo mntr | nc localhost 2181 | grep zk_server_state

# How big is the tree this node has to rebuild?
echo mntr | nc localhost 2181 | grep -E 'zk_(znode_count|approximate_data_size)'

# Snapshot and log footprint on disk.
ls -lhS /var/zookeeper/data/version-2/snapshot.* 2>/dev/null | head -5
ls -1 /var/zookeeper/txnlog/version-2/log.* 2>/dev/null | wc -l
du -sh /var/zookeeper/txnlog/version-2/ 2>/dev/null

# Is autopurge configured at all?
grep -E 'autopurge\.(purgeInterval|snapRetainCount)' /path/to/zoo.cfg

Adjust /var/zookeeper/... and /path/to/zoo.cfg to your install. If four-letter commands return empty, 4lw.commands.whitelist in zoo.cfg (ZooKeeper 3.5.3+) is restricting them; whitelist at least mntr, ruok, isro, srvr.

How to diagnose it

1. Confirm it is recovery, not a hang. If zk_uptime is incrementing and the process is consuming CPU (snapshot deserialization and log replay are CPU-bound), it is recovering. If CPU is pinned at zero and the JVM is unresponsive, suspect a GC pause or deadlock instead.
2. Watch zk_server_state. It will be empty or absent until recovery completes and the node enters election. Once it reports leader or follower, recovery is over.
3. Estimate remaining time from the log. ZooKeeper logs snapshot load and txnlog replay progress. Tail the server log and look for the snapshot load line and the replay sequence. The gap between process start and the election messages is your recovery window.
4. Size the snapshot. The largest recent snapshot file is a direct proxy for phase-one cost. If it is over roughly 1 GB, expect measurable load time; if it is multiple GB, expect minutes. There is no published seconds-per-GB rule; measure your own local load time to build one.
5. Count and size the transaction logs. Phase-two cost is proportional to the transaction volume in log.* files newer than the snapshot. If you see tens or hundreds of log files, autopurge is the problem.
6. Check disk latency during replay. Replay reads are sequential, but a saturated or shared disk still slows it. Run iostat -x 1 on the data volume and confirm await and %util are sane.
7. Rule out corruption. If recovery never completes or the node crashes mid-load, check zk_snapshot_error_count (3.9+) and grep the log for snapshot read errors. A corrupt latest snapshot can prevent startup entirely.

Metrics and signals to monitor

Fixes

The tree is too large

If snapshot files are large and zk_znode_count / zk_approximate_data_size are high, the data tree is the dominant cost. Recovery time will not improve until the tree shrinks.

• Identify the bloated subtree. The playbook notes that frameworks creating per-task or per-session znodes without cleanup are the usual cause. Use the dump command to inspect ephemeral nodes, and audit which application owns the growing path.
• Delete unnecessary persistent znodes. Caution: deletes fire watches and can trigger notification storms on heavily-watched paths. Do this in a controlled window.
• Stop using ZooKeeper as a database. Znodes are meant for coordination metadata. See the related guide on data size growth.
• Increasing heap will let the running cluster survive a bigger tree, but it will not make recovery faster and it makes full GC pauses longer.

Autopurge is off or broken

If dataLogDir is full of old log.* files, replay volume is the dominant cost. The playbook is explicit: autopurge.purgeInterval defaults to 0, which disables purge entirely.

• Set autopurge.purgeInterval to a positive number of hours (for example 1) and autopurge.snapRetainCount to at least 3 (the minimum). This needs a restart to take effect for the first clean, but it prevents the next restart from being worse.
• Do not purge files manually while ZooKeeper is running if you can avoid it. If you must reduce disk pressure immediately, only remove log.* and snapshot.* files older than the most recent snapshot plus its preceding log. Removing the wrong files corrupts recovery.
• Verify the purge is actually running after restart by watching the file count drop over the configured interval.

snapCount is mis-tuned

snapCount defaults to 100,000 transactions. Setting it far below default floods the disk with tiny snapshots and raises total I/O. Very large values (millions) are known to produce multi-GB transaction logs and 20+ second post-election syncs (ZOOKEEPER-3757, still open). Leave it at default unless you have measured a reason to change it.

The snapshot is corrupt

If zk_snapshot_error_count (3.9+) is incrementing or the node will not start, the latest snapshot may be damaged. Removing the most recent snapshot.* file is destructive: it forces ZooKeeper to fall back to the prior snapshot plus its logs and can lose the transactions between the two snapshots. Treat it as a last resort, do it on one node at a time, and let the rest of the ensemble bring it current via sync.

Prevention

• Gate startup alerts on zk_uptime. The playbook recommends suppressing non-critical alerts for the first 5-10 minutes after a planned restart. Page only on quorum loss or leader absence that persists past the cold-start window.
• Keep autopurge on. autopurge.purgeInterval=1 with autopurge.snapRetainCount=3 is a safe baseline. Verify the file count stays stable over time.
• Bound the tree. Trend zk_znode_count and zk_approximate_data_size and alert on growth. A tree that stops growing keeps recovery fast indefinitely.
• Separate dataLogDir from dataDir. This is the playbook’s number-one fsync recommendation, and it also keeps snapshot read I/O during recovery from competing with txnlog reads.
• Measure actual restart time. Track the gap between process start and the first leader/follower report. That number is your real recovery SLA; on 3.6+ zk_dbinittime / zk_startup_snap_load_time / zk_startup_txns_load_time from mntr or the Prometheus endpoint measure the phases directly.
• Plan rolling restarts. Restart one node at a time and wait for it to rejoin and sync before moving on, so the ensemble never loses quorum to a cluster-wide cold start.

How Netdata helps

• Per-second zk_uptime and zk_server_state let you see exactly when recovery ends and election completes, and build alert rules that stay silent during the cold-start window.
• zk_znode_count and zk_approximate_data_size trends surface the slow tree growth that turns a 10-second restart into a 5-minute one, months before it bites.
• Disk metrics on dataDir and dataLogDir (usage, await, %util) show whether replay is I/O-bound and whether autopurge is keeping the volume flat.
• Correlation across the ensemble lets you compare a restarting node against its peers, so you can tell a genuine recovery stall from a real outage in seconds.
• Anomaly detection on restart duration and log file count flags the moment recovery starts drifting from baseline, before it crosses a hard threshold.

Related guides

• ZooKeeper data size growing: using ZooKeeper as a database is an anti-pattern
• ZooKeeper avg_latency hides write stalls: why the headline number lies
• ZooKeeper “Cannot open channel to N at election address”: the blocked election port
• ZooKeeper “Client session timed out, have not heard from server”: the heartbeat miss
• ZooKeeper connection drops spiking: sessions dying in bursts
• ZooKeeper dataLogDir sharing a disk with snapshots: the #1 fsync-latency footgun
• ZooKeeper “Detected pause in JVM or host machine (eg GC)”: the pause-monitor warning
• ZooKeeper follower doing a SNAP sync: full snapshot transfer and its blast radius
• ZooKeeper follower sync time climbing: a follower approaching ejection
• ZooKeeper “fsync-ing the write ahead log took too long”: the disk warning behind most write stalls
• ZooKeeper GC pause cascade: how a Stop-the-World freeze expires sessions and re-elects the leader
• ZooKeeper OutOfMemoryError: Java heap space - the OOM that kills the whole ensemble at once