[입 개발] HikariCP 는 왜 나를 물먹이는가…

HikariCP는 왜 저를 물먹이는걸까요?… 정답은 제가 못나서 입니다. 흑흑흑, 오늘은 HikariCP를 사용하다가 겪는 일반적인 상황과는 전혀 상관없이 그냥 제가 겪은… 삽질을 공유하려고 합니다.

HikariCP를 아주 특이하게 사용하고 있었습니다. 그런데, 문제는 제가 자바맹이라서 HikariCP에 대한 지식이 일도 없다는 거죠. 히카리는 빛이라는 일본어라는 것만 알고 있습니다.(역시 H2!!!)

코드를 간략하게 정리하면 다음과 같은 형태로 사용하고 있었습니다. write가 가능한 DB 유저와 read가 가능한 DB 유저로 구분해서 사용하고 있었습니다. 아래와 같은 구조는 지양하셔야 합니다. 몰랐던거라…

    val dbConf = new HikariConfig()
    dbConf.setUsername(writeUser)
    dbConf.setPassword(writeUserPass)
    dbConf.addDataSourceProperty("user", readUser)
    dbConf.addDataSourceProperty("password", readUserPass)

그래서 read만 필요한 경우에 다음과 같이 DataSourceProperties를 넘겨서 readUser로 사용하는 케이스 였습니다.

dbConf.getDataSourceProperties

이것 자체가 올바른 사용방법은 아닌데, 이 방법을 혹시나 쓰신다면 HikariCP 3.2.0 이상에서부터만 가능합니다.

그런데 이상하긴 하지만, 이렇게 아주 잘 사용하고 있었습니다. 그런데 갑자기 다른 플랫폼으로 이전을 했더니, 기존에 잘 쓰던 writeUser 대신에 readUser로 접속을 하면서, 기존에 사용하던 것들이 모두 실패하기 시작했습니다.

일단 다음과 같은 형태로 움직이기 시작했습니다.

  1. 각 DB 계정의 권한이 명확한지 확인!
  2. 특정 버전 사이의 코드 변경 확인
  3. 각 플랫폼의 Library 버전 확인

각 DB의 계정은 명확했습니다. 메뉴얼 한 테스트 및, show grants for ‘writeUser’ 를 해봐도 명확하게 기 설정된 정보가 그대로 존재했었습니다. 특정 버전 사이의 코드도 전과 바뀐 것이 없는 것을 확인하자. 이제 생각은 아 HikariCP의 버전이 다르겠구나라는 생각이 들었습니다.

생각이 거기까지 들자, 버전을 확인해보니, 제가 쓰던 버전은 3.4.2 였고, 새로운 플랫폼의 버전은 3.1.0이었습니다. 그런데, 자바맹이다 보니 이걸 당장 분석할 시간은 없고, 일단은 뭔가 꽁수로 처리를 하고, 해당 건은 나중에 자세히 알아봐야지 할려고 하다가… 좀 시간이 나서 HikariCP를 보기 시작했습니다. 사실 3.1.0 -> 3.4.2 사이에 엄청 큰 변화는 제가 본 코드에는 없었습니다.(사실, README도 안보고, 그냥 쭈루룩 넘어간…)

그런데 그러면 왜 이런 문제가 생긴것일까요? 이걸 제대로 이해하기 위해서는 일단 간단히 이 부분에 대한 HikariCP의 구조를 알아야 합니다. 위의 소스에서 보듯이 configuration을 저장하고 있는 것은 HikariConfig 입니다. 그리고 다음과 같이 DataSource를 만들어서 사용하고 있습니다.

val dbConf = HikariConfig()
val ds = new HikariDataSource(dbConf)

그리고 필요한 connection 은 다음과 같이 DataSource 의 getConnection()을 호출합니다.

val connection = ds.getConnection()

그럼 이제 실제 DataSource의 getConnection 이 어떻게 동작하는지 살펴보도록 하겠습니다. 우리가 볼 것은 HikariDataSource인걸 그 위의 소스에서 알 수 있습니다. 그런데 HikariDataSource의 getConnection 은 아주 복잡합니다.(제 기준에서요.)

   @Override
   public Connection getConnection() throws SQLException
   {
      if (isClosed()) {
         throw new SQLException("HikariDataSource " + this + " has been closed.");
      }

      if (fastPathPool != null) {
         return fastPathPool.getConnection();
      }

      // See http://en.wikipedia.org/wiki/Double-checked_locking#Usage_in_Java
      HikariPool result = pool;
      if (result == null) {
         synchronized (this) {
            result = pool;
            if (result == null) {
               validate();
               LOGGER.info("{} - Starting...", getPoolName());
               try {
                  pool = result = new HikariPool(this);
                  this.seal();
               }
               catch (PoolInitializationException pie) {
                  if (pie.getCause() instanceof SQLException) {
                     throw (SQLException) pie.getCause();
                  }
                  else {
                     throw pie;
                  }
               }
               LOGGER.info("{} - Start completed.", getPoolName());
            }
         }
      }

      return result.getConnection();
   }

히카리한 코드입니다. 자세한 내용은 모르겠고, 일단 pool 이 없으면 pool을 생성합니다. new HikariPool(this) 이라는 코드가 보이네요. 그런데 요 생성자를 따라가보면, 많은 것을 하고 있습니다. 일단 생성자를 따라가기 전에 먼저 HikariPool의 구조를 보시면 PoolBase 라는 것을 상속 받고 있습니다. 나머지는 일단 패스~~~~(모르는건, 아는척 넘어갑시다.)

public final class HikariPool extends PoolBase implements HikariPoolMXBean, IBagStateListener {
}

그리고 실제 HikariPool의 생성자를 살펴봅니다. 중요한 부분이 많지만 과감하게 날려버립니다.

public HikariPool(final HikariConfig config)
   {
      super(config);

      this.connectionBag = new ConcurrentBag<>(this);
      this.suspendResumeLock = config.isAllowPoolSuspension() ? new SuspendResumeLock() : SuspendResumeLock.FAUX_LOCK;

      this.houseKeepingExecutorService = initializeHouseKeepingExecutorService();

      checkFailFast();

      ......
   }

이제 checkFailFast() 라는 함수가 보입니다. 여기서 보시면 PoolEntry를 createPoolEntry()라는 함수로 생성하고, 성공하면, connectionBag에 넣어주고 끝입니다.

private void checkFailFast()
   {
      final long initializationTimeout = config.getInitializationFailTimeout();
      if (initializationTimeout < 0) {
         return;
      }

      final long startTime = currentTime();
      do {
         final PoolEntry poolEntry = createPoolEntry();
         if (poolEntry != null) {
            if (config.getMinimumIdle() > 0) {
               connectionBag.add(poolEntry);
               logger.debug("{} - Added connection {}", poolName, poolEntry.connection);
            }
            else {
               quietlyCloseConnection(poolEntry.close(), "(initialization check complete and minimumIdle is zero)");
            }

            return;
         }

         if (getLastConnectionFailure() instanceof ConnectionSetupException) {
            throwPoolInitializationException(getLastConnectionFailure().getCause());
         }

         quietlySleep(SECONDS.toMillis(1));
      } while (elapsedMillis(startTime) < initializationTimeout);

      if (initializationTimeout > 0) {
         throwPoolInitializationException(getLastConnectionFailure());
      }
   }

