Filebeats autodiscover : Segmentation violation


(Theo Delahayes) #1

Hi,
I've tried the autodiscovery feature for Docker and i keep getting a segmentation violation error each time that i try launching filebeats ( with args -e -d "*" ) : using filebeats 6.2.4

Here are the logs :

018-05-25T15:29:07.919Z	INFO	instance/beat.go:468	Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/var/lib/filebeat] Logs path: [/var/log/filebeat]
2018-05-25T15:29:07.920Z	DEBUG	[beat]	instance/beat.go:495	Beat metadata path: /var/lib/filebeat/meta.json
2018-05-25T15:29:07.920Z	INFO	instance/beat.go:475	Beat UUID: 1bc283cb-c46d-4e84-bf39-4539ba035bc2
2018-05-25T15:29:07.920Z	INFO	instance/beat.go:213	Setup Beat: filebeat; Version: 6.2.4
2018-05-25T15:29:07.920Z	DEBUG	[beat]	instance/beat.go:230	Initializing output plugins
2018-05-25T15:29:07.920Z	DEBUG	[docker]	docker/watcher.go:156	Start docker containers scanner
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010c8c0]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[container:0xc42010c930 start:true]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010c9a0]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010ca10]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010ca80]
2018-05-25T15:29:07.928Z	DEBUG	[processors]	processors/processor.go:49	Processors: add_docker_metadata=[match_fields=[] match_pids=[process.pid, process.ppid]]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010caf0]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[container:0xc42010cb60 start:true]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010cbd0]
2018-05-25T15:29:07.928Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42010cc40]
2018-05-25T15:29:07.929Z	INFO	pipeline/module.go:76	Beat name: anton
2018-05-25T15:29:07.929Z	INFO	[monitoring]	log/log.go:97	Starting metrics logging every 30s
2018-05-25T15:29:07.930Z	INFO	instance/beat.go:301	filebeat start running.
2018-05-25T15:29:07.930Z	DEBUG	[registrar]	registrar/registrar.go:90	Registry file set to: /var/lib/filebeat/registry
2018-05-25T15:29:07.931Z	INFO	registrar/registrar.go:110	Loading registrar data from /var/lib/filebeat/registry
2018-05-25T15:29:07.931Z	INFO	registrar/registrar.go:121	States Loaded from registrar: 0
2018-05-25T15:29:07.931Z	WARN	beater/filebeat.go:261	Filebeat is unable to load the Ingest Node pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the Ingest Node pipelines or are using Logstash pipelines, you can ignore this warning.
2018-05-25T15:29:07.931Z	INFO	crawler/crawler.go:48	Loading Prospectors: 0
2018-05-25T15:29:07.931Z	INFO	crawler/crawler.go:82	Loading and starting Prospectors completed. Enabled prospectors: 0
2018-05-25T15:29:07.931Z	DEBUG	[registrar]	registrar/registrar.go:152	Starting Registrar
2018-05-25T15:29:07.931Z	DEBUG	[docker]	docker/watcher.go:156	Start docker containers scanner
2018-05-25T15:29:07.939Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:58	Configured autodiscover provider: docker
2018-05-25T15:29:07.939Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42016c070]
2018-05-25T15:29:07.939Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42016c0e0]
2018-05-25T15:29:07.939Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42016c150]
2018-05-25T15:29:07.939Z	INFO	autodiscover/autodiscover.go:77	Starting autodiscover manager
2018-05-25T15:29:07.939Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42016c1c0]
2018-05-25T15:29:07.939Z	DEBUG	[bus]	bus/bus.go:55	docker: map[start:true container:0xc42016c230]
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0xebfea6]
goroutine 58 [running]:
github.com/elastic/beats/libbeat/processors.(*Condition).Check(0x0, 0x1f36d60, 0xc42007d5c0, 0x0)
	/go/src/github.com/elastic/beats/libbeat/processors/condition.go:205 +0x26
github.com/elastic/beats/libbeat/autodiscover/template.(*Mapper).GetConfig(0xc42049c380, 0xc42007d5c0, 0xc4204bc528, 0xac369f, 0x10)
	/go/src/github.com/elastic/beats/libbeat/autodiscover/template/config.go:62 +0x63e
github.com/elastic/beats/libbeat/autodiscover/providers/docker.(*Provider).publish(0xc4205340c0, 0xc42007d5c0)
	/go/src/github.com/elastic/beats/libbeat/autodiscover/providers/docker/docker.go:137 +0x3d
github.com/elastic/beats/libbeat/autodiscover/providers/docker.(*Provider).emitContainer(0xc4205340c0, 0xc42015a240, 0x16c6c00, 0x5)
	/go/src/github.com/elastic/beats/libbeat/autodiscover/providers/docker/docker.go:110 +0x78a
github.com/elastic/beats/libbeat/autodiscover/providers/docker.(*Provider).Start.func1(0xc4205340c0)
	/go/src/github.com/elastic/beats/libbeat/autodiscover/providers/docker/docker.go:74 +0x1e9
created by github.com/elastic/beats/libbeat/autodiscover/providers/docker.(*Provider).Start
	/go/src/github.com/elastic/beats/libbeat/autodiscover/providers/docker/docker.go:65 +0x3f

And here's my the content of the autodiscovery of my filebeat.yml file :

