TCP Input - restarting pipeline "stalled" indefinitely and will not shut down


(Micah Hunsberger) #1

Using TCP input breaks shutdown/restart.
the pipeline will not reload if the configuration changes.

  • Version: Logstash v6.3.0, logstash-input-tcp v5.0.9
  • Operating System: Windows Server 2012
  • Config File (if you have sensitive info, please remove it):
input{
    tcp{
        port => 50000
    }
}
filter {
}
output{
}
  • Sample Data: none required

  • Steps to Reproduce: start the pipeline with tcp input, then make a change to the configuration file so the pipeline reloads

  • logstash-plain.log

[2018-07-20T14:07:32,763][INFO ][logstash.pipeline        ] Starting pipeline {:pipeline_id=>"health-check", "pipeline.workers"=>1, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50}
[2018-07-20T14:07:34,857][INFO ][logstash.inputs.tcp      ] Starting tcp input listener {:address=>"0.0.0.0:50000", :ssl_enable=>"false"}
[2018-07-20T14:07:39,435][INFO ][logstash.pipeline        ] Pipeline started successfully {:pipeline_id=>"health-check", :thread=>"#<Thread:0x355e4b9f@C:/LS/logstash-6.3.0/logstash-core/lib/logstash/pipeline_action/create.rb:44 run>"}
[2018-07-20T14:08:13,573][INFO ][logstash.pipelineaction.reload] Reloading pipeline {"pipeline.id"=>:"health-check"}
[2018-07-20T14:08:18,698][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}
[2018-07-20T14:08:18,714][ERROR][logstash.shutdownwatcher ] The shutdown process appears to be stalled due to busy or blocked plugins. Check the logs for more information.
[2018-07-20T14:08:23,672][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}
[2018-07-20T14:08:28,662][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}

that [logstash.shutdownwatcher ] event will repeat indefinitely until logstash is terminated. I let it go for 4 minutes

[2018-07-20T14:11:53,672][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}
[2018-07-20T14:11:58,669][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}
[2018-07-20T14:12:03,666][WARN ][logstash.shutdownwatcher ] {"inflight_count"=>0, "stalling_thread_info"=>{"other"=>[{"thread_id"=>35, "name"=>"[health-check]<tcp", "current_call"=>"[...]/vendor/bundle/jruby/2.3.0/gems/logstash-input-tcp-5.0.9-java/lib/logstash/inputs/tcp.rb:180:in `close'"}, {"thread_id"=>31, "name"=>nil, "current_call"=>"[...]/logstash-core/lib/logstash/pipeline.rb:418:in `read_batch'"}]}}

Then when I shut down logstash, there is still a "java.exe" process that cannot be terminated through task manager. If I try to start logstash again, it will through an exception and not start:

[2018-07-20T14:30:58,510][INFO ][logstash.configmanagement.elasticsearchsource] Configuration Management License OK
[2018-07-20T14:30:58,635][FATAL][logstash.runner          ] Logstash could not be started because there is already another instance using the configured data directory.  If you wish to run multiple instances, you must change the "path.data" setting.
[2018-07-20T14:30:58,650][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit

(Ry Biesemeyer) #2

Thanks for reporting. We'll follow up on the issue you filed logstash-plugins/logstash-input-tcp#119.


(system) #3

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