[AWS] CodeDeploy 배포자동화 오류 해결하기 (*오류코드: ScriptFailed)

가장 최근에 작성했던 글에서 서버 용량이 가득 차 자동 배포가 이뤄지지 않는 문제를 서버 용량 증설을 통해 해결했던 경험을 기록했었다. 이때 문제가 되고 있는 서버 용량을 늘렸으니 재배포를 시도했을 때 성공할 것이라 기대했지만, 다른 문제로 인해서 또 배포가 실패하는 이슈가 있어 여기에 대해서도 기록해보고자 한다 🤯

CodeDeploy 라이프 사이클

이번 배포가 실패한 로그를 분석하기 전에 CodeDeploy의 라이프 사이클을 이해하는 시간이 필요했다. CodeDeploy는 아래와 같은 순서로 이벤트 훅을 동작시켜 배포를 자동화해주고 있다. 이때 연하늘색으로 표시된 이벤트의 경우에는 해당 이벤트가 발생했을 때 어떤 훅을 동작시킬 것인지 appspec.yml에 유저가 커스텀하게 정의할 수 있도록 지원한다. 이 중 설명이 필요한 몇 가지에 이벤트에 대해서만 간단하게 언급하고자 한다.

• install 배포하려는 애플리케이션 파일 및 의존성을 EC2 인스턴스에 설치한다.
• AfterInstall 설치가 완료된 애플리케이션 파일을 실행시키기 전에 해야 하는 작업이 있다면 해당 단계에서 수행한다.
• ApplicationStart 애플리케이션을 실행하는 작업을 수행한다.

우리 서비스의 경우에는 아래와 같이 appspec.yml이 작성되어 있다.

hooks:
  AfterInstall:
    - location: scripts/stop.sh
      timeout: 60
      runas : root
  ApplicationStart:
    - location: scripts/start.sh
      timeout: 60
      runas : root

이때 AfterInstall 단계에서는 아래와 같이 작성한 stop.sh을 실행시켜 새 애플리케이션을 실행하기 전에 기존에 배포되어있는 애플리케이션의 프로세스를 kill하는 작업을 한다.

#!/bin/bash

ROOT_PATH="/home/ubuntu/freebe-backend"
JAR="$ROOT_PATH/application.jar"
STOP_LOG="$ROOT_PATH/stop.log"
SERVICE_PID=$(pgrep -f $JAR)

if [ -z "$SERVICE_PID" ]; then
  echo "서비스 NouFound" >> $STOP_LOG
else
  echo "서비스 종료 " >> $STOP_LOG
  kill "$SERVICE_PID"
fi

배포 실패 로그 분석하기

이번 배포실패 로그를 살펴보면 EC2 인스턴스에 애플리케이션 설치까지는 성공적으로 수행되었지만, AfterInstall 훅에서 stop.sh 스크립트를 실행하던 중 오류가 난 것을 확인할 수 있다.

stop.sh 스크립트 중에서 기존에 실행중이던 프로세스를 kill하는 과정에서 arguments must not be process or job IDs 로그가 찍힌 것을 보면 아마 kill 명령어와 관련해 문제가 발생하고 있는 것 같다.

실패 원인 가정하기

그렇다면 kill 명령어를 수행하는데 있어 발생할 수 있는 문제는 무엇이 있을까? 가장 먼저 떠올린 것은 권한 문제였다. 터미널에서 직접 kill 명령어를 수행하려고 하면 Operation not permitted가 출력되는 것을 확인할 수 있다.

왜냐하면 현재 내가 접속한 일반 사용자 계정으로는 root 권한으로 실행되는 application.jar 프로세스를 kill할 권한이 없기 때문이다. 이와 유사하게 CodeDeploy 에이전트에게도 root 권한이 없어서 kill 명령이 제한되고 있는 건 아닐까라는 생각을 하게 되었다. 하지만 확인해본 결과 CodeDeploy agent도 root 권한으로 실행되고 있었기 때문에 권한 문제는 아니었다.

