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

Error Log#

Datadog Logs

[Inotify] job: 1018639, task not found

Impact#

• Service: cupixworks-worker
• 발생 횟수: 1
• 최초 발생: 2026-04-16T17:45:35.975Z
• 최근 발생: 2026-04-16T17:45:35.975Z

Root Cause Summary#

FSWATCH가 EFS에서 1018639.eci 파일 생성을 감지하고 Cupix::Inotify::Job.notify_task_stopped(1018639)를 호출했으나, 해당 시점에 job의 state가 이미 stopped였기 때문에 job.running? 조건이 false를 반환하여 error 분기로 진입했다. 이 에러 로그의 메시지 task not found는 실제로 AwsTask 레코드가 없는 것이 아니라, job이 running 상태가 아닐 때 task를 처리하지 않는 조건 분기에서 발생한 것이다. 실제로 8초 뒤(02:45:43 KST) AwsTask 모델의 after_save 콜백에 의해 run_task_stopped_callbacks가 별도 경로로 정상 실행되었으므로 데이터 영향은 없다.

Technical Analysis#

Code Path#

• Entry point: FSWATCH bash 스크립트 (005-fswatch-settings.config:34)가 EFS 디렉토리를 polling하여 .eci 파일을 감지하면 Cupix::Inotify::Job.notify_task_stopped(JOB_ID)를 Rails runner로 호출한다.

# .ebextensions/005-fswatch-settings.config:34
/bin/bash -l -c "bundle exec rails runner -e $RACK_ENV \"Cupix::Inotify::Job.notify_task_stopped($JOB_ID)\""

• Cupix::Inotify::Job.notify_task_stopped에서 job을 조회하고 상태를 확인한다:

# lib/cupix/inotify/job.rb:5-18
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
  end
end

• Failure point: lib/cupix/inotify/job.rb:12 — job.running?이 false를 반환. job의 state가 이미 stopped였기 때문이다.

• 별도 경로: AwsTask#after_save 콜백에서 task_stopped? 조건 충족 시 run_task_stopped_callbacks가 호출되어 실제 후속 처리(action state 변경, UploadCpcLogWorker 실행)가 수행됨:

# app/models/aws_task.rb:28-30
after_save do |task|
  job.run_task_stopped_callbacks(task.task_id) if task_stopped?
end

• 기대 동작: FSWATCH가 .eci 파일을 감지하면 job이 아직 running 상태이고, aws_tasks.last가 존재하여 run_task_stopped_callbacks를 실행한다.
• 실제 동작: job의 state가 이미 stopped로 전환된 후에 FSWATCH 이벤트가 처리되어 running? 체크에서 실패했다. 하지만 AwsTask의 after_save 콜백이 별도로 run_task_stopped_callbacks를 트리거하여 후속 처리는 정상 수행되었다.

Log Evidence#

사용한 Datadog 쿼리:

service:cupixworks-worker "1018639"
Time: 2026-04-16T16:00:00Z ~ 2026-04-16T19:00:00Z

타임라인 (KST 기준):

핵심 로그:

[Inotify] job: 1018639 found, state: stopped

job의 state가 stopped임을 명확히 보여준다. Cupix::Inotify::Job.notify_task_stopped의 조건 task.present? && job.running?에서 job.running?이 false가 되어 else 분기(task not found 에러)로 진입했다.

02:45:43에 run_task_stopped_callbacks가 정상 실행된 것은 AwsTask 모델의 after_save 콜백(aws_task.rb:29)을 통한 별도 경로이다. 이 경로는 job의 state를 확인하지 않고 AwsTask의 last_status가 STOPPED로 변경될 때 트리거된다.

지난 7일간 동일 에러 검색 결과 이 1건만 발견됨 — 드물게 발생하는 타이밍 이슈이다.

service:cupixworks-worker status:error "Inotify" "task not found"
Time: 2026-04-10T00:00:00Z ~ 2026-04-17T00:00:00Z
Result: 1건

Fix Recommendation#

즉시 조치 (Critical)#

없음. 후속 처리(run_task_stopped_callbacks)가 AwsTask after_save 콜백을 통해 정상 수행되었으므로 데이터 손실이나 기능 장애는 없다.

단기 개선 (1주 이내)#

• 파일: lib/cupix/inotify/job.rb:12
• 현재 job.running? 조건이 실패하면 task not found라는 오해의 소지가 있는 에러 메시지를 출력한다. 실제 원인은 "task가 없는 것"이 아니라 "job이 이미 stopped 상태"인 것이다.
• else 분기의 에러 메시지를 job.running? 실패와 task.present? 실패를 구분하도록 변경하고, job이 이미 stopped인 경우는 error가 아닌 info/warn 레벨로 로깅하는 것이 적절하다. 이렇게 하면 불필요한 에러 알림을 방지할 수 있다.

장기 개선 (재발 방지)#

• FSWATCH polling과 AwsTask after_save 콜백이라는 두 가지 독립적인 경로가 동일한 run_task_stopped_callbacks를 호출하는 구조이다. race condition에 의해 한쪽이 실패해도 다른 쪽이 보완하므로 현재는 안전하지만, 에러 로그의 정확성을 위해 조건 분기 메시지를 개선할 필요가 있다.
• notify_task_stopped에서 job이 이미 stopped 상태이면 AwsTask 경로에서 이미 처리되었거나 처리될 것이므로, early return으로 처리하는 것을 고려.

Monitoring#

• 현재 에러가 드물게(7일간 1건) 발생하므로 별도 알림 추가는 불필요.
• 에러 메시지 개선 후 아래 쿼리로 모니터링:

service:cupixworks-worker status:error "Inotify"

Risk Assessment#

• Risk level: low
• 예상 복잡도: trivial — else 분기의 조건 분리 및 로그 레벨 변경만 필요