brettwooldridge / HikariCP

光 HikariCP・A solid, high-performance, JDBC connection pool at last.
Apache License 2.0
20.01k stars 2.93k forks source link

Fill the connection pool with only one connection, not maximum-pool-size. #2013

Open ghkvud2 opened 1 year ago

ghkvud2 commented 1 year ago

Hello, I am having a hard time using Hikaricp, so I ask for help. In certain situations, there is a problem that the hikari pool is not filled with connections as much as the maximum-pool-size, and only exactly one connection is filled.

[Development environment]

  1. springboot 2.6.9
  2. oracle 19c (and ojdbc10)
  3. springboot mybatis

Here's the Hikari setup log.

[2022-10-06 18:46:00.724] [DEBUG] [main] [HikariConfig             ]- HikariPool-1 - configuration:
[2022-10-06 18:46:00.730] [DEBUG] [main] [HikariConfig             ]- allowPoolSuspension................................false
[2022-10-06 18:46:00.730] [DEBUG] [main] [HikariConfig             ]- autoCommit................................true
[2022-10-06 18:46:00.730] [DEBUG] [main] [HikariConfig             ]- catalog................................none
[2022-10-06 18:46:00.730] [DEBUG] [main] [HikariConfig             ]- connectionInitSql................................none
[2022-10-06 18:46:00.731] [DEBUG] [main] [HikariConfig             ]- connectionTestQuery................................none
[2022-10-06 18:46:00.731] [DEBUG] [main] [HikariConfig             ]- connectionTimeout................................30000
[2022-10-06 18:46:00.731] [DEBUG] [main] [HikariConfig             ]- dataSource................................none
[2022-10-06 18:46:00.732] [DEBUG] [main] [HikariConfig             ]- dataSourceClassName................................none
[2022-10-06 18:46:00.732] [DEBUG] [main] [HikariConfig             ]- dataSourceJNDI................................none
[2022-10-06 18:46:00.734] [DEBUG] [main] [HikariConfig             ]- dataSourceProperties................................{password=<masked>}
[2022-10-06 18:46:00.734] [DEBUG] [main] [HikariConfig             ]- driverClassName................................"oracle.jdbc.OracleDriver"
[2022-10-06 18:46:00.734] [DEBUG] [main] [HikariConfig             ]- exceptionOverrideClassName................................none
[2022-10-06 18:46:00.734] [DEBUG] [main] [HikariConfig             ]- healthCheckProperties................................{}
[2022-10-06 18:46:00.734] [DEBUG] [main] [HikariConfig             ]- healthCheckRegistry................................none
[2022-10-06 18:46:00.735] [DEBUG] [main] [HikariConfig             ]- idleTimeout................................600000
[2022-10-06 18:46:00.735] [DEBUG] [main] [HikariConfig             ]- initializationFailTimeout................................1
[2022-10-06 18:46:00.735] [DEBUG] [main] [HikariConfig             ]- isolateInternalQueries................................false
[2022-10-06 18:46:00.735] [DEBUG] [main] [HikariConfig             ]- jdbcUrl................................[Cleared for security reasons.]
[2022-10-06 18:46:00.736] [DEBUG] [main] [HikariConfig             ]- keepaliveTime................................0
[2022-10-06 18:46:00.736] [DEBUG] [main] [HikariConfig             ]- leakDetectionThreshold................................2000
[2022-10-06 18:46:00.736] [DEBUG] [main] [HikariConfig             ]- maxLifetime................................1800000
[2022-10-06 18:46:00.736] [DEBUG] [main] [HikariConfig             ]- maximumPoolSize................................3
[2022-10-06 18:46:00.737] [DEBUG] [main] [HikariConfig             ]- metricRegistry................................none
[2022-10-06 18:46:00.737] [DEBUG] [main] [HikariConfig             ]- metricsTrackerFactory................................none
[2022-10-06 18:46:00.737] [DEBUG] [main] [HikariConfig             ]- minimumIdle................................3
[2022-10-06 18:46:00.737] [DEBUG] [main] [HikariConfig             ]- password................................<masked>
[2022-10-06 18:46:00.737] [DEBUG] [main] [HikariConfig             ]- poolName................................"HikariPool-1"
[2022-10-06 18:46:00.738] [DEBUG] [main] [HikariConfig             ]- readOnly................................false
[2022-10-06 18:46:00.738] [DEBUG] [main] [HikariConfig             ]- registerMbeans................................false
[2022-10-06 18:46:00.738] [DEBUG] [main] [HikariConfig             ]- scheduledExecutor................................none
[2022-10-06 18:46:00.738] [DEBUG] [main] [HikariConfig             ]- schema................................none
[2022-10-06 18:46:00.739] [DEBUG] [main] [HikariConfig             ]- threadFactory................................internal
[2022-10-06 18:46:00.739] [DEBUG] [main] [HikariConfig             ]- transactionIsolation................................default
[2022-10-06 18:46:00.739] [DEBUG] [main] [HikariConfig             ]- username................................[Cleared for security reasons.]
[2022-10-06 18:46:00.739] [DEBUG] [main] [HikariConfig             ]- validationTimeout................................5000
[2022-10-06 18:46:00.739] [INFO ] [main] [HikariDataSource         ]- HikariPool-1 - Starting...
[2022-10-06 18:46:02.249] [DEBUG] [main] [HikariPool               ]- HikariPool-1 - Added connection oracle.jdbc.driver.T4CConnection@1fc684e
[2022-10-06 18:46:02.252] [INFO ] [main] [HikariDataSource         ]- HikariPool-1 - Start completed.

