BaseService::handlingMessageErrors | Errors in error handling - {"response":{"statusCode":403,"body"

RCA: BaseService::handlingMessageErrors | Errors in error handling — Bim not found

Overview#

What Happened#

2026-04-20 21:11:33 UTC에 cupixworks-any-room-agent 서비스에서 BIM ID 18724에 대한 room extraction 처리 중 403 "Bim not found" 에러가 발생했다. room-agent가 BIM을 처리하는 동안 외부에서 해당 BIM이 trash 처리되어, 에이전트의 후속 API 호출과 에러 복구(updateErrorState) 모두 실패했다.

Quick Facts#

Field	Value
exception.class	`HttpError`
exception.message	`Bim not found (ENT4000, Cupix::Errors::NotFound)`
top_frame	`BaseService::handlingMessageErrors` (base-service.ts:307)
env	production, us-west-2

Timeline#

21:07:59 UTC — room-agent가 SQS 메시지를 수신하여 BIM 18724 처리 시작 (BaseService::runByMessage | id: 18724)
21:09:28 UTC — BIM 18724 정상 조회/업데이트 성공 ([200] GET/PUT /api/v1/bims/18724)
21:10:22 UTC — 외부에서 BIM 18724 trash 처리 ([204] PUT /api/v1/bims/18724/trash)
21:10:40 UTC — room-agent의 후속 API 호출들 실패 시작 ([403] PUT /api/v1/bims/18724 — "Bim not found")
21:11:33 UTC — 에러 핸들링 중 updateErrorState도 실패, "Errors in error handling" 로그 기록

Error Log#

Datadog Logs

text

BaseService::handlingMessageErrors | Errors in error handling - {"response":{"statusCode":403,"body":{"result":{"code":"ENT4000","type":"Cupix::Errors::NotFound","reason":"Bim not found","message":"Bim not found"}},...,"request":{"uri":{"pathname":"/api/v1/bims/18724"},"method":"PUT","headers":{"User-Agent":"cupix-tesla-room-agent"}}}}

Impact#

Service: cupixworks-any-room-agent
발생 횟수: 1
최초 발생: 2026-04-20T21:11:33.359Z
최근 발생: 2026-04-20T21:11:33.359Z

BIM 18724는 이미 trash 처리된 상태이므로 room extraction 결과가 반영되지 않았다. 다만, BIM이 의도적으로 삭제된 것이므로 데이터 손실은 아니다. 에이전트는 SQS 메시지를 정상 삭제하고 다음 작업으로 진행하였으므로 다른 BIM 처리에는 영향이 없다.

Root Cause Summary#

room-agent가 SQS 메시지를 받아 BIM 18724의 room extraction을 처리하는 도중(21:07:59~21:10:40 UTC), 외부에서 해당 BIM이 21:10:22 UTC에 trash 처리되었다. Tesla API의 visibility_scope(:UNTRASHED) 스코프는 cycle_state가 trashing/trashed인 레코드를 필터링하므로, trash 이후의 모든 API 호출(PUT /api/v1/bims/18724, GET /api/v1/rooms?bim_id=18724)이 ENT4000 (403) 에러를 반환했다. 이 에러가 BaseService::handlingMessageErrors의 에러 복구 경로(updateErrorState)에서도 동일하게 발생하여 "Errors in error handling" 이중 에러가 기록되었다.

Technical Analysis#

Code Path#

1. Entry point — SQS 메시지 수신 및 처리 시작

room-agent는 SQS 큐에서 메시지를 받아 BaseService::runByMessage를 호출한다.

packages/base/src/base-service.ts:153-191typescript

protected runByMessage = async (message: AWS.SQS.Message) => {
    this._messageInProcess = message;
    const messageBody = message.Body;
    if (messageBody && CPUtils.isJsonString(messageBody)) {
        const msgObject = JSON.parse(messageBody);
        const targetId = /* ... */ (msgObject.id ?? msgObject.model?.id);
        // ...
        await this.authenticateByMessage(msgObject);
        await this.run(targetId, msgObject);          // RoomService.run() 호출
        await this.cleanUpAnythingRelatedModel();
        await this.deleteByMessage(message);
        // ...
    }
};

2. RoomService.run() — BIM 처리 로직

run()은 BIM 정보를 조회한 후, room extraction → BIM state 업데이트 등을 수행한다.

packages/cupix-tesla-room-agent/src/room-service.ts:58-100typescript

protected run = async (targetId: number): Promise<void> => {
    const cpBim = await this.createCPBimByBimId(targetId);
    if (cpBim) {
        this._modelInProcess = cpBim;
        // ...
        await this.updateBimRoomState(targetId, RoomStateEnum.Extracting);
        await this.runRoomExtractor(cpBim);
        // ... room import 로직 ...
        await this.updateBimRoomState(targetId, RoomStateEnum.Extracted);
        // ... meta 업데이트 등 추가 API 호출들 ...
    }
};

run() 내의 여러 단계에서 cupixApi.bim.update(), cupixApi.room.getAll() 등 Tesla API를 반복 호출하는데, BIM이 trash된 이후의 호출이 모두 403을 반환한다.

3. 에러 전파 — handlingMessageErrors

run()에서 throw된 에러는 checkingQueue의 catch 블록에서 handlingMessageErrors로 전달된다.

packages/base/src/base-service.ts:105-116typescript

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

4. Failure point — updateErrorState에서 이중 에러 발생

handlingMessageErrors는 에러 복구 시도로 SQS 메시지 삭제 후 updateErrorState를 호출한다.

packages/base/src/base-service.ts:290-313typescript

private handlingMessageErrors = async (error: any): Promise<void> => {
    // ...
    if (this.messageInProcess) {
        const apiErrorObject = this.getApiErrorToDeleteMessage(error);
        if (apiErrorObject != undefined || this.checkReceiveCountToDeleteMessage()) {
            try {
                await this.deleteByMessage(this.messageInProcess);      // SQS 메시지 삭제 — 성공
                if (this._modelInProcess != undefined && this._modelInProcess.id > 0)
                    await this.updateErrorState(this._modelInProcess);  // ← 여기서 실패
            } catch (error) {
                logger.error('BaseService::handlingMessageErrors | Errors in error handling', error);
            }
        }
    }
    logger.error('BaseService::handlingMessageErrors | Error and message object - %s', JSON.stringify(errorAndMessage));
};

updateErrorState는 updateBimRoomState(id, Error)를 호출하는데, 이것이 PUT /api/v1/bims/18724을 실행한다.

packages/cupix-tesla-room-agent/src/room-service.ts:512-517typescript

protected updateErrorState = async (cpBim: CPBim): Promise<void> => {
    await this.updateBimRoomState(cpBim.id, TESLA.UpdateBimRequest.RoomStateEnum.Error);
};

5. Tesla API 측 — trash된 BIM에 대한 403 반환

Tesla API의 BaseRepository.show()는 기본적으로 visibility_scope(:UNTRASHED) 스코프를 적용한다. trash된 BIM은 이 스코프에서 제외되며, in_trash 체크에서 발견되면 ENT4000 에러를 발생시킨다.

app/repositories/base_repository.rb:338-352ruby

scope = current_class.visibility_scope(visibility)  # defaults to :UNTRASHED
model = query.merge(scope).first

if model.nil?
  if self.where(attrs).in_trash.present?
    raise Cupix::Errors::NotFound.new(code: 'ENT4000', reason: "#{current_class.name} not found")
  else
    raise Cupix::Errors::NotFound.new(code: 'ARG10002', reason: "#{current_class.name} not found")
  end
end

ENT4000은 not_found_403_error 핸들러에 의해 HTTP 403으로 변환된다.

app/controllers/concerns/client_error_controller.rb:27ruby

rescue_from Cupix::Errors::NotFound, with: :not_found_403_error

Log Evidence#

Datadog에서 아래 쿼리로 전체 타임라인을 확인했다.

text

service:cupixworks-any-room-agent "18724"
Time range: 2026-04-20T20:00:00Z to 2026-04-20T22:30:00Z

처리 시작 (정상):

json

{
  "timestamp": "2026-04-21 06:07:59 KST",
  "status": "info",
  "message": "BaseService::runByMessage | id: 18724"
}

BIM trash 시점 (API 측):

text

service:cupixworks-api "18724" "trash"

json

{
  "timestamp": "2026-04-21 06:10:22 KST",
  "status": "info",
  "message": "[204] PUT /api/v1/bims/18724/trash (Api::V1::BimsController#trash)"
}

trash 이후 실패한 API 호출들 (API 측):

text

service:cupixworks-api "bims" "18724"

json

{
  "timestamp": "2026-04-21 06:10:40 KST",
  "status": "info",
  "message": "[403] PUT /api/v1/bims/18724 (Api::V1::BimsController#update)",
  "error": { "reason": "Bim not found", "code": "ENT4000", "class": "Cupix::Errors::NotFound" }
}

에러 핸들링 과정의 warn 로그 (agent 측):

text

service:cupixworks-any-room-agent "18724" status:warn

json

{
  "timestamp": "2026-04-21 06:11:33 KST",
  "status": "warn",
  "message": "BaseService::getApiErrorToDeleteMessage | error msg - {\"statusCode\":403,\"requestUriHref\":\"http://api-tesla.cupix.internal/api/v1/rooms?...bim_id=18724...\",\"bodyResult\":{\"code\":\"ENT4000\",\"type\":\"Cupix::Errors::NotFound\",\"reason\":\"Bim not found\"},\"modelId\":18724}"
}

이중 에러 — updateErrorState 실패 (agent 측):

json

{
  "timestamp": "2026-04-21 06:11:33 KST",
  "status": "error",
  "message": "BaseService::handlingMessageErrors | Errors in error handling - {\"response\":{\"statusCode\":403,\"body\":{\"result\":{\"code\":\"ENT4000\",\"reason\":\"Bim not found\"}}},\"request\":{\"uri\":{\"pathname\":\"/api/v1/bims/18724\"},\"method\":\"PUT\"}}"
}

Hypotheses Considered#

#	Hypothesis	Evidence for	Evidence against	Verdict
H1	BIM이 처리 도중 외부에서 trash되어 후속 API 호출이 실패	API 로그에서 21:10:22 UTC에 `PUT /api/v1/bims/18724/trash` 204 응답 확인. 이후 21:10:40부터 모든 BIM API 호출이 ENT4000 403 반환. Tesla `BaseRepository.show()`의 `visibility_scope(:UNTRASHED)` 스코프가 trash된 BIM을 필터링 (`base_repository.rb:338-352`)	—	Confirmed
H2	인증 세션 만료로 403 발생	403 HTTP 상태 코드	에러 body가 인증 실패가 아닌 `ENT4000 Bim not found`를 명확히 반환. 첫 번째 실행(05:25~05:28)에서는 같은 세션으로 정상 동작. CupixAuth 에러 로그도 "Bim not found"를 표시	Rejected
H3	room-agent의 에러 핸들링 로직 자체의 버그	`updateErrorState`가 trash된 BIM을 업데이트하려 시도하여 이중 에러 발생 (`base-service.ts:305`)	이것은 H1의 결과이지 독립적인 버그가 아님. `updateErrorState`는 정상 BIM에서는 올바르게 동작하며, "BIM이 이미 삭제된 경우"에 대한 방어 로직이 없을 뿐	Rejected (H1의 부차적 영향)

Fix Recommendation#

즉시 조치 (Critical)#

없음. 발생 빈도가 매우 낮고(1회), BIM이 의도적으로 삭제된 경우의 부작용이므로 데이터 정합성 문제는 없다.

단기 개선 (1주 이내)#

updateErrorState에서 ENT4000 에러를 graceful하게 처리: room-service.ts:512-517의 updateErrorState에서 updateBimRoomState 호출 시, BIM이 이미 삭제/trash된 경우(ENT4000, 403)를 catch하여 warn 로그만 남기고 조용히 넘어가도록 수정. 이렇게 하면 "Errors in error handling" 이중 에러를 방지할 수 있다.
run() 내 API 호출에서 ENT4000 감지 시 조기 중단: room-service.ts:58-100의 run() 메서드에서 BIM 업데이트/조회가 ENT4000을 반환할 때, 전체 처리를 조기 중단하여 불필요한 후속 API 호출을 방지.

장기 개선 (재발 방지)#

BIM trash 시 진행 중인 에이전트 작업 취소 메커니즘: Tesla API에서 BIM trash 시 해당 BIM의 SQS 메시지를 무효화하거나, 에이전트에게 취소 신호를 보내는 방식을 고려.
에러 핸들링의 로그 레벨 재검토: "처리 대상이 이미 삭제된 경우"는 운영상 예상 가능한 시나리오이므로 error 대신 warn 레벨로 기록하는 것이 적절하다.

Monitoring#

현재 이 에러는 빈도가 낮아 별도 알림이 불필요하지만, 패턴 모니터링을 위해:

text

service:cupixworks-any-room-agent status:error "Errors in error handling" "ENT4000"

BIM trash와 에이전트 처리 간의 race condition 빈도를 확인하려면:

text

service:cupixworks-any-room-agent status:warn "Bim not found"

Risk Assessment#

Risk level: low
예상 복잡도: trivial