RCA: [Inotify] job: 50638, task not found

Overview#

What Happened#

2026-07-01 10:58 KST 무렵 cupixvista-api-migration-worker EB 인스턴스의 fswatch가 EFS ECI 신호 파일(/efs/ecis/50638.eci)을 감지하고 Cupix::Inotify::Job.notify_task_stopped(50638)를 실행했다. 해당 job은 이미 stopped 상태였기 때문에 task.present? && job.running? 조건이 실패하여 [Inotify] job: 50638, task not found 에러 로그가 남았다. 실제 task record는 DB에 존재했으며(aws_task_id 49783), 로그 메시지는 상태 불일치를 "task not found"로 잘못 표현한 것이다. 1건 발생, 사용자 영향 없음.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-01 10:56:45 KST — QMJob::getServerJob | job id: 50638, state: stopped — Queue Manager가 SQS 메시지로 job 50638을 pickup했으나 이미 stopped 상태로 관찰됨.
2. 2026-07-01 10:56:56 KST — QMAws::runTask | end - job id: 50638, task size: 1 — 그럼에도 ECS task가 launch되고 aws_task 레코드(id 49783)가 생성됨.
3. 2026-07-01 10:58:38 KST — EfsManager::saveJobEciFile | path: /efs/ecis/50638.eci, capture id : 19404 - end — ECS task 종료 알림용 ECI 파일이 EFS에 기록됨.
4. 2026-07-01 10:58:39, 10:58:42 KST — FSWATCH IN_CREATE (path: /efs/ecis/50638.eci, job_id: 50638) — fswatch 스크립트가 파일 생성을 감지, notify_task_stopped(50638) 실행(중복 2회).
5. 2026-07-01 10:58:48, 10:58:58 KST — [Inotify] job: 50638 found, state: stopped + [Inotify] job: 50638, task not found — job 상태가 stopped이라 job.running?가 false, else 분기 진입.

Error Log#

Datadog Logs

[Inotify] job: 50638, task not found

Impact#

• Service: cupixvista-api-migration-worker
• 발생 횟수: 1
• 최초 발생: 2026-07-01 10:58 KST
• 최근 발생: 2026-07-01 10:58 KST

지난 3일간 동일 error는 1개 job(50638)에서만 발생. 사용자 워크플로(capture 19404)에는 영향 없음 — job은 이미 정상적으로 stopped 상태에 진입한 뒤였고, after_transition any => :stopped 콜백(app/models/concerns/statable/job.rb:86-93)에서 job_stopped_callback + PullTaskWorker가 이미 실행되었을 것이므로 후속 처리 손실은 없다.

Root Cause Summary#

Cupix::Inotify::Job.notify_task_stopped는 fswatch가 EFS 상의 job ECI 파일을 감지했을 때 호출된다. 이 코드는 if task.present? && job.running? 조건이 참인 경우에만 run_task_stopped_callbacks를 실행하고, 그렇지 않으면 "[Inotify] job: X, task not found" 에러 로그를 남긴다. Job 50638의 경우 fswatch가 파일을 감지한 시점(10:58:39)에 이미 job의 state가 stopped(다른 경로로 이미 종료 처리 완료)였기 때문에 job.running? 체크가 false를 반환했다. 에러 메시지("task not found")는 실제로는 task 존재 여부가 아니라 "job이 running 상태가 아님"을 표현하는 misleading log이며, aws_task 레코드(id 49783)는 DB에 정상 존재한다. 즉 이는 정상 종료된 job에 대한 중복/후행 fswatch trigger에서 발생하는 무해한 상태 불일치이며, 실제 데이터 손실이나 기능 실패는 아니다.

Technical Analysis#

Code Path#

Entry point: fswatch bash loop → rails runner "Cupix::Inotify::Job.notify_task_stopped($JOB_ID)"

