IL-0041 PrometheusKube · 2020-11-11 (published)kubernetesobservability
PrometheusKube shipped application logs from its Kubernetes nodes to Elasticsearch with fluent-bit. On one node, fluent-bit stopped sending most records while staying silent: no error in its logs, and Prometheus metrics that only stopped growing. The team first chased an Elasticsearch write queue rejection and added CPU to Elasticsearch, which removed that error but not the problem. Rollbacks, upgrades and configuration changes did nothing. Debug logging showed the affected instance going quiet after its initial sync, and fluent-bit issue #2416 described the same behaviour without a fix.
Unable to fix fluent-bit in time, the team replaced it with Fluentd. They built a Fluentd deployment configuration and rolled it out one node at a time, starting with the affected node: node affinity placed Fluentd on a node and anti-affinity removed fluent-bit from it. Fluentd then failed with buffer overflow errors because, starting from scratch, it was pushing all of the old logs on that node at once, and Elasticsearch was barely keeping up. Raising flush_thread_count and tuning flush_interval, as Fluentd issue #2411 advises, did not help, and neither did a larger buffer. Slowing Fluentd down did: flush_thread_count 1 and a flush_interval of 5 seconds, plus the Position DB feature so already-ingested data is skipped. With that, Fluentd shipped logs without errors and was rolled out to every node.
The write-up adds that alerting on a shipper's throughput is hard: a rate threshold on fluentbit_output_proc_bytes_total needs different values for day and night, and a black-box check that writes a log line and looks for it in Elasticsearch is the other option.
On a Tuesday morning a developer reported that some production logs were missing. Only the logs from a single node were gone; the other nodes kept shipping normally through fluent-bit, the log shipper the team had run for more than three years.
fluent-bit's own logs showed Elasticsearch rejecting some bulk requests with "rejected execution of processing of [...][indices:data/write/bulk[s][p]]", reporting "EsThreadPoolExecutor[name = name-logs/write, queue capacity = 200, ... active threads = 2, queued tasks = 206 ...]". The write thread pool queue was full. The queue capacity could not be configured, so the team gave the Elasticsearch virtual machines more CPU. The error went away, but the logs from the node were still missing: it had been a red herring. Comparing one noisy pod on that node with what reached Elasticsearch confirmed most of its records were lost.
fluent-bit reported no error at all, and its Prometheus metrics showed nothing unusual: the metrics existed but simply stopped increasing (a separate bug, fluent-bit issue #1935). Rolling back minor versions, upgrading to the latest version and changing configuration parameters did not help. Only with debug logging turned on did the difference show: after the initial sync, the fluent-bit instance on the affected node stopped logging any actions while the instances on other nodes logged a lot, which pointed to a deadlock or a swallowed error.
The replacement brought its own symptom. A few hours after Fluentd started on the node, it failed with "[warn]: #0 emit transaction failed: error_class=Fluent::Plugin::Buffer::BufferOverflowError error="buffer space has too many data"" and stopped shipping entirely, while Elasticsearch again rejected some requests.
Symptom ? Monitoring outage
Root cause ? Software defect
A developer reported missing production logs; no alert fired because fluent-bit's metrics showed no errors.
A log shipper can fail without an error message and with metrics that simply stop moving, so error-based alerts never fire; throughput alerts or end-to-end checks can catch it. Open source software can break in ways nobody expects, and sometimes the way out is to switch to a different shipper fast, node by node. A new shipper that starts from scratch replays every old log on the node and needs to be slowed down.
same root cause · shared Telemetry agent
same root cause · shared Telemetry agent