DongHyeonkaandClaude Opus 5
74c9b3cea7
The audit found ~80 placeholders, and the damaging ones were where the measuring apparatus itself was prose rather than a command: a6 "( curl ... ) & 를 20개 띄우고 wait" — the 22.2s headline came from this a3 "<로그인 반복, sid 를 /tmp/sids 에>" — the whole RPO measurement a3 "<sid 목록>" — the control it is compared against a5 "<수신 파드IP>" — the injection a8 writes /tmp/tok, reads /tmp/rt — self-inconsistent, sent an empty token b3 $KC / $RT / $NEW never assigned c2 bare kcadm.sh with no kubectl exec a1 conntrack tuples written by hand, though the direction flips per restart Each is now a shell-expandable form: pod IPs from jsonpath, the admin password from the secret, ids from kcadm --format csv, conntrack tuples derived from "conntrack -L" with awk rather than transcribed. Then the rewritten commands were executed against the live cluster, and one of them failed — the 20-way load generator, written as "kubectl run --rm -i", lost its output stream twice in a row. That is a trap this series already hit once, and the rewrite reintroduced it. A-6 now uses a resident probe pod that collects into a file and is cat-ed once; verified 20/20 lines. Evidence: docs/evidence/followup/05-command-reproducibility.txt Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
376 lines
14 KiB
Markdown
376 lines
14 KiB
Markdown
# A-3 — DB 를 강제로 죽이면 무엇을 잃는가 (RPO)
|
||
|
||
브랜치 `feature/keycloak-a3-database-crash` ·
|
||
증거 [`docs/evidence/a3-database-crash/`](evidence/a3-database-crash/) ·
|
||
2026-09-04 12:00–12:05 KST · Keycloak 26.7.0 / PostgreSQL 16
|
||
|
||
선행: [`A-0`](experiment-00-session-replication.md) ·
|
||
[`A-2`](experiment-a2-database-loss.md)
|
||
|
||
---
|
||
|
||
## 0. 결론부터
|
||
|
||
```
|
||
클라이언트가 200 과 토큰을 받은 로그인 : 153 건
|
||
그중 DB 에 실제로 존재 : 149 건
|
||
★ 유실 : 4 건
|
||
```
|
||
|
||
**로그인이 성공했다고 응답받았는데 세션이 존재하지 않는다.**
|
||
|
||
A-0 에서 발견한 `SET LOCAL synchronous_commit TO OFF` 의 대가를 실측했다.
|
||
버그가 아니라 **의도된 설계**이며, 그 비용이 얼마인지를 숫자로 확인한 것이다.
|
||
|
||
---
|
||
|
||
## 1. 설계 — 무엇을 재야 손실이 보이는가
|
||
|
||
### 1-1. `LAST_SESSION_REFRESH` 로는 못 잰다
|
||
|
||
처음 계획은 "세션 갱신 시각이 되감기는지" 보는 것이었다. 스키마를 보고 접었다.
|
||
|
||
```
|
||
created_on | integer
|
||
last_session_refresh | integer ← 초 단위
|
||
```
|
||
|
||
**손실 창은 수백 밀리초**인데 눈금이 **1초**다. 보일 리가 없다.
|
||
|
||
### 1-2. 행 존재 여부로 잰다 — 이진 판정
|
||
|
||
```
|
||
로그인 1회 = OFFLINE_USER_SESSION 행 1개
|
||
클라이언트가 sid 를 받았다 = 서버가 COMMIT 했다고 응답했다
|
||
크래시 후 그 sid 가 없다 = 잃은 것
|
||
```
|
||
|
||
**있거나 없거나**이므로 눈금 문제가 없다.
|
||
|
||
### 1-3. 그런데 로그인도 비동기 커밋인가 — **먼저 확인해야 한다**
|
||
|
||
A-0 에서 잡은 것은 **refresh** 트랜잭션이었다. 로그인(INSERT)도 그런지는
|
||
확인하지 않았다. 아니라면 이 측정 설계 자체가 성립하지 않는다.
|
||
|
||
```bash
|
||
kubectl -n keycloak-lab exec deploy/postgres -- \
|
||
psql -U keycloak -d keycloak -c "alter system set log_statement='all'"
|
||
kubectl -n keycloak-lab exec deploy/postgres -- \
|
||
psql -U keycloak -d keycloak -c "select pg_reload_conf()"
|
||
```
|
||
|
||
```
|
||
BEGIN
|
||
insert into OFFLINE_USER_SESSION (...) values (...)
|
||
insert into OFFLINE_CLIENT_SESSION (...) values (...)
|
||
SET LOCAL synchronous_commit TO OFF ← 로그인도 비동기 커밋이다
|
||
COMMIT
|
||
```
|
||
|
||
**확인됐고, 함의가 refresh 보다 훨씬 무겁다.**
|
||
|
||
| | 잃으면 |
|
||
|---|---|
|
||
| refresh 갱신 시각 | 세션 수명이 조금 짧아진다. 사용자는 모른다 |
|
||
| **로그인 자체** | **토큰은 손에 있는데 세션이 없다.** 다음 요청부터 실패 |
|
||
|
||
---
|
||
|
||
## 2. 실패한 주입 ① — `--grace-period=0 --force` 는 크래시가 아니다
|
||
|
||
```bash
|
||
kubectl -n keycloak-lab delete pod -l app=postgres --grace-period=0 --force
|
||
```
|
||
|
||
```
|
||
클라이언트 성공: 291 건
|
||
DB 에 존재: 291 건
|
||
★ 유실: 0 건
|
||
```
|
||
|
||
**0건.** 그런데 이건 "안 잃었다"가 아니라 **죽인 적이 없는 것**이다.
|
||
|
||
```
|
||
=== 재기동 로그 ===
|
||
database system is ready to accept connections
|
||
(그뿐. "not properly shut down" 이 없다)
|
||
```
|
||
|
||
**crash recovery 가 돌지 않았다 = 깨끗하게 내려갔다.**
|
||
|
||
| 신호 | PostgreSQL 의 반응 |
|
||
|---|---|
|
||
| **SIGTERM** | **fast shutdown** — 진행 중 트랜잭션을 롤백하고 **WAL 을 플러시**한 뒤 종료 |
|
||
| SIGINT | smart shutdown — 연결이 끊기길 기다린다 |
|
||
| **SIGKILL** | **즉사** — 플러시 없음. 다음 기동에 crash recovery |
|
||
|
||
`--force --grace-period=0` 는 API 오브젝트를 즉시 지우지만 컨테이너 런타임은
|
||
여전히 정상 종료 절차를 밟는다. **PostgreSQL 은 SIGTERM 을 받고 얌전히
|
||
플러시했다.**
|
||
|
||
> **A-1 에서 배운 것이 또 나왔다** — 주입이 실제로 걸렸는지 먼저 확인하지
|
||
> 않으면 **"아무 일도 없었다"를 결과로 착각한다.**
|
||
> 여기서는 **crash recovery 메시지가 그 확인 수단**이다.
|
||
|
||
---
|
||
|
||
## 3. 실패한 주입 ② — 컨테이너 안에서 PID 1 은 SIGKILL 을 받지 않는다
|
||
|
||
```bash
|
||
kubectl -n keycloak-lab exec deploy/postgres -- kill -9 1
|
||
```
|
||
|
||
**아무 일도 일어나지 않았다.** 파드는 재시작하지 않았고 로그 시각도 그대로였다.
|
||
|
||
### 개념 — PID 1 의 시그널 보호
|
||
|
||
리눅스 커널은 **PID 1 을 특별 취급**한다. 자기 PID 네임스페이스 안에서 온
|
||
시그널은 **핸들러가 등록된 것만** 전달된다. **SIGKILL 도 예외가 아니다.**
|
||
|
||
```
|
||
같은 네임스페이스 안에서 → PID 1 은 등록하지 않은 시그널을 무시한다
|
||
조상 네임스페이스에서 → 전달된다 (노드에서 kill -9 하면 죽는다)
|
||
```
|
||
|
||
부팅 초기에 init 을 실수로 죽여 시스템이 멈추는 것을 막기 위한 장치인데,
|
||
컨테이너에서는 **"안에서는 PID 1 을 못 죽인다"** 로 나타난다.
|
||
|
||
---
|
||
|
||
## 4. 성공한 주입 — 백엔드 프로세스를 죽인다
|
||
|
||
PostgreSQL 은 **postmaster(부모) + 연결마다 백엔드(자식)** 구조다.
|
||
자식 하나가 비정상 종료하면 **postmaster 는 공유 메모리가 오염됐다고 보고
|
||
전체를 재초기화**한다. 그게 곧 crash recovery 다.
|
||
|
||
```bash
|
||
kubectl -n keycloak-lab exec deploy/postgres -- \
|
||
sh -c 'kill -9 $(pgrep -f "postgres: keycloak keycloak" | head -1)'
|
||
```
|
||
|
||
```
|
||
server process (PID 40) was terminated by signal 9: Killed
|
||
terminating any other active server processes
|
||
all server processes terminated; reinitializing
|
||
database system was not properly shut down; automatic recovery in progress
|
||
redo starts at 0/23CAB68
|
||
redo done at 0/2529E40
|
||
checkpoint complete: wrote 113 buffers ...
|
||
database system is ready to accept connections
|
||
```
|
||
|
||
**이번엔 주입이 걸렸다.** `not properly shut down` + `redo` 가 증거다.
|
||
|
||
파드는 재시작하지 않는다 (`restarts=0`) — 컨테이너의 PID 1 인 postmaster 는
|
||
살아 있고, 자식만 갈아치운 것이다. **데이터 관점에서는 전원이 나간 것과 같다.**
|
||
|
||
---
|
||
|
||
## 5. 결과
|
||
|
||
```
|
||
=== 크래시 전후 대조 ===
|
||
클라이언트가 200 과 토큰을 받은 로그인 : 153 건
|
||
그중 DB 에 실제로 존재 : 149 건
|
||
★ 유실 : 4 건
|
||
|
||
=== 유실된 sid ===
|
||
★ CQUfg9HLH29xvhiu6pVlfWOo ← 토큰은 발급됐는데 세션이 없다
|
||
★ 5gLP4fqmpZBbjhH_d-0TPMMr
|
||
★ hkcOv1QskUFmYveMLB6Hljra
|
||
★ p5XybeQIYmAs818gO4Vl_5ea
|
||
```
|
||
|
||
**약 2.6% 유실.**
|
||
|
||
처음 이 문서는 *"초당 19건 … `wal_writer_delay` 기본값(200ms)과 맞는다"* 고
|
||
썼는데, **그 시점에 `wal_writer_delay` 를 조회한 적이 없었다.** 나중에 쟀다.
|
||
|
||
```
|
||
name | setting | unit | source
|
||
------------------------+---------+------+---------
|
||
wal_writer_delay | 200 | ms | default
|
||
wal_writer_flush_after | 128 | 8kB | default
|
||
synchronous_commit | on | | default
|
||
```
|
||
[`08-wal-settings.txt`](evidence/a3-database-crash/08-wal-settings.txt)
|
||
|
||
**값은 맞았지만 그때는 추정이었다.** 그리고 로그인 속도도 정확히는
|
||
증거의 `8초에 112건` ≈ **초당 14건**이며 19건이 아니다. 4건은 그 속도에서
|
||
**약 0.29초 분량**이고, 200ms 창과 같은 자릿수이되 정확히 일치하지는 않는다.
|
||
|
||
### 사용자에게 어떻게 보이는가
|
||
|
||
```
|
||
로그인 성공 → access token + refresh token 을 받음
|
||
│
|
||
│ (크래시)
|
||
▼
|
||
다음 요청 → access token 은 60초간 통한다
|
||
│ (서명만 보는 경로라면)
|
||
▼
|
||
60초 후 refresh → "Session not active" → 다시 로그인
|
||
```
|
||
|
||
**즉시 드러나지 않는다.** access token 수명 동안은 정상으로 보이다가
|
||
갱신 시점에 끊긴다. 장애와 증상 사이에 **최대 60초의 시차**가 있다.
|
||
|
||
---
|
||
|
||
## 6. 개념
|
||
|
||
### WAL 과 `synchronous_commit`
|
||
|
||
```
|
||
COMMIT
|
||
│
|
||
├─ WAL 버퍼(메모리)에 기록 ← 항상 한다
|
||
│
|
||
├─ synchronous_commit = on : 디스크 플러시를 기다렸다가 응답
|
||
└─ synchronous_commit = off : 기다리지 않고 즉시 응답 ← Keycloak
|
||
│
|
||
└─ 크래시 시 이 구간이 사라진다
|
||
```
|
||
|
||
| 설정 | 응답 속도 | 잃는 것 |
|
||
|---|---|---|
|
||
| `on` (PostgreSQL 기본) | 느리다 (디스크 대기) | 없다 |
|
||
| **`off`** | 빠르다 | **최대 `wal_writer_delay` × 3 분량** |
|
||
|
||
**전역 설정은 `on` 이었다.**
|
||
|
||
```
|
||
전역 synchronous_commit: on
|
||
```
|
||
|
||
**Keycloak 이 자기 트랜잭션에만 `SET LOCAL` 로 끈다.** DBA 가 서버 설정만
|
||
보고 "우리는 동기 커밋"이라 믿으면 틀린다. **애플리케이션이 트랜잭션 단위로
|
||
뒤집을 수 있다.**
|
||
|
||
### crash recovery
|
||
|
||
```
|
||
기동 시 pg_control 을 읽는다
|
||
└─ "깨끗하게 종료됨" 표시가 없다
|
||
└─ "database system was not properly shut down"
|
||
└─ 마지막 체크포인트부터 WAL 을 재생(redo)
|
||
└─ 디스크에 안 내려간 커밋은 복구할 수 없다 ← 손실
|
||
```
|
||
|
||
`redo starts at 0/23CAB68` → `redo done at 0/2529E40` 사이가 재생된 구간이다.
|
||
**WAL 에 없는 것은 재생할 수도 없다.**
|
||
|
||
### 이 손실이 "허용된" 이유
|
||
|
||
Keycloak 의 판단은 이렇게 읽힌다.
|
||
|
||
| | |
|
||
|---|---|
|
||
| 세션 쓰기는 **매우 잦다** | 로그인마다, refresh 마다 |
|
||
| 잃어도 **회복 가능하다** | 사용자가 다시 로그인하면 된다 |
|
||
| 동기 커밋의 비용은 **모든 요청에 붙는다** | 크래시는 드물다 |
|
||
|
||
**드문 사고의 비용을 상시 지연으로 지불하지 않겠다는 선택**이다.
|
||
합리적이지만, **선택했다는 사실을 알고 있어야 한다.**
|
||
|
||
---
|
||
|
||
## 7. 운영에 주는 것
|
||
|
||
| 알게 된 것 | 함의 |
|
||
|---|---|
|
||
| 로그인도 비동기 커밋 | **RPO 가 0 이 아니다.** 크래시 시 마지막 수백 ms 로그인은 사라진다 |
|
||
| 전역 `on` 인데 세션만 `off` | **서버 설정으로 판단하면 안 된다.** 애플리케이션이 뒤집는다 |
|
||
| 손실이 즉시 안 보인다 | access token 수명만큼 시차. **모니터링은 갱신 실패율을 봐야 한다** |
|
||
| `--grace-period=0` 은 크래시가 아니다 | **장애 훈련이 훈련이 안 될 수 있다** |
|
||
| 컨테이너 안에서 PID 1 을 못 죽인다 | 크래시 재현은 **자식 프로세스**나 **노드에서** |
|
||
|
||
### 바꿀 수 있는가
|
||
|
||
```sql
|
||
-- 세션 트랜잭션까지 동기 커밋으로 강제하려면 (지연 대가를 치른다)
|
||
ALTER DATABASE keycloak SET synchronous_commit = on; -- SET LOCAL 이 이깁니다
|
||
```
|
||
|
||
**`SET LOCAL` 이 우선하므로 이것으로는 못 막는다.** Keycloak 설정이나
|
||
소스 수준의 문제이며, **RPO 0 이 필요하면 복제(streaming replication)로
|
||
푸는 것이 맞다** — 동기 스탠바이가 있으면 `synchronous_commit` 의 의미가
|
||
달라진다.
|
||
|
||
---
|
||
|
||
---
|
||
|
||
## 증거 파일
|
||
|
||
**증거 수집 시각: 2026-09-04 11:58 – 16:32 KST** (파일 mtime 기준. 문서 상단의 시각 표기는 작성 시점이라 다를 수 있다.)
|
||
|
||
| 파일 | 종류 |
|
||
|---|---|
|
||
| [`01-crash-injection.txt`](evidence/a3-database-crash/01-crash-injection.txt) | 터미널 원문 |
|
||
| [`02-design-check.txt`](evidence/a3-database-crash/02-design-check.txt) | 터미널 원문 |
|
||
| [`03-loss-measurement.txt`](evidence/a3-database-crash/03-loss-measurement.txt) | 터미널 원문 |
|
||
| [`04-comparison.txt`](evidence/a3-database-crash/04-comparison.txt) | 터미널 원문 |
|
||
| [`05-true-crash.txt`](evidence/a3-database-crash/05-true-crash.txt) | 터미널 원문 |
|
||
| [`06-backend-kill-crash.txt`](evidence/a3-database-crash/06-backend-kill-crash.txt) | 터미널 원문 |
|
||
| [`07-loss-result.txt`](evidence/a3-database-crash/07-loss-result.txt) | 터미널 원문 |
|
||
| [`08-wal-settings.txt`](evidence/a3-database-crash/08-wal-settings.txt) | 터미널 원문 |
|
||
|
||
파일별 상세는 [`evidence/a3-database-crash/README.md`](evidence/a3-database-crash/README.md).
|
||
|
||
## 8. 재현 절차 (명령어)
|
||
|
||
```bash
|
||
# 0. 설계 확인 — 로그인도 비동기 커밋인지 먼저 본다
|
||
kubectl -n keycloak-lab exec deploy/postgres -- psql -U keycloak -d keycloak \
|
||
-c "alter system set log_statement='all'" -c "select pg_reload_conf()"
|
||
# → 로그인 1회 후 로그에서 "SET LOCAL synchronous_commit TO OFF" 확인
|
||
|
||
# 1. 세션 테이블 비우기
|
||
kubectl -n keycloak-lab exec deploy/postgres -- psql -U keycloak -d keycloak \
|
||
-c "delete from offline_user_session"
|
||
|
||
# 2. 로그인 루프 — 호스트에서 백그라운드로 exec 한다.
|
||
# 파드 안에서 ( ... ) & 로 띄우면 exec 세션이 끝날 때 같이 죽는다(실측).
|
||
K0=$(kubectl -n keycloak-lab get pod keycloak-0 -o jsonpath='{.status.podIP}')
|
||
kubectl -n keycloak-lab exec a2-probe -- sh -c "
|
||
i=0
|
||
while [ \$i -lt 200 ]; do
|
||
R=\$(curl -s --max-time 5 -X POST http://$K0:8080/realms/master/protocol/openid-connect/token \
|
||
-d grant_type=password -d client_id=admin-cli -d username=admin -d password=lab-admin-change-me)
|
||
S=\$(echo \"\$R\" | sed -n 's/.*\"access_token\":\"\\([^\"]*\\)\".*/\\1/p' \
|
||
| cut -d. -f2 | sed 's/\$/==/' | base64 -d 2>/dev/null \
|
||
| sed -n 's/.*\"sid\":\"\\([^\"]*\\)\".*/\\1/p')
|
||
[ -n \"\$S\" ] && echo \"\$S\" >> /tmp/sids
|
||
i=\$((i+1))
|
||
done" >/dev/null 2>&1 &
|
||
LOOP=$!
|
||
|
||
# 3. 진짜 크래시 — 백엔드 프로세스에 SIGKILL
|
||
kubectl -n keycloak-lab exec deploy/postgres -- \
|
||
sh -c 'kill -9 $(pgrep -f "postgres: keycloak keycloak" | head -1)'
|
||
|
||
# 4. 주입이 걸렸는지 확인 — 이게 없으면 결과를 해석하지 않는다
|
||
kubectl -n keycloak-lab logs deploy/postgres | grep -E "not properly shut down|redo"
|
||
|
||
# 5. 대조 — 클라이언트가 200 을 받은 sid 를 그대로 IN 절로 만든다
|
||
kill $LOOP 2>/dev/null
|
||
kubectl -n keycloak-lab exec a2-probe -- cat /tmp/sids > /tmp/sids.txt
|
||
TOTAL=$(wc -l < /tmp/sids.txt)
|
||
IN=$(sed "s/^/'/; s/$/'/" /tmp/sids.txt | paste -sd,)
|
||
FOUND=$(kubectl -n keycloak-lab exec deploy/postgres -- psql -U keycloak -d keycloak -tAc \
|
||
"select count(*) from offline_user_session where offline_flag='0' and user_session_id in ($IN)")
|
||
echo "클라이언트 성공 $TOTAL / DB 존재 $FOUND / 유실 $((TOTAL-FOUND))"
|
||
```
|
||
|
||
---
|
||
|
||
## 9. 다음 실험에 남기는 것
|
||
|
||
| 실험 | 이 실험이 준 것 |
|
||
|---|---|
|
||
| **D-1** 백업·복구 | RPO 는 **백업 주기 + 이 손실**이다. 둘을 더해야 진짜 RPO |
|
||
| **B-6** Redis 영속화 | `appendfsync everysec` 은 **같은 모양의 트레이드오프** |
|
||
| **A-4** 노드 상실 | 노드가 죽으면 이것도 함께 일어난다 (postgres 가 kc-lab-2) |
|
||
| 전체 | **주입 성공 신호를 미리 정한다.** 여기서는 crash recovery 로그 |
|