Files
document-haness/docs/keycloak-session-store/tech-log-studio/when-the-measurement-lies/case/case-commands-written-as-prose-do-not-run.md
T
DongHyeonkaandClaude Opus 5 2109f726fe feat(pipeline): keycloak-session-store 25편·virtualization 59편을 S3→S5→S6 으로 돌린다
기록 84편을 계약 에이전트로 다시 썼다. 기존 71편(kss 25 · virt 46)과, 계약에만
있고 안 쓰여 있던 새 글감 13편이다. 원장 84개를 열어 단계마다 스킬 영수증과 관문
종료 코드를 적었고 verify-pipeline-run.py 가 error 0 으로 닫는다.

SSOT 결함 둘을 고쳤다.

- kss 의 `약 58일` 이 반입 중 `약 59일` 로 바뀌어 있었다. 원 증거 파일이
  「남은 일수: 88일 … 실제 갱신까지 약 58일」로 산수를 직접 적는다. D-4a 쪽
  `약 59일` 은 강제 갱신 뒤(`VALID: 89 days`)라 맞는 값이라 그대로 뒀다.
- virt §198 의 `11.6GB` 는 §178 의 원 측정 `Mem: 11648`(MiB)과 어긋나는데
  원 가이드의 표기 그대로라 고치지 않고 쓰이는 자리에 대조를 적었다.

기록의 수치 오류 셋을 고쳤다 — CASE 요약의 「게스트 셋에 8240MB」(5120+3120 은
둘이다), k3s 편이 같은 것을 여섯·일곱·여덟로 세던 것, no-docker 편의 「셋을 더
든다」(§281 의 표는 네 행이고 디스크 행이 빠져 있었다).

계약을 셋 고쳤다.

