共通部品にチャレンジ：#9）LotusScript 実行ログ - 経過時間の測定と出力

作成中のLotusScript 実行ログ出力ライブラリに処理時間を測定する機能を追加します。

まず、ログ出力の開始から終了までの経過時間を測定して記録します。

ついでに、ログ出力間の経過時間も測定し、閾値を越えるとログの先頭に表示する機能も作ります。この機能があれば簡易的にボトルネックを探すことができますね。

経過時間の測定方法

Now で取得できる時間の最小単位は秒のため経過時間測定には少々おおざっぱです。そこで、今回は Timer を使ってミリ秒単位で測定することとします。

◇ フォームの修正

まず、経過時間を表示するフィールドを実行時間欄に追加します。

項目	フィールド名	種類		補足
経過時間	LogElapsedTime	数値	編集可能	少数 2 桁

◇ スクリプトライブラリの修正

まず、(Declarations) に開始時点の Timer 値を記録する変数宣言を追加します。

・・・ 'カウンタ Private xlMessage As Long      '通常ログ出力件数 Private xlError As Long             'エラーログ出力件数 '経過時間管理 Private xsgST As Single            '実行開始時の Timer 値

初期化関数である LogOpen で Timer 値を代入します。

Public Function LogOpen(ByVal vsLogTitle As String) As Boolean          ・・・    If xbIsOpen = True Then Exit Function    '時間管理    xsgST = Timer()    'ログ文書の作成          ・・・

最後に終了処理で経過時間を記録します。

Private Function xLogClose() As Boolean          ・・・       xndLog.LogEndTime = Now       '経過時間       xndLog.LogElapsedTime = Timer() - xsgST       xndLog.LogMessageCount = xlMessage          ・・・

これで、実行時間欄に経過時間が表示されます。

ログ間の経過時間の記録

続いては、ログの出力間隔の経過時間を記録する機能を作ります。この作業はスクリプトライブラリの修正だけで対応します。

◇ 初期設定

この処理で使用する変数を(Declarations) に追加します。経過時間は紫色で表示するのでそのフォント変数と経過時間等の変数を 2 つ追加します。

・・・ 'フォント定義 Private xnrtsDT As NotesRichTextStyle        'ログ時刻 Private xnrtsMsg As NotesRichTextStyle     '通常のメッセージ Private xnrtsErr As NotesRichTextStyle       'エラーメッセージ Private xnrtsET As NotesRichTextStyle        '経過時間          ・・・ '経過時間管理 Private xsgST As Single             '実行開始時の Timer 値 Private xsgPrev As Single         'ひとつ前のログ出力時の Timer 値 Private xsgET_TH As Single    '経過時間の閾値（秒）          ・・・

経過時間用のフォント設定を初期化に追加します。

Private Function xInitFont(vnrti As NotesRichTextItem)          ・・・    '経過時間    Set xnrtsET = xns.CreateRichTextStyle()    xnrtsET.NotesColor = 11     '濃い紫    xnrtsET.FontSize = 10    xnrtsET.NotesFont = vnrti.GetNotesFont(sFont, True)    xnrtsET.Bold = False End Function

経過時間は一番左に小数点揃え表示するため、段落の設定を調整します。

Private Function xInitParagraphStyle()    '通常のメッセージ    Set xnrtpsMsg = xns.CreateRichTextParagraphStyle()    xnrtpsMsg.FirstLineLeftMargin = 1 * RULER_ONE_INCH    xnrtpsMsg.LeftMargin = 8.5 * RULER_ONE_CENTIMETER    Call xnrtpsMsg.SetTab(3.5 * RULER_ONE_CENTIMETER, TAB_DECIMAL)    Call xnrtpsMsg.SetTab(8.0 * RULER_ONE_CENTIMETER, TAB_RIGHT) End Function

この設定を行うことにより段落は次のように設定されます。

初期化処理である LogOpen で経過時間に関連する変数を初期化します。次のログ出力までの経過時間を知るために、開始時間を xsgPrev に保管しておきます。

Public Function LogOpen(ByVal vsLogTitle As String) As Boolean          ・・・    If xbIsOpen = True Then Exit Function    '時間管理    xsgST = Timer()    xsgPrev = xsgST    xsgET_TH = 0.5     ' 処理時間出力閾値          ・・・

なお、処理時間を出力する閾値は、とりあえず 0.5 秒としておきます。

◇ 経過時間の算出と出力

ログ間の経過時間の計算は単純です。現在の Timer 値と前回の Timer 値 xsgPrev の差をで算出します。算出後は次のログに備えて xsgPrev に現在の値をセットします。

Private Function xPrintLog(ByVal vbIsError As Boolean, ByVal vsMessage As String) As Boolean    Dim sgET As Single    Dim sgNow As Single    '経過時間    sgNow = Timer()    sgET = sgNow - xsgPrev    xsgPrev = sgNow    '通常ログのスタイル適用    Call xnrti.AppendParagraphStyle(xnrtpsMsg)    '経過時間を次を右寄せにするためのダミータブ    Call xnrti.AddTab(1)    '経過時間    If sgET >= xsgET_TH Then       '閾値を越えているので出力       Call xnrti.AppendStyle(xnrtsET)       Call xnrti.AppendText(Format(sgET, "#.00"))    End If    Call xnrti.AddTab(1)          ・・・

経過時間は、閾値を超えた場合に出力します。出力項目である経過時間、時刻、メッセージの間にはタブをセットします。段落設定と合わせると、次のように体裁よく表示されます。

なお、経過時間の検証を行うにはスクリプトを一時停止する必要があります。デバッガでステップ実行するか Sleep 関数を使うと確認できます。

If i = 5 Then Sleep 5     ' 5 秒停止

まとめ

今回は経過時間の測定と出力に対応しました。

ミリ秒単位の測定に使用した Timer 関数については過去の記事『実行時間の計測（Timer 関数）』を参照ください。また、ログの出力では少々細かいタブの設定を利用しました。タブの設定と動作については『リッチテキスト：#9）タブの設定』を参考にしてください。

前回

共通部品にチャレンジ