Flume Agent Stops Sending Data

[Cameron Gandevia <cg...@gmail.com>]

Hi

I'm experiencing a weird problem where my agents stop sending data to my
collector. This seems to happen every couple of hours.

I am currently running the trunk build of flume 0.9.5

Here is the flow per my agent.

{srcVer:'Fri Sep 09 07:39:02 UTC 2011' snkVer:'Fri Sep 09 07:39:02 UTC
2011'
 ts='Fri Sep 09 07:39:02 UTC 2011' flowId:'logDirFlow' source:'tailDir(
"/data1/mutator/logs", fileregex="^perf.*", delim="\\n\\d\\d\\d\\d",
delimMode="next" )' sink:'agentDFOChain( "van-mang-perf-flume-coll
ector1.net:36892" )' }

One thing to note is the log files are not changing during this time as the
application is not running.

On my agent I am running a tail dir. In the agent logs I see the following
It looks like agent can't connect to the collector, retries a few times then
stops. On the collector I see nothing. When I restart the agent everything
starts working again for a few hours.

2011-09-09 07:39:19,124 [FileFailover-26] INFO
 com.cloudera.flume.handlers.thrift.ThriftEventSink - ThriftEventSink to
van-mang-perf-flume-collector1.net:36892 opened
2011-09-09 07:39:19,138 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.StubbornAppendSink - append failed on
event 'van-mang-perf-mutator1 [INFO Fri Sep 09 07:39:06 UTC 2011] {
tailSrcFile : perf.
log.2011-09-03 } \n2011-09-03 00:09:35,150 gr.perf.timer -
AbstractGRCassandraClient.batchMutate, time:  7.42 ms, nanoTime:7415098,
started:2011-09-03 00:09:35.143, startedTime:1315008575143, thread:[Mutator
.performer-thread5], id:1594, ancestors:1578-MutatorRemote.mutate
1581-MutationWriter.queueMutation 1582-MutationWriter.performMutation
1587-CassDynamicPropertyManager.addEventForMessages 1593-CassDynamicPro
pertyManager.addPropertyToMessages,
vmid:da47a127-a4e8-4858-b04b-f20862f97509' with error: Append failed
java.net.SocketException: Broken pipe
2011-09-09 07:39:19,143 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.StubbornAppendSink - append failed on
event 'van-mang-perf-mutator1 [INFO Fri Sep 09 07:39:06 UTC 2011] {
tailSrcFile : perf.
log.2011-09-03 } \n2011-09-03 00:09:35,150 gr.perf.timer -
AbstractGRCassandraClient.batchMutate, time:  7.42 ms, nanoTime:7415098,
started:2011-09-03 00:09:35.143, startedTime:1315008575143, thread:[Mutator
.performer-thread5], id:1594, ancestors:1578-MutatorRemote.mutate
1581-MutationWriter.queueMutation 1582-MutationWriter.performMutation
1587-CassDynamicPropertyManager.addEventForMessages 1593-CassDynamicPro
pertyManager.addPropertyToMessages,
vmid:da47a127-a4e8-4858-b04b-f20862f97509' with error: Failed to open thrift
event sink to van-mang-perf-flume-collector1.net:36892 :
java.net.ConnectException
: Connection refused
2011-09-09 07:39:19,143 [FileFailover-26] INFO
 com.cloudera.flume.handlers.thrift.ThriftEventSink - ThriftEventSink on
port 36892 closed
2011-09-09 07:39:19,143 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentOpenDecorator - Opened
FailoverChainSink on try 0
2011-09-09 07:39:19,153 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentAppendDecorator - append attempt
0 failed, backoff (1000ms): Failed to open thrift event sink to
van-mang-perf-flume
-collector1.net:36892 : java.net.ConnectException: Connection refused
2011-09-09 07:39:20,163 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.StubbornAppendSink - append failed on
event 'van-mang-perf-mutator1 [INFO Fri Sep 09 07:39:06 UTC 2011] {
tailSrcFile : perf.
log.2011-09-03 } \n2011-09-03 00:09:35,150 gr.perf.timer -
AbstractGRCassandraClient.batchMutate, time:  7.42 ms, nanoTime:7415098,
started:2011-09-03 00:09:35.143, startedTime:1315008575143, thread:[Mutator
.performer-thread5], id:1594, ancestors:1578-MutatorRemote.mutate
1581-MutationWriter.queueMutation 1582-MutationWriter.performMutation
1587-CassDynamicPropertyManager.addEventForMessages 1593-CassDynamicPro
pertyManager.addPropertyToMessages,
vmid:da47a127-a4e8-4858-b04b-f20862f97509' with error: Failed to open thrift
event sink to van-mang-perf-flume-collector1.net:36892 :
java.net.ConnectException
: Connection refused
2011-09-09 07:39:20,163 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentOpenDecorator - Opened
FailoverChainSink on try 0
2011-09-09 07:39:20,173 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentAppendDecorator - append attempt
1 failed, backoff (2000ms): Failed to open thrift event sink to
van-mang-perf-flume
-collector1.net:36892 : java.net.ConnectException: Connection refused
2011-09-09 07:39:22,174 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.StubbornAppendSink - append failed on
event 'van-mang-perf-mutator1 [INFO Fri Sep 09 07:39:06 UTC 2011] {
tailSrcFile : perf.
log.2011-09-03 } \n2011-09-03 00:09:35,150 gr.perf.timer -
AbstractGRCassandraClient.batchMutate, time:  7.42 ms, nanoTime:7415098,
started:2011-09-03 00:09:35.143, startedTime:1315008575143, thread:[Mutator
.performer-thread5], id:1594, ancestors:1578-MutatorRemote.mutate
1581-MutationWriter.queueMutation 1582-MutationWriter.performMutation
1587-CassDynamicPropertyManager.addEventForMessages 1593-CassDynamicPro
pertyManager.addPropertyToMessages,
vmid:da47a127-a4e8-4858-b04b-f20862f97509' with error: Failed to open thrift
event sink to van-mang-perf-flume-collector1.net:36892 :
java.net.ConnectException
: Connection refused
2011-09-09 07:39:22,174 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentOpenDecorator - Opened
FailoverChainSink on try 0
2011-09-09 07:39:22,183 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.InsistentAppendDecorator - append attempt
2 failed, backoff (4000ms): Failed to open thrift event sink to
van-mang-perf-flume
-collector1.net:36892 : java.net.ConnectException: Connection refused
2011-09-09 07:39:26,089 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - closed
/data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writing/20110909-0739160
82+0000.3209139959980643.00000024
2011-09-09 07:39:26,090 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - File lives
in /data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writ
ing/20110909-073916082+0000.3209139959980643.00000024
2011-09-09 07:39:26,090 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - constructed new seqfile
event sink: file=/data1/flume/logs/van-mang-perf-mutator1.net_log_
dir_0/dfo_writing/20110909-073926090+0000.3209149967943825.00000024
2011-09-09 07:39:26,193 [FileFailover-26] INFO
 com.cloudera.flume.handlers.debug.StubbornAppendSink - append failed on
