aws-kinesis-agentのバグ

構成

• よくあるパターン
• デプロイしてAPサーバからkinesis-firehoseへ送ってS3に格納

環境

• aws-kinesis-agent-1.1.2-1.amzn1.noarch

事象

• 構築時は問題なかったが、取得対象ログがローテート処理されたタイミングでエラー発生
• 対象ログ
  • /var/app/current/log/production.log
    • ログ

/var/log/aws-kinesis-agent/aws-kinesis-agent.log

Initialization logs can be found in /tmp/aws-kinesis-agent.20170301165118.initlog
Unhandled exception during startup.
java.lang.IllegalStateException: Expected the service to be RUNNING, but the service has FAILED
	at com.google.common.util.concurrent.AbstractService.checkCurrentState(AbstractService.java:285)
	at com.google.common.util.concurrent.AbstractService.awaitRunning(AbstractService.java:229)
	at com.google.common.util.concurrent.AbstractExecutionThreadService.awaitRunning(AbstractExecutionThreadService.java:197)
	at com.amazon.kinesis.streaming.agent.Agent.startUp(Unknown Source)
	at com.google.common.util.concurrent.AbstractIdleService$2$1.run(AbstractIdleService.java:54)
	at com.google.common.util.concurrent.Callables$3.run(Callables.java:95)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
	at com.google.common.util.concurrent.MoreExecutors$2.execute(MoreExecutors.java:849)
	at com.google.common.util.concurrent.AbstractIdleService$2.doStart(AbstractIdleService.java:50)
	at com.google.common.util.concurrent.AbstractService.startAsync(AbstractService.java:174)
	at com.google.common.util.concurrent.AbstractIdleService.startAsync(AbstractIdleService.java:135)
	at com.amazon.kinesis.streaming.agent.Agent.main(Unknown Source)
Caused by: java.lang.IllegalStateException
	at com.google.common.base.Preconditions.checkState(Preconditions.java:158)
	at com.amazon.kinesis.streaming.agent.tailing.TrackedFileRotationAnalyzer.findCurrentOpenFileAfterTruncate(Unknown Source)
	at com.amazon.kinesis.streaming.agent.tailing.SourceFileTracker.updateCurrentFile(Unknown Source)
	at com.amazon.kinesis.streaming.agent.tailing.SourceFileTracker.initialize(Unknown Source)
	at com.amazon.kinesis.streaming.agent.tailing.FileTailer.initialize(Unknown Source)
	at com.amazon.kinesis.streaming.agent.tailing.FileTailer.startUp(Unknown Source)
	at com.google.common.util.concurrent.AbstractExecutionThreadService$1$2.run(AbstractExecutionThreadService.java:55)
	at com.google.common.util.concurrent.Callables$3.run(Callables.java:95)
	at java.lang.Thread.run(Thread.java:745)
FATAL: Thread FileTailer[fh:************:/var/app/current/log/production.log] threw an unrecoverable error. Aborting application

ローテート処理時に何か発生していることがわかる。

原因

• KinesisエージェントはfilePatternごとにチェックポイント/var/run/aws-kinesis-agent/checkpointsに記録されており、トラッキング対象がlogrotateでcopytruncateとなっている場合、Kinesisエージェントで記録したチェックポイントとの整合性が取れなくなって、当該エラーが発生するようです。

/etc/logrotate.elasticbeanstalk.hourly/logrotate.elasticbeanstalk.webapp.conf

/var/app/containerfiles/logs/* {
 size 10M
 rotate 5
 missingok 
 compress
 notifempty
 copytruncate
 dateext
 dateformat %s
 olddir /var/app/containerfiles/logs/rotated
 }

対策

1. ログの出力先を変更する
2. copytruncateをcopyかcreateに変更する
3. filePatternにおいてターゲットファイル末尾に*をつける

補足

• /var/run/aws-kinesis-agent/checkpointsを削除することでaws-kinesis-agentを再起動することが可能
• issueとして扱われているので、updateを期待
• Exception on LogRotate #50