RCA: Failed to create event: Permission denied @ rb_sysopen - tesla_production-event.log

Overview#

What Happened#

2026-04-23 15:02~15:55 UTC 사이에 cupixworks-worker 서비스(us-west-2)에서 Eventable::Events::Update.create_event 실행 시 Cupix::Event 싱글턴 로거가 /var/app/current/log/tesla_production-event.log 파일을 열지 못해 Permission denied @ rb_sysopen 에러가 반복 발생했다. 동일 호스트(ip-10-1-18-233)에서 배포 버전이 바뀌어도 지속적으로 발생했으며, 모두 Bim 모델(ID: 19207)의 processing_failed update 이벤트에서 트리거되었다.

Quick Facts#

Timeline#

1. 2026-04-23T15:02:13Z -- 최초 발생 (deploy 20260423T0910Z0-c44310a2, PID 3905564)
2. 2026-04-23T15:35:28Z -- 새 배포 후에도 재발 (deploy 20260423T1535Z0-c44310a2, PID 352174)
3. 2026-04-23T15:55:27Z -- 클러스터 파일 기준 마지막 발생
4. 2026-04-23T16:15:27Z -- Datadog 확장 검색 기준 마지막 발생 (deploy 20260423T1615Z0-c44310a2, PID 441987)
5. 2026-04-24 -- RCA 분석 완료

Error Log#

Datadog Logs

Failed to create event: Permission denied @ rb_sysopen - /var/app/current/log/tesla_production-event.log

Impact#

• Service: cupixworks-worker
• 발생 횟수: 14 (Datadog 확장 검색 기준, 클러스터 파일 기준 10)
• 최초 발생: 2026-04-23T15:02:13.270Z
• 최근 발생: 2026-04-23T15:55:27.118Z
• 영향 범위: 단일 호스트(ip-10-1-18-233)에서만 발생. Bim 모델(ID 19207)의 이벤트 로깅이 실패하여 event log 파일에 기록되지 않았으나, Cupix::EventService.publish_event(line 17)는 이 에러 이전에 실행되므로 이벤트 자체는 정상 발행됨. 다만 raise e(line 21)로 인해 model.event_created!(line 23)가 호출되지 않아 동일 이벤트가 반복 트리거될 수 있음.

Root Cause Summary#

postdeploy 스크립트 70_restart_sidekiq.sh가 tesla_production-json.log 파일만 touch로 사전 생성하고, tesla_production-event.log 파일은 사전 생성하지 않는다. chown -R $EB_APP_USER:$EB_APP_USER $APP_LOG_DIR 명령으로 log 디렉토리 소유권을 변경하지만, 특정 호스트(ip-10-1-18-233)에서 Elastic Beanstalk 배포 과정에서 /var/app/current/log/ 디렉토리의 쓰기 권한이 app user에게 제대로 적용되지 않아, Cupix::Event 싱글턴이 최초 인스턴스화될 때 ActiveSupport::Logger가 rb_sysopen으로 event log 파일을 생성하지 못한다. 이 문제가 동일 호스트에서 5회 이상 배포를 거쳐도 지속되었다는 점에서, 해당 호스트의 파일시스템 또는 배포 환경에 구조적 문제가 있을 가능성이 높다.

Technical Analysis#

Code Path#

1. Entry point: Bim 모델 업데이트 시 event_params가 설정되어 Eventable::Events::Update.create_event 호출

def create_event(model)
  return nil if invalid_event?(model)

  begin
    event = _create_event(model)
    reason = extract_reason(event, model)
    properties = build_properties(model)

    track_event(model, reason, properties)

    Cupix::EventService.publish_event([event])
    Cupix::Event.publish(event.serializable_hash(stringify_nested_fields: false))
  rescue StandardError => e
    Cupix::Logger.error("Failed to create event: #{e.message}", function: __method__, class: self.name, model: model.class.to_s, id: model.id, event_params: model.event_params, error: e)
    raise e
  else
    model.event_created!
    event
  end
end

2. Failure point: line 18에서 Cupix::Event.publish를 호출하면, Cupix::Event 싱글턴이 아직 인스턴스화되지 않은 경우 initialize가 실행된다.

require 'singleton'

module Cupix
  class Event < ActiveSupport::Logger
    include Singleton

    def initialize
      super("#{Rails.root}/log/tesla_#{Rails.env}-event.log", 'daily')
      self.formatter = Cupix::EventFormatter.new
      self.level = $CUPIX_LOGGER_LEVEL || Logger::INFO
    end

    def publish(event_body)
      info(event_body)
    end

    class << self
      delegate :publish, to: :instance
    end
  end
end

• line 8의 super(...) 호출이 ActiveSupport::Logger.new → Ruby Logger.new → File.open(path, 'a') 를 실행하며, 이 시점에서 rb_sysopen 에러가 발생한다.

3. 에러 전파 경로: Cupix::Event.publish → Cupix::Event.instance (싱글턴 최초 생성) → initialize → super → rb_sysopen 실패 → Errno::EACCES → base.rb:19의 rescue StandardError 캐치 → Cupix::Logger.error로 로깅 후 raise e (line 21)

4. 부작용: line 17의 Cupix::EventService.publish_event은 성공하지만, line 18에서 예외 발생 시 line 23의 model.event_created!가 실행되지 않아 같은 이벤트가 재시도 시 다시 트리거될 수 있다.

5. 배포 스크립트 분석:

