ES /docs

Forbidden

RCA: Forbidden — NotificationService recipe/subscription cleanup

Overview#

What Happened#

2026-07-18 10:00~10:02 KST, cupixworks-migration-worker (tesla Sidekiq migration role) 인스턴스에서 Cupix::NotificationService#delete_user_recipe 와 #unsubscribe 호출이 downstream notification-service API Gateway 로부터 HTTP 403 Forbidden 을 반환받아 73건의 error 로그가 발생했다. 트리거는 동시에 실행된 만료 편집자 권한 정리 cron (Cupix::Cron::EditingPermission.revoke_expired_editor_permissions) 이 대량의 FacilityPermission 을 destroy 하면서 이어진 pub-sub 정리 흐름이다.

Quick Facts#

Field Value
exception.class RestClient::ExceptionWithResponse (rescued, not raised)
exception.message Forbidden / recipe deletion failed: {"message":"Forbidden"}
top_frame lib/cupix/notification_service.rb:65 (delete_user_recipe rescue) / lib/cupix/notification_service.rb:110 (unsubscribe rescue)
runtime Rails / Sidekiq (tesla)
deploy production-us-west-2-20260718T0100Z0-f2b18e95-cupixworks
env production, us-west-2

Affected Teams#

Team / Domain Error Count Impact
tesla cupixworks-migration-worker (notification cleanup) 73 만료 편집자에 대한 email recipe 삭제 및 facility 알림 unsubscribe 가 downstream 에서 거부됨. 사용자 대면 요청은 실패하지 않고, 알림 side effect 만 정리 누락

Timeline#

  1. 2026-07-18 10:00 KST — Cupix::Cron::EditingPermission.revoke_expired_editor_permissions 실행 시작, 만료된 편집자 FacilityPermission 대량 destroy 개시
  2. 2026-07-18 10:00:49 KST (first_seen) — 첫 Forbidden 로그 발생 (Cupix::NotificationService)
  3. 2026-07-18 10:02:45~10:02:47 KST — [Permission][Cleanup] FacilityPermission destroyed. Checking parent permissions for accessor User(...) 대량 info 로그, 이어서 unsubscribe / delete_user_recipe 실패 로그가 연속 발생
  4. 2026-07-18 10:02:47 KST (last_seen) — 마지막 Forbidden 로그, 총 73건

Error Log#

Datadog Logs

text
Forbidden

두 가지 로그 라인 패턴이 관측됨.

Cupix::NotificationService#unsubscribe 실패json
{
  "message": "Forbidden",
  "status": "error",
  "class": "Cupix::NotificationService",
  "function": "unsubscribe",
  "facility_key": "36dufc",
  "service_role": "migrationworker",
  "service": "cupixworks-migration-worker",
  "tenant": "cupix"
}
Cupix::NotificationService#delete_user_recipe 실패json
{
  "message": "recipe deletion failed: {\"message\":\"Forbidden\"}",
  "status": "error",
  "class": "Cupix::NotificationService",
  "function": "delete_user_recipe",
  "recipe_name": "record_processing_completed",
  "facility_key": "36dufc",
  "service_role": "migrationworker",
  "service": "cupixworks-migration-worker",
  "tenant": "cupix"
}

Impact#

  • Service: cupixworks-migration-worker
  • 발생 횟수: 73
  • 최초 발생: 2026-07-18 10:00 KST
  • 최근 발생: 2026-07-18 10:02 KST

RestClient::ExceptionWithResponse 는 NotificationService 내부에서 rescue 되고 false 를 반환할 뿐 재던지지 않으므로 상위 Sidekiq job 은 실패로 마킹되지 않는다. 다만 downstream 정리가 skip 되어 만료된 편집자의 email recipe / facility subscription 이 notification-service 쪽에 남아있을 수 있다 (정합성 drift).

Root Cause Summary#

Cupix::Cron::EditingPermission.revoke_expired_editor_permissions 가 Facility#unshare(user) 를 통해 편집자 권한이 만료된 FacilityPermission 을 destroy 하면, UserRecipeCleaner / SubscriptionCleaner pub-sub subscriber 가 해당 user 를 caller 로 삼아 downstream notification-service 에 recipe 삭제/구독 해제 HTTP 요청을 보낸다. 요청의 x-cupix-auth 헤더는 user.api_token 인데, 이 user 들은 편집자 세션이 오래 전에 종료된 (>1개월) 만료 대상자이므로 notification-service Lambda authorizer 가 tesla /api/v1/me 로 프록시 인증을 시도할 때 200 을 받지 못한다 (isAuthorized: false). API Gateway 는 기본 응답 403 {"message":"Forbidden"} 을 반환하고, tesla 는 이를 RestClient::ExceptionWithResponse 로 rescue 한 뒤 error 로그를 남긴다. 즉, "만료된 사용자의 토큰으로 downstream cleanup 을 시도" 하는 것이 근본 원인이며 cron 이 배치성으로 destroy 를 몰아 실행하면 오탐형 error 가 폭증한다.

Technical Analysis#

Code Path#

Entry point — 만료 편집자 권한 정리 cron:

lib/cupix/cron/editing_permission.rb:45-70ruby
completed_pairs.pluck(:editor_id, :facility_id).each do |user_id, facility_id|
  next if active_set.include?([user_id, facility_id])

  last_updated = last_completed_map[[user_id, facility_id]]
  next if last_updated.present? && last_updated > 1.month.ago

  next unless permission_set.include?([user_id, facility_id])

  facility = ::Facility.find_by(id: facility_id)
  next if facility.nil?

  user = ::User.find_by(id: user_id)
  next if user.nil?

  Cupix::Logger.info("Revoking expired editor permission: user=#{user_id}, facility=#{facility_id}",
                     class: name, function: __method__, module: 'Cupix::Cron')
  facility.unshare(user)  # FacilityPermission destroy triggers pub-sub cascade
  count += 1
rescue StandardError => e
  Cupix::Logger.error("Failed to revoke editor permission: user=#{user_id}, facility=#{facility_id}, error=#{e.message}",
                      class: name, function: __method__, module: 'Cupix::Cron')
end

Pub-sub cascade — FacilityPermission destroy 시 recipe cleanup:

lib/cupix/pub_sub/subscribers/user_recipe_cleaner.rb:24-42ruby
def _delete_recipes_for_facility_permission(model)
  return false unless model.accessor_type == ::User.name

  user = model.accessor
  team_id = model.facility.team_id
  facility_key = model.facility.key

  _delete_recipes(user: user, team_id: team_id, facility_key: facility_key)
end

def _delete_recipes(opts = {})
  %w[
    record_preview_ready
    record_processing_completed
    facility_new_project
  ].each do |recipe_name|
    Cupix::NotificationService.new(user: opts[:user]).delete_user_recipe(recipe_name, team_id: opts[:team_id], facility_key: opts[:facility_key])
  end
end

Pub-sub cascade — subscription cleanup:

lib/cupix/pub_sub/subscribers/subscription_cleaner.rb:11-22ruby
def _delete_subscriptions_by_facility_permission(model)
  return false unless model.accessor_type == ::User.name

  user = model.accessor
  facility_key = model.facility.key

  _delete_subscription(user: user, facility_key: facility_key)
end

def _delete_subscription(opts = {})
  Cupix::NotificationService.new(user: opts[:user]).unsubscribe(facility_key: opts[:facility_key])
end

Failure point — downstream HTTP 호출과 rescue:

lib/cupix/notification_service.rb:55-68ruby
response = Cupix::HttpClient.delete(
  "#{@service_url}/api/recipes/v2/#{recipe['id']}",
  {
    content_type: :json,
    'x-cupix-auth': @user.api_token
  }
)

Cupix::Logger.info("recipe deleted: #{response.body}", class: self.class.name, function: __method__, recipe_name: recipe_name, facility_key: facility_key)
rescue RestClient::ExceptionWithResponse => e
  Cupix::Logger.error("recipe deletion failed: #{e.response.body}", class: self.class.name, function: __method__, recipe_name: recipe_name, facility_key: facility_key)

  false
end
lib/cupix/notification_service.rb:95-113ruby
def unsubscribe(facility_key: nil)
  return if @service_url.nil?

  begin
    response = Cupix::HttpClient.delete(
      "#{@service_url}/api/v1/subscriptions?model_type=Facility&model_id=#{facility_key}",
      {
        content_type: :json,
        'x-cupix-auth': @user.api_token
      }
    )
    Cupix::Logger.info("subscription of #{@user.email} on Facility #{facility_key} deleted", class: self.class.name, function: __method__, facility_key: facility_key)

    true
  rescue RestClient::ExceptionWithResponse => e
    Cupix::Logger.error(e.response, class: self.class.name, function: __method__, facility_key: facility_key)

    false
  end
end

Downstream authorizer — 403 의 실제 발생 지점:

applications/notification-service/src/lambda/authorizer.ts:11-43typescript
const token = event.headers['x-cupix-auth'];
if (!token) {
  throw new Error('Unauthorized; token not found');
}

const response = await CPUtils.fetchWithRetry(
  `https://api.${DOMAIN_NAME}/api/v1/me?fields=id,firstname,lastname,email,team`,
  {
    headers: { 'x-cupix-auth': token }
  }
);