그렇다면 kill 명령이 제대로 입력되지 않고 있는건 아닐까? 아래 stop.sh 스크립트를 다시 살펴보면 pgrep -f application.jar로 실행중인 프로세스를 SERVICE_PID 변수에 저장하고 kill $SERVICE_PID를 수행하게 되는데 SERVICE_PID에 pid가 제대로 저장되지 않고 있을 수 있다는 생각이 들었다.

#!/bin/bash

ROOT_PATH="/home/ubuntu/freebe-backend"
JAR="$ROOT_PATH/application.jar"
STOP_LOG="$ROOT_PATH/stop.log"
SERVICE_PID=$(pgrep -f $JAR)

if [ -z "$SERVICE_PID" ]; then
  echo "서비스 NouFound" >> $STOP_LOG
else
  echo "서비스 종료 " >> $STOP_LOG
  kill "$SERVICE_PID"
fi

그런데 터미널에서 직접 실행중인 프로세스를 찾아보니, 왜인지는 모르겠지만 application.jar 프로세스가 두 개가 돌아가고 있는 것을 발견할 수 있었다.

186470, 186551 두 프로세스가 시작된 시간을 확인해보니 9월 12일에 20분 간격을 두고 실행된 것을 확인할 수 있었는데, 두번째 프로그램이 배포된 이후부터 실행중인 프로세스가 두 개가 되면서 그 다음 배포 시도부터는 stop.sh이 여러 개의 프로세스를 kill하지 못하게 되어 배포에 실패한게 아닌가 라는 추측을 해보았다. 왜냐하면 기존 stop.sh 스크립트는 실행중인 프로세스가 하나인 경우를 가정하고 이미 존재하는 하나의 프로세스를 종료시키도록 작성되어 있기 때문이다.

그렇지만 스크립트 실행 자체가 실패하는 것은 이해가 가지 않았던 것이, 실행중인 프로세스가 여러개일 때 SERVICE_PID 변수에 기존에 실행중인 여러개의 프로세스 아이디가 공백으로 구분되어 저장되므로(ex: kill 186470 192838) kill 명령을 실행했을 때 가장 맨 앞에있는 프로세스(186470) 한개는 kill 되게끔 동작할 것이기 때문이다.

조치하기

이때까지는 정확한 실패 원인을 파악하지는 못했지만, 예상치 못하게 실행중인 프로세스가 두 개였기 때문에 이를 적절하게 처리하지 못해서 배포에 실패했을거라는 합리적 의심을 하게 되었다. 그래서 실행중인 프로세스가 여러개일 예외상황까지 고려해서 stop.sh에서 실행중인 모든 프로세스를 죽일 수 있도록 스크립트를 수정했다. 또 로그를 구체화 해서 앞으로는 어디서 오류가 났는지 쉽게 파악할 수 있도록 했다.

#!/bin/bash

ROOT_PATH="/home/ubuntu/freebe-backend"
JAR="$ROOT_PATH/application.jar"
STOP_LOG="$ROOT_PATH/stop.log"
NOW=$(date "+%Y %b %d %a %H:%M:%S")

echo "--------------------------------------------------" >> $STOP_LOG

# 실행 중인 모든 프로세스의 PID를 가져옴
SERVICE_PIDS=$(pgrep -f $JAR)

if [ -z "$SERVICE_PIDS" ]; then
  echo "[$NOW] 실행 중인 기존 프로세스 없음" >> $STOP_LOG
else
  echo "[$NOW] 기존 프로세스 종료 시도: PID $SERVICE_PIDS" >> $STOP_LOG

  for PID in $SERVICE_PIDS; do
    echo "[$NOW] kill $PID 실행 중" >> $STOP_LOG
    kill "$PID"
    sleep 1

    if kill -0 "$PID" 2>/dev/null; then
      echo "[$NOW] 프로세스 강제 종료 시도: PID $PID" >> $STOP_LOG
      kill -9 "$PID"
      echo "[$NOW] 프로세스 강제 종료됨: PID $PID" >> $STOP_LOG
    else
      echo "[$NOW] 프로세스가 성공적으로 종료됨: PID $PID" >> $STOP_LOG
    fi
  done
fi

이렇게 스크립트를 수정한 뒤에 다시 배포를 시도했더니 stop.log 파일에서 아래와 같이 스크립트 실행 과정을 트래킹할 수 있게 되었다. 여기서 주목해야 했던 것은 SERVICE_PID 변수에 pid 두개가 공백으로 구분되는 것이 아니라 개행으로 구분되고 있다는 점이었다.

