動的解析ツールとは

動的解析ツールはプログラムを動かして、問題点を検出したり、挙動を見たりするためのツールです。具体的な機能例として、カバレッジや関数の実行時間測定、実行履歴を残すトレースなどがあります。広義な意味ではデバッガもこのツールの中に含まれます（と思います）。

動的テストツール「CodeRecorder」とは

動的解析ツールとして、コンピューテックス製の「CodeRecorder」を使用します。このツールは動的テストツールと謳っていますが、意味的には動的解析ツールと同じです。CodeRecorderはプログラムの実行を記録して、プログラムの見える化、カバレッジ、実行時間測定などの機能が使用できます。Windowsで動くツールですが、バージョン5からJenkinsでも呼び出せるように、コマンドラインで処理できる機能が追加されています。

これを使って、カバレッジと関数の実行時間を取得して、回帰テストに応用したいと思います。

システムの構成

CodeRecorderを使用した場合のシステム構成は次のようになります。

前回までで使用した環境にCodeRecorderのハードウェア「CR-200」をターゲットシステムに接続しています。CR-200はターゲットシステムにGPIOが2本あれば接続できます。CodeRecorderはソースコードに、ちょっとしたデータ出力用のコードを埋め込みます。そのコードからGPIOへデータを出力し、CR-200を通してパソコンへと転送されます。

CodeRecorderでできること

CodeRecorderを使用することで、次のような結果をログとして残すことができます。

• 関数レベルの実行履歴をログ出力
• 関数の詳細な実行時間測定
• 関数の周期実行時間測定
• 変数値の遷移をログ出力
• C0/C1カバレッジ率を測定

これらのログを正しい結果のログと比較することで、実行シーケンスの間違いや変化の検出、システムの速度ダウン、割り込み周期の変化などの検出に応用できます。また、カバレッジ率を比較することで、まだテストされていない新たに追加されたコードを検出することもできます。

CodeRecorderを追加したテストのシナリオ

テストのシナリオは第1回の内容と同じですが、そこにCodeRecorderを加えてどのような結果を残すかを考えます。ターゲットプログラムの処理内容は、

初期化 ⇒ 機能A ⇒ 終了処理

となっていますので、ここに以下のログの保存を追加します。

• 機能Aの関数実行時間
• 機能Aのカバレッジ

機能Aの関数実行時間を計測することで、プログラムが変更された場合に処理時間の変化を検出します。また、機能Aが拡張された場合に、テストされていない関数やパスをカバレッジで検出します。

テストを自動化するための準備

CodeRecorderはソースファイルにテストコードの埋め込み処理が必要ですので、ビルド処理が必須です。また、最初にプロジェクトを作って、データが正しく取れるところまで動作確認しておくことが必要です。

今回は機能Aのカバレッジのデータを取得しますので、機能Aに関連する関数およびカバレッジが有効になるようにテストコードの埋め込みを設定します。

実際にこの設定で正しくデータが取得できることを確認しておきます。次の画面のように関数スタックとカバレッジが正しく表示できれば問題ありません。

次にプロジェクト・ウィンドウを残してウィンドウを全部閉じ、プロジェクトの保存を行ってから終了します。この時のプロジェクト名は「test_a.cre2proj」とします。

バッチファイルの追加

第1回で作ったバッチファイルにCodeRecorderの実行処理を追加します。バッチファイルの全体としては次のような処理を行います。

1. テストコードの埋め込み（CodeRecorder）
2. ビルド
3. データ取得（CodeRecorder）
4. オブジェクトファイルのダウンロード⇒実行⇒終了（PALMiCE4）
5. 取得データをログ出力（CodeRecorder）
6. テストコードの削除（CodeRecorder）
7. ログの比較

この一連の処理をバッチファイルで定義します。まずテストコードの埋め込みは以下のコマンドを実行します。%CR%はCodeRecorderのEXEファイルを定義した環境変数です。

%CR% -P test_a.cre2proj –I

ビルド処理は単純にバッチファイルを呼び出します。

call build.bat

