No logs in dashboard - Logstash crashing?

[FelixForbes]

Hi There,

I have NLS running on 2 nodes - has been working well for quite a while now - it has been very set and forget. One of our users recently told me there was nothing in the dashboard, turns out they were right. If I restart elasticsearch and logstash I get about a minute worth of data then ... nothing. The nodes are identical CentOS (installed from source following the guides on nagios.com) running on ESX5.5. I have given them each 4 cores and 4 Gb of RAM. I'm thinking where I have gone wrong is not telling logstash that more RAM is available. Here is what I saw in /var/log/messages after restarting logstash on one of the nodes:

Nov 17 13:50:19 hector logstash: Nov 17, 2015 1:50:19 PM org.elasticsearch.transport.netty.NettyTransport exceptionCaught
Nov 17 13:50:19 hector logstash: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] exception caught on transport layer [[id: 0x41228af7, /127.0.0.1:33608 :> localhost/127.0.0.1:9300]], closing connection
Nov 17 13:50:19 hector logstash: java.io.StreamCorruptedException: invalid internal transport message format, got (5a,56,1,1)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.transport.netty.SizeHeaderFrameDecoder.decode(SizeHeaderFrameDecoder.java:47)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:425)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.cleanup(FrameDecoder.java:482)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.channelDisconnected(FrameDecoder.java:365)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:102)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.Channels.fireChannelDisconnected(Channels.java:396)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.Channels$4.run(Channels.java:386)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.socket.ChannelRunnableWrapper.run(ChannelRunnableWrapper.java:40)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
Nov 17 13:50:19 hector logstash: at org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
Nov 17 13:50:19 hector logstash: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
Nov 17 13:50:19 hector logstash: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
Nov 17 13:50:19 hector logstash: at java.lang.Thread.run(Thread.java:745)
Nov 17 13:50:22 hector logstash: Error: Your application used more memory than the safety cap of 500M.
Nov 17 13:50:22 hector logstash: Specify -J-Xmx####m to increase it (#### = cap size in MB).
Nov 17 13:50:22 hector logstash: Specify -w for full OutOfMemoryError stack trace
Nov 17 20:10:01 hector systemd: Failed to mark scope session-817.scope as abandoned : Stale file handle
Nov 17 20:50:03 hector systemd: Failed to mark scope session-899.scope as abandoned : Stale file handle

I've highlighted in red the part that is concerning me. If I have 4Gb of RAM available, how high should I put the safety cap? Also, when it says "Specify -J-Xmx####m to increase it (#### = cap size in MB)." where do I specify this? I've had a look at a few other forum posts but can't find the instructions on adding RAM that I am looking for.

[jolson]

When Logstash is crashing, it's typically a good indicator of not enough RAM in _elasticsearch_, not Logstash. This may seem counterintuitive, but when Elasticsearch gets hung up, Logstash hangs in the process. My recommendation is to up the amount of RAM in each instance by 4GB (8GB per instance, 16GB total) and see if the bad behavior improves.

[FelixForbes]

Thanks I've given that a go - doesn't seem to have helped as I only got a minute more of logs before it crashed again.

I saw another post about the elasticsearch heap size so I've upped that for both instances. I'll reboot everything and try again - thanks for the quick reply and suggestion.

[FelixForbes]

That is looking a lot better now - at least I have logs in the dashboard. If I do "service logstash status" I am seeing lots of Message not fully read - is that normal?

[root@hector ~]# service logstash status
Logstash Daemonlogstash.service - LSB: Logstash
Loaded: loaded (/etc/rc.d/init.d/logstash)
Active: active (running) since Wed 2015-11-18 10:14:41 EST; 7min ago
Process: 1140 ExecStart=/etc/rc.d/init.d/logstash start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/logstash.service
├─1634 runuser -s /bin/sh -c exec /usr/local/nagioslogserver/logstash/bin/logstash agent -f /usr/local/nagioslogserver/logstash/etc/conf.d -l /var/log/logs...
└─1668 java -Djava.io.tmpdir=/usr/local/nagioslogserver/tmp -Djava.io.tmpdir=/usr/local/nagioslogserver/tmp -Xmx500m -Xss2048k -Djffi.boot.library.path=/us...

Nov 18 10:17:58 hector.hcf.local logstash[1140]: Nov 18, 2015 10:17:58 AM org.elasticsearch.transport.netty.MessageChannelHandler messageReceived
Nov 18 10:17:58 hector.hcf.local logstash[1140]: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] Message not fully read (response) for [191] handler org.elas...resetting
Nov 18 10:17:59 hector.hcf.local logstash[1140]: Nov 18, 2015 10:17:59 AM org.elasticsearch.transport.netty.MessageChannelHandler messageReceived
Nov 18 10:17:59 hector.hcf.local logstash[1140]: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] Message not fully read (response) for [191] handler org.elas...resetting
Nov 18 10:17:59 hector.hcf.local logstash[1140]: Nov 18, 2015 10:17:59 AM org.elasticsearch.transport.netty.MessageChannelHandler messageReceived
Nov 18 10:17:59 hector.hcf.local logstash[1140]: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] Message not fully read (response) for [193] handler org.elas...resetting
Nov 18 10:18:00 hector.hcf.local logstash[1140]: Nov 18, 2015 10:18:00 AM org.elasticsearch.transport.netty.MessageChannelHandler messageReceived
Nov 18 10:18:00 hector.hcf.local logstash[1140]: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] Message not fully read (response) for [193] handler org.elas...resetting
Nov 18 10:18:00 hector.hcf.local logstash[1140]: Nov 18, 2015 10:18:00 AM org.elasticsearch.transport.netty.MessageChannelHandler messageReceived
Nov 18 10:18:00 hector.hcf.local logstash[1140]: WARNING: [d81b097a-4eb8-4223-8ead-08131a78d2fa] Message not fully read (response) for [194] handler org.elas...resetting
Hint: Some lines were ellipsized, use -l to show in full.

[jolson]

I'd like to see the logstash outputs from both of your nodes. Please run the following on both of them:

Code: Select all

cat /usr/local/nagioslogserver/logstash/etc/conf.d/999*

I'm happy to hear that the upped ES size is helping - what version of NLS are you running? It may be worth updating to the latest if you continue having trouble - there are a lot of performance improvements compared to our older versions. We also set your ES HEAP_SIZE to half of the available memory in your instances so you don't have to toggle with the configuration file yourself.

Let me know how it goes, thanks!

[FelixForbes]

I'm running 1.3.0 - it says it is the latest available when I do an update check.

I've stepped the RAM up again, now 16Gb on each node. That seems to have done the trick. It has been stable for the past few hours now.

Thanks for your help, happy for this to be closed now.

[rkennedy]

You're welcome - we're glad to help. I'll close this now, but feel free to open another thread if you ever need assistance!