Filebeat panic error while running in Windows based Docker container

pbering · July 1, 2017, 11:17am

Hi, I'm trying to make a Docker container based on "microsoft/nanoserver" to run on my Windows based Docker hosts (in a Swarm). But I can't get Filebeat to work.

Observations:

Seems related to the the volume mounting, if I dont't specify a volume mount it can start without errors but then there is no logs to harvest
If I try Filebeat 6.0,0 alpha 2 it can also start but it can't "see" the files, nothing happens when new files are written. Only error in output is "ERR Error: The service process could not connect to the service controller."
If I base my image off microsoft/windowsservercore I get the same error as below
Filebeat works fine outside of a Docker container with the filebeat.yml below

Dockerfile:

# escape=`
FROM microsoft/nanoserver

SHELL ["powershell", "-Command", "$ErrorActionPreference = 'Stop'; $ProgressPreference = 'SilentlyContinue';"]

ADD https://artifacts.elastic.co/downloads/beats/filebeat/filebeat-5.4.3-windows-x86_64.zip C:\Filebeat.zip

RUN Expand-Archive -Path 'C:\Filebeat.zip' -Destination 'C:'; `
    Remove-Item -Path 'C:\Filebeat.zip'; `
    New-Item -Path 'C:\Program Files\Filebeat' -Type Directory | Out-Null; `
    Get-ChildItem -Path 'C:\filebeat*windows*\*' | Move-Item -Destination 'C:\Program Files\Filebeat'; `
    Remove-Item -Path 'C:\filebeat*windows*' -Force;

WORKDIR "C:\Program Files\Filebeat"

COPY filebeat.yml .

VOLUME C:\sitecore-logs

ENV ES_HOSTS="http://elasticsearch:9200"

ENTRYPOINT & 'C:\Program Files\Filebeat\filebeat.exe' -e

filebeat.yml:

filebeat.prospectors:

- input_type: log
  paths:
    - C:\sitecore-logs\log.*.txt
  tags: ["system"]
  json.keys_under_root: true
  json.add_error_key: true
  json.message_key: message

output.console:
  pretty: true

output.elasticsearch:
  hosts: '${ES_HOSTS}'
  index: "sitecore"

logging.level: debug

pbering · July 1, 2017, 11:18am

Part 2 (due to 7000 char limit on topics)

docker run

2017/07/01 10:57:06.811139 beat.go:285: INFO Home path: [C:\Program Files\Filebeat] Config path: [C:\Program Files\Filebeat] Data path: [C:\Program Files\Filebeat\data] Logs path: [C:\Program Files\Filebeat\logs]
2017/07/01 10:57:06.811139 beat.go:186: INFO Setup Beat: filebeat; Version: 5.4.3
2017/07/01 10:57:06.811139 metrics.go:23: INFO Metrics logging every 30s
2017/07/01 10:57:06.811139 processor.go:44: DBG  Processors:
2017/07/01 10:57:06.811139 beat.go:192: DBG  Initializing output plugins
2017/07/01 10:57:06.812139 output.go:258: INFO Loading template enabled. Reading template file: C:\Program Files\Filebeat\filebeat.template.json
2017/07/01 10:57:06.815140 output.go:269: INFO Loading template enabled for Elasticsearch 2.x. Reading template file: C:\Program Files\Filebeat\filebeat.template-es2x.json
2017/07/01 10:57:06.821140 output.go:281: INFO Loading template enabled for Elasticsearch 6.x. Reading template file: C:\Program Files\Filebeat\filebeat.template-es6x.json
2017/07/01 10:57:06.824140 client.go:123: INFO Elasticsearch url: http://elasticsearch:9200
2017/07/01 10:57:06.824140 outputs.go:108: INFO Activated elasticsearch as output plugin.
2017/07/01 10:57:06.824140 outputs.go:108: INFO Activated console as output plugin.
2017/07/01 10:57:06.824140 publish.go:238: DBG  Create output worker
2017/07/01 10:57:06.825153 publish.go:238: DBG  Create output worker
2017/07/01 10:57:06.825153 publish.go:280: DBG  No output is defined to store the topology. The server fields might not be filled.
2017/07/01 10:57:06.825153 publish.go:295: INFO Publisher name: 4b340fbf2cbf
2017/07/01 10:57:06.829139 async.go:63: INFO Flush Interval set to: 1s
2017/07/01 10:57:06.829139 async.go:64: INFO Max Bulk Size set to: 50
2017/07/01 10:57:06.829139 async.go:72: DBG  create bulk processing worker (interval=1s, bulk size=50)
2017/07/01 10:57:06.829139 async.go:63: INFO Flush Interval set to: 1s
2017/07/01 10:57:06.829139 async.go:64: INFO Max Bulk Size set to: 2048
2017/07/01 10:57:06.829139 async.go:72: DBG  create bulk processing worker (interval=1s, bulk size=2048)
2017/07/01 10:57:06.838140 beat.go:221: INFO filebeat start running.
2017/07/01 10:57:06.838140 registrar.go:68: INFO No registry file found under: C:\Program Files\Filebeat\data\registry. Creating a new registry file.
2017/07/01 10:57:06.838140 registrar.go:298: DBG  Write registry file: C:\Program Files\Filebeat\data\registry
2017/07/01 10:57:06.838140 file_windows.go:58: DBG  delete old: remove C:\Program Files\Filebeat\data\registry.old: The system cannot find the file specified.
2017/07/01 10:57:06.838140 file_windows.go:62: DBG  rotate to old: rename C:\Program Files\Filebeat\data\registry C:\Program Files\Filebeat\data\registry.old: The system cannot find the file specified.
2017/07/01 10:57:06.838140 registrar.go:323: DBG  Registry file updated. 0 states written.
2017/07/01 10:57:06.838140 registrar.go:106: INFO Loading registrar data from C:\Program Files\Filebeat\data\registry
2017/07/01 10:57:06.838140 registrar.go:123: INFO States Loaded from registrar: 0
2017/07/01 10:57:06.839141 service_windows.go:51: DBG  Windows is interactive: false
2017/07/01 10:57:06.839141 spooler.go:63: INFO Starting spooler: spool_size: 2048; idle_timeout: 5s
2017/07/01 10:57:06.839141 registrar.go:236: INFO Starting Registrar
2017/07/01 10:57:06.839141 sync.go:41: INFO Start sending events to output
2017/07/01 10:57:06.838140 crawler.go:38: INFO Loading Prospectors: 1
2017/07/01 10:57:06.839141 prospector.go:83: DBG  File Configs: [C:\sitecore-logs\log.*.txt]
2017/07/01 10:57:06.839141 prospector_log.go:44: DBG  exclude_files: []
2017/07/01 10:57:06.839141 prospector_log.go:65: INFO Prospector with previous states loaded: 0
2017/07/01 10:57:06.839141 prospector.go:124: INFO Starting prospector of type: log; id: 7549741024783683116
2017/07/01 10:57:06.839141 crawler.go:58: INFO Loading and starting Prospectors completed. Enabled prospectors: 1
2017/07/01 10:57:06.839141 prospector_log.go:70: DBG  Start next scan
2017/07/01 10:57:06.840154 service_windows.go:59: ERR Error: The service process could not connect to the service controller.
2017/07/01 10:57:06.841161 prospector.go:232: INFO Stopping Prospector: 7549741024783683116
2017/07/01 10:57:06.841161 prospector.go:134: INFO Prospector channel stopped
panic: runtime error: slice bounds out of range

