느리다는 신고에는 고칠 자리가 없다

한 줄 요약

주문이 지나간 자리마다 시각이 찍혀 있어야 어느 구간이 느린지 말할 수 있다. 그리고 구간의 양 끝이 다른 기계면 그 차이에는 두 기계의 시계 오차가 그대로 섞여 들어간다.

왜 이게 필요했나

"주문이 느립니다" 라는 신고를 받으면 처음에는 할 일이 없습니다. 무엇이 느린지 모르기 때문입니다. 게이트웨이가 느린지, 위험 점검이 오래 걸리는지, 회선이 막혔는지, 거래소가 늦게 받아 주는지 — 후보가 넷인데 고칠 팀은 넷 다 다릅니다. 이 상태에서 회의를 열면 각 팀이 자기 구간은 멀쩡하다고 말하고, 아무도 틀린 말을 하지 않은 채로 아무것도 고쳐지지 않습니다.

그래서 처음 하는 일은 경로에 자를 대는 것입니다. 주문 하나가 우리 안에서 지나가는 자리를 정하고 그 자리마다 시각을 남깁니다. 수신, 위험 점검 완료, 세션 인코딩 완료, 회선 송신, 거래소 접수, ack 수신. 여섯 자리를 정하면 다섯 구간이 생기고, 그때부터 "느리다" 는 "이 구간이 이만큼 느리다" 로 바뀝니다. 바뀐 순간 고칠 팀이 정해집니다.

어떻게 동작하나

구간 지연은 뒤 시각에서 앞 시각을 뺀 값입니다. 쉬워 보이지만 여기에 함정이 하나 있습니다. 두 시각을 같은 기계가 찍었는지가 값의 뜻을 바꿉니다.

같은 기계 안의 두 시각이면 그 차이는 그 기계의 시계가 얼마나 정확한지와 거의 무관합니다. 시계가 3밀리초 앞서 있어도 두 시각 모두 3밀리초 앞서 있으므로 빼면 사라집니다. 그래서 같은 기계 안의 구간은 믿을 수 있고, 여기서는 [단조 시계](https://docs.python.org/3/library/time.html)를 쓰는 것이 더 낫습니다. 벽시계는 시각 동기화 보정이 들어오면 뒤로 갈 수 있지만 단조 시계는 뒤로 가지 않습니다.

반대로 양 끝이 다른 기계인 구간은 두 기계의 시계 오차가 그대로 들어갑니다. 우리 게이트웨이가 회선으로 내보낸 시각과 거래소가 접수했다고 찍은 시각의 차이는 진짜 회선 시간에 두 시계의 차이를 더한 값입니다. 거래소 시계가 우리보다 뒤처져 있으면 이 값은 음수로 나옵니다. 빛보다 빨리 갔다는 뜻이 아니라 자가 틀린 것입니다.

그런데 왕복은 상쇄됩니다. 회선 송신 시각과 ack 수신 시각은 둘 다 우리 기계가 찍습니다. 그 사이에 주문이 거래소를 다녀왔지만, 두 시각이 같은 시계에서 나왔으므로 거래소 시계가 얼마나 틀렸든 차이에는 들어오지 않습니다. 편도는 오염되고 왕복은 깨끗하다는 이 성질이 [RFC 5905](https://www.rfc-editor.org/rfc/rfc5905)의 시각 동기화가 오프셋을 재는 방식의 바탕이기도 합니다. 그래서 편도 구간을 보려면 오프셋 보고를 받아 보정해야 하고, 보정한 뒤에도 음수가 남는 구간이 진짜 결함입니다. 여기서 흔한 실수는 반대쪽입니다. 한 구간이 통째로 음수로 나오면 "전부 시계 탓" 이라고 묶어 버리는데, 그 안에 섞여 있던 진짜 한 건이 그렇게 사라집니다.

모아 놓은 뒤에는 평균을 보지 않습니다. 지연 분포는 한쪽으로 길게 늘어져 있어서 평균은 소수의 느린 건에 끌려다닙니다. 대신 백분위수를 봅니다. 다만 백분위수에는 정의가 여러 개라는 사실이 중요합니다. 정렬해 놓고 그 자리의 값을 그대로 쓰는 방식과, 두 값 사이를 보간하는 방식은 같은 자료에서 다른 숫자를 냅니다. [statistics 모듈](https://docs.python.org/3/library/statistics.html)의 설명에도 방식이 여러 개 적혀 있습니다. 우리 대시보드와 상대의 계약서가 다른 정의를 쓰고 있으면 같은 회선을 두고 한쪽은 위반이라 하고 한쪽은 아니라고 합니다. 그래서 정의를 자료 옆에 적어 두고 그대로 구현합니다.

그리고 구간별 백분위수는 전체 꼬리를 설명하지 못합니다. 구간마다 p99 를 내면 보통 회선 구간이 가장 큽니다. 그런데 전체 지연이 가장 나쁜 상위 1퍼센트 주문을 뽑아 그 주문들의 가장 큰 구간을 세어 보면 다른 구간이 나오기도 합니다. 구간별 p99 는 각 구간에서 서로 다른 주문을 보고 있고, 전체 꼬리는 한 주문 안에서 무엇이 컸는지를 봅니다. 두 질문이 다르므로 답도 다릅니다. 고칠 자리를 정하는 것은 뒤쪽입니다.

마지막이 지연 예산입니다. 구간마다 상한을 정해 두고 초과 건수를 셉니다. 예산의 값은 취향이 아니라 결정입니다. 느슨하게 잡으면 이상한 것만 걸리고, 조이면 정상 변동까지 걸려서 경보가 하루 수천 건이 됩니다. 그 순간 아무도 그 경보를 보지 않게 되므로, 예산은 두 벌을 만들어 초과 건수를 실제로 세어 보고 정해야 합니다.

현장에서 만나는 모습

한 번은 회선 구간이 음수로 나온다는 이유로 그 구간의 측정이 통째로 버려진 적이 있습니다. 몇 달 뒤 거래소와 응답 시간을 두고 이야기가 오갔을 때 우리에게는 그 구간의 숫자가 없었습니다. 오프셋 보고를 받아 빼기만 하면 되는 일이었는데, 음수를 본 사람이 "측정이 고장 났다" 고 판단하고 대시보드에서 지운 것이 전부였습니다.

또 한 번은 회선 구간의 p99 가 가장 크다는 이유로 회선 증설이 결정된 적이 있습니다. 증설 뒤에도 느린 주문의 신고는 줄지 않았습니다. 가장 느린 주문들을 다시 열어 보니 그 주문들에서 큰 구간은 회선이 아니라 위험 점검과 인코딩 사이의 대기였고, 그것은 특정 시간대에만 나타났습니다. 구간별 p99 와 전체 꼬리를 같은 질문으로 여긴 대가였습니다.

다음 실습에서 할 것

주문 1500건의 구간 타임스탬프와 호스트별 시계 오프셋 보고, 지연 예산 두 벌, 백분위수 정의를 자료로 만듭니다. 구간 지연을 계산해 음수가 나오는 자리를 찾고, 오프셋으로 보정해 시계 오차와 진짜 결함을 가릅니다. 그 뒤 구간별 백분위수와 전체 꼬리를 만드는 구간을 따로 세어 둘이 다르다는 것을 확인하고, 예산 두 벌의 초과 건수를 견줍니다. 마지막에는 어느 구간이 몇 분부터 나빠졌는지와 자료로 배제한 가설을 함께 적습니다.