Open
Description
We observe LockException when logstash process is running. Looking at the logs, before LockException has occurred logstash.agent is trying to fetch the pipelines count but it couldn't get casing JavaNullPointerException.
[logstash.agent] Failed to execute action {:action=>LogStash::PipelineAction::Reload/pipeline_id:logstash, :exception=>'Java::JavaLang::NullPointerException', :message=>'', :backtrace=>['org.jruby.runtime.scopes.DynamicScope5.getValue(Unknown Source)', 'org.jruby.ir.interpreter.InterpreterEngine.retrieveOp(InterpreterEngine.java:594)', 'org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:348)', 'org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)', 'org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)', 'org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)', 'org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:76)', 'org.jruby.runtime.Block.yieldSpecific(Block.java:158)', 'org.jruby.ext.monitor.Monitor.synchronize(Monitor.java:82)', 'org.jruby.ext.monitor.Monitor$INVOKER$i$0$0$synchronize.call(Monitor$INVOKER$i$0$0$synchronize.gen)', 'org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroBlock.call(JavaMethod.java:561)', 'org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:90)', 'org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:103)', 'org.jruby.ir.instructions.CallBase.interpret(CallBase.java:545)', 'org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:367)', 'org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)', 'org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:82)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:201)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:188)', 'org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:220)', 'org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:242)', 'org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:318)', 'org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)', 'org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:82)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:201)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:188)', 'org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:257)', 'org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:270)', 'org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:341)', 'org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)', 'org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:88)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:238)', 'org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:225)', 'org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:228)', 'opt.logstash.logstash_minus_core.lib.logstash.agent.RUBY$block$converge_state$2(/opt/logstash/logstash-core/lib/logstash/agent.rb:386)', 'org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:141)', 'org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:64)', 'org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)', 'org.jruby.runtime.Block.call(Block.java:144)', 'org.jruby.RubyProc.call(RubyProc.java:352)', 'org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:111)', 'java.base/java.lang.Thread.run(Thread.java:829)']}
From the following traceback, logstash is trying to execute the reload pipeline
begin
logger.debug("Executing action", :action => action)
action_result = action.execute(self, @pipelines_registry)
converge_result.add(action, action_result)
unless action_result.successful?
logger.error("Failed to execute action",
:id => action.pipeline_id,
:action_type => action_result.class,
:message => action_result.message,
:backtrace => action_result.backtrace
)
end
Further tracing back, probably when the below lines of code is executed it is returning null and leaving the lock not getting removed.
github.com source
elastic/logstash/blob/main/logstash-core/lib/logstash/pipeline_action/reload.rb#L39-L42
def execute(agent, pipelines_registry)
old_pipeline = pipelines_registry.get_pipeline(pipeline_id)
if old_pipeline.nil?
Could you please let us know on what all scenarios NullPointerException, LockException is occurred. In case if the transaction has failed then as a rescue should it clean the lock for upcoming transaction to complete successfully.