event 'van-mang-perf-mutator1 [INFO Fri Sep 09 07:39:06 UTC 2011] {
tailSrcFile : perf.
log.2011-09-03 } \n2011-09-03 00:09:35,150 gr.perf.timer -
AbstractGRCassandraClient.batchMutate, time:  7.42 ms, nanoTime:7415098,
started:2011-09-03 00:09:35.143, startedTime:1315008575143, thread:[Mutator
.performer-thread5], id:1594, ancestors:1578-MutatorRemote.mutate
1581-MutationWriter.queueMutation 1582-MutationWriter.performMutation
1587-CassDynamicPropertyManager.addEventForMessages 1593-CassDynamicPro
pertyManager.addPropertyToMessages,
vmid:da47a127-a4e8-4858-b04b-f20862f97509' with error: Failed to open thrift
event sink to van-mang-perf-flume-collector1.net:36892 :
java.net.ConnectException
: Connection refused
2011-09-09 07:40:09,753 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@746ad0
2011-09-09 07:40:09,753 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-073916082+0000.3209139959980643.00000024
2011-09-09 07:40:09,756 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@191e4c
2011-09-09 07:40:09,757 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-073926090+0000.3209149967943825.00000024
2011-09-09 07:40:09,759 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@11415c8
2011-09-09 07:40:09,759 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-073936097+0000.3209159974692574.00000024
2011-09-09 07:40:09,762 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@1a220e6
2011-09-09 07:40:09,762 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-073946103+0000.3209169980991117.00000024
2011-09-09 07:40:09,765 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@d306dd
2011-09-09 07:40:09,765 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-073956110+0000.3209179987367812.00000024
2011-09-09 07:40:09,767 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@67c1a6
2011-09-09 07:40:16,121 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - closed
/data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writing/20110909-0740061

I then start seeing the following over and over

2011-09-09 07:40:16,121 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - File lives
in /data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writ
ing/20110909-074006116+0000.3209189993586231.00000024
2011-09-09 07:40:16,122 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-074006116+0000.3209189993586231.00000024
2011-09-09 07:40:16,122 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - constructed new seqfile
event sink: file=/data1/flume/logs/van-mang-perf-mutator1.net_log_
dir_0/dfo_writing/20110909-074016122+0000.3209199999915332.00000024
2011-09-09 07:40:16,124 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@17ebe66
2011-09-09 07:40:26,128 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - closed
/data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writing/20110909-0740161
22+0000.3209199999915332.00000024
2011-09-09 07:40:26,128 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - File lives
in /data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writ
ing/20110909-074016122+0000.3209199999915332.00000024
2011-09-09 07:40:26,128 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - opening
new file for 20110909-074016122+0000.3209199999915332.00000024
2011-09-09 07:40:26,128 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - constructed new seqfile
event sink: file=/data1/flume/logs/van-mang-perf-mutator1.net_log_
dir_0/dfo_writing/20110909-074026128+0000.3209210005931912.00000024
2011-09-09 07:40:26,130 [FileFailover-26] INFO
 com.cloudera.flume.agent.diskfailover.DiskFailoverSource - end of file
com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager$StateChangeDeco@12dd76
2011-09-09 07:40:36,134 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.handlers.hdfs.SeqfileEventSink - closed
/data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writing/20110909-0740261
28+0000.3209210005931912.00000024
2011-09-09 07:40:36,134 [Roll-TriggerThread-0] INFO
 com.cloudera.flume.agent.diskfailover.NaiveFileFailoverManager - File lives
in /data1/flume/logs/van-mang-perf-mutator1.net_log_dir_0/dfo_writ
ing/20110909-074026128+0000.3209210005931912.00000024


Thanks