Filebeat stops harvesting logs
- Dominant language
- Go
- Stars
- 12.7k
- Forks
- 5k
- Avg merge
- 2d 15m
- Merged PRs (30d)
- 385
Description
1. Filebeat harvested logs correctly
2. Restarted logstash
3. New logs appear in Kibana
4. After some time, logs are not being harvested from a docker container, although new log entries are written to file
Note that logstash correctly receives logs from other containers harvested by filebeat.
Filebeat harvester didn't recover even after a few hours.
Filebeat configuration:
```
output.logstash:
hosts: ["logstash:5044"]
setup.kibana.host: http://kibana:5601
filebeat.autodiscover:
providers:
- type: docker
hints.enabled: true
```
Docker compose service:
```
web:
image: app:latest
expose:
- 80
labels:
co.elastic.logs/multiline.pattern: '^[[:space:]]+(at|\\.{3})\\b|^Caused by:'
co.elastic.logs/multiline.negate: false
co.elastic.logs/multiline.match: after
app: web
environment:
ELASTIC_APM_SERVER_URLS: http://apm:8200
```
My docker container that is not being harvested has id: **3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c**
This container was also restarted at **2019-09-11 15:19:03,983**.
Last log entry correctly processed has timestamp **2019-09-11 15:19:37,235**.
Next log entry with timestamp **2019-09-11 15:20:15,276** and next ones are missing.
Filebeat relevant log:
```
2019-09-11T15:19:57.988Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":28150,"time":{"ms":120}},"total":{"ticks":54510,"time":{"ms":150},"value":54510},"user":{"ticks":26360,"time":{"ms":30}}},"handles":{"limit":{"hard":1048576,"soft":1048576},"open":13},"info":{"ephemeral_id":"17c964bc-009e-4840-89b6-4b9c511cdf14","uptime":{"ms":15900511}},"memstats":{"gc_next":8939216,"memory_alloc":4663776,"memory_total":6966547888},"runtime":{"goroutines":93}},"filebeat":{"events":{"active":-2,"added":114,"done":116},"harvester":{"open_files":5,"running":5}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":116,"batches":13,"total":116},"read":{"bytes":78},"write":{"bytes":31559}},"pipeline":{"clients":8,"events":{"active":0,"published":114,"total":114},"queue":{"acked":116}}},"registrar":{"states":{"current":10,"update":116},"writes":{"success":13,"total":13}},"system":{"load":{"1":1.19,"15":0.58,"5":0.86,"norm":{"1":0.2975,"15":0.145,"5":0.215}}}}}}
2019-09-11T15:20:04.554Z INFO input/input.go:149 input ticker stopped
2019-09-11T15:20:04.554Z INFO input/input.go:167 Stopping Input: 9894227653855818847
2019-09-11T15:20:04.554Z INFO log/harvester.go:274 Reader was closed: /var/lib/docker/containers/3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c/3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c-json.log. Closing.
2019-09-11T15:20:27.995Z INFO [monitoring] log/log.go:145 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":28160,"time":{"ms":10}},"total":{"ticks":54610,"time":{"ms":100},"value":54610},"user":{"ticks":26450,"time":{"ms":90}}},"handles":{"limit":{"hard":1048576,"soft":1048576},"open":12},"info":{"ephemeral_id":"17c964bc-009e-4840-89b6-4b9c511cdf14","uptime":{"ms":15930517}},"memstats":{"gc_next":5878912,"memory_alloc":7557664,"memory_total":6986384152,"rss":-2998272},"runtime":{"goroutines":82}},"filebeat":{"events":{"added":31,"done":31},"harvester":{"closed":1,"open_files":4,"running":4}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":30,"batches":12,"total":30},"read":{"bytes":72},"write":{"bytes":17806}},"pipeline":{"clients":7,"events":{"active":0,"filtered":1,"published":30,"total":31},"queue":{"acked":30}}},"registrar":{"states":{"current":10,"update":31},"writes":{"success":13,"total":13}},"system":{"load":{"1":1.24,"15":0.6,"5":0.89,"norm":{"1":0.31,"15":0.15,"5":0.2225}}}}}}
```
Logstash restarted timeline log:
```
[2019-09-11T15:16:36,298][INFO ][logstash.runner ] Starting Logstash {"logstash.version"=>"7.3.0"}
..................
[2019-09-11T15:16:45,397][INFO ][logstash.agent ] Successfully started Logstash API endpoint {:port=>9600}
```
Filebeat repository entry:
```
{
"source": "/var/lib/docker/containers/3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c/3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c-json.log",
"offset": 794342,
"timestamp": "2019-09-11T15:20:04.5542604Z",
"ttl": -1,
"type": "container",
"meta": null,
"FileStateOS": {
"inode": 802588,
"device": 2049
}
}
```
Log file stats:
```
sh-4.2# stat 3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c-json.log
File: '3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c-json.log'
Size: 911932 Blocks: 1784 IO Block: 4096 regular file
Device: 801h/2049d Inode: 802588 Links: 1
Access: (0640/-rw-r-----) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2019-09-11 17:39:48.711393000 +0000
Modify: 2019-09-11 17:19:37.112086700 +0000
Change: 2019-09-11 17:19:37.112086700 +0000
Birth: -
```
Hope I provided enough details to investigate this problem.
----------------------
Elastic stack 7.3.0
Contributor guide
Research direction
Start by reproducing the failure with the Filebeat 7.3.0 Docker autodiscover configuration and inspect the harvester log, registry entry, and container log path for container 3252b7646a23293b6728941769f0412e2bd4b74b801ee09ab747c7cdfa74550c. The report names no source file or test; done means identifying why harvesting stops after the container restart and verifying recovery for subsequent log entries.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- docker
- Domain
- devops, observability-sre
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 35/100