Fluentd end-to-end pipeline latency: stale logs during an incident

Your dashboards show errors spiking at 02:00, but when you query the log store for the same window, the newest events are 40 minutes old. Fluentd is running, the process is healthy, no alerts fired. The pipeline is alive but the data is stale, and you are debugging an incident on a delay you did not know existed.

Fluentd end-to-end pipeline latency is the time from event generation to arrival at the destination. Fluentd does not expose this as a native metric. There is no pipeline_latency_seconds field in the monitor_agent API. You have to derive it: compare event timestamps to arrival time at the destination, or inject synthetic events with known timestamps and measure round-trip time.

This matters most during incidents, which is exactly when latency silently degrades. Retry backoff, buffer queuing, and destination-side indexing lag can each push delivery delay from seconds to minutes or hours without tripping the usual alarms. The process-alive check passes. Retry counters may be zero. The buffer may not be full. And your freshest log line is old enough to be useless.

What this means

End-to-end latency is the sum of four components:

1. Flush wait: an event sits in a staged chunk until the flush trigger fires. With the default flush_interval of 60s, the latency floor is about a minute before anything else goes wrong.
2. Buffer queue wait: once a chunk is queued, it waits for a flush thread. If the output is slow, queued chunks stack up and wait longer.
3. Network transfer: the flush itself, including TLS handshakes and destination response time.
4. Destination indexing: the destination’s own ingestion delay, which Fluentd cannot see at all.

The dangerous multiplier is the retry engine. When a flush fails, exponential backoff schedules the next attempt further and further out. During a long retry cycle, latency can grow to hours without triggering any other alarm if the buffer has not overflowed. retry_count tells you errors happened; it does not tell you that retry.next_time is 30 minutes in the future and the pipeline is effectively stalled.

flowchart LR
  A[Event generated] --> B[Staged chunk: flush wait]
  B --> C[Queued chunk: queue wait]
  C --> D[Flush: network transfer]
  D --> E[Destination indexing]
  D -. flush fails .-> F[Retry backoff]
  F -. next attempt .-> D
  E --> G[Queryable in log store]

Common causes

One cause deserves emphasis: time-sliced outputs legitimately hold chunks until the slice expires. With time-based chunk keys, timekey_wait (default 600s) delays the flush of an expired time bucket on top of everything else. This is by design, but it sets a hard floor on freshness that no destination tuning will fix.

Quick checks

All of these are read-only. They assume monitor_agent is enabled on port 24220; in multi-worker mode, query each worker’s port (24220, 24221, …).

# 1. Oldest data age: how far behind is the oldest buffered chunk?
curl -s http://localhost:24220/api/plugins.json | \
  jq '.plugins[] | select(.plugin_category=="output") | {id: .plugin_id, oldest: .buffer_oldest_timekey, newest: .buffer_newest_timekey}'

# 2. Flush totals: compute average flush time from two samples
curl -s http://localhost:24220/api/plugins.json | \
  jq '.plugins[] | select(.plugin_category=="output") | {id: .plugin_id, flush_total: .flush_time_count, writes: .write_count}'

# 3. Slow flush count: how many flushes exceeded 20s?
curl -s http://localhost:24220/api/plugins.json | \
  jq '.plugins[] | select(.plugin_category=="output") | {id: .plugin_id, slow: .slow_flush_count}'

# 4. Retry state: when is the next attempt?
curl -s http://localhost:24220/api/plugins.json | \
  jq '.plugins[] | select(.plugin_category=="output") | {id: .plugin_id, retries: .retry_count, retry: .retry}'

# 5. Queue depth: is the backlog growing?
curl -s http://localhost:24220/api/plugins.json | \
  jq '.plugins[] | select(.plugin_category=="output") | {id: .plugin_id, queue_chunks: .buffer_queue_length, avail_pct: .buffer_available_buffer_space_ratios}'

# 6. Slow flush warnings in Fluentd's own log
grep -E "slow_flush_log_threshold|failed to flush" /var/log/td-agent/td-agent.log | tail -20

The slow-flush warning is logged as buffer flush took longer time than slow_flush_log_threshold: (Fluentd does not print the words “slow flush” in that line).

Notes on interpretation:

• buffer_oldest_timekey is only present when time-based chunking is configured. For tag-based chunking it may be absent.
• All counters (flush_time_count, write_count, slow_flush_count, retry_count) are cumulative and never reset during process lifetime. Compute deltas between samples, never alert on raw values.
• The retry object contains start, steps, and next_time. next_time far in the future is the smoking gun for backoff-induced staleness.
• flush_time_count is the cumulative sum of flush durations in milliseconds, so delta(flush_time_count) / delta(write_count) is average flush time in milliseconds; keep it below 50% of flush_interval.

How to diagnose it

1. Establish the actual latency. Pick recent events at the destination and compare their event timestamps to the time they became queryable. If your events carry a timestamp from the source application, this is direct. If you have no ground truth yet, inject a synthetic event and measure its round trip:

   # Inject a synthetic event with a known timestamp
   TIMESTAMP=$(date +%s)
   echo "{\"test\":\"latency_check\",\"ts\":$TIMESTAMP}" | fluent-cat debug.test
   # Then query the destination for debug.test and compare arrival time to $TIMESTAMP
   

   For periodic measurement, fluent-cat --event-time lets you control the event timestamp precisely, which avoids clock-skew noise between when the shell runs and when Fluentd stamps the event.

2. Decompose the latency into its components. Compare measured end-to-end latency against your configured flush_interval. If latency is roughly 1-2x flush_interval, the pipeline is healthy and the floor is configuration, not failure. If latency is many multiples of flush_interval, something downstream of staging is slow.

