Logstash ConcurrentModificationException: null

rojin · July 15, 2021, 9:36am

Hi, has anyone encountered this issue? Logstash instances keep restarting after a while with this error:

[2021-07-14T14:35:23,972][FATAL][logstash.runner ] An unexpected error occurred! {:error=>java.lang.IllegalStateException: java.util.ConcurrentModificationException, :backtrace=>["org.logstash.execution.WorkerLoop.run(org/logstash/execution/WorkerLoop.java:85)", "jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)", "jdk.internal.reflect.NativeMethodAccessorImpl.invoke(jdk/internal/reflect/NativeMethodAccessorImpl.java:62)", "jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(jdk/internal/reflect/DelegatingMethodAccessorImpl.java:43)", "java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:566)", "org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(org/jruby/javasupport/JavaMethod.java:440)", "org.jruby.javasupport.JavaMethod.invokeDirect(org/jruby/javasupport/JavaMethod.java:304)", "usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.start_workers(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:243)", "org.jruby.RubyProc.call(org/jruby/RubyProc.java:295)", "org.jruby.RubyProc.call(org/jruby/RubyProc.java:274)", "org.jruby.RubyProc.call(org/jruby/RubyProc.java:270)", "java.lang.Thread.run(java/lang/Thread.java:834)"]}

Could the reason be that previous logs do not have this field?

Their pipelines are exactly the same. Nginx logs were changed (a part was added to them) and thus, I changed grok patterns and added a field to "message". After that, logstash instances kept restarting. logs are shipped to elasticsearch and could be seen on Kibana as well.

Can anyone suggest me a solution to this problem? Thanks in advance!

Janko · July 15, 2021, 5:02pm

Hey there, could you please specify the exact version of Logstash and any plugins you use here?

What field exactly is new here?

There might be more information pre and post the error, as well as in the Elasticsearch logs.
Can you please check and see if anything correlates there?

Cheers!

rojin · July 15, 2021, 7:52pm

HI Janko! I am using ELK version 7.4.2 (also Filebeat version 7.4.2). The plugins include ip2location and for the filter, I am using Grok. The error logs before the FATAL error:

[2021-07-14T14:35:23,748][ERROR][org.logstash.execution.WorkerLoop][main] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash.
java.util.ConcurrentModificationException: null
        at java.util.IdentityHashMap.forEach(IdentityHashMap.java:1358) ~[?:?]
        at org.logstash.Rubyfier.deepMap(Rubyfier.java:71) ~[logstash-core.jar:?]
        at org.logstash.Rubyfier.lambda$initConverters$8(Rubyfier.java:99) ~[logstash-core.jar:?]
        at org.logstash.Rubyfier.deep(Rubyfier.java:53) ~[logstash-core.jar:?]
        at org.logstash.ext.JrubyEventExtLibrary$RubyEvent.ruby_get_field(JrubyEventExtLibrary.java:85) ~[logstash-core.jar:?]
        at usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_filter_minus_ip2location_minus_2_dot_1_dot_0.lib.logstash.filters.ip2location.RUBY$method$filter$0(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-ip2location-2.1.0/lib/logstash/filters/ip2location.rb:50) ~[?:?]
        at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:117) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:156) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:253) ~[jruby-complete-9.2.8.0.jar:?]
        at usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.RUBY$method$do_filter$0(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:143) ~[?:?]
        at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:117) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:156) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.ir.targets.InvokeSite.fail(InvokeSite.java:253) ~[jruby-complete-9.2.8.0.jar:?]
        at usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.RUBY$block$multi_filter$1(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:162) ~[?:?]
        at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.runtime.BlockBody.yield(BlockBody.java:114) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.runtime.Block.yield(Block.java:170) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.RubyArray.each(RubyArray.java:1800) ~[jruby-complete-9.2.8.0.jar:?]
        at usr.share.logstash.logstash_minus_core.lib.logstash.filters.base.RUBY$method$multi_filter$0(/usr/share/logstash/logstash-core/lib/logstash/filters/base.rb:159) ~[?:?]
at org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:117) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:156) ~[jruby-complete-9.2.8.0.jar:?]
        at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200) ~[jruby-complete-9.2.8.0.jar:?]
        at org.logstash.config.ir.compiler.FilterDelegatorExt.doMultiFilter(FilterDelegatorExt.java:99) ~[logstash-core.jar:?]
        at org.logstash.config.ir.compiler.AbstractFilterDelegatorExt.multiFilter(AbstractFilterDelegatorExt.java:115) ~[logstash-core.jar:?]
        at org.logstash.generated.CompiledDataset158.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset159.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset160.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset161.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset162.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset163.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset164.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset165.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset166.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset167.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset168.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset169.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset170.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset171.compute(Unknown Source) ~[?:?]
        at org.logstash.generated.CompiledDataset172.compute(Unknown Source) ~[?:?]
        at org.logstash.execution.WorkerLoop.run(WorkerLoop.java:64) [logstash-core.jar:?]
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
        at org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:440) [jruby-complete-9.2.8.0.jar:?]
        at org.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:304) [jruby-complete-9.2.8.0.jar:?]
        at org.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:36) [jruby-complete-9.2.8.0.jar:?]
        at usr.share.logstash.logstash_minus_core.lib.logstash.java_pipeline.RUBY$block$start_workers$2(/usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:243) [jruby-complete-9.2.8.0.jar:?]
       at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105) [jruby-complete-9.2.8.0.jar:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]

