A few days ago, our customer encountered connectivity issues while using HikariCP in their Java application. To troubleshoot the problem, we enabled detailed logging for the Microsoft JDBC Driver for SQL Server. This logging gave me a lot of information and details, following I would like to share my lessons learned here.

To capture detailed logs, we configured the Java logging framework to record the operations of the JDBC driver at a fine-grained level. 

To enable the logging I included these instrucctions in the code:

import java.util.logging.*;

public static void main(String[] args) throws Exception{
Logger globalLogger1 = Logger.getLogger(Logger.GLOBAL_LOGGER_NAME);
globalLogger1.setLevel(Level.FINE);
Logger rootLogger1 = Logger.getLogger(“”);
rootLogger1.setLevel(Level.FINE); // Set the root logger level
// Create a custom formatter
Formatter customFormatter = new Formatter() {
@Override
public String format(LogRecord record) {
return String.format(“[%1$tF %1$tT] [%2$s] %3$s %n”,
record.getMillis(),
record.getLevel().getName(),
record.getMessage());
}
};
// Remove all existing handlers

// Create a new console handler
ConsoleHandler consoleHandler = new ConsoleHandler();
consoleHandler.setLevel(Level.FINE); // Set the level for console handler
consoleHandler.setFormatter(customFormatter);
//consoleHandler.setFormatter(new SimpleFormatter()); // Set the formatter

// Add the new handler to the root logger
rootLogger1.addHandler(consoleHandler);

// Set specific log levels for SQL Server JDBC driver
Logger sqlLogger = Logger.getLogger(“com.microsoft.sqlserver.jdbc”);
sqlLogger.setLevel(Level.FINE);
Logger sqlDataSourceLogger = Logger.getLogger(“com.microsoft.sqlserver.jdbc.SQLServerDataSource”);
sqlDataSourceLogger.setLevel(Level.FINE);
}

Basically, after enabling this information we could see the following details (as an example):

ConnectionID.
Redirection (depending on connection policy).
Login Timeout. 

[2024-06-18 10:27:21] [FINE] ConnectionID:1 created by (SQLServerDataSource:1)
[2024-06-18 10:27:21] [FINE] ConnectionID:1 This attempt server name: servername.database.windows.net port: 1433 InstanceName: null useParallel: false
[2024-06-18 10:27:21] [FINE] ConnectionID:1 This attempt endtime: 1718699261215
[2024-06-18 10:27:21] [FINE] ConnectionID:1 This attempt No: 0
[2024-06-18 10:27:21] [FINE] ConnectionID:1 Connecting with server: servername.database.windows.net port: 1433 Timeout slice: 19934 Timeout Full: 20
[2024-06-18 10:27:21] [FINE] ConnectionID:1 ClientConnectionId: 80f77dcf-5d20-47bc-be53-025868ac76e6 Server returned major version:12
[2024-06-18 10:27:22] [FINE] ConnectionID:1 This attempt server name: aabeaXXX.trXXXX.northeurope1-a.worker.database.windows.net port: 11002 InstanceName: null useParallel: false
[2024-06-18 10:27:22] [FINE] ConnectionID:1 This attempt endtime: 1718699261215
[2024-06-18 10:27:22] [FINE] ConnectionID:1 This attempt No: 1
[2024-06-18 10:27:22] [FINE] ConnectionID:1 Connecting with server: aabeaXXX.trXXXX.northeurope1-a.worker.database.windows.net port: 11002 Timeout slice: 19074 Timeout Full: 20
[2024-06-18 10:27:22] [FINE] ConnectionID:1 ClientConnectionId: 0bb41f4c-dcac-4a32-9e04-8f9395055527 Server returned major version:12
[2024-06-18 10:27:22] [FINE] SQLServerStatement:1 created by (ConnectionID:1 ClientConnectionId: 0bb41f4c-dcac-4a32-9e04-8f9395055527)
[2024-06-18 10:27:22] [FINE] SQLServerStatement:1 Executing (not server cursor) select 1
[2024-06-18 10:27:23] [FINE] SQLServerResultSet:1 created by (SQLServerStatement:1)
[2024-06-18 10:27:23] [FINE] SQLServerStatement:2 created by (ConnectionID:1 ClientConnectionId: 0bb41f4c-dcac-4a32-9e04-8f9395055527)
[2024-06-18 10:27:23] [FINE] SQLServerStatement:2 Executing (not server cursor) SELECT 1
[2024-06-18 10:27:23] [FINE] ConnectionID:2 created by (SQLServerDataSource:1)
[2024-06-18 10:27:23] [FINE] sp_executesql SQL: SELECT 1 AS ID: calling sp_executesql: SQL:SELECT 1 AS ID
[2024-06-18 10:27:23] [FINE] ConnectionID:2 ClientConnectionId: 3161a9ac-f8f4-4eab-bf80-999f48859d26 Server returned major version:12
[2024-06-18 10:27:23] [FINE] SQLServerResultSet:3 created by (sp_executesql SQL: SELECT 1 AS ID)

​Microsoft Tech Community – Latest Blogs –Read More