Strangely, if the setting value is changed as shown below, the connection is normally filled by the maximum-pool-size.

  1. logging level is [com.zaxxer.hikari] : debug or
  2. initializationFailTimeout : -1

At first, I thought it was a communication problem between the application and the DB, but I don't think it's a network problem when I see one connection connected. And it's really weird that changing the settings above doesn't cause any problems.

And other processes running on the same server are using the connection without any problems. (Of course, the development language and framework are different.)

Can you tell me what else I need to look at?

dingyo777 commented 1 year ago

I also have same issue. I set maximumPoolSize to 10 only, so minimumIdle is also 10.

I expected it would be 10 connections after I create datasource, but actually there is only one connection.

I checked my MySQL db server and also confirmed that there is only single additional connection.

Why it doesn't work as manual?

May I miss something? please let me know

ghkvud2 commented 1 year ago

I don't know why, but when I set the log level to debug, it worked Give that a try.

dingyo777 commented 1 year ago

Ah, finally I confirmed that it had worked as expected.

It was because of my mistaken debugging timing.

ghkvud2 commented 1 year ago

Does it mean that the logging level of HIKARI is changed to debug and it works as expected? It works well if I set the log level to debug...That's a little weird. I don't understand that the number of connections is affected by the log level. Can you explain your situation in more detail? 이상한 상황이네요...

dingyo777 commented 1 year ago

Oh, actually it worked with info level. BTW, you're Korean, too. Nice to meet you ;)

How did you check the open connection count, though?

I checked on DB server side(MySQL) with the command

mysql> show status where `variable_name` = 'Threads_connected';

This command shows opened connections count.

So..

After creating hikariCP datasource with maxPoolSize = 5, then I Thread.sleep a few seconds while checking connection count on DB side.

In this way, I confirmed that it opened 5 connections as expected.

Below is code snippet.

    @Test
    public void test() throws SQLException, InterruptedException {
        HikariDataSource ds = getDatasource();
        Thread.sleep(5000);
        ds.close();
    }

    private HikariDataSource getDatasource() {
        HikariConfig config = new HikariConfig();
        config.setJdbcUrl("jdbc:mysql://localhost:3306/exampledb?createDatabaseIfNotExist=true&useUnicode=true&useJDBCCompliantTimezoneShift=true&useLegacyDatetimeCode=false&serverTimezone=Asia/Jakarta&useSSL=false");
        config.setUsername("root");
        config.setMaximumPoolSize(5);
        return new HikariDataSource(config);
    }
ghkvud2 commented 1 year ago

Nice to meet you, too.

In my case, I really can't connect as much as the maximum PoolSize.

I'm using Oracle, and I've made sure that there's only exactly one session right after running the application. So when two connections are required in one service logic cycle (there is a logic running with the requried_new option of Spring @transactional), a connection timeout occurs.

As I wrote in the text...It is ridiculous that if the logging level of the hikari package is set to debug, the connection is as good as maximumPoolSize.