shutdownwatcher output during stalled shutdown is not helpful #6507
Description
example with logstash 5.1.1:
/tmp/logstash-5.1.1 % bin/logstash -e "input { generator {} } filter {sleep { time => 1 } }"
Sending Logstash's logs to /tmp/logstash-5.1.1/logs which is now configured via log4j2.properties
[2017-01-09T17:26:05,322][INFO ][logstash.pipeline ] Starting pipeline {"id"=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>500}
[2017-01-09T17:26:05,335][INFO ][logstash.pipeline ] Pipeline main started
[2017-01-09T17:26:05,485][INFO ][logstash.agent ] Successfully started Logstash API endpoint {:port=>9600}
^C[2017-01-09T17:26:23,537][WARN ][logstash.runner ] SIGINT received. Shutting down the agent.
[2017-01-09T17:26:23,548][WARN ][logstash.agent ] stopping pipeline {:id=>"main"}
[2017-01-09T17:26:28,547][WARN ][logstash.runner ] Received shutdown signal, but pipeline is still waiting for in-flight events
to be processed. Sending another ^C will force quit Logstash, but this may cause
data loss.
[2017-01-09T17:26:28,655][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:28,658][ERROR][logstash.shutdownwatcher ] The shutdown process appears to be stalled due to busy or blocked plugins. Check the logs for more information.
[2017-01-09T17:26:33,571][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:38,574][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:43,567][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:48,573][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:53,573][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:26:58,576][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:27:03,566][WARN ][logstash.shutdownwatcher ] {}
[2017-01-09T17:27:08,571][WARN ][logstash.shutdownwatcher ] {}
output in logstash 2.4.1:
/tmp/logstash-2.4.1 % bin/logstash -e "input { generator {} } filter {sleep { time => 1 } }"
Settings: Default pipeline workers: 4
Pipeline main started
^CSIGINT received. Shutting down the agent. {:level=>:warn}
stopping pipeline {:id=>"main"}
Received shutdown signal, but pipeline is still waiting for in-flight events
to be processed. Sending another ^C will force quit Logstash, but this may cause
data loss. {:level=>:warn}
{"inflight_count"=>500, "stalling_thread_info"=>{["LogStash::Filters::Sleep", {"time"=>1}]=>[{"thread_id"=>16, "name"=>"[main]>worker0", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>17, "name"=>"[main]>worker1", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>18, "name"=>"[main]>worker2", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>19, "name"=>"[main]>worker3", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}]}} {:level=>:warn}
The shutdown process appears to be stalled due to busy or blocked plugins. Check the logs for more information. {:level=>:error}
{"inflight_count"=>500, "stalling_thread_info"=>{["LogStash::Filters::Sleep", {"time"=>1}]=>[{"thread_id"=>16, "name"=>"[main]>worker0", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>17, "name"=>"[main]>worker1", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>18, "name"=>"[main]>worker2", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>19, "name"=>"[main]>worker3", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}]}} {:level=>:warn}
{"inflight_count"=>500, "stalling_thread_info"=>{["LogStash::Filters::Sleep", {"time"=>1}]=>[{"thread_id"=>16, "name"=>"[main]>worker0", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>17, "name"=>"[main]>worker1", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>18, "name"=>"[main]>worker2", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}, {"thread_id"=>19, "name"=>"[main]>worker3", "current_call"=>"[...]/vendor/bundle/jruby/1.9/gems/logstash-filter-sleep-2.0.4/lib/logstash/filters/sleep.rb:105:in `sleep'"}]}} {:level=>:warn}