nginx api-tesla upstream connection failure — 502/504

RCA: PotreeService::handlingMessageErrors — 500 on check_uploading

Overview#

What Happened#

2026-07-03 05:46:11 KST에 cupixworks-any-potree-r1-xlarge-agent(us-west-2)가 pointcloud 1190788 처리 중 PUT /api/v1/pointclouds/1190788/check_uploading에서 500 응답을 받고 handlingMessageErrors가 발동했다. 발생 건수는 14일 동안 단 1건(single occurrence)이며, 동일 시각 cupixworks-api 쪽에는 대응되는 로그가 남아 있지 않다. 잠시 뒤 pointcloud는 정상적으로 done 상태로 전이되었기 때문에 사용자 영향은 없다.

Quick Facts#

Field	Value
exception.class	`PotreeService::handlingMessageErrors` (upstream HTTP 500)
exception.message	`statusCode: 500` from `http://api-tesla.cupix.internal/api/v1/pointclouds/1190788/check_uploading`
top_frame	`packages/cupix-tesla-potree-agent/src/potree-service.ts:378` (`this.cupixApi.pointcloud.checkUploading`)
env	production, us-west-2
tenant	cupix

Affected Teams#

Team / Domain	Error Count	Impact
siteline / potree processing	1	pointcloud 1190788의 최초 potree 업로드 확인 실패. 이후 재처리를 통해 pointcloud 상태가 `done`으로 전이되어 최종 사용자 영향 없음.

Timeline#

2026-07-03 05:32:11 KST — 에이전트가 SQS 메시지를 받아 pointcloud 1190788 처리 시작 (PotreeService::runByMessage | id: 1190788, state: queued, resource_state: uploaded, potree_state: created).
2026-07-03 05:34:44 KST — 처리 초기 단계에서 permission cache 무효화 발생 (Flush cached permissions By User for User 52107 on Pointcloud 1190788).
2026-07-03 05:46:10 KST — potree 변환/S3 업로드 후 check_uploading 호출에서 500 수신, PotreeService::getApiErrorToDeleteMessage warn 로그 기록.
2026-07-03 05:46:11 KST — PotreeService::handlingMessageErrors error 로그 기록, SQS 메시지 삭제 및 potree_state가 Error로 업데이트되었을 것으로 예상되는 error 분기 진입.
2026-07-03 05:54:35 KST — 동일 pointcloud 1190788가 Rails 측에서 pointcloud state changed from queued to done으로 전이되며 start_finalization 실행 (agent 재시도 없이 API 흐름을 통해 최종화됨).

Error Log#

Datadog Logs

text

PotreeService::handlingMessageErrors | Error and message object - {"error":{"statusCode":500,"requestUriHref":"http://api-tesla.cupix.internal/api/v1/pointclouds/1190788/check_uploading?fields%5B0%5D=id&fields%5B1%5D=name&fields%5B2%5D=kind&fields%5B3%5D=pointcloud_type&fields%5B4%5D=state&fields%5B5%5D=potree_state&fields%5B6%5D=potree_paths&fields%5B7%5D=resource_state&fields%5B8%5D=parent&fields%5B9%5D=record&fields%5B10%5D=level&fields%5B11%5D=capture&fields%5B12%5D=bim_icp_tm&fields%5B13%5D=use_bim_icp_tm&fields%5B14%5D=potree_url&fields%5B15%5D=entry_filename&fields%5B16%5D=voxel_state&fields%5B17%5D=voxels_result_urls&fields%5B18%5D=meta&fields%5B19%5D=thumbnail_urls&fields%5B20%5D=potree_upload_urls&fields%5B21%5D=created_at&fields%5B22%5D=cpc_download_url","modelId":1190788},"sqsMessage":{"MessageId":"336c1f41-865c-4ded-9aaa-d73095cb4abe","Attributes":{"ApproximateReceiveCount":"1"}}}

Impact#

