Set up:
- Kubernetes pod saves the log file on host machine at location /var/log/app_logs
- Filebeat 8.16.2 is configured as Daemonset to read from logfile and enrich the data
Filebeat.yml
filebeat.inputs:
- type: filestream
enabled: true
id: logs
paths:
- /var/log/app_logs/*/*.json # Custom log path
parsers:
- ndjson: # Parse JSON logs
target: "" # Merge JSON fields into the root
add_error_key: true # Add an error field if parsing fails
symlinks: true # Follow symlinks to log files
processors:
- add_kubernetes_metadata:
host: ${NODE_NAME} # Use the Kubernetes node name
default_indexers.enabled: false # Disable default indexers
default_matchers.enabled: false # Disable default matchers
indexers:
- ip_port: {} # Use the IP:port indexer
matchers:
- fields:
# Match logs based on the server IP field
lookup_fields: ["serverIP"]
# Output to Logstash
output.logstash:
hosts: ["logstash:5044"]
logging.level: debug # Enable debug logging for troubleshooting
logging.selectors: ["add_kubernetes_metadata", "kubernetes"]
App logs messages (Every one hour):
{"timestamp":"2024-12-18T14:47:02.459Z","level":"info","message":"Deleted 0 documents older than 30 days","serverIP":"10.42.220.231","version":"199c3a35",}
{"timestamp":"2024-12-18T15:47:02.459Z","level":"info","message":"Deleted 0 documents older than 30 days","serverIP":"10.42.220.231","version":"199c3a35"}
Message in filebeat debug logs on console:
2024-12-18T00:21:08.967525107-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T08:21:08.967Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T00:30:12.982235626-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T08:30:12.981Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T00:52:08.964461336-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T08:52:08.964Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T01:52:08.970823308-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T09:52:08.970Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T02:52:08.978094473-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T10:52:08.977Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T03:52:08.981683527-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T11:52:08.981Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T04:52:08.975535261-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T12:52:08.975Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T05:52:09.025519658-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T13:52:09.025Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T06:52:09.011829167-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T14:52:09.011Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T07:52:09.001376786-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T15:52:09.001Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T08:53:53.024873037-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T16:53:53.024Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T09:18:23.065093718-08:00 stderr F {"log.level":"info","@timestamp":"2024-12-18T17:18:23.064Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).readFromSource","file.name":"filestream/input.go","file.line":370},"message":"Reader was closed. Closing. Path='/var/log/app_logs/app1-staging/app1.json'","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
Additional Info:
- When the API is it, it prints some other log messages and that are sent across, although I have seen cases it is missed in cases the API access was after long time
- When I change the logic to dump the log message every 5 secs, it correctly pushes the message
Update:
- With full debug log, I am seeing it does detect an activity around the scan time. Event logged at 10:08:54 and filebeat debug log has logs from 10:09:01, about file updates
Filebeat debug logs on a new event
2024-12-18T10:09:01.204659854-08:00 stderr F {"log.level":"debug","@timestamp":"2024-12-18T18:09:01.204Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*fileProspector).onFSEvent","file.name":"filestream/prospector.go","file.line":186},"message":"File /var/log/app_logs/app1-staging/app1.json has been updated","service.name":"filebeat","id":"logs","prospector":"file_prospector","operation":"write","source_name":"native::1179763-64768","os_id":"1179763-64768","new_path":"/var/log/app_logs/app1-staging/app1.json","old_path":"/var/log/app_logs/app1-staging/app1.json","ecs.version":"1.6.0"}
2024-12-18T10:09:01.20466341-08:00 stderr F {"log.level":"debug","@timestamp":"2024-12-18T18:09:01.204Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream/internal/input-logfile.(*defaultHarvesterGroup).Start","file.name":"input-logfile/harvester.go","file.line":140},"message":"Starting harvester for file","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T10:09:01.204968147-08:00 stderr F {"log.level":"debug","@timestamp":"2024-12-18T18:09:01.204Z","log.logger":"processors","log.origin":{"function":"github.com/elastic/beats/v7/libbeat/processors.New","file.name":"processors/processor.go","file.line":114},"message":"Generated new processors: add_kubernetes_metadata","service.name":"filebeat","ecs.version":"1.6.0"}
2024-12-18T10:09:01.20505032-08:00 stderr F {"log.level":"debug","@timestamp":"2024-12-18T18:09:01.204Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*filestream).open","file.name":"filestream/input.go","file.line":208},"message":"newLogFileReader with config.MaxBytes:10485760","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
2024-12-18T10:09:01.205292694-08:00 stderr F {"log.level":"debug","@timestamp":"2024-12-18T18:09:01.205Z","log.logger":"input.filestream","log.origin":{"function":"github.com/elastic/beats/v7/filebeat/input/filestream.(*logFile).Read","file.name":"filestream/filestream.go","file.line":131},"message":"End of file reached: /var/log/app_logs/app1-staging/app1.json; Backoff now.","service.name":"filebeat","id":"logs","source_file":"filestream::logs::native::1179763-64768","path":"/var/log/app_logs/app1-staging/app1.json","state-id":"native::1179763-64768","ecs.version":"1.6.0"}
Update 2:
- I have verified the logs.json registry file, every time a new line is added per hour, it seems the new offset value is added in the file that is exactly for that line, but no event is pushed