RCA: CaptureIntelligenceService::updateCaptureSummaryState 502 HttpError

Overview#

What Happened#

2026-07-03 17:57 KST에 cupixworks-capture-intelligence-agent가 capture 724243의 summary_state를 processing으로 전이하기 위해 tesla API에 PUT /api/v1/captures/724243를 호출했으나, tesla가 ActiveRecord::LockWaitTimeout (Mysql2::Error::TimeoutError: Lock wait timeout exceeded)으로 502를 반환하여 agent가 HttpError 예외를 로깅했다. 동일 capture에 대한 502 응답이 17:44:50 KST부터 17:57:47 KST까지 7건 연속 관측되며, SQS 메시지가 재전달되어 약 1시간 뒤 18:55~18:57 KST에 정상 처리 완료(queued → processing → done)되었다.

Quick Facts#

Affected Teams#

Timeline#

1. 2026-07-03 17:37 KST — worker에서 Capture#run_zip, update_associated_sitetracks, update_associated_deviations가 capture 724243에 대해 실행 (service:cupixworks-worker).
2. 2026-07-03 17:44:50 KST — tesla API 첫 번째 502 응답 (ActiveRecord::LockWaitTimeout, PUT /api/v1/captures/724243, x-runtime 50.9s).
3. 2026-07-03 17:52:40 ~ 17:57:47 KST — 동일 요청에 대해 502 응답 6건 추가 발생 (총 7건).
4. 2026-07-03 17:57:46 KST — agent가 CaptureIntelligenceService::updateCaptureSummaryState 실패를 error 레벨로 로깅 (본 클러스터의 first/last seen).
5. 2026-07-03 18:55:42 KST — summary_state transitioned from queued to processing (재시도 성공).
6. 2026-07-03 18:57:29 KST — summary_state transitioned from processing to done (최종 완료).

Error Log#

Datadog Logs

CaptureIntelligenceService::updateCaptureSummaryState | failed - captureId: 724243, state: processing, error: {"stack":"HttpError: HTTP request failed
    at Request._callback (/tmp/agent/dist/node_modules/@tesla/typescript-node-sdk/api/captureApi.js:4350:40)
    at self.callback (/tmp/agent/dist/node_modules/request/request.js:185:22)
    at Request.emit (node:events:524:28)
    ...
","message":"HTTP request failed","response":{"body":{},"statusCode":502},"body":{},"statusCode":502,"name":"HttpError"}

Impact#

• Service: cupixworks-capture-intelligence-agent
• Team: weoneil
• 발생 횟수: 1 (agent 측 error 로그 기준). Upstream tesla 502는 동일 capture에 대해 7건.
• 최초 발생: 2026-07-03 17:57 KST
• 최근 발생: 2026-07-03 17:57 KST

Root Cause Summary#

Capture 724243의 PUT /api/v1/captures/724243이 tesla API에서 InnoDB row lock 획득에 실패해 Mysql2::Error::TimeoutError: Lock wait timeout exceeded가 발생했고, tesla가 이를 Cupix::Errors::BadGateway (502)로 매핑하여 응답했다. 응답 시각 직전(17:37 KST)에 Capture 모델의 run_zip, update_associated_sitetracks, update_associated_deviations가 worker에서 실행되며 동일 row에 대한 트랜잭션을 장시간 보유한 것이 lock 경합의 원인으로 추정된다(x-runtime 50.9s 는 InnoDB 기본 lock_wait_timeout=50s와 일치). agent 측에서는 CaptureIntelligenceService::updateCaptureSummaryState가 502에 대해 재시도/백오프 없이 그대로 예외를 던지고 BaseService.handlingMessageErrors가 이를 error 로그로 남겼다. 502는 agent의 getApiErrorToDeleteMessage 조건(statusCode >= 400 && statusCode <= 500)에 포함되지 않아 SQS 메시지가 즉시 삭제되지 않고 재전달을 통해 결국 성공 처리되었다. 즉, 본 error 로그의 근본 원인은 agent 코드의 결함이 아니라 tesla 측 Capture row에 대한 일시적 lock contention이며, agent는 이를 정상적으로 로깅한 뒤 SQS 재시도로 복구된 케이스이다.

Technical Analysis#

Code Path#

Entry point: packages/cupix-capture-intelligence-agent/src/capture-intelligence-service.ts:106 (CaptureIntelligenceService.run).

첫 단계로 capture의 summary_state를 processing으로 전이하기 위해 tesla API에 update 요청을 보낸다.

protected override run = async (targetId: number, msgObject: SqsMessageBody): Promise<void> => {
    this._spacetimeId = msgObject.spacetime_id;
    logger.info('CaptureIntelligenceService::run | begin - captureId: %d, spacetimeId: %d', targetId, this._spacetimeId);

    await this.updateCaptureSummaryState(targetId, TESLA.CaptureSummaryState.Processing);
    const cpCapture = await this.fetchAndValidateCapture(targetId);
    ...
};

Failure point: packages/cupix-capture-intelligence-agent/src/capture-intelligence-service.ts:135. capture.update SDK 호출이 502를 반환하면 catch 블록이 error를 로깅하고 재throw한다.

private async updateCaptureSummaryState(captureId: number, state: TESLA.CaptureSummaryState): Promise<void> {
    if (DEBUG_MODE) { ... }

    try {
        await this.cupixApi.capture.update(captureId, { summary_state: state });
        logger.debug(...);
    } catch (error) {
        logger.error('CaptureIntelligenceService::updateCaptureSummaryState | failed - captureId: %d, state: %s, error: %s',
            captureId, state, stringifyError(error));
        throw error;
    }
}

던진 예외는 상위 BaseService.checkingQueue 루프에서 catch되어 handlingMessageErrors로 전달된다.

try {
    await this.runByMessages();
} catch (error) {
    await this.handlingMessageErrors(error);
}

handlingMessageErrors는 getApiErrorToDeleteMessage로 상태 코드를 판정한다. 여기서 statusCode 판정 범위가 >= 400 && <= 500이므로 502는 매칭되지 않아 apiErrorObject가 undefined가 된다. 그리고 ApproximateReceiveCount=1이므로 checkReceiveCountToDeleteMessage도 false → 메시지는 삭제되지 않고 SQS 가시성 타임아웃 이후 재전달된다.

private getApiErrorToDeleteMessage = (error: any): any => {
    ...
    const statusCode = response.statusCode ? Number(response.statusCode) : undefined;
    ...
    if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
        if (statusCode === 401) return;
        return errorMsg;
    }
    return;
};

