search

logstash-plugins / logstash-output-rabbitmq

Apache License 2.0
17 stars 37 forks source link

Connection unrecoverables after RabbitMQ server restart #55

Open kavat opened 7 years ago

kavat commented 7 years ago

Hi, we restarted our rabbitmq server for a maintenance and logstash clients started to write in the log file this string:

[2016-12-30T13:42:32,108][ERROR][logstash.outputs.rabbitmq] Error while publishing. Will retry. {:message=>"#method(reply-code=320, reply-text=CONNECTION_FORCED - broker forced connection closure with reason 'shutdown', class-id=0, method-id=0)", :exception=>MarchHare::ChannelAlreadyClosed, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/exceptions.rb:121:in convert_and_reraise'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:980:inconverting_rjc_exceptions_to_ruby'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:978:in converting_rjc_exceptions_to_ruby'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:606:inbasic_publish'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/exchange.rb:77:in publish'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-rabbitmq-4.0.4-java/lib/logstash/outputs/rabbitmq.rb:54:inpublish'", "org/jruby/RubyProc.java:281:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-codec-json-3.0.2/lib/logstash/codecs/json.rb:42:inencode'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-rabbitmq-4.0.4-java/lib/logstash/outputs/rabbitmq.rb:47:in receive'", "/usr/share/logstash/logstash-core/lib/logstash/outputs/base.rb:92:inmulti_receive'", "org/jruby/RubyArray.java:1613:in each'", "/usr/share/logstash/logstash-core/lib/logstash/outputs/base.rb:92:inmulti_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator_strategies/legacy.rb:19:in multi_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator.rb:42:inmulti_receive'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:297:in output_batch'", "org/jruby/RubyHash.java:1342:ineach'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:296:in output_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:252:inworker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:225:in `start_workers'"]}

The solution was restart the logstash service.

We use:

The logstash configuration is set with the heartbeat parameter, like bottom:

    rabbitmq {
        exchange => "logstash"
        exchange_type => "topic"
        host => "XXX.XXX.XXX.XXX"
        port => "XXXX"
        user => "user"
        password => "password"
        key => ""
        ssl => true
        heartbeat => "5"
    }

Can you help us please?

kavat commented 7 years ago

Hi, can anyone help us please?

andrewvc commented 7 years ago

@kavat it looks like you shutdown your rabbitmq cluster with rabbitmqctl. Is that correct? Did the error message ever go away?

kavat commented 7 years ago

Hi @andrewvc , I restarted my RabbitMQ with reboot command. I continued see the error until I restarted logstash service. Why has not logstash client retried the connection and it has entered into this error log infinite loop?

kavat commented 7 years ago

Hi @andrewvc, In the next days we have to restart out rabbitmq server and we are worried about this. Have my informations helped you in your analysis? Have you got any news? Sorry but we need a urgent fix or workaround.

kavat commented 7 years ago

Any news?

andrewvc commented 7 years ago

@kavat AFAIK rabbitmqctl has no reboot command, you can stop and start it. I assume you're using an init script?

At any rate, I just tested it with a manual start and a rabbitmqctl stop and everything worked great.

The logstash config I used was: bin/logstash -e "input { stdin {} } output { rabbitmq { exchange => foobar exchange_type => fanout host => localhost} }"

I'll need a detailed reproducible test case to go any further with this.

It might even make sense to upload a virtualbox VM demonstrating this error.

Given that others haven't reported this error I am leaning toward this being an environment issue. RabbitMQ is very finicky to setup and there is a large amount of variation between environments.

kavat commented 7 years ago

I've reboot the entire linux server rabbitmq, with the command via ssh reboot. The server went down and the client started to write in log

[2016-12-30T13:42:32,108][ERROR][logstash.outputs.rabbitmq] Error while publishing. Will retry. {:message=>"#method(reply-code=320, reply-text=CONNECTION_FORCED - broker forced connection closure with reason 'shutdown', class-id=0, method-id=0)", :exception=>MarchHare::ChannelAlreadyClosed, :backtrace=>["/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/exceptions.rb:121:in convert_and_reraise'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:980:inconverting_rjc_exceptions_to_ruby'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:978:in converting_rjc_exceptions_to_ruby'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/channel.rb:606:inbasic_publish'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/march_hare-2.20.0-java/lib/march_hare/exchange.rb:77:in publish'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-rabbitmq-4.0.4-java/lib/logstash/outputs/rabbitmq.rb:54:inpublish'", "org/jruby/RubyProc.java:281:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-codec-json-3.0.2/lib/logstash/codecs/json.rb:42:inencode'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-output-rabbitmq-4.0.4-java/lib/logstash/outputs/rabbitmq.rb:47:in receive'", "/usr/share/logstash/logstash-core/lib/logstash/outputs/base.rb:92:inmulti_receive'", "org/jruby/RubyArray.java:1613:in each'", "/usr/share/logstash/logstash-core/lib/logstash/outputs/base.rb:92:inmulti_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator_strategies/legacy.rb:19:in multi_receive'", "/usr/share/logstash/logstash-core/lib/logstash/output_delegator.rb:42:inmulti_receive'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:297:in output_batch'", "org/jruby/RubyHash.java:1342:ineach'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:296:in output_batch'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:252:inworker_loop'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:225:in `start_workers'"]}

Also when the server recover itself the log continue to append the string before.

Is it clear now?

andrewvc commented 7 years ago

@kavat I already tried rebooting the server, didn't get the same error. What you've submitted is not a sufficient test case.

If you can create a VM image that demonstrates this effect I'd be glad to take a look.

Ghaithjemai commented 3 years ago

I'am having the same error logstash can't recover rabbitmq connection after restarting rabbitmq-server

RabbitMQ connection was closed! {XXXX} :automatic_recovery=>true, :cause=>com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method(reply-code=320, reply-text=CONNECTION_FORCED - broker forced connection closure with reason 'shutdown', class-id=0, method-id=0)}

ara-mark commented 1 month ago

Today i've encountered the same issue, is there any workaround?