$ guides / apache-pulsar / apache-pulsar-add-entry-in-progress-growing ▌

Operations Guides

Apache Pulsar bookie add-entry queue not draining: writes arriving faster than the disk can commit

When bookkeeper_server_ADD_ENTRY_IN_PROGRESS grows and does not drain to near-zero within seconds of a traffic burst, the bookie write path is saturated. Writes are arriving faster than the journal disk can fsync them, or the write thread is blocked by GC. Left unaddressed, this causes broker-side timeouts, producer failures, and throughput collapse.

This metric is a gauge, not a counter. Absolute value matters less than trend. Spikes during traffic bursts are normal; sustained positive growth is not. The queue fills and stays filled because the bookie cannot commit entries as fast as they arrive. By the time broker publish latency spikes, the bookie has already been saturated for seconds or minutes.

What this means

Every persistent message write in Pulsar passes through a bookie journal. The broker sends the write to a quorum of bookies. Each bookie appends the entry to its journal, calls fsync (either per entry or per batch via group commit), and acknowledges back to the broker. The broker acknowledges to the producer only after the ack quorum (Qa) is met. The journal fsync is the physical limit of write throughput.

When the journal disk cannot fsync fast enough, the internal pipeline backs up. Pending fsync operations accumulate in the force write queue (bookie_journal_JOURNAL_FORCE_WRITE_QUEUE_SIZE). Add-entry operations queue up waiting for journal acknowledgment (bookkeeper_server_ADD_ENTRY_IN_PROGRESS). Brokers wait for bookie acks, holding connections and buffers open. Throughput collapses as the system waits for the disk.

The force write queue is the earliest warning signal: it rises before journal sync latency spikes and before the add-entry in-progress count grows. If you are only watching ADD_ENTRY_IN_PROGRESS, you are already late.

flowchart TD
    A[Writes arrive at bookie] --> B[Add entries queued for journal]
    B --> C{Journal fsync keeping up?}
    C -- No --> D[JOURNAL_FORCE_WRITE_QUEUE_SIZE grows]
    D --> E[ADD_ENTRY_IN_PROGRESS stops draining]
    E --> F[Broker waits for Qa acks]
    F --> G[Publish latency rises]
    G --> H[Producers timeout, rate_in drops]
    E --> I[ADD_ENTRY_BLOCKED fires if maxAddsInProgressLimit is set]
    C -- Yes --> J[Queue drains normally]

Common causes

Cause	What it looks like	First thing to check
Journal disk I/O saturation	`JOURNAL_SYNC` P99 climbing, `iostat` `%util` near 100 on journal device	`iostat -x 1` on the journal disk
Bookie JVM GC blocking write thread	Queue growth correlates with GC pause events, sync latency normal between pauses	Bookie GC logs or `jstat -gcutil <pid> 1000`
DbLedgerStorage write cache exhaustion	`bookie_throttled_write_requests` increasing, `bookie_write_cache_size` at max	Write cache and throttled write metrics
Noisy neighbor on shared storage	Intermittent `JOURNAL_SYNC` spikes with no sustained high `%util`	Other processes on the journal mount, cloud disk throttling
Journal file misconfiguration	Frequent journal rotation, I/O spikes on file creation	`journalFileSize` in bookkeeper.conf

Quick checks

Run these read-only commands to confirm the state and narrow the cause. All are safe for production.

# Check add-entry queue depth and trend
curl -s http://<bookie-host>:8000/metrics | grep bookkeeper_server_ADD_ENTRY_IN_PROGRESS

# Check if writes are being actively blocked
curl -s http://<bookie-host>:8000/metrics | grep bookkeeper_server_ADD_ENTRY_BLOCKED

# Check journal fsync latency percentiles
curl -s http://<bookie-host>:8000/metrics | grep bookie_journal_JOURNAL_SYNC

# Check force write queue depth (earliest warning signal)
curl -s http://<bookie-host>:8000/metrics | grep JOURNAL_FORCE_WRITE_QUEUE_SIZE

# Check journal queue depth
curl -s http://<bookie-host>:8000/metrics | grep bookie_journal_JOURNAL_QUEUE_SIZE

# Check write cache pressure
curl -s http://<bookie-host>:8000/metrics | grep -E "bookie_write_cache|bookie_throttled_write|bookie_rejected_write"

# Check bookie server status (1=writable, 0=read-only)
curl -s http://<bookie-host>:8000/metrics | grep bookie_SERVER_STATUS

# Check journal disk I/O at the OS level
iostat -x 1 <journal-device>

# Check disk usage (bookie goes read-only at diskUsageThreshold, default 0.95)
df -h <journal-mount> <ledger-mount>

# Check bookie JVM GC. If multiple JVMs match, specify the PID manually.
jstat -gcutil $(pgrep -f BookieServer) 1000

