Fitebeat 6.3.1 system module issue

shaunak · July 25, 2018, 10:21pm

That was the last line in the log you posted a couple of comments above. That seems to indicate that the filebeat-6.3.1-system-syslog-pipeline ingest pipeline was loaded up.

If you run curl -XGET "http://localhost:9200/_ingest/pipeline/file*syslog* now, do you still not see the timezone setting in the date processor in that pipeline?

mouli_v · July 26, 2018, 5:25am

curl -XGET "http://localhost:9200/_ingest/pipeline/file*syslog*"
{"filebeat-6.3.1-system-syslog-pipeline":{"description":"Pipeline for parsing Syslog messages.","processors":[{"grok":{"ignore_missing":true,"field":"message","patterns":["%{SYSLOGTIMESTAMP:system.syslog.timestamp} %{SYSLOGHOST:system.syslog.hostname} %{DATA:system.syslog.program}(?:\[%{POSINT:system.syslog.pid}\])?: %{GREEDYMULTILINE:system.syslog.message}","%{SYSLOGTIMESTAMP:system.syslog.timestamp} %{GREEDYMULTILINE:system.syslog.message}"],"pattern_definitions":{"GREEDYMULTILINE":"(.|\n)"}}},{"remove":{"field":"message"}},{"date":{"field":"system.syslog.timestamp","target_field":"@timestamp","formats":["MMM d HH:mm:ss","MMM dd HH:mm:ss"],"ignore_failure":true}}],"on_failure":[{"set":{"field":"error.message","value":"{{ _ingest.on_failure_message }}"}}]},"filebeat-6.3.2-system-syslog-pipeline":{"description":"Pipeline for parsing Syslog messages.","processors":[{"grok":{"field":"message","patterns":["%{SYSLOGTIMESTAMP:system.syslog.timestamp} %{SYSLOGHOST:system.syslog.hostname} %{DATA:system.syslog.program}(?:\[%{POSINT:system.syslog.pid}\])?: %{GREEDYMULTILINE:system.syslog.message}","%{SYSLOGTIMESTAMP:system.syslog.timestamp} %{GREEDYMULTILINE:system.syslog.message}"],"pattern_definitions":{"GREEDYMULTILINE":"(.|\n)"},"ignore_missing":true}},{"remove":{"field":"message"}},{"date":{"field":"system.syslog.timestamp","target_field":"@timestamp","formats":["MMM d HH:mm:ss","MMM dd HH:mm:ss"],"ignore_failure":true}}],"on_failure":[{"set":{"field":"error.message","value":"{{ _ingest.on_failure_message }}"}}]}}

mouli_v · July 27, 2018, 11:12am

Please share me the filebeat.yml and "/etc/filebeat/modules/system.yml" config file; Just wanted to verify.

Why it is not working for me. I have not made changes to config file. Just made an entry[ var.convert_timezone: true] change to /etc/filebeat/modules/system.yml

Thanks

mouli_v · July 27, 2018, 11:42am

Please share me the filebeat.yml and "/etc/filebeat/modules/system.yml" config files;

As you mentioned you are good with system modules, just wanted to compare the config files. I have not made changes to config file. Just made an entry[ var.convert_timezone: true] change to /etc/filebeat/modules/system.yml

- module: system
  # Syslog
  syslog:
    enabled: true

    # Set custom paths for the log files. If left empty,
    # Filebeat will choose the paths depending on your OS.
    #var.paths:

    # Convert the timestamp to UTC. Requires Elasticsearch >= 6.1.
    var.convert_timezone: true

  # Authorization logs
  auth:
    enabled: true

    # Set custom paths for the log files. If left empty,
    # Filebeat will choose the paths depending on your OS.
    #var.paths:

    # Convert the timestamp to UTC. Requires Elasticsearch >= 6.1.
    var.convert_timezone: true

File: /var/lib/filebeat/registry