[Sun Sep 22 16:39:48 2024] 기존 프로세스 종료 시도: PID 186470
260650
[Sun Sep 22 16:39:48 2024] kill 186470 실행 중
[Sun Sep 22 16:39:48 2024] 프로세스 강제 종료 시도: PID 186470
[Sun Sep 22 16:39:48 2024] kill 260650 실행 중
[Sun Sep 22 16:39:48 2024] 프로세스가 성공적으로 종료됨: PID 260650

즉, 기존의 stop.sh스크립트로는 kill 186470/n 26065 으로 실행되었기 때문에 명령 자체가 잘못 입력되어 arguments must be process or job IDs 오류가 나면서 그동안 배포에 실패하지 않았을까 싶다. 하지만 이번에 수정한 스크립트에서는 kill 명령을 수행할 때 for문을 돌면서 pid를 꺼내와 하나의 프로세스만 죽이게끔 동작하기 때문에 kill 명령어를 수행할 때 유사한 이슈가 발생하지 않을 것이다.

또한 이번처럼 두 개 이상의 프로세스가 동시에 실행되고 있는 예외 상황을 아예 만들지 않기 위해서 애플리케이션 실행을 담당하는 start.sh 스크립트도 아래와 같이 보완해보았다. stop.sh 스크립트가 예상대로 실행되지 않아서 새 애플리케이션을 실행하기 전에 기존에 존재하는 프로세스를 종료시키지 못했다면, 새 애플리케이션을 실행하지 않고 배포가 실패하게끔 유도하고 관련 로그를 start.log에 남기도록 해두었다.

#!/bin/bash

# 환경 변수 로드
set -o allexport
source /home/ubuntu/freebe-backend/.env
set +o allexport

# 경로 및 파일 설정
ROOT_PATH="/home/ubuntu/freebe-backend"
JAR="$ROOT_PATH/application.jar"

APP_LOG="$ROOT_PATH/application.log"
ERROR_LOG="$ROOT_PATH/error.log"
START_LOG="$ROOT_PATH/start.log"
NOW=$(date "+%Y %b %d %a %H:%M:%S")

echo "--------------------------------------------------" >> $START_LOG
SERVICE_PIDS=$(pgrep -f $JAR)

# 실행 중인 프로세스가 있는지 확인
if [ ! -z "$SERVICE_PIDS" ]; then
  echo "[$NOW] 이미 실행 중인 프로세스가 있습니다: PID $SERVICE_PIDS" >> $START_LOG
  exit 1 
fi

# JAR 파일 복사
echo "[$NOW] $JAR 복사 중..." >> $START_LOG
if cp $ROOT_PATH/build/libs/freebe-0.0.1-SNAPSHOT.jar $JAR; then
  echo "[$NOW] JAR 파일 복사 완료" >> $START_LOG
else
  echo "[$NOW] JAR 파일 복사 실패" >> $START_LOG
  exit 1
fi

# 애플리케이션 실행
echo "[$NOW] > $JAR 실행" >> $START_LOG
nohup java -jar $JAR > $APP_LOG 2> $ERROR_LOG &

# 실행된 프로세스의 PID 확인
NEW_SERVICE_PID=$(pgrep -f $JAR)
if [ ! -z "$NEW_SERVICE_PID" ]; then
  echo "[$NOW] > 새로운 서비스 PID: $NEW_SERVICE_PID" >> $START_LOG
else
  echo "[$NOW] > 서비스 시작 실패" >> $START_LOG
  exit 1
fi

이번엔 진짜 배포 성공

스크립트 수정이 이뤄진 다음부터는 계속해서 배포에 성공한 것을 확인할 수 있었다.🥹 문제를 해결하게 되어 기쁘지만, 한편으로는 앞으로 프로덕션 환경에서 유사한 상황이 발생할때는 어떻게 대처하는게 현명한 방법일지 고민이 된다. 또 앞으로는 배포가 실패할 때 이에 대한 알림을 빠르게 받아볼 수 있게끔 환경을 구축해야겠다는 생각도 든다 💭