filter_kubernetes: metadata fetch has no read timeout and can wedge the pipeline (in_tail flatlines) when the API/kubelet connection stalls
- Dominant language
- C
- Stars
- 8.1k
- Forks
- 2k
- Avg merge
- 4d 20h
- Merged PRs (30d)
- 71
Description
### Bug Report
**`filter_kubernetes` resolves pod metadata with a synchronous request (async explicitly disabled) that has no read timeout, on the pipeline/event-loop thread. When the API server / kubelet connection establishes and then stalls, `recv()` blocks that thread forever, so `in_tail` (same event loop) stops collecting — the tail input flatlines while the pod stays healthy.**
This reproduces on **v5.0.9** (also seen on 5.0.7). It is the same failure class as the closed #937, with a deterministic reproduction and a proposed fix below.
## Symptom
- `fluentbit_input_bytes_total{name="tail.0"}` (and `fluentbit_filter_records_total{name="kubernetes.*"}`) flatline to 0 and stay there.
- The pod stays `Running`/healthy; `fluentbit_input_ingestion_paused` stays **0** and storage is not overlimit — i.e. this is **not** the normal mem_buf/storage backpressure pause.
- Preceded by `[net] connection timeout after 10 seconds to: kubernetes.default.svc:443` + `[filter:kubernetes] kube api upstream connection error`; the fatal blocking read itself logs nothing.
- Only a restart recovers it. At fleet scale we see this on ~18–21 nodes/day (each a ≥15-min tail outage).
## Root cause (v5.0.9 source)
The pod-metadata fetch is synchronous, inline in the filter callback on the event-loop thread, with async disabled and no read timeout:
- `plugins/filter_kubernetes/kubernetes.c` — filter registered `.flags = 0` (synchronous; runs during chunk append on the collector thread).
- `plugins/filter_kubernetes/kube_meta.c` — `flb_stream_disable_async_mode(&ctx->kube_api_upstream->base)` (and the kubelet upstream): the upstream cannot yield to the event loop.
- `kube_meta.c` — `flb_http_do()` with `Connection: close` (a fresh blocking connect per lookup).
- `src/flb_network.c` — connect is bounded by `poll(net.connect_timeout)` (default 10s), **but** `src/flb_upstream.c` — `net.io_timeout` defaults to `0s`, so the TLS handshake / `recv()` has **no timeout**.
- `kube_meta.c` `lookup_pod_meta()` — a failed lookup is **not** cached, so every subsequent record for an unseen pod re-issues the blocking request.
- The filter exposes **no `net.*` options**, so none of this is tunable today.
So a connection that establishes then stalls (half-open after a reset) blocks the event-loop thread in `recv()` indefinitely; `in_tail` collectors are never serviced and the pipeline wedges without ever reaching the pause path.
## Deterministic reproduction (minikube + Toxiproxy)
Toxiproxy sits between the filter and the apiserver; a `timeout` toxic (`timeout=0`) makes the connection **establish then stall** — the half-open read the bug needs. (A plain egress block only yields a connect timeout, which recovers, so it does *not* reproduce the permanent hang.)
1. fluent-bit `5.0.9`: `[INPUT] tail` on `/var/log/containers/*.log`; `[FILTER] kubernetes` with `Kube_URL https://toxiproxy:8443`, `tls.verify Off`; `[OUTPUT] null`.
2. Toxiproxy proxy `kube` → `:443`; `toxiproxy-cli toxic add kube -t timeout -a timeout=0`.
3. Append a log line whose filename encodes a **new** `__` (uncached → fresh lookup).
Result: `in_tail` stops. 24 continuous new-pod appends produced **0** new records (`records_total{tail.0}` frozen); a control append for an already-cached pod *is* read, so the tail is blocked specifically by the lookup. Thread state of the stuck process (captured via `/proc`):
```
tid=13 comm=flb-pipeline state=S wchan=wait_woken syscall=read(63)
fd=57 -> socket:[156132] -> /proc/net/tcp remote :8443 ESTABLISHED
```
i.e. the pipeline thread is parked in a post-connect `read()` on the metadata socket with no read timeout; all other threads idle in `epoll`/`nanosleep`.
## Proposed fix (validated)
Two operator-tunable safeguards (defaults on, `0` = legacy):
- **`kube_meta_io_timeout` (default 30s):** set `net.io_timeout` on the API + kubelet upstreams so a stalled read errors instead of blocking the pipeline forever.
- **`kube_meta_negative_cache_ttl` (default 60s):** short-TTL negative cache so a failed lookup isn't re-issued (and re-blocked) on every subsequent line for that pod.
Rebuilt `5.0.9` with this patch and re-ran the exact reproduction (`kube_meta_io_timeout 10`):
| | Unpatched 5.0.9 | Patched 5.0.9 |
|---|---|---|
| new-pod lookup, stalled API | `records{tail.0}` frozen **forever**; thread stuck in `read()` | stalls ≤10s → errors → **recovers** (records resume) |
| repeat lines for a bad pod | each re-blocks | negative-cached → **instant** (1→13 in the test) |
| pipeline | permanently wedged | keeps progressing (`ingestion_paused=0`) |
This is a *mitigation* — it bounds the synchronous fetch; the complete fix is async metadata resolution / a background pod cache (a larger change). Happy to open a PR with the patch above if this direction is acceptable.
**Environment:** Fluent Bit v5.0.9, Kubernetes (GKE) DaemonSet, default non-threaded `in_tail` + `filter_kubernetes` against the API server (no `Use_Kubelet`).
Contributor guide
Research direction
Start in plugins/filter_kubernetes/kubernetes.c and plugins/filter_kubernetes/kube_meta.c, then trace timeout handling through src/flb_network.c and src/flb_upstream.c. Reproduce the stalled-read case with minikube and Toxiproxy, and verify that the proposed timeout and negative-cache behavior lets records resume without wedging in_tail.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- c, kubernetes
- Domain
- observability-sre, stream-processing
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 58/100