이틀 만에 만든 서비스의 기술 부채, 운영에서 개선하기

운영 중인 발음 교정 서비스는 이틀 만에 만든 PoC로 시작했습니다. 운영진을 설득해야 했고, 시장이 반응하는지 빨리 확인해야 했으니까요. AI와 함께 속도를 우선해 쌓았고, 그 선택 덕분에 클로즈 베타와 테스터 모집을 거쳐 베타 서비스까지 왔습니다.

운영에 들어가자 운영진의 보고가 쌓이기 시작했습니다. "로그인이 느린 것 같아요", "D1이 느려서 AWS로 옮겨야 하는 것 아니에요?", "쓸 사람이 없는 시간인데 트래픽이 떠요" 같은 보고들입니다. 에러 로그 없이 전부 정상 응답인데 느리기만 했습니다. 어디부터 봐야 하는지조차 명확하지 않은 상태에서 조사를 시작해야 했습니다.

베타 환경에 wrangler tail을 걸고 요청마다 wallTime과 cpuTime을 기록했습니다. 연산은 적은데 전체 시간만 길다면, 코드가 느린 게 아니라 무언가를 기다리고 있다는 뜻입니다.

wrangler tail: 배포된 Cloudflare Workers의 요청 로그를 터미널에서 실시간으로 지켜보는 명령어.요청마다 wallTime(응답까지 걸린 전체 시간)과 cpuTime(그중 실제 연산에 쓴 시간)이 함께 남습니다.

결정적 단서는 세션 조회였습니다. 전체 573ms가 걸리는데 실제 연산은 11ms뿐이었습니다. 나머지 562ms는 무언가를 기다리는 시간이었고, 그 정체는 세션을 빠르게 하려고 넣어둔 KV 캐시였습니다.

측정으로 특정한 원인은 네 가지였고, 넷 다 초기에 속도를 위해 들어간 코드였습니다.

첫 번째는 세션 캐시로 쓰던 KV였습니다. 처음에는 세션 조회를 줄이기 위해 넣었지만, 최종 일관성 때문에 세션 상태가 늦게 반영됐습니다. 이 지연은 20분마다 로그인이 풀리는 버그로 이어졌고, 결국 세션의 기준 저장소는 D1으로 옮겼습니다. 이후 측정에서는 KV를 거치는 경로가 성능까지 깎고 있어, 남아 있던 캐시 계층도 제거했습니다.

갤러리 조회도 필요한 데이터보다 훨씬 많은 데이터를 읽고 있었습니다. 카드에는 이미지 주소만 필요했지만, 쿼리는 레거시 캔버스 데이터를 포함한 전체 레코드를 가져왔습니다. 카드가 519개인 선생님 계정에서는 응답 크기가 6.64MB였고, 그중 97%는 화면에서 사용하지 않는 데이터였습니다. 세션 정보가 준비되기 전에 쿼리가 실행돼 동일한 요청이 다시 발생했고, 요청 단위로 세션 조회를 공유하지 않아 한 화면에서 세션 조회가 다섯 번 반복됐습니다.

하나씩 걷어내고 묶은 결과입니다.

"쓸 사람이 없는 시간에 트래픽이 뜬다"는 보고는 5분간 들어오는 요청을 그대로 받아 적는 것으로 확인했습니다. 5분간 요청은 6건, 전부 같은 출처였습니다. Sentry의 업타임 모니터링 봇이 정확히 60초 간격으로 랜딩 페이지를 호출하고 있었고, 살아 있는지 확인하는 데 매번 페이지 전체를 서버 렌더링시키고 있었습니다. 하루 1,440회입니다. 같은 5분 동안 실사용자 요청은 0건이었습니다. 경량 헬스체크 엔드포인트를 만들어 봇을 그쪽으로 보냈습니다.

이른 아침 스파이크는 학생들의 과제 제출이었습니다. 시간대별 활동 기록을 세어 보니 오전 7시대에 몰려 있었습니다. 제출 한 건에 문장 수만큼 오디오가 올라가고, 그 뒤로 워크플로와 알림이 이어집니다. 팀에게는 "쓸 시간이 아닌" 시간대가 학생에게는 등교 전이었습니다.

"D1이 느려서 AWS로 옮겨야 하나"라는 질문에 대한 답은, D1 쿼리는 처음부터 45~96ms로 정상이었고 문제는 그 앞에 쌓인 캐시 계층과 호출 패턴이라는 것이었습니다. 인프라 이전은 필요 없었습니다.

빠르게 만든 것 자체를 후회하지는 않습니다. 그 속도가 없었으면 설득도 베타도 없었을 테니까요. 다만 이번에는 실측으로 되짚고 나서야 원인을 찾았습니다. 다음에도 wallTime과 cpuTime부터 볼 생각입니다. 아직 남은 빚도 있습니다. 연산이 무거운 프로시저 하나와 30초 폴링의 재검토가 다음 차례입니다.