Filebeat (6.4.2) autodiscover on Kubernetes. Missing field accessing 'containers.ids.0'


(Håvard Langdal) #1

I got this strange (I've not seen it before) error from Filebeat running as a daemonset on Kubernetes (minikube) today. It might be a misconfiguration, that's why I'm posting here first.
Filebeat yaml:

filebeat.yml: |-
    logging.level: info
    filebeat.autodiscover:
      providers:
        - type: kubernetes
          hints.enabled: true
          include_annotations:
          - "laas.express-rest.no/service"
          - "laas.express-rest.no/type"
          - "laas.express-rest.no/token"
          - "co.elastic.logs/*"
          - "co.elastic.logs/disable"
          - "co.elastic.logs.nginx/disable"

    processors:
      - add_kubernetes_metadata:
          in_cluster: true
      - drop_fields:
          fields: ["host"]

      # This ensures that every log that passes has required fields
      - drop_event:
          when:
            not.has_fields: ['kubernetes.annotations.laas.express-rest.no/service', 'kubernetes.annotations.laas.express-rest.no/token', 'kubernetes.annotations.laas.express-rest.no/type']
      
      - rename:
          fields:
            - from: "kubernetes.annotations.laas.express-rest.no/service"
              to: "_service"
            - from: "kubernetes.annotations.laas.express-rest.no/token"
              to: "_token"
            - from: "kubernetes.annotations.laas.express-rest.no/type"
              to: "type"
    
 
    output.logstash:
      hosts: ['${LOGSTASH_HOSTS}']

Some logs. Complete log file (debug logs, -v -d autodiscover, docker)

 2018-10-29T14:21:46.315Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:21:46.315Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:21:46.315Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:21:46.315Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:21:46.315Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-10-29T14:21:56.315Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:21:56.315Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:21:56.316Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:21:56.316Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:21:56.316Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-10-29T14:22:06.316Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:22:06.316Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:22:06.316Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:22:06.316Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:22:06.316Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-10-29T14:22:09.979Z	INFO	[monitoring]	log/log.go:141	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":23850,"time":{"ms":21}},"total":{"ticks":36210,"time":{"ms":189},"value":36210},"user":{"ticks":12360,"time":{"ms":168}}},"info":{"ephemeral_id":"68c73467-10fb-491d-b82f-fdc41991d459","uptime":{"ms":1170137}},"memstats":{"gc_next":9865024,"memory_alloc":6600632,"memory_total":479523192}},"filebeat":{"events":{"active":1,"added":35,"done":34},"harvester":{"open_files":10,"running":8}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":30,"batches":15,"total":30},"read":{"bytes":90},"write":{"bytes":11160}},"pipeline":{"clients":48,"events":{"active":1,"filtered":4,"published":31,"total":35},"queue":{"acked":30}}},"registrar":{"states":{"current":17,"update":34},"writes":{"success":19,"total":19}},"system":{"load":{"1":1.81,"15":1.24,"5":1.36,"norm":{"1":0.905,"15":0.62,"5":0.68}}}}}}
2018-10-29T14:22:16.317Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:22:16.317Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:22:16.317Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:22:16.317Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:22:16.317Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-10-29T14:22:26.317Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:22:26.317Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:22:26.317Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:22:26.317Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:22:26.318Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-10-29T14:22:36.319Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-10-29T14:22:36.319Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 18
2018-10-29T14:22:36.319Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-10-29T14:22:36.319Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-10-29T14:22:36.319Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0' 

Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
(Håvard Langdal) #2

Without touching the configuration and changing to 6.3.2 made this error disappear if that helps.
Will retest to validate in the near future.


(Jaime Soriano) #3

Hi @havlan,

This issue seems similar to the one fixed by https://github.com/elastic/beats/pull/7971, but this should be fixed on 6.4.2 :thinking:

Could you collect logs with the kubernetes debug flag?


(Håvard Langdal) #4

I am not able to reproduce (different machine than yesterday atm). I'll report back if I encounter the same issue with 6.4.2.

-- Håvard


(system) #5

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.


(Jaime Soriano) #6

Hi @havlan,

Sorry for the late reply, were you using disable annotations for hints-based configuration? We have found some misbehaviours around this. This PR should fix them: https://github.com/elastic/beats/pull/9305


(Jaime Soriano) #7

(Håvard Langdal) #8

Hey!
Like "co.elastic...: disable" as annotations in pods? That could be the case, I'll be able to check thursday.


(Jaime Soriano) #9

Yes, co.elastic.logs/disable: "true". It'd be great if you could confirm if you can reproduce these errors with these annotations.


(Håvard Langdal) #10

Can confirm that I am able to reproduce the error with the co.elastic.logs/disable: true annotation on the filebeat pod.
Do you have any estimate for how long until it will be merged?

Logs:

 2018-12-06T11:51:20.130Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-12-06T11:51:20.130Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 13
2018-12-06T11:51:20.131Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-12-06T11:51:20.131Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-12-06T11:51:20.131Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-12-06T11:51:30.132Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-12-06T11:51:30.133Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 13
2018-12-06T11:51:30.134Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-12-06T11:51:30.134Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-12-06T11:51:30.134Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-12-06T11:51:40.137Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-12-06T11:51:40.138Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 13
2018-12-06T11:51:40.140Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-12-06T11:51:40.141Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-12-06T11:51:40.142Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-12-06T11:51:41.981Z	INFO	[monitoring]	log/log.go:141	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":7680,"time":{"ms":113}},"total":{"ticks":18590,"time":{"ms":331},"value":18590},"user":{"ticks":10910,"time":{"ms":218}}},"info":{"ephemeral_id":"dab68faf-e691-4029-b271-1e20857a4a8f","uptime":{"ms":1290057}},"memstats":{"gc_next":9671296,"memory_alloc":4854232,"memory_total":1165674872}},"filebeat":{"events":{"active":-1,"added":27,"done":28},"harvester":{"open_files":4,"running":4}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":15,"batches":15,"total":15},"read":{"bytes":90},"write":{"bytes":7479}},"pipeline":{"clients":13,"events":{"active":0,"filtered":13,"published":14,"total":27},"queue":{"acked":15}}},"registrar":{"states":{"current":13,"update":28},"writes":{"success":28,"total":28}},"system":{"load":{"1":2.46,"15":2.95,"5":3.45,"norm":{"1":1.23,"15":1.475,"5":1.725}}}}}}
2018-12-06T11:51:50.147Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-12-06T11:51:50.148Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 13
2018-12-06T11:51:50.151Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-12-06T11:51:50.152Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-12-06T11:51:50.153Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0'
2018-12-06T11:52:00.155Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Reloading existing autodiscover configs after error
2018-12-06T11:52:00.156Z	DEBUG	[autodiscover]	cfgfile/list.go:70	Starting reload procedure, current runners: 13
2018-12-06T11:52:00.156Z	DEBUG	[autodiscover]	cfgfile/list.go:88	Start list: 1, Stop list: 0
2018-12-06T11:52:00.157Z	WARN	[cfgwarn]	docker/input.go:46	EXPERIMENTAL: Docker input is enabled.
2018-12-06T11:52:00.158Z	ERROR	[autodiscover]	cfgfile/list.go:104	Error creating runner from config: reading docker input config: missing field accessing 'containers.ids.0' 

(Jaime Soriano) #11

Thanks a lot for confirming it. The fix is already merged, it will get released in 6.5.3 and 6.6.0.


(Håvard Langdal) #12

@jsoriano cool, good job!


(Håvard Langdal) #13

Do you know when 6.5.3/6.6.0 will be released? =)


(Jaime Soriano) #14

Soon :slight_smile: