메모리도 CPU도 멀쩡한데 웹이 느려졌다

웹성능JavaScript디버깅브라우저비동기
메모리도 CPU도 멀쩡한데 웹이 느려졌다

메모리도 CPU도 멀쩡한데 웹이 느려졌다

6만 8천 개의 타이머를 추적하며 배운 장시간 웹 성능 디버깅.

웹 애플리케이션을 장시간 실행해두면 어느 순간부터 화면이 끊기기 시작했습니다.

처음에는 아주 멀쩡했습니다.

30분도 괜찮고, 한 시간 정도도 별 문제가 없습니다.

그런데 한두 시간이 지나면 가끔 애니메이션이 툭툭 끊기기 시작합니다. 시간이 더 지나면 그 빈도가 점점 늘어납니다.

새로고침하면 다시 멀쩡해집니다.

그리고 다시 오래 실행하면 같은 증상이 나타납니다.

전형적인 누수처럼 보였습니다.

그래서 가장 익숙한 것부터 확인했습니다.

메모리가 계속 늘어나는가?

GPU 리소스를 반환하지 않고 있는가?

DOM 노드가 쌓이고 있는가?

이벤트 리스너가 누적되고 있는가?

렌더링 횟수가 점점 많아지는가?

CPU를 오래 붙잡고 있는 작업이 있는가?

그런데 이상했습니다.

CPU도 멀쩡하고, 메모리도 멀쩡하고, GPU도 멀쩡했습니다.

그런데 사용자가 보고 있는 화면은 분명히 느려지고 있었습니다.

이번 문제를 해결하면서 저는 단순히 성능 버그 하나를 고친 것보다 더 많은 것을 배웠습니다.

첫 번째는 장시간 성능 문제는 관찰하는 방법부터 달라야 한다는 것.

두 번째는 우리가 평소 보는 성능 지표에도 사각지대가 있다는 것.

그리고 마지막은 제가 JavaScript의 비동기를 꽤 오랫동안 조금 잘못 이해하고 있었다는 것​이었습니다.


1. 한두 시간이 지나야 나타나는 버그

가장 먼저 부딪힌 문제는 원인을 찾는 것이 아니었습니다.

재현 시간이 너무 길었습니다.

몇 번 클릭하면 바로 발생하는 성능 문제라면 Chrome DevTools의 Performance 탭을 켜고 프로파일링하면 됩니다.

하지만 이번 문제는 한 시간이 넘게 기다려야 했습니다.

Performance Recording을 한두 시간 켜두는 건 현실적이지 않았습니다. 몇십 초만 녹화해도 데이터가 상당히 커지고, 수많은 이벤트 사이에서 장시간의 추세를 읽기도 어렵습니다.

그래서 생각을 바꿨습니다.

모든 것을 기록하지 말고, 변화만 기록하면 어떨까?

성능 문제를 찾기 위한 작은 관찰기를 하나 만들었습니다.

이름은 별것 없이 SOAK Probe.

몇 시간 동안 애플리케이션을 계속 실행하는 Soak Test를 위한 프로브였습니다.

설치할 것도 없었습니다.

빌드된 웹 애플리케이션을 Chrome에서 열고 DevTools의 Snippets에 스크립트를 붙여넣으면 끝입니다.

앱 내부 코드에 접근하지도 않았습니다.

브라우저 전역 API만 감쌌습니다.

덕분에 개발 환경뿐 아니라 실제 배포용으로 빌드된 결과물에서도 그대로 사용할 수 있었습니다.


2. 몇 시간을 기록해도 수백 KB만 남기는 관찰기

장시간 측정에서 가장 중요한 건 원본을 버리는 것이었습니다.

프레임 10만 개를 전부 기록할 필요는 없습니다.

제가 알고 싶은 건 이런 것이었습니다.

  • 평소 프레임은 여전히 정상인가?
  • 느린 프레임은 시간이 지나며 증가하는가?
  • 메모리가 같이 증가하는가?
  • GPU 리소스가 같이 증가하는가?
  • 이벤트 리스너가 증가하는가?
  • 타이머가 증가하는가?
  • 렌더링 루프 자체가 늘어나는가?
  • 긴 JavaScript 작업이 많아지는가?

그래서 한 번의 반복 작업을 하나의 구간으로 보고, 구간이 끝날 때마다 요약값만 남겼습니다.

프레임 데이터는 다음 정도만 저장했습니다.

function stats(frames) { const sorted = frames.slice().sort((a, b) => a - b); return { median: percentile(sorted, 0.5), p95: percentile(sorted, 0.95), p99: percentile(sorted, 0.99), max: sorted.at(-1), over33ms: frames.filter(v => v > 33).length, over50ms: frames.filter(v => v > 50).length, over100ms: frames.filter(v => v > 100).length, }; }

원본 프레임은 통계를 만든 뒤 버렸습니다.

이 방식으로 약 2시간 20분의 실행 결과를 수백 KB 수준으로 남길 수 있었습니다.

장시간 테스트에서는 무엇을 많이 기록하느냐보다,

무엇을 버릴 것인지 정하는 게 더 중요했습니다.


3. 앱을 수정하지 않고 브라우저 바깥에서 관찰했다

이번 테스트에는 또 하나의 제약이 있었습니다.

실제 배포용 빌드 결과를 그대로 테스트하고 싶었습니다.

그래서 앱 내부에 디버깅 코드를 심는 대신 브라우저 API를 감싸는 방식을 선택했습니다.

예를 들어 setTimeout이 몇 번 호출되는지 알고 싶다면 이렇게 기존 함수를 감쌌습니다.

const originalSetTimeout = window.setTimeout; window.setTimeout = function (...args) { counters.timeoutSet++; return originalSetTimeout.apply(this, args); };

requestAnimationFrame도 마찬가지였습니다.

const originalRAF = window.requestAnimationFrame; window.requestAnimationFrame = function (...args) { counters.rafCalls++; return originalRAF.apply(this, args); };

이벤트 리스너 역시 등록과 해제 횟수를 각각 셌습니다.

const originalAdd = EventTarget.prototype.addEventListener; const originalRemove = EventTarget.prototype.removeEventListener; EventTarget.prototype.addEventListener = function (...args) { counters.listenerAdd++; return originalAdd.apply(this, args); }; EventTarget.prototype.removeEventListener = function (...args) { counters.listenerRemove++; return originalRemove.apply(this, args); };

그래픽도 비슷한 방식으로 WebGL과 WebGPU 프로토타입을 감싸서 draw call과 texture, buffer 등의 생성량을 측정했습니다.

즉 SOAK Probe가 하는 일은 특별하지 않았습니다.

브라우저가 이미 가지고 있는 API 앞에 카운터 하나씩 달아둔 것에 가까웠습니다.

하지만 이 단순한 카운터들이 나중에는 꽤 중요한 단서가 됐습니다.


4. 장시간 테스트에서 탭이 가려진 데이터는 버렸다

장시간 성능 측정을 하면서 의외로 조심해야 할 것도 있었습니다.

브라우저는 화면에 보이지 않는 탭의 requestAnimationFrame을 제한합니다.

예를 들어 다른 창을 앞에 띄워두었다가 다시 돌아오면,

관찰기 입장에서는 이런 데이터가 만들어질 수 있습니다.

16.7ms 16.7ms 16.7ms 6,214ms 16.7ms

실제로 애플리케이션이 6초 동안 멈춘 게 아닙니다.

탭이 백그라운드로 들어가면서 rAF 호출이 멈췄던 것입니다.

그래서 visibilitychange를 감지해서 다시 화면에 보이는 순간의 첫 프레임은 버렸습니다.

document.addEventListener('visibilitychange', () => { if (!document.hidden) { skipNextFrame = true; } });

이런 종류의 계측에서는 숫자를 얻는 것만큼 그 숫자를 믿을 수 있는 조건을 만드는 것이 중요했습니다.


5. 그래서 무엇을 기록했나

최종적으로 각 구간마다 대략 다음과 같은 값을 남겼습니다.

분류측정값
Framemedian / p95 / p99 / max
Frame33ms / 50ms / 100ms 초과 횟수
MemoryJS Heap
GPUTexture / Buffer / Shader 등의 생존량
RenderingDraw Call / Frame
RenderingrequestAnimationFrame / Frame
EventListener 등록 - 해제
TimersetTimeout / setInterval
Main ThreadLong Task 횟수와 시간
Environment탭 가려짐 여부

HUD도 하나 만들었습니다.

화면 오른쪽 위에 처음 25% 구간의 중앙값과 최근 25% 구간의 중앙값을 비교해 보여줬습니다.

예를 들어 이런 식입니다.

SOAK 경과 1:42:07 반복 812 p99 17.6 → 41.2ms ▲134% 최악 33.4 → 210.6ms ▲531% 힙 180 → 490MB ▲172% 텍스처 0 → 838 ▲ 리스너 12 → 1240 ▲ rAF/f 5.10 → 5.12 ±0%

숫자를 정교하게 분석하기 위한 도구라기보다,

무엇이 같이 우상향하고 있는지

빠르게 보기 위한 HUD였습니다.

그리고 테스트가 끝나면 JSON으로 원본 요약 데이터를 저장하도록 했습니다.

SOAK Probe HUD SOAK Probe HUD는 장시간 실행 중에도 p99, heap, texture, listener, rAF 같은 핵심 지표를 한 화면에서 확인하기 위한 작은 관찰 창이었다.


6. 2시간 20분 뒤, 드디어 문제가 나타났다

약 2시간 20분 동안 반복 동작을 계속 돌렸습니다.

총 수천 번의 실행이 지나자 눈으로 느껴질 정도의 렉이 발생하기 시작했습니다.

관찰 데이터를 열었습니다.

우선 프레임부터 확인했습니다.

Frame Time시작종료
median16.7ms16.7ms
p9516.8ms83.3ms
p9917.0ms100.0ms

처음에는 이 숫자가 꽤 흥미로웠습니다.

중앙값이 전혀 움직이지 않았기 때문입니다.

평소의 50% 프레임은 테스트가 끝날 때까지 여전히 16.7ms였습니다.

대부분의 시간에는 화면이 멀쩡했다는 의미입니다.

문제가 된 건 꼬리였습니다.

p95와 p99만 시간이 지나면서 크게 올라갔습니다.

median, p95, p99 장시간 변화 여기서 spin은 같은 동작을 한 번 반복 실행한 단위다. median은 거의 16.7ms에 머무르지만, p95와 p99는 시간이 지날수록 꼬리 프레임이 무거워지는 모습을 보여준다.

여기서 첫 번째 교훈을 얻었습니다.

평균적인 프레임과 사용자가 경험하는 렉은 같은 것이 아니다.

100개의 프레임 중 99개가 부드러워도,

나머지 한 프레임이 100ms 동안 멈춘다면 사용자는 충분히 “끊긴다”고 느낍니다.

평균이나 median만 봤다면 이번 문제를 놓쳤을 가능성이 높았습니다.


7. 프레임이 이상할 정도로 정확하게 끊겼다

그리고 숫자를 보다 보니 더 이상한 특징이 하나 보였습니다.

느린 프레임들이 아무 값에나 위치하지 않았습니다.

16.7ms 33.3ms 50.0ms 66.7ms 83.3ms 100.0ms

전부 16.67ms의 정수배였습니다.

60Hz 화면에서 한 프레임의 시간은 약 16.67ms입니다.

즉 애플리케이션이 연속적으로 조금씩 느려지는 것이 아니었습니다.

렌더링 기회를 통째로 한 번, 두 번, 세 번씩 놓치고 있었습니다.

33.3ms라면 한 프레임을 놓친 것이고,

50ms라면 두 번,

100ms라면 대략 다섯 번의 렌더링 기회를 놓친 것입니다.

p99가 16.67ms 배수로 증가하는 그래프 p99가 16.67ms의 배수에 걸린다는 것은 렌더링 기회를 통째로 놓치고 있다는 신호였다.

이제 범인을 찾을 차례였습니다.


8. 그런데 흔한 용의자들이 전부 무죄였다

SOAK Probe로 모은 다른 지표도 비교했습니다.

누수 후보시작종료결과
JS Heap약 190MB약 200MB거의 평평
Live Texture20여 개20여 개평평
Live Buffer1414평평
DOM Node약 60약 60평평
Draw Call / Frame약 155약 157평평
rAF / Frame약 7약 7평평
Long Task 점유율약 0.2%-매우 낮음

메모리가 계속 치솟는 것도 아니었습니다.

GPU 객체가 계속 증가하는 것도 아니었습니다.

렌더링이 갑자기 복잡해진 것도 아니었습니다.

requestAnimationFrame 루프가 중복 생성된 것도 아니었습니다.

그리고 가장 이상한 것은 Long Task였습니다.

메인 스레드를 50ms 이상 붙잡는 작업은 거의 존재하지 않았습니다.

그런데 화면에서는 100ms짜리 프레임이 나오고 있었습니다.

Heap, GPU, rAF는 평평하지만 p99만 상승하는 그래프 JS Heap, GPU texture, rAF/frame은 큰 변화가 없는데 Frame p99만 계속 상승했다.

여기서 한동안 막혔습니다.

CPU도 평범하고,

메모리도 평범하고,

GPU도 평범한데,

대체 무엇 때문에 프레임이 밀리는 걸까요?


9. Long Task가 없다는 말의 함정

답은 Long Task라는 이름 자체에 있었습니다.

브라우저의 Long Tasks API는 일정 시간 이상 실행되는 긴 태스크를 알려줍니다.

기준은 약 50ms입니다.

예를 들어 이런 작업은 쉽게 잡힙니다.

JavaScript Task ────────────────────────────── 80ms

하지만 이런 작업은 어떨까요?

1µs 1µs 1µs 1µs 1µs ...

각 작업이 1마이크로초라면 Long Task에 하나도 잡히지 않습니다.

그런데 그런 작업이 10만 개 있다면?

각각은 짧지만,

메인 스레드는 결국 전부 실행해야 합니다.

제가 보고 있던 지표는

CPU가 한가한가?

가 아니었습니다.

정확히는

50ms보다 긴 하나의 태스크가 존재하는가?

였습니다.

둘은 전혀 다른 질문입니다.

하나가 얼마나 오래 걸리는지와, 몇 개가 실행되는지는 서로 다른 성능 축이었습니다.

그리고 이번 문제는 정확히 그 사각지대에 숨어 있었습니다.


10. 단 하나 이상했던 카운터

모든 카운터를 다시 훑어봤습니다.

그때 하나 이상한 숫자가 눈에 걸렸습니다.

setTimeout.

약 2시간 20분 동안 호출된 횟수는

5억 회 이상.

초당 수만 회,

프레임당 천 회가 넘는 수준이었습니다.

짧게 개발 환경에서 실행했을 때는 프레임당 한 자릿수 정도였습니다.

시간이 지나면서 무려 백 배 이상 증가하고 있었습니다.

setTimeout per frame 폭증 그래프 문제는 느린 함수 하나가 아니라, 프레임마다 처리해야 하는 setTimeout callback 수가 폭발적으로 늘어난 것이었다.

이제 처음으로 방향이 생겼습니다.

문제는 어떤 작업 하나가 느려지는 것이 아니었습니다.

실행해야 하는 작업의 개수가 폭발하고 있었습니다.


11. 힙 스냅샷 두 장

하지만 setTimeout 카운터만으로는 누가 그 타이머를 만들고 있는지 알 수 없습니다.

그래서 테스트 시작 직후와 렉이 충분히 발생한 시점에 Chrome DevTools의 Heap Snapshot을 각각 한 장씩 떴습니다.

두 스냅샷을 비교해보니 노드가 수십만 개 증가해 있었습니다.

그중 특히 눈에 띈 것이 익명의 클로저와 Context였습니다.

대략 25만 개가 새롭게 생겨 있었습니다.

메모리 증가량 자체는 수십 MB 수준이었습니다.

그래서 전체 Heap 그래프에서는 GC의 톱니무늬 사이에 묻혀 거의 보이지 않았습니다.

하지만 객체 수로 보면 명백한 이상치였습니다.

리테이너 경로를 따라 역으로 올라가 봤습니다.

그리고 대부분의 클로저가 한 곳에 매달려 있는 것을 발견했습니다.

오디오 라이브러리의 종료 이벤트 리스너 배열.

몇 개의 오디오 객체를 살펴보니 특정 이벤트 배열만 비정상적으로 커져 있었습니다.

객체종료 이벤트 리스너
audio A68,848
audio B67,181
audio C61,999
audio D51,430
합계249,458

반면 다른 이벤트의 리스너 배열은 대부분 몇 개 수준으로 일정했습니다.

이제 범인의 위치를 거의 찾았습니다.

Heap Snapshot과 Retainer Path Heap Snapshot의 증가분과 Retainer Path를 함께 보면, 누적된 closure와 Timeout 객체가 오디오 end listener 배열에 매달려 있다는 흐름이 보인다.


12. 원인은 정말 평범한 코드였다

문제가 된 코드는 개념적으로 이런 형태였습니다.

const soundId = audio.play(); audio.on('end', (endedId) => { if (endedId === soundId) { audio.stop(soundId); cleanup(); } });

효과음을 한 번 재생할 때마다

이 소리가 끝나면 정리해줘

라는 리스너를 하나 등록했습니다.

겉보기에는 꽤 자연스러운 코드입니다.

endedId가 내가 재생한 soundId와 같은지도 확인하고 있습니다.

그런데 문제가 두 개 있었습니다.

첫 번째,

이 리스너는 한 번 실행된 뒤에도 사라지지 않았습니다.

재생할 때마다 하나씩 계속 쌓였습니다.

1회 재생 1개 100회 100개 1,000회 1,000개 10,000회 10,000개 ...

그리고 두 번째 문제가 훨씬 컸습니다.

리스너를 등록할 때 라이브러리에 soundId를 전달하지 않았습니다.

ID 비교를 라이브러리에게 맡기지 않고 콜백 내부에서 직접 하고 있었습니다.


13. 라이브러리는 모든 리스너를 호출 후보로 봤다

사용하던 오디오 라이브러리의 이벤트 발화 부분을 확인해봤습니다.

개념적으로는 다음과 같은 코드였습니다.

for (let i = 0; i < events.length; i++) { if (!events[i].id || events[i].id === id) { setTimeout(() => { events[i].callback(); }, 0); } }

핵심은 이 부분입니다.

!events[i].id

ID 없이 등록한 이벤트 리스너는 모든 이벤트에 매칭됩니다.

우리 코드는 ID를 등록 시점에 주지 않았습니다.

대신 콜백 안에서 확인하고 있었습니다.

if (endedId === soundId) { ... }

즉 라이브러리 입장에서 보면 쌓여 있는 모든 리스너가 호출 대상이었습니다.

그리고 이 라이브러리는 이벤트 콜백 하나마다 setTimeout(..., 0) 하나를 생성하는 구조였습니다.

결과적으로 리스너가 68,848개 쌓여 있다면,

소리 하나가 종료될 때

68,848개의 setTimeout이 한꺼번에 등록됩니다.

그중 실제로 필요한 일을 하는 것은 하나입니다.

나머지 68,847개는 이렇게 됩니다.

if (endedId !== soundId) { return; }

ID 한번 비교하고 끝납니다.

아무것도 하지 않기 위해

수만 개의 JavaScript 콜백이 만들어지고 있었습니다.


14. 라이브러리의 버그는 아니었다

처음에는 라이브러리 내부 코드를 보고 잠깐 의심했습니다.

왜 이벤트 리스너 하나마다 setTimeout을 만드는 걸까?

하지만 코드를 더 보니 라이브러리의 동작 자체는 문서화된 정상 동작이었습니다.

ID 없이 이벤트를 등록하면 모든 ID에 대해 호출되는 것도 의도된 API였습니다.

콜백을 비동기로 실행해 현재 호출 스택을 끊는 설계 역시 충분히 이해할 수 있는 선택이었습니다.

문제는 라이브러리가 아니었습니다.

API를 사용하는 쪽에서 두 개의 조건을 동시에 잘못 사용하고 있었습니다.

리스너가 제거되지 않는다 × 모든 이벤트에 매칭된다 × 리스너마다 setTimeout을 만든다

이 세 가지가 결합되면서 평소에는 전혀 보이지 않는 문제가 장시간 뒤에 폭발했습니다.


15. 그런데 여기서 다시 막혔다

원인은 찾았습니다.

그런데 저는 여기서 꽤 오래 다시 막혔습니다.

머릿속에서 하나가 설명되지 않았습니다.

그런데 setTimeout은 비동기잖아.

왜 그게 프레임을 먹지?

당시 저는 JavaScript 비동기를 대략 이런 식으로 이해하고 있었습니다.

Call Stack Web APIs Callback Queue Event Loop

수많은 JavaScript 입문 자료에서 봤던 익숙한 그림입니다.

문제는 그림이 아니라 제가 그 그림을 해석하는 방법이었습니다.

저는 어렴풋이

Web API와 Event Loop가 메인 스레드 밖에서 일을 처리해준다.

고 생각하고 있었습니다.

그래서 타이머가 6만 개 생성되는 건 이상하지만,

그게 왜 렌더링을 100ms나 막는지는 직관적으로 이해되지 않았습니다.

제가 잘못 알고 있었습니다.


16. 다른 곳에서 하는 것은 '기다리기'다

setTimeout(fn, 1000)을 생각해봅시다.

JavaScript가 1초 동안 Call Stack을 붙잡고 숫자를 세는 것은 아닙니다.

1초를 기다리는 일은 런타임이 관리합니다.

그 부분은 맞습니다.

하지만 1초 뒤에 fn의 JavaScript 코드까지 어떤 다른 스레드가 대신 실행해주는 것은 아닙니다.

실행할 시간이 되면 해당 콜백은 메인 스레드에서 실행할 작업이 됩니다.

개념적으로 보면 이렇게 이해할 수 있습니다.

setTimeout(fn, 1000) 타이머 등록 기다림 실행 가능한 작업이 됨 Task Queue Main Thread fn()

그리고 이번 문제는 심지어

setTimeout(fn, 0);

이었습니다.

기다릴 시간조차 없습니다.

수만 개의 JavaScript 작업을 나중에 실행하도록 예약하고 있었을 뿐입니다.

그리고 그 “나중”이 오면,

결국 메인 스레드가 전부 처리해야 합니다.


17. 비동기는 병렬이라는 뜻이 아니다

이 문제를 겪으면서 제 머릿속 정의를 다시 정리했습니다.

비동기는

일을 다른 스레드로 보내는 것

이 아닙니다.

더 정확히는

지금 완료될 때까지 기다리지 않고, 나중에 이어서 처리할 수 있게 하는 것

에 가깝습니다.

물론 모든 비동기 작업이 같은 방식으로 동작하는 것은 아닙니다.

네트워크 I/O 같은 작업은 실제로 브라우저 내부의 다른 스레드나 시스템 영역에서 상당한 일을 처리합니다.

하지만 그 결과를 받아 JavaScript 콜백을 실행해야 하는 순간에는 다시 메인 스레드가 필요합니다.

그래서

비동기 = 다른 스레드

라고 뭉뚱그려 이해하면 이번 문제 같은 상황을 설명할 수 없었습니다.

잘못 이해했던 비동기 모델과 실제 비동기 모델 setTimeout은 실행을 나중으로 미룰 뿐, callback의 JavaScript 실행은 결국 메인 스레드로 돌아온다.


18. 100ms짜리 하나와 1µs짜리 10만 개

이제 Long Task가 거의 없는데도 프레임이 깨졌던 이유가 설명됐습니다.

브라우저가 60fps로 화면을 그리려면 대략 16.67ms마다 렌더링할 기회를 가져야 합니다.

그런데 메인 스레드 앞에 처리해야 할 작업이 계속 쌓여 있다면,

렌더링 시점까지 도달하지 못합니다.

이때 작업 하나의 크기는 본질적인 문제가 아닙니다.

예를 들어

100ms짜리 Task × 1개 1µs짜리 Task × 100,000개

는 Performance API 관점에서는 완전히 다른 형태입니다.

전자는 Long Task 하나로 잡힙니다.

후자는 Long Task가 하나도 없을 수 있습니다.

하지만 벽시계 관점에서는 둘 다

100ms가 흘렀습니다.

브라우저는 그동안 렌더링할 수 없습니다.

그래서 p99가

33.3 50.0 66.7 83.3 100.0

처럼 16.67ms의 배수에 정확히 걸리고 있었습니다.

메인 스레드가 타이머 콜백을 처리하느라 렌더링 시점을 통째로 놓치고 있었던 것입니다.


19. 수정은 세 줄이었다

원인을 알고 나니 수정은 놀랄 만큼 단순했습니다.

기존 코드는 이런 형태였습니다.

audio.on('end', (endedId) => { if (endedId === soundId) { cleanup(); } });

한 번만 필요했던 이벤트였으므로 on 대신 once를 사용했습니다.

그리고 콜백 내부에서 ID를 비교하지 않고,

등록 시점에 대상 ID를 지정했습니다.

audio.once('end', () => { cleanup(); }, soundId);

두 가지가 동시에 해결됐습니다.

첫째,

이벤트가 한 번 실행되면 리스너가 자동으로 제거됩니다.

둘째,

특정 soundId에 대해서만 해당 리스너가 매칭됩니다.

따라서 다른 소리가 종료되었을 때 이 콜백은 호출 후보에조차 들어가지 않습니다.


20. 한 가지 함정이 더 있었다

once로 바꾸고 끝내려고 했는데 한 군데 예외가 있었습니다.

소리가 자연스럽게 종료되는 것이 아니라 중간에 강제로 stop()되는 경로가 있었습니다.

그런데 사용하던 라이브러리에서는 stop()이 종료 이벤트를 발생시키지 않았습니다.

그렇다면 once 리스너도 실행되지 않고 그대로 남습니다.

그래서 강제로 종료하는 경로에서는 리스너를 직접 제거했습니다.

audio.off('end', undefined, soundId); audio.stop(soundId);

성능 문제를 고칠 때는 정상 경로보다 이런 중간 종료 경로가 더 중요할 때가 많습니다.

생성 → 사용 → 정상 종료만 보면 리소스가 잘 정리되는 것처럼 보입니다.

실제 누수는 종종

생성 사용 중간 취소 정리 로직 미실행

에서 만들어집니다.


21. 코드 세 줄보다 중요한 변화

수정 전과 후의 차이를 수학적으로 보면 더 명확합니다.

수정 전에는 실행할 때마다 리스너가 하나씩 쌓였습니다.

그리고 다음 이벤트가 발생할 때까지 쌓인 모든 리스너를 다시 검사했습니다.

대략 이런 형태입니다.

1 + 2 + 3 + 4 + ... + N

총 비용은 대략

N² / 2

에 가까워집니다.

반면 수정 후에는 사용한 리스너가 바로 제거됩니다.

1 + 1 + 1 + 1 + ... + 1

비용 증가가 선형으로 바뀝니다.

구분리스너누적 이벤트 처리량
수정 전계속 증가약 O(N²)
수정 후거의 일정약 O(N)

코드로 보면 몇 줄 수정했지만,

