Akkaの統合テストとEventFilterによるログの検査 |

Blog

2017.1.4

Akkaの統合テストとEventFilterによるログの検査

こんにちは。CA ProFit-Xのエンジニアの松村です。

先日このブログで Scalaのテストツールに関する社内勉強会についてご紹介しました。Specs2の Custom Matcher, Fragments, Tables, aka を使ってDRYで読みやすいテストを書く方法や、形式手法を導入するツール(Isabelle)がカバーされていますので是非ご覧ください！

今回は私たちのプロダクトで使っているAkkaのTestkitの機能の中から、EventFilter についてご紹介します。この記事はAkka 2.4.16をベースにしています。

Akkaでのテストの考え方とその基本的なツールについては Testing Actor Systems にまとめられていて、この文書では並行性（マルチスレッド, 非決定性）を考慮しない振舞い，考慮する振舞いのテストをそれぞれ単体テスト，統合テストと呼んでいます。以降では後者の統合テストとTestProbeについて軽く触れた後、EventFilterとその使い方、Tipsの順に説明します。

統合テストと TestProbe, EventFilter

単純な構成の統合テストでは expectMsg や receiveOne などのTestkit組込みのassertionを使って、エントリポイントの testActor が受取ったメッセージに基づいて検査を行うことが多いと思います。

一方エントリポイント以外のActorとの通信が多数発生するような複雑な構成のアクターネットワークの統合テストでは、TestProbeを介在させることでActor間通信の検査が行えます。TestProbe を使うには対象のアクターネットワークのActorにそれぞれ通信先のActorをテスト時に外部から注入できる実装にしておく必要がありますが、その際に 1) TestProbeの受入れやその設定コードのメンテのコストと、2) 本番構成からの差分がそれぞれ生じます。

今回ご紹介するEventFilterはTestProbeと同じくAkkaの統合テストを支援するツールの一つで、Actorのログメッセージを検査するためのものです。EventFilterはTestProbeほどは使い方のレールが敷かれておらず脇役な印象ですが、節度を持って使えばTestProbeのメンテコスト・本番構成との差分のデメリットをうまく補えるかも知れません。

EventFilterの使い方

Expecting Log Messages にEventFilterの基本的な使い方の説明があります。

まずtest環境の設定 ( src/test/resources/application.conf ) に下を追加します：

akka.loggers = [akka.testkit.TestEventListener]

1	akka.loggers = [akka.testkit.TestEventListener]

Actorの log.info(..) などで出力されたログは Event Stream に流れますが、EventFilter はこの TestEventListener で Event Stream のデータを捕捉することでログの中身を検査できるようにしているようです。

この項目を追加した上で、テストコードの中で下のように EventFilter を作って intercept のブロック内でテスト対象のコードを実行します。

import akka.testkit.EventFilter

EventFilter[MyException](occurrences = 1) intercept {
  // actor ! "my-msg"
}

import akka.testkit.EventFilter

EventFilter[MyException](occurrences = 1) intercept {

// actor ! "my-msg"

}

上の例では intercept 内で MyException によるerrorログが出力された時に assertion が通ります。

メッセージのマッチングとsourceの指定

ログメッセージの文字列でマッチングを行うには、EventFilterオブジェクトのログレベルごとのメソッドを使ってEventFilterを作ります。
sourceを指定しないとEventFilterのパターンマッチが動作しない仕様になっているので、ログ出力元のsource文字列をコンソール出力で確認するなどして引数に与えます。
ActorLoggingを使っている場合はActorのパス文字列がsourceになるので、下のようにsourceを指定すれば動きます。

EventFilter.info(source = myActor.path.toString, pattern = "weird.*message") intercept {
  // actor ! "my-msg"
}

EventFilter.info(source = myActor.path.toString, pattern = "weird.*message") intercept {

// actor ! "my-msg"

}

ログレベルを一時的に変える

Event Stream のログレベル設定に満たないものはテスト実行中に捕捉できないため、例えばdebugログを埋め込んであってもEvent Stream側のレベルがinfoになっているとログの検査が行えません。

このため、例えば特定のテストケースで下のようにEvent Streamのログレベルを一時的に変更すると捕捉できるようになります：

import akka.event.Logging

def changeLevel[T](level: Logging.LogLevel)(f: => T): T = {
  val originalLevel = system.eventStream.logLevel
  val es = system.eventStream
  try {
    es.setLogLevel(level)
    f
  } finally { es.setLogLevel(originalLevel) }
}

changeLevel(Logging.DebugLevel) {
  // test code
}

import akka.event.Logging

def changeLevel[T](level: Logging.LogLevel)(f: => T): T = {

val originalLevel = system.eventStream.logLevel

val es = system.eventStream

try {

es.setLogLevel(level)

} finally { es.setLogLevel(originalLevel) }

}

changeLevel(Logging.DebugLevel) {

// test code

}

テストケース内で標準出力を無効にする

EventFilterでマッチしたログはコンソール（標準出力）には表示されなくなります。
「ログで出力する内容」は全て「振舞いを検査したい内容」だと考えると、コンソールにログが出なくなるまでEventFilterのassersionを入れるべき、ということになります。
とはいえテストのメンテを考えるとコストに見合わないケースもあるため、コンソールにノイズが増えてテスト結果や仕様を確認しづらくなったら下のようにテストケース内の標準出力を無効化してしまっても良いかもしれません：

import org.specs2.reporter.NoStdOutAroundEach

class MySpec extends TestKit(ActorSystem("my-spec"))
  with SpecificationLike with ImplicitSender with NoStdOutAroundEach {
    ...
  }

import org.specs2.reporter.NoStdOutAroundEach

class MySpec extends TestKit(ActorSystem("my-spec"))

with SpecificationLike with ImplicitSender with NoStdOutAroundEach {

...

}

上は Specs2 の NoStdOutAroundEach を mix-in する例です。

まとめ

Akkaの統合テストでログ出力を検査するツール EventFilterの位置付け、使い方、Tipsをご紹介しました。EventFilterを適切に使うことで、複雑なアクターネットワークの統合テストのメンテコストや本番構成との差分を減らせるかも知れません。

Happy hAkking!

Author

ikuo