[FLUME-1682] Improve logging message when encrypted file channel is unable to be initialized due to invalid key/keystore

• Type: Improvement
• Status: Patch Available
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 1.2.0
• Assignee: Brock Noland
• Reporter: Jeff Lord
• Created: 06/Nov/12 03:23
• Updated: 09/Nov/12 19:15

Description

Currently if you have data in the file channel and stop flume for some reason (perhaps an upgrade) and then delete the keystore and regenerate the keystore. When flume is restarted it will throw an error similar to the following. It would be good if we could detect the reason for this failure to initialize as a change/mismatch in the keystore and report as such enabling self diagnosis and subsequent fix.

2012-10-23 09:21:32,230 ERROR file.Log: Failed to initialize Log on [channel=fileChannel]
java.io.IOException: Unable to read next Transaction from log file /flume/file-channel/data10/log-10 at offset 31519759
at org.apache.flume.channel.file.LogFile$SequentialReader.next(LogFile.java:456)
at org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:245)
at org.apache.flume.channel.file.Log.replay(Log.java:356)
at org.apache.flume.channel.file.FileChannel.start(FileChannel.java:258)
at org.apache.flume.lifecycle.LifecycleSupervisor$MonitorRunnable.run(LifecycleSupervisor.java:236)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
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:662)
Caused by: com.google.protobuf.InvalidProtocolBufferException: Protocol message tag had invalid wire type.
at com.google.protobuf.InvalidProtocolBufferException.invalidWireType(InvalidProtocolBufferException.java:78)
at com.google.protobuf.UnknownFieldSet$Builder.mergeFieldFrom(UnknownFieldSet.java:498)
at com.google.protobuf.GeneratedMessage$Builder.parseUnknownField(GeneratedMessage.java:438)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader$Builder.mergeFrom(ProtosFactory.java:2880)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader$Builder.mergeFrom(ProtosFactory.java:2732)
at com.google.protobuf.AbstractMessageLite$Builder.mergeFrom(AbstractMessageLite.java:212)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:746)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:238)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:282)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:760)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:288)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:752)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader.parseDelimitedFrom(ProtosFactory.java:2689)
at org.apache.flume.channel.file.TransactionEventRecord.fromByteArray(TransactionEventRecord.java:193)
at org.apache.flume.channel.file.LogFileV3$SequentialReader.doNext(LogFileV3.java:327)
at org.apache.flume.channel.file.LogFile$SequentialReader.next(LogFile.java:452)
... 13 more
2012-10-23 09:21:32,236 ERROR file.FileChannel: Failed to start the file channel [channel=fileChannel]
java.io.IOException: Unable to read next Transaction from log file /app/flume/file-channel/data1/log-1 at offset 31519759
at org.apache.flume.channel.file.LogFile$SequentialReader.next(LogFile.java:456)
at org.apache.flume.channel.file.ReplayHandler.replayLog(ReplayHandler.java:245)
at org.apache.flume.channel.file.Log.replay(Log.java:356)
at org.apache.flume.channel.file.FileChannel.start(FileChannel.java:258)
at org.apache.flume.lifecycle.LifecycleSupervisor$MonitorRunnable.run(LifecycleSupervisor.java:236)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
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:662)
Caused by: com.google.protobuf.InvalidProtocolBufferException: Protocol message tag had invalid wire type.
at com.google.protobuf.InvalidProtocolBufferException.invalidWireType(InvalidProtocolBufferException.java:78)
at com.google.protobuf.UnknownFieldSet$Builder.mergeFieldFrom(UnknownFieldSet.java:498)
at com.google.protobuf.GeneratedMessage$Builder.parseUnknownField(GeneratedMessage.java:438)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader$Builder.mergeFrom(ProtosFactory.java:2880)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader$Builder.mergeFrom(ProtosFactory.java:2732)
at com.google.protobuf.AbstractMessageLite$Builder.mergeFrom(AbstractMessageLite.java:212)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:746)
at com.google.protobuf.AbstractMessage$Builder.mergeFrom(AbstractMessage.java:238)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:282)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:760)
at com.google.protobuf.AbstractMessageLite$Builder.mergeDelimitedFrom(AbstractMessageLite.java:288)
at com.google.protobuf.AbstractMessage$Builder.mergeDelimitedFrom(AbstractMessage.java:752)
at org.apache.flume.channel.file.proto.ProtosFactory$TransactionEventHeader.parseDelimitedFrom(ProtosFactory.java:2689)
at org.apache.flume.channel.file.TransactionEventRecord.fromByteArray(TransactionEventRecord.java:193)
at org.apache.flume.channel.file.LogFileV3$SequentialReader.doNext(LogFileV3.java:327)
at org.apache.flume.channel.file.LogFile$SequentialReader.next(LogFile.java:452)
... 13 more

Issue Links

• is duplicated by: FLUME-1658 FileChannel file channel prints bad error message if encryption key has changed
• links to: Review Board