[Express] forever로 배포한 서비스가 오류로 종료된 후 다시 시작되지 않는 현상

forever 모듈로 express 서비스를 배포한 후, 서비스가 죽는 현상이 관찰되었다.

 

DDoS공격이 감지되긴 했지만, 서버가 아예 서버리는 상태가 아니라면

서비스가 죽은 후 다시 해당 서비스를 실행시키는 액션을 기대했지만 튕긴 상태로 유지될 뿐이였다.

 

error: Forever detected script exited with code: 1

forever 에러 로그 맨 마지막엔 해당 오류가 찍혀 있었고,

그 외에 다른 특이사항은 없었다.

 

재미있는 것은 어떤 로그에서는 해당 로그가 표시된 뒤 서비스를 재시작한 이후,

SIGTERM을 받고 프로세스가 죽어버리는 경우도 있었다.

error: Forever detected script exited with code: 1
error: Script restart attempt #1
...잠시동안은 잘 작동한다...
error: Forever detected script was killed by signal: SIGKILL

결국 이렇게 되도 프로세스는 종료된다.

 

원인

프로세스가 종료되는 원인 자체는 나도 잘 모르겠다...

 

다만 해결법은 찾은 것 같다.

 

해결법

forever 공식 문서를 보면 많은 옵션들이 있다.

github.com/foreversd/forever

foreversd/forever

 

세 가지 옵션과 함께 forever를 사용할 것이다.

 

먼저 forever로 실행한 프로세스가 종료/프리징 등에 걸렸을 때 forever의 분기 코드에 대해 간단히 알아보자.

 

When stop
    if hadRunTime >= minUptime 
       restart 
    else if spinSleepTime != 0
         wait spinSleepTime
         restart
    else 
         stop and no restart

출처: stackoverflow.com/questions/24921154/nodejs-forever-package-minuptime-and-spinsleeptime-warnings/37166482

 

[프로세스가 종료되었을 때]
만약 현재까지 실행된 프로세스 시간이 옵션으로 지정한 최소 실행 시간(minUpTIme)보다 크거나 같을 경우 (재시작)
또는 만약 스피닝 값이 감지되었을 경우 대기할 시간(spinSleepTime)이 0이 아닌 경우, 해당 시간 만큼 대기 후 (재시작)
//스피닝은 아마 첫 시작 후 필요한 초기 로딩 시간을 말하는 것 같다
그 외의 경우는 프로세스 정지 및 재시작 안함

우선 위에서 설명한 minUpTime, spinSleepTime 옵션을 지정해 스크립트를 작성하자.

 

forever --minUpTime=1000 --spinSleepTime=1000 start bin/www

이렇게 하면 프로세스가 정지되었을 때, 1초 이상 진행된 프로세스의 경우 재시작,

그렇지 않은 경우 1초 대기 후 재시작하게 된다.

 

minUpTime은 기본값으로 5초가 셋팅되어 있으나,

spinSleepTime은 값이 없기 때문에 초기 로딩 시간이 길다면 프로세스가 계속해서 재시작될 수도 있다.

 

마지막으로 -m(--max)옵션을 사용할 것이다.

 

해당 옵션 값은 forever가 프로세스를 다시 살리는 횟수를 의미한다.

 

즉 저렇게 작성해도, -m옵션 없이 2회부터는 그냥 프로세스가 종료된 채로 남아있게 된다.

 

따라서 최종 배포 스크립트는 다음과 같다.

(일단은 반복 횟수를 100정도로 줘봤다)

forever -m=100 --minUpTime=1000 --spinSleepTime=1000 start bin/www

일단 끝났지만 불안하다

해당 오류를 검색도 해보고 깃헙 이슈까지 뒤져봤지만 완벽한 원인과 해결법은 나오지 않았다.

 

만약 이래도 재시작이 안된다면, 다른 배포 툴로 옮겨야 할 것 같다.

 

expressjs.com/ko/advanced/pm.html

Express 앱용 프로세스 관리자

익스프레스 공식 추천이라 사용중이지만 많이 불안불안하다...

 

서운하다...

 

적용 후기

위 옵션을 이용해 실행시킨 후 로그를 분석해 보았다.

error: Script restart attempt #1
Time Fri Dec 18 2020 01:40:53 GMT+0900 (Korean Standard Time)
...
error: Script restart attempt #30
Time Fri Dec 18 2020 15:11:50 GMT+0900 (Korean Standard Time)

약 14시간동안 30번의 재시작이 있었다.

 

-m옵션 덕분에 1번의 재시작 이후에도 30번의 재시작이 있어 무사히 잘 작동했다.

(그런데 세션 기반의 작업을 하는 서버라면 다른 방법을 찾아봐야 할 것이다. 재시작이 너무 빈번히 일어난다...)

 

이 추세로는 하루에 약 52번의 재시작이 발생할 것으로 추정되므로

-m값을 10000으로 변경할 것이다.

forever -m=10000 --minUpTime=1000 --spinSleepTime=1000 start bin/www

 

그런데 -m옵션 준 이후 프로세스가 죽기 전 특정 예외를 발생시키는 모습이 포착되었다.

node:events:304
      throw er; // Unhandled 'error' event
      ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:213:20)
Emitted 'error' event on Connection instance at:
    at Connection._handleProtocolError (/var/www/html/cyphers-supporter/proxy/node_modules/mysql/lib/Connection.js:423:8)
    at Protocol.emit (node:events:327:20)
    at Protocol._delegateError (/var/www/html/cyphers-supporter/proxy/node_modules/mysql/lib/protocol/Protocol.js:398:10)
    at Protocol.handleNetworkError (/var/www/html/cyphers-supporter/proxy/node_modules/mysql/lib/protocol/Protocol.js:371:10)
    at Connection._handleNetworkError (/var/www/html/cyphers-supporter/proxy/node_modules/mysql/lib/Connection.js:418:18)
    at Socket.emit (node:events:327:20)
    at emitErrorNT (node:internal/streams/destroy:188:8)
    at emitErrorCloseNT (node:internal/streams/destroy:153:3)
    at processTicksAndRejections (node:internal/process/task_queues:80:21) {
  errno: -104,
  code: 'ECONNRESET',
  syscall: 'read',
  fatal: true
}

 

해당 오류에 대한 해결법은 아래 포스트에 작성하였으니 같은 오류 로그가 있다면 참고하길 바란다.

satisfactoryplace.tistory.com/179

[Nodejs] Error: read ECONNRESET at TCP.onStreamRead ...