LabHub
学习 学习路径 课程

可观测性

打开调试日志那天，排查需要的那几行反而没了

在 LabHub 中继续学习

한국어 원문으로 표시합니다.

목표

고정된 로그 파일 하나로 수준별 비용 표를 만들고, 요청 단위 표본·오류 보존·반복 접기·초당 상한을 직접 구현해 비용과 조사 가능성의 맞바꿈을 숫자로 만든 뒤 정책 파일로 못박습니다.

왜 중요한가

로그 비용을 줄이라는 요구는 항상 온다. 그때 가장 쉬운 답이 '수준을 올린다' 와 '표본을 뽑는다' 인데, 둘 다 잘못하면 비용만 줄고 조사 능력은 0 이 된다. 사람이 조사할 때 읽는 단위는 줄이 아니라 한 요청이 남긴 줄의 묶음이기 때문이다. 줄 단위로 10% 를 남기면 어느 요청도 끝까지 읽을 수 없지만, 요청 단위로 10% 를 남기면 그 10% 는 완전하다. 여기에 '오류로 끝난 요청은 빼지 않는다' 는 규칙 하나를 더하면 비용은 거의 그대로인 채 실패한 요청의 보존율이 0% 에서 100% 로 올라간다. 이 실습에서 만드는 표는 다음번 비용 회의에서 그대로 쓸 수 있는 근거다.

