Rejestrator wydajności i wywołanie zwrotne

pobierz sterownik JDBC

Począwszy od wersji 13.4, sterownik JDBC firmy Microsoft dla programu SQL Server udostępnia metryki wydajności do śledzenia chronometrażu krytycznych operacji sterowników. Za pomocą tej ramy można obserwować i analizować zachowanie wykonywania połączeń i instrukcji, aby pomóc w identyfikacji wąskich gardeł opóźnienia w interakcjach aplikacji z SQL Server.

Metryki są dostępne za pośrednictwem dwóch mechanizmów, które mogą być używane niezależnie lub razem:

  • Programowe wywołanie zwrotne — zarejestruj element PerformanceLogCallback w celu odbierania metryk w kodzie aplikacji.
  • Logowanie w Java — subskrybuj dedykowane java.util.logging loggery, aby przechwytywać metryki w danych wyjściowych dziennika.

Śledzone działania

Sterownik śledzi działania na dwóch poziomach: połączenie i zapytanie.

Działania na poziomie połączenia

Activity Opis
CONNECTION Łączny czas nawiązywania połączenia, w tym wszystkie podaktywności.
PRELOGIN Czas na wstępne negocjacje TDS z serwerem.
LOGIN Czas na rozpoczęcie procedury logowania i uwierzytelniania TDS.
TOKEN_ACQUISITION Czas na uzyskanie tokenów uwierzytelniania federacyjnego podczas korzystania z uwierzytelniania firmy Microsoft Entra.

Działania na poziomie instrukcji

Activity Opis
STATEMENT_REQUEST_BUILD Czas po stronie klienta w celu skompilowania żądania TDS (powiązania parametrów, przetwarzania SQL, konstruowania pakietów). Wyłącznie czasowy. Nie śledzi wyjątków.
STATEMENT_FIRST_SERVER_RESPONSE Czas od wysłania żądania do otrzymania pierwszej odpowiedzi serwera. Wyłącznie czasowy. Nie śledzi wyjątków.
STATEMENT_PREPARE Czas na sp_prepare kiedy prepareMethod=prepare.
STATEMENT_PREPEXEC Czas łącznego przygotowania i wykonania za pomocą polecenia sp_prepexec.
STATEMENT_EXECUTE Czas wykonywania instrukcji (sp_executesql, sp_execute, direct SQL lub batch).

Włączanie metryk wydajności

Opcja 1: Zarejestruj wywołanie zwrotne

Zarejestruj PerformanceLogCallback aby odbierać dane wydajności programowo:

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);
    }
});

Użyj nanosekundowego czasu i kontekstu zdań

Począwszy od wersji 13.6, callback może wybrać czas nanosekundowy przez nadpisanie useNanoseconds(). Funkcja wywołania zwrotnego może również wywołać getCurrentUserSql() i getCurrentStatementType(), aby skorelować zdarzenie na poziomie instrukcji z tekstem SQL przesłanym przez aplikację oraz typem wykonanej instrukcji. getCurrentStatementType() Zwraca STATEMENT, PREPARED_STATEMENT, lub CALLABLE_STATEMENT. Użyj getCurrentApplicationName() do identyfikacji połączenia lub puli, która wywołała zdarzenie, na podstawie applicationName jego właściwości połączenia. Jeśli applicationName nie jest ustawiony, metoda zwraca domyślną nazwę aplikacji sterownika.

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);
    }
});

Pomiar czasu z dokładnością do nanosekund wymaga włączenia. Funkcje wywołania zwrotnego, które nie zastępują useNanoseconds(), nadal otrzymują wartości czasu trwania w milisekundach. Gdy zarejestrowane wywołanie zwrotne zostanie włączone, dane wyjściowe dedykowanego rejestratora wydajności również używają nanosekund i oznaczają czasy trwania za pomocą ns; w przeciwnym razie używają milisekund i ms. Dzwonienie System.nanoTime() może wiązać się z większym obciążeniem niż System.currentTimeMillis() na niektórych platformach.

Kontekst odwołania jest dostępny tylko podczas odpowiadającego wywołania publish() . getCurrentApplicationName() jest dostępny w przypadku zdarzeń na poziomie połączenia i na poziomie instrukcji oraz zwraca null poza publish(). Może również zwracać null, gdy właściwości połączenia nie zostały przeanalizowane, na przykład gdy nawiązanie połączenia zakończy się niepowodzeniem, zanim zostanie ustalona nazwa aplikacji. Metody kontekstu SQL zwracają null dla zdarzeń na poziomie połączenia, metryk subaktywności instrukcji, które nie mają kontekstu SQL, oraz wywołań wykonywanych poza publish().

Caution

Tekst SQL może zawierać wrażliwe dane w postaci literalnych lub komentarzy. Oczyścij je i zastosuj wymagania organizacji dotyczące obsługi danych, zanim zapiszesz je w logach lub telemetrii.

Opcja 2. Konfigurowanie rejestrowania języka Java

Skonfiguruj java.util.logging dla rejestratorów metryk wydajności na poziomie FINE.

W pliku 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

Lub programowo:

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

Przygotowywanie wpływu metody na działania instrukcji

Działania śledzone dla PreparedStatement zależą od właściwości połączenia prepareMethod. Aby uzyskać więcej informacji na temat prepareMethod, odwołaj się do Ustawianie właściwości połączenia.

prepareMethod ustawienie Pierwsze uruchomienie Drugie uruchomienie Wykonywanie trzecie i kolejne
prepexec (ustawienie domyślne) STATEMENT_EXECUTE (sp_executesql) STATEMENT_PREPEXEC (sp_prepexec) STATEMENT_EXECUTE (sp_execute)
prepare STATEMENT_PREPARE + STATEMENT_EXECUTE STATEMENT_EXECUTE STATEMENT_EXECUTE
none STATEMENT_EXECUTE (bezpośredni język SQL) STATEMENT_EXECUTE (bezpośredni język SQL) STATEMENT_EXECUTE (bezpośredni język SQL)

Uwaga / Notatka

Domyślne ustawienie prepexec powoduje, że sterownik odracza przygotowanie przy założeniu jednorazowego użycia. Drugie wykonanie używa sp_prepexec (przygotowanie i wykonanie w jednym). Od trzeciego wykonania dalej buforowany uchwyt jest ponownie wykorzystywany przez sp_execute. Aby wymusić sp_prepexec na pierwszym wywołaniu, ustaw właściwość połączenia enablePrepareOnFirstPreparedStatementCall na true.

Przykładowe dane wyjściowe dziennika

Następujące dane wyjściowe przedstawiają działania śledzone w trzech kolejnych wykonaniach elementu PreparedStatement z ustawieniem domyślnym prepexec :

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