（※このトピックスは、Valence開発元（米CNX社）のブログ記事を翻訳・再編集したものとなります。原文記事は、コチラとなります。）
ユーザーを満足させるために重要な要素の1つは、ユーザーが頻繁に操作するアプリのパフォーマンスを向上させることです。以前のブログ記事で説明したように、ユーザーは、業務に必要なデータを取得するのに時間がかかりすぎると、焦ったり、作業に集中できなくなることもあります。そのため、開発者はパフォーマンスの問題をできる限り把握することが重要です。
(1) 特定のアプリの実行に予想以上の時間がかかる理由 (特に SQL が関係する場合) を突き止めること、および (2) 特定のユーザー要求に対してアプリが特定の値を返す理由を理解することを大幅に簡素化できる、多くのログ記録オプションが Valence には用意されています。Valence 6.1 の Portal Admin Log Viewer と併用することで、これらのログ機能は、デプロイされたアプリの舞台裏で何が起こっているかを簡単に理解することができます。
ログに記録される内容をコントロールすることが可能
Valence では、ブラウザから Valence インスタンスへの呼び出し、Valence インスタンスからブラウザへの応答、およびこれら 2 つのイベント間で発生するアクティビティのログを有効化および制御できます。ログ機能は、すべて[ポータル管理]> [設定] >[ログ設定]によって制御されます。
※日本バージョンでは上記の表示になります。
それぞれのログ設定について、少し詳しく説明します。
- ブラウザからのプログラムの呼び出しごとにログに記録します
チェックした場合、 Valence インスタンスで IBM i サーバーに行われた各 AJAX 呼び出しに対して、呼び出しがいつ行われたか、誰がそれを行ったか、何を呼び出したか、および呼び出しにかかった時間のタイムスタンプを含む VVCALLLOG という呼び出しログ表にレコードが書き込まれます。このログ出力はデフォルトではオフになっていますが、この単純なレベルのログに関連するオーバーヘッドはほとんどないため、一般的にはこれをオンにすることは悪い考えではないでしょう。 - ブラウザから渡されたすべてのパラメータをログに記録します
チェックした場合、VVCALLLOGレコードに追加情報が追加され、バックエンドに渡されたすべてのクエリパラメータ（合計8K文字まで）を見ることができるようになります。これは、ユーザーがブラウザでどのような操作をして呼び出しが行われたか、また何が要求されたかを判断するのに役立ちます。この補足的なログの記録には、すべてのパラメータを取得してログレコードに追加するためのわずかな追加オーバーヘッドが必要ですが、ほとんどの場合、それは無視できるほどの時間です。 - ブラウザに送信されたデータをすべてログに記録します
チェックした場合、バックエンドからユーザーのブラウザに返されるすべてのデータ（最大24K文字まで）が、VVCALLLOGレコードに追加されます。AJAX 呼び出しに対する応答は、特にグリッドの複数行のデータを返す呼び出しでは、かなり大きくなることがあるため、データの多いアプリを実行するユーザー数が多い場合、このログは多くのディスクスペースを使用する可能性があります。そのため、個々の呼び出しに対する応答データ(レスポンス)を見ることは有用ですが、この設定の有効化は、少し慎重を期す必要があるかもしれません。なお、ログデータの保持設定（以下の「ログサイズの制限」で説明）も、占有されるディスク容量の軽減に役立ちます。 - すべてのSQLステートメントのログ記録
チェックした場合、SQL結果をブラウザに送信するValenceバックエンドRPGツールキット・プロシージャ（特にvvOut_execSQLtoJSON、vvOut_execSQLtoSS、vvOut_execSQLtoCSV）のいずれかを呼び出すプログラムは、vvOut.logStmt=’0’で明示的にログ出力しないよう設定した場合を除き、SQL文をValence一般ログファイルVVGENLOGにログ出力します。各レコードには、実行されたSQLステートメント、いつ、誰がそれを実行したか、それを処理したIBM iジョブ番号、および実行の完了に要した時間が含まれます。この設定により、NAB アプリまたは Nitro File Editor アプリのいずれかからトリガーされたデータベースの更新/削除/追加も同様に記録されます。 - Nitro アプリのデータソースから実行されたすべてのSQLステートメントのログ記録
チェックした場合、NAB アプリが SQL 経由でデータを取得すると、VVGENLOG ログレコードの書き込みがトリガーされます。これは、長時間実行される SQL ステートメントを追跡し、ステートメントを変更したり、システムにインデックス/論理ファイルを追加するなどして、その速度を上げる方法を見つけるのに非常に役立ちます。
Valence をインストールしたときのデフォルトでは、上記すべてのログ出力がオフになっています。これは、小規模または低性能のシステムでパフォーマンスやディスク使用率に悪影響を与えないようにするためです。しかし、ほとんどの新しいシステムや高性能なシステムでは、ログを有効にしても通常パフォーマンスに顕著な影響はありません。ただし、システム構成に応じて、慎重にこれらの機能をオンにする必要があります。
RPGから手動でログデータを追加
これらの設定によって制御される自動ロギングに加えて、カスタムRPGプログラムはvvUtility_Logプロシージャを使用してVVGENLOGファイルにデータを書き込むこともできます。これは、デバッグや、様々なプログラム内で特定のコード行が実行されているときに単にログを取るのに便利です。RPGプログラムからログ・レコードを書き込む例は、次のようになります。
vvUtility_log('1':'Saving data for order number '+%char(ordno));
このようなログメッセージを、ブラウザからの呼び出しと結びつけて見ることができる方法は、後ほどご紹介します。
ログサイズの制限
ログデータは非常に便利ですが、システムのディスク容量が少ない場合、ログデータが多すぎると問題になることもあります。Valenceは、以下のように「ログ情報を保持する日数」の設定に基づき、一定時間が経過すると、古いログレコードを自動的に削除します。
- エラー情報を保持する日数
ファイル VVERRLOG に保存されたデータを参照し、RPG ツールキット・プロシージャのいずれかで発生した例外を保持します。 このデータは Errors アプリで使用/表示されます。 - ユーザー情報を保持する日数
すべてのユーザーセッションのログイン/ログアウトデータを保持するファイルVVUSRLOGに格納されているデータを指します。 このデータは、Nitroファイルエディタを使用して表示することができます。 - アプリ情報を保持する日数
ファイルVVAPPLOGに保存されるデータを指します。ユーザーが起動しているアプリに関する情報を保持します。 このデータは、アプリ使用状況アプリで使用されます。VVAPPLOGのレコードは比較的小さいため、一部のサイトでは、この設定を2年（730日）のようなはるかに長いパージ期間に拡張しています。 - VVCALL情報を保持する日数
前述のVVCALLLOGファイルに格納されるデータを指します。 このファイルは、特にバックエンドの応答データを含めると、すぐに大きくなり、1コールあたり最大24Kまで消費する可能性があります。したがって、この設定をデフォルトの14日間、または非常にアクティブなインスタンスではそれ以下に設定することをお勧めします。 - VVGENLOG 情報を保持する日数
前述の VVGENLOG ファイルに保存されるデータを指します。このファイルはSQL文と実行時間のリポジトリであり、一般的にあまり長くはないので、アプリのSQLパフォーマンスをより長い時間枠で分析したい場合は、この保持期間を14日のデフォルトより延長するとよいでしょう。
ログの内容を解析する
取得したログの内容を解析することで「成果」に結び付けます。ポータル管理アプリには「ログ」タブがあり（左上のメニュー選択でアクセス可能）、選択すると、最新のログデータが逆時系列で一覧表示できます。
※日本バージョンでは上記の表示になります。
左側のパネルにあるフィルターは、調査したいログ内容を探すのに非常に便利です。フィルタリング可能な要素は以下の通りです。
- 日付範囲– 指定された日付の間に行われたブラウザコールにリストをフィルタリングします。
- プログラム– リストを特定の RPG プログラムへの呼び出しのみにフィルタリングします。 これはコール・スタックの最上位にあるプログラムを参照し、そのプログラム内で続いて呼び出されるプログラムは参照しないことに注意してください。
- アクション– 特定の「ACTION」クエリパラメータを含む呼び出しのみにリストをフィルタリングします。
- ユーザー– 特定の IBM i プロファイルの下で行われたログ内容のみにリストをフィルタリングします。
- ジョブ番号– 特定の IBM i ジョブ番号に行われた呼び出しのみにリストをフィルタリングします。
- 転送– 指定したテキストに完全に一致する、または部分的に一致するクエリパラメータ値を含む呼び出しにリストをフィルタリングします。これはワイルドカード（”含む”）タイプの検索なので、この値と一緒に日付範囲や他のフィルタも併用すると、検索時間が短縮できます。
- 応答– 指定されたテキストに完全に一致する、または部分的に一致する値を返す呼び出しにリストをフィルタリングします。検索時間を短縮するには、これも他のフィルタと組み合わせて指定する必要があります。
- Valenceユーザー– 指定されたValenceユーザープロファイル名の下で行われたログ内容のみにリストをフィルタリングします。
- アプリケーション– リストを特定のValenceアプリで実行されたログ内容のみにフィルタリングします。
- 期間– 数ミリ秒を超える送受信にリストを制限します。 これは、完了までに数秒以上かかっているプログラム通話を探す場合に便利です（1000ミリ秒＝1秒）。 2.5秒を超える送受信は、期間(ﾐﾘ秒)が赤でハイライトされて表示されます。
- SID– リストを特定のValenceセッションID（SID）に対する呼び出しのみにフィルタリングします。通常、SIDの最初の5文字か6文字のみで、特定のセッションに分離するのには十分です。
検査したいプログラムコールが見つかったら、その行をクリックして詳細を確認します。最大で3つのタブのデータがあります。ポストデータを記録している場合、最初のタブ（「ポスト」）には、渡されたすべてのクエリーパラメーター（最大8K文字まで）がリストアップされます。
※日本バージョンでは上記の表示になります。
レスポンスデータを記録している場合、次のタブ（「応答」）には、ブラウザに戻された文字が最大24Kまで表示されます。JSON構造のレスポンスの場合、データは読みやすいようにフォーマットされています。
NAB アプリでは、ウィジェットがバックエンドからデータを取得するたびに、VVDATASRC プログラムへの “getData” 呼び出しが記録されます。SQL ロギングが有効な場合、各 SQL 文とその実行時間がこのタブに表示されます。
実行時間の長いSQL文をACSの「SQLスクリプトの実行」や「SQL Performance Center」などを使用して、実行に時間がかかっている原因を分析し、SQLエンジンがより速く処理できるように文を調整するか、インデックスを追加することが可能です。