Beats not working on 6.3.1 but did on 6.3.0


#1

Hi. Just upgraded my Elastic Cluster from 6.3.0 --> 6.3.1 (Ubuntu 16.04).

None of my Beats are working on my Linux hosts (filebeat or metricbeat).
They start and there are no errors in the log files (/var/log/filebeat /var/log/metricbeat).

I was ingesting files and metriclogs with 6.3.0.

Any pointers? Below is an extract of my filebeat & metricbeat log

2018-07-08T11:32:17.898+1000 DEBUG [publish] pipeline/processor.go:291 Publish event: {
"@timestamp": "2018-07-08T01:32:16.897Z",
"@metadata": {
"beat": "filebeat",
"type": "doc",
"version": "6.3.1",
"pipeline": "filebeat-6.3.1-system-auth-pipeline"
},
"prospector": {
"type": "log"
},
"input": {
"type": "log"
},
"beat": {
"timezone": "+10:00",
"name": "els01",
"hostname": "els01",
"version": "6.3.1"
},
"host": {
"name": "els01"
},
"source": "/var/log/auth.log",
"offset": 316772,
"message": "Jul 8 11:32:15 els01 sshd[100453]: pam_unix(sshd:auth): check pass; user unknown",
"fileset": {
"module": "system",
"name": "auth"
}
}
2018-07-08T11:32:20.724+1000 DEBUG [harvester] log/log.go:85 End of file reached: /var/log/auth.log; Backoff now.
2018-07-08T11:32:22.110+1000 DEBUG [elasticsearch] elasticsearch/client.go:303 PublishEvents: 1 events have been published to elasticsearch in 4.212042809s.
2018-07-08T11:32:22.112+1000 DEBUG [elasticsearch] elasticsearch/client.go:303 PublishEvents: 5 events have been published to elasticsearch in 7.215529797s.
2018-07-08T11:32:22.112+1000 DEBUG [memqueue] memqueue/ackloop.go:143 ackloop: receive ack [489: 0, 5]
2018-07-08T11:32:22.112+1000 DEBUG [memqueue] memqueue/ackloop.go:143 ackloop: receive ack [490: 0, 1]
2018-07-08T11:32:22.112+1000 DEBUG [memqueue] memqueue/eventloop.go:518 broker ACK events: count=6, start-seq=6196, end-seq=6201

2018-07-08T11:32:22.112+1000 DEBUG [memqueue] memqueue/ackloop.go:111 ackloop: return ack to broker loop:6
2018-07-08T11:32:22.112+1000 DEBUG [memqueue] memqueue/ackloop.go:114 ackloop: done send ack
2018-07-08T11:32:22.113+1000 DEBUG [acker] beater/acker.go:47 stateful ack {"count": 6}
2018-07-08T11:32:22.113+1000 DEBUG [registrar] registrar/registrar.go:236 Processing 6 events
2018-07-08T11:32:22.113+1000 DEBUG [registrar] registrar/registrar.go:206 Registrar state updates processed. Count: 6
2018-07-08T11:32:22.113+1000 DEBUG [registrar] registrar/registrar.go:291 Write registry file: /var/lib/filebeat/registry
2018-07-08T11:32:22.174+1000 DEBUG [registrar] registrar/registrar.go:284 Registry file updated. 74 states written.
2018-07-08T11:32:22.724+1000 DEBUG [harvester] log/log.go:85 End of file reached: /var/log/auth.log; Backoff now.

metricbeat log:

