On our ELK stack, while ingesting bulk logs, we are seeing HostUnreachableError often followed by connection restoration message in logstash.err. Following that we see NegativeArraySizeException: -1680966849 multiple times and then followed by OOM
[2020-07-23T10:01:01,334][ERROR][logstash.outputs.elasticsearch] Attempted to send a bulk request to elasticsearch' but Elasticsearch appears to be unreachable or down! {:error_message=>"Elasticsearch Unrea
[2020-07-23T10:01:04,645][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://192.168.8.59:9200/"}
[2020-07-23T10:01:04,647][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://192.168.8.59:9200/"}
2020-07-23 10:01:09,546 [main]<file ERROR An exception occurred processing Appender plain_console java.lang.NegativeArraySizeException: -1680966849
at org.jruby.util.ByteList.grow(ByteList.java:1106)
at org.jruby.util.ByteList.append(ByteList.java:545)
at org.jruby.util.Sprintf.rubySprintfToBuffer(Sprintf.java:386)
at org.jruby.util.Sprintf.rubySprintfToBuffer(Sprintf.java:354)
at org.jruby.util.Sprintf.rubySprintf(Sprintf.java:350)
at org.jruby.util.Sprintf.sprintf(Sprintf.java:342)
at org.jruby.RubyString.inspect(RubyString.java:2532)
at org.jruby.RubyString.inspect(RubyString.java:2372)
at org.jruby.RubyString.inspect(RubyString.java:2368)
at org.jruby.RubyString$INVOKER$i$0$0$inspect.call(RubyString$INVOKER$i$0$0$inspect.gen)
at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:318)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:139)
at org.jruby.RubyBasicObject.rbInspect(RubyBasicObject.java:1181)
at org.jruby.RubyObject.inspect(RubyObject.java:427)
at org.jruby.RubyHash$4.visit(RubyHash.java:850)
at org.jruby.RubyHash$4.visit(RubyHash.java:846)
at org.jruby.RubyHash.visitLimited(RubyHash.java:690)
at org.jruby.RubyHash.visitAll(RubyHash.java:675)
at org.jruby.RubyHash.inspectHash(RubyHash.java:841)
at org.jruby.RubyHash.inspect(RubyHash.java:878)
at org.jruby.RubyHash.to_s(RubyHash.java:946)
at org.jruby.RubyHash$INVOKER$i$0$0$to_s.call(RubyHash$INVOKER$i$0$0$to_s.gen)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:137)
at org.jruby.RubyObject.toRubyString(RubyObject.java:229)
at org.jruby.RubyObject.toString(RubyObject.java:238)
at java.base/java.lang.String.valueOf(String.java:2951)
at java.base/java.lang.StringBuilder.append(StringBuilder.java:168)
at org.logstash.log.StructuredMessage.getFormattedMessage(StructuredMessage.java:63)
at org.apache.logging.log4j.core.pattern.MessagePatternConverter.format(MessagePatternConverter.java:141)
at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
at org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:333)
at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:232)
at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:217)
at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:57)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:177)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:170)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:161)
at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:448)
Java OutOfMemoryError stack trace.
[2020-07-23T10:08:44,821][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://192.168.8.59:9200/"}
java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid18945.hprof ...
Heap dump file created [6199797949 bytes in 31.682 secs]
warning: thread "[main]>worker3" terminated with exception (report_on_exception is true):
java.lang.OutOfMemoryError: Java heap space
at java.base/java.util.Arrays.copyOf(Arrays.java:3745)
at java.base/java.io.ByteArrayOutputStream.toByteArray(ByteArrayOutputStream.java:211)
at com.jrjackson.JrJacksonBase.generate(JrJacksonBase.java:72)
at java.base/java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(DirectMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800785c40.invoke(LambdaForm$MH)
at java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800771040.guard(LambdaForm$MH)
at java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800771040.guard(LambdaForm$MH)
at java.base/java.lang.invoke.LambdaForm$MH/0x000000080076ec40.linkToCallSite(LambdaForm$MH)
at opt.logstash.logstash_minus_core.lib.logstash.json.RUBY$method$jruby_dump$0(/opt/logstash/logstash-core/lib/logstash/json.rb:24)
at java.base/java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(DirectMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800780440.invoke(LambdaForm$MH)
at java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800722440.guard(LambdaForm$MH)
at java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800722440.guard(LambdaForm$MH)
at java.base/java.lang.invoke.Invokers$Holder.linkToCallSite(Invokers$Holder)
at opt.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_output_minus_elasticsearch_minus_9_dot_4_dot_0_minus_java.lib.logstash.outputs.elasticsearch.http_client.RUBY$block$bulk$3(/opt/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-output-elasticsearch-9.4.0-java/lib/logstash/outputs/elasticsearch/http_client.rb:119)
at java.base/java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(DirectMethodHandle$Holder)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000801130440.invoke(LambdaForm$MH)
at java.base/java.lang.invoke.Invokers$Holder.invokeExact_MT(Invokers$Holder)
at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)
at org.jruby.runtime.BlockBody.yield(BlockBody.java:114)
at org.jruby.runtime.Block.yield(Block.java:165)
at org.jruby.RubyArray.collect(RubyArray.java:2563)
at org.jruby.RubyArray.map19(RubyArray.java:2577)
at java.base/java.lang.invoke.LambdaForm$DMH/0x0000000800748840.invokeVirtual(LambdaForm$DMH)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800760c40.invoke(LambdaForm$MH)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800768040.guardWithCatch(LambdaForm$MH)
at java.base/java.lang.invoke.LambdaForm$MH/0x0000000800768c40.invoke(LambdaForm$MH)
at java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)
Recent changes:
- We increased the number of shards from 1 to 2 and replicas from 0 to 1 for all our templates. - Not sure if this is causing this behavior.
- The mount point was remounted - I really don't think this is the issue.
- I do see GCs and is that a caused for dropping the connection?
Overall, what is triggerring this whole behavior is a black box for us and need to figure out as soon as possible. The functionality of ingesting logs is broken.