SIDEKIQ_LOG="/var/log/sidekiq_worker.log"
APP_LOG_DIR="/var/app/current/log"
APP_LOG_FILEPATH="$APP_LOG_DIR/tesla_$RACK_ENV-json.log"

touch $SIDEKIQ_LOG $APP_LOG_FILEPATH
chown -R $EB_APP_USER:$EB_APP_USER $SIDEKIQ_LOG $APP_LOG_DIR

• touch는 tesla_production-json.log만 생성하고, tesla_production-event.log와 tesla_request_production-json.log는 사전 생성하지 않는다.
• chown -R이 /var/app/current/log 디렉토리 전체를 app user 소유로 변경하므로, 정상적인 경우라면 app user가 새 파일을 생성할 수 있어야 한다.
• 그러나 단일 호스트에서 반복 발생하므로, 해당 호스트의 /var/app/current/log 디렉토리에 chown이 적용되지 않는 특수한 상황(예: mount 문제, symlink 경합, SELinux/AppArmor 정책)이 존재할 수 있다.

Log Evidence#

Datadog에서 아래 쿼리로 검색:

service:cupixworks-worker status:error "Failed to create event" @environment:production

14건의 로그 모두 동일한 패턴:

{
  "message": "Failed to create event: Permission denied @ rb_sysopen - /var/app/current/log/tesla_production-event.log",
  "level": "error",
  "class": "Eventable::Events::Update",
  "function": "create_event",
  "model": "Bim",
  "id": 19207,
  "event_params": { "reason": "processing_failed", "action": "update" },
  "host": "ip-10-1-18-233.us-west-2.compute.internal",
  "service": "cupixworks-worker",
  "service_role": "worker",
  "tenant": "cupix"
}

주요 관찰:

• 단일 호스트: 모든 14건이 ip-10-1-18-233에서 발생
• 다중 배포 관통: 20260423T0910Z0 → 20260423T1535Z0 → 20260423T1545Z0 → 20260423T1555Z0 → 20260423T1605Z0 → 20260423T1615Z0 (6개 배포 버전)
• PID 변경 확인: 3905564 → 352174 → 373260 → 389984 → 414447 → 441987 (배포마다 새 프로세스)
• 동일 모델/이벤트: 모두 Bim ID 19207, processing_failed + update action
• 쌍(pair) 패턴: 매 10분마다 2건씩 발생 — Cupix::EventService.publish_event 성공 후 Cupix::Event.publish 실패, event_created! 미호출로 인한 재시도 가능성

비에러 로그 검색:

service:cupixworks-worker "tesla_production-event" @environment:production

결과: 0건 — event log 파일이 정상적으로 기록된 적이 없음 (이 파일의 내용은 Filebeat로 수집되어 별도 인덱스에 저장되므로 Datadog에는 미존재)

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• .platform/hooks/postdeploy/70_restart_sidekiq.sh:13-15: touch 명령에 tesla_$RACK_ENV-event.log 파일을 추가하여 event log 파일도 사전 생성
• 동일하게 71_restart_transfer_sidekiq.sh:13-15와 72_restart_migration_sidekiq.sh:13-15에도 적용
• 해당 호스트 ip-10-1-18-233의 /var/app/current/log/ 디렉토리 퍼미션 및 소유권을 직접 확인하여 구조적 문제 여부 진단

단기 개선 (1주 이내)#

• Cupix::Event.initialize에 방어적 파일 생성 로직 추가: FileUtils.touch(path) 후 super 호출하거나, 파일 생성 실패 시 예외를 삼키고 /dev/null fallback 로거 사용
• Eventable::Events::Base.create_event의 에러 처리에서 Cupix::Event.publish 실패가 raise e로 전파되지 않도록 수정 — event file 로깅 실패는 이벤트 생성 자체를 실패시킬 만큼 critical하지 않음. Cupix::EventService.publish_event이 이미 성공한 상태에서 file logging 실패로 event_created!가 호출되지 않는 것은 불필요한 재시도를 유발

장기 개선 (재발 방지)#

• 모든 커스텀 로거(Cupix::Event, Cupix::Logger, lograge)가 사용하는 log 파일 목록을 postdeploy 스크립트에서 중앙 관리하도록 통합. 새 로거 추가 시 deploy 스크립트 업데이트 누락을 방지
• Cupix::Event 싱글턴의 lazy initialization을 eager initialization(Rails initializer)으로 변경하여 배포 시점에 파일 생성 문제를 조기 발견

Monitoring#

추가할 메트릭/알림:

service:cupixworks-worker status:error "Permission denied @ rb_sysopen" @environment:production

• 위 쿼리로 Datadog monitor 생성, threshold 1건 이상 시 알림
• host별 그룹핑으로 특정 호스트 문제 빠르게 식별

service:cupixworks-worker status:error "Failed to create event" @environment:production

• event 생성 실패 전체를 모니터링하는 별도 알림 추가

Risk Assessment#

• Risk level: medium -- 이벤트 발행(Cupix::EventService.publish_event)은 성공하므로 비즈니스 로직에 직접적 영향은 제한적이나, event_created! 미호출로 인한 중복 이벤트 발행 가능성 및 event log 데이터 누락이 있음
• 예상 복잡도: trivial -- postdeploy 스크립트에 touch 한 줄 추가가 핵심 수정이며, 방어적 에러 처리 개선은 소규모 코드 변경