TestNG で実行中のテストメソッドをリスナで可視化する #Java

TestNG あるある「ここはどこ？」

コンソール上で TestNG のテストをふつうに流すと，どのテストメソッドを実行中かといった情報を何も出してくれません．
全部のテストがすんなり流れてくれるならそれで構わないのですが，

% mvn clean test
[INFO] Scanning for projects...
(中略)
[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running TestSuite

↑ たまにこんな表示のまま固まってしまって，どのテストでハングしているかもわからず途方にくれることがあります．

というわけで，そんな困ったことにならないように，TestNG でどのテストを実行中かをコンソール上に出力させる方法を紹介します．
対処後に出力されるログのイメージはこんな感じです:

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running TestSuite
[CustomTestListener] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 0, 0)
[CustomTestListener] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 1, 1)

この記事では，以下の 3 つの方法を紹介します．

方法 1: テストメソッドにログを直接仕込む
方法 2: テストクラスの @BeforeMethod メソッドにログを仕込む
方法 3: リスナを追加して onTestStart メソッドにログを仕込む (← この記事のメイン)

サンプルコード

この記事で使用するサンプルコードは GitHub に置いてあります．

https://github.com/wgag/testng-listener-sample

方法 1: テストメソッドにログを直接仕込む

テストメソッドそのものに直接ログを仕込むという，素朴で安直な方法です．
ログを出したいメソッドが限られている場合はいいですが，数が多いと大変なことに...

public class CalcTest {
    @Test(dataProvider = "testAdd")
    public void testAdd(int x, int y, int expected) {
        // テストメソッドの情報をログに出力
        LOGGER.info(String.format(
        "Running: com.example.calc.test.CalcTest#testAdd(%d, %d, %d)", x, y, expected));

        Calc calc = new Calc();
        assertEquals(calc.add(x, y), expected);
    }
    // ...
}

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running TestSuite
[CalcTest] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 0, 0)
[CalcTest] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 1, 1)

方法 2: テストクラスの `@BeforeMethod` メソッドにログを仕込む

テストクラスに @BeforeMethod アノテーションを付けたメソッドを定義し，その中にログを仕込みます．
テストクラスをちょこっといじれば済むので，とっかかりやすくわかりやすいリーズナブルな方法ではないでしょうか．

import org.testng.annotations.BeforeMethod;

public class CalcTest {
    @BeforeMethod
    public void beforeMethod(Method method, Object[] data) {
        // テストメソッドの情報をログに出力
        LOGGER.info(String.format(
            "Running: %s#%s(%s)",
            method.getDeclaringClass().getCanonicalName(),
            method.getName(),
            Arrays.stream(data).map(x -> x.toString()).collect(Collectors.joining(", "))));
    }
    // ...
}

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running TestSuite
[CalcTest] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 0, 0)
[CalcTest] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 1, 1)

方法 3: リスナを追加して `onTestStart` メソッドにログを仕込む

TestNG のリスナを追加して，リスナの onTestStart メソッドでログを仕込むという方法です．
リスナを設定するという手間はありますが，設定がグローバルに効くので，ターゲットのテストメソッドが多い場合とかに有効です．
また，テストクラスをいじらなくても済むので，テストセットを変更できない場合 (TCK を実行する場合とか) にも役に立ちます．

TestNG のリスナは，ITestListener インタフェースを実装した以下のようなクラスとして用意します．

import org.testng.ITestContext;
import org.testng.ITestListener;
import org.testng.ITestResult;

public class CustomTestListener implements ITestListener {
    private static final Logger LOGGER = Logger.getLogger(CustomTestListener.class);

    public void onTestStart(ITestResult result) {
        // テストメソッドの情報をログに出力
        LOGGER.info(String.format(
            "Running: %s#%s(%s)",
            result.getMethod().getTestClass().getName(),
            result.getMethod().getMethodName(),
            Arrays.stream(result.getParameters()).map(x -> x.toString()).collect(Collectors.joining(", "))));
    }

    public void onTestSuccess(ITestResult result) { }
    public void onTestFailure(ITestResult result) { }
    public void onTestSkipped(ITestResult result) { }
    public void onTestFailedButWithinSuccessPercentage(ITestResult result) { }
    public void onStart(ITestContext context) { }
    public void onFinish(ITestContext context) { }
}

また，リスナを TestNG に登録するために，testng.xml を編集するか，テストクラスに @Listeners アノテーションを指定します．
testng.xml でリスナを登録する場合は，以下のように書きます．

<suite>
    <listeners>
        <listener class-name="com.example.calc.test.util.CustomTestListener"/>
    </listeners>
   <!-- ... -->
</suite>

テストクラスに @Listeners アノテーションを指定する場合は，以下のように書きます．

import org.testng.annotations.Listeners;

@Listeners({ CustomTestListener.class })
public class CalcTest {
    // ...
}

期待されるログの出力はこんな感じです．

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running TestSuite
[CustomTestListener] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 0, 0)
[CustomTestListener] [INFO] Running: com.example.calc.test.CalcTest#testAdd(0, 1, 1)

まとめ

TestNG で実行中のテストを可視化する方法を紹介しました．
この記事で紹介したように方法はいろいろあるので，ケースバイケースで試してみてください！

参考文献

TestNG Documentation

TestNG で実行中のテストメソッドをリスナで可視化する