이 뒤에서 뭔가 동작이 일어나면 복잡하겠지만, 일단 createPoolEntry() 함수를 봅니다. 전에 절 괴롭혔던(전, 항상 괴롭힘을 당합니다. MaxLifeTime 값을 이용하는 것이 보이지만, 우리의 관심은 그쪽은 아닙니다.

   private PoolEntry createPoolEntry()
   {
      try {
         final PoolEntry poolEntry = newPoolEntry();

         final long maxLifetime = config.getMaxLifetime();
         if (maxLifetime > 0) {
            // variance up to 2.5% of the maxlifetime
            final long variance = maxLifetime > 10_000 ? ThreadLocalRandom.current().nextLong( maxLifetime / 40 ) : 0;
            final long lifetime = maxLifetime - variance;
            poolEntry.setFutureEol(houseKeepingExecutorService.schedule(
               () -> {
                  if (softEvictConnection(poolEntry, "(connection has passed maxLifetime)", false /* not owner */)) {
                     addBagItem(connectionBag.getWaitingThreadCount());
                  }
               },
               lifetime, MILLISECONDS));
         }

         return poolEntry;
      }
      catch (ConnectionSetupException e) {
         if (poolState == POOL_NORMAL) { // we check POOL_NORMAL to avoid a flood of messages if shutdown() is running concurrently
            logger.error("{} - Error thrown while acquiring connection from data source", poolName, e.getCause());
            lastConnectionFailure.set(e);
         }
      }
      catch (Exception e) {
         if (poolState == POOL_NORMAL) { // we check POOL_NORMAL to avoid a flood of messages if shutdown() is running concurrently
            logger.debug("{} - Cannot acquire connection from data source", poolName, e);
         }
      }

      return null;
   }

다시 newPoolEntry() 함수를 따라갑니다. 좀 딥하게 내려가지만, 일차선 도로입니다. 빠질 곳이 없지요.

   PoolEntry newPoolEntry() throws Exception
   {
      return new PoolEntry(newConnection(), this, isReadOnly, isAutoCommit);
   }

newPoolEntry는 쉽습니다. newConnection()만 보면 되겠네요. newConnection() 함수에서는 밑에 connection 부분만 보시면 됩니다. username 과 password를 config(HikariConfig 입니다.) 에서 가져와서, username == null 이면, dataSource의 getConnection() 을 없으면 dataSource의 getConnection(username, password)를 호출합니다.

   private Connection newConnection() throws Exception
   {
      final long start = currentTime();

      Connection connection = null;
      try {
         String username = config.getUsername();
         String password = config.getPassword();

         connection = (username == null) ? dataSource.getConnection() : dataSource.getConnection(username, password);
         if (connection == null) {
            throw new SQLTransientConnectionException("DataSource returned null unexpectedly");
         }

         setupConnection(connection);
         lastConnectionFailure.set(null);
         return connection;
      }
      catch (Exception e) {
         if (connection != null) {
            quietlyCloseConnection(connection, "(Failed to create/setup connection)");
         }
         else if (getLastConnectionFailure() == null) {
            logger.debug("{} - Failed to create/setup connection: {}", poolName, e.getMessage());
         }

         lastConnectionFailure.set(e);
         throw e;
      }
      finally {
         // tracker will be null during failFast check
         if (metricsTracker != null) {
            metricsTracker.recordConnectionCreated(elapsedMillis(start));
         }
      }
   }

그럼 이 dataSource는 어디서 온 것일까요? 정체는 무엇일까요? 그걸 확인할려면 아까 HikariPool의 생성자에 있던 super(config); 구문을 따라가야 합니다. HikariPool은 뭘 상속 받았죠? 네! 그렇습니다. PoolBase 로 가봅시다.(그런데 사실 아까 newPoolEntry 부터 이미 PoolBase 였다는 사실은 안 비밀입니다.)

PoolBase(final HikariConfig config)
   {
      this.config = config;

      ......
      initializeDataSource();
   }

PoolBase의 생성자는 크게 딴게 없이 HikariConfig을 config으로 저장하고 initializeDataSource()를 호출하게 됩니다. 이 함수가 재미있는데, driverClass가 설정되었는지 jdbcUrl이 설정되었는지에 따라서 다르게 동작하는데. 일단 처음에는 DataSource가 내부적으로 없기 때문에 생성해야 합니다.

   private void initializeDataSource()
   {
      final String jdbcUrl = config.getJdbcUrl();
      final String username = config.getUsername();
      final String password = config.getPassword();
      final String dsClassName = config.getDataSourceClassName();
      final String driverClassName = config.getDriverClassName();
      final String dataSourceJNDI = config.getDataSourceJNDI();
      final Properties dataSourceProperties = config.getDataSourceProperties();

      DataSource ds = config.getDataSource();
      if (dsClassName != null && ds == null) {
         ds = createInstance(dsClassName, DataSource.class);
         PropertyElf.setTargetFromProperties(ds, dataSourceProperties);
      }
      else if (jdbcUrl != null && ds == null) {
         ds = new DriverDataSource(jdbcUrl, driverClassName, dataSourceProperties, username, password);
      }
      else if (dataSourceJNDI != null && ds == null) {
         try {
            InitialContext ic = new InitialContext();
            ds = (DataSource) ic.lookup(dataSourceJNDI);
         } catch (NamingException e) {
            throw new PoolInitializationException(e);
         }
      }

      if (ds != null) {
         setLoginTimeout(ds);
         createNetworkTimeoutExecutor(ds, dsClassName, jdbcUrl);
      }

      this.dataSource = ds;
   }

ds를 생성하는 DriverDataSource 부분을 확인해 봅시다. 파라매터로 config 의 username 과 password가 넘어갑니다.

   public DriverDataSource(String jdbcUrl, String driverClassName, Properties properties, String username, String password)
   {
      this.jdbcUrl = jdbcUrl;
      this.driverProperties = new Properties();

      for (Entry<Object, Object> entry : properties.entrySet()) {
         driverProperties.setProperty(entry.getKey().toString(), entry.getValue().toString());
      }

      if (username != null) {
         driverProperties.put(USER, driverProperties.getProperty("user", username));
      }
      if (password != null) {
         driverProperties.put(PASSWORD, driverProperties.getProperty("password", password));
      }

      ......
   }

중요하지 않은 부분을 다 날리고 보면, 저는 처음에 버그인줄 알았는데, username, password가 null 이 아닐 때, properties 에 “user”, 와 “password”가 있다면, 가지고 있는 username, password를 디폴트 값으로 셋팅합니다. 즉 property에 “user”, “password”가 설정되어 있다면, 이걸 무조건 우선적으로 쓰게 됩니다. 네네, 즉 둘 다 셋팅이 되면, 여기서 driverProperties는 값을 덮어씌우게 됩니다. 올레!!!, 그렇지 이 부분입니다!!! 라고 말하고 싶지만… 이 코드는 3.1.0 도 동일합니다. 원래 코드를 한번 다시 살펴보시죠.

    val dbConf = new HikariConfig()
    dbConf.setUsername(writeUser)
    dbConf.setPassword(writeUserPass)
    dbConf.addDataSourceProperty("user", readUser)
    dbConf.addDataSourceProperty("password", readUserPass)

그렇습니다. 우리의 코드는 처음부터 둘 다 쓰고 있었습니다. 그런데 위의 부분을 보면… 무조건 readUser, readUserPass 가 writeUser, writeUserPass로 설정된 값을 덮어써야만 합니다. 즉, 이전에도 동작을 안해야 정상이라는 겁니다. 여기서 사실 1차 좌절을 하게 됩니다. “왜 안되지!!!” 보다 더 무서운 “왜 되지!!!” 만나게 된겁니다. 저도 멘붕에 다시 한번 빠집니다.

그런데 여기서 아까 살짝 놓치고 지나간 부분이 생각났습니다. 아마도 여러분들은 다 맞추셨을꺼 같습니다. 전 초초초초초초초보 개발자라 T.T

혹시 아까 newConnection() 함수가 기억나시나요? 다시 가져오면 아래와 같습니다. 실제로 driverProperties가 설정되는 것은 위와 같지만… 우리가 사용하는 것은 아래 함수입니다.

connection = (username == null) ? dataSource.getConnection() : dataSource.getConnection(username, password);

오오 이 부분이 다르지 않을까 하고 3.1.0 소스를 봤더니!!! 당연하게도!!!, 똑 같습니다.(어어어, 이게 아닌데…)

음… 음.. 음… 다시 또 2차 좌절을 하는데…

dataSource 의 getConnection 함수가 다릅니다. 덜덜덜 아까 우리가 봤던 dataSource 는 DriverDataSource 입니다.

3.4.0 – cloned Properties를 만들고 여기에 user 와 password 를 넘겨 받은 값으로 셋팅합니다. null 이면 그냥 이전값 사용.

   public Connection getConnection(final String username, final String password) throws SQLException
   {
      final Properties cloned = (Properties) driverProperties.clone();
      if (username != null) {
         cloned.put("user", username);
         if (cloned.containsKey("username")) {
            cloned.put("username", username);
         }
      }
      if (password != null) {
         cloned.put("password", password);
      }

      return driver.connect(jdbcUrl, cloned);
   }

3.1.0 – 그냥 원래의 getConnection()을 그대로 호출합니다. 이건 뭥미!!!

   public Connection getConnection(String username, String password) throws SQLException
   {
      return getConnection();
   }

실제의 getConnection() 함수는 둘다 다음과 같이 동일합니다. 아까 우리가 만든 driverProperties 를 사용하고 있습니다.

   public Connection getConnection() throws SQLException
   {
      return driver.connect(jdbcUrl, driverProperties);
   }

결론적으로, getConnection함수에서 username, password를 처리하는 부분이 바뀌었기 때문에 3.4.0 에서는 의도한 대로 둘 다 동작을 했지만, 3.1.0 에서는 제대로 동작하지 않았던 것입니다. 자세한 패치는 https://github.com/brettwooldridge/HikariCP/commit/851e2d4592b52a9c367ada2c76f013b1d4e20ac3 를 보시면 됩니다.

코드를 보면 HikariCP의 개발자는 제가 사용한 것과 같은 방법을 쓸 거라고는 생각은 안했고, 이게 맞는 방향이 아니었던 것입니다. 흑… 역시 모르면 삽질하네요 T.T