for eci in "$EFS_ECIS_DIR"/*
do
  JOB_ID=$(basename $eci .eci)
  if [ -f $eci ] ; then
    if [ -n $JOB_ID ] ; then
      echo "{ \"level\": \"info\", \"message\": \"FSWATCH IN_CREATE (path: $eci, job_id: $JOB_ID)\" }" >> $FSWATCH_LOG_PATH
      /bin/bash -l -c "bundle exec rails runner -e $RACK_ENV \"Cupix::Inotify::Job.notify_task_stopped($JOB_ID)\""
      # ...
      rm -f $eci

Failure point: lib/cupix/inotify/job.rb:12-19 — job.running? 조건이 실패하여 else 분기 진입.

def notify_task_stopped(job_id)
  job = ::Job.untrashed.find_by_id(job_id)

  if job.present?
    Cupix::Logger.info("[Inotify] job: #{job_id} found, state: #{job.state}")
    task = job.aws_tasks.last

    if task.present? && job.running?
      Cupix::Logger.info("[Inotify] task: #{task.task_id} found, job: #{job_id}")
      job.run_task_stopped_callbacks(task.task_id)
      task.fetched_by = 'inotify'
      task.save!
    else
      Cupix::Logger.error("[Inotify] job: #{job_id}, task not found")
    end
  else
    Cupix::Logger.error("[Inotify] job: #{job_id} not found")
  end
end

Job 상태 정의:

scope :pending, -> { where(state: %i[pending created]) }
scope :running, -> { where(state: [:running]) }
scope :stopping, -> { where(state: [:stopping]) }
scope :stopped, -> { where(state: [:stopped]) }

Stopped 상태 진입 시 실행되는 콜백(이미 aws_task 처리를 수행):

after_transition any => :stopped do |job, transition|
  job.aws_tasks.each do |task|
    PullTaskWorker.perform_in(20.second, task.id)
  end

  jid = JobCallbackWorker.perform_inline(job.id, 'job_stopped_callback')
  Cupix::Logger.info("invoke job_stopped_callback with jid: #{jid} for job #{job.id}")
end

기대 동작: fswatch가 ECI 파일을 감지 시점에 job이 여전히 running 상태이면 task_stopped_callbacks 실행. 이미 stopped이면 콜백은 이미 실행됐으므로 이 fswatch 트리거는 no-op이어야 함.

실제 동작: else 분기에서 Cupix::Logger.error(...)로 오탐성 에러 로그가 남음. 실제 상태 불일치는 없으며 데이터 무결성도 유지됨. 그러나 error 레벨 로그이므로 알림 파이프라인(error-sweeper 포함)에 잡힘.

Log Evidence#

Datadog query:

service:cupixvista-api-migration-worker status:error @environment:production "[Inotify] job: 50638, task not found"

전체 시퀀스 (모든 서비스, "50638" 검색):

10:56:45 info  QMJob::getServerJob | job id: 50638, state: stopped, jobable id: 19404, type: Capture, kind: create_capture
10:56:45 info  QMAws::runTask | begin - job id: 50638, task def: cupix-skat-master-production-arm
10:56:45 info  QMJob::updateTaskIdToJob | begin - job id: 50638, task length: 0
10:56:56 info  QMAws::runTask | end - job id: 50638, task size: 1
10:56:56 info  [aws_task_stopped] aws_task_model_id: 49783, saved_changes: {"id"=>[nil, 49783], "task_id"=>[nil, "arn:aws:ecs:us-west-2:619071347432:task/cupix-tesla-ece/93d0ad6cb8d54bcbb92efdab917d6d2e"], "job_id"=>[nil, 50638], ...}
10:56:56 info  QMJob::updateTaskIdToJob | end - job id: 50638, task arn: arn:aws:ecs:us-west-2:619071347432:task/cupix-tesla-ece/93d0ad6cb8d54bcbb92efdab917d6d2e
10:56:58 info  [200] PUT /api/v1/jobs/50638/actions/skat-master/running
10:58:38 info  EfsManager::saveJobEciFile | path: /efs/ecis/50638.eci, capture id : 19404 - end
10:58:39 info  FSWATCH IN_CREATE (path: /efs/ecis/50638.eci, job_id: 50638)
10:58:42 info  FSWATCH IN_CREATE (path: /efs/ecis/50638.eci, job_id: 50638)   ← 중복 trigger
10:58:47 info  FSWATCH - finished to notify_task_stopped(50638)
10:58:47 info  FSWATCH - delete /efs/ecis/50638.eci
10:58:48 info  [Inotify] job: 50638 found, state: stopped                     ← job이 이미 stopped
10:58:48 error [Inotify] job: 50638, task not found                           ← else 분기 진입
10:58:50 info  FSWATCH - finished to notify_task_stopped(50638)
10:58:50 info  FSWATCH - delete /efs/ecis/50638.eci
10:58:58 info  [Inotify] job: 50638 found, state: stopped
10:58:58 error [Inotify] job: 50638, task not found                           ← 대상 로그

동일 error 발생 빈도(지난 3일):

Query: service:cupixvista-api-migration-worker "task not found"
Result: 1 log (only this cluster)

참고 — 정상 케이스와의 비교 (state: running):

10:41:55 info  [Inotify] job: 50690 found, state: running
10:41:55 info  [Inotify] task: arn:aws:ecs:us-west-2:...:task/cupix-tesla-ece/cf2889... found, job: 50690
10:41:55 info  [aws_task_stopped] aws_task_model_id: 49837, saved_changes: {"sys"=>[{}, {"fetched_by"=>"inotify"}], ...}

정상 케이스에서는 state: running → task found → fetched_by: inotify 업데이트가 이어진다.

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

없음 — 실제 데이터 무결성/기능 이슈가 아니므로 프로덕션 긴급 조치 불필요.

단기 개선 (1주 이내)#

• lib/cupix/inotify/job.rb:12-19 로그 정확성 개선. 현재 "task not found" 문구는 실제 원인(job.running? = false 또는 task.present? = false)을 구분하지 못한다. else 분기를 세분화하여:
  • task.blank? 인 경우: 기존과 유사한 "task not found" 로그 (하지만 error보다는 warn 수준)
  • !job.running? 인 경우: Cupix::Logger.warn("[Inotify] job: #{job_id} already in state: #{job.state}, skipping") — error → warn 강등
• 이유: 정상 종료된 job에 대한 후행 fswatch trigger는 시스템 설계상 예상 가능한 시나리오이므로 error 레벨은 부적절하다. warn 강등 시 error-sweeper 파이프라인의 오탐 알림을 줄일 수 있다. Memory에도 이런 패턴(운영상 예상 시나리오는 warn) 관련 노트가 있다.

장기 개선 (재발 방지)#

• fswatch → notify_task_stopped 파이프라인의 idempotency 재검토. ECI 파일 생성 이벤트가 여러 번 발생(현재 사례에서 39초, 42초 두 번의 IN_CREATE)하는 상황은 EFS의 특성상 불가피할 수 있다. notify_task_stopped가 이미 처리된 job에 대해서는 조용히 no-op으로 종료하도록 명시하는 것이 바람직하다.
• job.running? 대신 aws_tasks.running 스코프로 상태 확인 검토. 실제 관심사는 "아직 pull되지 않은 running task가 있는가"이므로, job 자체의 state가 아닌 task 상태로 조건을 판단하면 오탐이 줄어든다. 다만 도메인 이해가 필요하므로 조사 후 결정.
• EfsManager가 duplicate ECI 파일 생성 방지. 로그상 10:58:39와 10:58:42에 IN_CREATE가 두 번 감지된 것을 볼 때, 생성/재생성 이슈일 가능성. Producer 측 원인 규명 필요.

Monitoring#

writing-datadog-monitoring-queries 가이드에 따라 timeseries 위젯용 쿼리(파이프/monitor-only 문법 없이):

service:cupixvista-api-migration-worker status:error "[Inotify]" "task not found"

service:cupixvista-api-migration-worker "[Inotify]" "state: stopped"

• 첫 번째 쿼리: 동일 이벤트 재발 추적. 발생률이 급등하면 job 종료 처리 파이프라인에 실제 문제 발생 가능성.
• 두 번째 쿼리: job.running? 실패 조건 자체의 빈도. 정상 케이스(state: running)와 대비하여 stopped-hit 비율을 확인.

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial (로그 레벨/메시지 조정만) ~ standard (idempotency 및 조건 로직 재설계 시)