Connection Pool의 min 값이 프로세스 종료를 방해했던 이슈 정리

서론

• min 값이 방해했던 이슈는 맞지만, 원인파악의 과정을 정리하기 위함에 가깝습니다.
• 근본적인 원인은 아님을 참고부탁드립니다.

환경

• 일정 주기마다 특정 스크립트가 실행되는 스케줄링 서버
• 쉘 스크립트를 통해 빌드된 코드를 실행하는 구조
• 비동기로 동작하는 로직이 존재

문제상황

1. 특정 시점부터 모니터링 툴에 SequelizeConnctionAcquireTimeoutError가 발생했다는 알림이 오기 시작했습니다.
2. 서버에서 해당 스크립트의 프로세스가 정상 종료되지 않아 다수의 좀비 프로세스가 남아있어 메모리를 점유하는 문제가 발생했습니다.
3. 실행 로그를 파일로 남기고 있어, 로컬에서 스크립트를 실행했을 때 프로세스의 종료여부를 확인하지 못했습니다.

SequelizeConnectionAcquireTimeoutError: Operation timeout
    at pool.acquire.catch.err (/usr/src/app/node_modules/sequelize/lib/dialects/abstract/connection-manager.js:281:53)
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at /usr/src/app/node_modules/bluebird/js/release/catch_filter.js:17:41
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/usr/src/app/node_modules/bluebird/js/release/promise.js:512:31)
    at Promise._settlePromise (/usr/src/app/node_modules/bluebird/js/release/promise.js:569:18)
    at Promise._settlePromise0 (/usr/src/app/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/usr/src/app/node_modules/bluebird/js/release/promise.js:690:18)
    at _drainQueueStep (/usr/src/app/node_modules/bluebird/js/release/async.js:138:12)
    at _drainQueue (/usr/src/app/node_modules/bluebird/js/release/async.js:131:9)
    at Async._drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:147:5)
    at Immediate.Async.drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:17:14)
    at runCallback (timers.js:810:20)
    at tryOnImmediate (timers.js:768:5)
    at processImmediate [as _immediateCallback] (timers.js:745:5)

원인 파악 

• Node.js 환경에서 작성한 코드로, 아래와 같이 프로세스 종료 전 이벤트의 탐지가 가능합니다.
  서버를 구동하여 동작시키는 구조가 아닌 컴파일된 코드를 실행하는 구조여서 모든 로직이 종료된 후 아래 콘솔이 실행되어야 하는데, 
  로그를 확인해보니, 해당 콘솔 메시지가 출력되지 않고 있었습니다. ps 명령어로 메모리에도 해당 스크립트가 종료되지 않고 실행되고 있는 것을 확인했습니다.

process.on("beforeExit", (code) => {
  console.log("프로세스가 종료되었습니다. 이벤트 코드: ", code);
});

 

1. 지속적으로 로직을 업데이트 하던 스크립트 였기 때문에, 수정한 부분 중 일부가 커넥션을 정상적으로 반환하지 않아서 생긴 문제일 것으로 예상했습니다.
   
   
2. 여러 케이스별로 브레이크 포인트를 상세하게 걸어 꼼꼼히 디버깅하여도 로직은 맨 마지막 부분까지 정상적으로 실행하는 것을 확인하여 트랜잭션은 정상적으로 종료되는 것을 확인했고, 해당 문제가 아니었습니다.
   
   
3. 모니터링 툴의 해당 에러가 발생한 시점에서 Git의 커밋 기록을 보니 해당 스크립트가 수정된 시기와 상이했습니다.
   
   
4. 비슷한 시기에 커밋된 코드를 확인해보니 DB와 Connection을 관리하는 코드가 수정된 것을 확인했습니다.
   
   
5. 웹 서버에서도 동작하는 코드를 재사용한 것으로, 트래픽에 대응하기 위해 ConnectionPool의 min 값이 1 이상의 값으로 수정되어 있었습니다.

Process | Node.js v21.6.1 Documentation

결론

1. 웹서버에서 요청에 의해 동작하는 것이 아닌, 일회성 스크립트기 때문에 DB 요청 로직이 실행될 때만 커넥션을 맺고, min 값 만큼의 커넥션 객체가 풀에 저장되어 있었습니다.
2. DB 요청까지 도달하지 못하는 경우에는 문제가 되지 않지만, DB 요청이 존재할 경우엔 커넥션풀에 생성된 객체가 min 만큼 유지되기 때문에 반환되지 않고 프로세스가 종료되지 않아서 생긴 문제였습니다.

Connection Pool

1. 일정량의 커넥션 객체를 미리 만들어두는 프로그래밍 기법입니다.
2. 보통 서버의 커넥션 관리 코드부에서 최솟값과 최대값을 시스템의 사양에 맞춰서 지정합니다.
3. 본문처럼 0이 아닌 경우에는 커넥션을 맺는 시점에 설정한 만큼의 커넥션을 생성해둡니다.

보완할 점

1. 위에 나열한 원인 파악의 과정을 역순으로 진행했다면 더욱 빠르게 파악할 수 있었을 것 같습니다.
   혼자서 관리하는 코드였기 때문에 전혀 다른 영향일 것으로 의심하지 못했고, 단언하고 있었기 때문에 더욱 파악이 오래걸렸습니다.
2. 커넥션 풀의 설정을 일반적으로 건드린 적이 거의 없었고, 별다른 깊은 고민 없이 세팅되어 있는대로 사용했기 때문에, 본문 원인파악 4번의 내용을 파악한 후에도 상당한 시간이 소요되었습니다.

Sequelize Connection Pool

• 공식 문서를 보면, 옵셔널한 값이고 기본값은 0인 것을 확인할 수 있습니다.
• 해당 원인을 파악하며 다른 팀의 api를 확인해본 결과 언어별 ORM 마다 0이 아닌 값들도 있었습니다.

options.pool.min

number

optional default: 0

Minimum number of connection in pool

 

Sequelize | Sequelize