AwsTask#stop! missing error handling for removed tasks

RCA: InvalidParameterException on task_id: arn:aws:ecs:ap-northeast-1:002596530511:task/cupix-tesla-ece-j

Error Log#

text

InvalidParameterException on task_id: arn:aws:ecs:ap-northeast-1:002596530511:task/cupix-tesla-ece-jp/d2a8c995a80340eab62bbcf015549dde, message: The referenced task was not found

Impact#

Service: cupixworks-worker
발생 횟수: 46
최초 발생: 2026-04-07T02:15:31.925Z
최근 발생: 2026-04-07T09:55:27.999Z

Root Cause Summary#

AwsTask#stop! 메서드가 이미 종료되어 AWS ECS API에서 제거된 task에 대해 반복적으로 stop_task API를 호출하고 있습니다. ECS task d2a8c995는 2026-04-07T01:05:28Z에 정상 종료되었고, 약 1시간 후 ECS가 task 메타데이터를 정리(pruning)했습니다. 그러나 stop! 메서드의 에러 핸들링에서 InvalidParameterException을 catch한 후 task의 DB 상태를 업데이트하거나 archive 처리를 하지 않아, Cupix::Cron::Job.clean_running_jobs cron이 10분마다 동일한 task에 대해 stop!을 계속 호출하는 무한 루프가 발생했습니다.

Technical Analysis#

Code Path#

1. Cron trigger — Cupix::Cron::Job.clean_running_jobs

config/schedule.rb에서 10분 간격(5,15,25,35,45,55 * * * *)으로 실행됩니다.

ruby

# config/schedule.rb:67-68
every '5,15,25,35,45,55 * * * *' do
  runner 'Cupix::Cron::Job.clean_running_jobs'

이 cron은 오래된 running/stopping 상태의 Job을 찾아 관련 ECS task를 강제 종료합니다.

ruby

# lib/cupix/cron/job.rb:12-15
::Job.running.where('state_updated_at < ?', 3.days.ago).each do |job|
  if job.aws_tasks.running.exists?
    running_jobs_with_running_tasks_over_3days << job.id
    job.aws_tasks.running.each(&:stop!)

2. AwsTask#stop! — ECS API 호출 및 에러 핸들링

Entry point: app/models/aws_task.rb:107

ruby

# app/models/aws_task.rb:107-134
def stop!
  begin
    resp = self.ecs_client.stop_task({
      task: task_id,
      cluster: $AWS[:ecs][:cluster_name],
      reason: 'Task has been stopped by Tesla'
    })
  rescue Aws::ECS::Errors::ClientException => e
    Cupix::Logger.error("ClientException on task_id: #{task_id}, message: #{e.message}", class: self.class.name, function: __method__, task: { task_id: task_id })
  rescue Aws::ECS::Errors::InvalidParameterException => e
    Cupix::Logger.error("InvalidParameterException on task_id: #{task_id}, message: #{e.message}", class: self.class.name, function: __method__, task: { task_id: task_id })
  rescue Aws::ECS::Errors::ServerException => e
    Cupix::Logger.error("ServerException on task_id: #{task_id}, message: #{e.message}", class: self.class.name, function: __method__, task: { task_id: task_id })
  end

  Cupix::Logger.info(resp, class: self.class.name, function: __method__, task: { task_id: task_id })
  Cupix::Logger.info("Task has been requested to stop on task_id: #{task_id}", class: self.class.name, function: __method__, task: { task_id: task_id })

  return if resp.blank? || resp.task.blank?  # <-- 여기서 early return

  fetched = fetch!(by_force: true)

  unless fetched
    clean_stale_task
  end
end

Failure point: app/models/aws_task.rb:127

예외 발생 시 resp는 nil로 남아 있고, line 127의 return if resp.blank?에서 early return됩니다. 그 결과 line 129의 fetch!와 line 132의 clean_stale_task가 절대 실행되지 않습니다.

3. clean_stale_task — archive 처리 (미실행)

ruby

# app/models/aws_task.rb:91-97
def clean_stale_task
  if self.created_at < 1.hour.ago
    Cupix::Logger.info("Run task stopped_callbacks on task_id :#{task_id}", class: self.class.name, function: __method__, task: { task_id: task_id })
    job.run_task_stopped_callbacks(task_id)
    self.update_attribute(:archived_at, Time.current)
  end
end

이 메서드가 실행되었다면 archived_at이 설정되어 모든 scope에서 제외되었을 것입니다 (where(archived_at: nil) 조건). 그러나 InvalidParameterException 발생 시 이 코드 경로에 도달하지 못합니다.

4. fetchable? 가드 — fetch! 호출 차단

ruby

# app/models/aws_task.rb:59-61
def fetchable?
  self.last_status != STOPPED
end

fetch! 메서드(line 63)는 fetchable?이 false이면 즉시 return합니다. by_force 파라미터를 받지만 실제로 사용하지 않아 force fetch가 불가능합니다.

Log Evidence#

사용한 Datadog 쿼리:

text

service:cupixworks-worker status:error "InvalidParameterException" @timestamp:[2026-04-07T02:00:00Z TO 2026-04-07T10:10:00Z]

text

service:cupixworks-worker "d2a8c995a80340eab62bbcf015549dde" @timestamp:[2026-04-06T01:00:00Z TO 2026-04-07T10:10:00Z]

Task 생명주기 타임라인:

시간 (UTC)	이벤트	소스
2026-04-06T01:07:19Z	ECS task `d2a8c995` 생성 (cluster: `cupix-tesla-ece-jp`, task def: `cupix-skat-master-production-arm:1`)	Datadog `AwsTask.fetch!` info
2026-04-06T01:08:50Z	Task started	Datadog `AwsTask.fetch!` info
2026-04-07T01:05:23Z	Task stopping 시작 (`stop_code: UserInitiated`, reason: "Task has been stopped by Tesla")	Datadog `AwsTask.fetch!` info
2026-04-07T01:05:28Z	Task 완전 종료 (`execution_stopped_at`)	Datadog `AwsTask.fetch!` info
2026-04-07T01:55:25Z	`AwsTask.fetch!` 성공 — `last_status: STOPPED`, `desired_status: STOPPED` 확인	Datadog info
2026-04-07T02:05:25Z	`AwsTask.stop!` 마지막 성공 (ECS API에 task 메타데이터 아직 존재)	Datadog info
2026-04-07T02:15:31Z	첫 번째 실패 — `InvalidParameterException: The referenced task was not found`	Datadog error
2026-04-07T02:15~10:05	10분 간격으로 47회 반복 실패 (각각 다른 PID)	Datadog error

핵심 로그 (성공한 fetch — 01:55:25Z):

text

{
  "class": "AwsTask",
  "function": "fetch!",
  "task": {
    "task_id": "arn:aws:ecs:ap-northeast-1:002596530511:task/cupix-tesla-ece-jp/d2a8c995a80340eab62bbcf015549dde",
    "last_status": "STOPPED",
    "desired_status": "STOPPED",
    "stop_code": "UserInitiated",
    "stopped_reason": "Task has been stopped by Tesla",
    "stopped_at": "2026-04-07T01:05:28.443+00:00",
    "execution_stopped_at": "2026-04-07T01:05:28.411+00:00",
    "task_definition_arn": "arn:aws:ecs:ap-northeast-1:002596530511:task-definition/cupix-skat-master-production-arm:1",
    "launch_type": "EC2",
    "memory": "125952"
  }
}

핵심 로그 (반복 실패 패턴 — 02:15~10:05Z):

text

# 매 10분마다 동일한 패턴이 반복:
# 1) info 로그: stop! 호출
{"class": "AwsTask", "function": "stop!", "message": "Task has been requested to stop on task_id: arn:aws:ecs:ap-northeast-1:002596530511:task/cupix-tesla-ece-jp/d2a8c995a80340eab62bbcf015549dde"}

# 2) error 로그: InvalidParameterException
{"class": "AwsTask", "function": "stop!", "level": "error", "message": "InvalidParameterException on task_id: arn:aws:ecs:ap-northeast-1:002596530511:task/cupix-tesla-ece-jp/d2a8c995a80340eab62bbcf015549dde, message: The referenced task was not found", "host": "ip-10-1-80-188.ap-northeast-1.compute.internal"}

관찰 사항:

모든 47개 에러 로그의 host는 동일: ip-10-1-80-188.ap-northeast-1.compute.internal
PID는 매 호출마다 증가 (2517446 → 2874016) — 별도의 Sidekiq worker process에서 실행
동일 시간대에 다른 ECS task들은 정상적으로 생명주기 관리되고 있었음 (task ba5019f1, 5658176b 등)

Fix Recommendation#

즉시 조치 (Critical)#

파일: app/models/aws_task.rb:118-119
InvalidParameterException catch 블록에서 "The referenced task was not found" 메시지를 감지하면 task가 이미 ECS에서 제거된 것으로 판단하고, DB에서 last_status를 STOPPED로 업데이트하고 clean_stale_task를 호출하여 archived_at을 설정해야 합니다. 이렇게 하면 cron scope에서 제외되어 반복 호출이 중단됩니다.

단기 개선 (1주 이내)#

fetch! 메서드의 by_force 파라미터 활용 (app/models/aws_task.rb:63): 현재 by_force 파라미터를 받지만 무시합니다. by_force: true일 때 fetchable? 가드를 우회하도록 수정하여, stop! 후 강제로 task 상태를 동기화할 수 있도록 해야 합니다.
stop! 메서드의 에러 핸들링 개선 (app/models/aws_task.rb:107-134): 모든 exception handler에서 단순 로깅만 하지 말고, exception 종류에 따라 적절한 후속 조치(DB 상태 업데이트, archive 등)를 수행하도록 리팩터링해야 합니다.

장기 개선 (재발 방지)#

Cron 멱등성 보장: Cupix::Cron::Job.clean_running_jobs가 ECS 상태와 DB 상태의 불일치를 감지하고 자동으로 reconciliation할 수 있는 로직을 추가합니다. 예를 들어, stop! 호출 전에 describe_tasks API로 현재 상태를 확인하는 방식입니다.
Stale task 자동 정리: archived_at이 설정되지 않은 오래된 task 레코드를 주기적으로 탐지하여 정리하는 별도 cron job 추가를 검토합니다.

Monitoring#

InvalidParameterException 반복 발생 감지를 위한 alert 추가:

text

service:cupixworks-worker status:error "InvalidParameterException" "The referenced task was not found" | count by @task.task_id > 3 in 30m

AwsTask 레코드 중 archived_at이 nil이면서 created_at이 24시간 이상 경과한 레코드 수를 모니터링하는 custom metric 추가를 권장합니다.

Risk Assessment#

Risk level: low
예상 복잡도: trivial — stop! 메서드의 InvalidParameterException catch 블록에 DB 상태 업데이트 및 clean_stale_task 호출 로직 추가만으로 해결 가능합니다. 기능적 영향 없이 불필요한 에러 로그만 제거합니다.