[BUG] filebeat becomes totally unreliable with --once option

Elastic Stack Beats
1

Hi,
by using a config as simple as this one:

filebeat.inputs:

# filestream is an input for collecting log messages from files.
- type: filestream
  id: "test"
  enabled: true
  paths:
  - /home/krs/elasticsearch/*.log

output.console:
  pretty: true

with 2 simple and small files access.log and access2.log in the configured path, each one with less than 10 lines.

By executing this command:

filebeat -e --path.data /home/krs/elasticsearch/ -c /home/krs/elasticsearch/filebeat.yml --once

no events are sent to the console, and only after re-issung this command a random number of times, it will eventually work.
For example, after deleting the registry folder, this is what I got after 3 runs:

cat registry/filebeat/log.json
{"op":"set","id":1}
{"k":"filestream::test::native::270387460-64768","v":{"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":0,"updated":[281470681743360,18446744011573954816]}}
{"op":"set","id":2}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"}}}

And no events printed to the console.

Only after 14 attempts, I managed to get the events picked up, and cursor is no longer null in the log.


cat registry/filebeat/log.json
{"op":"set","id":1}
{"k":"filestream::test::native::270387460-64768","v":{"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":0,"updated":[281470681743360,18446744011573954816]}}
{"op":"set","id":2}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"}}}
{"op":"set","id":3}
{"k":"filestream::test::native::270387460-64768","v":{"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":1800000000000}}
{"op":"set","id":4}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"}}}
{"op":"set","id":5}
{"k":"filestream::test::native::270387460-64768","v":{"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null}}
{"op":"set","id":6}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"}}}
{"op":"set","id":7}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"}}}
{"op":"set","id":8}
{"k":"filestream::test::native::270387460-64768","v":{"ttl":1800000000000,"updated":[515421177449,1650903261],"cursor":null,"meta":{"identifier_name":"native","source":"/home/krs/elasticsearch/access.log"}}}
{"op":"set","id":9}
{"k":"filestream::test::native::270387460-64768","v":{"cursor":null,"meta":{"identifier_name":"native","source":"/home/krs/elasticsearch/access.log"},"ttl":1800000000000,"updated":[515421177449,1650903261]}}
{"op":"set","id":10}
{"k":"filestream::test::native::270387460-64768","v":{"cursor":null,"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":1800000000000,"updated":[515421177449,1650903261]}}
{"op":"set","id":11}
{"k":"filestream::test::native::270387458-64768","v":{"meta":{"source":"/home/krs/elasticsearch/access2.log","identifier_name":"native"},"ttl":0,"updated":[281470681743360,18446744011573954816],"cursor":null}}
{"op":"set","id":12}
{"k":"filestream::test::native::270387458-64768","v":{"meta":{"source":"/home/krs/elasticsearch/access2.log","identifier_name":"native"},"ttl":1800000000000,"updated":[515443920140,1650903373],"cursor":null}}
{"op":"set","id":13}
{"k":"filestream::test::native::270387460-64768","v":{"updated":[515444304620,1650903373],"cursor":{"offset":109},"meta":{"source":"/home/krs/elasticsearch/access.log","identifier_name":"native"},"ttl":1800000000000}}
{"op":"set","id":14}
{"k":"filestream::test::native::270387458-64768","v":{"cursor":{"offset":109},"meta":{"source":"/home/krs/elasticsearch/access2.log","identifier_name":"native"},"ttl":1800000000000,"updated":[515444137874,1650903373]}}
2

Hello @kRs , welcome to the Elastic community

Harvesting the files and sending to the output happens in an asynchronous way, and until the output is not acked the cursor is not updated.

Could you try to enable debug logs and share the output?

3

yes, I had imagined something like that, some sort of async operation not being correctly waited for, or some race conditions, and something alike. The problem is that, since I'm using the --once flag, it should be able to wait for the scanning to complete, as every time I re-issue the command, the previous one has already exited. By the way, the 'log' input it is waiting properly, and from what I've seen so far, it works reliably.

This said:

NO-OP execution:

filebeat -e --path.data /home/krs/elasticsearch/ -c /home/krs/elasticsearch/filebeat.yml --once
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.656+0200","log.origin":{"file.name":"instance/beat.go","file.line":669},"message":"Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/home/krs/elasticsearch/] Logs path: [/var/log/filebeat]","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.656+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":727},"message":"Beat metadata path: /home/krs/elasticsearch/meta.json","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.656+0200","log.origin":{"file.name":"instance/beat.go","file.line":677},"message":"Beat ID: 92799431-ee13-4df4-8809-24038ecf062e","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.657+0200","log.logger":"seccomp","log.origin":{"file.name":"seccomp/seccomp.go","file.line":117},"message":"Loading syscall filter","service.name":"filebeat","seccomp_filter":{"no_new_privs":true,"flag":"tsync","policy":{"default_action":"errno","syscalls":[{"names":["accept","accept4","access","arch_prctl","bind","brk","chmod","chown","clock_gettime","clone","clone3","close","connect","dup","dup2","epoll_create","epoll_create1","epoll_ctl","epoll_pwait","epoll_wait","exit","exit_group","fchdir","fchmod","fchmodat","fchown","fchownat","fcntl","fdatasync","flock","fstat","fstatfs","fsync","ftruncate","futex","getcwd","getdents","getdents64","geteuid","getgid","getpeername","getpid","getppid","getrandom","getrlimit","getrusage","getsockname","getsockopt","gettid","gettimeofday","getuid","inotify_add_watch","inotify_init1","inotify_rm_watch","ioctl","kill","listen","lseek","lstat","madvise","mincore","mkdirat","mmap","mprotect","munmap","nanosleep","newfstatat","open","openat","pipe","pipe2","poll","ppoll","pread64","pselect6","pwrite64","read","readlink","readlinkat","recvfrom","recvmmsg","recvmsg","rename","renameat","rseq","rt_sigaction","rt_sigprocmask","rt_sigreturn","sched_getaffinity","sched_yield","sendfile","sendmmsg","sendmsg","sendto","set_robust_list","setitimer","setsockopt","shutdown","sigaltstack","socket","splice","stat","statfs","sysinfo","tgkill","time","tkill","uname","unlink","unlinkat","wait4","waitid","write","writev"],"action":"allow"}]}},"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.657+0200","log.logger":"seccomp","log.origin":{"file.name":"seccomp/seccomp.go","file.line":124},"message":"Syscall filter successfully installed","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.657+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1047},"message":"Beat info","service.name":"filebeat","system_info":{"beat":{"path":{"config":"/etc/filebeat","data":"/home/krs/elasticsearch","home":"/usr/share/filebeat","logs":"/var/log/filebeat"},"type":"filebeat","uuid":"92799431-ee13-4df4-8809-24038ecf062e"},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.657+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1056},"message":"Build info","service.name":"filebeat","system_info":{"build":{"commit":"271435c21bfd4e2e621d87c04f4b815980626978","libbeat":"8.1.3","time":"2022-04-19T09:29:51.000Z","version":"8.1.3"},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.657+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1059},"message":"Go runtime info","service.name":"filebeat","system_info":{"go":{"os":"linux","arch":"amd64","max_procs":2,"version":"go1.17.8"},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.658+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1063},"message":"Host info","service.name":"filebeat","system_info":{"host":{"architecture":"x86_64","boot_time":"2022-04-24T01:54:08+02:00","containerized":false,"name":"centos7-kvm-dev","ip":["127.0.0.1/8","::1/128","192.168.1.11/24","fe80::5cb1:9741:5423:5ebe/64"],"kernel_version":"3.10.0-1127.8.2.el7.x86_64","mac":["52:54:00:62:00:e9"],"os":{"type":"linux","family":"redhat","platform":"centos","name":"CentOS Linux","version":"7 (Core)","major":7,"minor":5,"patch":1804,"codename":"Core"},"timezone":"CEST","timezone_offset_sec":7200,"id":"5ada7d2edf15474c9e3a1e3c0af9b055"},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.658+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1092},"message":"Process info","service.name":"filebeat","system_info":{"process":{"capabilities":{"inheritable":null,"permitted":null,"effective":null,"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend"],"ambient":null},"cwd":"/home/krs/elasticsearch","exe":"/usr/share/filebeat/bin/filebeat","name":"filebeat","pid":18107,"ppid":16952,"seccomp":{"mode":"filter","no_new_privs":true},"start_time":"2022-04-26T10:16:02.760+0200"},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.658+0200","log.origin":{"file.name":"instance/beat.go","file.line":323},"message":"Setup Beat: filebeat; Version: 8.1.3","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.659+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":351},"message":"Initializing output plugins","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.659+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/consumer.go","file.line":98},"message":"start pipeline event consumer","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.659+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/module.go","file.line":113},"message":"Beat name: centos7-kvm-dev","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.659+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/queue_reader.go","file.line":48},"message":"pipeline event consumer queue reader: start","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.660+0200","log.origin":{"file.name":"fileset/modules.go","file.line":103},"message":"Enabled modules/filesets:  ()","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2022-04-26T10:16:03.661+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":168},"message":"Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":142},"message":"Starting metrics logging every 30s","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.661+0200","log.origin":{"file.name":"instance/beat.go","file.line":489},"message":"filebeat start running.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile(/home/krs/elasticsearch/registry) -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile() -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":297},"message":"isDir(/home/krs/elasticsearch/registry/filebeat) -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/migrate.go","file.line":84},"message":"Registry type '' found","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.661+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile(.bak) -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.726+0200","log.origin":{"file.name":"memlog/store.go","file.line":119},"message":"Loading data file of '/home/krs/elasticsearch/registry/filebeat' succeeded. Active transaction id=0","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.726+0200","log.origin":{"file.name":"memlog/store.go","file.line":124},"message":"Finished loading transaction log file for '/home/krs/elasticsearch/registry/filebeat'. Active transaction id=0","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"warn","@timestamp":"2022-04-26T10:16:03.727+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":285},"message":"Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.727+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":82},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":83},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":88},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":89},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":90},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":109},"message":"States Loaded from registrar: 0","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":71},"message":"Loading Inputs: 1","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.728+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":117},"message":"starting input, keys present on the config: [filebeat.inputs.0.close_eof filebeat.inputs.0.enabled filebeat.inputs.0.id filebeat.inputs.0.paths.0 filebeat.inputs.0.type]","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.730+0200","log.logger":"scanner","log.origin":{"file.name":"filestream/fswatch.go","file.line":278},"message":"recursive glob enabled","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.731+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":148},"message":"Starting input (ID: 16017456397865473365)","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.731+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":106},"message":"Loading and starting Inputs completed. Enabled inputs: 1","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.729+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":140},"message":"Starting Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.731+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":111},"message":"Input filestream starting","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.731+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":133},"message":"Starting prospector","service.name":"filebeat","id":"test","prospector":"file_prospector","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.731+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":351},"message":"Running filebeat once. Waiting for completion ...","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":353},"message":"All data collection completed. Shutting down.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.origin":{"file.name":"beater/crawler.go","file.line":155},"message":"Stopping Crawler","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.origin":{"file.name":"beater/crawler.go","file.line":165},"message":"Stopping 1 inputs","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":170},"message":"Stopping input: 16017456397865473365","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":132},"message":"Input 'filestream' stopped","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.origin":{"file.name":"beater/crawler.go","file.line":185},"message":"Crawler stopped","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.732+0200","log.logger":"file_watcher","log.origin":{"file.name":"filestream/fswatch.go","file.line":138},"message":"Start next scan","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.733+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":180},"message":"A new file /home/krs/elasticsearch/access.log has been found","service.name":"filebeat","id":"test","prospector":"file_prospector","operation":"create","source_name":"path::/home/krs/elasticsearch/access.log","os_id":"270387461-64768","new_path":"/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.733+0200","log.logger":"input.filestream","log.origin":{"file.name":"input-logfile/harvester.go","file.line":145},"message":"Starting harvester for file","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.734+0200","log.origin":{"file.name":"beater/signalwait.go","file.line":93},"message":"Continue shutdown: All enqueued events being published.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.734+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":132},"message":"Stopping Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.734+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":166},"message":"Ending Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.734+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":167},"message":"Stopping Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.734+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":137},"message":"Registrar stopped","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2022-04-26T10:16:03.735+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":165},"message":"Prospector has stopped","service.name":"filebeat","id":"test","prospector":"file_prospector","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.736+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":124},"message":"Input 'filestream' stopped","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.772+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":192},"message":"Total metrics","service.name":"filebeat","monitoring":{"metrics":{"beat":{"cpu":{"system":{"ticks":60,"time":{"ms":67}},"total":{"ticks":170,"time":{"ms":181},"value":170},"user":{"ticks":110,"time":{"ms":114}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":9},"info":{"ephemeral_id":"317e0594-a084-48f9-9fd3-21846ba801e0","uptime":{"ms":176},"version":"8.1.3"},"memstats":{"gc_next":16506912,"memory_alloc":13415712,"memory_sys":32850952,"memory_total":50600784,"rss":104730624},"runtime":{"goroutines":16}},"filebeat":{"events":{"active":0,"added":0,"done":0},"harvester":{"closed":0,"open_files":0,"running":0,"skipped":0,"started":0},"input":{"log":{"files":{"renamed":0,"truncated":0}},"netflow":{"flows":0,"packets":{"dropped":0,"received":0}}}},"libbeat":{"config":{"module":{"running":0,"starts":0,"stops":0},"reloads":0,"scans":0},"output":{"events":{"acked":0,"active":0,"batches":0,"dropped":0,"duplicates":0,"failed":0,"toomany":0,"total":0},"read":{"bytes":0,"errors":0},"type":"console","write":{"bytes":0,"errors":0}},"pipeline":{"clients":0,"events":{"active":0,"dropped":0,"failed":0,"filtered":0,"published":0,"retry":0,"total":0},"queue":{"acked":0,"max_events":4096}}},"registrar":{"states":{"cleanup":0,"current":0,"update":0},"writes":{"fail":0,"success":0,"total":0}},"system":{"cpu":{"cores":2},"load":{"1":0.01,"15":0.05,"5":0.02,"norm":{"1":0.005,"15":0.025,"5":0.01}}}},"ecs.version":"1.6.0"}}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.773+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":193},"message":"Uptime: 176.808199ms","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.773+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":160},"message":"Stopping metrics logging.","service.name":"filebeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2022-04-26T10:16:03.774+0200","log.origin":{"file.name":"instance/beat.go","file.line":494},"message":"filebeat stopped.","service.name":"filebeat","ecs.version":"1.6.0"}

I will follow up in another msg, as I'm running out of space :slight_smile:

4

so, this is what happened when it finally succeeded:

(I stripped out "log.level" at the beginning of each line, otherwise I was still out of space for the msg)

10:19:00 [krs@centos7-kvm-dev +1] [~/elasticsearch]$ filebeat -e --path.data /home/krs/elasticsearch/ -c /home/krs/elasticsearch/filebeat.yml --once
{"info","@timestamp":"2022-04-26T10:19:01.376+0200","log.origin":{"file.name":"instance/beat.go","file.line":669},"message":"Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/home/krs/elasticsearch/] Logs path: [/var/log/filebeat]","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.376+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":727},"message":"Beat metadata path: /home/krs/elasticsearch/meta.json","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.376+0200","log.origin":{"file.name":"instance/beat.go","file.line":677},"message":"Beat ID: 92799431-ee13-4df4-8809-24038ecf062e","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.376+0200","log.logger":"seccomp","log.origin":{"file.name":"seccomp/seccomp.go","file.line":117},"message":"Loading syscall filter","service.name":"filebeat","seccomp_filter":{"no_new_privs":true,"flag":"tsync","policy":{"default_action":"errno","syscalls":[{"names":["accept","accept4","access","arch_prctl","bind","brk","chmod","chown","clock_gettime","clone","clone3","close","connect","dup","dup2","epoll_create","epoll_create1","epoll_ctl","epoll_pwait","epoll_wait","exit","exit_group","fchdir","fchmod","fchmodat","fchown","fchownat","fcntl","fdatasync","flock","fstat","fstatfs","fsync","ftruncate","futex","getcwd","getdents","getdents64","geteuid","getgid","getpeername","getpid","getppid","getrandom","getrlimit","getrusage","getsockname","getsockopt","gettid","gettimeofday","getuid","inotify_add_watch","inotify_init1","inotify_rm_watch","ioctl","kill","listen","lseek","lstat","madvise","mincore","mkdirat","mmap","mprotect","munmap","nanosleep","newfstatat","open","openat","pipe","pipe2","poll","ppoll","pread64","pselect6","pwrite64","read","readlink","readlinkat","recvfrom","recvmmsg","recvmsg","rename","renameat","rseq","rt_sigaction","rt_sigprocmask","rt_sigreturn","sched_getaffinity","sched_yield","sendfile","sendmmsg","sendmsg","sendto","set_robust_list","setitimer","setsockopt","shutdown","sigaltstack","socket","splice","stat","statfs","sysinfo","tgkill","time","tkill","uname","unlink","unlinkat","wait4","waitid","write","writev"],"action":"allow"}]}},"ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.376+0200","log.logger":"seccomp","log.origin":{"file.name":"seccomp/seccomp.go","file.line":124},"message":"Syscall filter successfully installed","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.376+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1047},"message":"Beat info","service.name":"filebeat","system_info":{"beat":{"path":{"config":"/etc/filebeat","data":"/home/krs/elasticsearch","home":"/usr/share/filebeat","logs":"/var/log/filebeat"},"type":"filebeat","uuid":"92799431-ee13-4df4-8809-24038ecf062e"},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:01.376+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1056},"message":"Build info","service.name":"filebeat","system_info":{"build":{"commit":"271435c21bfd4e2e621d87c04f4b815980626978","libbeat":"8.1.3","time":"2022-04-19T09:29:51.000Z","version":"8.1.3"},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:01.377+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1059},"message":"Go runtime info","service.name":"filebeat","system_info":{"go":{"os":"linux","arch":"amd64","max_procs":2,"version":"go1.17.8"},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:01.377+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1063},"message":"Host info","service.name":"filebeat","system_info":{"host":{"architecture":"x86_64","boot_time":"2022-04-24T01:54:08+02:00","containerized":false,"name":"centos7-kvm-dev","ip":["127.0.0.1/8","::1/128","192.168.1.11/24","fe80::5cb1:9741:5423:5ebe/64"],"kernel_version":"3.10.0-1127.8.2.el7.x86_64","mac":["52:54:00:62:00:e9"],"os":{"type":"linux","family":"redhat","platform":"centos","name":"CentOS Linux","version":"7 (Core)","major":7,"minor":5,"patch":1804,"codename":"Core"},"timezone":"CEST","timezone_offset_sec":7200,"id":"5ada7d2edf15474c9e3a1e3c0af9b055"},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:01.378+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":1092},"message":"Process info","service.name":"filebeat","system_info":{"process":{"capabilities":{"inheritable":null,"permitted":null,"effective":null,"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend"],"ambient":null},"cwd":"/home/krs/elasticsearch","exe":"/usr/share/filebeat/bin/filebeat","name":"filebeat","pid":18496,"ppid":16952,"seccomp":{"mode":"filter","no_new_privs":true},"start_time":"2022-04-26T10:19:00.480+0200"},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:01.378+0200","log.origin":{"file.name":"instance/beat.go","file.line":323},"message":"Setup Beat: filebeat; Version: 8.1.3","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.378+0200","log.logger":"beat","log.origin":{"file.name":"instance/beat.go","file.line":351},"message":"Initializing output plugins","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.378+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/consumer.go","file.line":98},"message":"start pipeline event consumer","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.379+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/module.go","file.line":113},"message":"Beat name: centos7-kvm-dev","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.379+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/queue_reader.go","file.line":48},"message":"pipeline event consumer queue reader: start","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.379+0200","log.origin":{"file.name":"fileset/modules.go","file.line":103},"message":"Enabled modules/filesets:  ()","service.name":"filebeat","ecs.version":"1.6.0"}
{"warn","@timestamp":"2022-04-26T10:19:01.380+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":168},"message":"Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":142},"message":"Starting metrics logging every 30s","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.380+0200","log.origin":{"file.name":"instance/beat.go","file.line":489},"message":"filebeat start running.","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile(/home/krs/elasticsearch/registry) -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile() -> false","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":297},"message":"isDir(/home/krs/elasticsearch/registry/filebeat) -> true","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"test","log.origin":{"file.name":"registrar/migrate.go","file.line":304},"message":"isFile(/home/krs/elasticsearch/registry/filebeat/meta.json) -> true","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.380+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/migrate.go","file.line":84},"message":"Registry type '1' found","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.380+0200","log.origin":{"file.name":"memlog/store.go","file.line":119},"message":"Loading data file of '/home/krs/elasticsearch/registry/filebeat' succeeded. Active transaction id=0","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.381+0200","log.origin":{"file.name":"memlog/store.go","file.line":124},"message":"Finished loading transaction log file for '/home/krs/elasticsearch/registry/filebeat'. Active transaction id=14","service.name":"filebeat","ecs.version":"1.6.0"}
{"warn","@timestamp":"2022-04-26T10:19:01.381+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":285},"message":"Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform request:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform response:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:append","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:delete","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/transform_registry.go","file.line":75},"message":"Register transform pagination:set","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":82},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":83},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":88},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":89},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"httpjson.transforms","log.origin":{"file.name":"httpjson/encoding.go","file.line":90},"message":"<nil>","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":109},"message":"States Loaded from registrar: 0","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":71},"message":"Loading Inputs: 1","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":117},"message":"starting input, keys present on the config: [filebeat.inputs.0.close_eof filebeat.inputs.0.enabled filebeat.inputs.0.id filebeat.inputs.0.paths.0 filebeat.inputs.0.type]","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.381+0200","log.logger":"scanner","log.origin":{"file.name":"filestream/fswatch.go","file.line":278},"message":"recursive glob enabled","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":148},"message":"Starting input (ID: 16017456397865473365)","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":106},"message":"Loading and starting Inputs completed. Enabled inputs: 1","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":140},"message":"Starting Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":111},"message":"Input filestream starting","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":133},"message":"Starting prospector","service.name":"filebeat","id":"test","prospector":"file_prospector","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"file_watcher","log.origin":{"file.name":"filestream/fswatch.go","file.line":138},"message":"Start next scan","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":180},"message":"A new file /home/krs/elasticsearch/access.log has been found","service.name":"filebeat","id":"test","prospector":"file_prospector","operation":"create","source_name":"path::/home/krs/elasticsearch/access.log","os_id":"270387461-64768","new_path":"/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"input-logfile/harvester.go","file.line":145},"message":"Starting harvester for file","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":180},"message":"A new file /home/krs/elasticsearch/access2.log has been found","service.name":"filebeat","id":"test","prospector":"file_prospector","operation":"create","source_name":"path::/home/krs/elasticsearch/access2.log","os_id":"270387460-64768","new_path":"/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.382+0200","log.logger":"input.filestream","log.origin":{"file.name":"input-logfile/harvester.go","file.line":145},"message":"Starting harvester for file","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":174},"message":"newLogFileReader with config.MaxBytes:10485760","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","path":"/home/krs/elasticsearch/access2.log","state-id":"path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"processors","log.origin":{"file.name":"processing/processors.go","file.line":209},"message":"Publish event: {\n  \"@timestamp\": \"2022-04-26T08:19:01.383Z\",\n  \"@metadata\": {\n    \"beat\": \"filebeat\",\n    \"type\": \"_doc\",\n    \"version\": \"8.1.3\"\n  },\n  \"message\": \"ciao2\",\n  \"input\": {\n    \"type\": \"filestream\"\n  },\n  \"ecs\": {\n    \"version\": \"8.0.0\"\n  },\n  \"host\": {\n    \"name\": \"centos7-kvm-dev\"\n  },\n  \"agent\": {\n    \"ephemeral_id\": \"7305e804-569e-4a80-a05e-c528b540894f\",\n    \"id\": \"92799431-ee13-4df4-8809-24038ecf062e\",\n    \"name\": \"centos7-kvm-dev\",\n    \"type\": \"filebeat\",\n    \"version\": \"8.1.3\"\n  },\n  \"log\": {\n    \"file\": {\n      \"path\": \"/home/krs/elasticsearch/access2.log\"\n    },\n    \"offset\": 0\n  }\n}","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/filestream.go","file.line":131},"message":"End of file reached: /home/krs/elasticsearch/access2.log; Backoff now.","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","path":"/home/krs/elasticsearch/access2.log","state-id":"path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"file_watcher","log.origin":{"file.name":"filestream/fswatch.go","file.line":205},"message":"Found 2 paths","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":174},"message":"newLogFileReader with config.MaxBytes:10485760","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","path":"/home/krs/elasticsearch/access.log","state-id":"path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"processors","log.origin":{"file.name":"processing/processors.go","file.line":209},"message":"Publish event: {\n  \"@timestamp\": \"2022-04-26T08:19:01.383Z\",\n  \"@metadata\": {\n    \"beat\": \"filebeat\",\n    \"type\": \"_doc\",\n    \"version\": \"8.1.3\"\n  },\n  \"message\": \"tree\",\n  \"log\": {\n    \"offset\": 0,\n    \"file\": {\n      \"path\": \"/home/krs/elasticsearch/access.log\"\n    }\n  },\n  \"input\": {\n    \"type\": \"filestream\"\n  },\n  \"ecs\": {\n    \"version\": \"8.0.0\"\n  },\n  \"host\": {\n    \"name\": \"centos7-kvm-dev\"\n  },\n  \"agent\": {\n    \"ephemeral_id\": \"7305e804-569e-4a80-a05e-c528b540894f\",\n    \"id\": \"92799431-ee13-4df4-8809-24038ecf062e\",\n    \"name\": \"centos7-kvm-dev\",\n    \"type\": \"filebeat\",\n    \"version\": \"8.1.3\"\n  }\n}","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/filestream.go","file.line":131},"message":"End of file reached: /home/krs/elasticsearch/access.log; Backoff now.","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","path":"/home/krs/elasticsearch/access.log","state-id":"path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":351},"message":"Running filebeat once. Waiting for completion ...","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.origin":{"file.name":"beater/filebeat.go","file.line":353},"message":"All data collection completed. Shutting down.","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.origin":{"file.name":"beater/crawler.go","file.line":155},"message":"Stopping Crawler","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.origin":{"file.name":"beater/crawler.go","file.line":165},"message":"Stopping 1 inputs","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"crawler","log.origin":{"file.name":"beater/crawler.go","file.line":170},"message":"Stopping input: 16017456397865473365","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":132},"message":"Input 'filestream' stopped","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.origin":{"file.name":"beater/crawler.go","file.line":185},"message":"Crawler stopped","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":143},"message":"Closing reader of filestream","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","path":"/home/krs/elasticsearch/access2.log","state-id":"path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":158},"message":"client: closing acker","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":163},"message":"client: done closing acker","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":165},"message":"client: unlink from queue","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":187},"message":"client: cancelled 0 events","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":167},"message":"client: done unlink","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":170},"message":"client: closing processors","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":175},"message":"client: done closing processors","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":158},"message":"client: closing acker","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":163},"message":"client: done closing acker","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":165},"message":"client: unlink from queue","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":187},"message":"client: cancelled 0 events","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":167},"message":"client: done unlink","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":170},"message":"client: closing processors","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":175},"message":"client: done closing processors","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":320},"message":"Reader was closed. Closing.","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","path":"/home/krs/elasticsearch/access2.log","state-id":"path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"input-logfile/harvester.go","file.line":219},"message":"Stopped harvester for file","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access2.log","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":320},"message":"Reader was closed. Closing.","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","path":"/home/krs/elasticsearch/access.log","state-id":"path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.383+0200","log.logger":"input.filestream","log.origin":{"file.name":"input-logfile/harvester.go","file.line":219},"message":"Stopped harvester for file","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.384+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/prospector.go","file.line":165},"message":"Prospector has stopped","service.name":"filebeat","id":"test","prospector":"file_prospector","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:01.384+0200","log.logger":"input.filestream","log.origin":{"file.name":"compat/compat.go","file.line":124},"message":"Input 'filestream' stopped","service.name":"filebeat","id":"test","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:01.384+0200","log.logger":"input.filestream","log.origin":{"file.name":"filestream/input.go","file.line":143},"message":"Closing reader of filestream","service.name":"filebeat","id":"test","source_file":"filestream::test::path::/home/krs/elasticsearch/access.log","path":"/home/krs/elasticsearch/access.log","state-id":"path::/home/krs/elasticsearch/access.log","ecs.version":"1.6.0"}
{
  "@timestamp": "2022-04-26T08:19:01.383Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "_doc",
    "version": "8.1.3"
  },
  "agent": {
    "type": "filebeat",
    "version": "8.1.3",
    "ephemeral_id": "7305e804-569e-4a80-a05e-c528b540894f",
    "id": "92799431-ee13-4df4-8809-24038ecf062e",
    "name": "centos7-kvm-dev"
  },
  "log": {
    "file": {
      "path": "/home/krs/elasticsearch/access2.log"
    },
    "offset": 0
  },
  "message": "ciao2",
  "input": {
    "type": "filestream"
  },
  "ecs": {
    "version": "8.0.0"
  },
  "host": {
    "name": "centos7-kvm-dev"
  }
}
{
  "@timestamp": "2022-04-26T08:19:01.383Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "_doc",
    "version": "8.1.3"
  },
  "host": {
    "name": "centos7-kvm-dev"
  },
  "agent": {
    "ephemeral_id": "7305e804-569e-4a80-a05e-c528b540894f",
    "id": "92799431-ee13-4df4-8809-24038ecf062e",
    "name": "centos7-kvm-dev",
    "type": "filebeat",
    "version": "8.1.3"
  },
  "message": "tree",
  "log": {
    "offset": 0,
    "file": {
      "path": "/home/krs/elasticsearch/access.log"
    }
  },
  "input": {
    "type": "filestream"
  },
  "ecs": {
    "version": "8.0.0"
  }
}
{"debug","@timestamp":"2022-04-26T10:19:02.384+0200","log.logger":"publisher","log.origin":{"file.name":"memqueue/ackloop.go","file.line":160},"message":"ackloop: receive ack [0: 0, 2]","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.384+0200","log.logger":"publisher","log.origin":{"file.name":"memqueue/eventloop.go","file.line":535},"message":"broker ACK events: count=1, start-seq=1, end-seq=1\n","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.384+0200","log.logger":"acker","log.origin":{"file.name":"beater/acker.go","file.line":64},"message":"stateless ack","service.name":"filebeat","count":1,"ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"publisher","log.origin":{"file.name":"memqueue/eventloop.go","file.line":535},"message":"broker ACK events: count=1, start-seq=1, end-seq=1\n","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"acker","log.origin":{"file.name":"beater/acker.go","file.line":64},"message":"stateless ack","service.name":"filebeat","count":1,"ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"publisher","log.origin":{"file.name":"memqueue/ackloop.go","file.line":128},"message":"ackloop: return ack to broker loop:2","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"publisher","log.origin":{"file.name":"memqueue/ackloop.go","file.line":131},"message":"ackloop:  done send ack","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.385+0200","log.origin":{"file.name":"beater/signalwait.go","file.line":93},"message":"Continue shutdown: All enqueued events being published.","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":132},"message":"Stopping Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":166},"message":"Ending Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"debug","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":167},"message":"Stopping Registrar","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.385+0200","log.logger":"registrar","log.origin":{"file.name":"registrar/registrar.go","file.line":137},"message":"Registrar stopped","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.421+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":192},"message":"Total metrics","service.name":"filebeat","monitoring":{"metrics":{"beat":{"cpu":{"system":{"ticks":60,"time":{"ms":67}},"total":{"ticks":170,"time":{"ms":177},"value":170},"user":{"ticks":110,"time":{"ms":110}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":9},"info":{"ephemeral_id":"7305e804-569e-4a80-a05e-c528b540894f","uptime":{"ms":1101},"version":"8.1.3"},"memstats":{"gc_next":21462656,"memory_alloc":13081984,"memory_sys":32850952,"memory_total":51028048,"rss":103014400},"runtime":{"goroutines":17}},"filebeat":{"events":{"active":0,"added":2,"done":2},"harvester":{"closed":0,"open_files":0,"running":0,"skipped":0,"started":0},"input":{"log":{"files":{"renamed":0,"truncated":0}},"netflow":{"flows":0,"packets":{"dropped":0,"received":0}}}},"libbeat":{"config":{"module":{"running":0,"starts":0,"stops":0},"reloads":0,"scans":0},"output":{"events":{"acked":2,"active":0,"batches":1,"dropped":0,"duplicates":0,"failed":0,"toomany":0,"total":2},"read":{"bytes":0,"errors":0},"type":"console","write":{"bytes":1194,"errors":0}},"pipeline":{"clients":0,"events":{"active":0,"dropped":0,"failed":0,"filtered":0,"published":2,"retry":0,"total":2},"queue":{"acked":2,"max_events":4096}}},"registrar":{"states":{"cleanup":0,"current":0,"update":0},"writes":{"fail":0,"success":0,"total":0}},"system":{"cpu":{"cores":2},"load":{"1":0.13,"15":0.06,"5":0.07,"norm":{"1":0.065,"15":0.03,"5":0.035}}}},"ecs.version":"1.6.0"}}
{"info","@timestamp":"2022-04-26T10:19:02.421+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":193},"message":"Uptime: 1.101865195s","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.421+0200","log.logger":"monitoring","log.origin":{"file.name":"log/log.go","file.line":160},"message":"Stopping metrics logging.","service.name":"filebeat","ecs.version":"1.6.0"}
{"info","@timestamp":"2022-04-26T10:19:02.421+0200","log.origin":{"file.name":"instance/beat.go","file.line":494},"message":"filebeat stopped.","service.name":"filebeat","ecs.version":"1.6.0"}
5

hi @kRs , I've looked in the code and the --once flag is not supported for the filestream input type.
So according to the outcome of the race condition between the start of the input and the shutdown of filebeat due to --once flag, it can happen or not that the files are parsed.

You could open a bug on GitHub - elastic/beats: Beats - Lightweight shippers for Elasticsearch & Logstash if you think this behaviour is worth to be triaged in order to fix it

6

Thanks @Andrea_Spacca for looking into this.

I've opened the issue on github as, yes, I believe it should be either fixed or at least made clear that such option is (at least currently) not usable with the official input module for handling log files (log module in fact is defined as deprecated in favor of filestream either in its log messages and on the official documentation on website).

Thank you again for your attention :slight_smile:

7

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