Beats not working on 6.3.1 but did on 6.3.0

jamesl · July 8, 2018, 1:36am

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:~#

andrewkroh · July 8, 2018, 12:45pm

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.

jamesl · July 8, 2018, 1:19pm

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

How do I fix this problem?

andrewkroh · July 8, 2018, 1:23pm

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

andrewkroh · July 8, 2018, 1:36pm

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.

jamesl · July 8, 2018, 1:38pm

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...

jamesl · July 8, 2018, 1:49pm

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}}]"}}

`

jamesl · July 8, 2018, 1:53pm

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"

jamesl · July 9, 2018, 8:47am

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}}]"}}

`

jamesl · July 10, 2018, 9:23am

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?

jamesl · July 10, 2018, 9:49pm

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.

andrewkroh · July 10, 2018, 10:33pm

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.

jamesl · July 11, 2018, 9:39pm

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}}]"}}

jamesl · July 11, 2018, 9:56pm

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?

andrewkroh · July 12, 2018, 11:41am

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.

jamesl · July 12, 2018, 8:22pm

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

jamesl · July 12, 2018, 8:25pm

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.

andrewkroh · July 12, 2018, 8:41pm

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

jamesl · July 12, 2018, 9:28pm

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...

andrewkroh · July 13, 2018, 11:48am

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

Topic		Replies	Views
My metricbeats stopped working after the latest ugprade! and I have errors on mapping 6.3.0 Beats metricbeat	2	646	July 23, 2018
Filebeat 6.7.0 not pushing logs to Elasticsearch 6.7.0 after upgrade Beats filebeat	6	6100	April 30, 2019
Filebeat 6.2.3 index is empty Beats filebeat	14	1808	April 19, 2018
Logstash Beats Error [ELK Stack 6.5.4] Logstash	5	1861	February 18, 2019
Filebeat not creating index in ES 6.5.1 Beats filebeat	3	1276	January 14, 2019

Beats not working on 6.3.1 but did on 6.3.0

Related topics