[
https://issues.apache.org/jira/browse/FLUME-2307?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14096325#comment-14096325
]
Nina Safonova commented on FLUME-2307:
--------------------------------------
Unfortunately I already restarted flume. But channel was operating normally,
sinks were reading from it, sources were writing to it. After restart no old
logs was deleted so I did it manually. Here is the log of restart with channel1
related info:
12 Aug 2014 21:36:38,022 INFO [conf-file-poller-0]
(org.apache.flume.channel.DefaultChannelFactory.create:40) - Creating instance
of channel channel1 type FILE
12 Aug 2014 21:36:38,035 INFO [conf-file-poller-0]
(org.apache.flume.node.AbstractConfigurationProvider.loadChannels:205) -
Created channel channel1
12 Aug 2014 21:36:38,205 INFO [conf-file-poller-0]
(org.apache.flume.node.AbstractConfigurationProvider.getConfiguration:119) -
Channel channel1 connected to [es-sink1, es-sink4, es-sink3, es-sink2]
12 Aug 2014 21:36:38,221 INFO [conf-file-poller-0]
(org.apache.flume.node.Application.startAllComponents:139) - Starting new
configuration:{ sourceRunners:{} sinkRunners:{google-BQ-perf-sink1=SinkRunner:
{ policy:org.apache.flume.sink.DefaultSinkProcessor@6eb5845c counterGroup:{
name:null counters:{} } }, es-sink1=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4f04eccc counterGroup:{
name:null counters:{} } }, es-sink4=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4c566d9b counterGroup:{
name:null counters:{} } }, es-sink3=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@3e360244 counterGroup:{
name:null counters:{} } }, es-sink2=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4bcede44 counterGroup:{
name:null counters:{} } }, google-BQ-sink4=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@7a62693d counterGroup:{
name:null counters:{} } }, google-BQ-sink3=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@52eb6290 counterGroup:{
name:null counters:{} } }, google-BQ-sink2=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@5b940677 counterGroup:{
name:null counters:{} } }, google-BQ-sink1=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@53349d99 counterGroup:{
name:null counters:{} } }} channels:{channel1=FileChannel channel1 { dataDirs:
[/local/flume-ng/data/channel1] }, channel2=FileChannel channel2 { dataDirs:
[/local/flume-ng/data/channel2] },
channel3=org.apache.flume.channel.MemoryChannel{name: channel3}} }
12 Aug 2014 21:36:38,222 INFO [conf-file-poller-0]
(org.apache.flume.node.Application.startAllComponents:146) - Starting Channel
channel1
12 Aug 2014 21:36:38,222 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.FileChannel.start:259) - Starting FileChannel
channel1 { dataDirs: [/local/flume-ng/data/channel1] }...
12 Aug 2014 21:36:38,270 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.Log.replay:385) - Found NextFileID 714, from
[/local/flume-ng/data/channel1/log-691, /local/flume-ng/data/channel1/log-707,
/local/flume-ng/data/channel1/log-696, /local/flume-ng/data/channel1/log-697,
/local/flume-ng/data/channel1/log-702, /local/flume-ng/data/channel1/log-710,
/local/flume-ng/data/channel1/log-704, /local/flume-ng/data/channel1/log-711,
/local/flume-ng/data/channel1/log-698, /local/flume-ng/data/channel1/log-686,
/local/flume-ng/data/channel1/log-688, /local/flume-ng/data/channel1/log-706,
/local/flume-ng/data/channel1/log-712, /local/flume-ng/data/channel1/log-705,
/local/flume-ng/data/channel1/log-714, /local/flume-ng/data/channel1/log-713,
/local/flume-ng/data/channel1/log-700, /local/flume-ng/data/channel1/log-689,
/local/flume-ng/data/channel1/log-687, /local/flume-ng/data/channel1/log-690,
/local/flume-ng/data/channel1/log-708, /local/flume-ng/data/channel1/log-701,
/local/flume-ng/data/channel1/log-703, /local/flume-ng/data/channel1/log-692,
/local/flume-ng/data/channel1/log-694, /local/flume-ng/data/channel1/log-709,
/local/flume-ng/data/channel1/log-695, /local/flume-ng/data/channel1/log-693,
/local/flume-ng/data/channel1/log-699]
12 Aug 2014 21:36:38,288 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.EventQueueBackingStoreFileV3.<init>:53) -
Starting up with /local/flume-ng/checkpoints/channel1/checkpoint and
/local/flume-ng/checkpoints/channel1/checkpoint.meta
12 Aug 2014 21:36:38,289 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.EventQueueBackingStoreFileV3.<init>:57) -
Reading checkpoint metadata from
/local/flume-ng/checkpoints/channel1/checkpoint.meta
12 Aug 2014 21:36:38,723 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:249) - Starting replay
of [/local/flume-ng/data/channel1/log-686,
/local/flume-ng/data/channel1/log-687, /local/flume-ng/data/channel1/log-688,
/local/flume-ng/data/channel1/log-689, /local/flume-ng/data/channel1/log-690,
/local/flume-ng/data/channel1/log-691, /local/flume-ng/data/channel1/log-692,
/local/flume-ng/data/channel1/log-693, /local/flume-ng/data/channel1/log-694,
/local/flume-ng/data/channel1/log-695, /local/flume-ng/data/channel1/log-696,
/local/flume-ng/data/channel1/log-697, /local/flume-ng/data/channel1/log-698,
/local/flume-ng/data/channel1/log-699, /local/flume-ng/data/channel1/log-700,
/local/flume-ng/data/channel1/log-701, /local/flume-ng/data/channel1/log-702,
/local/flume-ng/data/channel1/log-703, /local/flume-ng/data/channel1/log-704,
/local/flume-ng/data/channel1/log-705, /local/flume-ng/data/channel1/log-706,
/local/flume-ng/data/channel1/log-707, /local/flume-ng/data/channel1/log-708,
/local/flume-ng/data/channel1/log-709, /local/flume-ng/data/channel1/log-710,
/local/flume-ng/data/channel1/log-711, /local/flume-ng/data/channel1/log-712,
/local/flume-ng/data/channel1/log-713, /local/flume-ng/data/channel1/log-714]
12 Aug 2014 21:36:38,729 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-686
12 Aug 2014 21:36:38,845 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-687
12 Aug 2014 21:36:38,867 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-688
12 Aug 2014 21:36:38,895 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-689
12 Aug 2014 21:36:38,908 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-690
12 Aug 2014 21:36:38,922 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-691
12 Aug 2014 21:36:38,933 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-692
12 Aug 2014 21:36:38,945 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-693
12 Aug 2014 21:36:38,957 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-694
12 Aug 2014 21:36:38,965 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-695
12 Aug 2014 21:36:38,978 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-696
12 Aug 2014 21:36:38,988 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-697
12 Aug 2014 21:36:38,994 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-698
12 Aug 2014 21:36:39,005 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-699
12 Aug 2014 21:36:39,017 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-700
12 Aug 2014 21:36:39,022 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.ReplayHandler.replayLog:262) - Replaying
/local/flume-ng/data/channel1/log-701
12 Aug 2014 21:36:58,554 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623194835 in /local/flume-ng/data/channel1/log-702
12 Aug 2014 21:36:59,311 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195343 in /local/flume-ng/data/channel1/log-703
12 Aug 2014 21:37:00,637 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195377 in /local/flume-ng/data/channel1/log-704
12 Aug 2014 21:37:02,575 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195415 in /local/flume-ng/data/channel1/log-705
12 Aug 2014 21:37:04,328 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195243 in /local/flume-ng/data/channel1/log-706
12 Aug 2014 21:37:04,460 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195572 in /local/flume-ng/data/channel1/log-707
12 Aug 2014 21:37:05,668 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623195404 in /local/flume-ng/data/channel1/log-708
12 Aug 2014 21:37:05,710 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623194925 in /local/flume-ng/data/channel1/log-709
12 Aug 2014 21:37:06,347 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 1623194204 in /local/flume-ng/data/channel1/log-710
12 Aug 2014 21:37:07,900 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 712946491 in /local/flume-ng/data/channel1/log-711
12 Aug 2014 21:37:07,908 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$SequentialReader.next:657) -
Encountered EOF at 38156 in /local/flume-ng/data/channel1/log-714
12 Aug 2014 21:37:07,945 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.Log.replay:470) - Rolling
/local/flume-ng/data/channel1
12 Aug 2014 21:37:07,946 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.Log.roll:932) - Roll start
/local/flume-ng/data/channel1
12 Aug 2014 21:37:07,946 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$Writer.<init>:214) - Opened
/local/flume-ng/data/channel1/log-715
12 Aug 2014 21:37:07,947 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.EventQueueBackingStoreFile.beginCheckpoint:214)
- Start checkpoint for /local/flume-ng/checkpoints/channel1/checkpoint,
elements to sync = 8465
12 Aug 2014 21:37:07,973 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.Log.writeCheckpoint:1005) - Updated checkpoint
for file: /local/flume-ng/data/channel1/log-715 position: 0 logWriteOrderID:
1408282684040
12 Aug 2014 21:37:07,973 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-686
12 Aug 2014 21:37:07,979 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.channel.file.FileChannel.start:285) - Queue Size after
replay: 418 [channel=channel1]
12 Aug 2014 21:37:07,980 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.instrumentation.MonitoredCounterGroup.register:119) -
Monitored counter group for type: CHANNEL, name: channel1: Successfully
registered new MBean.
12 Aug 2014 21:37:07,980 INFO [lifecycleSupervisor-1-0]
(org.apache.flume.instrumentation.MonitoredCounterGroup.start:95) - Component
type: CHANNEL, name: channel1 started
12 Aug 2014 21:37:08,139 INFO [SinkRunner-PollingRunner-DefaultSinkProcessor]
(org.apache.flume.channel.file.LogFile$RandomReader.checkOut:544) - Opening
/local/flume-ng/data/channel1/log-686 for read, remaining number of file
handles available for reads of this file is 50
12 Aug 2014 21:37:08,139 INFO [SinkRunner-PollingRunner-DefaultSinkProcessor]
(org.apache.flume.channel.file.LogFile$RandomReader.checkOut:544) - Opening
/local/flume-ng/data/channel1/log-686 for read, remaining number of file
handles available for reads of this file is 50
12 Aug 2014 21:37:08,139 INFO [SinkRunner-PollingRunner-DefaultSinkProcessor]
(org.apache.flume.channel.file.LogFile$RandomReader.checkOut:544) - Opening
/local/flume-ng/data/channel1/log-686 for read, remaining number of file
handles available for reads of this file is 50
12 Aug 2014 21:38:18,255 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.EventQueueBackingStoreFile.beginCheckpoint:214)
- Start checkpoint for /local/flume-ng/checkpoints/channel1/checkpoint,
elements to sync = 418
12 Aug 2014 21:38:18,257 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.EventQueueBackingStoreFile.checkpoint:239) -
Updating checkpoint metadata: logWriteOrderID: 1408282684463, queueSize: 0,
queueHead: 2970240
12 Aug 2014 21:38:18,260 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.Log.writeCheckpoint:1005) - Updated checkpoint
for file: /local/flume-ng/data/channel1/log-715 position: 17282
logWriteOrderID: 1408282684463
12 Aug 2014 21:38:18,261 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-686
12 Aug 2014 21:38:18,266 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-687
12 Aug 2014 21:38:18,271 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-688
12 Aug 2014 21:38:18,277 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-689
12 Aug 2014 21:38:18,282 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-690
12 Aug 2014 21:38:18,287 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-691
12 Aug 2014 21:38:18,293 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-692
12 Aug 2014 21:38:18,298 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-693
12 Aug 2014 21:38:18,303 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-694
12 Aug 2014 21:38:18,309 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-695
12 Aug 2014 21:38:18,314 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-696
12 Aug 2014 21:38:18,319 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-697
12 Aug 2014 21:38:18,325 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-698
12 Aug 2014 21:38:18,330 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-699
12 Aug 2014 21:38:18,335 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-700
12 Aug 2014 21:38:18,340 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-701
12 Aug 2014 21:38:18,346 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-702
12 Aug 2014 21:38:18,351 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-703
12 Aug 2014 21:38:18,356 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-704
12 Aug 2014 21:38:18,362 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-705
12 Aug 2014 21:38:18,367 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-706
12 Aug 2014 21:38:18,372 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-707
12 Aug 2014 21:38:18,378 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-708
12 Aug 2014 21:38:18,383 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-709
12 Aug 2014 21:38:18,388 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-710
12 Aug 2014 21:38:18,394 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-711
12 Aug 2014 21:38:18,399 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-712
12 Aug 2014 21:38:18,404 INFO [Log-BackgroundWorker-channel1]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-713
(source was disabled so nothing interresting futher)
and after I realized that flume is not going to remove old files I stopped it:
12 Aug 2014 21:42:20,084 INFO [agent-shutdown-hook]
(org.apache.flume.node.Application.stopAllComponents:102) - Shutting down
configuration: { sourceRunners:{} sinkRunners:{google-BQ-perf-sink1=SinkRunner:
{ policy:org.apache.flume.sink.DefaultSinkProcessor@6eb5845c counterGroup:{
name:null counters:{runner.backoffs.consecutive=40, runner.backoffs=40} } },
es-sink1=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4f04eccc counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
es-sink4=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4c566d9b counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
es-sink3=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@3e360244 counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
es-sink2=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@4bcede44 counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
google-BQ-sink4=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@7a62693d counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
google-BQ-sink3=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@52eb6290 counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
google-BQ-sink2=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@5b940677 counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } },
google-BQ-sink1=SinkRunner: {
policy:org.apache.flume.sink.DefaultSinkProcessor@53349d99 counterGroup:{
name:null counters:{runner.backoffs.consecutive=65, runner.backoffs=65} } }}
channels:{channel1=FileChannel channel1 { dataDirs:
[/local/flume-ng/data/channel1] }, channel2=FileChannel channel2 { dataDirs:
[/local/flume-ng/data/channel2] },
channel3=org.apache.flume.channel.MemoryChannel{name: channel3}} }
12 Aug 2014 21:42:20,102 INFO [agent-shutdown-hook]
(org.apache.flume.node.Application.stopAllComponents:126) - Stopping Channel
channel1
12 Aug 2014 21:42:20,102 INFO [agent-shutdown-hook]
(org.apache.flume.lifecycle.LifecycleSupervisor.unsupervise:171) - Stopping
component: FileChannel channel1 { dataDirs: [/local/flume-ng/data/channel1] }
12 Aug 2014 21:42:20,102 INFO [agent-shutdown-hook]
(org.apache.flume.channel.file.FileChannel.stop:305) - Stopping FileChannel
channel1 { dataDirs: [/local/flume-ng/data/channel1] }...
12 Aug 2014 21:42:20,103 INFO [agent-shutdown-hook]
(org.apache.flume.channel.file.LogFile$Writer.close:370) - Closing
/local/flume-ng/data/channel1/log-715
12 Aug 2014 21:42:20,103 INFO [agent-shutdown-hook]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-715
12 Aug 2014 21:42:20,108 INFO [agent-shutdown-hook]
(org.apache.flume.channel.file.LogFile$RandomReader.close:504) - Closing
RandomReader /local/flume-ng/data/channel1/log-714
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:149) - Component
type: CHANNEL, name: channel1 stopped
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:155) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.start.time == 1407893827980
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:161) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.stop.time == 1407894140114
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.capacity == 16000000
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.current.size == 0
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.event.put.attempt == 0
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.event.put.success == 0
12 Aug 2014 21:42:20,114 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.event.take.attempt == 678
12 Aug 2014 21:42:20,115 INFO [agent-shutdown-hook]
(org.apache.flume.instrumentation.MonitoredCounterGroup.stop:177) - Shutdown
Metric for type: CHANNEL, name: channel1. channel.event.take.success == 418
No events in channel according to shutdown message: channel1.
channel.current.size == 0
> Remove Log writetimeout
> -----------------------
>
> Key: FLUME-2307
> URL: https://issues.apache.org/jira/browse/FLUME-2307
> Project: Flume
> Issue Type: Bug
> Components: Channel
> Affects Versions: v1.4.0
> Reporter: Steve Zesch
> Assignee: Hari Shreedharan
> Fix For: v1.5.0
>
> Attachments: FLUME-2307-1.patch, FLUME-2307.patch
>
>
> I've observed Flume failing to clean up old log data in FileChannels. The
> amount of old log data can range anywhere from tens to hundreds of GB. I was
> able to confirm that the channels were in fact empty. This behavior always
> occurs after lock timeouts when attempting to put, take, rollback, or commit
> to a FileChannel. Once the timeout occurs, Flume stops cleaning up the old
> files. I was able to confirm that the Log's writeCheckpoint method was still
> being called and successfully obtaining a lock from tryLockExclusive(), but I
> was not able to confirm removeOldLogs being called. The application log did
> not include "Removing old file: log-xyz" for the old files which the Log
> class would output if they were correctly being removed. I suspect the lock
> timeouts were due to high I/O load at the time.
> Some stack traces:
> {code}
> org.apache.flume.ChannelException: Failed to obtain lock for writing to the
> log. Try increasing the log write timeout value. [channel=fileChannel]
> at
> org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doPut(FileChannel.java:478)
> at
> org.apache.flume.channel.BasicTransactionSemantics.put(BasicTransactionSemantics.java:93)
> at
> org.apache.flume.channel.BasicChannelSemantics.put(BasicChannelSemantics.java:80)
> at
> org.apache.flume.channel.ChannelProcessor.processEventBatch(ChannelProcessor.java:189)
> org.apache.flume.ChannelException: Failed to obtain lock for writing to the
> log. Try increasing the log write timeout value. [channel=fileChannel]
> at
> org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doCommit(FileChannel.java:594)
> at
> org.apache.flume.channel.BasicTransactionSemantics.commit(BasicTransactionSemantics.java:151)
> at
> dataxu.flume.plugins.avro.AsyncAvroSink.process(AsyncAvroSink.java:548)
> at
> dataxu.flume.plugins.ClassLoaderFlumeSink.process(ClassLoaderFlumeSink.java:33)
> at
> org.apache.flume.sink.DefaultSinkProcessor.process(DefaultSinkProcessor.java:68)
> at org.apache.flume.SinkRunner$PollingRunner.run(SinkRunner.java:147)
> at java.lang.Thread.run(Thread.java:619)
> org.apache.flume.ChannelException: Failed to obtain lock for writing to the
> log. Try increasing the log write timeout value. [channel=fileChannel]
> at
> org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doRollback(FileChannel.java:621)
> at
> org.apache.flume.channel.BasicTransactionSemantics.rollback(BasicTransactionSemantics.java:168)
> at
> org.apache.flume.channel.ChannelProcessor.processEventBatch(ChannelProcessor.java:194)
> at
> dataxu.flume.plugins.avro.AvroSource.appendBatch(AvroSource.java:209)
> at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at
> org.apache.avro.ipc.specific.SpecificResponder.respond(SpecificResponder.java:91)
> at org.apache.avro.ipc.Responder.respond(Responder.java:151)
> at
> org.apache.avro.ipc.NettyServer$NettyServerAvroHandler.messageReceived(NettyServer.java:188)
> at
> org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
> at
> org.apache.avro.ipc.NettyServer$NettyServerAvroHandler.handleUpstream(NettyServer.java:173)
> at
> org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
> at
> org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
> at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296)
> at
> org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:321)
> at
> org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:303)
> at
> org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:220)
> at
> org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:75)
> at
> org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
> at
> org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
> at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268)
> at
> org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255)
> at
> org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:94)
> at
> org.jboss.netty.channel.socket.nio.AbstractNioWorker.processSelectedKeys(AbstractNioWorker.java:364)
> at
> org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:238)
> at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:38)
> at
> org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> {code}
> Channel Config:
> {code}
> agent.channels.fileChannel.type = file
> agent.channels.fileChannel.checkpointDir =
> /var/log/flume-ng/channels/fileChannel/checkpoint
> agent.channels.fileChannel.dataDirs =
> /var/log/flume-ng/channels/fileChannel/data
> agent.channels.fileChannel.capacity = 100000000
> agent.channels.fileChannel.transactionCapacity = 100000000
> agent.channels.fileChannel.maxFileSize = 104857600
> {code}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
