Unable to commit(rollback) against JDBC Connection

해당 예외는 Connection이 아무런 활동을 하지 않는 시간이 DB에 설정된 wait_timeout 시간에 도달할 때 발생할 수 있습니다.

 

잠깐 HikariCP Connection 관련하여 설명하자면

HikariCP가 제공하는 Connection 객체는 HikariProxyConnection으로 Wrapping되어있는 형태입니다!

 

다시 말하면 실제로 Mysql과 통신하는 Connection 객체를

클래스 안에 delegate로서 가지고 있으면서 Connection의 실제 기능을 수행할 때는 delegate를 대신 호출하는 방식입니다.

 

아래는 HikariProxyConnecton ProxyConnection 클래스의 일부입니다.

ProxyConnection을 보면 Mysql과 통신하는 Jdbc 함수(createStatement…)들 구현부에는 

delegate 함수를 대신 호출해주는 것을 확인할 수 있습니다.

 

갑자기 Hikari Conenction을 왜 설명했냐 하면……

wait_timeout으로 인해 Mysql과 연결이 끊어진다는 것은 실제로 연결된 Connection 

즉, delegate가 참조하는 Connection이 활동(쿼리 실행) 하지 않는 시간이 wait_timeout을 넘을 경우 Connection이 끊어집니다.

쉽게 말해 Connection이 쿼리를 날리지 않는 시간이 wait_timeout을 넘으면 Mysql에서 연결을 끊어버립니다.

 

Unable to commit(rollback) against JDBC Connection 발생하는 이유는! 

Hikari Connection이 어떠한 쿼리를 수행하기 위해 delegate의 함수를 호출하지만

실제 Mysql과 통신을 하는 과정에서 이미 연결이 끊어졌을 경우 해당 예외가 발생할 수 있습니다.

 

아래는 간단하게 예외를 발생시키는 코드입니다.

HikariCP 설정

wait_timeout

코드

@Service
@RequiredArgsConstructor
@Slf4j
@Transactional(readOnly = true)
public class HikariTestService {
    @PersistenceContext
    private final EntityManager em;

    @Transactional
    public void delaySaveMember() {
        log.info("=======delaySaveMember 수행========");
        try {Thread.sleep(22000);}
        catch (InterruptedException e) {}

        Member member = new Member("TestMember2");
        em.persist(member);
    }
}

@SpringBootTest
public class HikariTests {
    @Autowired
    HikariTestService hikariTestService;

    @Test
    void wait_timeout_test() {
        hikariTestService.delaySaveMember();
   }
}

 

코드는 다음과 같이 수행됩니다.

1. delaySaveMember() 호출
2. @Transactionl을 통해 Hikari Connection 획득
3. 22초(wait_timeout보다 긴 시간) 동안 Connection은 아무런 활동을 하지 않음
4. member 저장 시도
5. 이미 20초(wait_timeout)가 지난 시점에서 Mysql과의 연결은 끊어졌기에 예외 발생

 

Unable to rollback~말고 Unable to commit~이 발생할 수 도 있는데

이 경우는 commit 수행하는 시점에 Mysql Connection이 끊겨있을 경우 발생할 수 있습니다.

 

아래는 Unable to commit~ 유발하는 코드입니다.

...
//테스트 코드는 동일

@Service
@RequiredArgsConstructor
@Slf4j
@Transactional(readOnly = true)
public class HikariTestService {
    @PersistenceContext
    private final EntityManager em;

    @Transactional
    public void delaySaveMember() {
        try {Thread.sleep(22000);}
        catch (InterruptedException e) {}
    }
}

위 코드를 보면 @Transactional 로 Connection 획득하고 22초 Sleep후에 아무 동작도 하지 않습니다.

하지만 @Transactional 함수가 종료될 때 자동으로 commit 명령어를 수행합니다.

즉, 위 코드는 22초 후 commit을 날릴 때 이미 connection이 끊긴 상태이기 때문에 위 예외가 발생하는 것입니다.

 

여기서 하나 더 설명해야 할 것은 hikariCP max-lifetime, wait_timeout의 관계입니다.

max-lifetime은 Hikari Connection 생존 시간을 설정합니다.

그리고 해당 생존 시간은 정확히 말하면 Connection이 사용되지 않는 시간으로 측정됩니다.

 

예를 들어 max-lifetime을 30초로 설정하고 Connection Pool에서 28초를 대기하다 Connection이 사용되고

다시 Pool로 돌아오면 2초 후에 사라집니다.

만약 Connection을 얻었는데 DB와의 연결이 끊겨 있다면 해당 Connection은 제거되고 다른 Connection을 제공합니다.

 

이로 인해 **HikariCP는 max-lifetime을 wait_timeout보다 짧게 설정하는 것을 권장하고 있습니다.**

 

다음 코드는 HikariCP getConnection() 일부입니다.

코드를 보면 isConnectionAlive() 존재하는데

해당 함수에서 Connection이 끊겨있는지 체크하고, 끊어졌다면 close하는 것을 확인할 수 있습니다.

 

그런데 여기서 저는 궁금한 게 생겼습니다.

max-lifetime: 30초, wait_timeout: 20초로 설정(max-lifetime이 wait_timeout보다 길게 설정) 후 

Connection Pool에서 18초 대기하다 @Transactional 함수 진입 후 3초를 대기하면

해당 Connection은 21초 동안 활동을 안한게 되므로 끊어져야 하는게 아닌지 궁금했습니다.

 

이렇게 될 경우 wait_timeout으로 인해 끊기기 아슬아슬한 시간차이로(Ex:19.XX초) Connection이 사용된다면

함수 수행 과정에서 wait_timeout으로 인해 Connection이 끊기는 상황이 운영에서 간간히 발생할 수 있지 않을까 생각했습니다.

 

그래서 아래처럼 테스트를 진행해봤습니다. 

설정은 위 테스트와 동일합니다.

@Service
@RequiredArgsConstructor
@Slf4j
@Transactional(readOnly = true)
public class HikariTestService {
    @PersistenceContext
    private final EntityManager em;

    @Transactional
    public void delaySaveMember() {
        log.info("=======delaySaveMember 수행========");
        try {Thread.sleep(4000);}
        catch (InterruptedException e) {}

        Member member = new Member("TestMember2");
        em.persist(member);
    }
}

@SpringBootTest
public class HikariTests {

    @Autowired
    HikariTestService hikariTestService;

    @Test
    void wait_timeout_test() {
        try {Thread.sleep(18000);}
        catch (InterruptedException e) {}
        hikariTestService.delaySaveMember();
    }
}

 

간단하게 Connection 점유 전 18초를 대기하고 Connection 점유 후 4초 대기 후 쿼리를 날리는 테스트입니다.

결과는 정상적으로 수행됐고, Mysql log는 다음과 같습니다.

 

Connection이 연결된 후 18초 후에 SET autocommit=0 명령어가 수행되는 것을 확인할 수 있습니다.

즉 @Transactional 진입할 때 autocommit을 설정하는 것을 확인할 수 있었고,

이로 인해 wait_timeout이 초기화가 된다는 것을 알 수 있었습니다.

 

 

출처

https://saramin.github.io/2023-04-27-order-error/