I'm trying to properly configure Filebeat autodiscover on my kubernetes cluster to send log data from a specific namespace to a VM containing the elasticsearch installed. I couldn't identify the problem, because apparently the file is identified and Harvester is started for the file, but I can't see anything in the elastic search.
filebeat.yml: |-
# To enable hints based autodiscover, remove `filebeat.inputs` configuration and uncomment this:
filebeat.autodiscover:
providers:
- type: kubernetes
node: ${NODE_NAME}
hints.enabled: true
hints.default_config:
type: container
paths:
- /var/log/containers/my-poc-log/*-${data.kubernetes.pod.uid}.log
templates:
- condition:
equals:
kubernetes.namespace: my-poc
config:
- type: container
paths:
- /var/log/containers/my-poc-log/*-${data.kubernetes.pod.uid}.log
processors:
- add_cloud_metadata: ~
- drop_fields:
when:
has_fields: ['kubernetes.labels.app']
fields:
- 'kubernetes.labels.app'
output.elasticsearch:
hosts: ['${ELASTICSEARCH_HOST:elasticsearch}:${ELASTICSEARCH_PORT:9200}']
username: ${ELASTICSEARCH_USERNAME}
password: ${ELASTICSEARCH_PASSWORD}
index: "counter-pod-%{+yyyy.MM.dd}"
setup.template:
name: 'counter-pod'
pattern: 'counter-pod-*'
enabled: true
I created a pod that write a line in the log each 30 seconds, it's just to test until I make this work. On the filebeat log output I get:
2020-08-13T03:17:39.686Z INFO instance/beat.go:647 Home path: [/usr/share/filebeat] Config path: [/usr/share/filebeat] Data path: [/usr/share/filebeat/data] Logs path: [/usr/share/filebeat/logs]
2020-08-13T03:17:39.686Z INFO instance/beat.go:655 Beat ID: f74e140e-77de-4184-b16f-5729deeee091
2020-08-13T03:17:39.687Z INFO [seccomp] seccomp/seccomp.go:124 Syscall filter successfully installed
2020-08-13T03:17:39.687Z INFO [beat] instance/beat.go:983 Beat info {"system_info": {"beat": {"path": {"config": "/usr/share/filebeat", "data": "/usr/share/filebeat/data", "home": "/usr/share/filebeat", "logs": "/usr/share/filebeat/logs"}, "type": "filebeat", "uuid": "f74e140e-77de-4184-b16f-5729deeee091"}}}
2020-08-13T03:17:39.687Z INFO [beat] instance/beat.go:992 Build info {"system_info": {"build": {"commit": "94f7632be5d56a7928595da79f4b829ffe123744", "libbeat": "7.8.1", "time": "2020-07-21T15:12:45.000Z", "version": "7.8.1"}}}
2020-08-13T03:17:39.687Z INFO [beat] instance/beat.go:995 Go runtime info {"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":4,"version":"go1.13.10"}}}
2020-08-13T03:17:39.689Z INFO [beat] instance/beat.go:999 Host info {"system_info": {"host": {"architecture":"x86_64","boot_time":"2020-07-17T01:19:23Z","containerized":false,"name":"aks-nodepool1","ip":["127.0.0.1/8","::1/128","fe80::20d:3aff:fee5:ad37/64","172.17.0.1/16","10.240.0.4/16","fe80::20d:3aff:fee5:ad37/64","fe80::5899:f2ff:fe27:807a/64","fe80::4aa:deff:fe91:ad90/64","fe80::7cce:d0ff:feeb:4aa1/64","fe80::4c3f:e8ff:fe36:584a/64","fe80::ec7a:43ff:febe:4e83/64","fe80::a4b8:15ff:fe9b:f604/64","fe80::c050:c8ff:fe6c:1ac3/64","fe80::585e:eff:fe0c:55f9/64","fe80::14ed:7cff:fe9b:f02/64","fe80::c6a:ff:fe9f:60d4/64","fe80::4c50:36ff:fed2:24a/64","fe80::c37:7dff:fe87:9bc/64","fe80::2434:4fff:fe02:44e2/64","fe80::f45a:46ff:feb2:ac9d/64","fe80::907b:3eff:fe6c:a359/64","fe80::5cea:c7ff:fe61:5f87/64","fe80::38a3:9aff:fe9d:f10a/64","fe80::900c:70ff:fea0:c6e1/64"],"kernel_version":"4.15.0-1091-azure","mac":["00:0d:3a:e5:ad:37","02:42:48:62:36:d6","00:0d:3a:e5:ad:37","5a:99:f2:27:80:7a","06:aa:de:91:ad:90","7e:ce:d0:eb:4a:a1","4e:3f:e8:36:58:4a","ee:7a:43:be:4e:83","a6:b8:15:9b:f6:04","c2:50:c8:6c:1a:c3","5a:5e:0e:0c:55:f9","16:ed:7c:9b:0f:02","0e:6a:00:9f:60:d4","4e:50:36:d2:02:4a","0e:37:7d:87:09:bc","26:34:4f:02:44:e2","f6:5a:46:b2:ac:9d","92:7b:3e:6c:a3:59","5e:ea:c7:61:5f:87","3a:a3:9a:9d:f1:0a","00:0d:3a:e5:ad:37","92:0c:70:a0:c6:e1"],"os":{"family":"redhat","platform":"centos","name":"CentOS Linux","version":"7 (Core)","major":7,"minor":8,"patch":2003,"codename":"Core"},"timezone":"UTC","timezone_offset_sec":0,"id":"1a018e03a49f4bfc904c69b0d6c08959"}}}
2020-08-13T03:17:39.689Z INFO [beat] instance/beat.go:1028 Process info {"system_info": {"process": {"capabilities": {"inheritable":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_raw","sys_chroot","mknod","audit_write","setfcap"],"permitted":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_raw","sys_chroot","mknod","audit_write","setfcap"],"effective":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_raw","sys_chroot","mknod","audit_write","setfcap"],"bounding":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_raw","sys_chroot","mknod","audit_write","setfcap"],"ambient":null}, "cwd": "/usr/share/filebeat", "exe": "/usr/share/filebeat/filebeat", "name": "filebeat", "pid": 1, "ppid": 0, "seccomp": {"mode":"filter","no_new_privs":true}, "start_time": "2020-08-13T03:17:39.420Z"}}}
2020-08-13T03:17:39.689Z INFO instance/beat.go:310 Setup Beat: filebeat; Version: 7.8.1
2020-08-13T03:17:39.689Z INFO [index-management] idxmgmt/std.go:184 Set output.elasticsearch.index to 'filebeat-7.8.1' as ILM is enabled.
2020-08-13T03:17:39.689Z INFO eslegclient/connection.go:99 elasticsearch url: http://10.240.0.35:9200
2020-08-13T03:17:39.690Z INFO [publisher] pipeline/module.go:113 Beat name: aks-nodepool1
2020-08-13T03:17:39.690Z INFO [monitoring] log/log.go:118 Starting metrics logging every 30s
2020-08-13T03:17:39.690Z INFO instance/beat.go:463 filebeat start running.
2020-08-13T03:17:39.691Z INFO registrar/registrar.go:145 Loading registrar data from /usr/share/filebeat/data/registry/filebeat/data.json
2020-08-13T03:17:39.691Z INFO registrar/registrar.go:152 States Loaded from registrar: 64
2020-08-13T03:17:39.691Z INFO [crawler] beater/crawler.go:71 Loading Inputs: 0
2020-08-13T03:17:39.691Z INFO [crawler] beater/crawler.go:108 Loading and starting Inputs completed. Enabled inputs: 0
2020-08-13T03:17:39.692Z INFO [autodiscover.pod] kubernetes/util.go:79 kubernetes: Using node aks-nodepool1 provided in the config
2020-08-13T03:17:39.693Z INFO [autodiscover] autodiscover/autodiscover.go:113 Starting autodiscover manager
2020-08-13T03:17:39.693Z INFO [add_cloud_metadata] add_cloud_metadata/add_cloud_metadata.go:93 add_cloud_metadata: hosting provider type detected as az, metadata={"instance":{"id":"8c031f46-a97f-413e-98b8-1ade5d5a2569","name":"aks-nodepool1-37110876-vmss_0"},"machine":{"type":"Standard_F4s_v2"},"provider":"az","region":"eastus2"}
2020-08-13T03:17:39.794Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-e4374558-e22a-4bf6-9883-1b7f956f0f66.log]
2020-08-13T03:17:39.794Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-e4374558-e22a-4bf6-9883-1b7f956f0f66.log]
2020-08-13T03:17:39.795Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-124b7d6b-6cb8-4293-af2d-69a3057b708e.log]
2020-08-13T03:17:39.796Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-124b7d6b-6cb8-4293-af2d-69a3057b708e.log]
2020-08-13T03:17:39.796Z INFO log/harvester.go:297 Harvester started for file: /var/log/containers/my-poc-log/counter-124b7d6b-6cb8-4293-af2d-69a3057b708e.log
2020-08-13T03:17:39.817Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-5135964f-d7ef-416e-b12b-b5aa963782b8.log]
2020-08-13T03:17:39.818Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-d6301f10-bff5-47c6-9568-e30ca54769b8.log]
2020-08-13T03:17:39.818Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-d6301f10-bff5-47c6-9568-e30ca54769b8.log]
2020-08-13T03:17:39.917Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-4883bde1-2fee-4c98-b8e0-dbd4b7a55235.log]
2020-08-13T03:17:39.918Z INFO log/input.go:152 Configured paths: [/var/log/containers/my-poc-log/*-4883bde1-2fee-4c98-b8e0-dbd4b7a55235.log]
2020-08-13T03:18:09.692Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":30,"time":{"ms":37}},"total":{"ticks":180,"time":{"ms":190},"value":180},"user":{"ticks":150,"time":{"ms":153}}},"handles":{"limit":{"hard":1048576,"soft":1048576},"open":10},"info":{"ephemeral_id":"42a9f81d-6994-4bb1-9e66-6805f94b364f","uptime":{"ms":30028}},"memstats":{"gc_next":16887184,"memory_alloc":13523736,"memory_total":31699800,"rss":66465792},"runtime":{"goroutines":292}},"filebeat":{"events":{"active":1,"added":3,"done":2},"harvester":{"files":{"4e2f6d16-f885-4e41-98a1-4bc5ec69276d":{"last_event_published_time":"","last_event_timestamp":"","name":"/var/log/containers/my-poc-log/counter-124b7d6b-6cb8-4293-af2d-69a3057b708e.log","size":117610,"start_time":"2020-08-13T03:17:39.796Z"}},"open_files":1,"running":1,"started":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"type":"elasticsearch"},"pipeline":{"clients":22,"events":{"active":0,"filtered":2,"total":2}}},"registrar":{"states":{"current":64,"update":2},"writes":{"success":2,"total":2}},"system":{"cpu":{"cores":4},"load":{"1":0.34,"15":0.19,"5":0.23,"norm":{"1":0.085,"15":0.0475,"5":0.0575}}}}}}
2020-08-13T03:18:39.692Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70,"time":{"ms":37}},"total":{"ticks":220,"time":{"ms":37},"value":220},"user":{"ticks":150}},"handles":{"limit":{"hard":1048576,"soft":1048576},"open":10},"info":{"ephemeral_id":"42a9f81d-6994-4bb1-9e66-6805f94b364f","uptime":{"ms":60028}},"memstats":{"gc_next":16887184,"memory_alloc":14500832,"memory_total":32676896},"runtime":{"goroutines":292}},"filebeat":{"harvester":{"files":{"4e2f6d16-f885-4e41-98a1-4bc5ec69276d":{"size":112}},"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":22,"events":{"active":0}}},"registrar":{"states":{"current":64}},"system":{"load":{"1":0.2,"15":0.18,"5":0.2,"norm":{"1":0.05,"15":0.045,"5":0.05}}}}}}
So then it keeps updating "Non-zero metrics in the last 30s". And on ElasticSearch the new index is not created:
$ curl -XGET -u elastic:'password' '10.240.0.35:9200/_cat/indices?v'
health status index uuid pri rep docs.count docs.deleted store.size pri.store.size
yellow open .watcher-history-6-2020.08.13 xB6xcOzqTHiEhZoNjOsl2A 1 1 1130 0 1.1mb 1.1mb
yellow open .monitoring-alerts-6 lUhljw3ST1C3deaOR-oNhw 1 1 1 0 15.4kb 15.4kb
yellow open .watches lX7pGqcNRdqdhPhPN9sE_Q 1 1 4 0 70.1kb 70.1kb
yellow open .watcher-history-6-2020.08.12 kTxHzjcZSaO7M64VzvyU9A 1 1 1835 0 1.6mb 1.6mb
yellow open .monitoring-kibana-6-2020.08.12 iQuiStpKTGyUsXhRg90uhg 1 1 2088 0 1019.3kb 1019.3kb
yellow open .kibana _m09Fr7FTf6aPu1Z7mpeYA 1 1 2 0 47.2kb 47.2kb
yellow open .monitoring-es-6-2020.08.12 Suegk0T6QP2NOTxP2PMJ2g 1 1 24196 90 15.8mb 15.8mb
yellow open .triggered_watches n4ekM338RIGjI6nmYvApKg 1 1 0 0 142.1kb 142.1kb
yellow open .monitoring-kibana-6-2020.08.13 e9vOYYDwSWmcjXgPtSUwfA 1 1 1358 0 716.3kb 716.3kb
green open .security mWiLYMhGSAyYC5g8QA1Juw 1 0 2 0 5.5kb 5.5kb
yellow open .monitoring-es-6-2020.08.13 mnIey5BYS-qL1krKSR2ZFw 1 1 19064 168 13.1mb 13.1mb
I also tried to use the command tcpdump -Xni eth0 port 9200 on my VM to listen the port and check if there's some communication. But nothing, seems like Filebeat is not even trying to send something.