관측성 · 추적으로 느린 구간 찾기 · 실습
제일 느린 스팬을 고쳤는데 응답은 그대로였다
목표
파드에 들어 있는 3,454개 스팬을 표준 라이브러리만으로 분석해 자기 시간과 임계 경로를 직접 계산하고, '가장 오래 걸린 스팬' 과 '고쳐야 할 스팬' 이 다르다는 것을 숫자로 확인한 뒤 무엇을 고칠지 예상 절감과 함께 제출합니다.
왜 중요한가
폭포수 화면에서 제일 긴 막대는 '그 구간에 시간이 얼마나 걸렸나' 를 말해 줄 뿐, '그 구간을 줄이면 전체가 줄어드나' 에는 답하지 않는다. 병렬로 도는 형제 중 먼저 끝나는 쪽은 아무리 길어도 응답 시간에 기여하지 않는다. 두 질문을 가르는 것이 임계 경로 계산이고, 그 계산은 스팬의 시작 시각·지속 시간·부모 식별자 세 가지만 있으면 된다. 여기에 자기 시간을 겹쳐 보면 고칠 자리가 좁혀지고, 같은 이름의 형제를 묶어 보면 개별 순위에는 들지 않던 N+1 이 드러난다. 고치기 전에 예상 절감을 숫자로 적어 두는 습관이 마지막 한 조각이다 — 그래야 배포 뒤에 판단이 맞았는지 남는다.
단계
1. /root/obs-trace-critical/trace.py 를 만드세요. python3 trace.py shape 를 실행하면 /opt/lab/critpath/spans.jsonl 를 읽어 여섯 줄을 spans=, traces=, roots=, rootless_traces=, orphan_spans=, clean_traces= 순서로 출력해야 합니다. 루트 스팬은 parent_id 가 null 인 스팬, 고아 스팬은 parent_id 가 이 파일 안에 없는 스팬, clean_traces 는 루트가 정확히 하나이고 고아가 하나도 없는 트레이스 수입니다. 같은 여섯 줄을 /root/obs-trace-critical/01-shape.txt 에도 저장하세요.
2. trace.py tree <trace_id> 를 더하세요. 그 트레이스의 스팬을 루트부터 깊이 우선으로 훑으며 한 줄에 하나씩 <깊이><탭><span_id><탭><name><탭><지속시간> 을 출력합니다. 깊이는 루트가 0 이고, 형제는 start_ms 오름차순입니다. 지속 시간은 소수 셋째 자리까지 적습니다. 루트가 없는 트레이스를 주면 0 이 아닌 값으로 끝나야 합니다.
3. trace.py self <trace_id> 를 더하세요. 스팬마다 자기 시간(총 시간 − 자식들이 차지한 시간)을 구해 <span_id><탭><name><탭><자기시간> 을 자기 시간 내림차순으로 모두 출력합니다. 자식 구간이 서로 겹칠 때는 합집합 길이를 빼야 합니다 — 단순히 더해서 빼면 병렬 호출이 있는 스팬에서 음수가 나옵니다. 008cde18a6503944 로 확인해 보세요.
4. trace.py crit <trace_id> 를 더하세요. 루트의 지속 시간을 실제로 결정한 스팬들만 골라 <span_id><탭><name><탭><임계 경로 기여 밀리초> 를 기여 내림차순으로 출력합니다. 루트의 끝에서 거꾸로 훑으며 지금 시각보다 늦게 끝나는 자식은 건너뛰고, 가장 늦게 끝나는 자식으로 내려갑니다. 출력된 기여의 합은 루트의 지속 시간과 같아야 합니다 — 그것이 검산입니다.
5. 기준 트레이스 008cde18a6503944 에서 루트를 뺀 스팬을 세 가지로 줄 세워 /root/obs-trace-critical/05-compare.tsv 에 저장하세요. 머리글 없이 세 줄이고, 각 줄은 탭으로 나눈 네 칸 <순위><탭><총시간 1·2·3위 이름><탭><자기시간 1·2·3위 이름><탭><임계경로 기여 1·2·3위 이름> 입니다(순위는 1·2·3). 그리고 /root/obs-trace-critical/05-note.txt 에 두 줄을 적으세요 — longest_span= 뒤에 총 시간 1위 스팬의 이름, longest_on_critical_path= 뒤에 그 스팬이 임계 경로 위에 있으면 yes, 아니면 no.
6. trace.py nplus <trace_id> 를 더하세요. 같은 부모 아래에 같은 이름이 5개 이상 줄지어 있는 무리를 찾아 <부모 span_id><탭><name><탭><개수><탭><합계 밀리초><탭><절감 밀리초> 를 절감 내림차순으로 출력합니다. 절감은 '한 번의 호출로 묶었을 때' 로 보고 합계 − 그중 가장 긴 하나 로 계산합니다. 그리고 /root/obs-trace-critical/06-nplus.txt 에 기준 트레이스 008cde18a6503944 의 1위 무리를 name=, count=, total_ms=, saving_ms=, new_root_ms= 다섯 줄로 적으세요. new_root_ms 는 그 절감이 그대로 먹혔을 때의 루트 지속 시간입니다.
7. trace.py pct 를 더하세요. 깨끗한 트레이스(루트 하나·고아 없음)의 루트 지속 시간을 오름차순으로 줄 세우고 p50 과 p99 를 가장 가까운 순위(nearest-rank) 로 고릅니다 — 개수가 n 일 때 색인은 ceil(q × n) − 1 입니다. 출력은 두 줄이고 각각 <p50|p99><탭><trace_id><탭><루트 지속 시간> 입니다. 그다음 두 트레이스의 임계 경로를 견주어 /root/obs-trace-critical/07-p50p99.txt 에 여섯 줄을 적으세요 — p50_trace=, p50_ms=, p99_trace=, p99_ms=, only_in_p99=, only_in_p50=. 마지막 두 줄은 한쪽 임계 경로에만 나오는 스팬 이름을 쉼표로 이어 적습니다(이름 오름차순, 공백 없이).
8. 기준 트레이스 008cde18a6503944 를 놓고 후보 세 가지를 견주어 /root/obs-trace-critical/08-plan.tsv 에 저장하세요. 머리글 없이 세 줄이고 각 줄은 탭으로 나눈 네 칸 <id><탭><대상><탭><예상 절감 밀리초><탭><yes|no> 입니다. id 는 a·b·c 이고 대상은 차례로 inventory.db.scan 을 0 으로 만들기, pricing.rules.eval 을 0 으로 만들기, db.query.item 을 한 번으로 묶기입니다. 예상 절감은 앞 두 개가 그 스팬의 임계 경로 기여, 마지막이 6단계의 절감이며, 네 번째 칸은 그 대상이 임계 경로 위에 있으면 yes 입니다. 그다음 /root/obs-trace-critical/08-decision.txt 에 네 줄 fix=(a·b·c 중 하나), expected_ms=, new_root_ms=, reason=(60자 이상) 을 적으세요. 절감이 0 인 후보는 고를 수 없습니다.
참고
- 작업 디렉터리는
/root/obs-trace-critical입니다. 없으면 먼저 만드세요. - 재료는
/opt/lab/critpath/spans.jsonl입니다(JSON Lines, 3,454줄). 만든 스크립트는 같은 디렉터리의gen_spans.py입니다. 스팬 한 줄에는trace_id·span_id·parent_id·service·name·start_ms·duration_ms가 들어 있고,start_ms는 그 트레이스의 루트가 시작한 시점으로부터의 밀리초입니다. - 기준 트레이스는
008cde18a6503944이고, 느린 트레이스의 예로d1272fdd4d4bfe50를 함께 보면 차이가 잘 보입니다. - 파이썬은 3.12 표준 라이브러리만 씁니다.
pip install은 되지 않습니다. - 흔한 실수: 자식 시간을 그냥 더해서 자기 시간을 구하는 것. 병렬 자식이 있으면 음수가 나옵니다.
- 흔한 실수: 루트가 없거나 고아가 섞인 트레이스까지 통계에 넣는 것. 합계가 조용히 틀어집니다.
- [Traces (OpenTelemetry)](https://opentelemetry.io/docs/concepts/signals/traces/) · [Observability primer](https://opentelemetry.io/docs/concepts/observability-primer/) · [Instrumentation concepts](https://opentelemetry.io/docs/concepts/instrumentation/) · [Latency (SRE Book: 네 가지 골든 시그널)](https://sre.google/sre-book/monitoring-distributed-systems/)
단계 8개
- 자료의 모양부터 센다 — 루트 없는 트레이스와 고아 스팬
- 부모-자식을 다시 잇고 깊이를 붙인다
- 자기 시간 — 겹치는 자식은 합집합으로 뺀다
- 임계 경로 — 병렬 자식 중 늦게 끝난 쪽만 든다
- 세 목록이 다르다 — 어느 쪽을 고쳐야 응답이 줄어드나
- N+1 — 하나는 작지만 열여섯 개는 크다
- p50 과 p99 의 임계 경로는 다르다
- 무엇을 고칠 것인가 — 예상 절감을 숫자로 적는다