3. Check the retry object before the retry counter. A retry_count of 3 sounds minor. If retry.next_time is 20 minutes out, the pipeline is stalled for that chunk regardless of how small the count looks. See Fluentd failed to flush the buffer for the retry-side investigation.

4. Check average flush time. Compute delta(flush_time_count) / delta(write_count) over two samples a minute apart. Rising average flush time means the destination or network is the bottleneck. Cross-check slow_flush_count increments over the same window.

5. Check buffer data age. (current_time - buffer_oldest_timekey) should stay under roughly 2 * flush_interval for non-time-sliced outputs. For time-sliced outputs, the ceiling is timekey + timekey_wait. Anything beyond that is a real backlog.

6. Separate Fluentd latency from destination latency. If Fluentd’s metrics are all green (flush times low, queue empty, no retries) but data still appears late, the delay is on the destination side: indexing lag, bulk queue, or the destination’s own pipeline. Fluentd has no visibility into this; check the destination’s ingestion metrics directly.

7. Quantify which component dominates. Flush wait is bounded by config. Queue wait shows up as buffer_queue_length and oldest timekey. Transfer time shows up as average flush time. Indexing lag is everything left over. Fix the dominant component first.

Metrics and signals to monitor

Fixes

Destination is slow

Fix the destination first. Rising flush times are a symptom of Elasticsearch overload, S3 throttling, Kafka broker issues, or network congestion; no Fluentd tuning compensates for a destination that cannot accept writes at your input rate. If flush time regularly approaches flush_interval, you are at capacity: effective throughput is flush_thread_count / avg_flush_time chunks per second, and any further slowdown accumulates queue. Raising flush_thread_count helps when single-flush latency is high but the destination can absorb more parallel writes. It does not help if the destination is the constraint.

Retry backoff has stalled the pipeline

Fix the underlying destination issue, then restart Fluentd. Retry state resets on restart, which clears pathological retry.next_time values immediately. Warning: memory-backed buffers lose unflushed data on restart, and file-backed buffers replay their backlog, so expect a burst of flushes and brief duplicates after a restart. For future incidents, consider lowering retry_max_interval so backoff plateaus sooner, trading faster recovery against more load on a struggling destination. The full pattern is covered in Fluentd buffer queue length growing.

Baseline latency is configuration-bound

If healthy latency is near flush_interval and that is too slow for your use case, lower flush_interval. The tradeoff is more frequent, smaller flushes: higher per-request overhead on the destination and more chunks. Do not set flush_mode immediate on high-volume pipelines; it flushes after every event append, creates many tiny chunks, and degrades throughput. It is reasonable only for low-volume, latency-critical streams.

Time-sliced outputs are inherently stale

If you use time-based chunk keys (common for S3 and archival outputs), timekey and timekey_wait set a hard floor on freshness. Reduce timekey_wait toward 0 if you can tolerate chunks closing earlier, and shorten timekey if smaller slices are acceptable. Accept that archival outputs will never be near-real-time; route the events you need fresh (security, incident triage) to a separate, non-time-sliced output.

Prevention

• Alert on data age, not just pipeline health. buffer_oldest_timekey lag is the closest native proxy for staleness. Alert when it exceeds 2 * flush_interval.
• Run synthetic latency checks continuously. A cron job that injects a fluent-cat event and verifies arrival within your SLA catches silent degradation that no counter reveals, including destination-side indexing lag.
• Watch average flush time as a leading indicator. Keep it under 50% of flush_interval. Rising flush time appears before retries start, which is before queues grow, which is before anyone notices stale logs.
• Monitor the retry object, not just the counter. Sample retry.next_time and retry.steps so backoff-stalled chunks page someone before the data goes hours stale.
• Document your freshness floor. Given your flush_interval, chunk keys, and timekey_wait, compute the best-case latency and make sure the on-call runbook states it. Surprises about “normal” latency waste incident time.

How Netdata helps

• Data-age tracking: Netdata collects monitor_agent output per plugin, so buffer_oldest_timekey lag, queue length, and available buffer ratio are graphed together, making staleness visible as a trend instead of a discovery mid-incident.
• Flush-time derivation: because Netdata samples counters every second, delta(flush_time_count) / delta(write_count) becomes a usable per-minute average flush time chart, the earliest destination-degradation signal.
• Retry state correlation: retry counters alongside queue growth and flat write_count distinguish “retrying and recovering” from “retrying into a stalled pipeline”.
• Counter-rate handling: all Fluentd counters are cumulative and never reset; Netdata charts rates by default, so you do not have to compute deltas by hand.
• Cross-component correlation: buffer metrics next to host CPU, RSS, disk, and network metrics let you separate a Fluentd-internal stall from a host or network problem in one view.

Related guides

• Fluentd failed to flush the buffer: the output cannot deliver and retries begin
• Fluentd buffer queue length growing: the output cannot keep pace with the input
• Fluentd buffer available space low: computing time-to-overflow before it fires
• Fluentd BufferOverflowError: buffer space has too many data
• Fluentd drop_oldest_chunk_count incrementing: confirmed buffer data loss
• Fluentd emit_error_count: the number-one under-monitored data-loss signal
• Fluentd broken pipe / connection reset: dropped output connections and LB timeouts
• Fluentd input emit_records dropped to zero: ingestion has stopped
• Fluentd input emit_records stuck at zero: enable_input_metrics on older versions
• Fluentd config reload failed: SIGHUP that partially applies
• Fluentd CrashLoopBackOff: rapid restart cycling in Kubernetes
• How Fluentd actually works in production: a mental model for operators