단계

  1. 재료 로그는 /opt/lab/logsample/app.log 입니다. 줄 형식은 <시각> <수준> req=<id> handler=<경로> msg="<메시지>" 이고 수준은 DEBUG·INFO·WARN·ERROR 넷입니다. /root/obs-log-sampling/cost.tsv 에 머리글 없이 네 줄, 각 줄은 탭으로 나눈 세 칸 <수준> <줄 수> <바이트> 를 적으세요. 바이트는 그 수준의 줄들이 차지하는 바이트 수이고 줄바꿈 문자 한 개를 포함합니다.
  2. DEBUG 줄을 전부 버렸을 때의 결과를 /root/obs-log-sampling/drop-debug.txt 에 여섯 줄로 적으세요. kept_lines=<남은 줄 수>, kept_bytes=<남은 바이트>, saved_pct=<바이트 기준 절감률, 소수 두 자리>, req=<오류로 끝난 요청 중 request_id 가 사전순으로 가장 앞선 것>, req_lines_before=<그 요청의 원래 줄 수>, req_lines_after=<DEBUG 를 뺀 뒤 그 요청에 남은 줄 수> 입니다. '오류로 끝난 요청' 은 수준이 ERROR 인 줄을 하나 이상 가진 요청입니다.
  3. /root/obs-log-sampling/sample.py 를 만드세요. python3 sample.py --rate N < 입력 > 출력 으로 부르면 표준 입력의 줄을 읽어 남길 줄만 그대로 표준 출력에 씁니다(입력 순서 유지). 남기는 기준은 요청 단위입니다 — 줄의 req= 값을 r 이라 할 때 int(hashlib.md5(r.encode()).hexdigest()[:8], 16) % N == 0 이면 그 줄을 남깁니다. --rate 1 은 전부 남깁니다. 그다음 python3 sample.py --rate 10 < /opt/lab/logsample/app.log > /root/obs-log-sampling/sampled-10.log 로 결과 파일을 만드세요.
  4. /root/obs-log-sampling/sample.py 에 --keep-errors 옵션을 더하세요. 이 옵션이 있으면 수준이 ERROR 인 줄을 하나라도 가진 요청은 표본률과 무관하게 모든 줄을 남깁니다(입력 순서 유지). 옵션이 없을 때의 동작은 3단계와 같아야 합니다. 그다음 python3 sample.py --rate 10 --keep-errors < /opt/lab/logsample/app.log > /root/obs-log-sampling/sampled-10-err.log 로 결과를 만드세요.
  5. 표본률 N 을 1·4·10·50 으로 바꿔 가며 /root/obs-log-sampling/tradeoff.tsv 를 만드세요. 머리글 없이 네 줄이고 각 줄은 탭으로 나눈 다섯 칸 <N> <표본만 썼을 때 남은 줄 수> <그때 완전히 남은 오류 요청 수> <오류 보존까지 켰을 때 남은 줄 수> <그때 완전히 남은 오류 요청 수> 입니다. '완전히 남은 오류 요청' 은 오류로 끝난 요청 중 결과 파일에 줄이 하나라도 남아 있는 요청을 셉니다.
  6. /root/obs-log-sampling/squeeze.py 를 만드세요. python3 squeeze.py [--max-debug-per-sec K] < 입력 > 출력 (K 기본값 20)으로 부르면 두 규칙을 차례로 적용합니다. ① 바로 앞 줄과 (수준, handler, msg) 가 모두 같으면 한 덩어리로 보고 첫 줄만 남기되, 덩어리의 줄 수 k 가 2 이상이면 그 줄 끝에 repeated=<k> 를 붙입니다. ② 접은 뒤, DEBUG 줄만 같은 초(시각 문자열의 앞 19자) 안에서 앞에서부터 K 개까지 남기고 나머지는 버립니다. 그다음 python3 squeeze.py < /opt/lab/logsample/app.log > /root/obs-log-sampling/squeezed.log 를 만들고, /root/obs-log-sampling/squeeze.txt 에 네 줄 in_lines=, after_collapse=, after_cap=, bytes_saved_pct=<소수 두 자리> 를 적으세요.
  7. sample.py --rate 10 --keep-errors 의 출력을 squeeze.py(기본 상한)에 그대로 흘려 /root/obs-log-sampling/final.log 를 만드세요. 그리고 /root/obs-log-sampling/final.txt 에 여덟 줄을 적으세요 — in_lines=, out_lines=, in_bytes=, out_bytes=, reduction_pct=<바이트 기준, 소수 두 자리>, error_requests_kept=<final.log 에 줄이 남아 있는 오류 요청 수>, trace_req=<2단계에서 고른 그 요청 id>, trace_lines=<final.log 에 남은 그 요청의 줄 수> 입니다.
  8. /root/obs-log-sampling/policy.yml 을 YAML 로 쓰세요. levels 아래 DEBUG·INFO·WARN·ERROR 네 수준마다 retain_days(정수)와 sample_rate(정수) 를 둡니다. ERROR 의 sample_rate 는 1 이어야 하고 retain_days 는 DEBUG 보다 커야 합니다. DEBUG 의 sample_rate 는 2 이상이어야 합니다. rules 아래에는 keep_errors_whole_request: true, collapse_repeats: true, max_debug_per_sec(6단계에서 쓴 기본값)를 둡니다. estimate 아래에는 raw_bytes·kept_bytes·reduction_pct 를 7단계 결과와 같은 값으로 적고, 마지막에 note 로 이 정책의 맞바꿈을 40자 이상 한 문장으로 적으세요.

참고

수준별로 얼마를 쓰고 있는지부터 센다

재료 로그는 /opt/lab/logsample/app.log 입니다. 줄 형식은 <시각> <수준> req=<id> handler=<경로> msg="<메시지>" 이고 수준은 DEBUG·INFO·WARN·ERROR 넷입니다. /root/obs-log-sampling/cost.tsv 에 머리글 없이 네 줄, 각 줄은 탭으로 나눈 세 칸 <수준> <줄 수> <바이트> 를 적으세요. 바이트는 그 수준의 줄들이 차지하는 바이트 수이고 줄바꿈 문자 한 개를 포함합니다.

수준은 공백으로 나눈 둘째 칸입니다. awk '{print $2}' 로 꺼낼 수 있습니다. 바이트는 awk '{n[$2]++; b[$2]+=length($0)+1}' 처럼 줄 길이에 1 을 더해 모으면 됩니다. 네 숫자의 비율이 이 실습의 출발점입니다 — 어느 수준이 부피의 대부분을 차지하는지 보세요.

DEBUG 를 끄면 무엇이 남고 무엇이 사라지나

