vba stack trace logger アドインの活用例・注意事項
はじめに
プログラミングでデバッグを行う際、スタックトレース(関数の呼び出し履歴)は非常に重要な情報です。
エラーが起きたときにどの関数からどの関数を経由してここに至ったのかが分かれば、原因を突き止めやすくなります。
しかし、VBAでは「コード実行中」にスタックトレースを取得する標準的な機能がありません。
そこで、VBA でスタックトレースを含むログ出力を簡単に行えるロガーアドインを作成しました。
アドインの導入・基本的な利用方法は以下の記事をご確認ください。
本記事では、実際にこのロガーを使っているシーンをもとに、活用例や注意点を紹介します。
筆者の用途の都合上、エラーハンドリングやデバッグの内容が中心になりますが、実践的な視点での紹介になっていますので、ぜひ参考にしていただければ幸いです。
[2025-06-22 19:30:24.076][Trace][MyModule.MainProc] >> Enter MyModule.MainProc
[2025-06-22 19:30:24.077][DEBUG][MyModule.MainProc] This is my message
[2025-06-22 19:30:24.079][Trace][MyModule.SubProc < MyModule.MainProc] >> Enter MyModule.SubProc
活用例
例1:エラーハンドリング未実装時のログによる原因特定支援
VBA 開発では、エラーハンドリングが不十分な場合、エラー発生時の状況把握が困難になるという大きな課題があります。
通常では
- エラーハンドラー(
On Error GoTo ErrorHandler
)を記述する-
Debug.Print Err.Number
の様にエラー内容を記録する
-
- 呼び出し元へのエラーの伝播(
Err.Raise
)を記述する - プロシージャの呼び出し・完了時に
Debug.Print
でログを残す
といった対策を行います。
しかし、これらは工数が多く、開発速度優先で後回し・一部のみ実装とされるケースもあります。
対策無しでは、いつどこでエラーが発生したかの手がかりが皆無な状況へ陥ります。
本ロガーのスタックトレース機能を使用すれば、プロシージャの呼び出し記録を手軽に記録できます。
※ エラーハンドリングが無い場合、標準機能でエラー時に得られる情報の例
プロシージャ ProcessStepC()
にて 0 除算を行ったとします。
コードを実行すると、以下の様にエラーを知らせるダイアログが表示されます。
デバッグボタンを押すと、エラーが発生した行が黄色にハイライトされます。
---得られる情報は以上です。---
致命的なのは、上記情報は全て エディター(VBE)の GUI で表示されるだけであり、テキストデータ(ログなど)は有りません。
無論、情報量も不足しています。
- どのタイミングでエラーが起きたのか?
- どの様な順序でプロシージが呼び出されていたのか?
といった情報は分かりません。
---他の言語と比べ、VBA では対策なしにエラーが発生した際の代償がとても大きいと言えます。---
他の言語の場合、エラー時にスタックトレース情報がコンソールにテキストとして出力され最低限の情報が担保されているパターンが多いです。
活用イメージ
- シナリオ
ループ処理の中で、アイテムの番号に応じて複数の異なる処理が呼び出す。
特定の処理 (ProcessStepC
) にて、エラーハンドリング無しの状態で意図的にエラーを発生させる。
Option Explicit
Private Const MODULE_NAME As String = "MyModule"
Sub CheckLogger()
' === ロガーの初期化 ===
Mylogger.StartConfiguration _
.EnableStackTrace _
.EnableWriteToExcelSheet _
.SetOutputExcelSheet(ActiveSheet) _
.Build
' === ログの出力 ===
ProcessLargeData
' === ロガーの終了処理 ===
Mylogger.Terminate
End Sub
Sub ProcessLargeData()
Const PROC_NAME As String = "ProcessLargeData": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
Mylogger.Log "処理開始"
Dim i As Long
For i = 1 To 10
Mylogger.Log "[処理開始] " & i & " 番目のデータ"
ProcessStepA ' 必ず実施する処理
If i Mod 2 = 0 Then ProcessStepB ' 2の倍数の時のみ実施する処理
If i Mod 3 = 0 Then ProcessStepC ' 3の倍数の時のみ実施する処理
Mylogger.Log "[処理終了] " & i & " 番目のデータ"
Next i
Mylogger.Log "処理完了"
End Sub
Private Sub ProcessStepA()
Const PROC_NAME As String = "ProcessStepA": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
' 処理
End Sub
Private Sub ProcessStepB()
Const PROC_NAME As String = "ProcessStepB": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
' 処理
End Sub
Private Sub ProcessStepC()
Const PROC_NAME As String = "ProcessStepC": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
' わざとエラーを発生させる
Err.Raise 513
End Sub
得られるログ
[2025-06-27 23:45:41.067][Trace][MyModule.ProcessLargeData] >> Enter MyModule.ProcessLargeData
[2025-06-27 23:45:41.068][INFO][MyModule.ProcessLargeData] 処理開始
[2025-06-27 23:45:41.071][INFO][MyModule.ProcessLargeData] [処理開始] 1 番目のデータ
[2025-06-27 23:45:41.072][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] >> Enter MyModule.ProcessStepA
[2025-06-27 23:45:41.073][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] << Exit MyModule.ProcessStepA
[2025-06-27 23:45:41.073][INFO][MyModule.ProcessLargeData] [処理終了] 1 番目のデータ
[2025-06-27 23:45:41.074][INFO][MyModule.ProcessLargeData] [処理開始] 2 番目のデータ
[2025-06-27 23:45:41.074][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] >> Enter MyModule.ProcessStepA
[2025-06-27 23:45:41.075][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] << Exit MyModule.ProcessStepA
[2025-06-27 23:45:41.075][Trace][MyModule.ProcessStepB < MyModule.ProcessLargeData] >> Enter MyModule.ProcessStepB
[2025-06-27 23:45:41.076][Trace][MyModule.ProcessStepB < MyModule.ProcessLargeData] << Exit MyModule.ProcessStepB
[2025-06-27 23:45:41.076][INFO][MyModule.ProcessLargeData] [処理終了] 2 番目のデータ
[2025-06-27 23:45:41.077][INFO][MyModule.ProcessLargeData] [処理開始] 3 番目のデータ
[2025-06-27 23:45:41.077][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] >> Enter MyModule.ProcessStepA
[2025-06-27 23:45:41.078][Trace][MyModule.ProcessStepA < MyModule.ProcessLargeData] << Exit MyModule.ProcessStepA
[2025-06-27 23:45:41.079][Trace][MyModule.ProcessStepC < MyModule.ProcessLargeData] >> Enter MyModule.ProcessStepC
このテキストとして出力されたログから、VBA・VBE 標準機能では得られない様々な情報が分かります。
-
どのタイミングでエラーが起きたのか?
- 3 番目のデータの [処理終了] ログがないため、3 番目の処理でエラーが起こっていると推測できます。
-
ProcessStepC
の開始ログ (>> Enter ProcessStepC
) はありますが、終了ログ (<< Exit ProcessStepC
) がないことから、ProcessStepC
の処理途中でエラーが発生したと特定できます。
-
どの様な順序でプロシージが呼び出されていたのか? (スタックトレース)
- エラー発生で処理が止まったログの最終行を確認すると、[MyModule.ProcessStepC < MyModule.ProcessLargeData] という呼び出し階層が記録されています。
-
ProcessLargeData
→ProcessStepC
という順序でプロシージャが呼び出された結果、エラーに至ったと追跡できます。
-
直前までの処理状況
-
1 番目と 2 番目のデータの処理([処理開始] から [処理終了] まで)はログ上でも正常に完了していることが確認できます。
-
3 番目のデータについても、
ProcessStepA
は正常に実行された(>> Enter ProcessStepA
、<< Exit ProcessStepA
) ことがログから分かります。
-
例2:エラーハンドリングの強化
本ロガーを使用すれば、標準のエラーハンドリングで不足するスタックトレース情報を補えます。
活用イメージ
Option Explicit
Private Const MODULE_NAME As String = "MyModule"
Sub CheckLogger()
' === ロガーの初期化 ===
Mylogger.StartConfiguration _
.EnableStackTrace _
.EnableWriteToExcelSheet _
.SetOutputExcelSheet(ActiveSheet) _
.Build
' === ログの出力 ===
MainProc
' === ロガーの終了処理 ===
Mylogger.Terminate
End Sub
Sub MainProc()
Const PROC_NAME As String = "MainProc": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
On Error GoTo ErrorHandler
Mylogger.Log "処理開始"
SubProc
Mylogger.Log "処理終了"
Exit Sub
ErrorHandler:
Mylogger.Log "エラー発生。Number: " & Err.Number & "。Desc: " & Err.Description, LogTag_Error
End Sub
Private Sub SubProc()
Const PROC_NAME As String = "SubProc": Dim scopeGuard As Variant: Set scopeGuard = Mylogger.UsingTracer(MODULE_NAME, PROC_NAME)
On Error GoTo ErrorHandler
' エラーが発生する処理
Dim hoge: hoge = 1 / 0
ErrorHandler:
Mylogger.Log "エラー発生。Number: " & Err.Number & "。Desc: " & Err.Description, LogTag_Error
Err.Raise Err.Number, Err.Source, Err.Description
End Sub
得られるログ
エラーハンドラー(ErrorHandler
)にて、myLogger.Log "エラーの説明", LogTag_Error
の様に Error タグ
を指定したログを出力しています。
SubProc()
で発生したエラーがログに記録され、Err.Raise
によって MainProc()
に伝播し、そこでも再度エラーとしてログに記録されていることが分かります。
エクセルへログ出力するとエラーの確認が楽になります。
- タグの種類によって色が付く(例: Error なら赤色)
- Tag 列を Error でフィルターをかけることが可能
ログ全文(折り畳み)
[2025-06-28 00:44:52.011][Trace][MyModule.MainProc] >> Enter MyModule.MainProc
[2025-06-28 00:44:52.013][INFO][MyModule.MainProc] 処理開始
[2025-06-28 00:44:52.014][Trace][MyModule.SubProc < MyModule.MainProc] >> Enter MyModule.SubProc
[2025-06-28 00:44:52.016][ERROR][MyModule.SubProc < MyModule.MainProc] エラー発生。Number: 11。Desc: 0 で除算しました。
[2025-06-28 00:44:52.019][Trace][MyModule.SubProc < MyModule.MainProc] << Exit MyModule.SubProc
[2025-06-28 00:44:52.020][ERROR][MyModule.MainProc] エラー発生。Number: 11。Desc: 0 で除算しました。
[2025-06-28 00:44:52.023][Trace][MyModule.MainProc] << Exit MyModule.MainProc
例3:開発・リリースでのログ出力切り替え
開発中はログを細かく確認したい一方で、マクロを他の人に渡す(リリースする)際には、ログ出力を抑えるか、完全に無効化したい場面があります。
本ロガーのカスタマイズ機能と VBA の条件付きコンパイル機能を組み合わせることで、簡易に実現できます。
設定例
#Const DEBUG_MODE = False
のようにモジュールで条件付きコンパイラ定数を宣言します。
開発中は True
、リリース時は False
とします。
以下の例では、#If DEBUG_MODE ~ #End If
にてロガーのカスタマイズ(初期化処理)を変えています。
Option Explicit
#Const DEBUG_MODE = False
Private Const MODULE_NAME As String = "MyModule"
Sub MainProc()
' === ロガーの初期化 ===
#If DEBUG_MODE Then
' DEBUG_MODE が有効な時(開発中など)はログ出力を行う
MyLogger.StartConfiguration.Build
#Else
' 設定例1 ログ出力を全て無効化
MyLogger.StartConfiguration.DisableLogging.Build
' 設定例2 特定のタグを無効化
'(Info・Trace タグは無効化 = Error タグなどはログ出力される)
MyLogger.StartConfiguration _
.EnableTagFiltering _
.Add(LogTag_Info) _
.Add(LogTag_Trace) _
.Apply _
.Build
#End If
End Sub
(参考)通常の設定方法との比較
通常は、以下のように個別のログ出力を制御する形が多いかと思います。
これでは編集箇所が多く、冗長で可読性も悪いです。
Option Explicit
#Const DEBUG_MODE = False
Sub MainProc()
#If DEBUG_MODE Then
Debug.Print "何かしらのログ"
#End If
End Sub
本ロガーでは、初期化時にロガーの挙動をカスタマイズする仕様にすることで、初期化時部分のみを分岐させるだけで済みます。
コード中にあるログ指示 MyLogger.Log "何かしらのログ"
をコメントアウトする必要はなく、設定によってログ出力命令をロガーが無視するようになります。
ただし、ログ出力の命令文を起点としたロガーとの処理のやり取りは発生します。そのため、厳密に処理速度やメモリ消費量を削る場合は、ロガー関連のコードを全てコメントアウトすべきでしょう。(とはいえ影響は微細だと思うので、普段は気にする必要は無いはずです。)
(雑記)他言語だと標準機能として存在していたりします
例えば、C#(エディターは Visual Studio 想定)の場合、ビルド時(コードを exe
ファイルに変換する時)に「開発」/「リリース」モードを選択します。
開発モードではコード中の Debug.WriteLine()
が有効で、ログが出力されますが、リリースモードでは自動的に無効化され、ログが出力されません。
また、Trace.WriteLine()
のように、常に出力されるログ手段も用意されています。
こういった機能を公式がアップデートで追加してくれたら嬉しいのですが...。
Debug.WriteLine("このメッセージは開発中のみ出力されます");
Trace.WriteLine("このメッセージは常に出力されます");
例4:別ツールとの併用 - コードの自動挿入による効率化
スタックトレース機能を使用するための Const PROC_NAME ...
といった定型的なコードの記述は、プロシージャごとに手作業で行うと手間がかかります。
MZ-Tools
といった VBA 開発支援ツールや自作マクロを活用し、コード自動挿入を行うと作業が効率化できます。
MZ-Tools
様々な機能を追加するツールです。
ショートカットで定型文を挿入出来ます。
2025年6月時点では、有償($79.95)です。
また、定型文の挿入時に、自動的に値を割り当てる機能もあるようです。
Predefined variables are variables used in code templates, exception / error handlers, headers, etc. whose values are assigned automatically by MZ-Tools when the code template is inserted into the code file (on the contrary to user-defined variables, whose values are asked to the user through a dialog window).
Code Element Full Name ($P[CODE_ELEMENT_FULL_NAME]): the full name (with namespace or library name) of the code element where the template is being inserted. For example, "Vehicles.Car".
Code Element Name ($P[CODE_ELEMENT_NAME]): the name (without namespace) of the code element where the template is being inserted. For example, "Car".
自作マクロ(非推奨)
マクロでコードを直接編集して定型文を挿入する方法です。
実際のコードは StackTraceLib_VBA
などを参考にしてしてください。
詳細を知りたい方用
StackTraceLib_VBA
では、VBA を用いて VBE そのものにアクセスし、モジュールを参照・編集します。
' vbaModule には CodeModule が代入される
' VBComponents は Collection
' 実行すると、プロジェクトに含まれるいずれかのモジュール名が出力される
Dim vbaModule As Variant
Set vbaModule = Application.VBE.ActiveVBProject.VBComponents(1).CodeModule
Debug.Print vbaModule
Application.VBE.ActiveVBProject
を実行するためには
- VBA プロジェクト オブジェクト モデルへのアクセスを信頼する
を有効にする必要があります。
これをオンにすると、以下の様なセキュリティーリスクが懸念されます。
- VBA プロジェクトへ VBA マクロ経由でアクセス可能になる
- VBA コードの改ざん、情報漏洩が容易な環境となる
- 外部から入手したマクロファイルに悪意あるコードが含まれていた場合、被害が大きくなる
困ったことに、この設定は Excel アプリケーション全体に適用されるため、VBA プロジェクト単位で権限を制御することはできません。
個人開発であれば許容される場合もありますが、企業利用においてはセキュリティーポリシーに抵触するおそれが高く、慎重な判断が必要です。
注意事項
動作環境
筆者の開発環境は以下の通りです。
- Windows 11 64 bit
- Excel (Microsoft Office Home and Business 2019, Ver. 2503, Build 18623.20178)
- VBA (Ver. 7.1, Build 7.1.1146, Forms3 16.0.18623.20076)
他の環境では動作テストを行っていません。
VBA のバージョンが同じ(Ver 7)ならば、動作すると思いますが、保証は致しかねます。
また、Excel マクロ以外での使用も想定しておりません。
想定している用途・向かない用途
大規模開発にてログベースで詳細な情報を得るために本ロガーを使用する、といった方向性を想定しています。
言い換えると、標準・クラスモジュールが複雑に組み合わさったプログラムであり、各関数にて本ロガーのスタックトレース機能を仕込み、ログベースで複雑な処理を可視化する、という用途です。
以下の様なケースでは、別ツールを選択した方が「記述が楽」「動作負荷が低い」可能性があります。
- 小規模開発
- 手動で Debug.Print を埋め込めば十分
- ピンポイントで特定の処理だけスタックトレース情報を見たい
- Debug.Print、エラー伝播による擬似スタックトレース ※1
- CallByName ラッパー手法 ※2
- 動作速度が最優先
- (前提)ログ出力自体が処理負荷となる点を考慮すべき
- 最低限の Debug.Print を使用
- 本ロガー + 条件付きコンパイルによる ON/OFF 制御 ※3
- デバッグ時は詳細なログを取得し、リリース時はログ出力を無効化 or 削減
- レガシーコード(既存のコード)への新規導入
- StackTraceLib_VBA などによるコード自動一括挿入が楽 ※4
- セキュリティーリスクを考慮すると、初期導入でのみ利用、その後はリファクタリングを進めて別手法へ置き換えすべき
- StackTraceLib_VBA などによるコード自動一括挿入が楽 ※4
- 非同期的な処理 ※5
- Debug.Print、エラー伝播による擬似スタックトレース
- 本ロガーや StackTraceLib_VBA では意図しない挙動になるリスク有り
・※1 エラー伝播による擬似スタックトレース について
・※2 CallByName ラッパー手法について
・※3 条件付きコンパイルについて
動作負荷・避けるべき使用方法
や 例3:開発・リリースでのログ出力切り替え
で紹介する方法を参考にしてください。
・※4 StackTraceLib_VBA について
・※5 エクセル VBA における非同期処理について
VBA は非同期処理をサポートしていないです。
回避方法も存在しますが特殊な方法ですので、本ロガーでのサポートは考えていません。
参考資料
別記事で各手法をまとめているので、ご参照ください。
動作負荷・避けるべき使用方法
ログの書き込み処理は、その都度実行されます。
高頻度でログ出力を行うと、その分、書き込み処理に時間を取られます。
また、スタックトレース機能もログ出力を伴うので、同様です。
対処法 1
For 文の場合、ループ毎にログ出力するのではなく、10 ループ毎に 1 度、のように調整する。
対処法 2
条件付きコンパイルを利用し、本番稼働時はログ出力を無効化する。
処理時間の目安
For 文で myLogger.Log "hi"
を 100 回呼び出した場合の経過時間を測定しました。
なお、エクセルシートとイミディエイトウインドウへの出力を行う設定です。
- イミディエイトウインドウに何も表示されていない状態で実行した場合
n | 時間(ms) |
---|---|
1 | 105 |
2 | 105 |
3 | 104 |
- イミディエイトウインドウに 200 行表示されている状態で実行した場合
n | 時間(ms) |
---|---|
1 | 109 |
2 | 113 |
3 | 119 |
結論としては、ログ出力処理には約 1 ms かかります。
また、スタックトレース機能の処理時間も確認してみました。
For 文でプロシージャを 50 回呼び出した場合、107 ms かかりました。
※ 1 回のプロシージャの呼び出しで「開始」「終了」のログが自動出力されるので、ログ出力を 100 回することになります。
スタックトレース機能を使う場合、処理時間の大半はログ出力処理時間でした。
ログ出力量の制限
200 行を超えるログを記録したい場合は、エクセルシートへの出力を推奨します。
- エクセルシート 1,048,576 行
- イミディエイトウインドウ 200 行
イミディエイトウインドウは 200 行までしか表示できません。
201 行目を書き込む場合は、1 行目が削除されます。
保守について
自分自身の業務のために作っているので、しばらくはメンテナンスをする予定です。
しかし、継続的な保守は確約できません。
MIT ライセンスで公開するので、更新が止まったら各自 Github で Fork なりしてご利用ください。
不具合・要望・PR について
不具合、要望は、本記事のコメントに書き込むか、Github の Issue を作成してください。
記録管理の観点で、Github の Issue の方が有難いです。
Github での Pull Request(PR)は大歓迎です。
PR を送る前に、以下をご確認ください。
- 該当する Issue があれば、リンクする
- 無ければ、Issue を作成する
- コードスタイルや命名規則がプロジェクトに沿っているか確認する
- 型は明記、必要性の無い Public は Private とする(変数、プロシージャ、モジュール)
- PR の粒度が適切か
- 複数の Issue に対する変更ならば、個々の Issue に対する PR に分割する
- 動作テストを実施する(変更した機能はマスト)
- 現状、単体テストや CI パイプライン(自動テスト)は未導入です
開発途中(WIP)です
記事を公開する時点では、デバッグ、エラーハンドリング、ドキュメント整備、と todo 事項は多くあります。
ひとまず、動くものが完成したので公開しますが、まだ不具合が残っている可能性は高いです。
ご承知おきください。
Discussion