Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[filebeat] Kubernetes watcher leaks when filebeat reload with wrong input config #18629

Closed
DanielQujun opened this issue May 19, 2020 · 1 comment · Fixed by #18630
Closed
Labels
bug Team:Platforms Label for the Integrations - Platforms team

Comments

@DanielQujun
Copy link
Contributor

One of our customers running filebeat 7.7.0 to collect logs for their pods in Kubernetes clusters, They notice that the CPU and memory resource usage of Filebeat is suspicious.

%Cpu(s): 13.9 us,  6.1 sy,  0.0 ni, 80.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32780056 total, 23727968 free,  5407344 used,  3644744 buff/cache
KiB Swap:  5242876 total,  5242876 free,        0 used. 26631904 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                                     
31542 root      20   0 1560556 619264  19428 S  40.0  1.9  90:48.44 filebeat      

meanwhile the Filebeat log shows:

2020-05-19T09:44:18.869+0800    INFO    [kubernetes]    kubernetes/util.go:101  kubernetes: Using node %s discovered by in cluster pod node query192.168.0.35   {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:28.846+0800    ERROR   [reload]        cfgfile/list.go:96      Error creating runner from config: each input must have at least one path defined
2020-05-19T09:44:28.855+0800    INFO    add_kubernetes_metadata/kubernetes.go:71        add_kubernetes_metadata: kubernetes env detected, with version: v1.14.6
2020-05-19T09:44:28.855+0800    INFO    [kubernetes]    kubernetes/util.go:95   kubernetes: Using pod name filebeat-hm7g2 and namespace kube-system to discover kubernetes node {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:28.874+0800    INFO    [kubernetes]    kubernetes/util.go:101  kubernetes: Using node %s discovered by in cluster pod node query192.168.0.35   {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:32.121+0800    INFO    [monitoring]    log/log.go:145  Non-zero metrics in the last 30s        {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":140340,"time":{"ms":2332}},"total":{"ticks":242960,"time":{"ms":3611},"value":242960},"user":{"ticks":102620,"time":{"ms":1279}}},"handles":{"limit":{"hard":102400,"soft":102400},"open":11},"info":{"ephemeral_id":"3e49793b-e8b4-49e9-a3a9-212a5b1efccd","uptime":{"ms":42360299}},"memstats":{"gc_next":165532608,"memory_alloc":95442184,"memory_total":1615608576},"runtime":{"goroutines":1634}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0},"reloads":3,"scans":6},"pipeline":{"clients":1,"events":{"active":0}}},"registrar":{"states":{"current":742}},"system":{"load":{"1":5.37,"15":5.43,"5":5.84,"norm":{"1":0.6713,"15":0.6788,"5":0.73}}}}}}
2020-05-19T09:44:38.852+0800    ERROR   [reload]        cfgfile/list.go:96      Error creating runner from config: each input must have at least one path defined
2020-05-19T09:44:38.860+0800    INFO    add_kubernetes_metadata/kubernetes.go:71        add_kubernetes_metadata: kubernetes env detected, with version: v1.14.6
2020-05-19T09:44:38.860+0800    INFO    [kubernetes]    kubernetes/util.go:95   kubernetes: Using pod name filebeat-hm7g2 and namespace kube-system to discover kubernetes node {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:38.871+0800    INFO    [kubernetes]    kubernetes/util.go:101  kubernetes: Using node %s discovered by in cluster pod node query192.168.0.35   {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:48.857+0800    ERROR   [reload]        cfgfile/list.go:96      Error creating runner from config: each input must have at least one path defined
2020-05-19T09:44:48.868+0800    INFO    add_kubernetes_metadata/kubernetes.go:71        add_kubernetes_metadata: kubernetes env detected, with version: v1.14.6
2020-05-19T09:44:48.868+0800    INFO    [kubernetes]    kubernetes/util.go:95   kubernetes: Using pod name filebeat-hm7g2 and namespace kube-system to discover kubernetes node {"libbeat.processor": "add_kubernetes_metadata"}
2020-05-19T09:44:48.880+0800    INFO    [kubernetes]    kubernetes/util.go:101  kubernetes: Using node %s discovered by in cluster pod node query192.168.0.35   {"libbeat.processor": "add_kubernetes_metadata"}

It indicates that the input config might maybe be misconfigured, and it's indeed. Because they write a script to auto-generate configs in inputs.d which dir is for Filebeat to dynamic reload. and the script did not take the situation there are no pods running on the node which Filebeat running, so it generated a config which paths field is empty.

It's easy to fix this problem by modifying the script. But I notice that Filebeat is leaking plenty of Kubernetes watcher goroutines when It's config is not qualified, and that's why Filebeat using high CPU.
image

IMHO, we should take consider this, even though filebeat users can avoid this by fixing their wrong config.

steps to reproduce:

  • run filebeat in Kubernetes
  • enable inputs.reload
  inputs:
    # Mounted `filebeat-inputs` configmap:
    path: ${path.config}/inputs.d/*.json
    # Reload inputs configs as they change:
    reload.enabled: true
  • input config with empty paths
[{"processors": [{"add_kubernetes_metadata": {"annotations.dedot": true, "in_cluster": true, "labels.dedot": true, "include_pod_uid": true, "indexers": [{"pod_uid": null}], "default_indexers.enabled": false, "default_matchers.enabled": false, "matchers": [{"logs_path": {"resource_type": "pod", "logs_path": "/var/lib/kubelet/pods/"}}]}}], "paths": [], "scan_frequency": "20s", "max_procs": 2, "type": "log"}]

For confirmed bugs, please report:

  • Version: 7.7.0
@botelastic botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label May 19, 2020
@exekias exekias added bug Team:Platforms Label for the Integrations - Platforms team labels May 20, 2020
@elasticmachine
Copy link
Collaborator

Pinging @elastic/integrations-platforms (Team:Platforms)

@botelastic botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label May 20, 2020
DanielQujun added a commit to DanielQujun/beats that referenced this issue May 28, 2020
…t's misconfigured(elastic#18629)

fix log format missing in libbeat/common/kubernetes/util.go

Signed-off-by: 屈骏 <[email protected]>
exekias pushed a commit that referenced this issue May 28, 2020
…t's misconfigured(#18629) (#18630)

fix log format missing in libbeat/common/kubernetes/util.go

Signed-off-by: 屈骏 <[email protected]>
exekias pushed a commit to exekias/beats that referenced this issue May 28, 2020
…t's misconfigured(elastic#18629) (elastic#18630)

fix log format missing in libbeat/common/kubernetes/util.go

Signed-off-by: 屈骏 <[email protected]>
(cherry picked from commit 74d81c2)
exekias pushed a commit that referenced this issue May 28, 2020
…t's misconfigured(#18629) (#18630) (#18810)

fix log format missing in libbeat/common/kubernetes/util.go

Signed-off-by: 屈骏 <[email protected]>
(cherry picked from commit 74d81c2)

Co-authored-by: Daniel <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Team:Platforms Label for the Integrations - Platforms team
Projects
None yet
4 participants