A log sample would be:

2.147.123.21 - - [27/Jun/2021:01:32:08 +0430] "GET /dl-main/main.347.com.mn.tmntpp.mp4?st=aan3YDHYSZ9b4891EgOw&e=1690821264&product_id=189062&package_name=com.mn.tmnp&user_id=173646&parent_category_id=100&name="glass%2+book" HTTP/1.1" 200 1090000 "device_name)" 261.300 -

Here's the input configuration:

input {
  beats {
    port => 5044
  }
}

And one of the configuration's filters pattern (I added the name part to the pattern):

filter {
        if [fields][log_type] == "correct" {
           grok {
                match => { "message" => "%{IPV4:clientip} - - \[%{HTTPDATE:timestamp}\] \"%{WORD:verb} %{URIPATH:request}.*(?:product_id=%{INT:product_id}).*(?:product_name=%{DATA:product_name}&).*(?:user_id=%{INT:user_id}).*(?:parent_category_id=%{INT:category}).*(?:name=%{DATA:name}) HTTP/%{NUMBER:httpversion}\" %{NUMBER:response} %{NUMBER:bytes_sent}" }
           add_tag => ["healthy"]
           }
         if [clientip] {       
           ip2location  {
               use_memory_mapped => true
              source => "clientip"
              database => "/etc/logstash/conf.d/isps.BIN"
              }
           }
        }
}

The output would be like so (there's a real IP address instead of what's been mentioned and also log_type is defined in filebeat.yml):

output {
  if [fields][log_type] in [ "correct", "error" ] and "_grokparsefailure" not in [tags] {
     elasticsearch {
       user => "elastic"
       password => "password"
       hosts => ["THE_IP_ADDRESS:9200"]
       ilm_enabled => false
       manage_template => true
       document_id => "%{[@metadata][fingerprint]}"
       index => "logstash-product-%{+YYYY.MM}"
     }
   }
}

Badger · July 15, 2021, 8:20pm

If you run with --pipeline.workers 1 does the problem still occur? The Cache.find method is synchronized, so at first glance it should not have concurrency issues, but there may be a corner case...

rojin · July 16, 2021, 4:50am

Hi Badger! Logstash instances are running as a service and I have not changed anything in Logstash configurations for pipeline workers. What does this command do? Doesn't it have an effect on incomming logs?
The workers are set to 2 or 3 on the hosts with Filebeat. Could you please explain more about the problem? I can’t grasp it.

Could it be because previous logs did not include this field?

Janko · July 17, 2021, 12:31am

Thanks for the details @rojin

Funnily enough this sounds exactly like Logstash execption in pipeline worker where @badger also responded and pointed to ConcurrentModificationException · Issue #19 · ip2location/logstash-filter-ip2location · GitHub where it was suggested to try version 2.1.2. of ip2location. You seem to be using a previous version here so I'd give updating a try.
Not hearing back on that previous issue could well mean that this resolved the problem back then.

I had seen this issue initially and now that you also use ip2location, and on the same Elastic stack version, it seems that this might indeed be fitting. It can be hard at times to select the correct parts of a message to search for related issues and, as I mentioned on Slack, more information upfront is always helpful. Had you initially mentioned that this plugin was used and on what version, I would have directly suggested to look in that direction.

Have a great weekend, all!

rojin · July 17, 2021, 5:15am

Hi!, I updated the ip2location and now it restarts like every 10 seconds. What am I supposed to do?

Janko · July 18, 2021, 10:17am

Check what it says around the restarting time, maybe some configuration part is missing.
You might need to enable more verbose logging depending on the reason.

That being said, if this didn't help I'd try and reproduce this first on a recent version. The Elastic stack 7.4.2 has been end of life for a couple of months now (Elastic Product End of Life Dates | Elastic) and spending much time digging into issues with old releases can at times be saved this way.

There are also many improvements, performance enhancements and other bug fixes since this version was initially released.

rojin · July 23, 2021, 11:22am

It does not start logstash anymore, also does not write anything (any logs) in /var/log/logstash. It gives me the error while trying it with bin/logstash or the service:

[ERROR] 2021-07-18 10:26:53.732 [main] Logstash - java.lang.IllegalStateException: Logstash stopped processing because of an error: (LoadError) load error: /usr/share/logstash/logstash-core/lib/logstash/runner -- java.lang.RuntimeException: BUG: refined marker called as method

Badger · July 23, 2021, 4:45pm

That is a known JRuby bug that is fixed in newer versions. You should upgrade logstash.

rojin · July 24, 2021, 5:53am

Oh! then is it okay to use newer versions of logstash with elasticsearch and filebeat version 7.4.2?

system · August 21, 2021, 5:53am

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

Topic		Replies	Views
Force! Logstash keeps restarting Logstash elastic-stack-monitoring	1	229	August 11, 2021
Logstash resarting with error Logstash	1	249	August 11, 2021
Logstash restarts with "ConcurrentModificationException" Logstash	1	307	August 12, 2021
Logstash restart - Exception in pipelineworker Logstash	7	1476	September 6, 2019
Logstash Error - SystemExit Logstash	1	582	July 9, 2019

Logstash ConcurrentModificationException: null

Related Topics