# Logstash keeps crashing **URL:** \ **Category:** Logstash\ **Created:** [January 9, 2018, 2:15pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713 "2018-01-09T14:15:01Z")\ **Posts on this page:** 11\ **Page:** 1
**Author:** ![crapoulou](https://avatars.discourse-cdn.com/v4/letter/c/c2a13f/32.png) [@crapoulou](https://discuss.elastic.co/u/crapoulou)\ **Post date:** [January 9, 2018, 2:15pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/1 "2018-01-09T14:15:01Z")
Hello, Every day, logstash is crashing and generating dozens of errors per second in the logs concerning Kafka. I run ELK 5.6.4, Java 1.8.0\_151, Kafka 0.10.0.1. I get 2 logstash servers for indexing linked with Kafka (Server A @ IP 1.2.3.4 & Server B @ IP 1.2.3.5). I copy below the log when logstash is starting but the most important are these lines : 09:45:41 MY-SERVER logstash: [2018-01-04T09:45:41,934][ERROR][logstash.filters.ruby] Ruby exception occurred: undefined method `get' for #\ Jan 4 09:45:41 MY-SERVER logstash: [2018-01-04T09:45:41,935][ERROR][logstash.filters.ruby] Ruby exception occurred: undefined method `get' for #\ Jan 4 09:45:56 MY-SERVER logstash: [2018-01-04T09:45:56,837][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch\_size=\>1, :failures=\>1, :sleep=\>0.01} At the end of the day, logstash crashes and the service is down. The conf file is the following : output{ kafka{ bootstrap\_servers =\> "1.2.3.4:9092,1.2.3.5:9092" ##(IP MANUALLY CHANGED but OK) topic\_id =\> "salsa" codec =\> json{} } } Do you have any idea of this issue ? Many thanks for your help. ``` [...] Jan 4 09:45:10 MY-SERVER logstash: SLF4J: Found binding in [jar:file:/opt/logstash-receiver/vendor/bundle/jruby/1.9/gems/logstash-output-kafka-5.1.11/vendor/jar-dependencies/runtime-jars/slf4j-log4j12-1.7.21.jar!/org/slf4j/impl/StaticLoggerBinder.class] Jan 4 09:45:10 MY-SERVER logstash: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. Jan 4 09:45:10 MY-SERVER logstash: SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] Jan 4 09:45:10 MY-SERVER logstash: [2018-01-04T09:45:10,745][INFO][org.apache.kafka.clients.producer.ProducerConfig] ProducerConfig values: Jan 4 09:45:10 MY-SERVER logstash: bootstrap.servers = [1.2.3.4:9092, 1.2.3.5:9092] ##IP CHANGED MANUALLY IN MY LOG Jan 4 09:45:10 MY-SERVER logstash: [2018-01-04T09:45:10,824][INFO][org.apache.kafka.common.utils.AppInfoParser] Kafka version : 0.10.0.1 Jan 4 09:45:10 MY-SERVER logstash: [2018-01-04T09:45:10,824][INFO][org.apache.kafka.common.utils.AppInfoParser] Kafka commitId : a7a17cdec9eaa6c5 Jan 4 09:45:10 MY-SERVER logstash: [2018-01-04T09:45:10,841][INFO][logstash.pipeline] Starting pipeline {"id"=>"main", "pipeline.workers"=>2, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>250} Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,225][INFO][logstash.inputs.beats] Beats inputs: Starting input listener {:address=>"0.0.0.0:5044"} Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,365][INFO][logstash.inputs.lumberjack] Starting lumberjack input listener {:address=>"0.0.0.0:5555"} Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,804][INFO][org.logstash.beats.Server] Starting server on port: 5044 Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,844][INFO][logstash.pipeline] Pipeline main started Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,879][INFO][logstash.inputs.syslog] Starting syslog udp listener {:address=>"0.0.0.0:10514"} Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,899][INFO][logstash.inputs.syslog] Starting syslog tcp listener {:address=>"0.0.0.0:10514"} Jan 4 09:45:11 MY-SERVER logstash: [2018-01-04T09:45:11,909][INFO][logstash.agent] Successfully started Logstash API endpoint {:port=>9601} Jan 4 09:45:41 MY-SERVER logstash: [2018-01-04T09:45:41,934][ERROR][logstash.filters.ruby] Ruby exception occurred: undefined method `get' for # Jan 4 09:45:41 MY-SERVER logstash: [2018-01-04T09:45:41,935][ERROR][logstash.filters.ruby] Ruby exception occurred: undefined method `get' for # Jan 4 09:45:56 MY-SERVER logstash: [2018-01-04T09:45:56,837][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch_size=>1, :failures=>1, :sleep=>0.01} Jan 4 09:45:56 MY-SERVER logstash: [2018-01-04T09:45:56,868][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch_size=>1, :failures=>1, :sleep=>0.01} Jan 4 09:45:56 MY-SERVER logstash: [2018-01-04T09:45:56,881][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch_size=>1, :failures=>1, :sleep=>0.01} [....] Jan 4 18:09:08 MY-SERVER logstash: [2018-01-08T18:09:08,115][WARN][io.netty.channel.DefaultChannelPipeline] An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception. Jan 4 18:09:08 MY-SERVER logstash: java.io.IOException: Too many open files Jan 4 18:09:08 MY-SERVER logstash: at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) ~[?:1.8.0_151] Jan 4 18:09:08 MY-SERVER logstash: at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) ~[?:1.8.0_151] Jan 4 18:09:08 MY-SERVER logstash: at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) ~[?:1.8.0_151] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.socket.nio.NioServerSocketChannel.doReadMessages(NioServerSocketChannel.java:135) ~[netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.nio.AbstractNioMessageChannel$NioMessageUnsafe.read(AbstractNioMessageChannel.java:75) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:571) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:512) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:426) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:398) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:877) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144) [netty-all-4.1.3.Final.jar:4.1.3.Final] Jan 4 18:09:08 MY-SERVER logstash: at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151] ``` ---
**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\ **Post date:** [January 9, 2018, 5:40pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/2 "2018-01-09T17:40:17Z")
You have got a syntax error in your ruby filter. Also, the kafka output can't reach the kafka system. Post the config and we can help some more. ---
**Author:** ![crapoulou](https://avatars.discourse-cdn.com/v4/letter/c/c2a13f/32.png) [@crapoulou](https://discuss.elastic.co/u/crapoulou)\ **Post date:** [January 10, 2018, 7:46am UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/3 "2018-01-10T07:46:19Z")
Hello guyboertje, I sent the filter configuration files here : [https://www.cjoint.com/doc/18\_01/HAkhSKH2mYl\_Filter-Rules.zip](https://www.cjoint.com/doc/18_01/HAkhSKH2mYl_Filter-Rules.zip) Thank you for your help. ---
**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\ **Post date:** [January 10, 2018, 2:13pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/4 "2018-01-10T14:13:39Z")
First off, the ruby code that fails. In `1-110-filter-log-emon_peer_service.conf` This type of code will not work well, you can't do a double get() like this. ```auto event.get('emon_service').set('executionDuration', event.get('emon_service').get('endTime') - event.get('emon_service').get('startTime')); ``` This is better. ```auto event.set('[emon_service][executionDuration]', event.get('[emon_service][endTime]') - event.get('[emon_service][startTime]')); ``` This is best: ```auto event.set('[emon_service][executionDuration]', (event.get('[emon_service][endTime]') - event.get('[emon_service][startTime]') rescue 0); ``` In `1-999-filter-lowercase-loglevel.conf` the ruby filter code is not very performant at all. This is better: ```auto loglevel = event.get('loglevel').downcase value = 'unknown' case loglevel when 'alert', 'critical', 'debug', 'emergency', 'error','fatal', 'info', 'notice', 'severe', 'trace', 'warn', 'warning' value = loglevel when 'crit' value = 'critical' when 'emerg' value = 'emergency' when 'err' value = 'error' end event.set('loglevel', value) ``` ---
**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\ **Post date:** [January 10, 2018, 3:27pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/5 "2018-01-10T15:27:54Z")
About the Kafka output errors. These errors are the only ones which are trapped and result in a retry **but** are not logged as having happened. `org.apache.kafka.common.errors.TimeoutException` `org.apache.kafka.common.errors.InterruptException` `org.apache.kafka.common.errors.SerializationException` Some internet search on: TimeoutException; not much, ~ client version vs broker version mismatch (but hard fail not intermittent) InterruptException; nothing SerializationException; not much again. The only way to investigate further is for you to edit the kafka output plugin code and logging statements. All other errors are trapped and logged in one form or another. ---
**Author:** ![crapoulou](https://avatars.discourse-cdn.com/v4/letter/c/c2a13f/32.png) [@crapoulou](https://discuss.elastic.co/u/crapoulou)\ **Post date:** [January 11, 2018, 11:03am UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/6 "2018-01-11T11:03:47Z")
I set the logs in debug mode and found this error message : [2018-01-11T10:45:43,018][DEBUG][org.apache.kafka.clients.producer.KafkaProducer] Exception occurred during message send: org.apache.kafka.common.errors.RecordTooLargeException: The message is 13105524 bytes when serialized which is larger than the maximum request size you have configured with the max.request.size configuration. Thus I edited the following files : - /opt/kafka/config/consumer.properties fetch.message.max.bytes=209715200 #added this parameter - /opt/kafka/config/server.properties socket.request.max.bytes=209715200 #instead of 10MB replica.fetch.max.bytes=209715200 #added this parameter message.max.bytes=209715200 #added this parameter I still need to check the ruby exception regarding 'get' method : your previous message may need a lot. I let you know. Thank you for your support. ---
**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\ **Post date:** [January 11, 2018, 11:12am UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/7 "2018-01-11T11:12:13Z")
Great. So it does look like a SerializationException occurred. Sad that logging needs to be at the DEBUG level to spot this. We use the Kafka client jars that hook into our Log4J logging - seems as if this is a Client logging statement at DEBUG. ---
**Author:** ![crapoulou](https://avatars.discourse-cdn.com/v4/letter/c/c2a13f/32.png) [@crapoulou](https://discuss.elastic.co/u/crapoulou)\ **Post date:** [January 12, 2018, 12:57pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/8 "2018-01-12T12:57:29Z")
Unfortunately, today, I get the same issue. Finally, a wrong fix found regarding the max size. It looks the same issue than these topics but my config is correct in /opt/kafka/config/server.properties ! listeners=PLAINTEXT://1.2.3.4:9092 #(IP changed) > [@Sending batch to Kafka failed. Will retry after a delay Logstash error](https://discuss.elastic.co/t/sending-batch-to-kafka-failed-will-retry-after-a-delay-logstash-error/114133): > > Hi, I have a Logstash agent sending lines to a multi broker kafka setup. Currently I am getting the following error in Logstash log: [2017-12-27T15:06:15,369][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch\_size=\>125, :failures=\>125, :sleep=\>0.01} [2017-12-27T15:06:15,370][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch\_size=\>125, :failures=\>125, :sleep=\>0.01} [2017-12-27T15:06:15,370][INFO… > [@Logstash output plugin kafka is not pushing data into kafka](https://discuss.elastic.co/t/logstash-output-plugin-kafka-is-not-pushing-data-into-kafka/104383/3): > > After updating all logstash plugins now i am seeing following logs [2017-10-18T19:55:36,794][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch\_size=\>6, :failures=\>6, :sleep=\>0.01} [2017-10-18T19:56:06,901][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry after a delay. {:batch\_size=\>1, :failures=\>1, :sleep=\>0.01} [2017-10-18T19:56:06,903][INFO][logstash.outputs.kafka] Sending batch to Kafka failed. Will retry aft… (Indeed, I see in the start sequence these two parameters) : security.protocol = PLAINTEXT bootstrap.servers = [1.2.3.4:9092, 1.2.3.5:9092] It's not feeding through kafka. **In debug mode I find :** [2018-01-12T11:49:10,544][DEBUG][org.apache.kafka.clients.NetworkClient] Initiating connection to node -1 at 1.2.3.4:9092. [2018-01-12T11:49:10,546][DEBUG][org.apache.kafka.common.metrics.Metrics] Added sensor with name node--1.bytes-sent [2018-01-12T11:49:10,547][DEBUG][org.apache.kafka.common.metrics.Metrics] Added sensor with name node--1.bytes-received [2018-01-12T11:49:10,547][DEBUG][org.apache.kafka.common.metrics.Metrics] Added sensor with name node--1.latency [2018-01-12T11:49:10,547][DEBUG][org.apache.kafka.common.network.Selector] Connection with /1.2.3.4 disconnected java.net.ConnectException: Connection refused at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:1.8.0\_151] at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) ~[?:1.8.0\_151] at org.apache.kafka.common.network.PlaintextTransportLayer.finishConnect(PlaintextTransportLayer.java:51) ~[kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.common.network.KafkaChannel.finishConnect(KafkaChannel.java:73) ~[kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:309) [kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.common.network.Selector.poll(Selector.java:283) [kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:260) [kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:229) [kafka-clients-0.10.0.1.jar:?] at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:134) [kafka-clients-0.10.0.1.jar:?] at java.lang.Thread.run(Thread.java:748) [?:1.8.0\_151] I tried to shutdown one of the servers. I have only 1 error message from time to time "Sending batch to Kafka failed. Will retry after a delay." Once started, I have many times this error ! Do you have any idea ?? Thank you ! ---
**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\ **Post date:** [January 12, 2018, 2:33pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/9 "2018-01-12T14:33:03Z")
I have no ideas. It seems as if the Kakfa cluster is unstable or the network between LS and Kafka. ---
**Author:** ![crapoulou](https://avatars.discourse-cdn.com/v4/letter/c/c2a13f/32.png) [@crapoulou](https://discuss.elastic.co/u/crapoulou)\ **Post date:** [January 16, 2018, 5:38pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/10 "2018-01-16T17:38:26Z")
I can't explain it as these servers are absolutely in the same VLAN without iptables or FW. I'm really stuck with this. I can see connexions established on port 9092 (IP replaced=d by 1.2.3.4 & 1.2.3.5) : ``` tcp 0 0 1.2.3.5:59195 1.2.3.4:3888 ESTABLISHED 1000 26335 10633/java tcp 0 0 1.2.3.5:9092 1.2.3.4:44920 ESTABLISHED 1001 40394 11884/java tcp 0 0 1.2.3.5:2888 1.2.3.4:48359 ESTABLISHED 1000 135340437 10633/java tcp 0 0 1.2.3.5:42849 1.2.3.4:2181 ESTABLISHED 1001 135340439 11884/java tcp 0 0 1.2.3.5:46989 1.2.3.4:9092 ESTABLISHED 1002 37970 10601/java tcp 0 0 1.2.3.5:47023 1.2.3.4:9092 ESTABLISHED 1001 43655 11884/java tcp 0 0 1.2.3.5:46987 1.2.3.4:9092 ESTABLISHED 1002 37968 10601/java tcp 0 0 1.2.3.5:47060 1.2.3.4:9092 ESTABLISHED 1002 135446083 18598/java ``` And also listening to any IP address : `tcp 0 0 1.2.3.5:9092 0.0.0.0:* LISTEN 1001 37832 11884/java` I'll try to downgrade kafka to previous version. If I downgrade also Logstash to 5.0. Will it work with ElasticSearch 5.6.4 ? Other ideas are of course still welcomed ! Many thanks for your help. ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [February 13, 2018, 5:38pm UTC](https://discuss.elastic.co/t/logstash-keeps-crashing/114713/11 "2018-02-13T17:38:53Z")
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.