if (response.status !== 200) {
  throw new Error('Unauthorized; permission denied');
}
// ...
} catch (error: any) {
  console.log('Error authorizing: ', error.message);
  return { isAuthorized: false };  // API Gateway 가 403 {"message":"Forbidden"} 응답
}

기대 동작: 만료된 편집자 권한을 정리하면서 downstream 알림 side effect 도 정리되어야 한다.

실제 동작: 만료 대상 user 의 api_token 은 /api/v1/me 를 통과하지 못해 (세션 만료/사용자 상태 등), notification-service authorizer 가 isAuthorized: false 를 반환. API Gateway 가 기본 403 Forbidden 을 응답. 결과적으로 정리 요청이 downstream 에서 거부되며 tesla 는 노이즈성 error 로그만 남긴다. Sidekiq job 자체는 실패하지 않음 (rescue 후 false 반환).

Log Evidence#

Datadog 쿼리 — cluster URL 과 동일:

text
service:cupixworks-migration-worker status:error @environment:production "Forbidden"

증거 1 — Forbidden 에러 로그 (unsubscribe):

json
{
  "@timestamp": "2026-07-18T01:02:47.422Z",
  "service": "cupixworks-migration-worker",
  "service_role": "migrationworker",
  "class": "Cupix::NotificationService",
  "function": "unsubscribe",
  "facility_key": "36dufc",
  "message": "Forbidden",
  "level": "error",
  "host": "ip-10-1-144-200.us-west-2.compute.internal",
  "dd.version": "production-us-west-2-20260718T0100Z0-f2b18e95-cupixworks"
}

증거 2 — recipe deletion failed 에러 로그:

json
{
  "@timestamp": "2026-07-18T01:02:47.422Z",
  "service": "cupixworks-migration-worker",
  "class": "Cupix::NotificationService",
  "function": "delete_user_recipe",
  "recipe_name": "record_processing_completed",
  "facility_key": "36dufc",
  "message": "recipe deletion failed: {\"message\":\"Forbidden\"}",
  "level": "error"
}

증거 3 — 동일 시각 사전 이벤트 (cron → FacilityPermission destroy → pub-sub):

Datadog 쿼리:

text
service:cupixworks-migration-worker (FacilityPermission OR "facility_permission")

로그 (info):

text
2026-07-18 10:02:47  info  Revoking expired editor permission: user=48645, facility=21789
                            class=Cupix::Cron::EditingPermission function=revoke_expired_editor_permissions
2026-07-18 10:02:47  info  [Permission][Cleanup] WorkspacePermission being destroyed. Cleaning up children A permissions for accessor User(48645)
2026-07-18 10:02:47  info  [Permission][Cleanup] FacilityPermission destroyed. Checking parent permissions for accessor User(48645)
2026-07-18 10:02:47  info  Deleting cached_permission on user 48645  class=User function=flush_cached_permission
2026-07-18 10:02:47  error Forbidden  class=Cupix::NotificationService function=unsubscribe facility_key=...
2026-07-18 10:02:47  error recipe deletion failed: {"message":"Forbidden"}  class=Cupix::NotificationService function=delete_user_recipe

증거 4 — 재발 이력. 상태 보드는 동일 scope 에서 최근 재발을 기록:

text
2026-07-18-svc-cupixworks-migration-worker--unknown-1  (오늘, 이 cluster + edc458b4)
2026-07-13-svc-cupixworks-migration-worker--unknown-1  (5일 전, 5개 cluster)

07-13 재발은 동일 cron schedule 상에서 반복될 수 있는 클래스의 문제임을 시사 (uncertain — 각 재발이 정확히 같은 원인인지는 별도 검증 필요).

Hypotheses Considered#

