MSG-608 feat: 배포 직후 35초 동안 느려지던 지도 홈 집계를 기동 워밍업으로 데운다 - #288
Merged
Merged
Conversation
|
Claude finished @s13121312's task in 5m 55s —— View job 리뷰 완료
확인한 범위: 발견
나머지 확인 결과 — 문제 없음
|
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
테스트 커버리지
|
테스트 커버리지
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
🎫 관련 티켓
작업 내용
dev 서버를 재기동한 직후 지도 홈 줌아웃(미션 집계·핫구역 집계)에 10배 부하(초당 300건)를 걸면 약 35초 동안 핫구역 집계 p95가 3.4초로 뛰고, 관계없는 격자 조회까지 2.6초로 끌려갑니다. 4분 뒤 같은 부하는 p95 130ms입니다. 원인은 JIT 컴파일1입니다. 재기동 후 첫 20초에 컴파일 시간이 36초분(2 vCPU 중 한 코어) 들고, 톰캣 스레드 200개가 전부 대기에 묶입니다.
이 PR은 앱이 뜬 뒤 스스로 그 세 경로를 localhost로 미리 불러 컴파일을 배포 시점으로 옮기는 기동 워밍업을 넣습니다. 워밍업이 도는 동안은 readiness 프로브2로
/actuator/health가 503이라 CD의--wait가 끝날 때까지 기다립니다. 응답 계약, 스키마, 미션·핫구역·격자 코드는 바뀌지 않습니다.flowchart LR subgraph boot["앱 기동"] S[Spring 컨텍스트 준비] --> R[ApplicationReadyEvent] R --> W["WarmupRunner (동기)<br/>핫구역·미션·격자 × N=2,000<br/>4스레드 · 상한 45초"] W -. "localhost HTTP<br/>필터·컨트롤러·JSON까지 데움" .-> API[기존 공개 API 3종] W --> A[ACCEPTING_TRAFFIC] end H["docker healthcheck<br/>GET /actuator/health"] -- "워밍업 중 503" --> R H -- "끝나면 200 → CD --wait 통과" --> A N[nginx] -- "항상 8080 프록시<br/>(차단 아님)" --> API커밋 5개입니다.
WarmupProperties·WarmupConfig(완성RestClient빈),application.yml에fillmap.warmup.*(기본enabled: false,iterations: 2000)과management.endpoint.health.probes.enabled: true. 테스트 리소스는enabled: false명시.WarmupRunner—ApplicationReadyEvent동기 리스너. 대상별 N건을 고정 뷰포트 8개(서울·부산, 구·시 단위)로 번갈아 부르고, 호출별 예외는 실패 수로만 세며 밖으로 내지 않습니다. 격자 조회는 로그인이 필요해TokenProvider로 프로세스 안에서 토큰을 만듭니다(grid-user-id없으면 그 대상만 건너뜀). 단위 테스트 10건.WarmupReadinessIntegrationTest(워밍업 중 503 → 끝나면 200.@SpringBootTest는 리스너가 끝나야 테스트가 시작돼 "도는 동안"을 못 보므로SpringApplicationBuilder로 별도 스레드 기동 + JDKHttpServer스텁이 응답을 래치로 붙잡는 방식) + 프로퍼티 테스트 2건.scripts/msg608-dev-round.sh— env 블록 교체 +--force-recreate), JIT 로그 분석기(scripts/analyze-jit-log.py), Grafana 워밍업 대시보드 URI 수정, 증거 폴더(k6 요약·actuator 샘플·JIT 분석·캡처).docs/spec/MSG-608.md(D1~D9, 작업 로그에 실측표), deploy.md env 3행 + healthcheck 절, status.md, rtm.dev 실측(t3.small, 이 브랜치 이미지, 회차마다 컨테이너 재생성, healthy 직후 k6 10배 60초 + 카나리3 5/s)
워밍업 소요는 N=2,000에서 32.9초(상한 45초). 테스트: warmup 패키지 14건, 회귀 mission·hotzone·grid·region 전부 green. 전체 스위트 3,210건 중 event 패키지 2건(
EventNotificationSchedulerTest,EventSubmissionReviewSchemaTest)이 로컬에서 실패하는데 공유 로컬 DB에 남은 회차·위치 데이터(회차 458건) 때문이라 이 변경과 무관합니다. 전체 스위트는 CI에 맡깁니다.🤔 고민한 내용
진짜 원인을 로그로 굳혔습니다. 워밍업을 짜기 전에 dev에
-Xlog:jit+compilation=debug와-Xlog:class+load를 켜고 같은 부하를 걸었습니다. 부하 창 40초에 컴파일 6,300건이 나왔는데 우리 코드의 C2 승격은 0건이고 Spring MVC·Security 953건, Hibernate 906, Tomcat 462, Netty·Lettuce(Redis) 417, Jackson 106건이 처음 컴파일됐습니다. 클래스 로딩은 327개뿐이었습니다. 요청 경로가 인터프리터 상태였던 것이라, 서비스 빈을 직접 부르는 워밍업(카카오페이 글 방식)이 아니라 HTTP로 필터·컨트롤러·직렬화까지 밟는 워밍업을 골랐고, 클래스 로딩만 줄이는 AppCDS4는 쓰지 않았습니다.실패한 가설이 둘 있었습니다. (1) MSG-576에서 콜드 원인을 미션 스냅숏 재계산 락 대기로 보고 후보 코드까지 짰지만, dev에서는 첫 초 max 251ms로 관측되지 않았습니다. 스냅숏은
warmUpSnapshot()이 기동 때 이미 채우고 있었습니다. 데이터 캐시 워밍업은 있었고 코드 경로 워밍업이 없었던 것입니다. (2) dev의 SQL DEBUG 로깅(분당 25만 줄)이 CPU를 먹어 웜 상태 10배도 실패하던 것을 먼저 걷어냈습니다. 그래도 재기동 직후 35초는 그대로여서 로깅이 원인이 아님을 분리했습니다.반복 횟수는 곡선으로 골랐습니다. 손으로 240회쯤 불러 봤을 때 효과가 없었던 관측이 있어 200/1,000/2,000을 쟀습니다. 200은 효과가 없고(C1 문턱5 근처까지만), 1,000부터 벌점이 35초에서 2초로 줄고, 2,000이 p95 300ms 안에 들어 채택했습니다. 순차 1스레드로는 1,000회부터 상한 45초를 넘어 4스레드 병렬로 바꿨습니다(2 vCPU에서 컴파일 스레드와 경합하므로 8 이상은 늘리지 않음).
"트래픽 차단"은 솔직히 안 됩니다. readiness 503은 docker healthcheck와 CD
--wait만 봅니다. nginx는 항상 8080으로 넘기고 인스턴스가 한 대라, 워밍업 중 들어온 사용자 요청은 워밍업과 경합할 뿐 막히지 않습니다. 그래도 벌점을 배포 시점(사용자가 없는 시각)으로 옮기는 효과는 그대로이고, 진짜 차단은 인스턴스 2대와 로드밸런서에서만 됩니다. deploy.md에 그렇게 적었습니다.리뷰 2라운드에서 고친 것. 토큰 발급이 try 밖이라 예외가 기동을 죽일 수 있던 경로를 격자만 건너뛰게 감쌌고, 통합 테스트가 실패 경로에서 직접 기동한 앱을 안 닫아 공유 DB 커넥션을 물고 남을 수 있던 구멍을
startup.whenComplete로 막았습니다. Codex 교차 리뷰는 없습니다(결제 중단).👀 리뷰 포인트
3.3배인데, 원인은 워밍업 잔여가 아니라 dev에서 **매분 :02:03초에 세 엔드포인트가 함께 1~2초 멈추는 현상**이 60초 창 안에 걸려서입니다(containerd 43% 스파이크 1회 관측, healthcheck 10초 주기와 무관). 별도 조사 티켓으로 뺐습니다. 이 PR 범위에서 더 할 것이 있는지 의견 부탁드립니다.fillmap.warmup.grid-user-id는 점령 격자가 있는 실존 사용자여야 합니다. dev는 586, prod는 배포 때 env로 넣어야 합니다(없으면 격자 조회만 건너뛰고 집계 2종은 데워집니다).management.endpoint.health.probes.enabled=true로/actuator/health/readiness·liveness경로가 생깁니다. 노출 범위(exposure.include)는 그대로입니다.@Transactional(readOnly = true)때문에 요청마다 Hikari 커넥션을 먼저 잡습니다(HibernateJpaDialect가 readOnly면 begin 시점에 커넥션 획득). 이 PR 범위 밖이라 후속 티켓 후보로만 적었습니다.Footnotes
JIT(Just-In-Time) 컴파일: JVM은 자바 코드를 처음엔 한 줄씩 해석해 실행하다가 자주 불리는 메서드를 골라 기계어로 컴파일해 바꿔 끼운다. 컴파일 전 경로는 수십 배 느리고 컴파일 자체도 CPU를 쓴다. 프로세스가 죽으면 결과도 사라져 배포마다 반복된다. ↩
readiness 프로브: 앱이 "요청을 받을 준비가 됐는가"를 스스로 알리는 신호. Spring Boot는
ApplicationReadyEvent리스너가 전부 돌아온 뒤에야ACCEPTING_TRAFFIC으로 바꾸고, 그 전에는/actuator/health가 503을 준다. 원래 쿠버네티스용이지만 여기서는 docker healthcheck와 CD--wait가 같은 신호를 본다. ↩카나리 요청: 측정 대상이 아닌 다른 API(격자 뷰포트 조회)를 초당 5건 같이 보내, 대상이 느려질 때 서버 전체가 같이 느려지는지 보는 요청. 배율 = 부하 중 p95 ÷ 평소 p95. ↩
AppCDS: 앱이 쓰는 클래스를 미리 파싱·검증해 파일로 저장해 두고 기동 때 그대로 매핑하는 JDK 기능. 줄이는 건 클래스 로딩이지 JIT 컴파일이 아니다. ↩
컴파일 문턱: HotSpot은 메서드 호출 횟수를 세서 수백 회에서 C1(빠르지만 덜 최적화), 수천~1만 회 이상에서 C2(충분히 최적화)로 단계별 컴파일한다. 워밍업 N건은 C1까지를 배포 시점으로 옮기고 C2는 배포 뒤 실제 요청이 마저 채운다. ↩