LogStash::Error: Don't know how to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<main>`

fae · October 27, 2023, 6:46am

Need help troubleshooting logstash java issue, it was working fine until a while ago when it started throwing up this error below:

systemctl status logstash -l
● logstash.service - Logstash service (ELK stack).
   Loaded: loaded (/etc/systemd/system/logstash.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Fri 2023-10-27 14:28:16 +08; 5min ago
  Process: 802 ExecStart=/home/logstash/logstash-7.8.1/bin/logstash (code=exited, status=1/FAILURE)
 Main PID: 802 (code=exited, status=1/FAILURE)

Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: LogStash::Error: Don't know how to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<main>`
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: create at org/logstash/execution/ConvergeResultExt.java:129
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: add at org/logstash/execution/ConvergeResultExt.java:57
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: converge_state at /home/logstash/logstash-7.8.1/logstash-core/lib/logstash/agent.rb:369
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: [2023-10-27T14:28:16,834][ERROR][logstash.agent           ] An exception happened when converging configuration {:exception=>LogStash::Error, :message= to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<main>`"}
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: [2023-10-27T14:28:16,863][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<LogStash::Error: Don't know how to handle `Java::JStateException` for `PipelineAction::Create<main>`>, :backtrace=>["org/logstash/execution/ConvergeResultExt.java:129:in `create'", "org/logstash/execution/ConvergeResultExt.java:57:in `add'", "/home/logstas/logstash-core/lib/logstash/agent.rb:369:in `block in converge_state'"]}
Oct 27 14:28:16 NMS-ELK-LOG.localdomain logstash[802]: [2023-10-27T14:28:16,884][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error: (SystemEx
Oct 27 14:28:16 NMS-ELK-LOG.localdomain systemd[1]: logstash.service: main process exited, code=exited, status=1/FAILURE
Oct 27 14:28:16 NMS-ELK-LOG.localdomain systemd[1]: Unit logstash.service entered failed state.
Oct 27 14:28:16 NMS-ELK-LOG.localdomain systemd[1]: logstash.service failed.

nmselk.conf

input {
        beats {
                port => "9000"
                ssl => false
#               ssl_certificate_authorities => ["ssl/ca/ca.crt"]
#               ssl_certificate => "ssl/logstash/logstash.crt"
#               ssl_key => "ssl/logstash/logstash.pkcs8.key"
#               ssl_verify_mode => "peer"
        }

output {
        if ([level] and [level] <= 4) {
                elasticsearch {
                        hosts => ["SCRUBBED:9200"]
                        index => "filebeat-%{+YYYY.MM.dd}"
                        user => SCRUBBED
                        password => SCRUBBED
                }

pipelines.yml

- pipeline.id: main
  queue.type: persisted
  path.config: /home/logstash/logstash-7.8.1/config/nmselk.conf

not sure how to go about troubleshooting this issue, seek your kind assistance.

leandrojmp · October 27, 2023, 1:12pm

Can you check the system log?

Since the systemd service is failing, you will have some more information in the system logs.

Try to restart logstash and check /var/log/messages or /var/log/syslog for anything related to the logstash service.

fae · October 27, 2023, 6:20pm

hi @leandrojmp , this error was showing in /var/log/messages

[2023-10-22T03:35:45,193][WARN ][logstash.outputs.elasticsearch][main][73edd67285d1e41a35194e6c912a1274694a61fa137ef72a42edbd71dfc2ccb3] Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"filebeat-2023.10.21", :routing=>nil, :_type=>"_doc"}, #<LogStash::Event:0x285a923>], :response=>{"index"=>{"_index"=>"filebeat-2023.10.21", "_type"=>"_doc", "_id"=>nil, "status"=>400, "error"=>{"type"=>"validation_exception", "reason"=>"Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;"}}}}

leandrojmp · October 27, 2023, 7:15pm

This is a completely different error.

On your first post you shared an error that shows that Logstash is not starting, the error you shared now, which would also be present in Logstash error logs, is an indexing error because you reached the maximum number of shards allowed in your cluster, this would mean that your Logstash is at least running.

It is not clear if you are having issues starting Logstash or not.

About that second error, you need to remove some indices from your cluster, you can increase the number of shards allowed, but this is just a temporary fix.

To increase the number of shards per node you can use the following requests on Kibana Dev Tools:

PUT _cluster/settings
{
  "persistent" : {
    "cluster.routing.allocation.total_shards_per_node" : 2000 
  }
}

But keep in mind that this is not a definitive fix, you need to remove some old indices and implement a Index Lifecycle Policy as well.

fae · October 28, 2023, 6:58am

Hi @leandrojmp ,thanks for the reply. I tried deleting indexes but it still didn't work. I did journalct --since "1 min ago" and this showed up:

[root@NMS-ELK-LOG config]# journalctl --since "1 min ago"
-- Logs begin at Thu 2023-10-26 10:49:06 +08, end at Sat 2023-10-28 14:54:47 +08. --
Oct 28 14:54:33 NMS-ELK-LOG.localdomain polkitd[806]: Registered Authentication Agent for unix-process:2736:502683 (system bus name :1.54 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path
Oct 28 14:54:33 NMS-ELK-LOG.localdomain systemd[1]: Started Logstash service (ELK stack)..
Oct 28 14:54:33 NMS-ELK-LOG.localdomain polkitd[806]: Unregistered Authentication Agent for unix-process:2736:502683 (system bus name :1.54, object path /org/freedesktop/PolicyKit1/AuthenticationAge
Oct 28 14:54:43 NMS-ELK-LOG.localdomain logstash[2742]: Sending Logstash logs to /home/logstash/logstash-7.8.1/logs which is now configured via log4j2.properties
Oct 28 14:54:44 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:44,470][INFO ][logstash.runner          ] Starting Logstash {"logstash.version"=>"7.8.1", "jruby.version"=>"jruby 9.2.11.1 (
Oct 28 14:54:46 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:46,992][INFO ][org.reflections.Reflections] Reflections took 28 ms to scan 1 urls, producing 21 keys and 41 values
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,418][ERROR][org.logstash.execution.AbstractPipelineExt] Logstash failed to create queue.
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: java.io.IOException: Unable to allocate 1073741824 more bytes for persisted queue on top of its current usage of 0 bytes
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.Queue.ensureDiskAvailable(Queue.java:828) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.Queue.openPages(Queue.java:201) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.Queue.open(Queue.java:173) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.ext.JRubyAckedQueueExt.open(JRubyAckedQueueExt.java:120) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.ext.JRubyWrappedAckedQueueExt.initialize(JRubyWrappedAckedQueueExt.java:62) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.ackedqueue.QueueFactoryExt.create(QueueFactoryExt.java:59) ~[logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.execution.AbstractPipelineExt.openQueue(AbstractPipelineExt.java:196) [logstash-core.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.logstash.execution.AbstractPipelineExt$INVOKER$i$0$0$openQueue.call(AbstractPipelineExt$INVOKER$i$0$0$openQueue.gen) [jruby-complete-9.
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:831) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at home.logstash.logstash_minus_7_dot_8_dot_1.logstash_minus_core.lib.logstash.java_pipeline.RUBY$method$initialize$0(/home/logstash/logstash-
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:82) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:70) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.RubyClass.newInstance(RubyClass.java:939) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.RubyClass$INVOKER$i$newInstance.call(RubyClass$INVOKER$i$newInstance.gen) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at home.logstash.logstash_minus_7_dot_8_dot_1.logstash_minus_core.lib.logstash.pipeline_action.create.RUBY$method$execute$0(/home/logstash/log
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at home.logstash.logstash_minus_7_dot_8_dot_1.logstash_minus_core.lib.logstash.pipeline_action.create.RUBY$method$execute$0$__VARARGS__(/home/
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:82) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:70) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.ir.targets.InvokeSite.invoke(InvokeSite.java:207) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at home.logstash.logstash_minus_7_dot_8_dot_1.logstash_minus_core.lib.logstash.agent.RUBY$block$converge_state$2(/home/logstash/logstash-7.8.1
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:138) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:52) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.runtime.Block.call(Block.java:139) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.RubyProc.call(RubyProc.java:318) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105) [jruby-complete-9.2.11.1.jar:?]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: at java.lang.Thread.run(Thread.java:750) [?:1.8.0_372]
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,425][ERROR][logstash.agent           ] Failed to execute action {:action=>LogStash::PipelineAction::Create/pipeline_id:nm
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: warning: thread "Converge PipelineAction::Create<nms_elkpipeline>" terminated with exception (report_on_exception is true):
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: LogStash::Error: Don't know how to handle `Java::JavaLang::IllegalStateException` for `PipelineAction::Create<nms_elkpipeline>`
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: create at org/logstash/execution/ConvergeResultExt.java:129
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: add at org/logstash/execution/ConvergeResultExt.java:57
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: converge_state at /home/logstash/logstash-7.8.1/logstash-core/lib/logstash/agent.rb:369
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,440][ERROR][logstash.agent           ] An exception happened when converging configuration {:exception=>LogStash::Error,
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,476][FATAL][logstash.runner          ] An unexpected error occurred! {:error=>#<LogStash::Error: Don't know how to handle
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,490][ERROR][org.logstash.Logstash    ] java.lang.IllegalStateException: Logstash stopped processing because of an error:
Oct 28 14:54:47 NMS-ELK-LOG.localdomain systemd[1]: logstash.service: main process exited, code=exited, status=1/FAILURE
Oct 28 14:54:47 NMS-ELK-LOG.localdomain systemd[1]: Unit logstash.service entered failed state.
Oct 28 14:54:47 NMS-ELK-LOG.localdomain systemd[1]: logstash.service failed.

i think the error is here?

Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: [2023-10-28T14:54:47,418][ERROR][org.logstash.execution.AbstractPipelineExt] Logstash failed to create queue.
Oct 28 14:54:47 NMS-ELK-LOG.localdomain logstash[2742]: java.io.IOException: Unable to allocate 1073741824 more bytes for persisted queue on top of its current usage of 0 bytes

doing df -h gives:

[root@NMS-ELK-LOG config]# df -h
Filesystem               Size  Used Avail Use% Mounted on
devtmpfs                 7.8G     0  7.8G   0% /dev
tmpfs                    7.8G     0  7.8G   0% /dev/shm
tmpfs                    7.8G  3.1M  7.8G   1% /run
tmpfs                    7.8G     0  7.8G   0% /sys/fs/cgroup
/dev/mapper/centos-root   17G   17G  784M  96% /
/dev/sda1               1014M  321M  694M  32% /boot
tmpfs                    1.6G     0  1.6G   0% /run/user/1000

I am not sure if it is because my /dev/mapper/centos-root is near 100% capacity.

leandrojmp · October 28, 2023, 11:58am

Yeah, I just noticed that the second log you shared was not recent, it was from October 22nd.

This is probably the reason, you are using persistent queues, but your disk does not have enough space to allocate some space for the persistent queue.

You need to free up space on your disk.

fae · October 29, 2023, 6:53am

yup that was it, all I did was yum clean all and it's working again, thanks @leandrojmp

system · November 26, 2023, 6:54am

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