CodeRecorderをデータ取得待ちにしてから、並行してCSIDEを実行します。

start "" %CR% -P test_a.cre2proj -SN 1
%CSIDE% test_a.cpf

バッチでツールを起動すると、そのツールが終了するまで待ちになりますので、複数のツールを起動するためにstartコマンドを使用しています。%CSIDE%はCSIDEのEXEファイルを定義した環境変数です。

startコマンドの第二引数「""」はコマンドプロンプトのタイトルです。明示的に空のタイトルを指定しておかないと、%CR%がタイトルと間違って認識されるためです（これはハマります）。

カバレッジと関数実行時間のログを出力するのは以下のコマンドを実行します。

%CR% -P test_a.cre2proj -K 0 -RC -O test_ac.log
%CR% -P test_a.cre2proj -K 0 -RP -O test_ap.log

カバレッジ用と関数実行時間用、それぞれ機能ごとに実行します。

ログ出力が終われば、以下のコマンドでテストコードの埋め込みを解除して元のソースコードに戻しておきます。

%CR% -P test_a.cre2proj –E

ログの比較はCodeRecorder専用のログ比較コマンド（crdiff）を実行します。%CRDIFF%はそのEXEファイルを定義した環境変数です。カバレッジと関数実行時間のログをそれぞれ比較して、結果を「result_cr.txt」に出力します。

%CRDIFF% ok_test_ac.log test_ac.log > result_cr.txt
%CRDIFF% -g 10 ok_test_ap.log test_ap.log >> result_cr.txt

ここでfcコマンドを使わないのは、計測結果の時間に微妙なばらつきがあるため、同じプログラムを実行しても完全一致しないためです。crdiffコマンドは時間の誤差が指定できるようになっていますので、時間のばらつきを吸収して比較できます。

以上の内容をきっちりパスも含めて、全体をリストにすると次のようになります。

setlocal
set TDIR=C:\jenkins\TEST
set CR="C:\Program Files (x86)\COMPUTEX\CodeRecorder E2\Program\CodeRecorder E2.exe"
set CRDIFF="C:\Program Files (x86)\COMPUTEX\CodeRecorder E2\Program\crdiff.exe"
set CSIDE="C:\Program Files (x86)\CSIDE\Program\PALMiCE4 ARM.exe"

%CR% -P "%TDIR%\test_a.cre2proj" -I
call build.bat
start "" %CR% -P "%TDIR%\test_a.cre2proj" -SN 1
%CSIDE% "%TDIR%\test_a.cpf"

%CR% -P "%TDIR%\test_a.cre2proj" -K 0 -RC -O "%TDIR%\test_ac.log"
%CR% -P "%TDIR%\test_a.cre2proj" -K 0 -RP -O "%TDIR%\test_ap.log"

%CR% -P "%TDIR%\test_a.cre2proj" -E

%CRDIFF% "%TDIR%\ok_test_ac.log" "%TDIR%\test_ac.log" > "%TDIR%\result_cr.txt"
if not %errorlevel%==0 goto test_failed
%CRDIFF% -g 10 "%TDIR%\ok_test_ap.log" "%TDIR%\test_ap.log" >> "%TDIR%\result_cr.txt"

:test_failed
endlocal

ちょっとめんどくさいコード量になりましたね。途中にerrorlevelの判定をしていますが、ログ比較で不一致があった場合、Jenkinsに0以外の値を返して処理を失敗させるためです。

上で使用したCodeRecorderのオプションをまとめますと次の表のようになります。

オプション	説明
-P プロジェクトファイル名	対象となるプロジェクトファイルを指定します。このオプションは必須オプションです。
-I	プロジェクトに登録されている埋め込み対象のソースファイル全てにテストコードを埋め込みます。
-SN 秒	データ取得を開始し、指定秒数の間データが取得できなければ停止し、解析を自動で行います。
-K 番号	指定番号のレコードパケットを読み出します。番号は0 が最新、1 が一つ前、2 が二つ前となります。
-RC	カバレッジウィンドウの内容をCSV 形式で出力します。
-RP	関数の実行時間ウィンドウの内容をCSV 形式で出力します。
-O レポートファイル名	レポート出力のファイル名を指定します。このオプションが指定されていない場合は「log.txt」がデフォルトのファイル名となります。
-E	テストコードの埋め込みをすべて解除します。

