パフォーマンス ロガーとコールバック

JDBC ドライバーのダウンロード

バージョン 13.4 以降、Microsoft JDBC Driver for SQL Server には、重要なドライバー操作のタイミングを追跡するためのパフォーマンス メトリック フレームワークが用意されています。 このフレームワークを使用すると、接続とステートメントの実行動作を観察および分析し、アプリケーションと SQL Server との対話における待機時間のボトルネックを特定できます。

メトリックは、独立して、または一緒に使用できる 2 つのメカニズムを通じて利用できます。

  • プログラムによるコールバック - アプリケーション コードでメトリックを受信する PerformanceLogCallback を登録します。
  • Java ログ - ログ出力でメトリックをキャプチャするために、専用の java.util.logging ロガーをサブスクライブします。

追跡されたアクティビティ

ドライバーは、接続とステートメントの 2 つのレベルでアクティビティを追跡します。

接続レベルのアクティビティ

アクティビティ 説明
CONNECTION すべてのサブアクティビティを含む、接続を確立するための合計時間。
PRELOGIN サーバーとの TDS プリログイン ネゴシエーションの時間。
LOGIN TDS ログインと認証ハンドシェイクの時間。
TOKEN_ACQUISITION Microsoft Entra 認証を使用する場合にフェデレーション認証トークンを取得する時間。

ステートメント レベルのアクティビティ

アクティビティ 説明
STATEMENT_REQUEST_BUILD TDS 要求を構築するためのクライアント側の時間 (パラメーター バインド、SQL 処理、パケット構築)。 タイミングのみで、例外は追跡されません。
STATEMENT_FIRST_SERVER_RESPONSE 要求の送信から最初のサーバー応答の受信までの時間。 タイミングのみで、例外は追跡されません。
STATEMENT_PREPARE sp_prepareの時におけるprepareMethod=prepareの時間。
STATEMENT_PREPEXEC sp_prepexecを使用して準備と実行を組み合わせる時間。
STATEMENT_EXECUTE ステートメントの実行時間 (sp_executesqlsp_execute、直接 SQL、またはバッチ)。

パフォーマンス メトリックを有効にする

オプション 1: コールバックを登録する

パフォーマンス データをプログラムで受信する PerformanceLogCallback を登録します。

SQLServerDriver.registerPerformanceLogCallback(new PerformanceLogCallback() {
    @Override
    public void publish(PerformanceActivity activity, int connectionId,
            long durationMs, Exception exception) {
        // Connection-level metrics
        System.out.printf("Activity: %s, Connection: %d, Duration: %d ms%n",
                activity, connectionId, durationMs);
    }

    @Override
    public void publish(PerformanceActivity activity, int connectionId,
            int statementId, long durationMs, Exception exception) {
        // Statement-level metrics
        System.out.printf("Activity: %s, Connection: %d, Statement: %d, Duration: %d ms%n",
                activity, connectionId, statementId, durationMs);
    }
});

ナノ秒のタイミングと文のコンテキストを活用しましょう

バージョン13.6からは、コールバックが useNanoseconds()を上書きすることでナノ秒タイミングにオプトインできるようになりました。 コールバックはまた、 getCurrentUserSql()getCurrentStatementType() を呼び出し、ステートメントレベルのイベントとアプリケーションが提出したSQLテキストおよび実行された文の種類を関連付けることも可能です。 getCurrentStatementType()STATEMENTPREPARED_STATEMENT、または CALLABLE_STATEMENT を返します。 getCurrentApplicationName()を使って、applicationName接続プロパティからイベントを生じさせた接続やプールを特定します。 applicationNameが設定されていない場合、メソッドはドライバーのデフォルトアプリケーション名を返します。

SQLServerDriver.registerPerformanceLogCallback(new PerformanceLogCallback() {
    @Override
    public boolean useNanoseconds() {
        return true;
    }

    @Override
    public void publish(PerformanceActivity activity, int connectionId,
            long durationNs, Exception exception) {
        // Connection-level metrics don't have SQL statement context.
        System.out.printf("Application: %s, Activity: %s, Connection: %d, Duration: %d ns%n",
            getCurrentApplicationName(), activity, connectionId, durationNs);
    }

    @Override
    public void publish(PerformanceActivity activity, int connectionId,
            int statementId, long durationNs, Exception exception) {
        String applicationName = getCurrentApplicationName();
        String userSql = getCurrentUserSql();
        StatementType statementType = getCurrentStatementType();

        System.out.printf("Application: %s, Type: %s, Activity: %s, SQL: %s, Duration: %d ns%n",
            applicationName, statementType, activity, userSql, durationNs);
    }
});