[{"source":"/var/log/fontconfig.log","offset":1595,"timestamp":"2018-07-27T04:39:33.039794035-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":55457,"device":51713}},{"source":"/var/log/kern.log","offset":0,"timestamp":"2018-07-27T04:39:33.043196589-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":6554,"device":51713}},{"source":"/var/log/mail.log","offset":0,"timestamp":"2018-07-27T04:39:33.046297732-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":6542,"device":51713}},{"source":"/var/log/alternatives.log","offset":0,"timestamp":"2018-07-27T04:39:33.049354647-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":6560,"device":51713}},{"source":"/var/log/cloud-init-output.log","offset":1830858,"timestamp":"2018-07-27T04:39:33.052581509-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":51060,"device":51713}},{"source":"/var/log/cloud-init.log","offset":255061,"timestamp":"2018-07-27T04:39:33.055793968-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":51059,"device":51713}},{"source":"/var/log/dpkg.log","offset":33763,"timestamp":"2018-07-27T04:39:33.059004416-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":6556,"device":51713}},{"source":"/var/log/auth.log","offset":195840,"timestamp":"2018-07-27T04:39:33.131430975-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":5317,"device":51713}},{"source":"/var/log/syslog.1","offset":498236,"timestamp":"2018-07-27T04:39:33.145264877-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":4955,"device":51713}},{"source":"/var/log/syslog","offset":95634,"timestamp":"2018-07-27T04:39:33.149061775-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":4185,"device":51713}},{"source":"/var/log/ansible.log","offset":1524521,"timestamp":"2018-07-27T04:39:33.065642651-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":51200,"device":51713}},{"source":"/var/log/aptitude","offset":0,"timestamp":"2018-07-14T07:30:40.4573387-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":6552,"device":51713}},{"source":"/var/log/auth.log.1","offset":0,"timestamp":"2018-07-27T04:39:33.135059822-07:00","ttl":-1,"type":"log","meta":null,"FileStateOS":{"inode":5316,"device":51713}},{"source":"/var/log/syslog.7.gz","offset":23413,"timestamp":"2018-07-27T03:36:26.344859976-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":4590,"device":51713}},{"source":"/var/log/syslog.2.gz","offset":22455,"timestamp":"2018-07-27T03:36:26.35104531-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":4895,"device":51713}},{"source":"/var/log/syslog.3.gz","offset":23457,"timestamp":"2018-07-27T03:36:26.331978977-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":6436,"device":51713}},{"source":"/var/log/syslog.4.gz","offset":23302,"timestamp":"2018-07-27T03:36:26.334868819-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":5535,"device":51713}},{"source":"/var/log/syslog.5.gz","offset":23858,"timestamp":"2018-07-27T03:36:26.338248729-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":2967,"device":51713}},{"source":"/var/log/syslog.6.gz","offset":24364,"timestamp":"2018-07-27T03:36:26.341475422-07:00","ttl":-2,"type":"log","meta":null,"FileStateOS":{"inode":2788,"device":51713}},{"source":"/var/log/alternatives.log","offset":0,"timestamp":"2018-07-27T04:39:33.068791974-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":6560,"device":51713}},{"source":"/var/log/fontconfig.log","offset":1595,"timestamp":"2018-07-27T04:39:33.072163462-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":55457,"device":51713}},{"source":"/var/log/mail.log","offset":0,"timestamp":"2018-07-27T04:39:33.075215686-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":6542,"device":51713}},{"source":"/var/log/cloud-init.log","offset":255061,"timestamp":"2018-07-27T04:39:33.078431985-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":51059,"device":51713}},{"source":"/var/log/dpkg.log","offset":33763,"timestamp":"2018-07-27T04:39:33.081763426-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":6556,"device":51713}},{"source":"/var/log/kern.log","offset":0,"timestamp":"2018-07-27T04:39:33.085154411-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":6554,"device":51713}},{"source":"/var/log/ansible.log","offset":1524521,"timestamp":"2018-07-27T04:39:33.090848975-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":51200,"device":51713}},{"source":"/var/log/auth.log","offset":198711,"timestamp":"2018-07-27T04:39:33.216345544-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":5317,"device":51713}},{"source":"/var/log/cloud-init-output.log","offset":1830858,"timestamp":"2018-07-27T04:39:33.097910848-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":51060,"device":51713}},{"source":"/var/log/syslog","offset":0,"timestamp":"2018-07-27T04:39:33.194075037-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":4185,"device":51713}},{"source":"/var/log/syslog.1","offset":0,"timestamp":"2018-07-27T04:39:33.204599189-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":4955,"device":51713}},{"source":"/var/log/auth.log.1","offset":0,"timestamp":"2018-07-27T04:39:33.230591066-07:00","ttl":-1,"type":"log","meta":{},"FileStateOS":{"inode":5316,"device":51713}}]

