Files
keycloak-pattern/docs/experiment-00-session-replication.md
T
DongHyeonkaandClaude Opus 5 74c9b3cea7 docs: replace prose placeholders in reproduction steps with executable commands
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>
2026-09-04 17:01:54 +09:00

654 lines
28 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# 실험 0 — 한 노드에서 만든 세션이 다른 노드에서 쓰이는가
로드맵 A-0. 이후 모든 장애 실험의 기준선이다.
> **맥락이 안 잡히면 먼저 읽을 것** —
> [`docs/session-lab-prerequisites.md`](session-lab-prerequisites.md).
> 왜 세션이 문제가 되는지, Keycloak이 세션을 어디에 두는지, 그래서 이 실험이
> 무엇을 가르려는 것인지를 바닥부터 세워둔 문서다.
- 실행 스크립트 — [`deploy/lab/scripts/experiment-session-replication.sh`](../deploy/lab/scripts/experiment-session-replication.sh),
[`experiment-cache-replication-delta.sh`](../deploy/lab/scripts/experiment-cache-replication-delta.sh),
[`experiment-cache-ownership.sh`](../deploy/lab/scripts/experiment-cache-ownership.sh),
[`experiment-session-read-path.sh`](../deploy/lab/scripts/experiment-session-read-path.sh)
- 증거 — [`docs/evidence/session-replication/`](evidence/session-replication/)
- 수집 시각 — 2026-09-04 09:54 KST, Keycloak 26 / Infinispan 16.0.12 / PostgreSQL 16
---
## 0. 결론부터
| 물음 | 답 |
|---|---|
| 한 노드에서 만든 세션을 다른 노드가 쓸 수 있는가 | **그렇다** |
| 로그아웃이 반대 방향으로 전파되는가 | **그렇다** |
| **그 공유는 Infinispan 복제 덕분인가** | **아니다** |
| 그럼 무엇이 공유하는가 | **PostgreSQL** — 반대편 노드가 날린 SQL을 직접 잡았다 |
**클러스터가 형성됐다는 것과 세션이 복제된다는 것은 다른 얘기였다.**
로그에는 `(2) [keycloak-0, keycloak-1]`이 찍히고 `JGROUPS_PING`에도 둘 다
등록되어 있지만, **세션 엔트리는 노드 사이를 건너가지 않는다.**
각 노드는 **자기가 처리한 로그인만** 캐시한다. 두 노드가 같은 답을 내놓는
이유는 복제가 아니라 **같은 데이터베이스를 보기 때문**이다.
---
## 1. 왜 이 실험이 첫 번째인가
앞선 작업에서 Keycloak 2노드 클러스터를 세우고 `ISPN000094`로 멤버 2개를
확인했다. 거기서 멈추면 **"클러스터가 떴다"까지만 아는 것**이고, 그 위에서
장애를 주입해봐야 무엇이 무엇 때문에 깨졌는지 해석할 수 없다.
기준선이 없으면 이런 잘못된 추론을 하게 된다.
> 7800을 막았더니 세션이 깨졌다 → 역시 세션은 7800으로 복제되는구나
실제로는 7800으로 세션이 오가지 않는다는 것을 **먼저** 알아야, 7800을 막았을
때 깨지는 것이 무엇인지 정확히 말할 수 있다.
---
## 2. 실험 설계에서 배운 것 세 가지
측정값보다 **어떻게 측정할지**에서 더 많이 틀렸다. 세 번 고쳤다.
### 2-1. 대조군 없는 측정은 해석할 수 없다
첫 판본은 이렇게 보고했다.
```
=== [4] keycloak-0 이 발급한 토큰을 keycloak-1 이 받는가 ===
http_code=403
```
**403을 "복제 실패"로 읽을 뻔했다.** 발급 노드에도 같은 요청을 보내보니
```
--- userinfo, scope 없음 ---
k0(발급노드) 403
k1(반대편) 403
--- 403 본문 ---
WWW-Authenticate: Bearer realm="master", error="insufficient_scope",
error_description="Missing openid scope"
```
**양쪽 다 403이었다.** 원인은 복제가 아니라 요청에 `openid` scope가 없다는
것이었다. 오히려 **두 노드가 똑같이 답했다는 사실 자체가 일치의 증거**였다.
> **원칙** — 반대편 노드의 응답은 발급 노드의 응답과 나란히 놓기 전까지
> 아무 의미가 없다. 시험군만 재는 측정은 측정이 아니다.
### 2-2. 개수가 아니라 식별자로 추적한다
`client-session-stats``active=2`를 돌려줬다. 그런데 스크립트 자체가
로그인을 두 번 하고(시험용 + 관리 API 호출용) 있었다. **개수는 실험 도구가
만든 잡음에 그대로 오염된다.**
바꾼 방식: 토큰의 `sid`를 뽑아, 각 노드의 세션 목록에 **그 sid가 있는지**를
본다. 개수가 몇이든 상관없다.
```
keycloak-0 (발급 노드) 세션 2개 중 대상 sid → 보임 ✔
keycloak-1 (반대편) 세션 2개 중 대상 sid → 보임 ✔
```
### 2-3. 세션 저장소를 실제로 건드리는 탐침을 골라야 한다
| 탐침 | 하는 일 | 적합한가 |
|---|---|---|
| `userinfo` | 서명 검증 + scope 확인 | **아니다.** 세션을 몰라도 통과할 수 있다 |
| **`refresh_token` 그랜트** | 세션을 찾고, 살아있는지 보고, 갱신 시각을 쓴다 | **그렇다** |
refresh는 **읽고 쓴다.** 그래서 "저 노드가 이 세션을 정말로 아는가"에 답한다.
여기에 더해 refresh token은 **회전(rotation)** 된다 — 한 번 쓰면 옛 것이
무효가 된다. 따라서 **반대편 노드에 먼저 써야** 한다. 발급 노드에 먼저 쓰면
시험군에 쓸 토큰이 사라진다. 대조군과 시험군의 순서가 강제된다.
---
## 3. 실험 0 — 교차 노드 세션 사용
### 실행
```bash
kubectl -n keycloak-lab exec deploy/postgres -- \
psql -U keycloak -d keycloak -c "delete from offline_user_session"
kubectl -n keycloak-lab rollout restart statefulset/keycloak # 캐시를 비운다
./deploy/lab/scripts/experiment-session-replication.sh
```
nginx나 Traefik을 거치지 않고 **파드 IP로 직접** 말을 건다. 로드밸런서를
거치면 어느 노드가 처리했는지가 감춰지는데, 그게 바로 이 실험의 질문이다.
### 결과 — [`01-cross-node-session.txt`](evidence/session-replication/01-cross-node-session.txt)
```
### 사전 확인: 클러스터가 2 멤버로 형성되었는가
ISPN000094: Received new cluster view for channel ISPN:
[keycloak-1-48749(v=16.0.12)|5] (2) [keycloak-1-48749, keycloak-0-30843]
name | ip | coord
------------------+-----------------+-------
keycloak-1-48749 | 10.42.0.35:7800 | t
keycloak-0-30843 | 10.42.1.43:7800 | f
=== 대상 ===
keycloak-0 10.42.1.43 kc-lab-2
keycloak-1 10.42.0.35 kc-lab-1
=== [1] keycloak-0 에서 로그인 ===
sid jiv3rVZi1VeaO07oVJkL_MYW
iss https://auth.hyeonworks.com/realms/master
access 수명 60초
refresh 수명 1800초 typ=Refresh
=== [3] 같은 sid 가 두 노드 모두에서 보이는가 ===
keycloak-0 (발급 노드) 세션 2개 중 대상 sid → 보임 ✔
keycloak-1 (반대편) 세션 2개 중 대상 sid → 보임 ✔
=== [5] keycloak-0 이 발급한 refresh token 을 keycloak-1 에 사용 ===
HTTP 200 ← 기대대로
새 토큰의 sid → 동일 ✔
=== [6] keycloak-1 을 통해 로그아웃 ===
http_code=204
=== [7] 로그아웃 후 keycloak-0 에서 갱신 시도 (무효화 전파) ===
HTTP 400 ← 기대대로
error invalid_grant
error_description Session not active
=== [8] PostgreSQL 에서 그 sid 를 직접 확인 ===
행 없음 — 로그아웃으로 삭제되었다
```
**네 가지가 모두 기대대로다.**
| | 확인된 것 |
|---|---|
| 조회 | 같은 sid가 양쪽에서 보인다 |
| **쓰기** | keycloak-0의 refresh token을 keycloak-1이 받아 갱신했고, **sid가 유지된다** |
| **역방향 무효화** | keycloak-1의 로그아웃이 keycloak-0의 갱신을 막았다 |
| 영속 | 로그아웃과 함께 DB 행이 사라졌다 |
**`sid`는 JWT 안에만 있는 값이 아니다.** PostgreSQL의
`OFFLINE_USER_SESSION.user_session_id` 컬럼에 **문자 그대로** 들어 있다.
---
## 4. 실험 0b — 복제인가, 같은 DB를 본 것인가
실험 0은 "두 노드가 같은 답을 한다"까지만 증명한다. **그것으로는 Infinispan이
복제했다고 말할 수 없다.** `persistent-user-sessions`(Keycloak 26 기본값)에서는
세션이 PostgreSQL에 기록되므로, **캐시를 아예 꺼도 두 노드는 같은 답을 한다.**
가르는 방법: 로그인 한 번을 사이에 두고 **양쪽 노드의 캐시 계수기**를 잰다.
### 결과 — [`02-cache-delta.txt`](evidence/session-replication/02-cache-delta.txt)
```
=== 로그인은 keycloak-0 에만 보냈다 ===
로그인 응답: http_code=200
=== keycloak-0 (로그인을 받은 노드) ===
계수기 캐시 전 후 증가
approximate_entries_unique sessions 1 2 +1 ←
stores sessions 2 3 +1 ←
misses sessions 3 4 +1 ←
rpc.replication_count sessions 1 1 +0
=== keycloak-1 (아무 요청도 받지 않은 노드) ===
approximate_entries_unique sessions 0 0 +0
stores sessions 1 1 +0
hits sessions 4 4 +0
rpc.replication_count sessions 7 7 +0
```
**keycloak-1의 계수기가 하나도 움직이지 않았다.** 엔트리도 0, 저장도 0.
그리고 keycloak-1의 `sessions` 캐시 엔트리는 **처음부터 끝까지 0**이다.
keycloak-0이 세션을 9개 들고 있는 동안에도 0이었다.
---
## 5. 실험 0c — 엔트리는 어느 노드에 있는가
0b의 결과에는 두 가지 설명이 가능하다.
| | |
|---|---|
| (a) **분산 캐시 + owners=1** | 일관 해싱으로 흩어지는데 이번 건이 우연히 keycloak-0에 떨어졌다 |
| (b) **로컬 캐시** | 각 노드는 자기가 처리한 것만 캐시한다 |
**반대편 노드에 로그인을 몰아주면 갈린다.** (a)라면 어느 쪽에 요청하든 엔트리는
양쪽에 흩어진다. (b)라면 **요청을 받은 노드에서만** 는다.
### 결과 — [`03-cache-ownership.txt`](evidence/session-replication/03-cache-ownership.txt)
```
단계 k0 entries k1 entries
시작 2.0 0.0
keycloak-1 에 로그인 5회 2.0 5.0 ← k0 그대로, k1 만 +5
keycloak-0 에 로그인 5회 7.0 5.0 ← k0 만 +5, k1 그대로
=== 대조: PostgreSQL 에는 몇 건인가 ===
online 세션 12 ← 7 + 5 = 12, 정확히 일치
```
**(b)다.** 그리고 **7 + 5 = 12**로 DB 총계와 정확히 맞는다 — 모든 세션이 DB에
있고, 각각은 **자기를 만든 노드 한 곳에만** 캐시되어 있다.
### 그래프로 본 같은 사실
![세션 캐시 엔트리 수](evidence/session-replication/session-cache-entries-per-pod.png)
`vendor_statistics_approximate_entries_unique{cache="sessions"}` — Grafana Explore.
**파란 선(keycloak-1)이 0에 붙어 있는 동안 초록 선(keycloak-0)만 14까지
올라간다.** 파란 선은 09:50, 즉 **keycloak-1에 직접 로그인을 보낸 순간에만**
5로 뛴다. 중간의 절벽은 캐시를 비우려고 파드를 재시작한 지점이다.
> 캐시 설정은 파일에서 읽을 수 없다. 파드의 `/opt/keycloak/conf/cache-ispn.xml`은
> `<cache-container name="keycloak"><transport/></cache-container>` 뿐이고,
> Keycloak 26은 캐시를 **코드에서** 만든다. 그래서 위 결론은 설정을 읽어서가
> 아니라 **동작을 측정해서** 얻었다.
---
## 6. 실험 0d — 반대편 노드가 정말 DB에서 읽는가
0b·0c까지는 **추론**이었다. "keycloak-1의 메모리에 없는데 쓸 수 있으니 DB에서
읽었을 것이다" — 그럴듯하지만 **SQL을 본 적은 없다.**
PostgreSQL의 문장 로깅을 몇 초만 켜고, keycloak-0에서 만든 세션에 대해
**keycloak-1에 refresh를 딱 한 번** 보낸 뒤 로그를 뒤졌다.
```bash
alter system set log_statement='all';
alter system set log_line_prefix='%m [%p] %h '; -- %h 로 파드 IP 를 남긴다
select pg_reload_conf();
```
### 잡힌 트랜잭션 — [`04-read-path-sql.txt`](evidence/session-replication/04-read-path-sql.txt)
```
01:12:34.934 pid=81376 | BEGIN
01:12:34.934 pid=81376 | select ... from OFFLINE_USER_SESSION where (OFFLINE_FLAG,USER_SESSION_ID) in (($1,$2))
01:12:34.936 pid=81376 | select VERSION from OFFLINE_USER_SESSION ... for no key update skip locked
01:12:34.937 pid=81376 | select ... from OFFLINE_CLIENT_SESSION where (...) in ((...))
01:12:34.938 pid=81376 | select VERSION from OFFLINE_CLIENT_SESSION ... for no key update skip locked
01:12:34.944 pid=81376 | update OFFLINE_CLIENT_SESSION set TIMESTAMP=$1,VERSION=$2 where ... and VERSION=$8
01:12:34.946 pid=81376 | update OFFLINE_USER_SESSION set LAST_SESSION_REFRESH=$1,VERSION=$2 where ... and VERSION=$5
01:12:34.946 pid=81376 | SET LOCAL synchronous_commit TO OFF
01:12:34.947 pid=81376 | COMMIT
```
이 연결의 클라이언트 IP는 `10.42.0.35` — **keycloak-1의 파드 IP**다.
sid 하나에 대해 keycloak-0이 6건(로그인), keycloak-1이 6건(갱신)을 날렸다.
```
=== 요약: 파드별 질의 건수 ===
6 [keycloak-1]
6 [keycloak-0]
```
**추론이 관측이 되었다.** keycloak-1은 세션을 DB에서 읽고, DB에 쓴다.
### 여기서 딸려 나온 것 세 가지
이 13밀리초짜리 트랜잭션 하나에 **원래 질문들의 답이 절반쯤 들어 있다.**
#### (1) 낙관적 락 — `VERSION` 컬럼
```sql
update OFFLINE_USER_SESSION
set LAST_SESSION_REFRESH=$1, VERSION=$2
where OFFLINE_FLAG=$3 and USER_SESSION_ID=$4 and VERSION=$5
─────────────
읽을 때의 버전과 같을 때만 쓴다
```
읽은 뒤 다른 노드가 먼저 고쳤다면 `VERSION`이 달라져 **`UPDATE`가 0행을
갱신하고 실패한다.** 잠금을 오래 잡지 않고 충돌을 사후에 검출하는 방식이다.
**리프레시 토큰 동시 갱신 경쟁(로드맵 B-5)이 여기서 갈린다.** 두 요청이
같은 세션을 동시에 갱신하면 하나는 이 검사에서 진다.
#### (2) `FOR NO KEY UPDATE ... SKIP LOCKED`
```sql
select VERSION from OFFLINE_USER_SESSION
where USER_SESSION_ID=$1 and OFFLINE_FLAG=$2
for no key update of puse1_0 skip locked
────────────── ────────────
키가 아닌 컬럼만 잠근다 잠긴 행은 건너뛴다 (기다리지 않는다)
```
| 절 | 뜻 |
|---|---|
| `FOR NO KEY UPDATE` | 행을 잠그되 **외래키 참조는 막지 않는다.** `FOR UPDATE`보다 약해 경합이 준다 |
| **`SKIP LOCKED`** | 이미 잠긴 행을 **기다리지 않고 건너뛴다** |
`SKIP LOCKED`가 핵심이다. 같은 세션에 동시 요청이 몰려도 **줄을 서지 않는다.**
대기 대신 낙관적 락 실패로 처리한다 — 처리량을 위해 **지연 대신 재시도**를
고른 설계다.
#### (3) `SET LOCAL synchronous_commit TO OFF` — 내구성을 일부 포기한다
**같은 트랜잭션 안에서**, `COMMIT` 직전에 나온다. pid로 경계를 확인했다.
| | |
|---|---|
| 기본값 `on` | `COMMIT`**WAL이 디스크에 내려간 뒤** 돌아온다 |
| **`off`** | **WAL 플러시를 기다리지 않고** 즉시 돌아온다 |
**결과: PostgreSQL이 갑자기 죽으면 직전 수백 밀리초의 세션 갱신이 사라질 수
있다.** 커밋했다고 응답해놓고 없어진다.
Keycloak이 이걸 의도적으로 켠 이유는 명확하다 — `LAST_SESSION_REFRESH` 갱신은
**초당 수백 번 일어나고, 몇백 밀리초쯤 잃어도 사용자가 다시 갱신하면 그만**이다.
로그인·로그아웃 같은 것과 달리 잃어도 되는 쓰기다.
> **DB 복구 실험(A-2)에서 그대로 관측될 지점이다.** PostgreSQL을 정상 종료가
> 아니라 강제 종료시키면, 마지막 몇백 밀리초의 세션 갱신이 실제로 없어져야
> 한다. 이건 버그가 아니라 **설계된 트레이드오프**다.
```bash
kubectl -n keycloak-lab exec deploy/postgres -- \
psql -U keycloak -d keycloak -c "show synchronous_commit" # 전역 기본값은 on
```
전역 설정은 `on`이고, **Keycloak이 세션 트랜잭션에만 `SET LOCAL`로 끈다.**
`SET LOCAL`은 그 트랜잭션이 끝나면 되돌아간다.
### 덤: 캐시는 읽어도 채워지지 않는다
```
K1_ENTRIES_BEFORE=5.0
REFRESH_ON_K1=200
K1_ENTRIES_AFTER=5.0 ← 갱신을 처리하고도 그대로
```
**keycloak-1은 남의 세션을 DB에서 읽어 처리하고도 캐시에 담지 않았다.**
0c에서 세운 모델 "각 노드는 자기가 처리한 것만 캐시한다"를 더 좁혀야 한다.
> 캐시에 담기는 것은 **그 노드가 로그인시켜 만든 세션**뿐이다.
> 남의 세션은 매번 DB에서 읽는다.
로드밸런서가 세션을 만든 노드가 아닌 쪽으로 요청을 보내면 **매번 DB를 친다.**
세션 어피니티(sticky session)가 정확성이 아니라 **성능** 문제인 이유가 이것이다.
### 덤 2: jdbc-ping 하트비트가 그대로 보인다
```
01:12:37.551 pid=81369 | BEGIN
01:12:37.551 pid=81369 | DELETE from JGROUPS_PING WHERE address=$1
01:12:37.552 pid=81369 | INSERT INTO JGROUPS_PING (address, name, cluster_name, ip, coord, last_update, coordinated_by) values (...)
01:12:37.553 pid=81369 | COMMIT
```
**디스커버리는 별도 연결(pid=81369)에서 주기적으로 자기 행을 지우고 다시
넣는다.** 세션 트래픽과 완전히 분리된 경로다 — 11층에서 말한 "디스커버리와
트랜스포트는 다른 경로"가 로그에서 눈으로 확인된다.
---
## 7. 그래서 무엇이 세션을 공유하는가
```
로그인 (keycloak-0)
├──▶ PostgreSQL OFFLINE_USER_SESSION ← 진실의 원천. 양쪽이 본다
└──▶ keycloak-0 로컬 캐시 ← 자기 것만. 건너가지 않는다
keycloak-1 이 그 세션을 물으면
└──▶ 자기 캐시에 없음 → PostgreSQL 에서 읽는다
```
| 계층 | 역할 | 노드 간 공유 |
|---|---|---|
| **PostgreSQL** | 진실의 원천 | **여기서 일어난다** |
| **Infinispan `sessions`** | 자기 노드가 처리한 세션의 룩어사이드 캐시 | **일어나지 않는다** |
| **Infinispan 클러스터** | 무효화 메시지, `work` 캐시 등 | 형성은 되어 있다 |
이건 **Keycloak 26의 의도된 설계**다. `persistent-user-sessions`가 기본이 되면서
DB가 진실의 원천이 됐고, 세션 캐시는 **복제할 이유가 없어졌다.** 복제를 하면
네트워크와 메모리를 쓰면서 DB와 캐시 두 벌을 정합하게 유지해야 한다.
---
## 8. 개념
### 8-1. `persistent-user-sessions`
Keycloak 25에서 도입되고 **26에서 기본값**이 된 기능. 사용자 세션을
Infinispan에만 두지 않고 **데이터베이스에 기록**한다.
| | 켜져 있을 때 (기본) | 꺼져 있을 때 (volatile) |
|---|---|---|
| 진실의 원천 | **PostgreSQL** | Infinispan |
| 전체 재시작 후 | **세션이 남는다** | 전부 사라진다 |
| 노드 간 공유 | DB가 한다 | **복제가 해야 한다** |
| 로그인당 비용 | DB 쓰기 | 네트워크 복제 |
**이 실험의 결론은 전부 "켜져 있을 때"의 이야기다.** 끄면 다른 그림이 나오고,
그 비교가 로드맵 A-2다.
```bash
kubectl -n keycloak-lab exec keycloak-0 -- \
/opt/keycloak/bin/kc.sh show-config 2>/dev/null | grep -i feature
```
### 8-2. 온라인 세션이 `OFFLINE_` 테이블에 들어간다
**`USER_SESSION` 테이블은 존재하지 않는다.** 처음에 이걸 찾다가 없어서 당황했다.
```
public | auth_session | table | keycloak
public | jgroups_ping | table | keycloak
public | offline_client_session | table | keycloak
public | offline_user_session | table | keycloak
public | revoked_token | table | keycloak
public | root_auth_session | table | keycloak
```
`persistent-user-sessions`는 **기존 오프라인 세션 테이블을 재사용**하고
`offline_flag` 컬럼으로 구분한다.
| `offline_flag` | 의미 |
|---|---|
| **`'0'`** | **온라인 세션** (일반 로그인) |
| `'1'` | 오프라인 세션 (`offline_access`) |
기본키가 `(user_session_id, offline_flag)` 복합키인 이유다 — 같은 세션 id가
온라인/오프라인 두 행으로 존재할 수 있다.
```sql
select offline_flag, count(*) from offline_user_session group by offline_flag;
select user_session_id, offline_flag, created_on, last_session_refresh
from offline_user_session where user_session_id = '$SID';
```
**이름이 내용을 배신하는 스키마다.** 운영에서 "온라인 세션이 DB 어디 있냐"를
찾을 때 이걸 모르면 한참 헤맨다.
### 8-3. `sid` — 토큰과 DB를 잇는 열쇠
```
JWT access_token 의 sid jiv3rVZi1VeaO07oVJkL_MYW
↕ 같은 값
DB user_session_id jiv3rVZi1VeaO07oVJkL_MYW
↕ 같은 값
Admin API 세션 목록의 id jiv3rVZi1VeaO07oVJkL_MYW
```
세 곳에서 같은 문자열이다. **장애를 추적할 때 이 값 하나로 토큰·DB·관리 API를
꿰뚫을 수 있다.** 백채널 로그아웃의 `sid` 클레임도 이것이다.
### 8-4. `openid` scope가 없으면 OIDC 토큰이 아니다
`admin-cli``scope` 없이 direct grant를 하면 나오는 클레임은 이렇다.
```
--- access_token ---
클레임: azp, exp, iat, iss, jti, scope, sid, typ
typ = Bearer | sub = None | sid = OxikTqdHCJ7ESm2GPKI1oa6c
```
**`sub`이 없다.** OIDC가 아니라 순수 OAuth2 액세스 토큰이기 때문이다.
`sub`은 OIDC가 요구하는 클레임이고, `openid` scope가 있어야 붙는다.
같은 이유로 `userinfo`가 403 `insufficient_scope`를 준다 — userinfo는 OIDC
엔드포인트다. **두 현상은 하나의 원인**이다.
### 8-5. 룩어사이드(lookaside) 캐시
```
읽기: 캐시 확인 → 없으면 DB → 캐시에 채움
쓰기: DB 에 쓰고 → 캐시에도 씀
```
캐시가 **DB 앞에 서 있되 DB를 대체하지 않는** 구조. 캐시를 통째로 날려도
정확성은 유지되고 느려지기만 한다. Keycloak 26의 세션 캐시가 이 모양이다.
이 성질이 **노드 상실 실험(A-3)의 결과를 미리 결정한다** — 노드가 죽으면
그 노드의 캐시는 사라지지만 세션은 DB에 있으므로 살아남아야 한다.
---
## 9. 다음 실험에 대한 예측
기준선이 생겼으므로 **틀릴 수 있는 예측**을 세울 수 있다. 예측이 빗나가면
그것이야말로 배울 거리다.
| 실험 | 예측 | 근거 |
|---|---|---|
| **A-1** TCP 7800 차단 | **세션 공유는 안 깨진다.** 대신 무효화 전파와 `work` 캐시가 깨진다 | 세션은 7800으로 오가지 않는다 |
| **A-2** DB 손실 | **즉시 전면 장애.** 캐시에 있는 세션도 못 쓴다 | DB가 진실의 원천 |
| **A-2'** DB **강제** 종료 | 직전 수백 ms 의 세션 갱신이 **사라진다** | `synchronous_commit OFF` |
| **B-5** 동시 갱신 경쟁 | 한쪽이 `VERSION` 검사에서 지고 재시도한다 | 낙관적 락 |
| **A-3** 노드 상실 (kc-lab-2) | **세션은 살아남는다.** 죽은 노드의 캐시만 사라진다 | 룩어사이드 |
| **A-4** volatile 비교 | 7800 차단이 **A-1과 정반대로** 치명적이 된다 | 그때는 캐시가 진실의 원천 |
특히 A-1은 **직관과 어긋나는 예측**이다. "클러스터 포트를 막으면 세션이
깨진다"가 상식이지만, 이 기준선이 맞다면 안 깨져야 한다.
---
## 10. 겪은 함정
### 10-1. kubectl 스트림에서 출력이 통째로 사라졌다
`kubectl run --rm -i ... | grep` 로 받으면 **중간 조각이 유실됐다.**
keycloak-1의 스냅샷과 그 다음 마커가 함께 없어져, 전값이 0으로 잡히면서
**가짜 델타가 만들어졌다.**
```
###BEFORE_K1 ← 여기 있어야 할 지표 20줄과
http_code=200 다음 마커 ###LOGIN 이 통째로 사라졌다
###AFTER_K0
```
이때 리포트는 keycloak-1이 `+9`, `+7` 증가한 것처럼 보였다. **없는 복제가
있는 것처럼 보이는, 가장 나쁜 종류의 오류다.**
| 고친 방법 | |
|---|---|
| 파드 안에서 파일로 모으고 마지막에 `cat` 한 번 | 스트리밍 중 유실을 없앤다 |
| 스냅샷이 비면 **경고를 출력**한다 | 조용히 0으로 계산되는 것을 막는다 |
```bash
for n in ('BEFORE_K0','BEFORE_K1','AFTER_K0','AFTER_K1'):
if not blocks.get(n):
print(f' !! {n} 스냅샷이 비었다 — 델타를 신뢰할 수 없다')
```
**계측 코드는 자기가 실패했는지 스스로 말해야 한다.**
### 10-2. DB에서 직접 지우면 캐시는 남는다
정리하려고 `delete from offline_user_session`을 실행했더니, **캐시 엔트리는
그대로 남아** 캐시 합계(19)와 DB 총계(15)가 어긋났다.
> 운영에서 세션 테이블을 직접 손대면 캐시와 DB가 갈라진다. 세션을 지울 때는
> 관리 API(`logout-all`)를 쓰거나, DB를 건드렸다면 **파드를 재시작**해야 한다.
이 실험의 최종 수치는 **파드 재시작 후** 다시 잰 것이다.
### 10-3. Keycloak 이미지에는 `curl`이 없다
`kubectl exec keycloak-0 -- curl` 은 실패한다. 임시 `curlimages/curl` 파드를
띄워 파드 네트워크 안에서 호출했다. 파드 IP는 클러스터 밖에서 닿지 않으므로
이 방법이 사실상 유일하다.
### 10-4. 중첩 셸의 변수 치환
`ssh host '... $VAR ...'` 안에 다시 `sh -c "..."` 를 넣으면 인용이 세 겹이 되어
치환이 조용히 깨진다. 첫 시도에서 파드 IP가 빈 문자열이 되어 아무 출력도
나오지 않았다.
**스크립트 파일로 만들어 `scp` 로 옮기는 쪽이 옳다.** 재현도 되고 저장소에
남는다. `deploy/lab/scripts/` 아래 세 스크립트가 그 결과다.
---
---
## 증거 파일
**증거 수집 시각: 2026-09-04 09:52 10:12 KST** (파일 mtime 기준. 문서 상단의 시각 표기는 작성 시점이라 다를 수 있다.)
| 파일 | 종류 |
|---|---|
| [`01-cross-node-session.txt`](evidence/session-replication/01-cross-node-session.txt) | 터미널 원문 |
| [`02-cache-delta.txt`](evidence/session-replication/02-cache-delta.txt) | 터미널 원문 |
| [`03-cache-ownership.txt`](evidence/session-replication/03-cache-ownership.txt) | 터미널 원문 |
| [`04-read-path-sql.txt`](evidence/session-replication/04-read-path-sql.txt) | 터미널 원문 |
| [`keycloak-admin-sessions.png`](evidence/session-replication/keycloak-admin-sessions.png) | 스크린샷 |
| [`session-cache-entries-per-pod.png`](evidence/session-replication/session-cache-entries-per-pod.png) | 스크린샷 |
파일별 상세는 [`evidence/session-replication/README.md`](evidence/session-replication/README.md).
## 11. 재현
```bash
# 1. 깨끗한 상태로 되돌린다 (DB 비우고 캐시 비우기)
ssh test-server '
kubectl -n keycloak-lab exec deploy/postgres -- \
psql -U keycloak -d keycloak -c "delete from offline_user_session"
kubectl -n keycloak-lab rollout restart statefulset/keycloak
kubectl -n keycloak-lab rollout status statefulset/keycloak --timeout=300s'
# 2. 세 실험을 순서대로
ssh test-server '/tmp/experiment-session-replication.sh' # 교차 노드 사용
ssh test-server '/tmp/experiment-cache-replication-delta.sh' # 복제인가 DB인가
ssh test-server '/tmp/experiment-cache-ownership.sh' # 엔트리 위치
# 3. 그래프
# https://app2.hyeonworks.com/explore
# vendor_statistics_approximate_entries_unique{cache="sessions"}
# Legend: {{pod}} on {{node}}
```
### 확인용 명령 모음
```bash
# 클러스터 멤버
kubectl -n keycloak-lab logs keycloak-0 | grep ISPN000094 | tail -1
kubectl -n keycloak-lab exec deploy/postgres -- \
psql -U keycloak -d keycloak -c "select name, ip, coord from jgroups_ping"
# DB 세션
kubectl -n keycloak-lab exec deploy/postgres -- psql -U keycloak -d keycloak \
-c "select offline_flag, count(*) from offline_user_session group by offline_flag"
# 노드별 캐시 엔트리 (파드 안에서)
curl -s http://$(kubectl -n keycloak-lab get pod keycloak-0 -o jsonpath='{.status.podIP}'):9000/metrics \
| grep 'approximate_entries_unique{cache="sessions"'
```