New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Beats input generates thousands of identical messages #15

Closed
hc4 opened this Issue Oct 19, 2016 · 5 comments

Comments

Projects
None yet
2 participants
@hc4
Contributor

hc4 commented Oct 19, 2016

Problem occured twice.
Graylog version: 2.1.1
Beats input: 1.1.2

Incoming messages raised to 100000+ /s
Graylog CPU usage 100%
From ganglia I can see exact moment, when problem occured.
image

Incomming traffic also increased
image

I suspect that root of problem is that Beats input produces messages without confirmation of Ack reveived by remote beat.
Possibly problem caused by #14

@hc4

This comment has been minimized.

Contributor

hc4 commented Oct 19, 2016

This not remote Beat problem, because their version was not changing for months.
But problem started to happen only after updating to Beats input 1.1.2

@hc4

This comment has been minimized.

Contributor

hc4 commented Oct 19, 2016

Attached thread dump, when problem exist - dump.txt

@hc4

This comment has been minimized.

Contributor

hc4 commented Oct 19, 2016

graylog-server restart helps to solve problem (for some time)

@hc4

This comment has been minimized.

Contributor

hc4 commented Oct 19, 2016

a lot of identical messages as a proof :)
image

And the histogramm with 100000000 messages at same time :)
image

@hc4

This comment has been minimized.

Contributor

hc4 commented Oct 19, 2016

last error logged before identical messages generation begins:

2016-10-19T03:37:21.329+03:00 ERROR [NettyTransport] Error in Input [Beats/5735ce701d8ed83590d2c69a] (channel [id: 0x95aabddb, /123.56.251.192:53315 => /172.20.1.206:5044])
java.io.IOException: Broken pipe
    at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[?:1.8.0_91]
    at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) ~[?:1.8.0_91]
    at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) ~[?:1.8.0_91]
    at sun.nio.ch.IOUtil.write(IOUtil.java:51) ~[?:1.8.0_91]
    at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) ~[?:1.8.0_91]
    at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) ~[graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:146) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:99) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:36) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:779) [graylog.jar:?]
    at org.jboss.netty.handler.ssl.SslHandler.flushPendingEncryptedWrites(SslHandler.java:1066) [graylog.jar:?]
    at org.jboss.netty.handler.ssl.SslHandler.wrap(SslHandler.java:1004) [graylog.jar:?]
    at org.jboss.netty.handler.ssl.SslHandler.handleDownstream(SslHandler.java:557) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784) [graylog.jar:?]
    at org.jboss.netty.handler.traffic.GlobalTrafficShapingHandler.submitWrite(GlobalTrafficShapingHandler.java:261) [graylog.jar:?]
    at org.jboss.netty.handler.traffic.AbstractTrafficShapingHandler.writeRequested(AbstractTrafficShapingHandler.java:762) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:582) [graylog.jar:?]
    at org.jboss.netty.channel.Channels.write(Channels.java:704) [graylog.jar:?]
    at org.jboss.netty.channel.Channels.write(Channels.java:671) [graylog.jar:?]
    at org.jboss.netty.channel.AbstractChannel.write(AbstractChannel.java:347) [graylog.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.sendACK(BeatsFrameDecoder.java:170) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.parseJsonFrame(BeatsFrameDecoder.java:185) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.processUncompressedBuffer(BeatsFrameDecoder.java:143) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.processCompressedDataFrames(BeatsFrameDecoder.java:219) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.processCompressedFrame(BeatsFrameDecoder.java:207) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.decode(BeatsFrameDecoder.java:109) [graylog-plugin-beats-1.1.2.jar:?]
    at org.graylog.plugins.beats.BeatsFrameDecoder.decode(BeatsFrameDecoder.java:49) [graylog-plugin-beats-1.1.2.jar:?]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) [graylog.jar:?]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.messageReceived(SimpleChannelHandler.java:142) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [graylog.jar:?]
    at org.jboss.netty.handler.traffic.AbstractTrafficShapingHandler.messageReceived(AbstractTrafficShapingHandler.java:718) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124) [graylog.jar:?]
    at org.graylog2.plugin.inputs.util.PacketInformationDumper.messageReceived(PacketInformationDumper.java:51) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [graylog.jar:?]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [graylog.jar:?]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [graylog.jar:?]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443) [graylog.jar:?]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303) [graylog.jar:?]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [graylog.jar:?]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [graylog.jar:?]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [graylog.jar:?]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [graylog.jar:?]
    at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [graylog.jar:?]
    at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [graylog.jar:?]
    at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [graylog.jar:?]
    at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) [graylog.jar:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_91]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_91]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]

Actualy I have this message logged many times. About 50 per day and all for same Chinese server with bad internet.

@hc4 hc4 changed the title from Beats input generates many identical messages to Beats input generates thousands identical messages Oct 19, 2016

@hc4 hc4 changed the title from Beats input generates thousands identical messages to Beats input generates thousands of identical messages Oct 19, 2016

hc4 added a commit to hc4/graylog-plugin-beats that referenced this issue Oct 26, 2016

Fix frame decoding in case of lost connection
Fixes Graylog2#14 and Graylog2#15
Removed readable bytes checks (it will be checked by ReplayingDecoder)
Added decodingLast implementation, that ignores all received data (we can't use it, because can't send ACK) and resets decoding state
Fixed error message for bad protocol version

@joschi joschi closed this in 8c751e0 Oct 26, 2016

joschi added a commit that referenced this issue Oct 26, 2016

Fix frame decoding in case of lost connection (#17)
Fixes #14
Fixes #15
(cherry picked from commit 8c751e0)

joschi added a commit that referenced this issue Oct 26, 2016

Fix frame decoding in case of lost connection (#17)
Fixes #14
Fixes #15
(cherry picked from commit 8c751e0)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment