Details
-
Type:
Bug
-
Status: Closed
-
Priority:
Major
-
Resolution: Fixed
-
Affects Version/s: v0.9.0
-
Fix Version/s: v0.9.1
-
Component/s: Sinks+Sources
-
Labels:None
-
Environment:Using flume packages on Debian Lenny 64bit.
java -version
java version "1.6.0_20"
Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01, mixed mode)
dpkg -l | egrep 'flume|hadoop'
ii flume 0.9.0+1-1~lenny-cdh3b2 Flume is a reliable, scalable, and manageable distributed log
ii flume-node 0.9.0+1-1~lenny-cdh3b2 The flume node daemon is a core element of flume's data path a
ii hadoop-0.20 0.20.2+320-1~lenny-cdh3b2 A software platform for processing vast amounts of data
ii hadoop-0.20-native 0.20.2+320-1~lenny-cdh3b2 Native libraries for Hadoop (e.g., compression)
ii hadoop-zookeeper 3.3.1+7-1~lenny-cdh3b2 A high-performance coordination service for distributed applic
Using flume packages on Debian Lenny 64bit. java -version java version "1.6.0_20" Java(TM) SE Runtime Environment (build 1.6.0_20-b02) Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01, mixed mode) dpkg -l | egrep 'flume|hadoop' ii flume 0.9.0+1-1~lenny-cdh3b2 Flume is a reliable, scalable, and manageable distributed log ii flume-node 0.9.0+1-1~lenny-cdh3b2 The flume node daemon is a core element of flume's data path a ii hadoop-0.20 0.20.2+320-1~lenny-cdh3b2 A software platform for processing vast amounts of data ii hadoop-0.20-native 0.20.2+320-1~lenny-cdh3b2 Native libraries for Hadoop (e.g., compression) ii hadoop-zookeeper 3.3.1+7-1~lenny-cdh3b2 A high-performance coordination service for distributed applic
Description
ISSUE
I configured rsyslog on debian to forward syslog messages via udp to flume on port 5140 and noticed it had a "java.nio.BufferUnderflowException". Investigation of the source pointed me to that flumes SyslogWireExtractor expects a '\n' char deliminator to signal end of the message. According to RFC3164 on the syslog protocol section 4.1.3 it states that the message payload of the protocol has no ending deliminator. I looked into "RFC5426 - Transmission of Syslog Messages over UDP" which states in section 3.1 that each datagram " MUST contain only one syslog message, which MAY be complete or truncated." RFC 3164 is Obsoleted by RFC 5424 but RFC 5424 does not discuss deliminators in the message section at all. Also it looks as if RFC 5424 is not implemented in lots of syslog servers yet.
CONCLUSION
SyslogWireExtractor needs to be fixed to not expect '\n' character to stop reading from the socket.
How to reproduce.
Setup a flume node to listen on for syslog UDP messages on port 5140 and use the following command to send a log line with no '\n' at the end.
echo -n "<37>hello via syslog" | nc -w0 -u localhost 5140
Console output from flume when no newline is sent.
flume node_nowatch -n host
10/07/14 14:58:57 INFO agent.FlumeNode: Starting flume agent on: hadoop-n02.lab
10/07/14 14:58:57 INFO agent.FlumeNode: Working directory is: /home/konetzed/flume/.
10/07/14 14:58:57 INFO conf.FlumeConfiguration: Loading configurations from /etc/flume/conf
10/07/14 14:58:57 INFO agent.FlumeNode: Flume 0.9.0+1
10/07/14 14:58:57 INFO agent.FlumeNode: rev 7fde7f12540ae30a2d5396115c7fa343a66fd56d
10/07/14 14:58:57 INFO agent.FlumeNode: Compiled on Mon Jun 28 13:39:04 PDT 2010
10/07/14 14:58:58 WARN agent.FlumeNode: Log directory is writing inside of /tmp. This data may not survive reboot!
10/07/14 14:58:58 INFO util.StatusHttpServer: starting web app in directory: /usr/lib/flume/webapps/flumeagent
10/07/14 14:58:58 INFO http.HttpServer: Version Jetty/5.1.4
10/07/14 14:58:58 INFO util.Credential: Checking Resource aliases
10/07/14 14:58:58 INFO util.Container: Started org.mortbay.jetty.servlet.WebApplicationHandler@5eb7ec5d
10/07/14 14:58:58 INFO util.Container: Started WebApplicationContext[/,/]
10/07/14 14:58:58 INFO http.SocketListener: Started SocketListener on 0.0.0.0:35862
10/07/14 14:58:58 INFO util.Container: Started org.mortbay.jetty.Server@77fddc31
10/07/14 14:58:58 INFO agent.ThriftMasterRPC: Connected to master at master:35872
10/07/14 14:58:58 INFO agent.LogicalNodeManager: creating new logical node host
10/07/14 14:58:58 INFO agent.LogicalNode: Connector started: LazyOpenSource | LazyOpenDecorator
10/07/14 14:58:58 INFO agent.LogicalNode: host: Connector stopped: LazyOpenSource | LazyOpenDecorator
10/07/14 14:58:58 INFO agent.LogicalNode: Connector started: LazyOpenSource | LazyOpenDecorator
10/07/14 14:58:58 INFO agent.LogicalNode: host: Connector stopped: LazyOpenSource | LazyOpenDecorator
10/07/14 14:58:58 WARN durability.NaiveFileWALDeco: Context does not have a logical node name – this will likely be a problem if you have multiple WALs
10/07/14 14:58:58 INFO agent.LogicalNode: Node config sucessfully set to FlumeConfigData(timestamp:1278969743523, sourceConfig:syslogUdp( 5140 ), sinkConfig:agentSink( "collector", 35853 ), sourceVersion:1278969743523, sinkVersion:1278969743523, flowID:default-flow)
10/07/14 14:58:58 INFO agent.LogicalNode: Connector started: LazyOpenSource | LazyOpenDecorator
10/07/14 14:59:07 ERROR connector.DirectDriver: Stream source failed! LazyOpenSource | LazyOpenDecorator
java.nio.BufferUnderflowException
at java.nio.Buffer.nextGetIndex(Buffer.java:474)
at java.nio.HeapByteBuffer.get(HeapByteBuffer.java:117)
at com.cloudera.util.ByteBufferInputStream.read(ByteBufferInputStream.java:37)
at java.io.DataInputStream.readByte(DataInputStream.java:248)
at com.cloudera.flume.handlers.syslog.SyslogWireExtractor.extract(SyslogWireExtractor.java:144)
at com.cloudera.flume.handlers.syslog.SyslogWireExtractor.extractEvent(SyslogWireExtractor.java:88)
at com.cloudera.flume.handlers.syslog.SyslogUdpSource.next(SyslogUdpSource.java:86)
at com.cloudera.flume.handlers.debug.LazyOpenSource.next(LazyOpenSource.java:53)
at com.cloudera.flume.core.connector.DirectDriver$PumperThread.run(DirectDriver.java:88)
10/07/14 14:59:07 INFO agent.LogicalNode: Connector hostexited with error
java.nio.BufferUnderflowException
at java.nio.Buffer.nextGetIndex(Buffer.java:474)
at java.nio.HeapByteBuffer.get(HeapByteBuffer.java:117)
at com.cloudera.util.ByteBufferInputStream.read(ByteBufferInputStream.java:37)
at java.io.DataInputStream.readByte(DataInputStream.java:248)
at com.cloudera.flume.handlers.syslog.SyslogWireExtractor.extract(SyslogWireExtractor.java:144)
at com.cloudera.flume.handlers.syslog.SyslogWireExtractor.extractEvent(SyslogWireExtractor.java:88)
at com.cloudera.flume.handlers.syslog.SyslogUdpSource.next(SyslogUdpSource.java:86)
at com.cloudera.flume.handlers.debug.LazyOpenSource.next(LazyOpenSource.java:53)
at com.cloudera.flume.core.connector.DirectDriver$PumperThread.run(DirectDriver.java:88)
10/07/14 14:59:07 INFO core.EventSource: closing SyslogUdpSource on port 5140
Exception in thread "logicalNode host-18" java.lang.NullPointerException
at com.cloudera.flume.agent.durability.NaiveFileWALDeco.close(NaiveFileWALDeco.java:138)
at com.cloudera.flume.agent.AgentSink.close(AgentSink.java:117)
at com.cloudera.flume.core.EventSinkDecorator.close(EventSinkDecorator.java:65)
at com.cloudera.flume.handlers.debug.LazyOpenDecorator.close(LazyOpenDecorator.java:64)
at com.cloudera.flume.agent.LogicalNode$1.fireError(LogicalNode.java:178)
at com.cloudera.flume.core.connector.DirectDriver.fireError(DirectDriver.java:201)
at com.cloudera.flume.core.connector.DirectDriver$PumperThread.run(DirectDriver.java:100)