Auto_flush_interval is invalid with Logstash 7.5.1

Elastic Stack Logstash
1

Hello,
I've been running Logstash 7.5.1 on IBM Power systems for a couple of months. But, the last time I restarted Logstash, it kept shutdown and restarting. So I run it with

config.debug = true
log.level: trace

and found errors in logstash-plain.log about invalid config setting auto_flush_interval.

[2020-07-20T18:06:04,589][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"7.5.1"}
[2020-07-20T18:06:07,562][INFO ][org.reflections.Reflections] Reflections took 72 ms to scan 1 urls, producing 20 keys and 40 values
[2020-07-20T18:06:08,250][ERROR][logstash.filters.grok    ] Unknown setting 'auto_flush_interval' for grok
[2020-07-20T18:06:08,264][ERROR][logstash.agent           ] Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:main, :exception=>"Java::JavaLang::IllegalStateException", :message=>"Unable to configure plugins: (ConfigurationError) Something is wrong with your configuration.",...

I've looked in all Logstash *.conf and *.yml files and didn't see auto_flush_interval defined anywhere. Could this property be set up internal of a plugin? We do have a Logstash plugin to read in input data but I have no details about it.

2

auto_flush_interval is an option on a multiline codec, not a grok filter.

If you have enabled config.debug it should be showing you the configuration it is using and you can search that for auto_flush_interval.

3

Thank you for the reply. I just saw that I might have a typo when defining config.debug (with = instead of :). Will fix that and see if it'll print out which config file auto_flush_interval was in.

4

Interesting... After I changed "config.debug = true" to "config.debug: true" and restarted Logstash, the error auto_flush_interval didn't occur. However, Logstash still failed as before:

[2020-07-21T11:35:47,225][DEBUG][org.logstash.ackedqueue.QueueUpgrade] PQ version file with correct version information (v2) found.
[2020-07-21T11:35:47,228][DEBUG][org.logstash.ackedqueue.Queue] opening head page: 68, in: /var/log/logstash/logstash-queue/main, with checkpoint: pageNum=68, firstUnackedPageNum=68, firstUnackedSeqNum=8385120, minSeqNum=8348433, elementCount=36687, isFullyAcked=yes
[2020-07-21T11:35:47,462][ERROR][logstash.agent           ] Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:main, :exception=>"Java::JavaLang::NoSuchMethodError", :message=>"java.nio.MappedByteBuffer.position(I)Ljava/nio/MappedByteBuffer;", :backtrace=>["org.logstash.ackedqueue.io.MmapPageIOV2.recover(MmapPageIOV2.java:135)", "org.logstash.ackedqueue.Queue.open(Queue.java:210)", "org.logstash.ackedqueue.ext.JRubyAckedQueueExt.open(JRubyAckedQueueExt.java:101)", "org.logstash.ackedqueue.ext.JRubyWrappedAckedQueueExt.initialize(JRubyWrappedAckedQueueExt.java:42)", "org.logstash.ackedqueue.QueueFactoryExt.create(QueueFactoryExt.java:39)", "org.logstash.execution.AbstractPipelineExt.openQueue(AbstractPipelineExt.java:174)", "org.logstash.execution.AbstractPipelineExt$INVOKER$i$0$0$openQueue.call(AbstractPipelineExt$INVOKER$i$0$0$openQueue.gen)", "org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:354)", "org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:143)", "org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:345)", ...

I wonder if it's some problem with jruby and why it didn't fail month ago.

5

There are other java errors after the above jruby error:

[2020-07-21T14:03:56,433][ERROR][logstash.agent           ] An exception happened when converging configuration {:exception=>LogStash::Error, :message=>"Don't know how to handle `Java::JavaLang::NoSuchMethodError` for `PipelineAction::Create<main>`", :backtrace=>["org/logstash/execution/ConvergeResultExt.java:109:in `create'", "org/logstash/execution/ConvergeResultExt.java:37:in `add'", "/usr/share/logstash/logstash-core/lib/logstash/agent.rb:339:in `block in converge_state'"]}
[2020-07-21T14:03:56,443][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<LogStash::Error: Don't know how to handle `Java::JavaLang::NoSuchMethodError` for `PipelineAction::Create<main>`>, :backtrace=>["org/logstash/execution/ConvergeResultExt.java:109:in `create'", "org/logstash/execution/ConvergeResultExt.java:37:in `add'", "/usr/share/logstash/logstash-core/lib/logstash/agent.rb:339:in `block in converge_state'"]}
[2020-07-21T14:03:56,440][DEBUG][logstash.agent           ] Starting puma
[2020-07-21T14:03:56,451][DEBUG][logstash.agent           ] Trying to start WebServer {:port=>9600}
[2020-07-21T14:03:56,453][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemExit) exit

I didn't know that logstash also runs a web server. Is this right? So it can't start the web server at port 9600 for some reasons?

6

Yes, logstash runs a webserver for the monitoring API.

That exception is occuring here. It is trying to throw an exception, but the NoSuchMethodError means you do not get to see what exception it wanted to throw.

Is the JVM you are using supported?

I do not think it will change anything, but can you try running with "--java_execution false"?

7

The JVM is official release on RHEL 8.1:

openjdk 13.0.2 2020-01-14
OpenJDK Runtime Environment 19.9 (build 13.0.2+8)
OpenJDK 64-Bit Server VM 19.9 (build 13.0.2+8, mixed mode, sharing)

I run Logstash with systemctl. Sorry, I'm not sure how to run with "--java_execution false". Can I set that in logstash.yml?

8

Yes.

pipeline.java_execution: false
9

Running with java_execution: false resulted in the same error. Following is the "long" jruby error that I didn't want to post here. But, may be there's clue in there as per which method was causing problem. Could you take a look please:

[2020-07-21T14:55:45,315][ERROR][logstash.agent           ] Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:main, 
:exception=>"Java::JavaLang::NoSuchMethodError", 
:message=>"java.nio.MappedByteBuffer.position(I)Ljava/nio/MappedByteBuffer;", 
:backtrace=>["org.logstash.ackedqueue.io.MmapPageIOV2.create(MmapPageIOV2.java:171)", 
"org.logstash.ackedqueue.Queue.newCheckpointedHeadpage(Queue.java:315)", 
"org.logstash.ackedqueue.Queue.open(Queue.java:166)", 
"org.logstash.ackedqueue.ext.JRubyAckedQueueExt.open(JRubyAckedQueueExt.java:101)", 
"org.logstash.ackedqueue.ext.JRubyWrappedAckedQueueExt.initialize(JRubyWrappedAckedQueueExt.java:42)", 
"org.logstash.ackedqueue.QueueFactoryExt.create(QueueFactoryExt.java:39)", 
"org.logstash.execution.AbstractPipelineExt.openQueue(AbstractPipelineExt.java:174)", 
"org.logstash.execution.AbstractPipelineExt$INVOKER$i$0$0$openQueue.call(AbstractPipelineExt$INVOKER$i$0$0$openQueue.gen)", 
"org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:354)", 
"org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:143)", 
"org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:345)", 
"org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)", 
"org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:105)", 
"org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:92)", 
"org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332)", 
"org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86)", 
"org.jruby.RubyClass.newInstance(RubyClass.java:915)", 
"org.jruby.RubyClass$INVOKER$i$newInstance.call(RubyClass$INVOKER$i$newInstance.gen)", 
"org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332)", 
"org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86)", 
"org.jruby.ir.instructions.CallBase.interpret(CallBase.java:540)", 
"org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:361)", 
"org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)", 
"org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:92)", 
"org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:204)", 
"org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:191)", 
"org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:208)", 
"org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:396)", 
"org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:205)", 
"org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:325)", 
"org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)", 
"org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:114)", 
"org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:151)", 
"org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:79)", 
"org.jruby.runtime.Block.call(Block.java:129)", 
"org.jruby.RubyProc.call(RubyProc.java:295)", 
"org.jruby.RubyProc.call(RubyProc.java:274)", 
"org.jruby.RubyProc.call(RubyProc.java:270)", 
"org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105)", "java.lang.Thread.run(Thread.java:748)"]}
10

I manually broke apart the long string. Maybe that is worth to take a look? Thanks!

11

OK, so MmapPageIOV2.java:171 is this line of code. It is calling .position on a java.nio.MappedByteBuffer and passing it an int. The problem is, it is looking for a method that returns a java.nio.MappedByteBuffer, and since position is inherited I suspect it can only find a .position method that returns a Buffer.

Can you try running this with Java 1.8? There are some this in issue lists for a couple of other projects that make this sound like it might be a workaround.

12

My logstash is built for the Power systems (ppc64le) and RHEL 8.1 particularly. I wasn't able to install it with Java 1.8. That's why I upgraded to Java-13. It probably will not work if I go back to Java 1.8. I'm still wondering how did it work for the time before this error happened when I restarted logstash. It's possible some other software installations changed java or jruby. I don't have control on all software installations. But, I'm thinking, maybe I can reinstall Java-13. Do you think that's worth a try?

13

You could try it, but I am not optimistic.

14

There is actually another version of Java (1.8) on the same system. I've been keeping the ELK stack to run with Java-13 by using $JAVA_HOME and $PATH. I just tried setting

export JAVA_HOME=/usr/lib/jvm/java-1.8.0
export PATH=/usr/lib/jvm/java-1.8.0/bin:$PATH

Then, started Logstash. It got the same error. Is this what you suggested to try?

15

Yes. Unfortunately I have no further ideas.

16

Thanks for helping to look into a couple problems! I uninstalled and installed java-13 and still got the same error. Because it's questionable that the error is a result of Logstash failed to get an integer returned from a java function, I'll open a GitHub issue to get a further look into the problem. I also ran out of ideas to try.

17

GitHub ticket opened: https://github.com/elastic/logstash/issues/12133

18

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