ナノ秒のタイミングはオプトインです。 useNanoseconds() をオーバーライドしないコールバックは、引き続きミリ秒単位の時間を受け取ります。 登録されたコールバックがオプトインすると、専用のパフォーマンスロガー出力もナノ秒単位を使用し、持続時間を nsでラベル付けします。それ以外はミリ秒と msを使用します。 一部のプラットフォームでは、 System.nanoTime() に電話をかけることに System.currentTimeMillis() 以上のオーバーヘッドがかかることがあります。

コールバックコンテキストは対応する publish() 呼び出し時のみ利用可能です。 getCurrentApplicationName()接続レベルおよびステートメントレベルのイベントに利用可能で、publish()null返却します。 また、接続プロパティが解析されていない場合、例えばアプリケーション名が解決される前に接続が失敗した場合など、 null を返すこともあります。 SQLコンテキストメソッドは、接続レベルのイベント、SQLコンテキストを持たない文のサブアクティビティメトリクス、publish()外での呼び出しに対してnullを返します。

Caution

SQLテキストにはリテラルやコメントで機密データが含まれていることがあります。 ログやテレメトリに書き込む前に、組織のデータ処理要件を適切に処理し、整理してください。

オプション 2: Java ログを構成する

パフォーマンスメトリックのロガーをjava.util.loggingFINEレベルに構成します。

logging.properties ファイル内:

com.microsoft.sqlserver.jdbc.PerformanceMetrics.Connection.level = FINE
com.microsoft.sqlserver.jdbc.PerformanceMetrics.Statement.level = FINE
handlers = java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level = FINE

または、プログラムで次の操作を行います。

Logger.getLogger("com.microsoft.sqlserver.jdbc.PerformanceMetrics.Connection")
      .setLevel(Level.FINE);
Logger.getLogger("com.microsoft.sqlserver.jdbc.PerformanceMetrics.Statement")
      .setLevel(Level.FINE);

ステートメント アクティビティに対する Prepare メソッドの効果

PreparedStatement追跡されるアクティビティは、prepareMethod接続プロパティによって異なります。 prepareMethodの詳細については、「接続プロパティの設定」を参照してください。

prepareMethod 設定 最初の実行 2 回目の実行 3 回目以降の実行
prepexec (既定値) STATEMENT_EXECUTE (sp_executesql) STATEMENT_PREPEXEC (sp_prepexec) STATEMENT_EXECUTE (sp_execute)
prepare STATEMENT_PREPARE + STATEMENT_EXECUTE STATEMENT_EXECUTE STATEMENT_EXECUTE
none STATEMENT_EXECUTE (直接 SQL) STATEMENT_EXECUTE (直接 SQL) STATEMENT_EXECUTE (直接 SQL)

既定の prepexec 設定では、ドライバーは 1 回の使用を想定して準備を延期します。 2 番目の実行では、 sp_prepexec (準備と実行の組み合わせ) が使用されます。 3 回目以降、キャッシュされたハンドルは sp_execute経由で再利用されます。 最初の呼び出しで強制的に sp_prepexec するには、接続プロパティの enablePrepareOnFirstPreparedStatementCalltrue に設定します。

ログ出力のサンプル

次の出力は、既定のPreparedStatement設定を使用して、prepexecの 3 回連続して実行されたアクティビティを示しています。

ConnectionID:1, StatementID:1 Request build time, duration: 8ms
ConnectionID:1, StatementID:1 First server response, duration: 17ms
ConnectionID:1, StatementID:1 Statement execute, duration: 75ms        ← 1st call: sp_executesql
ConnectionID:1, StatementID:1 Request build time, duration: 9ms
ConnectionID:1, StatementID:1 First server response, duration: 0ms
ConnectionID:1, StatementID:1 Statement prepexec, duration: 0ms        ← 2nd call: sp_prepexec
ConnectionID:1, StatementID:1 Request build time, duration: 0ms
ConnectionID:1, StatementID:1 First server response, duration: 0ms
ConnectionID:1, StatementID:1 Statement execute, duration: 0ms         ← 3rd call: sp_execute