크롤러 로그의 500이 전부 장애는 아니었다, 4,134건 중 회복 0건을 증명한 이야기

법원경매 정보를 모으는 배치 크롤러의 로그에 HTTP 500이 매번 수백 건씩 쌓여 있었다. 재시도 로직이 이걸 세 번씩 다시 요청하고 대부분 다시 실패했다. 결론부터 말하면 그 500은 서버 장애가 아니라 사라진 문서에 대한 안정적인 거부 응답이었고 재시도를 통째로 버리고 “소멸 판별”로 바꾼 뒤로는 소멸 물건당 요청이 4회에서 2회로 줄었다. 첫 프로덕션 실행에서는 런타임이 9.3시간에서 7.66시간으로 짧아졌다.

증상은 “매번 실패하는 문서 100여 개”였다

크롤러는 매물마다 법원 사이트에서 문서를 내려받는다. 명세서(SPEC)와 기일공고(NOTICE) 두 종류가 있는데 기일공고 쪽 문서뷰어 API인 selectDocVwrInf가 특정 물건에서만 500을 냈다. 직전 실행 기준 108개 물건이 그랬고 재시도 3회를 포함하면 324번의 실패 로그가 찍힌다. 나머지 약 94%는 같은 실행에서 정상적으로 성공했다. 서버 전체가 죽은 게 아니라 특정 문서만 선택적으로 죽어 있는 그림이었다.

문제는 이걸 일시 장애로 분류해둔 내 코드 쪽이었다. 명세서에는 소멸 판별 로직이 있었는데 기일공고에는 없어서 죽은 문서를 매 실행마다 transient로 분류하고 3회씩 재시도한 것이다.

첫 번째 증거: 시간이 지나도 안 살아난다

일시 장애라면 시간이 약이다. 그래서 500으로 끝난 108건 중 9개 법원 샘플을 골라 11시간 뒤 로컬 IP에서 다시 요청해봤다. 전부 3회 모두 500이었다.

응답 속도가 결정적이었다. 53~79ms 만에 돌아왔다. 타임아웃이나 과부하라면 이렇게 빠를 수 없고 서버가 즉시 거부하고 있다는 뜻이다.

체인 앞단도 멀쩡했다. 열람등록 단계는 9건 모두 200 OK에 정상 파라미터까지 발급됐다. 죽는 곳은 문서뷰어 딱 한 곳이었다. 법원 쪽 야간 배치에서 물건이 정리되면서 문서 ID가 소멸한 것으로 추정했다. 이건 어디까지나 추정이고 확정 증거는 다음 단계에서 나왔다.

두 번째 증거: 재시도가 단 한 번도 성공시킨 적이 없다

“재시도가 의미 있다”는 건 회복 사례가 존재한다는 뜻이어야 한다. 그래서 지난 11일치 실행 로그 6개를 전수로 뒤졌다.

핵심은 정합성이다. 500 응답 수가 매번 “실패 물건 수 × 3회”와 정확히 일치했다. 즉 모든 500은 죽은 문서가 3회 동일하게 실패한 것이고 2회차나 3회차에 200으로 돌아온 적이 단 한 번도 없었다. 총 4,134건의 500 중 회복 0건이었다.

0907 실행에 [500, 500, 200] 패턴으로 보이는 13건이 있어서 예외인가 했는데 버스트 단위로 로그를 다시 펼쳐보니 인접 물건으로 넘어가는 경계였다. 같은 물건의 회복이 아니었다.

처음엔 직전 실행 로그만 보고 판단하려다가 과거 실행 전부를 확인해야 한다는 지적을 받고 범위를 넓혔다. 단일 실행만 보면 그날 우연히 안 됐는지, 원래 안 되는 건지 구분이 안 된다. 이 지적이 안 있었으면 “그날 서버가 불안정했다”로 결론냈을 거다.

세 번째 증거: 브라우저에서는 “잘못된 번호”라고 한다

서버 입장을 확인했다면 이번엔 사용자 입장이다. Playwright로 경매사건검색 화면을 직접 띄워 실패한 사건번호를 검색해봤다.

대구 2025타경10855와 인천 2025타경34139, 둘 다 “해당 사건번호는 잘못된 번호입니다”라는 메시지와 함께 빈 화면이 나왔다. 대조군으로 넣은 인천 2025타경507416은 기본내역, 물건내역, 당사자내역이 전부 정상 렌더링됐다. 검색 기능 자체는 멀쩡하고 실패한 사건만 법원 쪽에 존재하지 않는 번호로 응답하는 것이다. API의 500이 UI에서는 “잘못된 번호”로 나타난다는 걸 양쪽에서 확정했다.

재시도를 버리고 소멸 판별로

증거가 셋이니 설계를 바꿨다. 당초 계획은 “재시도 전에 소멸 판별을 앞에 추가하는 것”이었는데 회복 0건 증거가 나오면서 실행 내 500 재시도 자체를 제거하는 쪽으로 확장됐다.