Thanks

mouli_v · July 27, 2018, 11:42am

I observed only prospector logs[/var/log/*.log] are coming into elasticsearch, not system module logs.
filebeat logs:

|2018-07-27T04:29:03.417-0700|INFO|log/harvester.go:228|Harvester started for file: /var/log/auth.log|
|---|---|---|---|
|2018-07-27T04:29:03.427-0700|INFO|log/input.go:113|Configured paths: [/var/log/auth.log* /var/log/secure*]|
|2018-07-27T04:29:03.433-0700|INFO|log/input.go:113|Configured paths: [/var/log/messages* /var/log/syslog*]|
|2018-07-27T04:29:03.433-0700|INFO|crawler/crawler.go:82|Loading and starting Inputs completed. Enabled inputs: 1|
|2018-07-27T04:29:03.433-0700|INFO|cfgfile/reload.go:122|Config reloader started|
|2018-07-27T04:29:03.441-0700|ERROR|fileset/factory.go:72|Error creating input: Can only start an input when all related states are finished: {Id:0-5317-51713 Finished:false Fileinfo:0xc4204ae5b0 Source:/var/log/auth.log Offset:197900 Timestamp:2018-07-27 04:29:03.430147214 -0700 PDT m=+0.080186641 TTL:-1ns Type:log Meta:map[] FileStateOS:5317-51713}|
|2018-07-27T04:29:03.441-0700|ERROR|cfgfile/reload.go:201|Unable to create runner due to error: Can only start an input when all related states are finished: {Id:0-5317-51713 Finished:false Fileinfo:0xc4204ae5b0 Source:/var/log/auth.log Offset:197900 Timestamp:2018-07-27 04:29:03.430147214 -0700 PDT m=+0.080186641 TTL:-1ns Type:log Meta:map[] FileStateOS:5317-51713}|
|2018-07-27T04:29:03.441-0700|INFO|cfgfile/reload.go:214|Loading of config files completed.|
|2018-07-27T04:29:04.420-0700|INFO|elasticsearch/client.go:690|Connected to Elasticsearch version 6.2.4|
|2018-07-27T04:29:04.422-0700|INFO|template/load.go:73|Template already exists and will not be overwritten.|

recent logs:

|2018-07-27T05:30:57.451-0700|ERROR|fileset/factory.go:69|Error creating prospector: Can only start a prospector when all related states are finished: {Id: Finished:false Fileinfo:0xc4204449c0 Source:/var/log/auth.log Offset:0 Timestamp:2018-07-27 05:30:57.447433007 -0700 PDT m=+0.032391182 TTL:-1ns Type:log FileStateOS:5317-51713}|
|---|---|---|---|
|2018-07-27T05:30:57.451-0700|ERROR|cfgfile/reload.go:206|Unable to create runner due to error: Can only start a prospector when all related states are finished: {Id: Finished:false Fileinfo:0xc4204449c0 Source:/var/log/auth.log Offset:0 Timestamp:2018-07-27 05:30:57.447433007 -0700 PDT m=+0.032391182 TTL:-1ns Type:log FileStateOS:5317-51713}|

shaunak · July 27, 2018, 4:41pm

I noticed that in the output from GET _ingest/pipeline/file*syslog*, you are actually getting back two ingest pipelines, one named filebeat-6.3.1-system-syslog-pipeline and the other named filebeat-6.3.2-system-syslog-pipeline.

This indicates that you are running filebeat-6.3.1 and filebeat-6.3.2 in parallel.

Also in an earlier post you mentioned that you have installed filebeat on 50+ servers.

For debugging this issue could you temporarily stop all your 50+ filebeat instances? Then follow the steps from Fitebeat 6.3.1 system module issue using only one filebeat instance. Then please post the results of those steps, specifically steps 4 and 5.

mouli_v · July 27, 2018, 6:10pm

performed those steps:
Filebeat log:

2018-07-27T11:06:28.684-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5a7a8b3c900, ext:93243359275, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "source":"/var/log/auth.log", "offset":528450, "message":"Jul 27 11:06:22 mouli-i-038f2e3e573d951b6 sshd[3691]: Close session: user rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "input":common.MapStr{"type":"log"}, "fileset":common.MapStr{"name":"auth", "module":"system"}, "prospector":common.MapStr{"type":"log"}, "beat":common.MapStr{"version":"6.3.1", "timezone":"-07:00", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:528591, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:06:48.685-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5ade8c6d6b9, ext:118244607969, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"beat":common.MapStr{"version":"6.3.1", "timezone":"-07:00", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "source":"/var/log/auth.log", "offset":528591, "message":"Jul 27 11:06:37 mouli-i-038f2e3e573d951b6 sshd[3691]: Starting session: command for rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "input":common.MapStr{"type":"log"}, "fileset":common.MapStr{"module":"system", "name":"auth"}, "prospector":common.MapStr{"type":"log"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:528742, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:06:49.458-0700	INFO	[monitoring]	log/log.go:124	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":440,"time":{"ms":8}},"total":{"ticks":3850,"time":{"ms":20},"value":3850},"user":{"ticks":3410,"time":{"ms":12}}},"info":{"ephemeral_id":"a7a58680-f4b8-4332-adfd-f101bdf33780","uptime":{"ms":120010}},"memstats":{"gc_next":7615056,"memory_alloc":4144944,"memory_total":421250472}},"filebeat":{"events":{"added":10,"done":10},"harvester":{"open_files":13,"running":13}},"libbeat":{"config":{"module":{"running":1}},"output":{"events":{"acked":4,"batches":7,"dropped":6,"total":10},"read":{"bytes":2296},"write":{"bytes":7283}},"pipeline":{"clients":5,"events":{"active":0,"published":10,"total":10},"queue":{"acked":10}}},"registrar":{"states":{"current":12,"update":10},"writes":{"success":7,"total":7}},"system":{"load":{"1":0.02,"15":0,"5":0.02,"norm":{"1":0.02,"15":0,"5":0.02}}}}}}
2018-07-27T11:06:53.685-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5ade8c6e334, ext:118244611160, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"source":"/var/log/auth.log", "offset":528742, "message":"Jul 27 11:06:37 mouli-i-038f2e3e573d951b6 sshd[3691]: Close session: user rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "input":common.MapStr{"type":"log"}, "fileset":common.MapStr{"module":"system", "name":"auth"}, "prospector":common.MapStr{"type":"log"}, "beat":common.MapStr{"timezone":"-07:00", "version":"6.3.1", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:528883, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:07:03.686-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5b1a8d78e96, ext:133245703613, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "source":"/var/log/auth.log", "offset":528883, "message":"Jul 27 11:06:55 mouli-i-038f2e3e573d951b6 sshd[26661]: Connection from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 33916 on 2600:1f18:2270:741e:48e:c1e6:ffc0:c1e port 22", "fileset":common.MapStr{"name":"auth", "module":"system"}, "prospector":common.MapStr{"type":"log"}, "input":common.MapStr{"type":"log"}, "beat":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "version":"6.3.1", "timezone":"-07:00"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:529054, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}

mouli_v · July 27, 2018, 6:15pm

2018-07-27T11:12:05.704-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5fbe9e6a517, ext:430263469628, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"offset":532217, "message":"Jul 27 11:11:55 mouli-i-038f2e3e573d951b6 sshd[26808]: Connection closed by 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 35524 [preauth]", "source":"/var/log/auth.log", "fileset":common.MapStr{"module":"system", "name":"auth"}, "prospector":common.MapStr{"type":"log"}, "input":common.MapStr{"type":"log"}, "beat":common.MapStr{"timezone":"-07:00", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "version":"6.3.1"}, "host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:532354, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:12:15.708-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5ffa9f8d8a6, ext:445264662475, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "source":"/var/log/auth.log", "offset":532354, "message":"Jul 27 11:12:10 mouli-i-038f2e3e573d951b6 sshd[3691]: Starting session: command for rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "fileset":common.MapStr{"module":"system", "name":"auth"}, "prospector":common.MapStr{"type":"log"}, "input":common.MapStr{"type":"log"}, "beat":common.MapStr{"timezone":"-07:00", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "version":"6.3.1"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:532505, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:12:15.708-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5ffa9f8e54d, ext:445264665711, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"fileset":common.MapStr{"module":"system", "name":"auth"}, "beat":common.MapStr{"version":"6.3.1", "timezone":"-07:00", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "source":"/var/log/auth.log", "offset":532505, "message":"Jul 27 11:12:10 mouli-i-038f2e3e573d951b6 sshd[3691]: Close session: user rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "prospector":common.MapStr{"type":"log"}, "input":common.MapStr{"type":"log"}}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:532646, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:12:15.708-0700	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbecef5ffa9f8eaef, ext:445264667150, loc:(*time.Location)(0x1f4a300)}, Meta:common.MapStr{"pipeline":"filebeat-6.3.1-system-auth-pipeline"}, Fields:common.MapStr{"offset":532646, "input":common.MapStr{"type":"log"}, "fileset":common.MapStr{"module":"system", "name":"auth"}, "prospector":common.MapStr{"type":"log"}, "beat":common.MapStr{"timezone":"-07:00", "hostname":"mouli-i-038f2e3e573d951b6.k.dev.eng-us", "version":"6.3.1", "name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "host":common.MapStr{"name":"mouli-i-038f2e3e573d951b6.k.dev.eng-us"}, "message":"Jul 27 11:12:12 mouli-i-038f2e3e573d951b6 sshd[3691]: Starting session: command for rdmon from 2600:1f18:2270:741e:3f2a:54ab:3f89:5fe9 port 49894 id 0", "source":"/var/log/auth.log"}, Private:file.State{Id:"", Finished:false, Fileinfo:(*os.fileStat)(0xc42006ac30), Source:"/var/log/auth.log", Offset:532797, Timestamp:time.Time{wall:0xbecef590600dcc76, ext:98263559, loc:(*time.Location)(0x1f4a300)}, TTL:-1, Type:"log", Meta:map[string]string{}, FileStateOS:file.StateOS{Inode:0x14c5, Device:0xca01}}}, Flags:0x1} (status=400): {"type":"illegal_argument_exception","reason":"pipeline with id [filebeat-6.3.1-system-auth-pipeline] does not exist"}
2018-07-27T11:12:19.460-0700	INFO	[monitoring]	log/log.go:124	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":460,"time":{"ms":8}},"total":{"ticks":3990,"time":{"ms":16},"value":3990},"user":{"ticks":3530,"time":{"ms":8}}},"info":{"ephemeral_id":"a7a58680-f4b8-4332-adfd-f101bdf33780","uptime":{"ms":450011}},"memstats":{"gc_next":6889456,"memory_alloc":4402624,"memory_total":434379744,"rss":-11476992}},"filebeat":{"events":{"added":8,"done":8},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":1}},"output":{"events":{"acked":2,"batches":5,"dropped":6,"total":8},"read":{"bytes":1634},"write":{"bytes":6026}},"pipeline":{"clients":5,"events":{"active":0,"published":8,"total":8},"queue":{"acked":8}}},"registrar":{"states":{"current":12,"update":8},"writes":{"success":5,"total":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}

I stopped the service on 50+ servers, just enabled 6.3.1 on a server.

mouli_v · July 27, 2018, 6:24pm

Stopped the service
delete existing pipelinee
started service
Log

instance# systemctl stop filebeat.service 
instance# curl -XDELETE "http://sherlock:9200/_ingest/pipeline/filebeat-*"
instance# systemctl restart filebeat.service 
instance# tail -n10 /var/log/filebeat/filebeat 
2018-07-27T11:22:38.774-0700	INFO	log/harvester.go:228	Harvester started for file: /var/log/auth.log
2018-07-27T11:22:38.778-0700	INFO	log/input.go:113	Configured paths: [/var/log/auth.log* /var/log/secure*]
2018-07-27T11:22:38.787-0700	INFO	log/input.go:113	Configured paths: [/var/log/messages* /var/log/syslog*]
2018-07-27T11:22:38.787-0700	INFO	crawler/crawler.go:82	Loading and starting Inputs completed. Enabled inputs: 1
2018-07-27T11:22:38.787-0700	INFO	cfgfile/reload.go:122	Config reloader started
2018-07-27T11:22:38.789-0700	ERROR	fileset/factory.go:72	Error creating input: Can only start an input when all related states are finished: {Id:0-5317-51713 Finished:false Fileinfo:0xc420498680 Source:/var/log/auth.log Offset:538015 Timestamp:2018-07-27 11:22:38.787001557 -0700 PDT m=+0.048636661 TTL:-1ns Type:log Meta:map[] FileStateOS:5317-51713}
2018-07-27T11:22:38.789-0700	ERROR	cfgfile/reload.go:201	Unable to create runner due to error: Can only start an input when all related states are finished: {Id:0-5317-51713 Finished:false Fileinfo:0xc420498680 Source:/var/log/auth.log Offset:538015 Timestamp:2018-07-27 11:22:38.787001557 -0700 PDT m=+0.048636661 TTL:-1ns Type:log Meta:map[] FileStateOS:5317-51713}
2018-07-27T11:22:38.789-0700	INFO	cfgfile/reload.go:214	Loading of config files completed.
2018-07-27T11:22:39.779-0700	INFO	elasticsearch/client.go:690	Connected to Elasticsearch version 6.2.4
2018-07-27T11:22:39.780-0700	INFO	template/load.go:73	Template already exists and will not be overwritten.

Indeed, i just uninstalled the package on all 50 instances, now filebeat is running on only one instance.

mouli_v · July 27, 2018, 8:00pm

current log: just wanted to share this log.

|2018-07-27T12:54:08.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":780,"time":{"ms":8},"value":780},"user":{"ticks":620,"time":{"ms":8}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5490010}},"memstats":{"gc_next":4194304,"memory_alloc":1864848,"memory_total":89560816}},"filebeat":{"events":{"added":2,"done":2},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":2,"batches":1,"total":2},"read":{"bytes":346},"write":{"bytes":1281}},"pipeline":{"clients":4,"events":{"active":0,"published":2,"total":2},"queue":{"acked":2}}},"registrar":{"states":{"current":12,"update":2},"writes":{"success":1,"total":1}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|---|---|---|---|---|---|
|2018-07-27T12:54:38.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":790,"value":790},"user":{"ticks":630}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5520009}},"memstats":{"gc_next":4194304,"memory_alloc":2030312,"memory_total":89726280}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":4,"events":{"active":0}}},"registrar":{"states":{"current":12}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:55:08.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":790,"time":{"ms":4},"value":790},"user":{"ticks":630,"time":{"ms":4}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5550009}},"memstats":{"gc_next":4194304,"memory_alloc":2520960,"memory_total":90216928}},"filebeat":{"events":{"added":6,"done":6},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":6,"batches":1,"total":6},"read":{"bytes":377},"write":{"bytes":3323}},"pipeline":{"clients":4,"events":{"active":0,"published":6,"total":6},"queue":{"acked":6}}},"registrar":{"states":{"current":12,"update":6},"writes":{"success":1,"total":1}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:55:38.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":800,"time":{"ms":4},"value":800},"user":{"ticks":640,"time":{"ms":4}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5580010}},"memstats":{"gc_next":4194304,"memory_alloc":2771128,"memory_total":90467096}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":4,"events":{"active":0}}},"registrar":{"states":{"current":12}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:56:08.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":800,"time":{"ms":8},"value":800},"user":{"ticks":640,"time":{"ms":8}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5610010}},"memstats":{"gc_next":4194304,"memory_alloc":1519096,"memory_total":91188640}},"filebeat":{"events":{"added":4,"done":4},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":4,"batches":2,"total":4},"read":{"bytes":690},"write":{"bytes":2562}},"pipeline":{"clients":4,"events":{"active":0,"published":4,"total":4},"queue":{"acked":4}}},"registrar":{"states":{"current":12,"update":4},"writes":{"success":2,"total":2}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:56:38.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":810,"time":{"ms":4},"value":810},"user":{"ticks":650,"time":{"ms":4}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5640010}},"memstats":{"gc_next":4194304,"memory_alloc":2275752,"memory_total":91945296}},"filebeat":{"events":{"added":4,"done":4},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":4,"batches":2,"total":4},"read":{"bytes":693},"write":{"bytes":2562}},"pipeline":{"clients":4,"events":{"active":0,"published":4,"total":4},"queue":{"acked":4}}},"registrar":{"states":{"current":12,"update":4},"writes":{"success":2,"total":2}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:57:08.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":810,"time":{"ms":4},"value":810},"user":{"ticks":650,"time":{"ms":4}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5670009}},"memstats":{"gc_next":4194304,"memory_alloc":3004864,"memory_total":92674408}},"filebeat":{"events":{"added":4,"done":4},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":4,"batches":2,"total":4},"read":{"bytes":687},"write":{"bytes":2578}},"pipeline":{"clients":4,"events":{"active":0,"published":4,"total":4},"queue":{"acked":4}}},"registrar":{"states":{"current":12,"update":4},"writes":{"success":2,"total":2}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|
|2018-07-27T12:57:38.755-0700|INFO|[monitoring]|log/log.go:124|Non-zero metrics in the last 30s|{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":160},"total":{"ticks":820,"time":{"ms":4},"value":820},"user":{"ticks":660,"time":{"ms":4}}},"info":{"ephemeral_id":"4a992943-2964-4f31-8391-807246f6cc41","uptime":{"ms":5700009}},"memstats":{"gc_next":4194304,"memory_alloc":3495544,"memory_total":93165088}},"filebeat":{"events":{"added":4,"done":4},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":4,"batches":1,"total":4},"read":{"bytes":360},"write":{"bytes":2367}},"pipeline":{"clients":4,"events":{"active":0,"published":4,"total":4},"queue":{"acked":4}}},"registrar":{"states":{"current":12,"update":4},"writes":{"success":1,"total":1}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}|

system · August 24, 2018, 8:01pm

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

Topic		Replies	Views
Filebeat 6.3.2 syslogs are not logging to elastcisearch Beats filebeat	15	978	October 30, 2018
Filebeat 7.3 Timezone Issues with System Module Beats filebeat	6	1007	September 18, 2019
Filebeat system module auth log timezone conversion problem Beats filebeat	7	2318	August 16, 2018
Filebeat 6.2.1 system module does not convert timestamp with timezone Beats filebeat	3	4639	March 13, 2018
Filebeat 6.4.2 the timestamp is not right Beats filebeat	6	2258	November 15, 2018

Fitebeat 6.3.1 system module issue

Related topics