Upstream failure point: tesla Api::V1::CapturesController#update (app/controllers/api/v1/captures_controller.rb:46-50)에서 repository_instance.update(params) 실행 중 InnoDB row lock을 얻지 못해 50초 후 timeout 발생.

def update
  @model = repository_instance.update(params)

  super
end

기대 동작: summary_state만 갱신하는 짧은 트랜잭션이 즉시 성공. 실제 동작: 다른 트랜잭션이 동일 Capture 724243 row에 대한 write lock을 보유하고 있어 lock_wait_timeout=50s 후 Mysql2::Error::TimeoutError 발생 → tesla가 502(Cupix::Errors::BadGateway)로 매핑.

lock을 보유한 것으로 의심되는 경로는 17:37 KST에 실행된 Capture#update_associated_sitetracks, Capture#update_associated_deviations, Capture#run_zip이며(worker 로그로 확인), 이들은 Capture row와 연관 테이블을 함께 갱신하는 concern 로직이다.

Log Evidence#

Datadog 쿼리 (agent):

service:cupixworks-capture-intelligence-agent "CaptureIntelligenceService::updateCaptureSummaryState"

agent가 남긴 유일한 error 로그 (본 클러스터의 대표 에러):

2026-07-03 17:57:46 KST  error
CaptureIntelligenceService::updateCaptureSummaryState | failed - captureId: 724243, state: processing, error: {"stack":"HttpError: HTTP request failed
    at Request._callback (/tmp/agent/dist/node_modules/@tesla/typescript-node-sdk/api/captureApi.js:4350:40)
    ...","message":"HTTP request failed","response":{"body":{},"statusCode":502},"body":{},"statusCode":502,"name":"HttpError"}

동일 시각 BaseService::handlingMessageErrors가 남긴 error and message 로그 (upstream 원인 노출):

{
  "error": {
    "response": {
      "statusCode": 502,
      "body": {
        "result": {
          "code": "BG10000",
          "type": "Cupix::Errors::BadGateway",
          "reason": "BadGateway",
          "message": "Mysql2::Error::TimeoutError: Lock wait timeout exceeded; try restarting transaction"
        }
      },
      "headers": {
        "x-request-id": "e25ce3ab-ed6a-4420-8dc2-c3a481bac18a",
        "x-runtime": "50.915142"
      },
      "request": {
        "method": "PUT",
        "headers": { "User-Agent": "cupix-agent", "X-CUPIX-AUTH": "session_token:9bs6k8vn6sfq,session_id:11376438", "content-length": 30 },
        "uri": { "pathname": "/api/v1/captures/724243" }
      }
    },
    "statusCode": 502,
    "name": "HttpError"
  },
  "sqsMessage": {
    "MessageId": "042709c3-2284-40bf-8387-8af31a0c8b82",
    "Attributes": { "ApproximateReceiveCount": "1" }
  }
}

Datadog 쿼리 (tesla API, upstream):

service:cupixworks-api "Lock wait timeout exceeded" "captures/724243"

동일 capture에 대한 502 응답 7건 (모두 Mysql2::Error::TimeoutError, x-runtime ~50s):

2026-07-03 17:44:50 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:52:40 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:53:40 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:54:33 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:55:36 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:56:40 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)
2026-07-03 17:57:47 KST  [502] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)

동일 시각대에 capture 724243에 write 트랜잭션을 발생시킨 worker 활동:

2026-07-03 17:37:37 KST  info  Zip lambda status_code(202) on Capture 724243  (Capture#run_zip)
2026-07-03 17:39:20 KST  info  Updating associated sitetracks for Capture 724243  (Capture#update_associated_sitetracks)
2026-07-03 17:39:20 KST  info  Updating associated deviations for Capture 724243  (Capture#update_associated_deviations)

재시도 성공 로그:

2026-07-03 18:55:42 KST  info  summary_state transitioned from queued to processing on Capture 724243
2026-07-03 18:57:29 KST  info  summary_state transitioned from processing to done on Capture 724243
2026-07-03 18:57:30 KST  info  [200] PUT /api/v1/captures/724243 (Api::V1::CapturesController#update)

Hypotheses Considered#

Fix Recommendation#

즉시 조치 (Critical)#

• 별도 코드 수정 없이 SQS 재전달을 통해 이미 자연 복구됨 (18:57 KST 완료). 즉각 조치 필요 없음.
• tesla 측 lock contention 재발 여부는 dashboard(아래 Monitoring 참조)로 모니터링.

단기 개선 (1주 이내)#

• applications/agents/packages/cupix-capture-intelligence-agent/src/capture-intelligence-service.ts:128-142 의 updateCaptureSummaryState에 대해 5xx (특히 502/503/504)와 LockWaitTimeout 계열 에러에 한해 짧은 지수 백오프 재시도(예: 3회, 1s→3s→9s)를 추가하는 방향 검토. SQS 재시도에 의존할 때 다음 delivery까지 30~60분이 소요되어 사용자 관점의 summary 완료 지연이 크므로, in-process 재시도가 있으면 이번 사례처럼 lock이 짧게 걸린 경우 즉시 복구 가능.
• applications/agents/packages/base/src/base-service.ts:270 (getApiErrorToDeleteMessage) — 현재 조건 statusCode >= 400 && statusCode <= 500이 실질적으로 500만 포함하고 502/503/504는 제외한다. 명세와 실제 의도(4xx = 클라이언트 오류로 삭제, 5xx = 서버 오류로 재시도) 사이의 경계가 애매하므로, 조건을 >= 400 && < 500으로 명확히 하거나 재시도/삭제 정책을 상수 테이블로 문서화. (동작 자체는 이번 사례에 유리하게 작동했으므로 우선순위는 낮음.)
• tesla 측 Api::V1::CapturesController#update 트랜잭션에 대해, summary_state만 갱신하는 얇은 경로가 update_associated_sitetracks/update_associated_deviations 등 무거운 concern과 같은 row lock 큐를 공유하지 않는지 검토. 필요시 summary_state만을 위한 전용 endpoint(예: PATCH /captures/:id/summary_state) 분리 검토.

장기 개선 (재발 방지)#

• worker 측 Capture#update_associated_sitetracks, update_associated_deviations, run_zip이 하나의 DB 트랜잭션에 묶여 실행되는지 리뷰. 단일 트랜잭션이 associated 테이블까지 오래 잠그는 구조라면, 배치 사이즈 축소 또는 트랜잭션 분리로 lock 보유 시간을 단축.
• lock_wait_timeout을 앱 레벨에서 짧게(예: 10s) 설정해 502가 지연 없이 실패하도록 하고, 대신 client 측 재시도로 총 처리 시간을 줄이는 방향 검토.
• Capture summary 파이프라인의 end-to-end 완료 시간을 SLI로 측정하여 이번처럼 SQS 재전달 지연을 자동 감지하도록 함.

Monitoring#

writing-datadog-monitoring-queries skill 규칙에 따라 timeseries widget에서 그래프로 렌더되도록 monitor-only 문법(| stats, count by(...), threshold suffix)을 피하고 metric 문법을 사용한다.

Capture intelligence agent 에러 추이:

sum:datadog.estimated_usage.logs.ingested_events{service:cupixworks-capture-intelligence-agent,status:error}.as_count()

tesla API에서 발생하는 ActiveRecord::LockWaitTimeout 추이 (release dashboard에 그래프로 표시):

logs("service:cupixworks-api \"Lock wait timeout exceeded\"").index("*").rollup("count").by("resource").last("1h")

capture 리소스에 대한 502 응답 추이:

logs("service:cupixworks-api \"[502]\" \"captures\"").index("*").rollup("count").last("1h")

CaptureIntelligenceService::updateCaptureSummaryState 실패 추이 (본 클러스터의 재발 감지용):

logs("service:cupixworks-capture-intelligence-agent \"CaptureIntelligenceService::updateCaptureSummaryState\" \"failed\"").index("*").rollup("count").last("1h")

추천 알림:

• 최근 10분 동안 동일 capture에 대한 Lock wait timeout exceeded 3회 이상 → warn
• cupixworks-capture-intelligence-agent 서비스에서 시간당 error 로그가 baseline 대비 3x 이상 급증 → warn

Risk Assessment#

• Risk level: low — 단일 capture(724243)에 국한된 일시적 lock 경합이며 SQS 재전달로 자연 복구됨. 반복 재현될 경우 medium으로 격상.
• 예상 복잡도: standard — agent 재시도 도입은 소규모 변경이나 base-service의 삭제 조건 재정의는 회귀 테스트 필요.