이미 JDBC 커넥션 풀 관련 다양한 글들이 존재하지만 대부분 오래된 commons-dbcp 1.x 의 내용 위주라서 최근에 많이 사용되고 있는 tomcat-jdbc-pool과 hikariCP에 대한 내용을 추가로 조사하고 정리해 보았습니다. 이 글은 기본적인 commons-dbcp 1.x 에 대한 내용을 이해하고 있는 분들을 대상으로 작성되었습니다. 본문을 읽기 전에 참고 자료의 "1. Commons DBCP 이해하기"와 "2. JDBC Internal - 타임아웃의 이해"를 다시 한번 읽어 보시는 것을 추천드립니다.
Spring Boot 1.x 에서 기본으로 적용되는 tomcat-jdbc-pool의 경우는 기존의 commons-dbcp 1.x 와 비교해서 동작 방식 및 사용 방법이 유사한데 성능은 대폭 개선되어 인기를 끌었고 최근 Spring Boot 2.x 에서 기본으로 적용되는 hikariCP의 경우는 기존의 모든 커넥션 풀들을 압도하는 성능 및 네트워크 장애 상황에서도 의도된 timeout 설정이 정상 동작(참고자료 "5. Bad behavior" 참조)하여 개발자들에게 성능과 안정성 모든면에서 만족감을 주고 있다. 하지만, hikariCP의 경우 개발자의 기본적인 철학이 이전의 다른 커넥션 풀들과는 달라 옵션 설정에 주의를 필요로 한다.
- 본문의 내용은 MySQL 5.7.28, mysql-connector/j-5.1.46, tomcat-jdbc-pool-1.2, commons-dbcp-2.7.x, hikariCP-2.4.x 기준으로 작성되었다.
구체적인 문제 상황을 가정해서 각 커넥션 풀들이 어떻게 동작하는지 알아보자
MySQL을 사용하는 환경에서 익숙하게 접하게 되는 에러 메시지인 "The last packet successfully received from the server was …"가 발생하는 상황에 대해서 알아보자. 웹 개발자들이 출근해서 업무를 시작할때 개발 환경에서 보통 마주하게 되는 에러 메시지로 mysql-connector/J에서 MySQL 서버와의 통신 과정에서 문제가 발생된 상황이다. 일반적인 웹애플리케이션 운영 환경에서는 원인을 크게 아래 2가지 이유로 볼 수 있다.
1. MySQL 서버에서 끊어버린 Idle 상태의 커넥션
2. TCP socketTimeout 옵션을 Response Timout 성격으로 사용
MySQL 서버에서 끊어버린 Idle 상태의 커넥션
MySQL 서버 입장에서 JDBC 커넥션이 Idle인 상태로 wait_timeout(default 28800초) 이상 사용되지 않을 경우 해당 커넥션을 close 하여 할당된 리소스를 회수하게 된다. 이런 경우 TCP 레벨에서 해당 socket이 정리가 되더라도 JDBC 드라이버나 커넥션 풀에서는 close 여부를 바로 알 수 없고 해당 커넥션을 사용하려고 시도 할 때에서야 비로소 커넥션에 문제가 있는 것을 알게 된다. 이런 상황일 경우 최근에 성공한 통신이 XXX,XXX milliseonds 이전이라고 위와 같은 에러 메시지를 출력하게 된다.
그럼, 어떻게 하면 위와 같은 에러가 발생되지 않을 수 있을까?
서비스의 특성에 따라 다양한 wait_timeout 값이 설정되어 사용되고 있을텐데 해당 값을 크게 설정하는 것은 올바른 해결책이 아니다. Idle 상태의 커넥션들이 MySQL 서버에 의해서 close의 대상으로 판단하지 않도록 해야하는데, 방법은 사용하고 있는 커넥션 풀에 따라 다르다.
commons-dbcp와 tomcat-jdbc-pool, hikariCP 모두 커넥션 풀의 커넥션들을 관리하는 별도의 쓰레드가 존재한다.
commons-dbcp의 경우는 Evictor 쓰레드로 자세한 동작 방식은 참고 자료의 "1. Commons DBCP 이해하기"를 참조하기 바란다. tomcat-jdbc-pool의 경우는 PoolCleaner 쓰레드로 commons-dbcp의 Evictor와 이름도 다르고 구현 방식도 다르지만 개발 의도 및 동작 방식이 유사하며 제공하는 옵션도 비슷하다.
그래서, 두 커넥션 풀 모두 testWhileIdle 옵션을 true로 설정하여 idle 상태의 커넥션들에 대해서 일정한 주기로 valid 여부를 확인 하게하여 MySQL 서버에서 인지하는 해당 커넥션의 idle 시간이 초기화되게 할 수 있다. 즉, 주기적인 health check 기능의 부수 효과로 MySQL 서버의 wait_timeout으로 인해 커넥션이 close 되는 것을 막을 수 있다.
Evictor와 PoolCleaner 의 차이점은 commons-dbcp 1.x 이 synchronized 키워드를 활용한 instance lock 방식으로 구현한 부분을 tomcat-jdbc-pool의 경우는 JDK의 concurrent 패키지의 클래스들을 사용해서 구현하여 멀티쓰레드 환경에서 성능이 대폭 개선되었다. 그래서인지 numTestsPerEvictionRun 옵션은 tomcat-jdbc-pool에서는 더 이상 사용되지 않는다.
또한 기존의 common-dbcp 1.x 에서는 Evictor 쓰레드가 커넥션 풀에 instance lock을 잡고 실행되기 때문에 서비스의 성능에 영향을 주어, 실행 주기(timeBetweenEvictionRunsMillis) 및 한번의 실행 타임에 테스트할 커넥션 개수(numTestsPerEvictionRun)등을 설정하기가 까다로웠다. 설정한 주기마다 설정한 개수의 커넥션들의 valid 여부를 확인해서, 커넥션 풀의 모든 idle 상태의 커넥션들을 확인하는데 걸리는 시간이 DBMS와 인프라 레벨의 idle timeout 성격의 설정들에 걸리지 않도록 신경써야 했기 때문이다. 하지만 tomcat-jdbc-pool에서는 더 이상 그럴 필요가 없다. 아래 소스 1의 PoolCleaner 클래스의 run() 메소드처럼 testWhileIdle 옵션이 true일 경우 testAllIdle() 메소드로 idle 상태의 모든 커넥션에 대해서 한번에 valid 여부를 확인할 수 있게 되었다.
protected static class PoolCleaner extends TimerTask {
...
@Override
public void run() {
ConnectionPool pool = this.pool.get();
if (pool == null) {
stopRunning();
} else if (!pool.isClosed()) {
try {
if (pool.getPoolProperties().isRemoveAbandoned()
|| pool.getPoolProperties().getSuspectTimeout() > 0)
pool.checkAbandoned();
if (pool.getPoolProperties().getMinIdle() < pool.idle
.size())
pool.checkIdle();
if (pool.getPoolProperties().isTestWhileIdle())
pool.testAllIdle();
} catch (Exception x) {
log.error("", x);
}
}
}
소스 1. tomcat-jdbc-pool의 PoolCleaner 클래스의 run() 메소드
hikariCP의 경우는 위 두개의 풀과 유사한 목적으로 HouseKeeper라는 이름의 커넥션 풀 관리 쓰레드를 사용하지만 validation에 대한 기본적인 철학이 다르다. 기존의 커넥션 풀들이 너무 잦은 valid 여부 확인을 통해 과하게 DBMS에 부하를 발생시킨다는 주장이다. 그래서인지 아래 소스 2에서와 같이 HouseKeeper 쓰레드는 run() 메소드에서 커넥션 풀의 커넥션들의 valid 여부를 확인하는 작업을 하지 않는다. 다만, 설정된 minnumIdle < maximumPoolSize 인 상황에서 minnumIdle 개수 이상의 커넥션이 있을 경우 설정한 idleTimeout이 지난 커넥션을 제거하여 커넥션 풀에 minnumIdle 개수를 유지하는 역할만 한다.(참고자료 "4. HikariCP" 참조)
/**
* The house keeping task to retire and maintain minimum idle connections.
*/
private final class HouseKeeper implements Runnable
{
private volatile long previous = plusMillis(currentTime(), -HOUSEKEEPING_PERIOD_MS);
@Override
public void run()
{
...
if (idleTimeout > 0L && config.getMinimumIdle() < config.getMaximumPoolSize()) {
logPoolState("Before cleanup ");
afterPrefix = "After cleanup ";
final List<PoolEntry> notInUse = connectionBag.values(STATE_NOT_IN_USE);
int toRemove = notInUse.size() - config.getMinimumIdle();
for (PoolEntry entry : notInUse) {
if (toRemove > 0 && elapsedMillis(entry.lastAccessed, now) > idleTimeout && connectionBag.reserve(entry)) {
closeConnection(entry, "(connection has passed idleTimeout)");
toRemove--;
}
}
}
logPoolState(afterPrefix);
fillPool(); // Try to maintain minimum connections
...
}
}소스 2. hikariCP의 HouseKeeper 클래스의 run() 메소드
즉, hikariCP에는 앞의 두 커넥션 풀들처럼 testWhileIdle 성격의 옵션이 없다. 소스 2의 HouseKeeper 클래스의 run() 메소드를 보면 마지막으로 사용한지 idleTimeout 이상이 지난 커넥션들을 제거하는 것처럼 보여 같은 목적을 달성할 수 있을 것으로 보이지만, idle 상태의 커넥션 개수가 minnumIdle 개수보다 클때가 조건이다. minnumIdle 개수가 유지되고 있는 상황에서는 idleTimeout 값이 설정되어 있고 설정된 값 이상의 idle 상태가 유지되어도 커넥션 풀에서 제거되지 않는다. 서비스의 트래픽 대비 크게 설정된 mininumIdle 설정일 경우 결국 동일한 문제를 발생시키게 되는 것이다.
대신 hikariCP는 커넥션 풀에 머무를 수 있는 최대의 시간을 의미하는 maxLifetime 옵션을 제공한다. 아래 소스 3처럼 커넥션을 생성할 때마다 사용자가 설정한 maxLifeTime 값에 2.5% 수준의 변화를 주어 lifetime을 계산하고 그 값을 timeout 값으로 설정하여 스케쥴러에 등록시킨다. maxLifetime 설정을 MySQL 서버의 wait_timeout 설정보다 작게 해서 위 에러 상황을 해결할 수 있다. 커넥션마다 등록되는 timer 태스크의 timeout 값도 2.5% 수준으로 분산되기 때문에 모든 커넥션이 동시에 끊겼다가 연결을 시도하는 상황도 피할 수 있다.
/**
* Creating new poolEntry.
*/
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(new Runnable() {
@Override
public void run() {
softEvictConnection(poolEntry, "(connection has passed maxLifetime)", false /* not owner */);
}
}, lifetime, MILLISECONDS));
}
...
}소스 3. hikariCP의 HikariPool 클래스의 createPoolEntry() 메소드
socketTimeout 옵션을 Response Timeout 성격으로 사용
짧게 설명을 하자면 TCP socketTimeout 설정을 너무 작게 설정하였거나 요청을 처리하기 위한 query가 slow query로 실행 시간이 오래 걸렸을 경우 발생하는데 TCP socketTimeout 옵션을 Response Timeout 성격으로 잘 못 사용하고 있는 상황인 경우가 많다. Response Timeout 성격으로 사용할 수 있는 Spring Framework에서의 TransactionTimeout 이나 JDBC 레벨의 StatementTimeout(queryTimeout) 옵션 등을 설정해서 사용하는 것을 추천한다.
TCP socketTimeout을 Response Timeout 성격으로 사용하는 상황에서는 일시적인 과부하 발생 시 잦은 socketTimeout이 발생할 수 있고, 이런 상황은 사용하고 있는 JDBC 드라이버와 커넥션 풀의 종류에 따라서 커넥션 풀의 전체적인 효율성이 저하되어 시스템의 안정성에 악영향을 줄 수 있다. mysql-connector/J에서 사용자의 query가 실행되는 과정을 따라가보며 어떤 이유로 이런 상황이 발생하는지 알아보자.
관련된 소스를 확인하기 쉽도록 SocketTimeoutException이 발생했을 때의 메소드 콜스택을 보면 아래 표1 과 같다. 사용자의 query를 실행한 메소드의 호출 흐름은 결국 is.socketRead() 메소드에서 Read timed out 이 발생했고 IOException의 서브 타입인 java.net.SocketTimeoutException이 상위로 throw 됐다.
Read timed out. Stacktrace follows:
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3472)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3462)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3905)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903)
...표 1. socketTimeout으로 인한 메소드 콜 스택 덤프
위 표 1의 checkErrorPacket() 메소드를 보면 아래 소스 4와 같다. 이 부분이 중요한 이유는 앞에서 말한 상위로 throw 된 SocketTimeoutException이 이 메소드에서 SQLError.createCommunicationsException() 메소드를 통해 SQLException의 서브타입인 CommunicationException 으로 wrapping 되어 throw 되게 된다는 것이다.
/**
* Checks for errors in the reply packet, and if none, returns the reply
* packet, ready for reading
*
* @param command
* the command being issued (if used)
*
* @throws SQLException
* if an error packet was received
* @throws CommunicationsException
*/
private Buffer checkErrorPacket(int command) throws SQLException {
//int statusCode = 0;
Buffer resultPacket = null;
this.serverStatus = 0;
try {
// Check return value, if we get a java.io.EOFException, the server has gone away. We'll pass it on up the exception chain and let someone higher up
// decide what to do (barf, reconnect, etc).
resultPacket = reuseAndReadPacket(this.reusablePacket);
} catch (SQLException sqlEx) {
// Don't wrap SQL Exceptions
throw sqlEx;
} catch (Exception fallThru) {
throw SQLError.createCommunicationsException(this.connection, this.lastPacketSentTimeMs, this.lastPacketReceivedTimeMs, fallThru,
getExceptionInterceptor());
}
checkErrorPacket(resultPacket);
return resultPacket;
}소스 4. mysql-connector/J의 MySQLIO 클래스의 checkErrorPacket() 메소드
결국 IOException 이 발생되었지만 execSQL() 메소드는 아래 소스 5처럼 SQLException 으로 catch 해서 Exception을 처리하게 된다. getHighAvailability() 메소드는 MySQL JDBC 드라이버의 auto_reconnect 옵션과 관련된 메소드로 현재 상황(auto_reconnect=false) 에서는 false 이다. 결국 else 문을 통해서 cleanup() 메소드를 호출하여 리소스를 정리하게 된다.
(참고로, 소스 5의 SQLError.SQL_STATE_COMMUNICATION_LINK_FAILURE 의 값이 "08S01" 이다.)
public ResultSetInternalMethods execSQL(StatementImpl callingStatement, String sql, int maxRows, Buffer packet, int resultSetType, int resultSetConcurrency,
boolean streamResults, String catalog, Field[] cachedMetadata, boolean isBatch) throws SQLException {
synchronized (getConnectionMutex()) {
...
return packet == null
? this.io.sqlQueryDirect(callingStatement, sql, getUseUnicode() ? getEncoding() : null, null, maxRows, resultSetType,
resultSetConcurrency, streamResults, catalog, cachedMetadata)
: this.io.sqlQueryDirect(callingStatement, null, null, packet, maxRows, resultSetType, resultSetConcurrency, streamResults, catalog,
cachedMetadata);
} catch (java.sql.SQLException sqlE) {
// don't clobber SQL exceptions
...
if (getHighAvailability()) {
if (SQLError.SQL_STATE_COMMUNICATION_LINK_FAILURE.equals(sqlE.getSQLState())) {
// IO may be dirty or damaged beyond repair, force close it.
this.io.forceClose();
}
this.needsPing = true;
} else if (SQLError.SQL_STATE_COMMUNICATION_LINK_FAILURE.equals(sqlE.getSQLState())) {
cleanup(sqlE);
}
throw sqlE;
} catch (Exception ex) { 소스 5. mysql-connector/J의 ConnectionImpl 클래스의 execSQL() 메소드
리소스가 정리되는 과정에서 mysql-connector/J는 MySQL 서버로 아래 소스 6처럼 QUIT 커맨드를 보내고 해당 커넥션을 close 한다. 이럴 경우 커넥션 풀 입장에서는 생성의 오버헤드를 줄이기 위해 풀로 관리하는 커넥션이 짧은 시간동안만 사용되고 close 되는 상황이라 커넥션 풀로써의 전체적인 효율성이 떨어지게 된다.
/**
* Log-off of the MySQL server and close the socket.
*
* @throws SQLException
*/
final void quit() throws SQLException {
try {
// we're not going to read the response, fixes BUG#56979 Improper connection closing logic leads to TIME_WAIT sockets on server
try {
if (!this.mysqlConnection.isClosed()) {
try {
this.mysqlConnection.shutdownInput();
} catch (UnsupportedOperationException ex) {
// ignore, some sockets do not support this method
}
}
} catch (IOException ioEx) {
this.connection.getLog().logWarn("Caught while disconnecting...", ioEx);
}
Buffer packet = new Buffer(6);
this.packetSequence = -1;
this.compressedPacketSequence = -1;
packet.writeByte((byte) MysqlDefs.QUIT);
send(packet, packet.getPosition());
} finally {
forceClose();
}
}소스 6. mysql-connector/J의 MysqlIO 클래스의 quit() 메소드
TransactionTimeout이나 StatementTimeout 옵션을 설정하여 사용할 경우는 참고 자료 "2. JDBC Internal - 타임아웃의 이해"에 설명되어 있는 것처럼 별도의 Watch Dog 성격의 쓰레드(TimerTask)를 사용해서 timeout이 발생할 경우, 아래 소스 7처럼 추가로 별도의 JDBC 커넥션을 생성하여 "KILL QUERY [connectionId]"를 실행한다. 이럴 경우 기존에 timeout이 발생한 커넥션은 query의 실행이 interrupted 되었다는 의미의 Error Code = 1317을 응답으로 받게 되고 그후에는 SocketTimeoutException 때처럼 커넥션을 close 하는 것이 아니라 단순 Transaction "rollback"만을 실행하고 커넥션 풀로 반환하여 커넥션 풀을 좀 더 효율적으로 사용할 수 있다.
/**
* Thread used to implement query timeouts...Eventually we could be more
* efficient and have one thread with timers, but this is a straightforward
* and simple way to implement a feature that isn't used all that often.
*/
class CancelTask extends TimerTask {
...
@Override
public void run() {
Thread cancelThread = new Thread() {
@Override
public void run() {
...
cancelConn = (Connection) DriverManager.getConnection(CancelTask.this.origConnURL, CancelTask.this.origConnProps);
cancelStmt = cancelConn.createStatement();
cancelStmt.execute("KILL QUERY " + CancelTask.this.origConnId);
...
};
cancelThread.start();
}
}소스 7. mysql-connector/J의 StatementImpl 클래스의 CancelTask 클래스
마무리
MySQL 기반의 웹애플리케이션 개발자라면 최소 한번 이상은 접해봤을 에러 메시지에 대한 내용을 다뤄봤습니다. 개발 경력이 오래된 분들에게는 잠시나마 예전의 추억을 떠오르게 하지 않았을까? 하는 생각도 해 봅니다.
개발자에 따라서는 "TCP socketTimeout 옵션을 Response Timeout 성격으로 잘못 사용"이라는 표현이 다르게 받아들여 질것 같기도 합니다. JDBC도 Request/Response 모델이라 유사하게 통용되는 HTTP 커넥션 풀들에서처럼 크게 문제가 되지 않을 것 같기도 합니다. SocketTimeoutException으로 JDBC 커넥션이 close 되어도 새로 생성하는데 길어야 xx ms 정도의 시간 밖에 안 걸리니 큰 문제가 아닐 것 같기도 합니다. 하지만 대용량 트래픽을 처리하는 서비스에서는 이 작은 차이가 일시적인 과부하 상황에서 잠깐의 응답시간 지연 현상이냐? 아니면 서비스 장애냐?를 결정짓는 중요한 차이를 만든다고 생각합니다.
본문에서 전달하고자 하는 내용의 문맥에 녹이지 못해 추가하지 못한 tomcat-jdbc-pool과 hikariCP의 특징들이 아직 많이 남아 있습니다. 앞으로도 카카오커머스의 기술블로그에 많은 관심을 부탁드립니다.
참고 자료
1. Commons DBCP 이해하기
https://d2.naver.com/helloworld/5102792
2. JDBC Internal - 타임아웃의 이해
https://d2.naver.com/helloworld/1321
3. Configuration Properties for Connector/J
https://dev.mysql.com/doc/connector-j/5.1/en/connector-j-reference-configuration-properties.html
4. HikariCP
https://github.com/brettwooldridge/HikariCP
5. Bad Behavior: Handling Database Down
https://github.com/brettwooldridge/HikariCP/wiki/Bad-Behavior:-Handling-Database-Down
6. Rapid Recovery
https://github.com/brettwooldridge/HikariCP/wiki/Rapid-Recovery
함께 해요!
'krew story > tech story' 카테고리의 다른 글
| 2021 카카오커머스 개발자 공개 채용 (0) | 2021.03.22 |
|---|---|
| 카카오커머스 개발자의 하루 (Vlog) (0) | 2020.11.17 |
| 플랫폼개발랩 1만의 기적!!! (0) | 2020.06.19 |
| 주문개발파트 <Benji> - "카카오커머스에서 개발하실래요?" (0) | 2020.05.12 |
| 카카오커머스를 지탱하는 Angular (0) | 2020.02.13 |