DEBUG 줄을 전부 버렸을 때의 결과를 /root/obs-log-sampling/drop-debug.txt 에 여섯 줄로 적으세요. kept_lines=<남은 줄 수>, kept_bytes=<남은 바이트>, saved_pct=<바이트 기준 절감률, 소수 두 자리>, req=<오류로 끝난 요청 중 request_id 가 사전순으로 가장 앞선 것>, req_lines_before=<그 요청의 원래 줄 수>, req_lines_after=<DEBUG 를 뺀 뒤 그 요청에 남은 줄 수> 입니다. '오류로 끝난 요청' 은 수준이 ERROR 인 줄을 하나 이상 가진 요청입니다.

사전순으로 가장 앞선 아이디는 grep ' ERROR ' | grep -o 'req=[0-9a-f]*' | sort -u | head -1 로 찾을 수 있습니다. 그 요청의 줄만 보려면 grep 'req=<id>' 하면 됩니다. 남은 줄 수가 아니라 그 요청의 흐름을 읽을 수 있는가 가 이 단계의 질문입니다.

줄이 아니라 요청을 표본으로 뽑는다

/root/obs-log-sampling/sample.py 를 만드세요. python3 sample.py --rate N < 입력 > 출력 으로 부르면 표준 입력의 줄을 읽어 남길 줄만 그대로 표준 출력에 씁니다(입력 순서 유지). 남기는 기준은 요청 단위입니다 — 줄의 req= 값을 r 이라 할 때 int(hashlib.md5(r.encode()).hexdigest()[:8], 16) % N == 0 이면 그 줄을 남깁니다. --rate 1 은 전부 남깁니다. 그다음 python3 sample.py --rate 10 < /opt/lab/logsample/app.log > /root/obs-log-sampling/sampled-10.log 로 결과 파일을 만드세요.

판정을 줄이 아니라 요청에 걸기 때문에 한 요청의 줄이 통째로 남거나 통째로 사라집니다. 그것이 이 필터의 전부입니다 — 결과 파일에서 아무 request_id 나 골라 grep 해 보면 원본과 줄 수가 같습니다. 해시 방식은 과제에 적힌 그대로 써야 합니다. 채점기가 같은 규칙으로 다시 계산해 줄 단위로 맞춰 봅니다.

오류로 끝난 요청은 표본에서 빼지 않는다

/root/obs-log-sampling/sample.py 에 --keep-errors 옵션을 더하세요. 이 옵션이 있으면 수준이 ERROR 인 줄을 하나라도 가진 요청은 표본률과 무관하게 모든 줄을 남깁니다(입력 순서 유지). 옵션이 없을 때의 동작은 3단계와 같아야 합니다. 그다음 python3 sample.py --rate 10 --keep-errors < /opt/lab/logsample/app.log > /root/obs-log-sampling/sampled-10-err.log 로 결과를 만드세요.

어떤 요청이 오류로 끝났는지는 파일을 끝까지 읽어야 알 수 있으므로 두 번 훑어야 합니다 — 먼저 ERROR 줄의 request_id 를 모으고, 그다음 줄을 다시 훑으며 판정합니다. 이 규칙을 넣으면 줄 수가 얼마나 늘어나는지 3단계 결과와 비교해 보세요. 생각보다 적게 늡니다.

표본률과 조사 가능성의 맞바꿈을 표로 만든다

표본률 N 을 1·4·10·50 으로 바꿔 가며 /root/obs-log-sampling/tradeoff.tsv 를 만드세요. 머리글 없이 네 줄이고 각 줄은 탭으로 나눈 다섯 칸 <N> <표본만 썼을 때 남은 줄 수> <그때 완전히 남은 오류 요청 수> <오류 보존까지 켰을 때 남은 줄 수> <그때 완전히 남은 오류 요청 수> 입니다. '완전히 남은 오류 요청' 은 오류로 끝난 요청 중 결과 파일에 줄이 하나라도 남아 있는 요청을 셉니다.

sample.py 를 옵션만 바꿔 여덟 번 돌리면 됩니다. 오류 요청 수는 grep ' ERROR ' <결과> | grep -o 'req=[0-9a-f]*' | sort -u | wc -l 로 셀 수 있습니다. 셋째 칸이 어디서 0 이 되는지, 그리고 그때 넷째 칸이 둘째 칸보다 얼마나 늘어나는지를 보세요.