성능 관점에서는 곱셈을 덧셈으로 바꾼 것에 가까웠습니다.

O(N²)에서 O(N)으로 바뀐 실행 비용 리스너가 누적되던 구조를 한 번만 등록하고 제거되는 구조로 바꾸자, 누적 처리량의 증가 모양이 달라졌다.


22. 수정 후 다시 측정했다

같은 SOAK Probe를 사용해서 수정 후 빌드를 다시 테스트했습니다.

결과는 확연했습니다.

지표수정 전수정 후
Frame p9917 → 100ms16.8 → 16.8ms
33ms 초과 Frame약 5.6%약 0.1%
setTimeout / Frame1,000회 이상1회 미만
Long Task거의 없음거의 없음

특히 setTimeout / frame이 핵심이었습니다.

수정 전에는 시간이 지날수록 계속 올라가던 값이 수정 후에는 처음부터 끝까지 거의 평평했습니다.


23. 그런데 첫 번째 검증은 실패한 검증이었다

여기서 재미있는 일이 하나 더 있었습니다.

수정 후 첫 테스트는 약 1시간 반 정도 실행한 뒤 외부 문제로 종료됐습니다.

그래프는 완벽했습니다.

p99도 안정적이었고,

타이머 수도 증가하지 않았습니다.

처음에는 해결됐다고 생각했습니다.

그런데 수정 전 데이터를 다시 봤습니다.

기존 버전에서 본격적인 열화가 시작된 시점이 첫 검증보다 조금 더 뒤였습니다.

즉 제가 한 것은

원래 문제가 발생하기 직전까지만 돌려보고 문제가 없다고 확인한 것

이었습니다.

검증이라고 부르기 어려웠습니다.


24. 성능 수정은 기존 실패 지점을 넘어야 한다

그래서 두 번째 테스트에서는 그냥 오래 돌렸습니다.

몇 시간이 아니라 하루 이상 연속 실행했습니다.

기존 버전이 무너지던 시점을 훨씬 넘어선 뒤에도 프레임은 안정적으로 유지됐습니다.

중요했던 건 절대적인 테스트 시간이 아니었습니다.

기존 문제가 실행 횟수에 따라 증가하는 문제였기 때문에,

비교 기준 역시 단순한 시간보다 누적 실행 횟수가 되어야 했습니다.

예를 들어 기존 문제가 2,000회쯤부터 나타났다면,

수정 후 1,500회까지 아무 문제가 없는 것은 증거가 아닙니다.

최소한 그 지점을 충분히 넘어가야 합니다.

수정 전후 비교와 최종 장시간 검증 수정 전에는 p99와 setTimeout/frame이 함께 무너졌고, 수정 후에는 기존 실패 조건을 넘긴 뒤에도 p99가 안정적으로 유지됐다.

이 과정에서 검증에 대해서도 하나 배웠습니다.

수정 후 좋아졌다는 것을 확인하는 것과,

기존 버전이 실패했던 조건을 넘어섰다는 것을 확인하는 것은 다르다.

성능 문제에서는 후자가 훨씬 중요합니다.


25. CPU, Memory, GPU 그리고 하나 더

이번 문제 전까지 웹 성능 문제가 발생하면 저도 자연스럽게 세 가지 축을 떠올렸습니다.

CPU.

Memory.

GPU.

대부분의 성능 문제는 실제로 이 범위에서 설명할 수 있습니다.

그런데 이번 문제에서는 세 개가 모두 정상처럼 보였습니다.

부족했던 축은 하나였습니다.

작업의 개수였습니다.

사용한 지표이번 결과
CPULong Task정상처럼 보임
MemoryHeap거의 평평
GPUDraw Call / Resource평평
Task CountsetTimeout / Frame비정상적으로 증가

Long Task는

하나의 작업이 얼마나 오래 걸리는가

를 잘 보여줍니다.

하지만

작은 작업을 몇 개 실행하고 있는가

에는 답해주지 않습니다.

타이머뿐만의 이야기는 아닙니다.

Promise callback,

이벤트 핸들러,

MessageChannel,

작은 observer callback처럼

하나하나는 거의 비용이 없는 작업도 개수가 충분히 많아지면 메인 스레드를 압박할 수 있습니다.

작은 비용이라고 해서 공짜는 아닙니다.


26. 메모리는 실제로 새고 있었다

조금 역설적인 부분도 있었습니다.

처음에는 메모리가 정상이라고 생각했지만,

힙 스냅샷을 비교해보니 실제로 수십 MB 정도의 메모리는 증가하고 있었습니다.

수십만 개의 이벤트 리스너와 클로저가 남아 있었기 때문입니다.

