> On April 12, 2013, 9:37 a.m., Juhani Connolly wrote:
> > The tests still don't pass in our environment, failing on the assertion
> > Assert.assertTrue(!backup || channel.checkpointBackupRestored())
> >
> > Relevant from the surefire-reports:
> >
> > <testcase time="7.258"
> > classname="org.apache.flume.channel.file.TestFileChannelRestart"
> > name="testCorruptInflightTakesWithBackup">
> > <failure type="java.lang.AssertionError">java.lang.AssertionError
> > at org.junit.Assert.fail(Assert.java:92)
> > at org.junit.Assert.assertTrue(Assert.java:43)
> > at org.junit.Assert.assertTrue(Assert.java:54)
> > at
> > org.apache.flume.channel.file.TestFileChannelRestart.doTestCorruptInflights(TestFileChannelRestart.java:514)
> > at
> > org.apache.flume.channel.file.TestFileChannelRestart.testCorruptInflightTakesWithBackup(TestFileChannelRestart.java:431)
> > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> > at
> > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> > at
> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> > at java.lang.reflect.Method.invoke(Method.java:597)
> > ...
> > </failure>
> > <system-out>2013-04-12 18:16:16,498 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.start(FileChannel.java:281)]
> > Starting FileChannel FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934 {
> > dataDirs: [/tmp/1365758176497-0/data1,
> > /tmp/1365758176497-0/data2, /tmp/1365758176497-0/data3] }...
> > 2013-04-12 18:16:16,499 (main) [INFO -
> > org.apache.flume.channel.file.Log.<init>(Log.java:321)] Encryption is
> > not enabled
> > 2013-04-12 18:16:16,499 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:368)] Replay started
> > 2013-04-12 18:16:16,500 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:380)] Found NextFileID 0,
> > from []
> > 2013-04-12 18:16:16,504 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.<init>(EventQueueBackingStoreFile.java:91)]
> > Preallocated /tmp/1365758176497-0/chkpt/checkpoint to 88232 for capacity
> > 10000
> > 2013-04-12 18:16:16,505 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFileV3.<init>(EventQueueBackingStoreFileV3.java:53)]
> > Starting up with /tmp/1365758176497-0/chkpt/checkpoint and
> > /tmp/1365758176497-0/chkpt/c
> > heckpoint.meta
> > 2013-04-12 18:16:16,507 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:417)] Last Checkpoint Fri
> > Apr 12 18:16:16 JST 2013, queue depth = 0
> > 2013-04-12 18:16:16,507 (main) [INFO -
> > org.apache.flume.channel.file.Log.doReplay(Log.java:498)] Replaying logs
> > with v2 replay logic
> > 2013-04-12 18:16:16,507 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:244)]
> > Starting replay of []
> > 2013-04-12 18:16:16,507 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:338)]
> > read: 0, put: 0, take: 0, rollback: 0, commit: 0, skip: 0, eventCount:0
> > 2013-04-12 18:16:16,508 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data1
> > 2013-04-12 18:16:16,508 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data1
> > 2013-04-12 18:16:16,508 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data1/log-1
> > 2013-04-12 18:16:16,510 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:16,510 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data2
> > 2013-04-12 18:16:16,511 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data2
> > 2013-04-12 18:16:16,511 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:16,513 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:16,513 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data3
> > 2013-04-12 18:16:16,513 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data3
> > 2013-04-12 18:16:16,514 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data3/log-3
> > 2013-04-12 18:16:16,516 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:16,516 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.beginCheckpoint(EventQueueBackingStoreFile.java:215)]
> > Start checkpoint for /tmp/1365758176497-0/chkpt/checkpoint, elements to
> > sync = 0
> > 2013-04-12 18:16:16,520 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.checkpoint(EventQueueBackingStoreFile.java:240)]
> > Updating checkpoint metadata: logWriteOrderID: 1365758273442, queueSize:
> > 0, queueHead: 0
> > 2013-04-12 18:16:16,521 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.startBackupThread(EventQueueBackingStoreFile.java:276)]
> > Attempting to back up checkpoint.
> > 2013-04-12 18:16:16,522
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:100)]
> > Skipping in_use.lock because it is
> > in excludes set
> > 2013-04-12 18:16:16,522
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:113)]
> > Deleted the following files: .
> > 2013-04-12 18:16:16,524 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data1/log-1 position: 0
> > logWriteOrderID: 1365758273442
> > 2013-04-12 18:16:16,535 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data2/log-2 position: 0
> > logWriteOrderID: 1365758273442
> > 2013-04-12 18:16:16,539 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data3/log-3 position: 0
> > logWriteOrderID: 1365758273442
> > 2013-04-12 18:16:16,540 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.start(FileChannel.java:307)]
> > Queue Size after replay: 0
> > [channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934]
> > 2013-04-12 18:16:16,540
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile$1.run(EventQueueBackingStoreFile.java:291)]
> > Checkpoint backup
> > completed.
> > 2013-04-12 18:16:16,540 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.register(MonitoredCounterGroup.java:89)]
> > Monitoried counter group for type: CHANNEL, name:
> > FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934, re
> > gistered successfully.
> > 2013-04-12 18:16:16,540 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.start(MonitoredCounterGroup.java:73)]
> > Component type: CHANNEL, name:
> > FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934 started
> > 2013-04-12 18:16:16,541 (main) [DEBUG -
> > org.apache.flume.channel.file.LogFile$Writer.preallocate(LogFile.java:290)]
> > Preallocating at position 0
> > 2013-04-12 18:16:21,544 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.beginCheckpoint(EventQueueBackingStoreFile.java:215)]
> > Start checkpoint for /tmp/1365758176497-0/chkpt/checkpoint, elements to
> > sync = 0
> > 2013-04-12 18:16:21,551 (main) [DEBUG -
> > org.apache.flume.channel.file.FlumeEventQueue$InflightEventWrapper.serializeAndWrite(FlumeEventQueue.java:422)]
> > Number of events inserted into inflights file: 100 file:
> > /tmp/1365758176497-0/chkpt/i
> > nflightputs
> > 2013-04-12 18:16:21,560 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.checkpoint(EventQueueBackingStoreFile.java:240)]
> > Updating checkpoint metadata: logWriteOrderID: 1365758273543, queueSize:
> > 0, queueHead: 0
> > 2013-04-12 18:16:21,566 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.startBackupThread(EventQueueBackingStoreFile.java:276)]
> > Attempting to back up checkpoint.
> > 2013-04-12 18:16:21,570
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:100)]
> > Skipping in_use.lock because it is
> > in excludes set
> > 2013-04-12 18:16:21,571
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:113)]
> > Deleted the following files: , infl
> > ighttakes, checkpoint.meta, checkpoint, inflightputs.
> > 2013-04-12 18:16:21,580 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data1/log-1 position: 0
> > logWriteOrderID: 1365758273543
> > 2013-04-12 18:16:21,587 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data2/log-2 position: 7800
> > logWriteOrderID: 1365758273543
> > 2013-04-12 18:16:21,589 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data3/log-3 position: 0
> > logWriteOrderID: 1365758273543
> > 2013-04-12 18:16:21,590 (main) [DEBUG -
> > org.apache.flume.channel.file.Log.removeOldLogs(Log.java:1058)] Files
> > currently in use: [1, 2, 3]
> > 2013-04-12 18:16:21,591
> > ([channel=FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile$1.run(EventQueueBackingStoreFile.java:291)]
> > Checkpoint backup completed.
> > 2013-04-12 18:16:23,605 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.stop(FileChannel.java:327)]
> > Stopping FileChannel FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934 {
> > dataDirs: [/tmp/1365758176497-0/data1, /tmp/1365758176497-0/data2,
> > /tmp/1365758176497-0/data3] }...
> > Attempting to shutdown background worker.
> > 2013-04-12 18:16:23,619 (main) [INFO -
> > org.apache.flume.channel.file.Log.shutdownWorker(Log.java:821)] Attempting
> > to shutdown background worker.
> > 2013-04-12 18:16:23,619 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data1/log-1
> > 2013-04-12 18:16:23,619 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,619 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data3/log-3
> > 2013-04-12 18:16:23,619 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data1/log-1
> > 2013-04-12 18:16:23,625 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,631 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data3/log-3
> > 2013-04-12 18:16:23,638 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.stop(MonitoredCounterGroup.java:100)]
> > Component type: CHANNEL, name:
> > FileChannel-3d21a8cc-6f46-45c4-8dee-ac5fd530c934 stopped
> > 2013-04-12 18:16:23,638 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.start(FileChannel.java:281)]
> > Starting FileChannel FileChannel-5de59d23-c19a-424a-a407-9209741e3e00 {
> > dataDirs: [/tmp/1365758176497-0/data1, /tmp/1365758176497-0/data2,
> > /tmp/1365758176497-0/data3] }...
> > 2013-04-12 18:16:23,639 (main) [INFO -
> > org.apache.flume.channel.file.Log.<init>(Log.java:321)] Encryption is
> > not enabled
> > 2013-04-12 18:16:23,639 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:368)] Replay started
> > 2013-04-12 18:16:23,643 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:380)] Found NextFileID 3,
> > from [/tmp/1365758176497-0/data1/log-1, /tmp/1365758176497-0/data2/log-2,
> > /tmp/1365758176497-0/data3/log-3]
> > 2013-04-12 18:16:23,644 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFileV3.<init>(EventQueueBackingStoreFileV3.java:53)]
> > Starting up with /tmp/1365758176497-0/chkpt/checkpoint and
> > /tmp/1365758176497-0/chkpt/checkpoint.meta
> > 2013-04-12 18:16:23,644 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFileV3.<init>(EventQueueBackingStoreFileV3.java:57)]
> > Reading checkpoint metadata from /tmp/1365758176497-0/chkpt/checkpoint.meta
> > 2013-04-12 18:16:23,644 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:417)] Last Checkpoint Fri
> > Apr 12 18:16:21 JST 2013, queue depth = 0
> > 2013-04-12 18:16:23,645 (main) [INFO -
> > org.apache.flume.channel.file.Log.doReplay(Log.java:498)] Replaying logs
> > with v2 replay logic
> > 2013-04-12 18:16:23,645 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:244)]
> > Starting replay of [/tmp/1365758176497-0/data1/log-1,
> > /tmp/1365758176497-0/data2/log-2, /tmp/1365758176497-0/data3/log-3]
> > 2013-04-12 18:16:23,645 (main) [DEBUG -
> > org.apache.flume.channel.file.FlumeEventQueue$InflightEventWrapper.deserialize(FlumeEventQueue.java:482)]
> > Reached end of inflights buffer. Long buffer position =104
> > 2013-04-12 18:16:23,646 (main) [DEBUG -
> > org.apache.flume.channel.file.FlumeEventQueue$InflightEventWrapper.deserialize(FlumeEventQueue.java:482)]
> > Reached end of inflights buffer. Long buffer position =2
> > 2013-04-12 18:16:23,646 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:257)]
> > Replaying /tmp/1365758176497-0/data1/log-1
> > 2013-04-12 18:16:23,646 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$SequentialReader.skipToLastCheckpointPosition(LogFile.java:484)]
> > Checkpoint for file(/tmp/1365758176497-0/data1/log-1) is: 1365758273543,
> > which is beyond the requested checkpoint time: 1365758273543 and position 0
> > 2013-04-12 18:16:23,646 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:257)]
> > Replaying /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$SequentialReader.skipToLastCheckpointPosition(LogFile.java:482)]
> > fast-forward to checkpoint position: 7800
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:257)]
> > Replaying /tmp/1365758176497-0/data3/log-3
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$SequentialReader.skipToLastCheckpointPosition(LogFile.java:484)]
> > Checkpoint for file(/tmp/1365758176497-0/data3/log-3) is: 1365758273543,
> > which is beyond the requested checkpoint time: 1365758273543 and position 0
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$SequentialReader.next(LogFile.java:505)]
> > Encountered EOF at 7836 in /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:338)]
> > read: 1, put: 0, take: 0, rollback: 0, commit: 1, skip: 0, eventCount:100
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data1
> > 2013-04-12 18:16:23,647 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data1
> > 2013-04-12 18:16:23,648 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data1/log-4
> > 2013-04-12 18:16:23,650 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:23,650 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data2
> > 2013-04-12 18:16:23,650 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data2
> > 2013-04-12 18:16:23,650 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data2/log-5
> > 2013-04-12 18:16:23,652 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:23,652 (main) [INFO -
> > org.apache.flume.channel.file.Log.replay(Log.java:461)] Rolling
> > /tmp/1365758176497-0/data3
> > 2013-04-12 18:16:23,652 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:922)] Roll start
> > /tmp/1365758176497-0/data3
> > 2013-04-12 18:16:23,652 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.<init>(LogFile.java:169)]
> > Opened /tmp/1365758176497-0/data3/log-6
> > 2013-04-12 18:16:23,654 (main) [INFO -
> > org.apache.flume.channel.file.Log.roll(Log.java:937)] Roll end
> > 2013-04-12 18:16:23,654 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.beginCheckpoint(EventQueueBackingStoreFile.java:215)]
> > Start checkpoint for /tmp/1365758176497-0/chkpt/checkpoint, elements to
> > sync = 100
> > 2013-04-12 18:16:23,658 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.checkpoint(EventQueueBackingStoreFile.java:240)]
> > Updating checkpoint metadata: logWriteOrderID: 1365758273545, queueSize:
> > 100, queueHead: 9998
> > 2013-04-12 18:16:23,660 (main) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile.startBackupThread(EventQueueBackingStoreFile.java:276)]
> > Attempting to back up checkpoint.
> > 2013-04-12 18:16:23,661
> > ([channel=FileChannel-5de59d23-c19a-424a-a407-9209741e3e00] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:100)]
> > Skipping in_use.lock because it is in excludes set
> > 2013-04-12 18:16:23,663
> > ([channel=FileChannel-5de59d23-c19a-424a-a407-9209741e3e00] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.Serialization.deleteAllFiles(Serialization.java:113)]
> > Deleted the following files: , inflighttakes, checkpoint.meta, checkpoint,
> > inflightputs.
> > 2013-04-12 18:16:23,663 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data1/log-4 position: 0
> > logWriteOrderID: 1365758273545
> > 2013-04-12 18:16:23,673 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data2/log-5 position: 0
> > logWriteOrderID: 1365758273545
> > 2013-04-12 18:16:23,677 (main) [INFO -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:997)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data3/log-6 position: 0
> > logWriteOrderID: 1365758273545
> > 2013-04-12 18:16:23,678 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,682
> > ([channel=FileChannel-5de59d23-c19a-424a-a407-9209741e3e00] -
> > CheckpointBackUpThread) [INFO -
> > org.apache.flume.channel.file.EventQueueBackingStoreFile$1.run(EventQueueBackingStoreFile.java:291)]
> > Checkpoint backup completed.
> > 2013-04-12 18:16:23,685 (main) [DEBUG -
> > org.apache.flume.channel.file.Log.writeCheckpoint(Log.java:1017)] Updated
> > checkpoint for file: /tmp/1365758176497-0/data2/log-2logWriteOrderID
> > 1365758273545
> > 2013-04-12 18:16:23,686 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.start(FileChannel.java:307)]
> > Queue Size after replay: 100
> > [channel=FileChannel-5de59d23-c19a-424a-a407-9209741e3e00]
> > 2013-04-12 18:16:23,686 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.register(MonitoredCounterGroup.java:89)]
> > Monitoried counter group for type: CHANNEL, name:
> > FileChannel-5de59d23-c19a-424a-a407-9209741e3e00, registered successfully.
> > 2013-04-12 18:16:23,686 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.start(MonitoredCounterGroup.java:73)]
> > Component type: CHANNEL, name:
> > FileChannel-5de59d23-c19a-424a-a407-9209741e3e00 started
> > 2013-04-12 18:16:23,686 (main) [INFO -
> > org.apache.flume.channel.file.FileChannel.stop(FileChannel.java:327)]
> > Stopping FileChannel FileChannel-5de59d23-c19a-424a-a407-9209741e3e00 {
> > dataDirs: [/tmp/1365758176497-0/data1, /tmp/1365758176497-0/data2,
> > /tmp/1365758176497-0/data3] }...
> > Attempting to shutdown background worker.
> > 2013-04-12 18:16:23,686 (main) [INFO -
> > org.apache.flume.channel.file.Log.shutdownWorker(Log.java:821)] Attempting
> > to shutdown background worker.
> > 2013-04-12 18:16:23,687 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data1/log-4
> > 2013-04-12 18:16:23,687 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data2/log-5
> > 2013-04-12 18:16:23,687 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$Writer.close(LogFile.java:273)]
> > Closing /tmp/1365758176497-0/data3/log-6
> > 2013-04-12 18:16:23,687 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data1/log-1
> > 2013-04-12 18:16:23,692 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data2/log-2
> > 2013-04-12 18:16:23,698 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data3/log-3
> > 2013-04-12 18:16:23,704 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data1/log-4
> > 2013-04-12 18:16:23,711 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data2/log-5
> > 2013-04-12 18:16:23,716 (main) [INFO -
> > org.apache.flume.channel.file.LogFile$RandomReader.close(LogFile.java:354)]
> > Closing RandomReader /tmp/1365758176497-0/data3/log-6
> > 2013-04-12 18:16:23,723 (main) [INFO -
> > org.apache.flume.instrumentation.MonitoredCounterGroup.stop(MonitoredCounterGroup.java:100)]
> > Component type: CHANNEL, name:
> > FileChannel-5de59d23-c19a-424a-a407-9209741e3e00 stopped
> > </system-out>
> >
Can you give the new patch a try? At this point, I cannot reproduce this issue
anymore.
- Hari
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/10415/#review19059
-----------------------------------------------------------
On April 12, 2013, 10:49 p.m., Hari Shreedharan wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/10415/
> -----------------------------------------------------------
>
> (Updated April 12, 2013, 10:49 p.m.)
>
>
> Review request for Flume.
>
>
> Description
> -------
>
> Increase sleeps so forceCheckpoint does not fail because the copy is not
> completed.
>
>
> This addresses bug FLUME-1986.
> https://issues.apache.org/jira/browse/FLUME-1986
>
>
> Diffs
> -----
>
>
> flume-ng-channels/flume-file-channel/src/test/java/org/apache/flume/channel/file/TestFileChannelRestart.java
> fb0e208
>
> flume-ng-channels/flume-file-channel/src/test/java/org/apache/flume/channel/file/TestUtils.java
> 7c490b5
>
> Diff: https://reviews.apache.org/r/10415/diff/
>
>
> Testing
> -------
>
> Ran full tests.
>
>
> Thanks,
>
> Hari Shreedharan
>
>