では、この段階でこのバッチファイルを実行してみます。もちろん正解のログがありませんので、比較コマンドでエラーになりますが、ここで作成されたログを保存しておいて、以下のように正解のログとしてファイル名を変更しておきます。

test_ac.log　⇒　ok_test_ac.log
test_ap.log　⇒　ok_test_ap.log

Jenkinsへ追加

バッチファイルが正しく動作したら、それをJenkinsのスクリプトに追加してみましょう。

Jenkinsの管理画面を表示して[ダッシュボード]から[設定]をクリックします。

パイプラインをクリックしてスクリプト・エディタで下記の赤枠部分を追加します。前回作成した「テストA」と別ステージに「テストB」を追加します。

スクリプトの全体は以下のようになります。前回との違いは「cr_test_a.bat」の呼び出しを追加しただけとなります。

pipeline {
    agent { label 'node_a' }

    environment {
        def TEST_DIR = "c:\\jenkins\\TEST"
    }

    stages {
        stage('テストA') {
            steps {
                timeout(10) {
                    bat "${TEST_DIR}\\test_a.bat"
                }
            }
        }
        stage('テストB') {
            steps {
                timeout(10) {
                    bat "${TEST_DIR}\\cr_test_a.bat"
                }
            }
        }
    }
}

テストの実行

ここまでで準備は整いましたので、テストを実行します。ダッシュボードから[ビルド実行]をクリックするとパイプラインが実行されます。

実行中の状態がStage Viewに表示されます。テストに成功すると以下のように緑色のボックスで表示されます。

最終的な結果はファイルの比較でresult_cr.txtに出力されます。result_cr.txtの内容は以下の通りです。

違いは見つかりませんでした。C:\jenkins\TEST\ok_test_ac.log, C:\jenkins\TEST\test_ac.log
違いは見つかりませんでした。C:\jenkins\TEST\ok_test_ap.log, C:\jenkins\TEST\test_ap.log

次にソースコードを少し変更して検出結果がどうなるか確認してみましょう。ターゲットプログラムの関数内に3行ばかりコードを追加して、ビルド実行を行うと...

ご覧のようにテストBが失敗しました。比較結果のresult_cr.txtを確認すると以下のように違いが検出されています。

C:\jenkins\TEST\ok_test_ac.log(2): 実行結果が一致しません。"175", "178"
C:\jenkins\TEST\ok_test_ac.log(2): 実行結果が一致しません。"132", "133"
C:\jenkins\TEST\ok_test_ac.log(2): カバレッジ率が変化しています。"[ALL]", "75.4%", "74.7%"
C:\jenkins\TEST\ok_test_ac.log(2): 実行結果が一致しません。"35", "37"
C:\jenkins\TEST\ok_test_ac.log(2): 実行結果が一致しません。"17", "18"
C:\jenkins\TEST\ok_test_ac.log(4): 実行結果が一致しません。"90", "93"
C:\jenkins\TEST\ok_test_ac.log(4): 実行結果が一致しません。"83", "84"
C:\jenkins\TEST\ok_test_ac.log(4): カバレッジ率が変化しています。"[ALL]", "92.2%", "90.3%"
C:\jenkins\TEST\ok_test_ac.log(4): 実行結果が一致しません。"12", "14"
C:\jenkins\TEST\ok_test_ac.log(4): 実行結果が一致しません。"7", "8"

結果としてはソースコードの行数が増えたことによって、カバレッジ率が変化し、カバレッジの結果が不一致となりました。

このように動的解析を行うことで、プログラムの変化を敏感に検出できます。これを日々行うことで、例えば関数のわずかな速度ダウンが、将来大きなバグにつながることを未然に防いでくれるかもしれません。

ダウンロード

この記事で使用したファイルをまとめてダウンロードできます。