# Hypothesis Evidence for Evidence against Verdict
H1 만료 편집자 정리 cron 이 FacilityPermission 을 destroy 하며 만료된 user 의 api_token 으로 downstream 호출 → notification-service authorizer 가 /api/v1/me 200 을 받지 못해 API Gateway 가 403 Forbidden 반환 (a) 동일 시각 Cupix::Cron::EditingPermission#revoke_expired_editor_permissions info 로그, (b) [Permission][Cleanup] FacilityPermission destroyed info 로그가 각 error 직전에 위치, (c) NotificationService#unsubscribe / delete_user_recipe 호출부는 x-cupix-auth: @user.api_token 사용 (notification_service.rb:20,59,83,103), (d) downstream authorizer 는 /api/v1/me 비-200 시 isAuthorized: false 반환 → API Gateway 기본 403 body 는 {"message":"Forbidden"} (authorizer.ts:31-42) — Confirmed
H2 $CUPIX_NOTIFICATION_SERVICE_URL 가 nil 또는 잘못 설정되어 실패 — NotificationService#delete_user_recipe 는 return if @service_url.nil? 로 early-return 하며 error 로그가 안 남는다 (notification_service.rb:49). 실제로 로그가 남았으므로 URL 은 설정됨 Rejected
H3 notification-service 다운스트림 자체가 outage (5xx) — 관측된 응답은 API Gateway 표준 {"message":"Forbidden"} 403 body. recipe.proxy.ts 는 ItemNotFoundException 을 403 으로 매핑하지만 body 는 "Item not found" 이며 일치하지 않음 (recipe/proxy.ts:99-103). 인증 단계 실패임 Rejected
H4 RestClient 자체가 인증서/네트워크 에러 — 예외가 RestClient::ExceptionWithResponse 로 rescue 되고 e.response.body 가 JSON 문자열로 출력됨 → HTTP 응답이 정상 수신됨. 네트워크 계층 문제 아님 (notification_service.rb:64-67) Rejected
H5 만료 대상 user 가 cycle_state_deleted? (soft-deleted) 이라 /api/v1/me 가 401/403 반환 (a) revoke 대상 조건은 "마지막 완료 편집이 1개월 이상 이전" 이므로 계정이 이후 비활성/삭제됐을 가능성 큼, (b) tesla User.refresh_api_token 은 before_create 만 실행되므로 로테이션 안 됨 (user.rb:100-137) — 그래도 계정 상태에 의해 인증이 거부될 수 있음 개별 user 의 상태를 로그로 직접 확인하지는 못함 — uncertain, DB 확인 필요 Inconclusive (probable sub-cause of H1)

Fix Recommendation#

즉시 조치 (Critical)#

  • error → warn 다운그레이드 (403 한정): lib/cupix/notification_service.rb:65 (delete_user_recipe rescue) 와 lib/cupix/notification_service.rb:110 (unsubscribe rescue) 에서 downstream 403 응답은 만료 사용자 정리 시나리오에서 정상 발생 가능한 조건이므로 e.response&.code == 403 인 경우에만 Cupix::Logger.warn 으로 하향. 그 외 상태코드는 error 유지 (rate-limit / downstream outage 를 놓치지 않기 위함). 근거: rescue 후 false 반환만 하고 job 실패로 이어지지 않으므로 error 레벨 유지가 알림 과다를 유발.

단기 개선 (1주 이내)#

  • Subscriber 단에서 caller 사전 검증: UserRecipeCleaner._delete_recipes_for_facility_permission (user_recipe_cleaner.rb:24) 및 SubscriptionCleaner._delete_subscriptions_by_facility_permission (subscription_cleaner.rb:11) 에서 user 의 활성 상태를 먼저 확인해 (user.deleted_user? 또는 active session 존재 여부) 만료/삭제된 user 에 대해서는 downstream 호출을 skip. notification-service 는 어차피 인증 실패로 no-op 이 되므로 호출 자체를 skip 하는 편이 안전.
  • System-token 기반 admin API 도입 검토: notification-service 에 정리 전용 admin route 를 만들어 개별 user 토큰 대신 서비스 간 signed token 을 사용. 만료 사용자 정리 시나리오에서는 caller 가 destroy 되는 user 이므로 근본적으로 부적합한 현재 구조를 바꿀 수 있음.

장기 개선 (재발 방지)#

  • 정리 파이프라인 재설계: FacilityPermission destroy 시 downstream cleanup 을 event bus (persistent queue) 로 위임하고, downstream 은 자신의 데이터 기준으로 orphan recipe / subscription 을 주기적으로 GC. Tesla 쪽에서 매 destroy 마다 개별 HTTP 요청을 보내는 fan-out 구조가 근본 취약점.
  • Cupix::Cron::EditingPermission#revoke_expired_editor_permissions throttling: 배치성 대량 destroy 로 인해 순간적으로 downstream fan-out 이 폭증. 배치 크기 제한 및 sleep interval 추가.

Monitoring#

  • NotificationService error 발생률 timeseries (본 이슈 fix 후 감소 확인용):
text
service:cupixworks-migration-worker status:error @class:Cupix::NotificationService
  • 정리 cron 실행 volume (info 카운트 기반):
text
service:cupixworks-migration-worker @class:Cupix::Cron::EditingPermission "Revoking expired editor permission"
  • Downstream notification-service 인증 실패 자체 모니터링:
text
service:cupixworks-notification-service status:error "Error authorizing"

Risk Assessment#

  • Risk level: low
  • 예상 복잡도: trivial (log level narrowing) / standard (subscriber pre-check)