Hot reload stuck in progress after pausing inputs

[yuvalhnoga]

Bug Report

Executing a hot reload with from a sidecar container in the same pod as fluent-bit with curl -X POST http://localhost:2020/api/v2/reload -d '{}' gets stuck and if you try to reload again you get {"reload":"in progress","status":-2}

In the fluent-bit configuration we can see this and its stuck like this forever:

[engine] caught signal (SIGHUP)
[ info] reloading instance pid=1 tid=0x7f20c800ee40
[ info] [reload] stop everything of the old context
[ warn] [engine] service will shutdown when all remaining tasks are flushed
[ info] [input] pausing input-kube-pods-logs
[ info] [input] pausing input-kube-node-logs
[ info] [input] pausing cpu.2
[ info] [engine] service has stopped (0 pending tasks)
[ info] [input] pausing input-kube-pods-logs
[ info] [input] pausing input-kube-node-logs
[ info] [input] pausing cpu.2

Normally when the reload works the lines that come after this should be:

[input] pausing input-kube-node-logs
[input] pausing cpu.2
[output:forward:forward-to-fluentd] thread worker #0 stopping...
[output:forward:forward-to-fluentd] thread worker #0 stopped
[output:forward:forward-to-fluentd] thread worker #1 stopping...
[output:forward:forward-to-fluentd] thread worker #1 stopped
[input:tail:input-kube-node-logs] inotify_fs_remove(): inode=3146021 watch_fd=1
[input:tail:input-kube-node-logs] inotify_fs_remove(): inode=3145852 watch_fd=2
[input:tail:input-kube-node-logs] inotify_fs_remove(): inode=3145851 watch_fd=3
[input:tail:input-kube-node-logs] inotify_fs_remove(): inode=3146020 watch_fd=4
[reload] start everything

To Reproduce

Create fluent-bit.yaml:

service:
    flush: 5
    daemon: off
    http_server: on
    http_listen: 0.0.0.0
    http_port: 2020
    health_check: on
    hot_reload: on
    hc_errors_count: 5
    hc_retry_failure_count: 5
    hc_period: 5
    log_level: info
    parsers_file: /fluent-bit/etc/parsers.conf
    
pipeline:
  inputs:
    - name: cpu
      tag: temp_cpu
  filters:
    - name: throttle
      match: kubernetes.var.log.containers.example1-*
      alias: example1
      rate: 999999
      window: 999999
      interval: 999999s
  outputs:
    - name: forward
      alias: forward-to-fluentd
      match: kubernetes.*
      upstream: /fluent-bit/etc/upstream.conf
      port: 24224
      retry_limit: false
      
