ConnectionAcquireTimeoutError [SequelizeConnectionAcquireTimeoutError]: Operation 해결하기

지난 몇 개월 동안 인스타그램 API를 활용해서 사내의 콘텐츠 서비스와 연동하는 작업을 진행했었고, 약 한 달간의 QA를 끝으로 실제 서비스에 배포하게 되었다. 워낙 큰 작업을 진행했었기 때문에 대규모 단위의 배포를 진행했었다. 사전에 꼼꼼하게 점검하고, 놓친 부분이 없는지 다시 점검한 후에 실 서비스에 배포했지만, 불과 2시간 만에 ConnectionAcquireTimeoutError가 발생했다.

문제

배포를 하고 나서 직접 기능들을 사용해 봤을 때는 문제가 없었다. 하지만 2시간 후에 원인을 알 수 없는 에러로 인해 전체 서비스에 장애가 발생하게 되었다. 우선 Error로그를 파악해봤는데, 특정 시점부터 아래와 같은 Error 로그가 지속적으로 발생하게 되었다. 굉장히 당황스러웠고, 뭐부터 해야 할지 감이 잡히지 않았다...😭

ConnectionAcquireTimeoutError [SequelizeConnectionAcquireTimeoutError]: Operation timeout
ConnectionAcquireTimeoutError [SequelizeConnectionAcquireTimeoutError]: Operation timeout
ConnectionAcquireTimeoutError [SequelizeConnectionAcquireTimeoutError]: Operation timeout
...
...
ConnectionAcquireTimeoutError [SequelizeConnectionAcquireTimeoutError]: Operation timeout

우선 Connection을 획득하는데 문제가 있다고 판단하고, 재 배포하여 대응했다. 그러고 나서 정상적으로 동작하는 것을 확인하고, 로그를 분석하기 시작했다.

원인

첫 번째로 특정 시점의 서버의 CPU, Memory를 확인해봤지만 치솟는 구간이 없었다. 두 번째로 RDS의 Connection 및 Commit 지연과 및 기타 로그를 파악해봤지만 문제가 없었다.

Api 로그를 다시 분석해 봤을 때, 조회성 작업에는 정상적으로 응답하고 있었다. 문제가 없었던 이유를 생각해보니 MySQL의 데이터를 가공하여, Elasticsearch에 적재하고, 응답이 느린 부분에 대해서는 Redis 캐시를 활용하고 있었기 때문에 빠른 응답이 가능했고, 애초에 SequelizeConnectionAcquireTimeoutError가 발생했다는 것은 Sequelize ORM에서 발생하는 에러였기 때문에 MySQL에 등록하거나, 수정하거나, 삭제하는 작업으로 범위를 좁혀서 보게 되었다.

그러고 나서 등록, 수정, 삭제 시 커넥션을 획득하지 못하는 원인에 대해서 팀장님과 팀원들과 상의를 했고, 2가지 결론을 내렸다. 첫 번째로 트랜잭션 작업이 굉장히 오래 걸리는지 확인해보자는 의견이 있었고, 두 번째로 Connection을 사용하고 Connection Pool에 반환하지 않는 로직이 있는지 확인해보자는 의견이 있었다.

나는 두 번째의 의견을 가장 먼저 파악해보기 시작했고, 구현된 코드들의 SQL 쿼리를 실행 로그를 봤을 때, 대부분 아래와 같이 정상적인 트랜잭션 처리가 수행되었다.

START TRANSACTION;
-- 작업
COMMIT;

그런데 특정 기능에서 아래와 같은 쿼리가 실행되고 있었고, 가장 큰 문제는 Commit이나 Rollback을 실행하지 않고 있었다.

START TRANSACTION;
SELECT * FROM table WHERE xxx
UPDATE table SET xxx WHERE xxxx 
-- Commit 이나 Rollback 이 실행되지 않음

빠른 시간 안에 원인을 찾게 되었다는 점에서 다행스럽게? 생각했고, 기존 로직을 파악해보기로 했다.

해결

기존 로직

updateFunc = async (data) => {
    // 트랜잭션 시작
    const transaction = await this.repository.getTransaction()
    
    // 조회 작업 - select
    const { id } = await findById()
    
    if (id === 0) {
    	return
    }
    
    try {
        // 수정 작업 - update
    	await update(id)
    
    	// 커밋
    	await transaction.commit()    
    } catch (error) {
    	// 롤백
    	await transaction.rollback()
    }
}

위의 코드를 보면, Connection을 사용하고 나서 경우에 따라 Pool에 Connection을 반환하지 않아서 문제가 발생했던 것이다. 결론부터 말하자면, findById() 메서드를 통해 얻은 id 값이 0인 경우에는 if문에 의해서 return 된다. 즉, Commit 또는 Rollback을 실행하지 않으면서 Connection도 Pool에 반환하지 않는다. 이러한 문제 때문에 다른 작업에서 Connection을 획득하지 못하고, 결국 전체적으로 서비스 장애가 발생하게 되었던 것이다.

버그를 수정한 로직

updateFunc = async (data) => {
    // ------------------------------------------------
    // 조회 작업은 트랜잭션 시작하기 전에 실행하도록 로직을 수정했다!
    const { id } = await findById()
    
    if (id === 0) {
    	return
    }
    // ------------------------------------------------    

    // 트랜잭션 시작
    const transaction = await this.repository.getTransaction()
    
    try {
        // 수정 작업 - update
    	await update(id)
    
    	// 커밋
    	await transaction.commit()    
    } catch (error) {
    	// 롤백
    	await transaction.rollback()
    }
}

위와 같이 findById() 메서드를 호출하고, id 값을 검증하는 로직을 트랜잭션 시작하기 전에 두었고, 문제는 더 이상 발생하지 않게 되었다.

회고

위와 같은 문제를 해결하면서 가장 먼저 들었던 생각은 PR 리뷰를 꼼꼼하게 하지 못했던 점이 너무 아쉬웠다. 하지만, 이러한 경험을 통해 또 배울 수 있다는 점이 생겨서 너무 좋았고 감사했다.