Service: cupixworks-any-potree-r1-xlarge-agent
Team: siteline
발생 횟수: 1 (14일 전체 기간에서 유일)
최초 발생: 2026-07-03 05:46:11 KST
최근 발생: 2026-07-03 05:46:11 KST
User Impact: 없음 — pointcloud 1190788은 05:54:35 KST에 정상적으로 done으로 전이됨.

Root Cause Summary#

potree 에이전트가 S3에 결과물을 업로드한 뒤 tesla API의 PUT /api/v1/pointclouds/1190788/check_uploading을 호출했는데, 클라이언트 측에서는 HTTP 500 응답을 받았다. 그러나 동일 시각 cupixworks-api 서비스의 Datadog 로그에는 해당 요청에 대응되는 [500] ... check_uploading 접근 로그, InvalidState/STAT10000 예외 로그, status:error 로그가 하나도 없다. 반면 인접한 128842, 1190836, 1190838 등 다른 pointcloud에 대한 check_uploading 요청은 05:46:14~05:46:19 KST에 모두 200으로 처리되었고, 동일 시간대에 API의 /status 헬스체크도 모두 200이다. 이는 요청이 Rails 애플리케이션 계층에 도달하지 못했거나, 상위 프록시(nginx / ALB / internal LB api-tesla.cupix.internal)가 Rails 앞단에서 500을 반환한 transient upstream failure일 가능성이 매우 높다. 애플리케이션 코드의 결함이라기보다는 인프라/네트워크 레이어의 일회성 장애이며, 이후 Rails 측 finalization 흐름을 통해 pointcloud가 자동으로 done으로 전이되면서 사용자에게 영향이 없었다.

Technical Analysis#

Code Path#

Entry point: SQS message consumption in PotreeService.runByMessage → potree conversion → S3 upload → checkUploading API call.

packages/cupix-tesla-potree-agent/src/potree-service.ts:180 — runByMessage 진입, msgObject.id로 pointcloud 로드.
packages/cupix-tesla-potree-agent/src/potree-service.ts:337-379 — uploadPotreeFiles 마지막 단계에서 checkUploading 호출.
packages/cupix-tesla-potree-agent/src/potree-service.ts:378 — Failure point (실제 500을 받은 지점).

packages/cupix-tesla-potree-agent/src/potree-service.ts:372-379typescript

await awsS3Manager.uploadDirectoryToS3({
    bucketName: s3Credentials.bucket_name,
    bucketKeyPath: s3Credentials.basepath,
    targetDirectoryPath: resultDir,
    acl: s3Credentials.acl
});
await this.cupixApi.pointcloud.checkUploading(cpPointcloud.id);

API 클라이언트는 표준 checkUploading 래퍼로 위임한다:

packages/api/src/api/pointcloud.api.ts:182-186typescript

checkUploading = async (pointcloudId: number): Promise<TESLA.Pointcloud> => {
    const api = await this.api();
    const res = await api.checkUploading(pointcloudId, Fields.PointCloudFields);
    return unwrapAttributes(res);
};

500이 발생하면 checkingQueue catch 블록이 handlingMessageErrors를 호출한다:

packages/cupix-tesla-potree-agent/src/potree-service.ts:72-79typescript

this._countWaitedToStopTask = 0;
await this.agentScaleOut();
try {
    await this.runByMessages();
} catch (error) {
    await this.handlingMessageErrors(error);
}

handlingMessageErrors는 4xx/5xx (401 제외) 응답에 대해 SQS 메시지를 삭제하고 potree_state를 Error로 업데이트한다:

packages/cupix-tesla-potree-agent/src/potree-service.ts:502-525typescript

