New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve error handling if logstah beat input is run twice on the same machine #6495

Closed
cnico opened this Issue Jan 6, 2017 · 1 comment

Comments

Projects
None yet
2 participants
@cnico

cnico commented Jan 6, 2017

Hello,

While migrating from logstash 2.3.1 to 5.1.1, I encountered a few problem.
One of them is that logstash does not shutdown without a kill -9 signal if the filter chain is blocked / stalled.
So I accidently run two logstash instance with the same configuration both of them listen for beat input on port 5044.
During this, I got the following logs :

[2017-01-04T11:44:15,077][ERROR][logstash.pipeline        ] A plugin had an unrecoverable error. Will restart this plugin.
  Plugin: <LogStash::Inputs::Beats port=>5044, id=>"6f8bc7961b72673e633541fcddb2002a6a5f17b0-1", enable_metric=>true, codec=><LogStash::Codecs::Plain id=>"plain_569f6793-d211-405c-bc6c-4263f0a05fc7", enable_metric=>true, charset=>"UTF-8">, host=>"0.0.0.0", ssl=>false, ssl_verify_mode=>"none", include_codec_tag=>true, ssl_handshake_timeout=>10000, congestion_threshold=>5, target_field_for_codec=>"message", tls_min_version=>1, tls_max_version=>1.2, cipher_suites=>["TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384", "TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256", "TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256", "TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384", "TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384", "TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256"], client_inactivity_timeout=>60>
  Error: event executor terminated
[2017-01-04T11:44:16,079][INFO ][org.logstash.beats.Server] Starting server on port: 5044
[2017-01-04T11:44:16,079][WARN ][io.netty.channel.AbstractChannel] Force-closing a channel whose registration task was not accepted by an event loop: [id: 0xadb2ee9f]
java.util.concurrent.RejectedExecutionException: event executor terminated
        at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:840) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:342) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:335) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:765) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:475) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:80) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:74) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.MultithreadEventLoopGroup.register(MultithreadEventLoopGroup.java:85) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:330) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.doBind(AbstractBootstrap.java:281) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:277) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:259) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at org.logstash.beats.Server.listen(Server.java:68) [logstash-input-beats-3.1.12.jar:?]
        at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_111]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_111]
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:436) [?:?]
        at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:300) [?:?]
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:35) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:134) [?:?]
        at rubyjit.LogStash::Inputs::Beats$$run_a30aeb9e5dd342a58558ea937f97cedc6ffae0521846274136.__file__(/home/admtdoc/proto-elk-nca/logstash-5.1.1/vendor/bundle/jruby/1.9/gems/logstash-input-beats-3.1.12-java/lib/logstash/inputs/beats.rb:213) [?:?]
        at rubyjit.LogStash::Inputs::Beats$$run_a30aeb9e5dd342a58558ea937f97cedc6ffae0521846274136.__file__(/home/admtdoc/proto-elk-nca/logstash-5.1.1/vendor/bundle/jruby/1.9/gems/logstash-input-beats-3.1.12-java/lib/logstash/inputs/beats.rb) [?:?]
        at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168) [?:?]
        at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.ast.RescueNode.executeBody(RescueNode.java:221) [?:?]
        at org.jruby.ast.RescueNode.interpret(RescueNode.java:116) [?:?]
        at org.jruby.ast.EnsureNode.interpret(EnsureNode.java:96) [?:?]
        at org.jruby.ast.BeginNode.interpret(BeginNode.java:83) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.ast.BlockNode.interpret(BlockNode.java:71) [?:?]
        at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74) [?:?]
        at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:182) [?:?]
        at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:203) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:326) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:170) [?:?]
        at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:112) [?:?]
        at org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:206) [?:?]
        at org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:194) [?:?]
        at org.jruby.runtime.Interpreted19Block.call(Interpreted19Block.java:125) [?:?]
        at org.jruby.runtime.Block.call(Block.java:101) [?:?]
        at org.jruby.RubyProc.call(RubyProc.java:300) [?:?]
        at org.jruby.RubyProc.call(RubyProc.java:230) [?:?]
        at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:99) [?:?]
        at java.lang.Thread.run(Thread.java:745) [?:1.8.0_111]
[2017-01-04T11:44:16,080][ERROR][io.netty.util.concurrent.DefaultPromise.rejectedExecution] Failed to submit a listener notification task. Event loop shut down?
java.util.concurrent.RejectedExecutionException: event executor terminated
        at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:840) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:342) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:335) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:765) ~[netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.DefaultPromise.safeExecute(DefaultPromise.java:767) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:435) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:111) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:82) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1062) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:486) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:80) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:74) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.channel.MultithreadEventLoopGroup.register(MultithreadEventLoopGroup.java:85) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:330) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.doBind(AbstractBootstrap.java:281) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:277) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at io.netty.bootstrap.AbstractBootstrap.bind(AbstractBootstrap.java:259) [netty-all-4.1.3.Final.jar:4.1.3.Final]
        at org.logstash.beats.Server.listen(Server.java:68) [logstash-input-beats-3.1.12.jar:?]
        at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_111]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_111]
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:436) [?:?]
        at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:300) [?:?]
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:35) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:134) [?:?]
        at rubyjit.LogStash::Inputs::Beats$$run_a30aeb9e5dd342a58558ea937f97cedc6ffae0521846274136.__file__(/home/admtdoc/proto-elk-nca/logstash-5.1.1/vendor/bundle/jruby/1.9/gems/logstash-input-beats-3.1.12-java/lib/logstash/inputs/beats.rb:213) [?:?]
        at rubyjit.LogStash::Inputs::Beats$$run_a30aeb9e5dd342a58558ea937f97cedc6ffae0521846274136.__file__(/home/admtdoc/proto-elk-nca/logstash-5.1.1/vendor/bundle/jruby/1.9/gems/logstash-input-beats-3.1.12-java/lib/logstash/inputs/beats.rb) [?:?]
        at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:181) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168) [?:?]
        at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.ast.RescueNode.executeBody(RescueNode.java:221) [?:?]
        at org.jruby.ast.RescueNode.interpret(RescueNode.java:116) [?:?]
        at org.jruby.ast.EnsureNode.interpret(EnsureNode.java:96) [?:?]
        at org.jruby.ast.BeginNode.interpret(BeginNode.java:83) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.ast.BlockNode.interpret(BlockNode.java:71) [?:?]
        at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74) [?:?]
        at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:182) [?:?]
        at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:203) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:326) [?:?]
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:170) [?:?]
        at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36) [?:?]
        at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105) [?:?]
        at org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:112) [?:?]
        at org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:206) [?:?]
        at org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:194) [?:?]
        at org.jruby.runtime.Interpreted19Block.call(Interpreted19Block.java:125) [?:?]
        at org.jruby.runtime.Block.call(Block.java:101) [?:?]
        at org.jruby.RubyProc.call(RubyProc.java:300) [?:?]
        at org.jruby.RubyProc.call(RubyProc.java:230) [?:?]
        at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:99) [?:?]
        at java.lang.Thread.run(Thread.java:745) [?:1.8.0_111]

The stack trace repeats indefinitely until I understand my mistake.

It would be great of having a better error handling for such a case with a clear error message telling the port 5044 is already in use.

Regards,

@ph

This comment has been minimized.

Show comment
Hide comment
@ph

ph Jan 6, 2017

Member

There is already an issue on the beats repo at logstash-plugins/logstash-input-beats#158

I will close this one.

Member

ph commented Jan 6, 2017

There is already an issue on the beats repo at logstash-plugins/logstash-input-beats#158

I will close this one.

@ph ph closed this Jan 6, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment