wodup 인입 수리 — 유령 "처리 중"·실패 4연타·진행률 신호·정본 기입 후속 최적화 (2026-08-21)
- 기간: 2026-08-21 저녁 ~ 08-22 (세션 3개 — ① 유령 "처리 중" 수사·#543 / ② 2~4차 실패 수리 + 진행률 바(#548·#559·#562·#566, 계정 전환 승계 1회) / ③ 재인입 완주 후 후속 #572)
- 랜딩: PR #543 · #548 · #559 · #562 · #566 · #572, 마이그레이션 6건(
20260821230000·270000·320000·335000·390000·400000) 전부 Production 적용 +check:remote-schemaEXIT=0, 엣지 2종(wodup-start-import·wodup-process-import-jobs) 재배포 1회(#562), Vercel 배포 3회(#543 · #548 · #562) - 결과: 08-22 13:04 KST 오너 재인입 완주 — 620세션 · 1,588종목 · 8,054세트 · 매핑 258 · placeholder 0 · 오류 0. 정본 기입 RPC 1회 ≈ 50s(8초 벽에 사망) → 120s 상한으로 통과 → 후속 최적화 뒤 ≈ 18s
- 런북·계약:
docs/data/import-pipeline.md(실패 배치 스테이징 보존 정책 반영) ·docs/data/wodup-import-async-jobs.md
1. 배경
일회성 인입 전환(2026-08-21-brid-identity-system.md)과 08-20 전량 제거 뒤, 오너의 새 WodUp export(2022~2026, 620세션·7,291세트 원본)를 다시 들이는 일이 남아 있었다. 사전 분석·파서 보강·카탈로그 대조는 끝나 있었고(2026-08-21-exercise-catalog-curation.md), 할 일은 "파일을 올리는 것"뿐이었다.
08-21 저녁 오너가 barbelic.com에서 파일을 올리자 화면이 "처리 중"에 멈췄다. 그날 밤 자정을 넘기며 재시도마다 다른 결함이 하나씩 드러나는 4연타가 이어졌고 — 화면 상태 이름 충돌, 한글 종목명 바이트 상한, 스테이징 O(n²), 스테이징 삭제 인덱스 부재와 8초 문장 타임아웃 — 전부 같은 밤에 수리해 다음 날 정오 재인입이 완주했다. 완주 뒤 "정본 기입 50초"의 진범을 계측으로 찾고, 실패 배치가 남긴 스테이징 행의 보존 정책을 정하는 후속까지가 이 기록의 범위다.
2. 문제 제기
화면은 "처리 중", 서버는 요청 0건 (1차)
드롭 즉시 "원본 저장 ✓ · 서버 정규화 스피너"가 떴지만 Supabase 게이트웨이 로그에 업로드 요청이 0건이었다. 이후 재드롭은 전부 무반응 — 처리 중 화면엔 드롭존이 없었다. 시크릿 모드·확장 제거·최근 배포 롤백 후보 전부 무관했다.
정본 기입이 400으로 죽는데 화면은 영영 스피너 (2차)
수리본으로 재시도하자 업로드·정규화(620세션)·스테이징(1,588종목)은 통과했지만 정본 기입 RPC가 400 → 배치 failed(원자 롤백, 정본 0행). 그런데 화면은 실패를 보여주지 못하고 스피너에 고착됐다 — 서버 결함과 클라이언트 결함이 한 시도에 겹쳐 있었다.
스테이징이 청크마다 배치 전체를 다시 파생했다 (3차)
다음 재시도는 스테이징 단계에서 statement timeout(57014). 50줄 청크 13개 중 10번째가 8초를 넘겼다 — 청크 소요가 1.0s → 7.0s로 자라고 있었다.
실패 배치의 잔존 행이 다음 시도를 더 느리게 만들었다 (4차)
수리본의 재시도는 카탈로그 패스 15초 통과·진행률 정상 → 최종 패스 첫 청크(p_reset=true)에서 8초 타임아웃. 실패 배치마다 스테이징 행이 쌓여 reset 삭제가 시도마다 무거워지고 있었고, 그 다음 단계인 정본 기입은 48.5초였다 — 어느 쪽도 8초 안에 들어올 수 없었다.
진행률이 가짜였다
"원본 저장 → 정규화 → 정리 → 기입" 단계 표시는 있었지만 비율은 indeterminate였다. 30초 넘게 스피너만 도는 화면에서 오너는 멈춘 건지 도는 건지 알 수 없었다.
"50초"의 진범을 모른 채 상한만 올렸다 (후속)
4차 수리는 service_role의 문장 상한을 120초로 올려 정본 기입을 통과시켰고, 머리말엔 "row 트리거 부하(exercise_sets 9 · session_exercises 9 · sessions 5 × 1만 행)"로 적었다. 추정이었다. 실패 배치 3건의 스테이징 행(rows 1,690 · sessions 1,690 · exercises 4,316 · sets 21,939)도 그대로 남아 있었다.
3. 해결 방안
원칙
- 실측 없이 단정하지 않는다. 게이트웨이 로그(management API), 라이브 번들 해시 대조, Production 롤백 트랜잭션 계측(
track_functions+pg_stat_xact_user_functions차분)으로 "어디서 몇 초"를 먼저 확정하고 그 자리만 고친다. - 수리는 원인 자리에만, 함수는 전문 재선언(SCR-3), 의미 불변. 청크 범위 파생·바이트 상한· 인덱스 — 결과 행이 달라지지 않는 변경만.
- Production 비가역 직전엔 롤백 트랜잭션으로 before/after를 잰다. 인덱스·수정 본문을 같은 롤백 트랜잭션에 넣어 측정하면 적용 전에 효과가 증명된다.
- 실패는 원자적으로, 흔적은 남긴다. 실패 배치의 행·
error_message·원본은 보존하고, 스테이징 행은 진단 유예(7일) 뒤 정리한다. - 재시도 비용은 상수여야 한다. 누적량에 비례하는 경로(청크 파생·cascade 삭제)는 구조로 잠근다.
- 유저 경로 상한(8초)은 건드리지 않는다. 올리는 건 엣지 워커가 쓰는 service_role뿐.
접근
실패 한 번 = 수리 한 건. 각 시도 직후 Production 로그·롤백 계측 → 최소 수리 → 격리 로컬 스택에서 수리 전 엔진으로 음성 대조군 확보 후 pgTAP → 랜딩 → Production 적용 → 재측정 → 오너 재시도. 완주 뒤에는 "50초"를 함수 단위로 쪼개 본 다음에야 최적화했다.
4. 적용한 내용
4-1. 1차 — 유령 "처리 중" (#543, 클라이언트만)
wodupImportController.ts의 isProcessingWodupImportStatus가 드래프트 status **'ready'(파일 사전검사 완료·시작 대기)**를 처리 중으로 분류하고 있었다 — 서버 배치 status 'ready'(정규화 완료)와 이름이 충돌한 것. 파일을 고르기만 해도 phase가 processing으로 렌더되고 인입 시작 버튼이 영영 나오지 않아 업로드 API는 시작조차 안 됐다. 수리 + 회귀 계약 3건 (wodupImportViewPhase.test.mjs). 클라이언트 번들이라 Vercel 배포가 나가야 적용 — 라이브 번들 전이 크롤로 DesktopAdminFeature-*.js의 상태 목록이 수정본임을 확인한 뒤 오너에게 넘겼다.
수사 과정의 헛다리(#527 배포 시각과의 상관관계, Vercel 스테일 빌드, auth 잠금, 확장 간섭)는 게이트웨이 로그와 배포 번들 정적 분석(마이그레이션 기대값 문자열로 빌드 시점 특정, 로컬 빌드 해시 비트 일치)으로 하나씩 배제했다. 재현은 워크트리 + 격리 supabase 스택 + vite dev + __BARBELIC_E2E_CONFIG__ 인라인 오버라이드로 만든 로컬 풀스택 리그에서 했다.
4-2. 2차 — synonym 바이트 상한 + 폴링 무대기 (#548, 230000)
- 서버:
import_wodup_batch_to_canonical_engine이 미매핑 종목명을left(…, 80)(문자)로만 자르는데, synonym 컷오버의 미러 트리거가 그 이름을exercise_synonyms(160바이트 check)로 복사한다. 한글 54자를 넘는 이름은 23514 — export 526키 중 단 1건(wodup:global:119644, 98자/166바이트)이 배치 전체를 죽였다. 수리는 그 자리만left_utf8_bytes(left(…, 80), 160)(세션 제목 등 다른 텍스트는 이미 같은 헬퍼로 160B 준수). 격리 스택에서 수리 전 23514 재현 → 적용 후 pgTAP 537 PASS. - 클라이언트: 관리자
pollWodupImportBatch가 start 응답 뒤startTracker ? race(sleep) : null로 대기 없이 돌아 15초에 181회(MAX 180) 소진·중단 → 47초 뒤의 failed 전이를 못 봤다(프로필 runner는 두 분기 모두 대기해 멀쩡). 비-tracker 분기도 sleep + 소스 계약 테스트.
4-3. 3차 — 스테이징 호출 비용을 청크 범위로 (#559, 270000)
stage_wodup_import_batch_engine이 청크마다 배치 전체 줄에서 세션·종목·세트를 다시 파생·업서트하고, 복합종목 검증은 복합 행마다 전체 스테이징을 상관 서브쿼리로 재스캔했다. Production 롤백 계측(450줄 상태): 빈 청크 1회 1.8~2.2s, 그중 복합 검증 1,035ms · 세트 파생 202ms(#550의 refresh 190ms는 무죄). 첫 시도가 통과한 건 스테이징 테이블이 비어 있었기 때문. 수리: 청크 줄 번호를 임시 테이블에 담아 파생 세 곳에 조인 + 그룹 구성원 수 1회 집계. 재전송 줄은 그대로 upsert라 의미 불변. pgTAP wodup_import_stage_chunk_scope(7): 두 청크 == 한 번 호출 + 첫 청크 세트 ctid 불변(구 엔진에서 실패하는 음성 대조군). 적용 후 같은 상태 빈 청크 0.4s(상수).
4-4. 진행률 실제값 (#562, 320000, 엣지 2종 재배포)
wodup_import_batches.progress jsonb + 워커 reportProgress(best-effort, normalizing 행에만; 카탈로그 패스 = normalize k/N, 최종 패스 = staging k/N, 정본 기입 = canonical 0/0 — 한 트랜잭션이라 단계 안 비율 없음) + 클라이언트 select/어댑터/타입/buildProgress(stage → 활성 단계·pct·"k/N줄", 신호 없으면 기존 indeterminate). 계약 2파일 신설.
4-5. 4차 — 스테이징 row_id 인덱스 + service_role 120s (#566, 335000)
롤백 계측: delete from wodup_import_rows where batch_id = … 8,627ms — 자식 3테이블의 row_id FK(ON DELETE CASCADE)에 인덱스가 없어 부모 620행마다 자식을 순차 스캔(세트 29k행, 실패 배치 잔존 행이 쌓일수록 악화); 임시 인덱스로 27ms. 다음 단계 정본 기입 import_wodup_batch_to_canonical은 48.5s. 함수 정의의 SET statement_timeout은 이미 무장된 타이머를 재무장하지 않는다(Production pg_temp 함수 실험으로 확정) → alter role service_role set statement_timeout = '120s' + notify pgrst, 'reload config'(PostgREST가 impersonated role 설정을 요청마다 적용). anon/authenticated는 불변. 수리 후 삭제 119ms. PostgREST가 역할 설정을 실제 적용하는지는 service key 없이 직접 증명할 수 없었고 — 08-22 13:04 KST 오너 재업로드(배치 1689c6f5) 완주(스테이징 300/620 진행 표시 → importing → 50초 뒤 completed)가 증명했다.
4-6. 후속 — "50초"의 진범과 실패 배치 스테이징 보존 정책 (#572, 390000 · 400000)
Production 롤백 트랜잭션에서 오너 배치를 제거 → 재기입 → 통계 처리하고 함수별 시간을 차분했다:
| 구간 | 시간 |
|---|---|
remove_import_data_v1 (참고) | 13.6s |
import_wodup_batch_to_canonical — 엔진 본체 + row 트리거 전부 | 5.3s (트리거 합 ~2.7s: calendar dirty 0.72 · set limits 0.64 · effective load 0.27 · fact identity 0.24 · …) |
인라인 통계 process_user_exercise_stats_refresh_jobs_for_user | 50.5s |
↳ refresh_user_set_purpose_projection | 38.5s |
↳ refresh_user_strength_estimation_projection_core | 7.7s |
↳ validate_user_exercise_stats_integrity | 2.2s |
"트리거 부하"가 아니었다. set-purpose 투영의 첫 UPDATE가 관측 행마다 같은 (user_id, session_exercise_id)의 뒤 세트(set_position >)를 상관 exists로 찾는데 user_exercise_strength_observations에 session_exercise_id를 앞세운 인덱스가 없어 행마다 유저 관측 전부(8,203행)를 훑었다 — 8,203² ≈ 6,700만 행 방문. 같은 롤백 트랜잭션에 (user_id, session_exercise_id, set_position) 인덱스를 만들고 재측정: 38.5s → 1.07s(생성 18ms, 플랜 = Index Cond 세 컬럼). 이것이 400000(함수 본문 무변경). 적용 후 Production 재측정 1.21s.
390000은 실패 배치 스테이징 보존 정책이다. 실패 배치는 종착 상태라(start가 409로 거부, 재시도는 새 배치, requeue는 원본 파일에서 p_reset=true 재스테이징) 그 스테이징 행은 어떤 경로에서도 다시 읽히지 않는다 — 가치는 진단뿐(4차의 8.6초 계측이 이 행들로 이뤄졌다). 그래서 즉시가 아니라 7일 보존 뒤 지운다: purge_wodup_import_failed_staging_v1(p_keep '7 days', p_batch_limit 20) (privileged/관리자만, 1시간 미만 보존 거부, 배치 단위로 sets → exercises → sessions → rows, 영수증 jsonb) + cron barbelic-wodup-failed-staging-purge(매일 04:27 UTC) + 같은 함수를 p_keep='1 hour'로 한 번 불러 08-21 실패 3건을 즉시 정리. 배치 행·error_message·원본은 남고 완료 배치 스테이징은 불변(절차 A의 재인입 재료). pgTAP wodup_import_failed_staging_purge(13) · strength_observation_entry_position_index(2).
주요 결정과 그 근거
- 상태 전이의 정본은 배치 행, 화면 신호는 best-effort. 폴링·진행률은 보조 정보라 실패해도 인입을 막지 않고, 화면은 배치 status 전이만 믿는다(1차·2차·진행률 수리의 공통 축).
- 한글 이름 상한은 문자가 아니라 바이트. synonym 미러 계약(160B)과 같은 상한을 같은 헬퍼로 — 두 제약이 엇갈릴 수 없다.
- 청크 범위 파생. 워커가 청크로 나눠 보내는 이상 엔진은 "이 호출이 가져온 줄"만 파생해야 호출 비용이 상수다. 재전송 줄은 upsert로 흡수되므로 의미는 변하지 않는다.
- 역할 상한은 워커만. 유저 경로(anon/authenticated) 8초는 유지하고 service_role만 120초. 후속 최적화로 정본 기입이 ≈18초가 된 뒤에도 오너 결정(08-22): 120초 유지 — 비용이 세션 수에 비례하므로(2~3배 큰 export ≈ 40~55초) 여유를 남긴다. 되돌리기는 한 줄 (
alter role service_role reset statement_timeout; notify pgrst, 'reload config';). - 최적화는 계측 뒤에. #566의 "트리거 부하" 추정을 그대로 좇았다면 엔진 본체(5.3초)를 손댔을 것이다. 함수별 차분이 38.5초짜리 한 줄(상관 exists)을 가리켰고, 인덱스 한 개로 끝났다.
- 인라인 통계는 그대로 둔다.
completed= "통계까지 준비됨"의 의미를 유지한다. 18초면 120초 안에서 충분하고, 분리하면 화면이 통계 지연을 따로 다뤄야 한다. - 실패 배치 스테이징은 7일 보존. 즉시 삭제는 진단 재료를 잃고, 영구 보존은 재시도마다 무거워진 원인이었다. 완료 배치는 건드리지 않는다.
작업 중 드러난 것
- Production 실측 경로: management API
POST /v1/projects/<ref>/database/query(토큰~/.supabase/access-token)가 SQL을 실행한다 —begin; … select <report>; rollback;로 쓰면 안전하고 API는 마지막 행 반환 statement의 결과를 돌려준다.postgres역할의 statement_timeout은 2분이고 statement별이라 긴 계측은 DO 블록을 나눈다.set local track_functions='all'+pg_stat_xact_user_functions스냅샷 차분이 함수별 시간을 준다. one-shot 게이트는 같은 트랜잭션에서remove_import_data_v1→ 배치 status 덮어쓰기 → 래퍼 호출로 우회(전부 롤백). jwt claim은set_config('request.jwt.claim.sub' …). - 함수 정의의
SET statement_timeout은 무장된 타이머를 재무장하지 않는다 — 상한을 바꾸려면 역할 설정뿐. - 배포 확정 기법: GitHub deployments API(
environment=Production – barbelic)로 sha↔배포 URL을 맵핑하고 각 배포 URL의 index 해시를 읽으면 "지금 www가 어느 커밋인가"가 확정된다. 번들 문자열은 백틱 템플릿 리터럴이라 큰따옴표 grep은 0건. - 번호가 세 번 밀렸다(210000→230000, 290000→320000, 325000→335000) — 같은 밤 병행 트랙 4개가 랜딩하면 번호는 push 직전 꼬리로만 확정된다. 재이식 때 내 커밋 파일을 통째 올려 #561의
barbelicRepository수정이 되돌아갈 뻔한 것을 계약 테스트가 잡았다(교집합만 main 위에 hunk 재적용). - 로컬 격리 스택 패턴: scratchpad
config.toml(고유 project_id·포트 블록) +migrations/testsjunction →supabase start -x …→ 수리 전 상태에서 새 pgTAP만 돌려 음성 대조군 → 적용 →test db. 정리는cmd /c rmdir로 junction만 먼저 떼고 실제로 사라진 걸 확인한 뒤. - pgTAP에
like()는 없다(alike).plan(n)은 마지막에 다시 센다. - Browser 페인이 비표시 상태면 스크린샷·좌표 클릭을 믿지 말 것 — fetch 후킹·React 파이버 판독이 결정적이었다.
- HQ 세션이 ListAgents에 없을 때 번호 신고는 열린 PR의 마이그레이션 파일 스캔으로 대체했다.
5. 적용 결과
| 항목 | 결과 |
|---|---|
| 오너 재인입 | 08-22 13:04 KST 완주: 620세션 · 1,588종목 · 8,054세트 · 매핑 258 · placeholder 0 · 오류 0 (실패 배치 3건을 거쳐) |
| 정본 기입 RPC 1회 | 48.5~50s(8초 벽에 사망) → 120s 상한으로 통과 → ≈18s(엔진 5.3 + 통계 ~13; set-purpose 38.5s → 1.2s 실측) |
| 스테이징 청크 | 1.0s → 7.0s로 증가(10번째 57014) → 0.4s 상수 |
| 스테이징 reset 삭제 | 8,627ms → 119ms |
| 화면 | 유령 "처리 중" 0(회귀 계약 3건) · 실패 전이 표시 · 실제 진행률(k/N줄) |
| 실패 배치 스테이징 | rows 1,690 · sessions 1,690 · exercises 4,316 · sets 21,939 → 0 + 7일 보존 cron |
service_role statement_timeout | 8s → 120s (오너 결정: 유지) |
| 마이그레이션 | 6건 Production 적용, check:remote-schema EXIT=0, 엣지 2종 재배포 1회 |
| 테스트 | pgTAP 34 → 40파일, 537 → 583 PASS(wodup_external_name_bytes_bound · wodup_import_stage_chunk_scope · wodup_import_staging_row_id_index · wodup_import_failed_staging_purge · strength_observation_entry_position_index 등) · 계약 테스트(wodupImportViewPhase · wodupImportProgressView · wodupImportWorkerProgress · 폴링 소스 계약) · npm test 1,697 |
6. 이번 개선으로 향상된 것
인입이 보이는 대로 움직인다
파일을 고르면 시작 버튼이 나오고, 단계 표시는 실제 청크 비율을 따르고, 실패하면 화면이 실패를 보여준다. 화면 상태와 배치 행이 어긋나는 경로가 없다.
재시도가 싸졌다
스테이징 청크 비용과 reset 삭제가 누적량과 무관한 상수가 됐다. 실패가 다음 시도를 느리게 만들지 않고, 남는 행도 7일 뒤 정리된다.
큰 export가 통과한다
워커 경로의 문장 상한 120초 안에서 정본 기입이 ≈18초 — 2~3배 큰 export도 여유가 있다. 유저 경로 상한은 그대로다.
통계 갱신 전체가 빨라졌다
set-purpose 투영의 O(n²)는 인입만의 문제가 아니었다 — 저장·편집·cron이 부르는 모든 통계 갱신이 같은 함수를 거친다. 기록이 많은 유저일수록 체감이 크다(오너 기준 38.5초 → 1.2초).
남은 것
refresh_user_strength_estimation_projection_core7.7s(세션 투표 루프의 per-session UPDATE +user_exercise_pr_events조회) — 통계 트랙 몫으로 기록만.