- kss 의 sourceRepository 리비전이 cdac9b8 이었는데 그 커밋에는 docs/guides/**
  28개가 아예 없다. 9465582b 로 바꾸고, 반입한 바이트가 어느 커밋과도 같지 않다는
  것을 측정값과 함께 적었다 — 반입은 커밋이 아니라 그 시점의 작업 트리에서 떠 온
  것이다(kss 297/306 · virt 12/14 가 작업 트리와 같고, 200 커밋을 거슬러 전수
  대조했을 때 가장 가까운 커밋도 28개가 어긋났다).
- virt 계약이 「2026-09-11 재배분」이라고 적는데 SSOT 는 재배분 날짜를 적지 않고
  재배분 뒤 값은 이미 2026-09-10 측정에 찍혀 있다.
- kss 후보 대장이 지나친 절 아홉에 처분을 적었다(warn 9 → 0). 새 글감은 0건이고
  넷은 앵커가 h3 슬러그의 접두가 아니라 중간 토막이라 검사기가 못 본 것이었다.

style_profile.mjs 의 결함 둘을 고쳤다 — frontmatter 가 문장으로 세어져
(실측 398자짜리 「문장」 하나) 평균 길이를 기준 안으로 밀어 올리고 있었고,
engPerSent 의 분자는 목록을 포함한 글에서, 분모는 목록을 걷어낸 글에서 세고
있었다(Question 기록에서 11.94 → 3.86).

verify-pipeline.py 전 항목 PASS · error 0 · unittest 334건 OK.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-17 11:01:55 +09:00

138 lines
9.2 KiB
Markdown

---
kind: CASE
slug: commands-written-as-prose-do-not-run
title: 산문으로 적힌 측정 장치를 실행 가능하게 고쳤더니 한 건이 깨졌다
topic: when-the-measurement-lies
topicName: 주입이 걸렸는지 무엇으로 아는가
project: keycloak-session-store
status: 게시 전
lastVerifiedOn:
sourceRevision: cdac9b8178391311d8eca1ebc6cac15bb62d79af
source:
- final/document.md#결정이-지켜지는지-확인하는-방법-재현-가능성
- final/document.md#검토한-선택지와-막힌-지점-스크립트를-쓰지-않는다
assets:
- key: reproducibility-gap
file: ../../../final/assets/reproducibility-gap/reproducibility-gap.svg
evidence:
- ../../../final/evidence/raw/a6-latency-injection__04-pool-under-load.txt
- ../../../final/evidence/raw/followup__05-command-reproducibility.txt
---
# 산문으로 적힌 측정 장치를 실행 가능하게 고쳤더니 한 건이 깨졌다
산문으로 적힌 측정 장치 넷을 셸 표현식으로 바꿔 실제로 돌렸더니 한 건이 깨졌다. 22.2초를 낸 A-6 의 부하 생성기였고, 일회성 파드의 stdout 이 유실돼 동시 20건 중 일부만 도착했다. 상주 탐침 안 파일로 모아 회수하는 방식으로 고치고 20/20 을 다시 확인했다.
## 관계
- **주입이 아홉 번 조용히 실패했고 전부 아무 일도 없는 것처럼 보였다**
여기서 깨진 부하 생성기가 그 아홉 건의 마지막 항목이다. 고치고 나서야 아홉 번째 실패로 확정됐다.
- **예측을 먼저 적고, 주입이 걸렸는지 결과와 따로 확인하고, 대조군 없이 귀속하지 않는다**
주입을 확인하는 명령도 절차의 일부라서, 그 명령이 실제로 도는지까지 확인해야 이 기준이 성립한다.
## 문제
절차를 스크립트로 감싸면 무엇을 했는지가 스크립트 안으로 숨는다. 그래서 모든 절차를 셸에 그대로 붙여넣을 수 있는 명령으로 적었다.
명령을 적는 것만으로는 부족했다. 측정 장치 자체를 괄호와 설명으로 적어 둔 곳이 넷 있었고, 그 넷이 헤드라인 수치를 만든 명령이었다.
## 결론
산문으로 적혀 있던 측정 장치 : 4곳 (A-6 · A-3 · A-8 · A-1)
셸 표현식으로 바꾼 뒤 실제로 돌렸을 때 깨진 것 : 1건 (A-6 의 부하 생성기)
깨진 이유 : 일회성 파드의 stdout 이 유실된다
고친 방법 : 상주 탐침 + 파드 안 파일 수집
고친 뒤 : 동시 20건에서 20/20 도착
고친 장치에서 나온 값 : 가장 느린 요청 22.230871초 · 커넥션 획득 대기 최대 20000.0ms
명령을 실행 가능하게 고쳤다는 것과 고친 명령이 동작한다는 것은 다른 주장이다. 넷 중 셋은 고치자마자 돌았고 하나는 돌지 않았는데, 실제로 실행해 보기 전에는 넷이 같아 보였다.
## 검증 환경
대상 실험 : A-6 지연 주입 (200ms 를 걸고 동시 20건 로그인)
부하 대상 : keycloak-1
측정한 것 : 상태코드 · 응답 시간 · agroal 커넥션 풀 지표 · readiness 이벤트
처음 쓴 방법 : kubectl run --rm -i 로 일회성 파드를 띄워 stdout 수집
고친 방법 : 상주 탐침 안에서 실행하고 파드 안 파일로 모은 뒤 회수
스크립트 사용 : x
## 재현 조건
1. 절차 문서에서 괄호와 설명으로 적힌 명령을 찾는다.
실행할 수 없는 형태로 적힌 측정 장치를 골라낸다.
2. 그것을 셸에 붙여넣을 수 있는 표현식으로 바꾼다.
3. 바꾼 표현식을 실제로 실행한다. 문법 검사로 대신하지 않는다.
4. 기대한 만큼의 줄이 도착했는지 센다.
동시 20건이면 20줄이 있어야 한다.
5. 줄이 모자라면 출력 경로를 바꾼다.
일회성 파드의 stdout 대신 상주 탐침 안 파일에 쓰고 회수한다.
6. 고친 장치로 다시 측정해 원래 수치가 재현되는지 본다.
## 본문
<!-- body:start -->
## 스크립트를 쓰지 않기로 했다
절차를 스크립트로 감싸면 무엇을 했는지가 스크립트 안으로 숨는다. 파일 이름만 남고 그 안에서 어떤 명령이 어떤 순서로 돌았는지는 다른 파일을 열어야 알 수 있다. 그래서 이 실험대는 모든 절차를 셸에 그대로 붙여넣을 수 있는 명령으로 적었다.
그런데 나중에 재현 절차를 점검해 보니 셸에 붙여넣을 수 없는 형태로 남아 있는 곳이 넷 있었다.
## 명령으로 적히지 않은 곳이 넷 있었다
문서의 명령을 하나씩 봤더니 절차 대부분은 붙여넣으면 도는 형태였고, 걸린 넷은 전부 측정 장치 자체를 적어 둔 곳이었다.
| 어디 | 무엇이 산문으로 적혀 있었나 |
|---|---|
| A-6 | `( curl ... ) & 를 20개 띄우고 wait` ← 22.2초의 출처 |
| A-3 | `<로그인 반복, sid 를 /tmp/sids 에>` ← RPO 측정 전체 |
| A-8 | `/tmp/tok` 에 쓰고 `/tmp/rt` 를 읽는다 ← 빈 토큰을 보내고 있었다 |
| A-1 | conntrack 튜플을 손으로 적는다 ← 방향이 재시작마다 바뀐다 |
넷 다 이 실험대의 헤드라인 수치를 만든 명령이다. A-6 의 한 줄이 22.2초를 냈고, A-3 의 한 줄은 RPO(복구 시점 목표 — 장애로 잃을 수 있는 데이터의 시간 범위) 측정 전체를 냈다. A-8 은 적힌 대로 읽으면 토큰을 쓴 파일과 읽는 파일이 달라서 빈 토큰을 보내고 있었고, A-1 은 재시작마다 바뀌는 방향을 사람이 그때그때 적는 형태였다.
## 바꾼 다음 실제로 돌렸고, 거기서 한 건이 깨졌다
넷을 전부 셸 표현식으로 바꾸고 문법이 맞는지가 아니라 실제로 실행해서 확인했다. 돌려 보지 않고 「재현 가능하게 고쳤다」고 적는 것은 측정하지 않고 단언하는 일이라, 애초에 이 넷을 걸러 낸 점검이 잡아낸 실수를 그대로 되풀이하는 것이 된다. 그래서 실행 기록을 따로 남겼다. 셋은 그대로 돌았고 A-6 의 부하 생성기가 깨졌다.
깨진 이유는 표현식이 아니라 출력 경로였다. `kubectl run --rm -i` 로 띄운 일회성 파드는 명령이 끝나면 곧바로 지워지는데, 그 과정에서 stdout 이 유실돼 동시 20건의 결과가 일부만 도착하거나 아예 끊겼다. 두 번 시도해서 두 번 다 출력이 도착하지 않고 세션이 그대로 끊겼다. 셸은 오류를 내지 않고 종료 코드도 0 이므로, 도착한 줄 수를 세기 전에는 실패한 것으로 보이지 않는다.
같은 함정을 이 실험 시리즈에서 이미 한 번 겪었는데, 재현 절차를 실행 가능하게 고치면서 그 깨진 형태를 그대로 다시 써넣었다.
출력을 파드 밖으로 흘려보내는 대신 파드 안에 모으는 쪽으로 바꿨다. 상주 탐침 하나를 계속 띄워 두고 그 안에서 요청을 보내 결과를 파일에 쓴 뒤, 측정이 끝나고 파일을 통째로 회수했다.
![산문으로 적힌 측정 장치를 셸 표현식으로 바꾸고, 그것을 실행해 확인하는 단계까지 거치는 경로](../../../final/assets/reproducibility-gap/reproducibility-gap.svg)
두 화살표가 각각 다른 것을 걸러낸다. 첫 번째를 지나면 붙여넣어 실행할 수 있는 명령이 되고, 두 번째를 지나야 그 명령이 기대한 출력을 내는지 확인된다. 이 실험대에서 넷은 첫 번째를 다 지났고 한 건이 두 번째에서 멈췄다.
## 고친 장치로 다시 잰 값
바꾼 탐침으로 동시 20건을 다시 돌렸다. 20줄이 전부 도착했고 상태코드는 모두 200 이었다.
```text label="고친 부하 생성기로 다시 돌린 동시 20건과 직후의 커넥션 풀"
1 200 1.911191
1 200 19.053724
1 200 22.228466
1 200 22.230871
agroal_blocking_time_max_milliseconds 20000.0
agroal_max_used_count 19.0
agroal_acquire_count_total 672.0
```
가장 느린 요청이 22.230871초였고 이것이 A-6 이 보고한 22.2초다. 커넥션 획득 대기 최댓값은 20000.0ms 로 찍혔다. 일회성 파드로 재던 때에는 스무 줄 중 몇 줄이 도착했는지 셀 수 없었으므로, 같은 수치가 스무 건 전부에서 나온다는 것은 고친 장치로 돌린 다음에 확인됐다.
부하 직후에 함께 수집한 이벤트에는 `keycloak-1` 의 readiness 프로브가 503 과 타임아웃으로 실패한 기록이 남아 있다. 지연을 건 노드가 느려지다 로드밸런서에서 빠지는 구간이고, 응답 시간 20줄과 커넥션 풀 지표와 이 이벤트가 한 파일에 함께 들어 있다.
## 이 확인이 닿지 않은 곳
고친 명령을 다른 환경에서 돌려 보지 않았다. 이 실험대의 k3s 와 이 Keycloak 구성에서만 확인했고, 상주 탐침이 필요한 이유였던 일회성 파드의 출력 유실이 다른 런타임에서도 같은 모양으로 나타나는지는 재지 않았다.
넷 중 셋은 바꾼 표현식이 한 번에 돌았다는 것까지만 확인했다. A-3 과 A-8 과 A-1 의 측정값을 고친 명령으로 처음부터 다시 만들어 원래 수치와 맞춰 보지는 않았다.
실행 확인을 하면서 A-6 의 단일 요청 지연도 같이 쟀는데, 그것은 지연을 걸지 않은 평시 값이라 본문의 22.2초와 나란히 놓으면 안 된다. 거기서 확인한 것은 명령이 돈다는 것뿐이다.
<!-- body:end -->