private handlingMessageErrors = async (error: any): Promise<void> => {
    const errorAndMessage = {
        error: error,
        sqsMessage: {}
    };
    if (this.messageInProcess) {
        errorAndMessage.sqsMessage = {
            MessageId: this.messageInProcess.MessageId,
            Attributes: this.messageInProcess.Attributes
        };
        const apiErrorObject = this.getApiErrorToDeleteMessage(error);
        if (apiErrorObject != undefined || this.checkReceiveCountToDeleteMessage()) {
            try {
                errorAndMessage.error = apiErrorObject;
                await this.deleteByMessage(this.messageInProcess);
                if (this._modelInProcess != undefined) await this.updatePotreeState(this._modelInProcess.id, TESLA.PointcloudPotreeState.Error);
            } catch (error) {
                logger.error('PotreeService::handlingMessageErrors | Errors in error handling - %s', JSON.stringify(error));
            }
        }
    }
    logger.error('PotreeService::handlingMessageErrors | Error and message object - %s', JSON.stringify(errorAndMessage));
    resetLogMeta();
};

getApiErrorToDeleteMessage (라인 456-490)에서 statusCode 500은 >= 400 && <= 500 조건에 걸려 삭제 대상이 되며, ApproximateReceiveCount:"1" 상태에서도 즉시 메시지가 큐에서 삭제된다.

기대 동작 vs 실제 동작:

기대: check_uploading 200 응답, pointcloud potree_state가 uploaded로 전이.
실제: 500 응답, SQS 메시지 즉시 삭제(ApproximateReceiveCount:"1"), potree_state가 Error로 갱신되었을 것. 그러나 05:54:35 KST 이후 Rails 측 start_finalization 흐름에서 pointcloud가 done으로 전이된 것을 볼 때 별도 finalization 경로가 정상 상태를 복원했다.

Rails 측 엔드포인트는 check_potree_uploading을 통해 potree_state를 uploaded로 전이하며, 정상적인 예외 경로는 Cupix::Errors::InvalidState (STAT10000) 400 응답이다:

app/repositories/pointcloud_repository.rb:267-283ruby

def check_uploading
  case @model.resource_state_name
  when :uploading, :missing, :created
    if @model.manual_potree_convert
      @model.uploaded_resource_state
    else
      raise Cupix::Errors::Resource.new(code: 'RESC10000', reason: 'Resource does not uploaded') unless @model.check_resource_uploading
    end
  when :uploaded
    case @model.potree_state_name
    when :uploading, :missing, :created
      raise Cupix::Errors::InvalidState.new(code: 'STAT10000', reason: 'Potree does not uploaded') unless @model.check_potree_uploading
    end
  end

  @model
end

이 코드에서 발생 가능한 애플리케이션 에러는 4xx (RESC10000 / STAT10000)이며 자연스러운 5xx 원인은 없다. Datadog에는 해당 pointcloud에 대한 check_uploading 접근 로그가 아예 없어 요청이 Rails에 도달하지 않았음을 시사한다.

Log Evidence#

Query used (Datadog):

text

service:cupixworks-any-potree-r1-xlarge-agent "handlingMessageErrors"

Time range: 2026-07-02T19:30:00Z – 2026-07-02T21:00:00Z — 1건 반환.

text

service:cupixworks-any-potree-r1-xlarge-agent "handlingMessageErrors"

Time range: now-14d — 1건 반환. 14일 전체 기간 동안 유일한 발생.

Agent flow (KST 시각):

text

2026-07-03 05:32:11  info  PotreeService::runByMessage | id: 1190788
2026-07-03 05:32:11  info  PotreeService::runByMessage | state: queued, resource_state: uploaded, potree_state: created
2026-07-03 05:46:10  warn  PotreeService::getApiErrorToDeleteMessage | error msg - {"statusCode":500,"requestUriHref":"...pointclouds/1190788/check_uploading...","modelId":1190788}
2026-07-03 05:46:11  error PotreeService::handlingMessageErrors | Error and message object - {"error":{"statusCode":500,...},"sqsMessage":{"MessageId":"336c1f41-865c-4ded-9aaa-d73095cb4abe","Attributes":{"ApproximateReceiveCount":"1"}}}

API-side check (cupixworks-api):

text

service:cupixworks-api "/pointclouds/1190788"

Time range: 2026-07-02T20:40:00Z – 2026-07-02T20:55:00Z — 반환된 로그에 check_uploading 항목이 없다:

text

2026-07-03 05:41:10  info  [200] GET  /api/v1/pointclouds/1190788                          (PointcloudsController#show)
2026-07-03 05:43:47  info  [200] POST /api/v1/pointclouds/1190788/potree_upload_credentials (PointcloudsController#create_potree_upload_credentials)
(check_uploading 요청 로그 없음)
2026-07-03 05:54:35  info  pointcloud state changed from queued to done. id: 1190788   (StateMachines::Machine)
2026-07-03 05:54:35  info  create editing entity on start finalization Pointcloud 1190788 (Pointcloud#start_finalization)

동시각 인접 pointcloud들에 대한 check_uploading 요청은 모두 정상 200 응답:

text

2026-07-03 05:46:19  info  [200] PUT /api/v1/pointclouds/1190838/check_uploading  (PointcloudsController#check_uploading)
2026-07-03 05:46:14  info  [200] PUT /api/v1/pointclouds/128842/check_uploading   (PointcloudsController#check_uploading)
2026-07-03 05:46:09  info  [200] PUT /api/v1/pointclouds/128840/check_uploading   (PointcloudsController#check_uploading)
2026-07-03 05:45:43  info  [200] PUT /api/v1/pointclouds/1190836/check_uploading  (PointcloudsController#check_uploading)

동시각 API 5xx 검색 결과: 0건.

text

service:cupixworks-api ("500" OR "502" OR "503" OR "504")

Time range: 2026-07-02T20:45:30Z – 2026-07-02T20:46:30Z — 0건.

InvalidState / STAT10000 예외 검색 결과: 0건.

text

service:cupixworks-api "InvalidState"

Time range: 2026-07-02T20:44:00Z – 2026-07-02T20:48:00Z — 0건.

동시각 API 서비스는 정상 상태(/status 200이 초당 다수 관측):

text

2026-07-03 05:46:14 info [200] GET /status (Api::V1::ApiController#status)

동시간대 tesla 다른 서비스(cupixworks-worker)에서는 Cupix::VoxelService 503 Service Unavailable 등 별도 다운스트림 이슈가 관측되나, 이번 클러스터의 check_uploading 실패와 직접적 인과 관계를 뒷받침하는 로그는 없다:

text

2026-07-03 05:46:25 error failed to get captured area - error: 503 Service Unavailable  (Cupix::VoxelService)
2026-07-03 05:46:25 error failed to calculate captured size for Facility ID: 13307      (Facility)

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	상위 프록시 / internal LB(`api-tesla.cupix.internal`)의 transient 5xx — 요청이 Rails에 도달하지 못하고 프록시 계층에서 500 반환.	`cupixworks-api`에 해당 요청의 접근 로그 자체가 완전히 부재. 동시각 인접 pointcloud들의 `check_uploading` 요청은 모두 200. 동시각 API `/status` 200 다수 관측. 14일 동안 유일한 1건 (매우 낮은 재발률).	프록시 계층 로그를 이 스킬로는 직접 조회 불가 — nginx / ALB access log 확인 필요 (uncertain — needs verification).	Confirmed (most likely)
H2	Rails 애플리케이션의 `check_uploading` 처리 중 unhandled 예외로 500 발생.	이론상 `check_potree_uploading` 내부 상태 전이 실패 등에서 unhandled 예외 발생 가능.	`cupixworks-api` 로그에 해당 요청의 접근 로그 자체가 없음. `status:error`, `InvalidState`, `500`, `PointcloudsController#check_uploading` 어떤 형태로도 대응 로그 없음. 동일 pointcloud가 잠시 뒤 정상적으로 `done`으로 전이됨.	Rejected
H3	Agent-side 요청 자체가 malformed로 500 유도.	—	`requestUriHref`의 query string 포맷이 정상. 동일 코드 경로로 인접 pointcloud 요청은 모두 200.	Rejected
H4	다운스트림 voxel-service 503 파급으로 `check_uploading` 처리 중 500.	동시각 `Cupix::VoxelService` 503 로그 다수 관측.	`check_uploading` 코드 경로(`pointcloud_repository#check_uploading` → `check_potree_uploading`)는 voxel-service를 호출하지 않음. pointcloud 1190788와 voxel-service 요청 간 직접 연결 증거 없음.	Rejected (unrelated)
H5	Rails 요청 처리 시간이 프록시 timeout 초과, 프록시가 500 대신 반환.	다른 pointcloud와 달리 이 요청만 API 로그에 남지 않음.	동시각 API 응답 지연 지표 부재(uncertain — needs verification). 다른 pointcloud들의 `check_uploading`은 즉시 200 반환.	Inconclusive

Fix Recommendation#

즉시 조치 (Critical)#

없음 — pointcloud 1190788은 자동으로 done으로 복구되었고, 14일 기간 동안 1건에 불과한 transient event이다. 사용자 영향 및 시스템적 반복 발생이 확인되지 않는다.

단기 개선 (1주 이내)#

프록시/LB 로그 확인: api-tesla.cupix.internal 뒤단의 nginx / ALB access log를 2026-07-02 20:46:10 UTC 시점의 pointcloud 1190788 check_uploading 요청에 대해 조회하여, 응답 코드(500) 및 upstream_response_time을 확인한다. 이는 인프라 팀 협조가 필요하며 근본 원인 확정에 결정적이다.
에이전트 재시도 정책 검토: packages/cupix-tesla-potree-agent/src/potree-service.ts:456-490 getApiErrorToDeleteMessage가 500을 삭제 대상으로 분류(>= 400 && <= 500)하는 로직 재검토. 5xx는 서버 측 transient 장애일 가능성이 크므로 SQS visibility timeout으로 재시도를 유도하는 것이 안전하다. 다만 이번 case에서는 Rails-side finalization으로 자동 복구되었으므로, 재시도 정책 변경은 pointcloud 상태 이중 갱신 위험(Rails가 이미 done으로 전이한 뒤 agent가 Error로 덮어쓰는 race)을 함께 고려해야 한다.

packages/cupix-tesla-potree-agent/src/potree-service.ts:485-489typescript

if (statusCode != undefined && statusCode >= 400 && statusCode <= 500) {
    if (statusCode === 401) return;
    return errorMsg;
}
return;

장기 개선 (재발 방지)#

API access log completeness 검증: internal LB → Rails 사이의 요청 로깅 파이프라인을 점검하여, LB가 5xx 응답한 요청도 Datadog에 유입되도록 access log 스트림을 정비한다. 현재는 Rails에 도달하지 못한 요청의 근본 원인 추적이 어렵다.
엔드투엔드 상관관계 추적 강화: agent 요청에 correlation id (예: X-Request-Id)를 부여하고, LB / Rails / agent 로그에서 모두 검색 가능하게 하여 이러한 유형의 "missing side" 사건을 빠르게 진단할 수 있게 한다.

Monitoring#

potree agent handlingMessageErrors 발생률 — 상승 추세 감시:

text

sum:logs.hits{service:cupixworks-any-potree-r1-xlarge-agent,status:error,@message:handlingMessageErrors}.as_count()

check_uploading 5xx 응답률 (agent 관점):

text

sum:logs.hits{service:cupixworks-any-potree-r1-xlarge-agent,@message:handlingMessageErrors,@error.statusCode:500}.as_count()

cupixworks-api 5xx 총량 (인프라 이슈 조기 감지):

text

sum:logs.hits{service:cupixworks-api,status:error}.as_count()

check_uploading 요청량 (인접 pointcloud와의 상관관계 확인):

text

sum:logs.hits{service:cupixworks-api,@http.url_details.path:/api/v1/pointclouds/*/check_uploading}.as_count()

Risk Assessment#

Risk level: low — 14일 동안 1건, 자동 복구 확인, 사용자 영향 없음.
예상 복잡도: trivial — 코드 변경은 불필요하며, 프록시 로그 확인/모니터링 강화 위주의 후속 조치만 필요.