goroutine 42 [running]:
panic(0x952260, 0xc042014020)
        /usr/local/go/src/runtime/panic.go:500 +0x1af
syscall.Readlink(0xc042148b20, 0x10, 0xc042248380, 0x80, 0x80, 0x0, 0x0, 0x0)
        /usr/local/go/src/syscall/syscall_windows.go:1031 +0x3a9
os.Readlink(0xc042148b20, 0x10, 0xca6fe0, 0xc04225a000, 0x0, 0x0)
        /usr/local/go/src/os/file_posix.go:21 +0x94
os.Stat(0xc042148b20, 0x10, 0x10, 0x0, 0x0, 0x41fee34a)
        /usr/local/go/src/os/stat_windows.go:72 +0x9e
path/filepath.glob(0xc042148b20, 0x10, 0xc042148b31, 0x9, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /usr/local/go/src/path/filepath/match.go:307 +0xeb
path/filepath.Glob(0xc042148b20, 0x1a, 0xc0422396b0, 0x0, 0xc0422396b0, 0x0, 0x0)
        /usr/local/go/src/path/filepath/match.go:250 +0x379
github.com/elastic/beats/filebeat/prospector.(*ProspectorLog).getFiles(0xc042248280, 0x7e1)
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector_log.go:124 +0xf8
github.com/elastic/beats/filebeat/prospector.(*ProspectorLog).scan(0xc042248280)
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector_log.go:212 +0xa0
github.com/elastic/beats/filebeat/prospector.(*ProspectorLog).Run(0xc042248280)
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector_log.go:85 +0xd9
github.com/elastic/beats/filebeat/prospector.(*Prospector).Run(0xc04206f200)
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector.go:170 +0x56
github.com/elastic/beats/filebeat/prospector.(*Prospector).Start.func2(0xc04206f200)
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector.go:161 +0x58
created by github.com/elastic/beats/filebeat/prospector.(*Prospector).Start
        /go/src/github.com/elastic/beats/filebeat/prospector/prospector.go:162 +0x1a8

pbering · July 1, 2017, 11:24am

Part 3

docker version

Client:
 Version:      17.06.0-ce
 API version:  1.30
 Go version:   go1.8.3
 Git commit:   02c1d87
 Built:        Fri Jun 23 21:30:30 2017
 OS/Arch:      windows/amd64

Server:
 Version:      17.06.0-ce
 API version:  1.30 (minimum version 1.24)
 Go version:   go1.8.3
 Git commit:   02c1d87
 Built:        Fri Jun 23 22:19:00 2017
 OS/Arch:      windows/amd64
 Experimental: true

on WIndows 10 Enterprise Creators Update...

pbering · July 1, 2017, 4:40pm

I found out that the panic error is fixed in GoLang 1.9 beta 2 so I compiled a new exe that now works inside a Windows based container

StefanScherer · July 1, 2017, 4:41pm

Glad it worked with Golang 1.9 beta2. Any plan to share the Windows docker image?

pbering · July 2, 2017, 6:18pm

Properly will, just need to split out my implementation details from what could be useful for others

system · July 31, 2017, 3:16am

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