A note on ADD_ENTRY_BLOCKED: if you see zero even during severe saturation, check whether maxAddsInProgressLimit is configured. Without it, the bookie has no hard back-pressure at the Netty layer and this gauge will never fire. The default is unbounded (0) in current BookKeeper versions. Upgrading to Pulsar 3.0.x (bundled BookKeeper 4.16) also lost or renamed several other bookie metrics (apache/pulsar#21766), so verify each metric appears in your /metrics output before relying on it.

How to diagnose it

Confirm the queue is truly stuck, not a transient burst. Scrape ADD_ENTRY_IN_PROGRESS at 5-second intervals for at least 30 seconds after a traffic burst. If the value does not return to near-zero, the write path is saturated.
Check JOURNAL_FORCE_WRITE_QUEUE_SIZE first. This is the earliest warning signal. If it is sustained above zero for more than 10 seconds, the journal disk cannot commit fsync operations as fast as they arrive. This confirms a journal disk bottleneck.
Check bookie_journal_JOURNAL_SYNC latency. Compare the P99 against your storage device type. SSDs should see P99 below 5ms; HDDs below 20ms. Sustained 2x degradation from baseline indicates disk saturation. Use the journalIndex label to isolate individual journal directories if multiple are configured. All journal metrics are aggregates across directories; one slow journal instance on a problematic volume may only show in histogram percentiles, not in the aggregate gauge.
Run iostat -x 1 on the journal device. Look at %util and w_await. If %util is near 100, the disk is saturated. If w_await is high while %util is moderate, suspect cloud storage latency variability or a noisy neighbor.
Check for non-Pulsar processes on the journal mount. Any other I/O on the journal disk is the most common architectural mistake. Run lsof | grep <journal-mount> or iotop -o to identify competing processes.
Check bookie JVM GC pauses. If queue growth correlates with GC pause events rather than disk latency, the write thread is being stopped by the garbage collector, not the disk. Look for full GC pauses exceeding 1 second. The shipped Pulsar scripts have used ZGC as the default since Pulsar 2.11 (2.10 and earlier shipped G1GC). ZGC has much shorter pause times than G1.
Check DbLedgerStorage write cache pressure. If bookie_throttled_write_requests is increasing, the write cache is full and writes are waiting. If bookie_rejected_write_requests is increasing, the write thread has timed out waiting for cache space (default dbStorage_maxThrottleTimeMs is 10 seconds). This is a different bottleneck from journal disk saturation and requires a different fix.
Determine scope: single bookie or cluster-wide. If only one bookie is affected, suspect hardware (degraded disk, failed controller) or a noisy neighbor. If multiple bookies show the same pattern, suspect a traffic spike that has outgrown disk capacity or a shared infrastructure problem.

Metrics and signals to monitor

Signal	Why it matters	Warning sign
`bookkeeper_server_ADD_ENTRY_IN_PROGRESS`	Write queue depth, the pressure gauge	Sustained growth, not draining within 30s of a burst
`bookie_journal_JOURNAL_FORCE_WRITE_QUEUE_SIZE`	Earliest indicator of journal saturation	Sustained above zero for more than 10s
`bookie_journal_JOURNAL_SYNC` (P99)	Physical limit of write throughput	SSD: P99 above 5ms. HDD: P99 above 20ms. 2x baseline degradation
`bookkeeper_server_ADD_ENTRY_BLOCKED`	Bookie actively refusing writes	Any non-zero value (requires `maxAddsInProgressLimit` to be set)
`bookie_throttled_write_requests`	DbLedgerStorage write cache under pressure	Counter increasing
`bookie_rejected_write_requests`	Write cache fully saturated, writes timing out	Any non-zero value
`bookie_SERVER_STATUS`	Bookie accepting writes at all	Value 0 (read-only), -1 (unregistered)
`pulsar_broker_publish_latency` (P99)	End-to-end write latency as seen by broker	2x baseline elevation, correlates with bookie queue growth

Fixes

Journal disk I/O saturation

The journal disk is the critical path. If %util is near 100 and w_await is elevated, the disk cannot keep up with the fsync workload.

Immediate mitigation: Reduce producer rate to let the queue drain. If using Pulsar rate limiting, lower the namespace or topic-level publish rate. If the saturation is transient (traffic burst), this may be sufficient.

Short-term: Identify and remove any non-Pulsar processes writing to the journal mount. If the journal disk is shared with entry logs or any other workload, separate them. Journal and entry log on separate physical disks is a hard requirement for production.

Medium-term: If a single bookie has a degraded disk, decommission it gracefully to trigger ledger recovery to other bookies:

# Destructive: triggers recovery I/O on surviving bookies
bin/bookkeeper shell decommissionbookie -bookieid <bookie-address:port>

This is disruptive. Recovery I/O competes with foreground traffic on surviving bookies and can trigger a cascade if the cluster is already under pressure. Consider pausing auto-recovery (lostBookieRecoveryDelay) if other bookies are also showing saturation signs.

Long-term: Add bookies to distribute write load. Ensure each bookie has a dedicated NVMe or SSD journal device. Verify that the journal disk bandwidth exceeds peak write throughput with at least 50% headroom.

Bookie JVM GC blocking the write thread

If GC pause events correlate with queue growth and journal sync latency is normal between pauses, the write thread is being stopped by the garbage collector.

Immediate: Check bookie GC logs for full GC frequency and duration. Any full GC pause exceeding 1 second is critical; the write thread cannot progress during stop-the-world pauses.

Configuration: Verify the GC algorithm. ZGC has been the default in the shipped Pulsar scripts since Pulsar 2.11. If still using G1, switching to ZGC reduces pause-induced write stalls significantly. ZGC is production-ready since JDK 15 (JEP 377); Pulsar 2.11+ ships on JDK 17. Adjust heap size if old generation occupancy is consistently high after GC.

Tradeoff: A larger heap reduces GC frequency but increases pause duration when full GC does occur. A smaller heap triggers more frequent but shorter collections. The right balance depends on your latency SLA.

DbLedgerStorage write cache exhaustion

If bookie_throttled_write_requests or bookie_rejected_write_requests are increasing, the bottleneck is the write cache, not the journal disk. The write cache (default 25% of max direct memory, configurable via dbStorage_writeCacheMaxSizeMb) holds entries before they are flushed to entry logs. When it fills, writes block waiting for space.

Check bookie_write_cache_size: If it stays at max, the cache is undersized for the write workload.

Configuration: Increase dbStorage_writeCacheMaxSizeMb in bookkeeper.conf if direct memory has headroom. Alternatively, reduce flushInterval to flush entries to entry logs more frequently, freeing cache space faster.

Tradeoff: A larger write cache consumes direct memory that Netty and read operations also need. A shorter flush interval increases entry log I/O. Monitor bookie_write_cache_size after changes to confirm improvement.

Cloud storage latency variability

Cloud-managed disks can exhibit highly variable fsync latency. A disk that performs well under benchmark load may spike unpredictably under production write patterns.

Diagnosis: If JOURNAL_SYNC P99 is elevated but %util is moderate and no competing processes exist, suspect cloud disk variability. Compare the P99 against P99.9: if the gap is large, you are hitting intermittent throttling rather than sustained saturation.

Mitigation: Use provisioned IOPS volumes for journal disks. Avoid lower-tier general-purpose volumes for journals in production. Ensure the journal volume is not co-located with other volumes on the same instance.

Prevention

Dedicate journal disks. The journal disk must not serve any other workload. This is the single most important architectural decision for bookie write performance.
Monitor JOURNAL_FORCE_WRITE_QUEUE_SIZE proactively. Alert on sustained non-zero values. It is the earliest warning signal for write-path saturation.
Set maxAddsInProgressLimit explicitly. Without this setting, the bookie has no hard back-pressure at the Netty layer. ADD_ENTRY_BLOCKED will never fire, and the bookie will accept unlimited writes until it exhausts memory or threads.
Watch the P99/P50 ratio on journal sync latency. A high ratio means intermittent stalls. This is a leading indicator of disk degradation before average latency rises.
Remember that gauges are samples. Journal queues can fill and empty faster than a 15-second scrape interval. A lack of queue growth on a coarse scrape does not rule out journal saturation. Use failed request rates and write thread utilization as complementary signals.
Track journal disk bandwidth utilization. Peak utilization should stay below 50% of rated disk bandwidth to handle bursts. The degradation curve is cliff-edge: performance drops to near-zero throughput as the device queue depth explodes.

How Netdata helps

Per-second granularity on bookkeeper_server_ADD_ENTRY_IN_PROGRESS, JOURNAL_FORCE_WRITE_QUEUE_SIZE, and JOURNAL_SYNC reveals queue growth and drain patterns that 15-second Prometheus scrapes can miss entirely.
ML anomaly detection on journal sync latency flags intermittent stall patterns (high P99/P50 ratio) before they trigger sustained queue growth.
Correlation across the write path shows ADD_ENTRY_IN_PROGRESS growth alongside pulsar_broker_publish_latency degradation and pulsar_rate_in decline in a single view, confirming the cascade without switching dashboards.
Per-bookie breakdown isolates a single slow bookie from cluster-wide saturation, which is the most important diagnostic distinction for this failure pattern.
OS-level disk metrics alongside bookie metrics confirm whether the bottleneck is the disk hardware or the bookie JVM without SSH access to the host.