그러니까 엄밀히 보면 메모리 누수도 맞았습니다.

그런데 중요한 건

메모리가 늘었기 때문에 느려진 것이 아니었다는 점입니다.

기준 Heap이 이미 수백 MB였고 GC에 따른 등락도 상당했습니다.

몇 시간 동안 천천히 증가한 수십 MB는 일반 Heap 그래프에서는 쉽게 묻혔습니다.

그리고 그 정도 메모리가 늘어난 것만으로는 100ms의 프레임 드롭을 설명할 수도 없었습니다.

진짜 문제는 그 객체들이 살아 있기 때문에

이벤트가 발생할 때마다 다시 순회 대상이 되고 있었다는 것이었습니다.

메모리의 양보다

그 메모리가 만들어내는 행동 비용이 문제였습니다.

그래서 이번 문제는 제게는 단순한 메모리 누수보다

CPU 누수에 가까운 문제였습니다.

시간이 지날수록 메모리가 아니라,

앞으로 해야 할 일이 누적되고 있었으니까요.


27. SOAK Probe를 만들면서 얻은 또 하나의 교훈

이번 문제를 해결하면서 성능 도구에 대한 생각도 조금 바뀌었습니다.

처음에는

DevTools에 필요한 기능이 다 있는데 굳이 직접 만들 필요가 있을까?

라고 생각했습니다.

실제로 짧은 순간을 깊게 분석하는 데는 Chrome DevTools가 훨씬 뛰어납니다.

하지만 모든 도구는 특정 질문에 최적화되어 있습니다.

Performance Profiler는

지금 이 몇 초 동안 무슨 일이 있었는가?

를 파악하는 데 좋습니다.

Heap Snapshot은

지금 무엇이 메모리에 살아 있는가?

를 파악하는 데 좋습니다.

반면 제가 필요했던 질문은 조금 달랐습니다.

두 시간 전과 지금 사이에 무엇이 꾸준히 변하고 있는가?

그래서 복잡한 프로파일러가 아니라

몇 개의 카운터와 백분위 값만 저장하는 작은 도구가 오히려 더 유용했습니다.

좋은 성능 도구를 고르는 기준은 기능의 많고 적음이 아니라

내가 지금 묻고 있는 질문에 답해주는가였습니다.


28. 내가 고친 것은 코드보다 멘탈 모델이었다

최종 수정 자체는 몇 줄이었습니다.

on을 once로 바꾸고,

이벤트 ID를 등록 시점에 전달하고,

강제 종료 경로에서 리스너를 직접 제거했습니다.

하지만 원인을 찾는 데는 훨씬 오랜 시간이 걸렸습니다.

그리고 더 인상 깊었던 건 원인을 찾은 뒤였습니다.

저는 원인 코드를 눈앞에 두고도 한동안

그런데 왜 이게 렌더링을 막지?

를 이해하지 못했습니다.

제 머릿속에 있던 JavaScript 비동기의 모델 때문이었습니다.

저는 비동기를 꽤 오랫동안

런타임이 알아서 다른 곳에서 실행해주는 것

이라고 어렴풋이 이해하고 있었습니다.

이번 문제를 겪으며 그 모델을 이렇게 바꿨습니다.

비동기는 일을 없애주는 것이 아니다.

지금 하지 않고 나중에 이어서 할 수 있게 해주는 것이다.

그리고 나중으로 미룬 일이

6개가 아니라

6만 8천 개라면,

그 일은 사라진 것이 아닙니다.

언젠가 전부 내 차례로 돌아옵니다.


29. 성능 문제를 볼 때 이제 하나를 더 묻는다

이번 경험 이후 성능 문제를 볼 때 확인하는 질문이 하나 늘었습니다.

예전에는 주로 이런 질문을 했습니다.

메모리가 많이 증가했나?

오래 걸리는 함수가 있나?

렌더링 비용이 커졌나?

GPU 리소스가 쌓이고 있나?

이제 하나를 더 묻습니다.

아주 작은 일을 너무 많이 하고 있지는 않은가?

한 번 실행하는 데 1마이크로초밖에 걸리지 않는 함수는 분명 빠른 함수입니다.

하지만 그 함수를 매번 10만 번 호출하는 시스템까지 빠른 것은 아닙니다.

성능 문제에서 중요한 것은 결국 하나의 코드가 얼마나 빠른지만이 아니었습니다.

얼마나 자주 실행되는가.

시간이 지나면서 그 횟수가 어떻게 변하는가.

그리고 그 변화가 사용자에게 어떤 비용으로 돌아오는가.

이번에는 그 답이

6만 8천 개의 타이머였습니다.

댓글