요청 하나가 아니라 전부가 느려졌다 · 한 줄에 선 일감 · 실습
루프가 멈춘 시간을 재는 자를 만든다
목표
이벤트 루프가 얼마나 오래 멈춰 있었는지를 재는 자를 직접 만들고, 동기
작업 한 번이 그 프로세스의 모든 요청을 어떻게 함께 늦추는지 숫자로 확인합니다.
왜 중요한가
"API 가 느려요" 라는 신고가 들어오면 대개 그 API 의 코드를 먼저 봅니다. 그런데
Node 에서는 범인이 다른 곳에 있는 경우가 잦습니다. 자바스크립트를 실행하는
줄은 하나뿐이라, 어떤 요청 하나가 그 줄을 300ms 붙잡으면 그 시간 동안 도착한
모든 요청이 함께 300ms 늦습니다. 느려진 API 의 코드에는 아무 문제가 없습니다.
그래서 이 코스의 첫 도구는 프로파일러가 아니라 자 입니다. 일정한 간격으로
울리게 해 둔 타이머가 얼마나 늦게 울렸는지를 보면, 그 사이에 루프가 남의 일에
붙잡혀 있던 시간이 나옵니다. 평균은 거의 움직이지 않고 꼬리만 움직인다는
것이 이 분포의 핵심이고, 평균만 보는 대시보드가 이 사고를 못 잡는 이유입니다.
단계
1. /root/work/loop/lag.mjs 에 pct(samples, p) 를 만듭니다.
2. 같은 파일에 sample({durationMs, intervalMs}) 를 만듭니다.
3. 아무 일도 시키지 않고 재어 /root/work/loop/report.json 의 runs.idle 에 적습니다.
4. blockFor(ms) 를 만들고, 재는 도중에 한 번 막아 runs.blocked 에 적습니다.
5. 100ms 를 넘긴 표본의 개수와 비율, 그리고 평균을 runs.blocked 에 더합니다.
6. queue({n, serviceMs, blockAt, blockMs}) 로 요청 여럿을 한꺼번에 처리해runs.queue 에 적습니다.
7. verdict(run, budgetMs) 로 예산을 넘긴 표본을 세는 규칙을 만듭니다.
참고
- 백분위는 가장 가까운 순위(nearest-rank) 로 셉니다. 오름차순으로 정렬한 뒤
- 지연은 잰 간격을 뺀 나머지 입니다. 경과 시간을 그대로 담으면 조용한
report.json에는node필드로 이 파드의 판(process.version)을 적습니다.- 흔한 실수: 막는 동안에도 표본이 쌓일 것이라고 생각하는 것. 루프가 멈추면
ceil(p/100 * n) - 1 번째 값이고, 범위를 벗어나면 양 끝으로 맞춥니다.
채점기가 같은 규칙으로 다시 계산해 대조합니다.
상태에서도 중앙값이 간격만큼 나옵니다.
타이머도 멈추므로 그 구간은 표본 하나의 큰 값으로 나타납니다.
단계 7개
- 백분위부터 못 박는다
- 타이머가 늦은 만큼이 루프가 멈춘 시간이다
- 아무 일도 없을 때의 기준선
- 한 번 막고 다시 잰다
- 평균은 왜 아무 말도 하지 않는가
- 느려진 것은 한 요청이 아니었다
- 잰 것을 판단으로 바꾼다