반복을 접고 초당 상한을 건다

/root/obs-log-sampling/squeeze.py 를 만드세요. python3 squeeze.py [--max-debug-per-sec K] < 입력 > 출력 (K 기본값 20)으로 부르면 두 규칙을 차례로 적용합니다. ① 바로 앞 줄과 (수준, handler, msg) 가 모두 같으면 한 덩어리로 보고 첫 줄만 남기되, 덩어리의 줄 수 k 가 2 이상이면 그 줄 끝에 repeated=<k> 를 붙입니다. ② 접은 뒤, DEBUG 줄만 같은 초(시각 문자열의 앞 19자) 안에서 앞에서부터 K 개까지 남기고 나머지는 버립니다. 그다음 python3 squeeze.py < /opt/lab/logsample/app.log > /root/obs-log-sampling/squeezed.log 를 만들고, /root/obs-log-sampling/squeeze.txt 에 네 줄 in_lines=, after_collapse=, after_cap=, bytes_saved_pct=<소수 두 자리> 를 적으세요.

접기는 '연속' 일 때만 합니다 — 사이에 다른 요청의 줄이 끼면 다른 덩어리입니다. after_collapse 는 상한을 아주 크게 준 채로 한 번 더 돌려 세면 쉽습니다. 상한을 DEBUG 에만 거는 이유가 이 단계의 핵심입니다. 수준을 가리지 않고 걸면 폭주하는 그 순간에 ERROR 가 잘려 나가, 가장 필요한 시각의 로그만 사라집니다.

응용 ① — 두 필터를 이어 붙이고 조사가 되는지 확인한다

sample.py --rate 10 --keep-errors 의 출력을 squeeze.py(기본 상한)에 그대로 흘려 /root/obs-log-sampling/final.log 를 만드세요. 그리고 /root/obs-log-sampling/final.txt 에 여덟 줄을 적으세요 — in_lines=, out_lines=, in_bytes=, out_bytes=, reduction_pct=<바이트 기준, 소수 두 자리>, error_requests_kept=<final.log 에 줄이 남아 있는 오류 요청 수>, trace_req=<2단계에서 고른 그 요청 id>, trace_lines=<final.log 에 남은 그 요청의 줄 수> 입니다.

두 필터 모두 표준 입출력을 쓰므로 파이프로 이으면 됩니다. trace_lines 를 2단계의 req_lines_before 와 비교해 보세요 — DEBUG 를 껐을 때와 무엇이 다른지가 이 실습의 결론입니다. 반복이 접힌 요청이라면 줄 수가 원래보다 줄어들 수도 있습니다.

응용 ② — 수준·표본률·보존기간·비용을 정책 파일로 못박는다

/root/obs-log-sampling/policy.yml 을 YAML 로 쓰세요. levels 아래 DEBUG·INFO·WARN·ERROR 네 수준마다 retain_days(정수)와 sample_rate(정수) 를 둡니다. ERROR 의 sample_rate 는 1 이어야 하고 retain_days 는 DEBUG 보다 커야 합니다. DEBUG 의 sample_rate 는 2 이상이어야 합니다. rules 아래에는 keep_errors_whole_request: true, collapse_repeats: true, max_debug_per_sec(6단계에서 쓴 기본값)를 둡니다. estimate 아래에는 raw_bytes·kept_bytes·reduction_pct 를 7단계 결과와 같은 값으로 적고, 마지막에 note 로 이 정책의 맞바꿈을 40자 이상 한 문장으로 적으세요.

python3 -c "import yaml,sys;yaml.safe_load(open('policy.yml'))" 로 문법을 먼저 확인하세요. 숫자는 손으로 옮기지 말고 final.txt 에서 읽어 채우면 실수가 없습니다. 보존 기간을 정할 때는 '이 수준을 며칠 뒤에 찾을 일이 있는가' 를 물어보세요 — 분기 회고에서 찾는 것은 ERROR 이지 DEBUG 가 아닙니다.