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. Some Pulsar 3.0.x versions also lost this metric entirely after upgrade , so verify it 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_PROGRESSat 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_SIZEfirst. 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_SYNClatency. 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 thejournalIndexlabel 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 1on the journal device. Look at%utilandw_await. If%utilis near 100, the disk is saturated. Ifw_awaitis high while%utilis 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>oriotop -oto 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. ZGC has much shorter pause times than G1.
Check DbLedgerStorage write cache pressure. If
bookie_throttled_write_requestsis increasing, the write cache is full and writes are waiting. Ifbookie_rejected_write_requestsis increasing, the write thread has timed out waiting for cache space. 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) |
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. If still using G1, switching to ZGC reduces pause-induced write stalls significantly. 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 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_SIZEproactively. Alert on sustained non-zero values. It is the earliest warning signal for write-path saturation. - Set
maxAddsInProgressLimitexplicitly. Without this setting, the bookie has no hard back-pressure at the Netty layer.ADD_ENTRY_BLOCKEDwill 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, andJOURNAL_SYNCreveals 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_PROGRESSgrowth alongsidepulsar_broker_publish_latencydegradation andpulsar_rate_indecline 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.
Related guides
- Apache Pulsar active connections climbing: connection leaks and file descriptor exhaustion
- Apache Pulsar broker down: telling a dead broker from a fenced one
- Apache Pulsar broker GC death spiral: heap pressure, stop-the-world pauses, and lost topic ownership
- Apache Pulsar broker lookup failures: new clients cannot find their topic
- How Apache Pulsar actually works in production: a mental model for operators
- Apache Pulsar monitoring checklist: the signals every production cluster needs
- Apache Pulsar monitoring maturity model: from survival to expert
- Apache Pulsar OutOfDirectMemoryError: the off-heap crash JVM heap dashboards never show
- Apache Pulsar throttled connections: the broker shedding load under pressure