2018-07-08T11:34:27.101+1000 WARN elasticsearch/client.go:502 Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbec87868896b5d77, ext:55560371421543, loc:(*time.Location)(0x3b01400)}, Meta:common.MapStr(nil), Fields:common.MapStr{"metricset":common.MapStr{"module":"system", "rtt":24990, "name":"process"}, "system":common.MapStr{"process":common.MapStr{"cwd":"/", "pgid":1127, "username":"root", "ppid":1, "name":"filebeat", "fd":common.MapStr{"open":0x9, "limit":common.MapStr{"soft":0x400, "hard":0x1000}}, "pid":1127, "memory":common.MapStr{"size":0x19d49000, "rss":common.MapStr{"pct":0.0071, "bytes":0x1be0000}, "share":0x112b000}, "cpu":common.MapStr{"total":common.MapStr{"norm":common.MapStr{"pct":0}, "value":14090, "pct":0}, "start_time":common.Time{wall:0x0, ext:63666554905, loc:(*time.Location)(nil)}}, "cgroup":common.MapStr{"blkio":common.MapStr{"id":"filebeat.service", "path":"/system.slice/filebeat.service", "total":common.MapStr{"bytes":0x42aa000, "ios":0xa84}}, "id":"filebeat.service", "path":"/system.slice/filebeat.service", "cpu":common.MapStr{"cfs":common.MapStr{"period":common.MapStr{"us":0x186a0}, "quota":common.MapStr{"us":0x0}, "shares":0x400}, "rt":common.MapStr{"period":common.MapStr{"us":0x0}, "runtime":common.MapStr{"us":0x0}}, "stats":common.MapStr{"throttled":common.MapStr{"periods":0x0, "ns":0x0}, "periods":0x0}, "id":"filebeat.service", "path":"/system.slice/filebeat.service"}, "cpuacct":common.MapStr{"percpu":common.MapStr{"2":0x1a84f4734, "1":0x1a02d8e39}, "stats":common.MapStr{"user":common.MapStr{"ns":0x172251480}, "system":common.MapStr{"ns":0xd1cef000}}, "id":"filebeat.service", "path":"/system.slice/filebeat.service", "total":common.MapStr{"ns":0x3487cd56d}}, "memory":common.MapStr{"mem":common.MapStr{"failures":0x0, "limit":common.MapStr{"bytes":0x7ffffffffffff000}, "usage":common.MapStr{"bytes":0x2383000, "max":common.MapStr{"bytes":0x43a9000}}}, "memsw":common.MapStr{"failures":0x0, "limit":common.MapStr{"bytes":0x0}, "usage":common.MapStr{"max":common.MapStr{"bytes":0x0}, "bytes":0x0}}, "kmem":common.MapStr{"failures":0x0, "limit":common.MapStr{"bytes":0x7ffffffffffff000}, "usage":common.MapStr{"max":common.MapStr{"bytes":0x0}, "bytes":0x0}}, "kmem_tcp":common.MapStr{"failures":0x0, "limit":common.MapStr{"bytes":0x7ffffffffffff000}, "usage":common.MapStr{"bytes":0x0, "max":common.MapStr{"bytes":0x0}}}, "stats":common.MapStr{"rss_huge":common.MapStr{"bytes":0x0}, "active_file":common.MapStr{"bytes":0xad0000}, "page_faults":0x6ffe, "active_anon":common.MapStr{"bytes":0xbb7000}, "hierarchical_memory_limit":common.MapStr{"bytes":0x7ffffffffffff000}, "mapped_file":common.MapStr{"bytes":0xfc3000}, "cache":common.MapStr{"bytes":0x17cc000}, "major_page_faults":0xa3, "pages_in":0x9c1a, "swap":common.MapStr{"bytes":0x0}, "inactive_anon":common.MapStr{"bytes":0x0}, "rss":common.MapStr{"bytes":0xbb7000}, "hierarchical_memsw_limit":common.MapStr{"bytes":0x0}, "inactive_file":common.MapStr{"bytes":0xcfc000}, "pages_out":0x7897, "unevictable":common.MapStr{"bytes":0x0}}, "id":"filebeat.service", "path":"/system.slice/filebeat.service"}}, "state":"sleeping", "cmdline":"/usr/share/filebeat/bin/filebeat -c /etc/filebeat/filebeat.yml -path.home /usr/share/filebeat -path.config /etc/filebeat -path.data /var/lib/filebeat -path.logs /var/log/filebeat"}}, "beat":common.MapStr{"version":"6.3.1", "name":"els01", "hostname":"els01"}, "host":common.MapStr{"name":"els01"}}, Private:interface {}(nil)}, Flags:0x0} (status=400): {"type":"mapper_parsing_exception","reason":"Failed to parse mapping [doc]: Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]","caused_by":{"type":"mapper_parsing_exception","reason":"Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]"}}
root@els01:~#


(Andrew Kroh) #2

Based on the logs it looks like Filebeat is publishing events successfully.

Metricbeat appears to have a problem with the "ticks" value. There was a problem in 6.3.0 where the index template did not contain a mapping for ticks and should only affect you if process.include_cpu_ticks: true is set. That was fixed in 6.3.1.

If you are using the default index naming pattern that includes the version number this should not affect you because Metricbeat will automatically install an updated index template for 6.3.1 that has the mapping for ticks. But if you are managing templates yourself or have customized index naming to not include the beat.version then you'll need to manually handle the changes to the index template.


#3

