"Failed to install template... contact Elasticsearch"

bme · November 2, 2016, 9:06am

I am testing elastic search with logstash and filebeats, trying to import our IIS log for analysing and viewing in Kibana. All latest version (5.0).

I have run into a problem during the startup of logstash where it says this during startup:

[2016-11-02T09:57:12,578][WARN ][logstash.runner ] SIGINT received. Shutting down the agent.
[2016-11-02T09:57:12,687][WARN ][logstash.agent ] stopping pipeline {:id=>"main"}
[2016-11-02T09:58:44,305][INFO ][logstash.inputs.beats ] Beats inputs: Starting input listener {:address=>"192.168.0.2:5045"}
[2016-11-02T09:58:44,633][INFO ][org.logstash.beats.Server] Starting server on port: 5045
[2016-11-02T09:58:45,008][INFO ][logstash.outputs.elasticsearch] Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>["http://192.168.0.2:9200"]}}
[2016-11-02T09:58:45,027][INFO ][logstash.outputs.elasticsearch] Using mapping template from {:path=>"M:\logstash-5.0.0\config\iis.myapp.template.json"}
[2016-11-02T09:58:45,258][INFO ][logstash.outputs.elasticsearch] Attempting to install template {:manage_template=>{"mappings"=>{"default"=>{"_all"=>{"enabled"=>true, "norms"=>{"enabled"=>false}}, "dynamic_templates"=>[{"iisTemplate"=>{"mapping"=>{"doc_values"=>true, "ignore_above"=>1024, "index"=>"not_analyzed", "type"=>"{dynamic_type}"}, "match"=>""}}], "properties"=>{"@timestamp"=>{"type"=>"date", "index"=>"analyzed"}, "status"=>{"type"=>"integer", "index"=>"analyzed", "doc_values"=>true}, "timeTaken"=>{"type"=>"integer", "index"=>"analyzed", "doc_values"=>true}, "bytesSent"=>{"type"=>"integer", "index"=>"analyzed", "doc_values"=>true}, "bytesTotal"=>{"type"=>"integer", "index"=>"analyzed", "doc_values"=>false}, "bytesReceived"=>{"type"=>"integer", "index"=>"analyzed", "doc_values"=>true}, "subStatus"=>{"type"=>"integer", "index"=>"not_analyzed"}, "geoip"=>{"type"=>"object", "dynamic"=>"true", "index"=>"analyzed", "properties"=>{"location"=>{"type"=>"geo_point"}}}}}, "settings"=>{"index.refresh_interval"=>"5s"}, "template"=>"iis-"}}}
[2016-11-02T09:58:45,274][INFO ][logstash.outputs.elasticsearch] Installing elasticsearch template to _template/logstash
[2016-11-02T09:58:45,305][ERROR][logstash.outputs.elasticsearch] Failed to install template. {:message=>"Got response code '400' contact Elasticsearch at URL 'http://192.168.0.2:9200/_template/logstash'", :class=>"LogStash::Outputs::ElasticSearch::HttpClient::Pool::BadResponseCodeError"}
[2016-11-02T09:58:45,321][INFO ][logstash.outputs.elasticsearch] New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["192.168.0.2:9200"]}
[2016-11-02T09:58:45,586][INFO ][logstash.filters.geoip ] Using geoip database {:path=>"M:\logstash-5.0.0\GeoLite2-City.mmdb"}
[2016-11-02T09:58:45,618][INFO ][logstash.pipeline ] Starting pipeline {"id"=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>500}
[2016-11-02T09:58:45,618][INFO ][logstash.pipeline ] Pipeline main started
[2016-11-02T09:58:45,774][INFO ][logstash.agent ] Successfully started Logstash API endpoint {:port=>9600}

Can anyone tell me from this what the issue could be? Elastic pointed me to this forum...

The template is present in the log above.

Also, the default configuration of elasticsearch itself seems to cause it to crash (multiple exceptions and out-of-memory errors). I had hoped elasticsearch could handle it a bit better when memory was tight instead of outright failing. :-/

Thanks,

Bernhard

warkolm · November 2, 2016, 9:07am

Check your ES logs;

Means something wasn't accepted in ES.

bme · November 2, 2016, 9:11am

I cannot see anything wrong looking in the elasticsearch log:

[2016-11-02T09:57:49,563][INFO ][o.e.n.Node [2016-11-02T09:57:49,704][INFO ][o.e.e.NodeEnvironment [2016-11-02T09:57:49,704][INFO ][o.e.e.NodeEnvironment [2016-11-02T09:57:49,766][INFO ][o.e.n.Node [2016-11-02T09:57:49,766][INFO ][o.e.n.Node [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,344][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,359][INFO ][o.e.p.PluginsService [2016-11-02T09:57:51,359][INFO ][o.e.p.PluginsService [2016-11-02T09:57:55,891][INFO ][o.e.n.Node [2016-11-02T09:57:55,891][INFO ][o.e.n.Node [2016-11-02T09:57:56,453][INFO ][o.e.t.TransportService [2016-11-02T09:57:56,469][INFO ][o.e.b.BootstrapCheck [2016-11-02T09:58:00,610][INFO ][o.e.c.s.ClusterService [2016-11-02T09:58:00,625][INFO ][o.e.h.HttpServer [2016-11-02T09:58:00,641][INFO ][o.e.n.Node [2016-11-02T09:58:01,281][INFO ][o.e.g.GatewayService [2016-11-02T09:58:01,938][INFO ][o.e.c.r.a.AllocationService] ] [] initializing ...
] [OGKkOnR] using [1] data paths, mounts [[MainDb (M:)]], net usable_space [987.4gb], net total_space [999.8gb], spins? [unknown], types [NTFS]
] [OGKkOnR] heap size [1.9gb], compressed ordinary object pointers [true]
] [OGKkOnR] node name [OGKkOnR] derived from node ID; set [node.name] to override
] [OGKkOnR] version[5.0.0], pid[23916], build[253032b/2016-10-26T04:37:51.531Z], OS[Windows Server 2012/6.2/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_101/25.101-b13]
] [OGKkOnR] loaded module [aggs-matrix-stats]
] [OGKkOnR] loaded module [ingest-common]
] [OGKkOnR] loaded module [lang-expression]
] [OGKkOnR] loaded module [lang-groovy]
] [OGKkOnR] loaded module [lang-mustache]
] [OGKkOnR] loaded module [lang-painless]
] [OGKkOnR] loaded module [percolator]
] [OGKkOnR] loaded module [reindex]
] [OGKkOnR] loaded module [transport-netty3]
] [OGKkOnR] loaded module [transport-netty4]
] [OGKkOnR] no plugins loaded
] [OGKkOnR] initialized
] [OGKkOnR] starting ...
] [OGKkOnR] publish_address {192.168.0.2:9300}, bound_addresses {192.168.0.2:9300}
] [OGKkOnR] bound or publishing to a non-loopback or non-link-local address, enforcing bootstrap checks
] [OGKkOnR] new_master {OGKkOnR}{OGKkOnRcQNKOtKqF2X7XFQ}{YgqBcaU8QNyjNoTLMxlL9g}{192.168.0.2}{192.168.0.2:9300}, reason: zen-disco-elected-as-master ([0] nodes joined)
] [OGKkOnR] publish_address {192.168.0.2:9200}, bound_addresses {192.168.0.2:9200}
] [OGKkOnR] started
] [OGKkOnR] recovered [3] indices into cluster_state
[OGKkOnR] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[.kibana][0]] ...]).

But is there any hints of anything wrong?

bme · November 7, 2016, 11:01am

I guess this is an unsolvable error then.

warkolm · November 7, 2016, 9:02pm

What does GET _template against ES show?

bme · November 8, 2016, 9:48am

It lists 2 templates, none of which are relevant to my logstash template.

The logstash output has this output configured:

output {
elasticsearch {
hosts => ['192.168.0.2:9200']
index => 'iis-myapp-%{+YYYY.MM}'
template => "M:\logstash-5.0.0\config\iis.myapp.template.json"
template_overwrite => true
}
}

The index is being created as iis-myapp-* but there is no template. I guess the template must be bad, but elasticsearch didn't complain about it and logstash says elastisearch wont accept it. JSON validater says the template is valid json. I am at a loss here.

warkolm · November 8, 2016, 9:49am

Maybe you can show us your template.

bme · November 8, 2016, 9:50am

Sure, it is already in the first post as part of the log, but here it is again:

{
"mappings": {
"default": {
"_all": {
"enabled": true,
"norms": {
"enabled": false
}
},
"dynamic_templates": [{
"iisTemplate": {
"mapping": {
"doc_values": true,
"ignore_above": 1024,
"index": "not_analyzed",
"type": "{dynamic_type}"
},
"match": ""
}
}
],
"properties": {
"@timestamp": {
"type": "date",
"index": "analyzed"
},
"status": {
"type": "integer",
"index": "analyzed",
"doc_values": true
},
"timeTaken": {
"type": "integer",
"index": "analyzed",
"doc_values": true
},
"bytesSent": {
"type": "integer",
"index": "analyzed",
"doc_values": true
},
"bytesTotal": {
"type": "integer",
"index": "analyzed",
"doc_values": false
},
"bytesReceived": {
"type": "integer",
"index": "analyzed",
"doc_values": true
},
"subStatus": {
"type": "integer",
"index": "not_analyzed"
},
"geoip": {
"type": "object",
"dynamic": "true",
"index": "analyzed",
"properties": {
"location": {
"type": "geo_point"
}
}
}
}
},
"settings": {
"index.refresh_interval": "5s"
},
"template": "iis-"
}
}