デバッグログを解析するための新ツールが登場

4D v17 R5では、デバッグログにメソッドを追加し、各プロセスを独立してトレースできるように改善しました。このR-リリースでは、さらに一歩進んで、プロセスの実行を監視するのに役立つデバッグログアナライザツールを出荷しました。どのプロセスが最も消費されているか、コールチェーンとそれに対応する実行時間などを見ることができるようになります。

HDI: デバッグログアナライザ

このブログでは、動的なウェブページを提供するデータベースからの応答が遅い理由を見つけなければならないシナリオを紹介します。

一部のユーザーは、Webサイトの応答が遅いことがあることに気づいていますが、詳細を説明することはできません。調査する方法はいくつかあるので、何が起こっているのか見てみましょう。

デバッグログを生成する

デバッグログアナライザーは、4D v14のデバッグログファイルフォーマットをベースにしています。ですから、ロギングを有効にするには、次のコードを使用するだけです。
//パラメータ(オプション2)、4D v14ファイルフォーマット(オプション4)、書き込み遅延(オプション8)でデバッグログを有効 化
SET DATABASE PARAMETER (Debug log recording;2+4+8 )

4D v17 R5から、単一のプロセスに対してデバッグを有効にすることができることに留意してください。もし、特定のプロセスが遅延の原因であると思われる場合、その特定のプロセスだけのデバッグログを開始することが簡単になり、時間もかからなくなりました。

SET DATABASE PARAMETER ( ;2+4+8)Current process debug log recording

プロジェクトの作成

デバッグ・ログ・アナライザーは、デバッグ・ログ・ファイルの集合であるプロジェクトと、デバッグ・ログ・セッションを管理する。

データベースを開くと、保存されているプロジェクトのリストが表示されます。新規作成」ボタンでプロジェクトを作成することができます。デバッグ・ログが格納されているフォルダを選択するか、解析したいファイルを選択し、プロジェクト名を付ける必要があります。

解析処理はプリエンプティブに実行されていても、スキャンするファイル数やマシンの処理能力によって時間がかかる場合がありますので、ご注意ください。

プロジェクトの解析

リストからプロジェクトを選択すると、デバッグ・ログの範囲や解析された行などの基本情報がサマリーとして表示されます。対応するボタンをクリックすると、プロジェクトのコールチェーン、統計、プロジェクトの詳細が表示されます。

コールチェーン

コールチェーン画面では、プロセスの実行時間の合計が一覧表示されます。リストの順番は、最も時間のかかるプロセスが画面の上部に表示されます。

プロセスのコールチェーンを拡張し、各レベルで最も時間のかかる処理を確認することができます。ALTキーストロークでプロセスをクリックすると、自動的に最も重いコールチェーンを拡張し、操作をダブルクリックすると、チェーンエクスプローラーに移動する。そして、リストからレベルを選択すると、対応するレベルの階層リストビューが更新されます。選択された各コマンドについて、総呼出数、総時間、平均時間が表示されます。

例

以下の例では、最も消費量の多いプロセスとコマンドを検索しています。RELATE MANY SELECTION コマンドが完了するまでに1分以上かかることがわかります。詳細情報のセクションを見て、このコマンドが呼び出された場所を確認しましょう。

詳細情報

時間範囲の選択

詳細画面では、アクティビティのタイムラインが分単位で表示されます。ズームイン、ズームアウトして、詳細を見たり、減らしたりすることができます。これにより、分析する特定の時間範囲を選択することができます。制限を移動することで、1分または数分だけを選択することができます。

新しい範囲を選択すると、分析が実行され、その結果が画面の下部に表示されます。アクティビティの高い時間帯を指摘することで、遅いプロセスを判断する別の方法があります。

サマリー]タブ

サマリー] タブには、選択した時間間隔でのプロセス実行時間の一般的な統計が表示されます。リストからプロセスを選択することで、統計情報を折りたたむことができます。

トップ] タブ

トップ] タブには、選択したプロセスと時間範囲について、ログに記録されたすべての操作とそのコール数、および合計実行時間が表示されます。コマンド、メソッド、またはメンバー・メソッドのフィルタを使用して、リストを縮小することができます。これは、最も消費されるコマンド、メソッドなどを決定するためのもう一つの良い方法です。

この例に従って、時間範囲を選択し、コマンドでフィルターをかけました。確認が表示されます。RELATE MANY SELECTION コマンドは数回使用され、長い時間がかかりました。次のステップに進み、詳細を確認しましょう。

オペレーション

Operations」タブには、選択されたプロセスについて、1つの孤立した分単位の詳細な操作がすべて表示されます。リストを縮小したり、操作を検索して単純にハイライト表示することもできます。パフォーマンス上の理由から、この統計は1分間に制限されています。したがって、開始された操作を表示する分数を選択することを忘れないでください

このリストは、実行されたすべてのコード行を表示するため、非常に便利です。また、列で並べることもできます。

この例を終えるために、RELATE MANY SELECTION コマンドを検索し、リストにフィルターをかけ、Duration 列でソートしました（最も長い呼び出しをリストの一番上に置くため）。最も時間のかかる2つの呼び出しは、同じフィールドで行われているようです。データベースの構造をざっと見て、犯人がわかりました：フィールドのインデックス付けが必要だったのです。

結論として

このツールは、コードの中のコンフリクトを発見し、データベースのパフォーマンスを向上させるために設計されています。上記のHDIをダウンロードして、手を汚して楽しく調査してみましょう!