includes:
    - /fluent-bit/filters/*.yaml
    - /fluent-bit/config/filters.yaml

• Steps to reproduce the problem:
  • Start the container
  • Execute curl -X POST http://localhost:2020/api/v2/reload -d '{}' multiple times until the reload hangs like I mentioned above

Expected behavior
The reload should fail/continue but not hang.

Your Environment

• Version used: FluentBit 3.1.7, Linux docker on Amazon EKS cluster node

Additional context
I am running a sidecar next to my fluent-bit container that dynamically creates a filter with throttling configuration that is per container on the same node as fluent-bit(fluent-bit runs as daemonset in my kubernetes cluster).
Everytime theres a change to the filter configuration the sidecar performs a hot reload with
curl -X POST http://localhost:2020/api/v2/reload -d '{}'

Is there maybe an option to verify when the reload fails and be able to retry it because if I try to run the reload again it just says it's in progress forever.
Also is there a way to monitor or know that it happens? Since health check shows as ok, I only noticed that happened because I stopped receiving logs.
Would be nice if there was a way to know about it and maybe restart the fluent-bit container or perform some sort of forced reload.

[yuvalhnoga]

Seems like reproducing this issue is not as easy as I thought but I have some more insight:

I managed to find all the pods where this issue happens by querying this in prometheus:

increase(fluentbit_uptime[5m]) == 0

I noticed that the pods that stop sending logs also have the fluentbit_uptime metric stop increasing
I looked at the resource consumption of the fluent-bit container and the memory in more than half of them is around 20-30mb memory usage where my requests is 64mb and limits is 256mb
As for CPU resource consumption it was pretty much the same (not fully used).

I checked how many hot reloads back to back it took for it to fail and it seems like it was 2 reloads in 30s increments but in some it was even 2mins.
In one of them I noticed it took just 1 reload to make it stop working and both cpu/memory were low in the container.

I tried reproducing it spamming the hot reload curl in multiple different kind of pods with different scenarios:

• container with a lot of pods in the same node
• container with pods that write a lot of logs
• container with high cpu/memory usage

I didn’t find any of these criterias to affect if the hot reload will fail even when spamming the hot reload curl nonstop without any wait.

Not really sure what else it could be but it’s a tough one 😛

[jjsiv]

I'm experiencing the same issue, except in my case as far as I can see the uptime metric still keeps increasing as normal and the server responds positively, so unfortunately setting a livenessProbe on the Kubernetes pod does not resolve the issue as I had hoped it would.

I'm using Fluent Operator which has a fluent-watcher process send a SIGHUP signal on a config change and it will occassionally make the fluent-bit process hang on reload until the pod is restarted. Most recent example:

level=info time=2024-11-21T11:08:37Z msg="Config file changed, reloading..."
[2024/11/21 11:08:37] [engine] caught signal (SIGHUP)
[2024/11/21 11:08:37] [ info] reloading instance pid=13 tid=0x7fc1d87a7e40
level=info time=2024-11-21T11:08:37Z msg="Config file changed, reloading..."
[2024/11/21 11:08:37] [engine] caught signal (SIGHUP)
level=info time=2024-11-21T11:08:37Z msg="Config file changed, reloading..."
level=info time=2024-11-21T14:12:00Z msg="Config file changed, reloading..."
level=info time=2024-11-21T14:12:00Z msg="Config file changed, reloading..."
level=info time=2024-11-21T14:12:00Z msg="Config file changed, reloading..."
level=info time=2024-11-21T14:12:00Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:16:28Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:16:28Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:16:28Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:23:07Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:23:07Z msg="Config file changed, reloading..."
level=info time=2024-11-21T15:23:07Z msg="Config file changed, reloading..."
level=info time=2024-11-22T07:52:26Z msg="Config file changed, reloading..."
level=info time=2024-11-22T07:52:26Z msg="Config file changed, reloading..."
level=info time=2024-11-22T07:52:26Z msg="Config file changed, reloading..."
level=info time=2024-11-22T09:26:42Z msg="Config file changed, reloading..."
level=info time=2024-11-22T09:26:42Z msg="Config file changed, reloading..."
level=info time=2024-11-22T09:26:42Z msg="Config file changed, reloading..."

When I try to restart it manually via HTTP:

bash-5.1# curl -XGET -d '{}' http://192.168.38.198:2020/api/v2/reload
{"hot_reload_count":2}

bash-5.1# curl -XPOST -d '{}' http://192.168.38.198:2020/api/v2/reload
{"reload":"in progress","status":-2}

bash-5.1# curl -XGET -d '{}' http://192.168.38.198:2020/api/v2/reload
{"hot_reload_count":2}

Essentially it stays "in progress" forever. On a healthy pod to compare:

bash-5.1# curl -XGET -d '{}' http://192.168.85.123:2020/api/v2/reload
{"hot_reload_count":12}

bash-5.1# curl -XPOST -d '{}' http://192.168.85.123:2020/api/v2/reload
{"reload":"done","status":0}

bash-5.1# curl -XGET -d '{}' http://192.168.85.123:2020/api/v2/reload
{"hot_reload_count":13}

As a sidenote, I've noticed a similar issue in fluent-bit before hot reload was introduced and we used fluent-watcher to send SIGTERM on config change. This would also make fluent-bit hang sometimes and so at some point we introduced a SIGKILL if it failed to terminate after a while: fluent/fluent-operator#510
But once hot reload was introduced we switched to that and that feature was removed.

[btalakola]

HI Team, I am also facing same issue where hot reload is not working very effectively. If there are any configurational changes, fluent-bit-config secret is updated but those changes are applied with hot reload flag . Can you please provide an update on this issue?

[btalakola]

Also have one more question, does fluent-watcher internally use hot reload or the rest api localhost:2020/api/v2/reload?

[github-actions]

This issue is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 5 days. Maintainers can add the exempt-stale label.

[github-actions]

This issue was closed because it has been stalled for 5 days with no activity.