filebeat.autodiscover:
  providers:
    - type: docker
      templates:
        - condition:
          equals:
            docker.container.image: nginx
          config:
            - module: nginx
              access:
                prospector:
                  type: docker
                  container.ids:
                    - "${data.docker.container.id}"
              error:
                prospector:
                  type: docker
                  container.ids:
                    - "${data.docker.container.id}"

I can't figure out what causes the problem.
Thanks in advance :smiley:


(Adrian Serrano) #2

This is caused by an indentation error in your configuration. The equals clause must be indented so that its part of the - condition above. Note the difference with this correction:

[...]
templates:
  - condition:
      equals:
        docker.container.image: nginx
    config:
      - module: nginx
[...]

However, this configuration mistake should be diagnosed, instead of crashing filebeat :slight_smile: We'll have it fixed, here's the link to the issue in case you want to follow-up:
https://github.com/elastic/beats/issues/7183

Thanks for your report.


(Theo Delahayes) #3

Thanks a lot that did the trick, I also made a typo with - containers-ids i forgot the 's' at containers.

However now although Filebeat seams to discover the container it's not picking up logs

    se=GPLv2     org.label-schema.build-date=20180402"},"name":"filebeats"}}]
2018-05-28T07:45:55.004Z	WARN	[cfgwarn]	docker/prospector.go:25	EXPERIMENTAL: Docker prospector is enabled.
2018-05-28T07:45:55.004Z	DEBUG	[processors]	processors/processor.go:49	Processors:
2018-05-28T07:45:55.004Z	DEBUG	[prospector]	log/config.go:178	recursive glob enabled
2018-05-28T07:45:55.004Z	DEBUG	[prospector]	log/prospector.go:120	exclude_files: [(?-s:.)gz(?-m:$)]. Number of stats: 0
2018-05-28T07:45:55.004Z	DEBUG	[prospector]	log/prospector.go:141	Prospector with previous states loaded: 0
2018-05-28T07:45:55.004Z	INFO	log/prospector.go:111	Configured paths: [/var/lib/docker/containers/8d8f70dabc024c281f7fd53fb08949e647982a5688ca4eeedb877c59831a544e/*.log]
2018-05-28T07:45:55.004Z	WARN	[cfgwarn]	docker/prospector.go:25	EXPERIMENTAL: Docker prospector is enabled.
2018-05-28T07:45:55.005Z	DEBUG	[processors]	processors/processor.go:49	Processors:
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/config.go:178	recursive glob enabled
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:120	exclude_files: [(?-s:.)gz(?-m:$)]. Number of stats: 0
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:141	Prospector with previous states loaded: 0
2018-05-28T07:45:55.005Z	INFO	log/prospector.go:111	Configured paths: [/var/lib/docker/containers/8d8f70dabc024c281f7fd53fb08949e647982a5688ca4eeedb877c59831a544e/*.log]
2018-05-28T07:45:55.005Z	INFO	autodiscover/autodiscover.go:145	Autodiscover starting runner: nginx (access, error)
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	prospector/prospector.go:87	Starting prospector of type: docker; ID: 11780369310384567314
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	prospector/prospector.go:87	Starting prospector of type: docker; ID: 8951206303945484939
2018-05-28T07:45:55.005Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:109	Got a start event: map[start:true host:172.17.0.2 port:80 docker:{"container":{"id":"8d8f70dabc024c281f7fd53fb08949e647982a5688ca4eeedb877c59831a544e","image":"nginx","labels":{"maintainer":"NGINX Docker Maintainers \u003cdocker-maint@nginx.com\u003e"},"name":"nginx"}} meta:{"docker":{"container":{"id":"8d8f70dabc024c281f7fd53fb08949e647982a5688ca4eeedb877c59831a544e","image":"nginx","labels":{"maintainer":"NGINX Docker Maintainers \u003cdocker-maint@nginx.com\u003e"},"name":"nginx"}}} config:[0xc42013c420]], generated configs: [0xc42013c420]
2018-05-28T07:45:55.005Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:193	Got a meta field in the event
2018-05-28T07:45:55.005Z	DEBUG	[autodiscover]	autodiscover/autodiscover.go:135	Config &{{<nil> } <nil> 0xc420537100} is already running
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:45:55.005Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	prospector/prospector.go:124	Run prospector
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	prospector/prospector.go:124	Run prospector
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:46:05.006Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	prospector/prospector.go:124	Run prospector
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	prospector/prospector.go:124	Run prospector
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	log/prospector.go:147	Start next scan
2018-05-28T07:46:15.006Z	DEBUG	[prospector]	log/prospector.go:168	Prospector states cleaned up. Before: 0, After: 0, Pending: 0

Here is my new config

    filebeat.autodiscover:
  providers:
    - type: docker
      templates:
        - condition:
            contains:
              docker.container.image: nginx
          config:
            - module: nginx
              access:
                prospector:
                  type: docker
                  containers.ids:
                    - "${data.docker.container.id}"
              error:
                prospector:
                  type: docker
                  containers.ids:
                    - "${data.docker.container.id}"

I curled the nginx a couple of times and logs displayed, i use the json-file log-driver and tried the default stdout too on docker side.

Is there something i'm missing on ?
Thanks again for your time and sorry for the inconvenience i'm fairly new to Filebeat. :smiley:


(system) #4

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