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

Silent Drop for empty messages on RAW input #1584

Closed
gruselglatz opened this Issue Nov 25, 2015 · 2 comments

Comments

Projects
None yet
3 participants
@gruselglatz

gruselglatz commented Nov 25, 2015

We have a very very old proprietary system which produces very bad logs, this is why we use the raw input. but the machine produces empty messages and some messages with non printable chars.

Every empty Message produce this stacktrace:

2015-11-25_07:18:12.96801 ERROR [NettyTransport] Error on Input [Raw/Plaintext TCP/565489b1e4b07590aa58b954] (channel [id: 0xf21efd17, /192.168.102.36:34225 :> /192.168.100.21:5515])
2015-11-25_07:18:12.96802 java.lang.IllegalArgumentException: The message payload must not be empty!
2015-11-25_07:18:12.96802       at com.google.common.base.Preconditions.checkArgument(Preconditions.java:122)
2015-11-25_07:18:12.96802       at org.graylog2.plugin.journal.RawMessage.<init>(RawMessage.java:95)
2015-11-25_07:18:12.96802       at org.graylog2.plugin.journal.RawMessage.<init>(RawMessage.java:81)
2015-11-25_07:18:12.96802       at org.graylog2.plugin.inputs.transports.NettyTransport$RawMessageHandler.messageReceived(NettyTransport.java:338)
2015-11-25_07:18:12.96803       at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88)
2015-11-25_07:18:12.96803       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96803       at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
2015-11-25_07:18:12.96803       at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296)
2015-11-25_07:18:12.96804       at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462)
2015-11-25_07:18:12.96805       at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443)
2015-11-25_07:18:12.96805       at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303)
2015-11-25_07:18:12.96805       at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
2015-11-25_07:18:12.96805       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96806       at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
2015-11-25_07:18:12.96806       at org.jboss.netty.channel.SimpleChannelHandler.messageReceived(SimpleChannelHandler.java:142)
2015-11-25_07:18:12.96806       at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88)
2015-11-25_07:18:12.96806       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96806       at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
2015-11-25_07:18:12.96807       at org.jboss.netty.handler.traffic.AbstractTrafficShapingHandler.messageReceived(AbstractTrafficShapingHandler.java:718)
2015-11-25_07:18:12.96807       at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88)
2015-11-25_07:18:12.96807       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96807       at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
2015-11-25_07:18:12.96808       at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124)
2015-11-25_07:18:12.96808       at org.graylog2.plugin.inputs.util.PacketInformationDumper.messageReceived(PacketInformationDumper.java:73)
2015-11-25_07:18:12.96808       at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
2015-11-25_07:18:12.96808       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96808       at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
2015-11-25_07:18:12.96809       at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124)
2015-11-25_07:18:12.96809       at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
2015-11-25_07:18:12.96809       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
2015-11-25_07:18:12.96809       at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
2015-11-25_07:18:12.96809       at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268)
2015-11-25_07:18:12.96810       at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255)
2015-11-25_07:18:12.96810       at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88)
2015-11-25_07:18:12.96810       at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108)
2015-11-25_07:18:12.96810       at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337)
2015-11-25_07:18:12.96810       at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89)
2015-11-25_07:18:12.96811       at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
2015-11-25_07:18:12.96811       at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
2015-11-25_07:18:12.96811       at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
2015-11-25_07:18:12.96812       at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
2015-11-25_07:18:12.96812       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
2015-11-25_07:18:12.96812       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
2015-11-25_07:18:12.96812       at java.lang.Thread.run(Thread.java:745)

But they get into the system and are shown with an empty messagefield in the Web-UI.
I also have the Problem that this machine produces messages with "����" in it.

@bernd bernd added bug S2 P4 labels Feb 11, 2016

@kroepke kroepke added this to the 2.0.0 milestone Mar 30, 2016

@kroepke

This comment has been minimized.

Member

kroepke commented Mar 30, 2016

This will also bubble up all the way to a Kafka consumer, effectively killing the consumer thread.
In this it can severely impact performance, too.

@kroepke

This comment has been minimized.

Member

kroepke commented Mar 30, 2016

Suggested fix: Drop empty messages without exception and introduce a counter for tracking received empty messages.

kroepke added a commit that referenced this issue Mar 30, 2016

Allow RawMessage's payload to be empty (but not null)
RawMessage previously threw an exception when the payload was empty during construction. This lead to errors in the call sites, which, depending on the input, could cause connections and/or threads to be closed, e.g. the Kafka consumer would be shut down.

With this change we accept empty payloads, but discard them before inserting them into the input buffer. Since this happens in a central place we should cover all available inputs.
We also track the number of discarded empty messages and show this with each input next to the throughput metrics. Empty payloads usually indicate a sender error but can be safely ignored for now. Discarded messages do not count towards the local or global incoming messages as they are discarded before being journaled and processed by Graylog.

 This change also improved the exception logging in the NettyTransport, where we now are way less verbose when faced with a "Connection reset by peer". We don't currently write significant information back to the client so we don't need to log the entire (meaningless) stacktrace here. The information is still available on TRACE.

fix #1584

@joschi joschi closed this in #1995 Mar 30, 2016

@kroepke kroepke added the triaged label Sep 21, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment