Protokolovací a zpětná volání výkonu

Stáhnout ovladač JDBC

Od verze 13.4 poskytuje ovladač Microsoft JDBC pro SQL Server architekturu metrik výkonu pro sledování načasování důležitých operací ovladačů. Pomocí této architektury můžete sledovat a analyzovat chování při provádění připojení a příkazů, což pomáhá identifikovat kritické body latence při interakcích vaší aplikace s SQL Serverem.

Metriky jsou dostupné prostřednictvím dvou mechanismů, které je možné používat nezávisle nebo společně:

  • Programové zpětné volání – Zaregistrujte PerformanceLogCallback, abyste přijímali metriky v kódu aplikace.
  • Protokolování v Javě – Přihlaste se k odběru vyhrazených java.util.logging protokolovacích protokolů, abyste zachytili metriky ve výstupu protokolu.

Sledované aktivity

Ovladač sleduje aktivity na dvou úrovních: připojení a dotaz.

Aktivity na úrovni připojení

Activity Description
CONNECTION Celkový čas vytvoření připojení, včetně všech dílčích aktivit.
PRELOGIN Doba vyjednávání preloginu TDS se serverem
LOGIN Čas pro přihlášení TDS a ověřování metodou handshake
TOKEN_ACQUISITION Doba získání federovaných ověřovacích tokenů při použití ověřování Microsoft Entra

Aktivity na úrovni příkazů

Activity Description
STATEMENT_REQUEST_BUILD Čas na straně klienta pro sestavení požadavku TDS (vazby parametrů, zpracování SQL, konstrukce paketů). Pouze časování; nesleduje výjimky.
STATEMENT_FIRST_SERVER_RESPONSE Čas od odeslání požadavku na přijetí první odpovědi serveru Pouze časování; nesleduje výjimky.
STATEMENT_PREPARE Čas pro sp_prepare, když prepareMethod=prepare.
STATEMENT_PREPEXEC Doba pro kombinovanou přípravu a provedení prostřednictvím sp_prepexec.
STATEMENT_EXECUTE Doba provádění SQL dotazů (sp_executesql, přímé SQL sp_execute nebo dávková úloha).

Povolení metrik výkonu

Možnost 1: Registrace zpětného volání

Zaregistrujte PerformanceLogCallback pro přijímání dat o výkonu programově:

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

Použijte nanosekundové časování a kontext výroku

Od verze 13.6 může callback zvolit nanosekundové časování přepsáním useNanoseconds(). Zpětné volání může také volat getCurrentUserSql() a getCurrentStatementType() za účelem korelace události na úrovni příkazu s textem SQL odeslaným aplikací a s typem příkazu, který byl proveden. getCurrentStatementType() vrací STATEMENT, PREPARED_STATEMENT, nebo CALLABLE_STATEMENT. Použijte getCurrentApplicationName() k identifikaci připojení nebo fondu připojení, které událost vyvolalo, pomocí jeho vlastnosti připojení applicationName. Pokud applicationName není nastaveno, metoda vrátí výchozí název aplikace ovladače.

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

Nanosekundové časování je dobrovolné. Zpětná volání, která nepřetěžují useNanoseconds(), nadále přijímají doby trvání v milisekundách. Pokud se registrované zpětné volání aktivuje, výstup vyhrazeného protokolovače výkonu také používá nanosekundy a doby trvání označuje pomocí ns; jinak používá milisekundy a ms. Volání System.nanoTime() může mít na některých platformách vyšší režii než System.currentTimeMillis().

Kontext zpětného volání je dostupný pouze během odpovídajícího publish() volání. getCurrentApplicationName() je dostupný pro události na úrovni spojení a příkazů a vrací se null mimo publish(). Může se také vrátit null , když vlastnosti spojení nebyly parsovány, například když spojení selže před vyřešením názvu aplikace. Metody kontextu SQL vracejí null pro události na úrovni připojení, metriky dílčích aktivit příkazů, které nemají kontext SQL, a volání provedená mimo publish().

Caution

SQL text může obsahovat citlivá data v literálech nebo komentářích. Vyčistěte ho a aplikujte požadavky vaší organizace na zpracování dat, než ho zapíšete do logů nebo telemetrie.

Možnost 2: Konfigurace protokolování Java

Nakonfigurujte java.util.logging zapisovače metrik výkonu na úrovni FINE.

logging.properties V souboru:

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

Nebo programově:

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

Příprava účinku metody na aktivity příkazů

Sledované aktivity PreparedStatement závisí na vlastnosti připojení prepareMethod. Pro více informací o prepareMethod viz Nastavení vlastností připojení.

prepareMethod nastavení První spuštění Druhé spuštění Třetí+ spuštění
prepexec (výchozí) STATEMENT_EXECUTE (sp_executesql) STATEMENT_PREPEXEC (sp_prepexec) STATEMENT_EXECUTE (sp_execute)
prepare STATEMENT_PREPARE + STATEMENT_EXECUTE STATEMENT_EXECUTE STATEMENT_EXECUTE
none STATEMENT_EXECUTE (přímý přístup přes SQL) STATEMENT_EXECUTE (přímý přístup přes SQL) STATEMENT_EXECUTE (přímý přístup přes SQL)

Poznámka:

Při výchozím prepexec nastavení ovladač odkládá přípravu za předpokladu jednorázového použití. Druhé provedení používá sp_prepexec (kombinovaná příprava a spuštění). Od třetího spuštění je mezipaměťový popisovač znovu použit prostřednictvím sp_execute. Chcete-li vynutit sp_prepexec při prvním volání, nastavte vlastnost připojení enablePrepareOnFirstPreparedStatementCall na hodnotu true.

Ukázkový výstup protokolu

Následující výstup ukazuje aktivity sledované během tří po sobě jdoucích spuštění PreparedStatement s výchozím nastavením 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