// 500은 1회 시도 후 즉시 throw
// 근거: 6개 실행 4,134건 500 중 재시도 회복 0건
// 429, 502, 503, 504는 재시도 유지

500은 1회 시도 후 즉시 예외를 던지고 429는 과속 신호라 재시도를 유지했다. 502, 503, 504는 관측 데이터에 없었는데 게이트웨이 일시 장애 가능성을 고려해 재시도를 남겨뒀다. 상태 코드마다 근거를 다르게 못 박은 게 이번 변경의 핵심이다.

그다음은 분기다. 500이 뜬 문서가 정말 소멸했는지는 사건검색 API인 15A에 물어본다. 15A의 처분물건 배열에 해당 물건번호가 있으면 아직 살아있는 것이고 배열이 비어있으면 소멸이다. 실측하면서 알았는데 15A가 죽은 사건을 부르면 에러가 아니라 200에 434바이트짜리 빈 봉투가 온다. 브라우저의 “잘못된 번호”와 정확히 일치하는 API 단 증거였다.

한 가지 비대칭도 그대로 남겼다. 명세서는 빈 ID를 일시적 실패로 보지만 기일공고는 소멸로 본다. 공개 창이 닫히면 철거되는 문서 특성이 양쪽이 다르기 때문이다.

스킵은 영구 무시가 아니라 DB 상태다

소멸 판별을 통과하면 물건을 지우는 게 아니다. 판별 순간 해당 컬럼을 null로 만들고 다음 실행의 대상 선정 조건 자체가 “값이 있을 때”라서 목록에 애초에 포함되지 않는다. 물건 행은 그대로 남아 서비스에 계속 노출된다. 없어지는 건 죽은 문서를 찾아다니는 행위뿐이다.

재공고로 사건이 살아나면 15A에서 새 문서 ID가 발견되는 순간 자동으로 다시 주입된다. 죽은 문서는 멈추고 재공고되면 자동 복구되고 안 오면 은퇴하는 구조다.

구현은 소스 5개와 테스트 2개, 단위 테스트 210건을 통과시켰다. 이슈가 있었던 법원 중 가장 작은 춘천지방법원에서 드라이런했는데 실패 물건 5건이 전부 소멸로 판정됐다. 요청 흐름은 열람등록 200, 문서뷰어 500이 1회(예전엔 3회), 15A 빈 봉투, 판정 소멸의 순서였다. 물건당 요청이 4회에서 2회로 줄어든 것을 직접 확인했다.

숫자를 오독하면 생기는 일

이 작업을 하면서 같은 코드베이스에서 숫자 오독 사건을 두 건 더 정리했다.

첫 번째는 9시간짜리 실행이었다. 평시 6.5시간 대비 오래 걸려서 성능 저하로 의심했는데 알고 보니 직전 11일간 클라우드 수집이 전부 실패해 쌓인 백로그를 한 번에 소화한 것이었다. 처리량을 보니 전 구간이 시간당 8,300~11,500 요청으로 일정했다. 느려진 게 아니라 일이 많았던 거다. 잡이 끝나고 Cloud Batch 콘솔에 FAILED가 떠서 놀랐는데 이건 수집 실패가 1건이라도 남으면 exit 2로 종료하는 설계된 계약이었다. 플랫폼이 0이 아닌 종료 코드를 전부 FAILED로 표시할 뿐이었다. 상태 필드가 아니라 로그의 종료 마커를 봐야 한다.

두 번째는 분석 대상 DB를 잘못 고른 거였다. 쿼리를 날렸는데 클라우드 실행 창 안에 쓰기 기록이 0건이었다. 데이터는 있는데 쓴 적이 없다는 모순이 발견돼서 조회했던 DB가 로컬 개발 DB라는 걸 알아냈다. 데이터가 최신으로 보여도 프로덕션 판별 근거는 못 된다. 시간 창 기반 교차 검증이 가장 확실한 신호였다.

첫 프로덕션 실행의 결과

소멸 판별을 탑재한 첫 프로덕션 실행에서 세 가지가 확인됐다. 우선 예전에 오류로 집히던 소멸 물건 346건이 별도 카운터로 분리돼 나왔다. 실행 자체가 깔끔해졌다. 둘째, 런타임이 9.3시간에서 7.66시간으로 1.6시간 줄었다. 스케줄 이전 효과와 소멸 스킵이 겹친 것으로 보는데 정확한 기여분 분리는 못 했다. 셋째, 남은 failed 3건의 정체가 PostgreSQL 22003, 숫자 범위 초과 에러라는 게 원인 코드 로그 개선 덕에 바로 드러났다. 어느 컬럼에서 터지는 건지는 아직 못 찾았고 다음 실행에서 잡을 과제로 남아 있다.

돌아보면 이 사가 전체가 같은 질문의 반복이었다. 500은 정말 장애인가. 9시간은 정말 느려진 건가. FAILED는 정말 실패인가. 로그의 숫자를 설계 당시의 가정으로 읽지 말고 지금 쌓인 증거로 다시 읽어야 한다는 게 이번 주에 몸으로 배운 거다.