Logstash Stalling Out on Automatic Config Restart

Elastic Stack Logstash
1

Hello, I've been slamming my head into the desk all day trying to solve this problem. I've set up my logstash to adapt to changes in the config file, but when I change it, it begins to shutdown the pipeline, but stalls, and can't finish shutting it down. Here's a sample of the message that logstash keeps feeding me after I've edited the config file and it recognizes that it needs to restart:

[2018-07-26T20:42:00,975][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{["LogStash::Filters::Metrics", {"meter"=>"%{event_type}_events", "add_tag"=>"metric", "id"=>"146b56c026c6d51504073286f9d2f8d0378458967e1011818475cf59a87e8627"}]=>[{"thread_id"=>25, "name"=>nil, "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/manticore-0.6.1-java/lib/manticore/response.rb:50:incall'"}]}}`

[2018-07-26T20:42:05,977][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{["LogStash::Filters::Metrics", {"meter"=>"%{event_type}_events", "add_tag"=>"metric", "id"=>"146b56c026c6d51504073286f9d2f8d0378458967e1011818475cf59a87e8627"}]=>[{"thread_id"=>25, "name"=>nil, "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/manticore-0.6.1-java/lib/manticore/response.rb:50:incall'"}]}}`

Sorry for any formatting errors.

2

I can't think of any reasons why that backtrace (an http call using the manticore adapter) would be coming from the Metrics Filter Plugin. Can you restart logstash with debug-level logging enabled?

  • What does your pipeline configuration look like?
  • What version of Logstash are you running?
  • Do you have any other customisations in your logstash.yml? (e.g., multiple pipelines, persistent queues, experimental java execution, etc.)
3

Here is my pipeline, running in Logstash 6.3.0, docker-compose
input
{

  file
 {
                path => "/usr/share/logstash/canarylogs/canary_exporter_output.log"

                codec => "json"
        }
}
filter{

         metrics
        {       meter => "%{event_type}_events"
                add_tag => "metric"
        }

}
output
{
if "metric" in [tags]{
        elasticsearch{
                hosts => "elasticsearch:9201"
                index => "metrics"
                }
#       stdout{}


}



else {
elasticsearch
        {
                index => "%{event_type}"
                hosts => "elasticsearch:9201"
        }

#       if [event_type]== "binary_info"
#       {
 #             file{
  #                   path => "/usr/share/logstash/binary/binaryinfo.logs"
   #                  codec => "json"
    #               }
#       }

}

}

my yaml file is just:
config:
reload:
automatic: true

4

Enabling the debug feature has just too much data coming in, is there any way to have it not print for each time it logs something?

5

Update: Letting it run for like 5 minutes of just feeding me the stall error gives this:

[2018-07-27T15:57:06,835][INFO ][logstash.pipeline        ] Pipeline has terminated {:pipeline_id=>"main", :thread=>"#<Thread:0x5788b355 run>"}
logstash_1       | [2018-07-27T15:57:07,319][INFO ][logstash.pipeline        ] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>6, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50}
logstash_1       | [2018-07-27T15:57:07,400][INFO ][logstash.outputs.elasticsearch] Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>[http://elasticsearch:9201/]}}
logstash_1       | [2018-07-27T15:57:07,401][INFO ][logstash.outputs.elasticsearch] Running health check to see if an Elasticsearch connection is working {:healthcheck_url=>http://elasticsearch:9201/, :path=>"/"}
logstash_1       | [2018-07-27T15:57:07,429][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://elasticsearch:9201/"}
logstash_1       | [2018-07-27T15:57:07,437][INFO ][logstash.outputs.elasticsearch] ES Output version determined {:es_version=>6}
logstash_1       | [2018-07-27T15:57:07,438][WARN ][logstash.outputs.elasticsearch] Detected a 6.x and above cluster: the `type` event field won't be used to determine the document _type {:es_version=>6}
logstash_1       | [2018-07-27T15:57:07,441][INFO ][logstash.outputs.elasticsearch] Using mapping template from {:path=>nil}
logstash_1       | [2018-07-27T15:57:07,446][INFO ][logstash.outputs.elasticsearch] Attempting to install template {:manage_template=>{"template"=>"logstash-*", "version"=>60001, "settings"=>{"index.refresh_interval"=>"5s"}, "mappings"=>{"_default_"=>{"dynamic_templates"=>[{"message_field"=>{"path_match"=>"message", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false}}}, {"string_fields"=>{"match"=>"*", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false, "fields"=>{"keyword"=>{"type"=>"keyword", "ignore_above"=>256}}}}}], "properties"=>{"@timestamp"=>{"type"=>"date"}, "@version"=>{"type"=>"keyword"}, "geoip"=>{"dynamic"=>true, "properties"=>{"ip"=>{"type"=>"ip"}, "location"=>{"type"=>"geo_point"}, "latitude"=>{"type"=>"half_float"}, "longitude"=>{"type"=>"half_float"}}}}}}}}
logstash_1       | [2018-07-27T15:57:07,463][INFO ][logstash.outputs.elasticsearch] New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["//elasticsearch:9201"]}
logstash_1       | [2018-07-27T15:57:07,468][INFO ][logstash.outputs.elasticsearch] Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>[http://elasticsearch:9201/]}}
logstash_1       | [2018-07-27T15:57:07,469][INFO ][logstash.outputs.elasticsearch] Running health check to see if an Elasticsearch connection is working {:healthcheck_url=>http://elasticsearch:9201/, :path=>"/"}
logstash_1       | [2018-07-27T15:57:07,474][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://elasticsearch:9201/"}
logstash_1       | [2018-07-27T15:57:07,477][INFO ][logstash.outputs.elasticsearch] ES Output version determined {:es_version=>6}
logstash_1       | [2018-07-27T15:57:07,477][WARN ][logstash.outputs.elasticsearch] Detected a 6.x and above cluster: the `type` event field won't be used to determine the document _type {:es_version=>6}
logstash_1       | [2018-07-27T15:57:07,478][INFO ][logstash.outputs.elasticsearch] Using mapping template from {:path=>nil}
logstash_1       | [2018-07-27T15:57:07,479][INFO ][logstash.outputs.elasticsearch] Attempting to install template {:manage_template=>{"template"=>"logstash-*", "version"=>60001, "settings"=>{"index.refresh_interval"=>"5s"}, "mappings"=>{"_default_"=>{"dynamic_templates"=>[{"message_field"=>{"path_match"=>"message", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false}}}, {"string_fields"=>{"match"=>"*", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false, "fields"=>{"keyword"=>{"type"=>"keyword", "ignore_above"=>256}}}}}], "properties"=>{"@timestamp"=>{"type"=>"date"}, "@version"=>{"type"=>"keyword"}, "geoip"=>{"dynamic"=>true, "properties"=>{"ip"=>{"type"=>"ip"}, "location"=>{"type"=>"geo_point"}, "latitude"=>{"type"=>"half_float"}, "longitude"=>{"type"=>"half_float"}}}}}}}}
logstash_1       | [2018-07-27T15:57:07,481][INFO ][logstash.outputs.elasticsearch] New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["//elasticsearch:9201"]}
logstash_1       | [2018-07-27T15:57:07,559][INFO ][logstash.pipeline        ] Pipeline started successfully {:pipeline_id=>"main", :thread=>"#<Thread:0x389dad29 sleep>"}
logstash_1       | [2018-07-27T15:57:07,594][INFO ][logstash.agent           ] Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>[]}
logstash_1       | [2018-07-27T15:57:12,141][INFO ][logstash.outputs.file    ] Opening file {:path=>"/usr/share/logstash/binary/binaryinfo.logs"}

Followed by this about 2 minutes later:

logstash_1       | [2018-07-27T15:59:40,095][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<NoMethodError: undefined method `map_cleanup' for nil:NilClass>, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/2.3.0/gems/logstash-codec-multiline-3.0.9/lib/logstash/codecs/identity_map_codec.rb:55:in `block in start'"]}
logstash_1       | [2018-07-27T15:59:40,407][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit
shimada_logstash_1 exited with code 1

****Have not been able to replicate

6

Also still stalls regardless if the filter is commented out or not.

7

Here's my docker-compose.yml
services:

  elasticsearch:
    build:
      context: elasticsearch/
      dockerfile: Dockerfile
    volumes:
      - ./elasticsearch/esdata:/usr/share/elasticsearch/data
      - ./elasticsearch/config/elasticsearch.yml:/usr/share/elasticsearch/config/elasticsearch.yml:ro
    ports:
      - "9201:9201"
      - "9301:9301"
    environment:
      ES_JAVA_OPTS: "-Xmx8g -Xms8g"
    networks:
      - elk


  logstash:
    build:
      context: logstash/
      dockerfile: Dockerfile
    volumes:
      - ./logstash/config/logstash.yml:/usr/share/logstash/config/logstash.yml
      - ./logstash/pipeline:/usr/share/logstash/pipeline
      - ./canary_exporter_staging/output:/usr/share/logstash/canarylogs:ro
      - ./binarylogs:/usr/share/logstash/binary
    ports:
      - "5001:5001"
    environment:
      LS_JAVA_OPTS: "-Xmx256m -Xms256m"
    networks:
      - elk
    depends_on:
      - elasticsearch



  kibana:
    build:
      context: kibana/
    volumes:
      - ./kibana/config/:/usr/share/kibana/config:ro
    ports:
      - "5602:5602"
    networks:
      - elk
    depends_on:
      - elasticsearch

networks:

  elk:
    driver: bridge
8

I have isolated the issue to the file input plugin, and only with the specific file being read from. All restart attempts where the file was different worked. Could it be that the sheer volume of data that I'm reading is causing the restart to fail? Its reading in approximately 1GB every 45 seconds.

9

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