Thanks. I have default index names. Right now the latest one is metricbeat-6.3.0-2018.07.07 which is right because this morning at 10am no new index was created because no new data :frowning:

How do I fix this problem?


(Andrew Kroh) #4

Are you sure you are using 6.3.1 everywhere? You can check with metricbeat version.


(Andrew Kroh) #5

I guess it does say 6.3.1 in the error.

Can you please share the config you are using? I'd like to see if process.include_cpu_ticks: true is used somewhere.

So then how about ensuring that 6.3.1 is removed everywhere and see if that fixes the issue.

Stop metricbeat. Then run these commands on Elasticsearch.

GET _cat/indices/metricbeat-6.3.1*

DELETE metricbeat-6.3.1-<dates from the previous command>

DELETE _template/metricbeat-6.3.1

Restart metricbeat.


#6

Yep all confirmed running 6.3.1

root@els01:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@els02:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@els03:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@els04:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@kib01:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@kib02:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@log01:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

root@log02:~# metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159713e0ffd4 built 2018-06-29 21:14:09 +0000 UTC]

And 4 Windows machines that just checked and are running 6.3.1.

Windows Server 1 Win2012R2
C:\ProgramData\metricbeat>metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159
713e0ffd4 built 2018-06-29 21:12:59 +0000 UTC]
C:\ProgramData\metricbeat>

DC1
C:\ProgramData\metricbeat>metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159
713e0ffd4 built 2018-06-29 21:12:59 +0000 UTC]

DC2
C:\ProgramData\metricbeat>metricbeat version
metricbeat version 6.3.1 (amd64), libbeat 6.3.1 [ed42bb85e72ae58cc09748dc1825159
713e0ffd4 built 2018-06-29 21:12:59 +0000 UTC]

Windows 10
Can't paste info because I only have a vm console to it not able to copy paste info...


#7

Yes shutdown metricbeat on all my nodes. Deleted the template. I had no indices though.
Restarted metricbeat on only 1 node. Got this in my lob but still no indices has been created...

[2018-07-08T23:45:19,698][INFO ][o.e.c.m.MetaDataIndexTemplateService] [els01] removing template [metricbeat-6.3.1]
[2018-07-08T23:45:46,408][INFO ][o.e.c.m.MetaDataIndexTemplateService] [els01] adding template [metricbeat-6.3.1] for index patterns [metricbeat-6.3.1-*]

extract of my log on this 1 host.

> }}, "beat":common.MapStr{"name":"els01", "hostname":"els01", "version":"6.3.1"}}, Private:interface {}(nil)}, Flags:0x0} (status=400): {"type":"mapper_parsing_exception","reason":"Failed to parse mapping [doc]: Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]","caused_by":{"type":"mapper_parsing_exception","reason":"Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]"}}

`


#8

This is the only config that I have added/changed.. It's the same as when I was on 6.3.0.

This is from my ES Master Node.

output.elasticsearch:
  # Array of hosts to connect to.
  hosts: ["kib01:9200","kib02:9200"]

  # Optional protocol and basic auth credentials.
  #protocol: "https"
  username: "elastic"
  password: "elastic"

#9

HI, just a bit of an update on this. I removed and reinstalled metricbeat on 1 host. All I put in the metricbeat.yml file was the hostname of my 2 Elastic ingest nodes. Started the service but again ...

Same problem..

mon.MapStr{"open":0x6, "limit":common.MapStr{"soft":0x400, "hard":0x1000}}, "state":"sleeping", "name":"snapd", "cwd":"/", "pid":1141, "ppid":1}}, "beat":common.MapStr{"name":"log01", "hostname":"log01", "version":"6.3.1"}, "host":common.MapStr{"name":"log01"}}, Private:interface {}(nil)}, Flags:0x0} (status=400): {"type":"mapper_parsing_exception","reason":"Failed to parse mapping [doc]: Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]","caused_by":{"type":"mapper_parsing_exception","reason":"Mapping definition for [system] has unsupported parameters: [properties : {ticks={type=long}}]"}}

`


#10

Could my issue be that I have too many metricbeat templates... looks like one for each version i went to... 6.2.2, 6.2.3, 6.2.4, 6.3.0

Should I delete all the metricbeat templates?

image


#11

Hi. Ran commands as requested:

root@els01:~# curl -u superuser -X GET els01:9200/_cat/indices/metricbeat-6.3.1*?pretty
Enter host password for user 'superuser':
root@els01:~# 

Ran for 6.3.0 indices just in case I had a syntax error but no all good..

root@els01:~# curl -u superuser -X GET els01:9200/_cat/indices/metricbeat-6.3.0*?pretty
Enter host password for user 'superuser':
green open metricbeat-6.3.0-2018.07.04 7LibeeZZTCG2W5F_7KVeEg 1 1 1825958 0 1.1gb 583.1mb
green open metricbeat-6.3.0-2018.07.06 -e3vpPG5TGC9mN-QttP1Tw 1 1 1856934 0 1.1gb 590.4mb
green open metricbeat-6.3.0-2018.07.05 c6gzmD0cSV-iU-N-m_h5aw 1 1 1842198 0 1.1gb 588.7mb
green open metricbeat-6.3.0-2018.07.07 CFvyH26QQjmlTWB_4FCJzA 1 1 1597283 0   1gb 512.1mb
root@els01:~# 


root@els01:~# curl -u superuser -X DELETE els01:9200/_template/metricbeat-6.3.1?pretty
Enter host password for user 'superuser':
{
  "acknowledged" : true
}
root@els01:~# 
root@els01:~# 

and now I have an indices!!

And metricbeat dashboard is loaded as well!

So looks like had to delete template.. it must have been corrupted?
Thank you for your help.


(Andrew Kroh) #12

I'm not really sure what went wrong. It kind of seemed like the old 6.3.0 template got installed as 6.3.1. Hard to tell. But glad it's working now. I will keep an out for similar issues.


#13

Hi Strange that it's happened again. I have nothing in my indice since 23:59:59.

and this is what is in my beats client logs.. all the same.

2018-07-12T07:16:16.676+1000	WARN	elasticsearch/client.go:502	Cannot index event publisher.Event{Content:beat.Event{Timestamp:time.Time{wall:0xbec9bac7e9bd91cf, ext:82920086332392, loc:(*time.Location)(0x3b01400)}, Meta:co
mmon.MapStr(nil), Fields:common.MapStr{"metricset":common.MapStr{"rtt":8416, "name":"diskio", "module":"system"}, "system":common.MapStr{"diskio":common.MapStr{"name":"sda2", "read":common.MapStr{"count":0x4, "time":0x4, "bytes":0x1
000}, "write":common.MapStr{"bytes":0x0, "count":0x0, "time":0x0}, "io":common.MapStr{"time":0x4}, "iostat":common.MapStr{"busy":0, "read":common.MapStr{"per_sec":common.MapStr{"bytes":0}, "request":common.MapStr{"merges_per_sec":0,
 "per_sec":0}}, "write":common.MapStr{"request":common.MapStr{"merges_per_sec":0, "per_sec":0}, "per_sec":common.MapStr{"bytes":0}}, "queue":common.MapStr{"avg_size":0}, "request":common.MapStr{"avg_size":0}, "await":0, "service_tim
e":0}}}, "beat":common.MapStr{"name":"els01", "hostname":"els01", "version":"6.3.1"}, "host":common.MapStr{"name":"els01"}}, Private:interface {}(nil)}, Flags:0x0} (status=400): {"type":"mapper_parsing_exception","reason":"Failed to
 parse mapping [doc]: Mapping definition for [system] has unsupported parameters:  [properties : {ticks={type=long}}]","caused_by":{"type":"mapper_parsing_exception","reason":"Mapping definition for [system] has unsupported paramete
rs:  [properties : {ticks={type=long}}]"}}


#14

Just deleted the 6.3.1 metricbeat template and it came good again... Will see if it happens again tonight at 23:59.59

It also started a new index. I thought they should get created at GMT?


(Andrew Kroh) #15

If it happens again can you dump the contents of GET _template/metricbeat-6.3.1 to file. I'm curious to see the mapping and the metadata in there.


#16

Hi, confirmed. Again no new indices at midnight local time. As requested, a dump of the template..

Refer pastbin url because it's too big.

https://pastebin.com/ySUWw2wf


#17

I found I had a 'metricbeat' template. I deleted it and a new indices with todays date got made.... maybe I had an overlap? Will see again tomorrow.


(Andrew Kroh) #18

Did you upgrade from 5.x at one point? We started including versions in the templates and indices in 6.0.


#19

Yes I have have this system up since ES 2.4.x.

Should I go through and dome some housekeeping (delete) all old templates?
I have so many...

image


(Andrew Kroh) #20

Yeah, delete the metricbeat index template because the template applies to "index_patterns": ["metricbeat-*"]. This causes it to affect the mapping used to new 6.x indices.

DELETE _template/metricbeat