로컬에서 재현이 안 된 건 버그가 없다는 뜻이 아니었다
Railway로 옮긴 뒤 의정보기 웹의 메모리가 26시간 동안 226MB에서 833MB로 곧게 올랐다. 렌더 부하도 아니고 같은 스택의 옆 서비스는 멀쩡했다. 맥에서 3,000건을 때려도 재현이 안 돼 "요청량으로는 재현 불가"라고 적었는데, 컨테이너 안에서 다시 재니 요청당 388KB였다. 플랫폼이 신호를 가리고 있었다
의정활동 트래커(의정보기)의 웹은 Railway로 막 옮겨 온 Next.js 프론트다. 대시보드를 보니 읽기 API 서버보다 프론트가 메모리를 더 쓰고 있었고, 26시간치 시계열을 뽑으니 톱니가 아니라 곧은 직선이었다. 동시성을 낮추거나 캐시를 줄여서 될 문제가 아니었다.
하려던 것
새벽 한 시에 Railway 대시보드를 보다가 의정보기 웹이 눈에 걸렸다. 읽기 API 서버보다 프론트가 메모리를 더 쓰고 있었다.
의정보기 웹의 메모리 사용량을 더줄일 수 있어?? 레일 웨이 확인좀
한 시간 뒤에 하나 더 물었다.
왜 api 서버보다 더 높은거야??
처음엔 튜닝 질문이라고 생각했다. 동시성을 낮추거나 캐시를 줄이면 될 일이라고 봤다. 그래서 “줄일 수 있어?”라고 물은 것이다. 그 질문이 틀린 질문이었다.
어떻게 시켰나
에이전트에게 대시보드 수치가 아니라 시계열을 가져오게 했다. 순간값으로는 많고 적음밖에 안 보인다. 26시간치를 뽑으니 모양이 나왔다.
| 시각 | 메모리 |
|---|---|
| 09-07 09:00 | 226MB |
| 09-07 21:00 | 400MB |
| 09-08 03:00 | 633MB |
| 09-08 11:00 | 833MB |
톱니가 아니라 직선이었다. 시간당 24MB씩, 26시간 동안 한 번도 안 내려왔다. 이건 많이 쓰는 게 아니라 안 돌려주는 것이다. 튜닝 질문이 누수 질문으로 바뀌었다.
어디서 막혔나
가설을 세 개 세우고 하나씩 껐다.
렌더 부하인가. 아니었다. 기울기가 가장 가파른 09-08 09시에서 11시 사이의 트래픽이 시간당 1.0MB로 창 전체에서 가장 낮았다. 반대로 트래픽이 열 배였던 09-07 08시에는 메모리가 오히려 내려갔다. 부하와 증가가 반대로 움직이면 부하는 범인이 아니다.
CPU가 뭔가 돌고 있나. 아니었다. 26시간 내내 0.001에서 0.004 vCPU였다. 아무 일도 안 하면서 메모리만 먹고 있었다.
Next 자체 문제인가. 이걸 확인하려고 옆 서비스를 끌어왔다. 공시 요약 서비스의 프론트는 같은 Next 16.2.6, 같은 standalone 빌드, 같은 ISR, 같은 Railway 호스트다. 34시간 추세를 나란히 놓으니 이쪽은 155MB와 725MB 사이를 오가는 톱니였다. 추세가 없었다. 같은 스택인데 한쪽만 오른다면 스택이 아니라 둘의 차이가 범인이다.
차이를 훑다가 내가 먼저 말을 꺼냈다.
그런데 dartbrief-web 도 지금 센트리에 로그 쌓이고 있네… 근데 왜 의정보기만 계속 메모리 올라가는데..
Sentry는 양쪽 다 켜져 있는 것처럼 보였다. 실제로는 아니었다. 공시 요약 쪽은 엿새 전에 서버측 Sentry를 들어냈다. Cloudflare Workers에서 Error 1102, 워커가 리소스 한도를 넘었다는 오류가 나서 걷어낸 것이었다. 클라이언트측은 그대로라 대시보드에는 로그가 계속 쌓이고 있었고, 그래서 내 눈에는 둘 다 켜진 걸로 보였다.
여기서 한 가지가 뒤집혔다. 같은 설정이 플랫폼에 따라 다른 증상을 낸다. Workers는 아이솔레이트를 돌려쓰니 요청당 잔류가 콜드 스타트 CPU로 나타난다. Railway는 하나의 Node 프로세스가 오래 산다. 같은 잔류가 여기서는 메모리 누적이 된다. 엿새 전에 CPU 문제로 진단했던 것이 이번에는 메모리 문제로 보이는 것이라면, 범인은 같은 놈일 수 있었다.
어떻게 풀었나
확정하려고 로컬에서 재현을 시도했다. 맥에서 프로덕션 빌드를 띄우고 같은 요청 3,000건을 밀어 넣었다.
재현이 안 됐다. heapUsed는 1,500건에서 3,000건 구간에서 87MB가 88MB가 됐다. 1MB다. rss는 47MB와 233MB 사이를 제멋대로 널뛰었다. 신호라고 부를 만한 게 없었다. 그래서 나는 “요청량으로는 재현 불가”라고 적었다.
그 문장이 틀렸다. 정확히는 결론의 주어가 틀렸다. 재현이 안 된 게 아니라 재고 있는 자가 달랐다. macOS는 메모리를 압축하고 스스로 회수한다. rss가 널뛴 건 노이즈가 아니라 그 관리의 결과다. 운영은 리눅스 컨테이너다. 거기서는 커널이 cgroup 단위로 쓴 만큼을 그대로 센다.
그래서 재는 자리를 옮겼다. node:22-alpine 컨테이너를 띄우고 실제 법안 상세 URL로 다시 밀었다.
| 누적 요청 | cgroup | anon | file | slab |
|---|---|---|---|---|
| 0 | 45.7MB | 41.9 | 0.0 | 1.0 |
| 1,200 | 511.9MB | 242.2 | 212.3 | 49.0 |
| 3,500 | 1,158.2MB | 379.8 | 625.5 | 141.0 |
요청당 약 388KB. 운영에서 본 기울기와 자릿수가 맞았다. 같은 코드, 같은 요청, 같은 횟수인데 맥에서는 1MB고 컨테이너에서는 1.1GB였다. 차이는 코드가 아니라 재는 자리였다.
계측기는 frontend/memprobe.cjs로 남겼다. 5분마다 process.memoryUsage()와 /sys/fs/cgroup을 한 줄로 뱉는다. Dockerfile의 실행 줄에 --require로 물려서 운영에서도 같은 걸 재게 했다. 임시 코드라고 적어 뒀다.
여기서 한 번 더 미끄러질 뻔했다. 컨테이너 수치에서 file 버킷이 625MB까지 올라갔길래 처음엔 .next/cache라고 생각했다. 디스크를 재 보니 62MB였다. 열 배 차이다. 같은 이름표가 붙었다고 같은 것이 아니다. 그래서 계측기를 한 번 더 고쳐 shmem을 따로 떼어냈고, 문서에는 “cgroup 버킷만으로는 원인을 확정하지 말 것”이라고 박아 뒀다.
그리고 이 글을 쓰는 지금도 판정은 안 났다. 서버측 Sentry 초기화를 주석 처리한 가지를 띄워 두고 곡선이 평평해지는지 보는 중이다. 초반에는 두 곡선이 겹쳤고, 후반에 Sentry를 끈 쪽이 떨어지긴 했다. 다만 재시작 없이 반납하는 모양이라 그건 JS 힙이 아니라 페이지 캐시일 수 있다. 아직 범인을 지목할 단계가 아니다. 이 가지는 main에 머지하지 않았다.
배운 점
- 로컬에서 재현이 안 된 건 증거가 아니다. 재는 자리가 다르면 없는 게 아니라 안 보이는 것이다. 맥에서 1MB였던 게 컨테이너에서 1.1GB였다.
- 순간값 대신 시계열을 본다. 833MB라는 숫자만으로는 아무 결론도 안 나온다. 26시간 직선이라는 모양이 누수라고 말해 준다.
- 부하와 증가가 반대로 움직이면 부하는 범인이 아니다. 트래픽이 가장 낮을 때 기울기가 가장 가팔랐다.
- 같은 스택의 옆 서비스가 가장 좋은 대조군이다. 차이가 하나로 좁혀질 때까지 공통점을 지워 나가면 된다.
- 같은 설정이 플랫폼에 따라 다른 증상을 낸다. 서버리스에서 CPU 문제였던 게 상주 프로세스에서는 메모리 문제다.
- 버킷 이름을 보고 정체를 단정하지 않는다. file 625MB는 디스크 캐시 62MB가 아니었다.
- 판정이 안 났으면 안 났다고 적는다. 곡선 하나 떨어진 걸로 범인을 정하면 다음 달에 같은 걸 또 쫓는다.