Issues creating ES indexes after upgrading from 1.4.2 to 1.5.0-1

Hi everyone,

I'm hoping this is an easy one. I upgraded from 1.4.2 to 1.5.0-1 on CentOS 6.5 running Java 1.8.0_31, and now I cannot seem to create indexes in my ES cluster :frowning:

The only configuration update I made was to change "index_type" to "document_type". What's more, when I start Logstash in the foreground on the CLI, a ctrl-C does not stop the process. I have to kill -9 it to get it to stop! Something is definitely amiss.

I'm doing a basic read of some Apache HTTP logs, and sending them to ES. I would really appreciate someone pointing out where I've gone wrong here, because I am stumped.

Here is my logstash.conf:

input {
  file {
    path => "/var/log/glados/glados.perf.log"
    type => "portal.perf.portalserver01"
    sincedb_path => "/derby/data/disk1/logstash/glados.perf"
  }
  file {
    path => "/var/log/glados/glados.log"
    type => "portal.app.portalserver01"
    sincedb_path => "/derby/data/disk1/logstash/glados.app"
  } 
}   
    
filter {
  date {
    match => [ "timestamp" , "dd/MMM/yyyy:HH:mm:ss Z" ]
  } 
    
  if [type] == "portal.app.portalserver01" {
    grok {
      match => { "message" => "\[%{NOTSPACE:appname}\]\s*%{TIMESTAMP_ISO8601:log_time}\s*%{LOGLEVEL:severity}\s*\[%{NOTSPACE:class}\]\s*- %{GREEDYDATA:log_message}" }
      tag_on_failure => [ ]
    }
  } 
  if [type] == "portal.perf.portalserver01" {
    grok {
      match => { "message" => "\[%{NOTSPACE:appname}\]\s*%{TIMESTAMP_ISO8601:log_time}\s*%{GREEDYDATA:kv_pair}" }
      tag_on_failure => [ ]
    } 
    kv {
      source => "kv_pair"
      trim => ">"
      trimkey => "<"
    }
#    prune {
#      remove_field => [ "kv_pair" ]
#    }
  } 
      
  # stacktrace java as one message
  multiline { 
    #type => "all" # no type means for all inputs
    pattern => "(^.+Exception: .+)|(^\s+at .+)|(^\s+... \d+ more)|(^\s*Caused by:.+)"
    what => "previous" 
  }  
  
  geoip {
    source => "ip"
    target => "geoip"
    add_field => { "[geoip][coordinates]" => "%{[geoip][longitude]}" }
    add_field => { "[geoip][coordinates]" => "%{[geoip][latitude]}"  }
  } 
  
  # Fix types
  mutate {
    convert => { "elasticsearch.cache.get.duration" => "integer" }
    convert => { "elasticsearch.cache.put.duration" => "integer" }
    convert => { "elasticsearch.query.duration" => "integer" }
    convert => { "process.duration" => "integer" }
    convert => { "result.cnt" => "integer" }
    convert => { "[geoip][coordinates]" => "float"}
  } 
} 
    
output {
  if [type] == "portal.perf.portalserver01" {
    
    elasticsearch {
      bind_host => "prodes01.mydomain.com"
      cluster => "elasticsearch-prod"
      flush_size => 1
      host => [ "prodes01.mydomain.com", "prodes02.mydomain.com", "prodes03.mydomain.com", "prodes04.mydomain.com", "prodes05.mydomain.com", "prodes06.mydomain.com" ]
      index => "derby-portal-%{+YYYYMMdd}"
      document_type => "perf_portal"
      node_name => "logstash-portalserver01"
      protocol => "transport"
    } 
  }
  if [type] == "portal.app.portalserver01" {

    elasticsearch {
      bind_host => "prodes01.mydomain.com"
      cluster => "elasticsearch-prod"
      flush_size => 1
      host => [ "prodes01.mydomain.com", "prodes02.mydomain.com", "prodes03.mydomain.com", "prodes04.mydomain.com", "prodes05.mydomain.com", "prodes06.mydomain.com" ]
      index => "app-%{+YYYYMMdd}"
      document_type => "app_portal"
      template => "/etc/logstash/app-defaults"
      template_name => "app-defaults"
      template_overwrite => true
      node_name => "logstash-portalserver01"
      protocol => "transport"
    }
  }
}

And here is the output of logstash starting with -verbose, and me generating some logs to Apache that should have gone to ES, but do not, then me killing Logstash with kill -9:

root@ip-10-0-2-95:portalserver01[855]:/opt/logstash> bin/logstash -f /etc/logstash/conf.d/ --verbose
Using version 0.1.x input plugin 'file'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x codec plugin 'plain'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'date'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'grok'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'kv'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'multiline'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'geoip'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x filter plugin 'mutate'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Using version 0.1.x output plugin 'elasticsearch'. This plugin isn't well supported by the community and likely has no maintainer. {:level=>:info}
Registering file input {:path=>["/var/log/glados/glados.perf.log"], :level=>:info}
Registering file input {:path=>["/var/log/glados/glados.log"], :level=>:info}
Grok patterns path {:patterns_dir=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns", "/opt/logstash/patterns/*"], :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/redis", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/java", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/haproxy", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/firewalls", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/junos", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/mongodb", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/postgresql", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/grok-patterns", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/linux-syslog", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/ruby", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/mcollective", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/mcollective-patterns", :level=>:info}
Grok loading patterns from file {:path=>"/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/nagios", :level=>:info}
Match data {:match=>{"message"=>"\\[%{NOTSPACE:appname}\\]\\s*%{TIMESTAMP_ISO8601:log_time}\\s*%{LOGLEVEL:severity}\\s*\\[%{NOTSPACE:class}\\]\\s*- %{GREEDYDATA:log_message}"}, :level=>:info}
Grok compile {:field=>"message", :patterns=>["\\[%{NOTSPACE:appname}\\]\\s*%{TIMESTAMP_ISO8601:log_time}\\s*%{LOGLEVEL:severity}\\s*\\[%{NOTSPACE:class}\\]\\s*- %{GREEDYDATA:log_message}"], :level=>:info}

<SNIP ADDING PATTERNS>

Create client to elasticsearch server on prodes01.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:39 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes02.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:41 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes03.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:41 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes04.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:41 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes05.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:42 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes06.mydomain.com: {:level=>:info}
Jun 01, 2015 11:38:42 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []


Automatic template management enabled {:manage_template=>"true", :level=>:info}
Using mapping template {:template=>{"template"=>"logstash-*", "settings"=>{"index.refresh_interval"=>"5s"}, "mappings"=>{"_default_"=>{"_all"=>{"enabled"=>true, "omit_norms"=>true}, "dynamic_templates"=>#<Java::JavaUtil::ArrayList:0x32e5d785>, "properties"=>{"@version"=>{"type"=>"string", "index"=>"not_analyzed"}, "geoip"=>{"type"=>"object", "dynamic"=>true, "properties"=>{"location"=>{"type"=>"geo_point"}}}}}}}, :level=>:info}
New Elasticsearch output {:cluster=>"elasticsearch-prod", :host=>["prodes01.mydomain.com", "prodes02.mydomain.com", "prodes03.mydomain.com", "prodes04.mydomain.com", "prodes05.mydomain.com", "prodes06.mydomain.com"], :port=>"9300-9305", :embedded=>false, :protocol=>"transport", :level=>:info}
Create client to elasticsearch server on prodes01.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:12 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes02.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:13 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes03.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:13 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes04.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:13 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes05.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:14 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Create client to elasticsearch server on prodes06.mydomain.com: {:level=>:info}
Jun 01, 2015 11:39:14 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash-portalserver01] loaded [], sites []
Automatic template management enabled {:manage_template=>"true", :level=>:info}
Using mapping template {:template=>{"template"=>"app-*", "settings"=>{"index"=>{"merge"=>{"policy"=>{"segments_per_tier"=>4, "max_merge_at_once"=>4, "max_merge_at_once_explicit"=>4, "max_merged_segment"=>"1gb"}}}}, "mappings"=>{"_default_"=>{"_all"=>{"enabled"=>false}}}}, :level=>:info}
New Elasticsearch output {:cluster=>"elasticsearch-prod", :host=>["prodes01.mydomain.com", "prodes02.mydomain.com", "prodes03.mydomain.com", "prodes04.mydomain.com", "prodes05.mydomain.com", "prodes06.mydomain.com"], :port=>"9300-9305", :embedded=>false, :protocol=>"transport", :level=>:info}
Pipeline started {:level=>:info}
Logstash startup completed


<at this point, about 60 log entries have been created, but nothing is in Elasticsearch>

^CSIGINT received. Shutting down the pipeline. {:level=>:warn}
Sending shutdown signal to input thread {:thread=>#<Thread:0x411e3c36 sleep>, :level=>:info}
Sending shutdown signal to input thread {:thread=>#<Thread:0x6ad518dc sleep>, :level=>:info}
^CSIGINT received. Shutting down the pipeline. {:level=>:warn}
Sending shutdown signal to input thread {:thread=>#<Thread:0x411e3c36 run>, :level=>:info}
Sending shutdown signal to input thread {:thread=>#<Thread:0x6ad518dc dead>, :level=>:info}

<Control-C did not stop it>

Killed
root@ip-10-0-2-95:portalserver01[858]:/opt/logstash>

Thanks guys for taking a look at this for me.
Very much appreciate your time and suggestions.
Chris

Ok, so I did some regression testing of other Logstash versions, and got some interesting results. I tested:

logstash-1.5.0.rc4
logstash-1.5.0-rc3
logstash-1.5.0.rc2
logstash-1.5.0.beta1
logstash-1.4.2

with my configuration, and none of them worked. Hmm. That makes me think instead that something did actually change in my configuration that broke the ES output plugin. I'm going to do some more looking in that area now, but if anyone sees something suspicious in that section of my config, please let me know!

Chris

Ok, I think I take it all back. I think my ES cluster was hosed somehow and not letting anything get indexed. sigh.

Also, having a flush_size of 1 is a bit of a waste of resources, better to increase it or leave as default.

Agreed! This was just for debugging purposes. :slight_smile: