Debug Java HikariCP Pool for JDBC SQL with Logback

In this article, we will explain how to use and debug HikariCP Pool for JDBC SQL with Logback. The goal is to be able to monitor how many connections are opened / closed by the connection pool. We will do a multi-thread load test of SQL requests on the pool, and see how it reacts.

1) The dependencies for HikariCP Pool and Logback

In your pom.xml, add:

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.3</version>
</dependency>
<dependency>
    <groupId>com.zaxxer</groupId>
    <artifactId>HikariCP</artifactId>
    <version>3.4.1</version>
</dependency>

2) Build the Hikari DataSource object

Replace the following variables with your own values:

String jdbcUrl = "jdbc:postgresql://localhost:49156/database";
String username = "user";
String password = "password";
String driver = "org.postgresql.Driver";

Then, to build the Hikari DataSource, do:

HikariConfig hikaConfig = new HikariConfig();
hikaConfig.setJdbcUrl(jdbcUrl);
hikaConfig.setUsername(username);
hikaConfig.setPassword(password);
hikaConfig.setDriverClassName(driver);
hikaConfig.setPoolName("HikariPool-1");
hikaConfig.setMinimumIdle(2);
hikaConfig.setMaximumPoolSize(7);   hikaConfig.setConnectionTimeout(Duration.ofSeconds(30).toMillis());

HikariDataSource dataSource = new HikariDataSource(hikaConfig);

Now, to obtain a SQL connection through the HikariCP Pool, simply do:

java.sql.Connection conn = dataSource.getConnection()

3) Run multi-threaded SQL queries on the HikariCP Pool

We will run 500 parallel SQL select queries through the pool, using 30 parallel threads. We want to see how the HikariCP Pool reacts, and how many connections it will open. To do this, we use an ExecutorService, to which we submit multiple Callable. We then obtain a list of Future. They represent asynchronous computations in Java. Then we will wait for all of them to finish, by calling Future.get():

ExecutorService executorService = null;
try {
    executorService = Executors.newFixedThreadPool(30);

    Callable<Void> callable = () -> {
        try (Connection c = dataSource.getConnection()) {
            try (Statement stmt = c.createStatement()) {
                ResultSet rs = stmt.executeQuery("select * from customer");
                while (rs.next()) {
                    // do nothing here, just iterate over the ResultSet
                }
            }
        }
        return null;
    };

    List<Future<Void>> futures = new ArrayList<>();
    for (int i = 0; i < 500; i++)
        futures.add(executorService.submit(callable));                      

    for (Future<Void> f : futures)
        f.get();

} finally {
    if (executorService != null)
        executorService.shutdown();
}

4) Setup Logback to display HikariCP DEBUG logs

Right now, we only see INFO logs in the console, and we don’t see the HikariCP information about connections, because they have a DEBUG level.

To setup Logback, add a new file called logback.xml in the folder src/main/resources of your Java project. Write the following content in the file logback.xml:

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="warn">
        <appender-ref ref="STDOUT"/>
    </root>

    <logger name="com.zaxxer.hikari" level="debug"/>
</configuration>

The most important part of the file is:

<logger name="com.zaxxer.hikari" level="debug"/>

This is where we tell Logback to log all logs from the package com.zaxxer.hikari.* with a DEBUG level.

5) Analyze the results

When running the code in part 4), we get the following Logback DEBUG logs in the console:

00:37:56.871 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@1b918d9

This log happens every time the Hikari Pool opens an additional connection (when all the connections it opened before are busy). If we count all the occurrences of the above log, it should match the max pool size value that we set in part 2):

hikaConfig.setMaximumPoolSize(7)

6) Full working Java code

Here is a fully running Java code, that starts a PostgreSQL container, runs the multi-threaded SQL select queries from above, and captures the console logs to count how many connections were opened by the HikariCP Pool:

Thank you for reading ! If you have questions, please leave a reply below, we reply within 24h.