# 세션은 어디에 있는가 — Keycloak 다중 노드 실험 26건의 기록 Keycloak 을 두 대로 늘리면 세션은 어떻게 되고, 저장소를 Redis 로 옮기면 무엇이 달라지며, 그 저장소가 죽으면 어떻게 복구하는가. 이 문서는 그 물음들에 설계가 아니라 **측정으로** 답한 기록이다. 실험 26건과 증거 파일 147개가 들어 있고, 그 안에는 **아홉 번의 조용한 주입 실패**와 **틀린 예측 다섯 개**도 지우지 않고 남겨 두었다. 왜 지우지 않았는지는 마지막 절에서 따로 적는다. --- ## 코드보다 먼저 드러난 문제 ### 답할 수 없던 질문 네 개 앞선 작업([인증 패턴 네 가지](../../keycloak/final/document.md))은 네 가지 인증 패턴의 경계를 설계한 뒤 끝에 **열린 질문 네 개**를 남겼다. 넷 다 설계로는 답이 나오지 않고 실제로 돌려봐야 아는 것들이었다. | | 질문 | |---|---| | Q1 | 서버 세션 기반 인증 구조는 다중 인스턴스에서 어떻게 운영할 것인가 | | Q2 | Refresh Token Rotation 과 다중 Replica 경쟁을 어떻게 처리할 것인가 | | Q3 | BFF 의 Session 과 OAuth2AuthorizedClient 를 어디에 저장할 것인가 | | Q4 | Forward-Auth 구조에서 Application Authorization 을 어디까지 Edge 에 둘 것인가 | 네 질문은 같은 전제 위에 서 있다. **인스턴스가 둘 이상이고, 요청이 어느 쪽으로 갈지 모른다**는 것인데, 인스턴스가 하나면 이 질문들은 애초에 생기지 않으므로 전제를 갖춘 환경이 먼저 있어야 했다. 그래서 인스턴스를 둘로 만들고 그 사이를 끊어 보고 저장소를 죽여 보는 실험대를 세웠다. ### 그런데 첫 실험에서 전제가 무너졌다 실험대를 세우고 가장 먼저 확인한 것은 「한 노드에서 만든 세션을 다른 노드가 쓸 수 있는가」였고, 답은 **그렇다**였다. 그런데 **그렇게 되는 이유가 예상과 달랐다.** 로그만 보면 클러스터가 형성됐고 그것이 원인처럼 보인다. ``` ISPN000094: Received new cluster view for channel ISPN: [keycloak-0-10001|1] (2) [keycloak-0-10001, keycloak-1-52537] ``` `JGROUPS_PING` 테이블에도 둘 다 등록되어 있으니 「Infinispan 이 세션을 복제한다」고 읽기 쉬운데, 확인해 보니 그렇지 않았다. 노드 A 로 로그인하고 노드 B 로 refresh 했을 때 **노드 B 가 PostgreSQL 로 날린 SQL 을 문장 로깅으로 직접 잡았다.** 세션 엔트리는 노드 사이를 건너가지 않으며 각 노드는 자기가 처리한 로그인만 캐시하므로, 두 노드가 같은 답을 내놓는 이유는 복제가 아니라 **같은 데이터베이스를 보기 때문**이다. ![세션 공유가 실제로 지나는 경로](assets/session-sharing-path/session-sharing-path.svg) 두 노드는 `JGROUPS_PING` 으로 서로를 발견해 클러스터 뷰를 만들지만 `sessions` 캐시 사이에는 경로가 없어서, 같은 답이 나오는 것은 둘 다 `OFFLINE_USER_SESSION` 을 읽기 때문이다. > **클러스터가 형성됐다는 것과 세션이 복제된다는 것은 다른 얘기였다.** 이 하나가 이후 실험 전체의 해석을 바꿔 놓았다. 「클러스터를 끊으면 세션 공유가 깨질 것」이라는 예측이 A-1 에서 빗나간 이유도 여기에 있었다. ### 그리고 이 결론에는 버전 조건이 붙어 있었다 Keycloak 26 은 `persistent-user-sessions` 가 기본값이라 세션을 DB 에 쓰는데, 24 이전은 그렇지 않아서 메모리에 두고 Infinispan 으로 복제했다. 같은 실험을 `--features-disabled=persistent-user-sessions` 로 다시 돌리자 **세 결과가 정반대로 뒤집혔다.** | 실험 | persistent (26 기본) | volatile (24 이전) | |---|---|---| | A-1 · 7800 차단 후 교차 노드 refresh | `200` — 안 깨진다 | `400 Session not active` — 깨진다 | | A-8 · 롤링 재시작 후 refresh | `200` — 세션 생존 | `400 Session not active` — 전원 로그아웃 | | A-2 · DB 정지 중 새 로그인 | `500` | `200` — 된다 | 그래서 **「Keycloak 은 이렇다」고 쓸 수 있는 문장이 거의 없다.** 버전과 설정을 같이 적지 않으면 절반은 틀린 말이 되기 때문이다. ![설정에 따라 갈리는 세션의 거처](assets/version-conditional-results/version-conditional-results.svg) 설정 하나가 세션의 거처를 바꾸고, 그 거처가 장애 결과를 결정한다. --- ## 문제를 어렵게 만든 제약 ### 실험대 베어메탈 한 대(`test-server`, Arch Linux, 12GB, WiFi only) 위에 VM 두 대를 올렸다. | | 역할 | |---|---| | kc-lab-1 | k3s server (컨트롤 플레인) · keycloak-1 | | kc-lab-2 | k3s agent · keycloak-0 · PostgreSQL · Redis | | 호스트 nginx | Let's Encrypt TLS 종단 → traefik 으로 프록시 | ![실험대의 구성](assets/lab-topology/lab-topology.svg) 저장소가 kc-lab-2 한 곳에 몰려 있어서 A-4 의 두 결과가 이 배치에서 갈린다. 이름 셋(`auth` · `app1` · `app2`)이 한 인증서의 SAN 에 들어 있고 와일드카드가 아닌데, 이 제약은 나중에 실제 비용을 청구했다. oauth2-proxy 실험(B-7)을 할 때 네 번째 이름이 없어 **Grafana 의 `app2` 를 빌려야 했다.** ### 게스트와 호스트의 sudo 가 다르다 kc-lab-1/2 는 무암호 sudo 라 `conntrack`·`tc`·`iptables` 를 자유롭게 썼지만 **호스트는 비밀번호를 요구한다.** 이 차이를 모르고 한동안 nginx 설정을 읽으려 했는데 계속 빈 결과가 나왔고, **sudo 가 조용히 실패하고 있었다.** 하마터면 「빈 로그」를 「아무 일도 없음」으로 읽을 뻔했다. 호스트에서 해야 하는 일(인증서 강제 갱신, nginx reload)은 결국 **사람이 직접 쳐야** 했으므로, D-4 에서는 「명령 한 줄을 헛되이 쓰지 않는 것」이 설계의 일부가 됐다. ### 주입이 먹지 않는다 — 아홉 번, 전부 조용히 이 실험대에서 가장 많은 시간을 쓴 곳인데, **주입이 실패하면 「아무 일도 없었다」로 보이고 그 모습은 「영향이 없다」와 구별되지 않기 때문이다.** | # | 무엇을 했나 | 왜 안 먹었나 | |---|---|---| | 1 | NetworkPolicy 로 7800 차단 | **conntrack** — ESTABLISHED 연결은 규칙 평가를 건너뛴다. `cluster_size` 가 25분간 2 로 남았다 | | 2 | `kubectl delete --grace-period=0 --force` | **크래시가 아니다.** 런타임이 SIGTERM 을 보내 PostgreSQL 이 정상 플러시했다 | | 3 | `kill -9 1` | **PID 1 은 자기 네임스페이스의 SIGKILL 을 무시한다** | | 4 | `iptables -I FORWARD 1` | **kube-router** 가 자기 체인을 FORWARD 맨 위에 다시 끼워 넣는다 (패킷 0) | | 5 | raw 규칙을 한쪽 노드에 | **방향이 뒤집혀 있었다.** JGroups 의 client/server 역할은 재시작마다 바뀐다 | | 6 | `tc ... dev eth0` | **Debian 은 `enp1s0`** 이고, flannel VXLAN 이 이미 캡슐화해 파드 IP 가 안 보인다 | | 7 | `spring.sql.init` 로 스키마 생성 | 기본 DDL 이 `blob` 인데 PostgreSQL 은 `bytea` 다. `continue-on-error: true` 가 삼켰다 | | 8 | 호스트에서 `sudo` | **비밀번호를 요구한다.** 빈 출력이 곧 실패였다 | | 9 | `kubectl run --rm -i` 로 동시 20건 | **일회성 파드의 stdout 이 유실된다.** 20줄 중 일부만 도착하거나 아예 끊긴다 | 여기서 배운 규칙이 하나 있고, 이후 모든 실험에 적용했다. > **주입했다고 걸린 것이 아니다.** > 주입 뒤에는 「대상이 실제로 그 상태인가」를 따로 확인한다. > `cluster_size`, 워커 PID, conntrack 표, 패킷 카운터 — 결과가 아니라 상태를 본다. ![주입이 걸렸는지 따로 확인한다](assets/injection-verification/injection-verification.svg) 아홉 번의 실패가 모두 같은 단계에서 생겼다 — 주입과 관측 사이가 비어 있었다. --- ## 검토한 선택지와 막힌 지점 ### 관측을 어디에 둘 것인가 처음에는 밖에서만 쟀다. `curl` 로 외부 진입점을 찍고 상태 코드를 셌는데 **A-1 에서 그 방식이 무너졌다.** 7800 을 끊었는데도 외부 응답이 전부 200 이었기 때문이다. 장애가 없어서가 아니라 **분단된 노드가 readiness 실패로 스스로 로드밸런서에서 빠졌기** 때문이었고, 밖에서만 보면 이 실험은 「아무 일도 없음」으로 끝난다. 그래서 관측 지점을 셋으로 늘렸다. | 지점 | 무엇을 보는가 | |---|---| | 외부 `curl` | 사용자가 겪는 것 | | Prometheus 지표 | `vendor_cluster_size` · `vendor_jgroups_*` · `agroal_*` | | PostgreSQL 직접 조회 | 실제로 무엇이 저장됐는가 | `up` 지표를 신뢰할 수 없다는 것도 여기서 나왔다. A-2 에서 **503 이 나는 동안에도 `up` 은 1 이었는데**, 프로세스가 살아 있고 `/metrics` 가 응답하기만 하면 1 이 되므로 **「살아 있지만 쓸모없는」 상태를 못 보기 때문이다.** ![관측을 어디에 둘 것인가](assets/observation-points/observation-points.svg) 세 지점이 서로 다른 층을 보기 때문에, 하나만 두면 그 층의 사각이 그대로 사각으로 남는다. ### 스크립트를 쓰지 않는다 절차를 스크립트로 감싸면 「무엇을 했는지」가 스크립트 안으로 숨는다. 그래서 모든 절차를 **셸에 그대로 붙여넣을 수 있는 명령**으로 적었다. 이 결정에는 대가가 따랐다. 나중에 재현 절차를 점검해 보니 `( curl ... ) & 를 20개 띄우고 wait` 처럼 **측정 장치 자체를 산문으로 적어 둔 곳이 여럿** 있었고, 22.2초라는 헤드라인 수치를 만든 부하 생성기부터가 실행 가능한 형태가 아니었다. 전부 셸 표현식으로 바꾸고 **실제로 돌려서 확인**했더니 그 확인에서 한 건이 깨졌다(위 표의 #9). 문법은 멀쩡한데 실행하면 조용히 실패하는 종류였다. > **「명령을 실행 가능하게 고쳤다」와 「고친 명령이 동작한다」는 다른 주장이다.** --- ## 선택의 이유와 지킨 경계 ### A층 — Keycloak 자체가 깨질 때 여덟 개 실험을 같은 모양으로 돌렸다. 예측을 **먼저 문서에 적어 두고** 주입한 뒤 관측하고, 마지막에 그 예측과 대조하는 순서였다. #### A-1 · JGroups 전송(TCP 7800) 차단 예측을 둘 세웠고 하나는 맞고 하나는 틀렸다. | 예측 | 결과 | |---|---| | 세션 공유는 안 깨진다 | **맞다.** 교차 노드 refresh 가 `200` | | 로그아웃 전파는 안 깨진다 | **틀렸다.** `400` 이어야 할 것이 `200` | 세션은 DB 에 있으니 7800 과 무관한데, **로그아웃 무효화 통지는 7800 을 타기 때문에** 끊으면 반대편 노드가 「이 세션은 죽었다」를 알 방법이 없다. NetworkPolicy 는 허용목록이라 「deny 7800」 같은 규칙을 쓸 수 없으므로, 8080·9000 만 열고 7800 을 **목록에서 빼는 방식으로** 막았다. ![발견과 전송은 다른 경로다](assets/a1-transport-vs-discovery/a1-transport-vs-discovery.svg) 발견은 DB 를 쓰고 전송은 7800 을 쓴다 — 예측이 하나만 맞은 이유가 이 분기에 있다. 이 두 포트가 하중을 진다 — 9000(health·metrics)을 빠뜨리면 kubelet 이 파드를 죽여서 **분단이 아니라 죽은 Keycloak 을 재게 된다.** #### A-2 · A-3 — DB 가 멈출 때와 죽을 때 | | A-2 정지 | A-3 강제 종료 | |---|---|---| | 새 로그인 | `500` | — | | 관측된 것 | **`up` 이 계속 1** | **RPO 가 0 이 아니다** | A-3 이 이 실험대에서 가장 값진 숫자를 냈다. ``` 클라이언트가 200 과 토큰을 받은 로그인 : 153 건 그중 DB 에 실제로 존재 : 149 건 ★ 유실 : 4 건 ``` **로그인이 성공했다고 응답받았는데 세션이 존재하지 않는다.** 버그는 아니고, Keycloak 이 트랜잭션마다 `SET LOCAL synchronous_commit TO OFF` 를 걸기 때문에 COMMIT 이 WAL 디스크 기록을 기다리지 않고 즉시 반환한다. 그 사이(측정된 `wal_writer_delay` 200ms)에 프로세스가 죽으면 그만큼이 사라진다. 의도된 설계이므로, 이 실험은 그 대가가 얼마인지를 숫자로 확인했을 뿐이다. ![200 과 디스크 사이의 빈 구간](assets/a3-commit-to-disk-gap/a3-commit-to-disk-gap.svg) 성공 응답과 영속화가 다른 사건이어서, RPO 가 0 이 아닌 이유가 그 사이에 있다. #### A-4 · 노드 상실 — 둘 다 전면 장애지만 이유가 다르다 | | 4a 워커 상실 | 4b 컨트롤 플레인 상실 | |---|---|---| | 외부 응답 | `503` | `000` (연결 자체가 안 됨) | | `kubectl` | 정상 | 불통 | | 원인 | **DB 가 같이 죽었다** | **들어갈 길이 없다** | | 복구 | `virsh start` 이후 60초 | `virsh start` 이후 60초 | 4b 에서 keycloak-0 은 **계속 돌고 있었는데도** 도달할 수 없어서 장애였다. **진입점이 단일 노드에 있으면 워크로드를 이중화해도 소용이 없다.** 그리고 예상하지 못한 것이 셋 더 나왔다. 1. **죽은 파드가 산 파드보다 건강해 보인다** — kubelet 이 사라져 상태가 갱신되지 않으니 `Running` 으로 남는다 2. **StatefulSet 은 Terminating 파드의 대체를 만들지 않는다** — 이름이 같아야 하므로 지워지기를 기다린다 3. `node-monitor-grace-period` 40초 + `tolerationSeconds` 300초 = 축출까지 **5분 40초** > 장애 시간의 대부분은 복구가 아니라 **「누가 죽은 것을 알아채는 데」** 걸린 시간이었다. ![노드를 잃는 두 가지](assets/a4-two-node-losses/a4-two-node-losses.svg) 저장소 상실과 진입 경로 상실은 복구 시간이 같아도 대비하는 방법이 다르다. #### A-5 · 비대칭 분단 — 전면 장애 경로가 없다 한 방향만 막으면 **열린 방향으로 재연결하므로** 클러스터가 갈라지지 않는다. 양방향을 다 막으면 갈라지기는 하는데 **한쪽만 DOWN** 이 되어서, 코디네이터 쪽이 살아남고 분단된 쪽은 스스로 로드밸런서에서 빠지며 서비스는 이어진다. 이 실험에서 주입을 세 번 실패했다(위 표의 #4·#5·#6). **세 번 모두 다른 이유였고, 셋 다 「아무 일도 없었다」로 보였다.** ![비대칭 차단은 가르지 못한다](assets/a5-partition-asymmetry/a5-partition-asymmetry.svg) 한 방향을 막을 때와 둘을 다 막을 때의 차이가 여기서 갈린다. #### A-6 · 지연 주입 — 200밀리초가 22초가 된다 | 측정 | 값 | |---|---| | 주입한 네트워크 지연 | 200 ms | | 로그인 응답 시간 | 66 ms → **1,872 ms** (28배) | | 동시 20건에서 최대 응답 | **22.2 초** | | 커넥션 획득 대기 최대 | 20,000 ms | | readiness 프로브 | **타임아웃으로 실패** | 두 단계로 곱해지는데, 로그인 한 번이 DB 왕복을 여러 번 하므로 **왕복 횟수만큼** 더해지고 요청이 커넥션을 오래 붙들어 뒤의 요청이 풀에서 대기하므로 **거기서 한 번 더** 곱해진다. 마지막에는 파드가 죽는다. readiness 가 타임아웃으로 실패해 느린 노드가 로드밸런서에서 빠지므로, **느림이 곧바로 장애로 승격된다.** ![지연이 곱해지는 두 단계](assets/a6-latency-multiplication/a6-latency-multiplication.svg) 왕복 누적과 풀 경합을 하나로 보면 28배가 어디서 왔는지 설명되지 않는다. #### A-8 · 롤링 재시작 — 세션은 살아남고 캐시만 사라진다 | 확인 | 결과 | |---|---| | 재시작 중 서비스 중단 | 없음. 전 구간 `200` | | 재시작 전 발급한 refresh token | 여전히 `200` | | DB 세션 수 | 151 → **151** 그대로 | | 세션 캐시 | **0 으로 초기화** | `persistent-user-sessions` 를 켜는 진짜 이유가 여기에 있다. ![재시작이 지우는 것과 남기는 것](assets/a8-cache-vs-session/a8-cache-vs-session.svg) 캐시와 세션을 분리하지 않으면 재시작 후 로그인이 유지되는 이유를 설명할 수 없다. #### A-7 · A-7a — 전부 뒤집는 설정 하나, 그리고 그 표에도 조건이 있었다 A-7 은 `--features-disabled=persistent-user-sessions` 로 A층을 다시 돌려 세 결과가 뒤집히는 것을 보였다. 그리고 **refresh 가 `500` 인 이유를 가설로 남겼다** — `REVOKED_TOKEN` 테이블일 것이라고. A-7a 에서 문장 로깅으로 확정했더니 **가설이 틀렸다.** 로그인은 SQL 을 **0개** 쏜다. refresh 는 딱 한 문장을 쏘는데, 그것이었다. ``` select cscme1_0.SCOPE_ID from CLIENT_SCOPE_CLIENT cscme1_0 where cscme1_0.CLIENT_ID=$1 and cscme1_0.DEFAULT_SCOPE=$2 parameters: $1 = '131a9912-b578-4b9c-b16a-97518704077e', $2 = 'f' ``` `REVOKED_TOKEN` 은 한 번도 나오지 않으며, `DEFAULT_SCOPE='f'` 이므로 **선택적 클라이언트 스코프** 조회다. refresh 는 새 access token 에 어떤 스코프를 담을지 다시 계산하는데 그 목록이 이 테이블에 들어 있다. 그 다음이 더 중요하다. **그 조회는 첫 refresh 에서 한 번만 일어나고 캐시된다.** 그래서 같은 설정이 캐시 온도만으로 세 가지 답을 낸다. | 캐시 상태 | 로그인 | refresh | 실패한 SQL | |---|---|---|---| | 완전 냉시동 | **400** | 400 | `select ce1_0.ID from CLIENT ...` | | CLIENT 만 더움 ← A-7 이 본 것 | 200 | **500** | `CLIENT_SCOPE_CLIENT ...` | | 완전히 더움 | 200 | **200** | 없음 (SQL 0건) | 셋 다 재현해 보니 **A-7 이 적은 「volatile 이면 DB 없이 로그인된다」도 조건부였는데**, 냉시동에서는 클라이언트 조회조차 캐시에 없어 `400` 이 나온다. > volatile 에서 DB 정지 시의 동작은 「무엇을 하느냐」가 아니라 > **「그 경로가 이미 캐시를 채웠느냐」** 로 결정된다. > 이런 종류는 **한 번 재고 표로 적으면 안 된다.** ![캐시 온도가 결과를 가른다](assets/cache-temperature-outcomes/cache-temperature-outcomes.svg) 세 결과를 만드는 것은 조회 두 개이고, 캐시가 그 조회를 삼키는 순간 결과가 바뀐다. --- ## 선택이 코드와 흐름에 반영되는 방식 ### B층 — 열린 질문 네 개에 대한 답 A층이 Keycloak 자체를 다뤘다면 B층은 **애플리케이션 쪽**이다. BFF(Spring Boot) 두 인스턴스와 Redis, 그리고 oauth2-proxy 두 replica 를 올리고 잰다. #### B-0 · 아무것도 설정하지 않으면 무엇이 선택되는가 저장소를 붙이기 **전에** 먼저 들여다봤고, 추측으로 두면 안 되는 이유가 여기서 나왔다. ``` authorizedClientService → InMemoryOAuth2AuthorizedClientService authorizedClientRepository → AuthenticatedPrincipalOAuth2AuthorizedClientRepository SessionRepository → 없음 (서블릿 컨테이너 in-memory) Redis / Spring Session → 없음 ``` 둘째 줄이 핵심인데, **`AuthenticatedPrincipalOAuth2AuthorizedClientRepository` 는 principal 이름으로 찾기 때문에 조회 키에 session id 가 없다.** 그래서 이름은 비슷해도 서로 다른 것을 저장하는 두 개가 따로 굴러간다. | | 무엇을 담나 | 조회 키 | |---|---|---| | Application Session | 누가 로그인했는지 | **세션 id** | | OAuth2AuthorizedClient | access · refresh token | **principal 이름** | 이 둘을 하나로 생각하면 다음 실험의 결과를 해석할 수 없다. ![BFF 가 저장하는 두 가지와 그 조회 키](assets/bff-store-lookup-keys/bff-store-lookup-keys.svg) 같은 요청이 세션은 세션 id 로, 토큰은 principal 이름으로 두 갈래로 조회되기 때문에, B-1 에서 세션만 Redis 로 옮겼을 때 토큰이 따라오지 않았고 B-2 에서 따로 PostgreSQL 로 옮겨야 했다. #### B-1 · 세션만 Redis 로 옮기면 — 반쪽만 옮겨진다 `SPRING_SESSION_STORE_TYPE=redis` 로 Application Session 을 Redis 로 옮기자 파드를 재시작해도 로그인이 유지됐지만 **토큰은 같이 살아남지 못했다.** 조회 키가 다르므로 세션 저장소를 바꿔도 `OAuth2AuthorizedClient` 는 따라오지 않는다 — B-0 에서 확인한 그대로다. #### B-2 · 저장소를 나눠 풀자 다른 두 문제가 남았다 토큰은 `JdbcOAuth2AuthorizedClientService` 로 PostgreSQL 에 옮겼고, 이것이 **Q3 가 말한 「각각 설계한다」를 실제로 해 본 모습**이다. | Q1 검증 | 결과 | |---|---| | ① 다른 인스턴스로 요청해도 되는가 | **된다** | | ② 재시작 후 로그인 유지 | **된다** | | ③ 같은 사용자의 다른 브라우저가 덮어쓰는가 | **★ 덮어쓴다** | | ④ 로그아웃하면 두 저장소가 다 정리되는가 | **★ 아니다. 한쪽만** | ③④ 의 뿌리는 저장소 선택이 아니라 **DDL 한 줄**이다. ```sql PRIMARY KEY (client_registration_id, principal_name) ``` **세션 id 가 키에 없어서** 같은 사용자의 두 세션이 같은 행을 쓰게 되고, 나중 로그인이 앞의 토큰을 덮어쓴다. 로그아웃한 뒤에는 이렇게 남는다. ``` Redis 세션 : 0 키 ← 정리됨 PostgreSQL 토큰 : 1 행 ← 평문 refresh token 이 그대로 남는다 ``` ![덮어쓰기를 만드는 기본키](assets/b2-primary-key-overwrite/b2-primary-key-overwrite.svg) 저장소를 무엇으로 골랐느냐가 아니라 스키마가 원인이다. #### B-3 · Refresh Token Rotation 경쟁 (Q2) `revokeRefreshToken=true` · `refreshTokenMaxReuse=0` 에서 같은 refresh token 으로 동시에 5건을 보냈다. 순차로 돌리면 재현되지 않는다 — `&` 와 `wait` 이 있어야 경합이 생긴다. 경쟁이 감지되면 Keycloak 이 client session 을 지우기 때문에, 이긴 요청이 받은 **새 토큰조차 쓸 수 없다.** 「하나는 성공하고 나머지가 실패한다」가 아니라 **전부 못 쓰게 되는** 쪽이다. ![회전 경쟁에서 이긴 요청도 진다](assets/b3-rotation-contention/b3-rotation-contention.svg) 실패가 진 요청에만 오는 것이 아니어서, 재시도를 어떻게 설계할지가 여기서 갈린다. #### B-4 · Edge 인가의 범위 (Q4) nginx → oauth2-proxy → 앱의 2홉 구조에서 헤더를 위조해 봤다. 여기서도 예측이 틀렸다. **nginx 는 자기가 설정하지 않은 동명 헤더를 덮어쓰지 않기 때문에** `proxy_set_header X-Auth-Request-Roles ""` 로 먼저 지우지 않으면 위조 헤더가 그대로 통과한다. 그리고 **IdP 에서 값을 바꿔도 반영되지 않는다.** 12회 요청·6초 동안 옛 값이 갔고, Redis 세션을 지워 재인증시킨 뒤에야 새 값이 왔다. > **세션은 로그인 시점의 스냅샷이어서**, `--cookie-refresh` 가 없으면 > 요청을 몇 번 보내든 쿠키 만료나 재인증까지 옛 값이 그대로 간다. ![지우지 않으면 통과한다](assets/b4-header-trust-boundary/b4-header-trust-boundary.svg) 위조 경로와 정상 경로가 같은 헤더 이름을 쓰므로, 지우는 단계가 없으면 둘을 구별할 수 없다. #### B-5 · B-6 — 저장소 상실과 키 회전 B-5 에서 `redis-cli config set appendonly yes` 를 켜도 아무것도 달라지지 않았는데, `/data` 가 컨테이너 파일시스템이라 컨테이너와 함께 죽기 때문이다. **볼륨 없는 영속화 설정은 장식에 그친다.** B-6 에서 realm 키를 회전하고 JWKS 캐시의 유예 구간을 기대했는데 **없었다.** `NimbusJwtDecoder` 는 모르는 `kid` 를 만나면 JWKS 를 다시 가져온다. ![볼륨 없는 영속화와 유예 없는 회전](assets/b5-b6-storage-and-keys/b5-b6-storage-and-keys.svg) 설정과 매체를 나눠서 보아야 한다. 설정만 보면 둘 다 되어 있는 것으로 읽히기 때문이다. #### B-7 · B-7a — 쿠키에 담는 세션, 그리고 그 대가 oauth2-proxy 는 BFF 와 정반대로 **서버 상태를 갖지 않는다.** 세션 전체가 쿠키에 있고 replica 는 같은 k8s Secret 만 읽으므로, 공유할 것이 없어서 콜백이 다른 replica 로 가도 문제가 없다. 대신 `--cookie-secret` 이 단수라서 **겹침 구간을 만들 수 없다.** 「옛 secret 도 당분간 받아준다」가 불가능하므로, 교체하는 순간 모든 쿠키가 한꺼번에 무효가 된다. Redis 세션 저장소를 켜면 쿠키에는 티켓만 남는데, 그러면 문제의 성격이 바뀐다. secret 을 바꾸면 티켓을 못 풀고, **티켓 안에 세션 id 가 있으므로 어느 Redis 키를 지울지도 모른다.** ``` Error removing session: error decoding ticket to clear session ``` B-7 은 여기서 「지우지 못했다」로 멈췄다. B-7a 가 이어받아 잰 결과 — **oauth2-proxy 의 한계이지 Redis 의 한계가 아니었다.** | 물음 | 답 | |---|---| | 고아는 정말 사라지는가 | **사라진다.** 생성 후 정확히 1시간. TTL 이 갱신되지 않는다 | | 운영자가 지울 수 있는가 | **있다.** `redis-cli del` 후에도 산 세션은 `200` | | 어느 것이 고아인지 아는가 | **Redis 값으로는 모른다.** 이름·타입·크기(3510바이트)가 같고 값은 암호화 | | 그럼 어떻게 고르는가 | **TTL 로 생성 시각을 역산한다** | TTL 이 요청으로 갱신되지 않으므로(`refresh:disabled`) **TTL 은 생성 시각의 정확한 함수**다. ``` 생성시각 = 지금 − (cookie-expire − TTL) ``` 이 값이 회전 시각보다 이르면 고아인데, 역산한 `11:30:26` 과 로그의 `AuthSuccess 11:30:27` 이 **1초 차**였다. 그 기준으로 실제로 골라 지웠고 산 세션만 남았다. 전제도 같이 적는다 — **`--cookie-refresh` 를 켜면 이 역산이 무너진다.** 그때는 `FLUSHDB` 로 전부 지우고 모두 재인증시키는 편이 정직하다. ![쿠키에 담으면 공유할 것이 없다](assets/b7-cookie-session-tradeoff/b7-cookie-session-tradeoff.svg) 쿠키 저장과 Redis 저장을 나란히 두면, 옮기는 순간 지울 수 없는 상태가 생기는 것이 보인다. ### C층 — SSO 와 로그아웃 전파 C-1 에서 두 앱이 같은 realm 으로 SSO 되는 것을 확인하면서 로그아웃이 다른 앱으로 퍼지지 않는 것도 함께 관측했고, C-2 에서 들여다본 원인은 단순했다. | 확인 | 결과 | |---|---| | 백채널 로그아웃이 설정되어 있었는가 | **아니다.** 두 클라이언트 모두 `backchannelLogoutUrl` 없음 | | 앱에 그 엔드포인트가 있는가 | **아니다.** 소스에 `oidcLogout` 설정이 없다 | | IdP 쪽만 설정하면 되는가 | **★ 안 된다.** 앱 세션이 그대로 남았다 | | Keycloak 이 앱 URL 에 닿기는 하는가 | 닿는다 (`HTTP 200`) — 네트워크 문제가 아니다 | **아무도 구현하지 않았다.** 그리고 「설정이 빠졌다」와 「기능이 없다」는 고치는 방법이 다른데 여기는 둘 다였으므로, 확인 순서를 바꿨다면 한쪽만 고치고 끝냈을지도 모른다. ![백채널 로그아웃은 양쪽이 있어야 한다](assets/c2-backchannel-both-sides/c2-backchannel-both-sides.svg) IdP 쪽 결손과 앱 쪽 결손이 한 경로 위에 있어서, 하나만 고쳐서는 여전히 되지 않는다. ### D층 — 운영 #### D-1 · D-2 — 백업과 업그레이드 D-2 에서 26.7.0 → 26.7.3 은 **무중단**이었지만(87회 요청 전부 200) 되돌리기는 **막혔다.** ``` liquibase ValidationFailedException: 1 changesets check sum ``` 새 버전이 남긴 체크섬을 옛 버전이 거부한다. 그런데 **서비스는 살아 있었다** — StatefulSet 롤링 업데이트가 첫 파드에서 멈추고 나머지를 건드리지 않았기 때문이다. **「롤백 계획」이 없어도 사고가 전면화되지 않았다.** 이 결론은 나중에 더 정밀해졌다. **「롤백 불가」는 조건부여서** 스키마가 움직였을 때만 해당하며 판단 기준도 하나로 정해진다. ```sql select count(*) from databasechangelog ``` 업그레이드 전후로 이 수가 같으면 롤백이 되고 늘었으면 안 되는데, 26.7.3 → 26.7.0 을 스키마 변경 없이 되돌리는 것은 **실제로 성공했다**(전환 순간 `000` 1회). ![방향에 따라 갈리는 업그레이드](assets/d2-upgrade-direction/d2-upgrade-direction.svg) 체크섬 검증은 되돌리기를 막고, 롤링 업데이트는 그 사고의 피해를 줄인다. #### D-3 · 비밀 `kubectl get secret -o yaml` 의 base64 는 암호화가 아니라 인코딩이므로 etcd 에는 평문으로 있고, 파드 안에서 `env | grep -i secret` 을 치면 그대로 나온다. ![base64 는 암호화가 아니다](assets/d3-secret-exposure/d3-secret-exposure.svg) 인코딩과 암호화는 다르고, 드러나는 두 경로 모두 끝이 평문이다. #### D-4 · D-4a — 인증서, 그리고 이 실험대 최대의 발견 계획서의 물음은 「nginx reload 중 진행 중이던 요청은 어떻게 되는가」였고, 답하기 전에 **대조군부터** 잡았다. | 대조군 | 결과 | |---|---| | 새 연결 (0.2초 × 900회 / 180초) | **900 전부 200, 오류 0** · 중앙 98ms · p95 195ms | | 진행 중 요청 (845KB @ 20k/s) | 200 · 845361바이트 · 연결수 1 · 42.3초 완주 | 두 번째가 왜 필요했는가 하면, 첫 폴링은 **TLS 핸드셰이크가 900/900** 이라 매 요청이 새 연결이고 그래서 「새 연결을 받아주는가」만 재기 때문이다. 계획서가 물은 것은 **「진행 중이던 요청」** 이므로 reload 순간에 실제로 전송 중인 요청이 있어야 했다. 845KB 짜리 번들을 일부러 느리게 받아 요청 하나를 42초 동안 살려 두었다. 그리고 강제 갱신을 했더니 — **인증서가 바뀌지 않았다.** ``` 디스크 cert2.pem 2026-09-04 17:22:13 KST 기록됨 네트워크 일련번호 564표본 내내 옛 것. 08:58:52 에야 바뀜 ``` | | 시각 (실제 UTC) | |---|---| | 새 인증서 디스크 기록 | 08:20:27 | | 실제 서빙 시작 (`nginx -s reload`) | 08:58:52 | | **공백** | **2305초 = 38분 25초** (그 사이 428회 관측) | 그 38분은 **우연히 짧았을 뿐인데**, reload 를 시킨 것이 자동화가 아니라 사람이었기 때문이다. 아무도 치지 않았다면 다음 nginx 재시작까지, 사실상 무기한으로 옛 인증서가 나갔을 터였다. 원인이 셋 겹쳤고 **셋 다 비어 있었다.** | | 상태 | |---|---| | `certbot-renew.service` 의 `ExecStartPost` | 없음 | | `/etc/letsencrypt/renewal-hooks/{deploy,post,pre}/` | **셋 다 비었음** | | certbot 의 nginx 플러그인 | 없음 (`dns-cloudflare, manual, null, standalone, webroot`) | nginx 는 인증서를 기동 시점에 읽어 메모리에 들고 있는데 certbot 은 경로가 아니라 `live/` 심볼릭 링크를 갈아끼우므로, **설정은 멀쩡해 보이는데 옛 인증서가 나간다.** 설정을 고칠 일이 아니라 reload 를 걸 일이다. ![인증서 갱신이 서빙에 닿기까지](assets/renewal-to-serving-gap/renewal-to-serving-gap.svg) `live/` 는 심볼릭 링크라 **경로가 그대로이고 가리키는 대상만 바뀐다.** 그래서 nginx 설정을 고칠 필요가 없고, 바로 그 때문에 「설정이 그대로니 괜찮다」고 착각하기 쉽다. 필요한 것은 설정 변경이 아니라 reload 이며, 그 reload 를 부르는 경로가 이 실험대에서는 셋 다 비어 있었다. reload 가 실제로 일어났는지 가리는 방법도 여기서 나왔다. **마스터 PID 는 유지되고 워커 PID 만 바뀌면 reload 된 것**이다. ``` 585 1 80529 Thu Sep 3 19:00:39 nginx: master process 586 585 80529 Thu Sep 3 19:00:39 nginx: worker process ``` 워커가 마스터 기동 직후의 첫 fork(585→586) 그대로 22.4시간째다. **이 결함은 88일 동안 드러나지 않는다.** 타이머는 정상이고 매번 `SUCCESS` 로 끝나는데, 만료 30일 전까지는 갱신 자체를 하지 않아 발현할 기회가 없기 때문이다. 발현하는 날의 증상은 **인증서 만료**이고, 그날에도 로그에는 `SUCCESS` 라고 적혀 있을 것이다. D-4a 에서 처방(`deploy/` 훅 하나)을 실제로 넣고 검증했다. | | 훅 없음 | 훅 있음 | |---|---|---| | 갱신 → 서빙 | 2305초 = 38분 25초 | **1~2초** | | 무엇이 reload 했나 | 사람 | certbot deploy 훅 | 여기에도 함정이 하나 더 있었다. certbot 이 `Hook 'deploy-hook' ran with error output` 이라고 찍지만 **실패는 아니고**, nginx 의 `types_hash` 경고가 stderr 로 나갔을 뿐이어서 내용은 `test is successful` · `signal process started` 다. **로그에서 `error` 를 grep 하는 감시를 걸면 성공한 훅을 실패로 오독한다.** reload 자체는 무중단이었다 — 새 연결 **8856건 전부 200**, p95 205.7 → 204.3ms. 그리고 전송 12초째에 reload 를 맞은 42초짜리 요청이 **845361바이트를 온전히** 받았다(연결수 1). 옛 워커가 그 요청을 끝까지 책임졌기 때문이다. ![훅 하나가 만드는 차이](assets/d4a-hook-effect/d4a-hook-effect.svg) 훅이 있고 없고가 이 차이를 만든다 — 판정은 로그 문구가 아니라 워커 PID 로 한다. --- ## 결정이 지켜지는지 확인하는 방법 ### 측정이 거짓말할 때 이 실험대가 남긴 것 중 결과표보다 오래 갈 것은 **어디서 측정이 틀리는가**다. #### 대조군 없이는 아무것도 귀속할 수 없다 D-4 에서 갱신 중 비200 이 한 번 나왔다고 하면, **평시 오류율을 모르는 채로는 그게 갱신 탓인지 알 수 없다.** 그래서 주입 전에 900건을 재서 오류가 0 이라는 것부터 확인해 두었다. 이 규칙을 어긴 사례가 이미 있었다. A-6 에서 **−41% 인 대조군을 「영향 없음」** 이라고 적었고 A-8 에서는 **표본 9개로 무중단을 주장**했다. 둘 다 나중에 고쳤다. 가장 최근 사례는 D-4 의 in-flight 감시다. 76건이 실패했고 그대로 적었으면 「갱신 중 대규모 요청 실패」라는 오보가 됐을 것이다. 확인해 보니 서버 탓이 아니었다. | 근거 | 값 | |---|---| | 같은 순간 폴링 | 49건 **전부 200** | | 연결수 | **0** — TCP 연결 시도조차 못 했다 | | 소요 시간 | **50µs** — DNS 조회보다 짧다 | | 재현 | **0/100** | 대조군이 있었기에 오보를 내지 않을 수 있었다. ![대조군 없이는 귀속할 수 없다](assets/measurement-control/measurement-control.svg) 대조군이 관측과 귀속 사이에 있어서, 그것이 없으면 같은 관측이 두 가지로 읽힌다. #### 두 시계에서 온 값을 빼면 안 된다 D-4a 에서 1~2초를 재려다 걸렸다. `test-server` 는 NTP 가 꺼져 있어 **106초 빠른** 반면 dev 머신은 Google 및 Let's Encrypt ACME 응답과 0초 차였다. 그 사실을 적지 않고 계산한 D-4 의 공백은 **106초 짧았다**(2199 → 2305초). 그리고 1~2초를 재는 D-4a 에서는 보정 없이는 **훅이 인증서 발급보다 104초 먼저 실행된 것**이 되어 물리적으로 불가능해진다. 보정은 독립 기준으로 교차검증했다 — 새 인증서의 SCT(`Sep 4 12:27:49.054 GMT`, CT 로그가 자체 시계로 서명)가 보정한 훅 시각의 정확히 1초 앞에 놓인다. > 두 시계에서 온 값을 그냥 빼면 **자릿수가 아니라 방향까지 틀릴 수 있다.** #### 관측 도구는 진실의 부분집합만 본다 | 도구 | 못 보는 것 | |---|---| | `up` 지표 | **「살아 있지만 쓸모없는」 상태.** 503 이 나는 동안에도 1이었다 | | crt.sh | 서빙 중인 인증서에 **SCT 가 두 개 박혀 있는데도 0건**으로 답한다 | | Prometheus | **Redis·BFF·PostgreSQL 을 아예 긁지 않는다** | 마지막 것 때문에 **B층 실험 대부분에 Grafana 스크린샷이 없는데**, 안 찍어서가 아니라 지표 자체가 없어서다. 그래서 이 사실을 「스크린샷 누락」이 아니라 **측정된 공백**으로 기록했다. #### 문서가 자기 증거와 어긋난 곳 기록을 다 쓴 뒤 증거와 하나씩 대조했더니 어긋난 곳이 여럿 나왔다. | 어디 | 무엇이 어긋났나 | |---|---| | C-1 | 본문은 「세션 0」인데 증거는 4 | | C-2 | `exit code 1` 인 명령의 성공 읽기를 실었다 | | A-1 | 4초 전 파드 재시작이 만든 분단을 conntrack 공으로 돌렸다 | | A-2 | 첫 측정의 `000000{"error":"HTTP 401"}401` 을 숨겼다 | | A-3 | `wal_writer_delay` 를 재지 않고 단언했다 (실측 200ms, 로그인율도 19/s 가 아니라 14/s) | | D-1 | 본문은 RTO 30초, 자기 타임라인은 41초 | 전부 고치면서 **무엇이 어긋났는지를 표로 남겼다.** 지워 버리면 다음 사람이 같은 방식으로 틀리기 때문이다. ### 재현 가능성을 어떻게 보장했나 절차를 명령으로 적는 것만으로는 부족했다. **측정 장치 자체를 산문으로 적어 둔 곳**이 남아 있었는데, 하필 그것들이 헤드라인 수치를 만든 바로 그 명령이었다. | 어디 | 산문이던 것 | |---|---| | A-6 | `( curl ... ) & 를 20개 띄우고 wait` ← 22.2초의 출처 | | A-3 | `<로그인 반복, sid 를 /tmp/sids 에>` ← RPO 측정 전체 | | A-8 | `/tmp/tok` 에 쓰고 `/tmp/rt` 를 읽는다 ← 빈 토큰을 보내고 있었다 | | A-1 | conntrack 튜플을 손으로 적는다 ← 방향이 재시작마다 바뀐다 | 전부 셸 표현식으로 바꾸고 **실제로 실행해 확인**했다. 그 확인에서 A-6 의 부하 생성기가 깨졌다 — 일회성 파드의 출력 스트림이 유실됐다. 상주 탐침 + 파드 안 파일 수집으로 고쳐 20/20 을 확인했다. ![명령으로 적는 것과 도는 것](assets/reproducibility-gap/reproducibility-gap.svg) 산문에서 명령으로, 다시 실행 확인으로 두 단계를 거쳤고 두 번째에서 한 건이 깨졌다. --- ## 얻은 것, 잃은 것, 적용하지 않을 때 ### 열린 질문 네 개에 대한 답 | | 질문 | 답 | |---|---|---| | Q1 | 다중 인스턴스 세션 운영 | **저장소를 밖으로 빼면 ①② 는 풀린다.** ③④ 는 저장소가 아니라 **스키마** 문제다 — `PRIMARY KEY (client_registration_id, principal_name)` 에 세션 id 가 없다 | | Q2 | Refresh Rotation 경쟁 | **이긴 요청의 토큰조차 못 쓴다.** 경쟁이 감지되면 client session 이 지워진다 | | Q3 | Session 과 AuthorizedClient 를 어디에 | **둘은 조회 키가 다르므로 각각 결정해야 한다.** 세션을 Redis 로 옮겨도 토큰은 따라오지 않는다 | | Q4 | Edge 인가의 범위 | **nginx 는 자기가 설정하지 않은 헤더를 덮어쓰지 않는다.** 먼저 지워야 한다. 그리고 **IdP 의 클레임 변경은 재인증 전까지 반영되지 않는다** | ![열린 질문 네 개가 닿은 곳](assets/open-questions-answered/open-questions-answered.svg) 네 질문이 공통 원인으로 모이면서, 저장소 선택만으로는 풀리지 않는 것들이 함께 드러난다. ### 이 기록이 적용되지 않는 조건 - **Keycloak 26 미만.** `persistent-user-sessions` 가 기본이 아니면 A층 결론 중 셋이 뒤집힌다. A-7·A-7a 가 그 대조군이다 - **캐시가 더운지 찬지.** volatile 에서 DB 정지 시의 동작은 캐시 온도로 갈린다 - **단일 인스턴스.** B층 질문은 인스턴스가 둘 이상일 때만 생긴다 - **`--cookie-refresh` 를 켠 oauth2-proxy.** B-7a 의 TTL 역산 정리 규칙이 무너진다 - **NTP 가 동기된 환경.** 이 실험대는 106초 왜곡이 있었고 그것을 보정한 수치다 ![이 기록이 적용되지 않는 조건](assets/not-applicable-conditions/not-applicable-conditions.svg) 적용 조건을 목록이 아니라 무엇을 무효로 만드는가로 이었다. ### 재보지 않은 것 | 항목 | 왜 | |---|---| | `certbot-renew.timer` 가 **실제 갱신**을 하는가 | 만료 30일 전(약 89일 뒤)에야 조건이 성립한다 | --- ## 결국 지키려던 것은 무엇이었나 이 실험대에서 **예측 다섯 개가 틀렸고 주입이 아홉 번 조용히 실패했다.** 그것을 지우지 않고 남긴 이유가 이 기록의 요지다. | 틀린 예측 | 실제 | |---|---| | A-1 로그아웃 전파는 안 깨진다 | 깨졌다 — A-0 의 인과 설명을 고쳐야 했다 | | A-2 `up` 이 장애를 보여준다 | 503 내내 1이었다 | | A-6 낙관적 락 충돌이 보인다 | 0건 — 로그인은 INSERT 라 경합하지 않는다 | | B-4 nginx 가 동명 헤더를 덮어쓴다 | 덮어쓰지 않는다 | | B-6 JWKS 캐시가 유예를 준다 | 주지 않는다 | | A-7 refresh 500 은 `REVOKED_TOKEN` 때문 | `CLIENT_SCOPE_CLIENT` 였다 | **틀린 예측이 맞은 예측보다 많은 것을 가르쳤는데**, A-1 이 틀리지 않았다면 A-0 의 인과 설명이 잘못된 채로 남았을 것이고 A-7 의 가설이 확정되지 않았다면 「volatile 이면 이렇다」는 표가 조건 없이 유통됐을 것이기 때문이다. 그래서 이 기록을 쓰면서 지킨 규칙은 셋이다. 1. **예측을 먼저 적는다.** 결과를 보고 나면 무엇을 예상했는지 정직하게 쓸 수 없다 2. **주입이 걸렸는지를 결과와 따로 확인한다.** 「아무 일도 없었다」는 「영향이 없다」와 구별되지 않는다 3. **대조군 없이 귀속하지 않는다.** 평시를 모르면 이상을 해석할 수 없다 세 번째가 가장 자주 어겨졌고 치른 값도 가장 컸다. ![틀린 예측이 남긴 것](assets/wrong-predictions/wrong-predictions.svg) 세 규칙을 순서대로 놓으면, 각 단계가 빠졌을 때 어떻게 틀리는지가 실제 이력으로 남는다. --- ## 자료 | | | |---|---| | 원본 | [`../source/docs/`](../source/docs/) — 실험 문서 29편 · 계획서 · 개념 문서 · 선수지식 문서 | | 매니페스트 | [`../source/deploy/`](../source/deploy/) — 실험이 쓰는 k8s 매니페스트 8개 | | 증거 원문 | [`evidence/raw/`](evidence/raw/) — 125건. 정본이다 | | 실행 메타 | [`evidence/meta/`](evidence/meta/) — 125건 | | 브라우저 캡처 | [`evidence/browser/`](evidence/browser/) — 22건 | | 그림 | [`assets/`](assets/) — techviz 로 만든 28건. 정본은 [`.techviz/`](.techviz/) 의 VizSpec | | 실험 목록 | [`../source/docs/experiment-index.md`](../source/docs/experiment-index.md) | | 로드맵 | [`../source/docs/experiment-plan.md`](../source/docs/experiment-plan.md) — 실험별 예측·판정 규칙 | | 개념 | [`../source/docs/session-lab-concepts.md`](../source/docs/session-lab-concepts.md) · [`../source/docs/session-lab-prerequisites.md`](../source/docs/session-lab-prerequisites.md) | 원본 저장소의 리비전은 [`../source/.source-revision`](../source/.source-revision) 에 적어 두었다. --- ## 이 기록에 아직 없는 것 **그림은 28건 모두 techviz 로 다시 만들었다.** 원본 저장소의 손그림 28개는 [`../source/docs/diagrams/`](../source/docs/diagrams/) 에 그대로 있다. 형식만 바꾼 것이 아니라 처음부터 다시 그렸다. 이 저장소는 발행 SVG 안에 제목·부제· 설명 밴드를 넣지 못하게 하는데 손그림은 전부 캔버스 안에 제목과 설명 문단을 담고 있었다. 그래서 그림 안에는 이름만 남기고 문장은 `` 와 옆 문단으로 옮겼으며, 각 그림마다 문서의 줄 범위를 인용하는 VizSpec 을 쓰고 lint 를 통과시켰다. lint 가 잡아낸 것 중 사람이 놓치기 쉬운 것 둘을 적어 둔다. | 검사 | 무엇을 막았나 | |---|---| | `edge-through-node` | 화살표가 무관한 노드를 관통해 잘못된 인접을 암시하는 것 | | `evidence-outside-prepared-context` | 그림이 다른 절의 내용을 근거로 대는 것 | 두 번째 때문에 그림 하나는 앵커를 옮겨야 했다. B-0 절에 앵커를 두고 B-2 의 내용을 인용하려다 막혔고, B-1 로 옮겨 세 절이 문맥에 들어오게 했다. **Studio 기록은 아직 쓰지 않았다.** 이 문서까지가 SSOT 이고 `tech-log-studio/` 아래 글감 추출과 기록 작성은 다음 단계이기 때문이다. --- ## 실험대가 쓴 개념 — 조사한 것 26건을 돌리면서 쓴 용어와, 그 용어를 실제로 설명한 곳을 대조했다. **이름만 쓰고 넘어간 것이 24개**였다. `conntrack` 은 실험 문서에 35번, `refresh token rotation` 은 17번, `JWKS` 와 `Liquibase` 는 각각 11번 나오는데 무엇인지 설명한 곳이 없었다. 여기서 그것들을 조사해 채운다. 시스템에서 확인할 수 있는 것은 확인했고, 확인할 수 없는 외부 사실은 출처를 달았다. --- ### 1층. 리눅스와 systemd — 이 실험대의 바닥 `systemctl` 을 명령으로만 여덟 번 썼고 무엇인지 설명한 적이 없다. 그런데 호스트 nginx·certbot 타이머·libvirtd·k3s 가 전부 이 위에서 돈다. #### 유닛 파일 — 서비스의 정의 **무엇인가.** systemd 가 관리하는 대상 하나를 기술한 파일이다. `.service` 말고도 `.timer`·`.socket`·`.target` 이 있고, 이 실험대에는 앞의 셋이 다 있다. ``` [Unit] 의존 관계와 순서 — After= · Wants= · Requires= [Service] 무엇을 어떻게 실행하나 — ExecStart= · Type= · Restart= [Install] enable 했을 때 어디에 걸리나 — WantedBy= ``` **왜 여기 나오나.** D-4 에서 갱신이 반영되지 않은 원인 셋 중 하나가 `certbot-renew.service` 에 `ExecStartPost` 가 없다는 것이었고, 그 판정은 유닛 파일을 읽어서 내렸다. **없거나 틀리면.** 배포판이 준 기본 유닛을 그대로 쓰면서 그 안에 무엇이 있는지 모르면, D-4 처럼 「타이머는 도는데 아무 일도 안 일어나는」 상태를 88일 동안 못 본다. **확인.** 두 명령이 다른 것을 보여 준다. ```bash systemctl cat nginx # 파일에 적힌 것 systemctl show nginx # 기본값까지 합쳐 실제로 적용되는 것 ``` `systemctl cat` 에 `Restart=on-failure` 만 있어도 `systemctl show` 는 `RestartUSec=100ms`·`StartLimitBurst=5` 같은 기본값을 함께 보여 준다. **적용값을 알려면 두 번째를 봐야 한다.** #### `Type=` — systemd 가 「떴다」고 판단하는 방식 **무엇인가.** 시작이 끝난 시점을 어떻게 아는지를 정한다. 이 호스트에서 실제로 쓰이는 값이 넷이다. | Type | 언제 「떴다」고 보나 | 이 호스트에서 | |---|---|---| | `simple` | `ExecStart` 프로세스를 띄운 즉시 | — | | `forking` | 부모가 끝나고 자식이 남았을 때 | **nginx** | | `notify` | 프로세스가 `sd_notify(READY=1)` 를 보냈을 때 | tailscaled | | `notify-reload` | notify + reload 신호도 알림 | sshd · libvirtd · journald | **왜 여기 나오나.** nginx 의 `systemctl status` 를 읽을 때 이 값이 출력을 설명한다. ``` Process: 584 ExecStart=/usr/bin/nginx (code=exited, status=0/SUCCESS) Main PID: 585 (nginx) ``` `forking` 이라 **시동 프로세스 584 는 끝나고**(`exited`) 실제 데몬은 585 로 남았다. `simple` 이었다면 584 가 그대로 Main PID 로 남는다. 어느 프로세스를 추적할지는 `PIDFile=/run/nginx.pid` 로 알려 준다. **없거나 틀리면.** `forking` 데몬을 `simple` 로 적으면 systemd 가 부모가 끝난 것을 죽은 것으로 보고 재시작을 반복한다. 반대로 `simple` 데몬을 `forking` 으로 적으면 영원히 시작을 기다린다. **확인.** ```bash systemctl show nginx -p Type -p MainPID -p PIDFile --value ``` #### `Restart=` — 죽으면 어떻게 되는가 호스트 nginx 가 죽으면 어떻게 되는지가 이 한 줄에 있다. ``` Restart=on-failure RestartUSec=100ms StartLimitBurst=5 StartLimitIntervalUSec=10s ``` **무엇인가.** 프로세스가 끝났을 때 systemd 가 다시 띄울지 정한다. | 값 | 다시 띄우는 경우 | |---|---| | `no` | 없다 (기본값) | | `on-failure` | 0 아닌 종료 코드 · 시그널 사망 · 타임아웃 | | `on-abnormal` | 시그널 사망과 타임아웃만. 종료 코드는 무시 | | `always` | 정상 종료를 포함해 언제나 | 이 호스트에서도 갈린다 — nginx·tailscaled·libvirtd 는 `on-failure`, sshd 와 journald 는 `always` 다. **접속 경로와 로그 수집은 어떤 이유로 꺼져도 되살아나야 하기 때문**이다. **없거나 틀리면 — 이쪽이 중요하다.** `on-failure` 라도 무한히 되살리지는 않는다. `StartLimitIntervalUSec=10s` 안에 `StartLimitBurst=5` 번 실패하면 systemd 가 **포기하고 `failed` 로 둔다.** 설정이 깨져 기동이 반복 실패하는 상황이 정확히 여기에 해당하며, 그때는 자동 복구를 기다려도 오지 않는다. ```bash systemctl reset-failed nginx && systemctl start nginx # 상한에 걸린 뒤 되살리는 법 ``` **확인.** ```bash systemctl show nginx -p Restart -p RestartUSec -p StartLimitBurst -p StartLimitIntervalUSec systemctl is-failed nginx # failed 면 상한에 걸렸을 수 있다 ``` > **이것은 설정을 읽은 것이지 측정한 것이 아니다.** 이 실험대가 스물여섯 번 > 배운 것이 「설정이 그렇다고 그렇게 동작하지는 않는다」이므로, 실제로 > 죽여 봐야 안다. 아직 하지 않았다. #### `KillMode=` · `KillSignal=` — 멈출 때 **무엇인가.** 정지 신호를 **누구에게** 보낼지(`KillMode`)와 **무엇을** 보낼지(`KillSignal`)를 정한다. | KillMode | 신호를 받는 대상 | 이 호스트에서 | |---|---|---| | `control-group` | cgroup 안 **모든** 프로세스 (기본값) | tailscaled · journald | | `mixed` | 주 프로세스에 먼저, 남으면 그룹 전체에 SIGKILL | **nginx** | | `process` | 주 프로세스만 | sshd · libvirtd | nginx 는 `KillSignal=SIGQUIT` 이다. **nginx 에서 SIGQUIT 은 graceful shutdown** — 진행 중 요청을 끝내고 종료하라는 뜻이고, SIGTERM(즉시 종료)과 다르다. `mixed` 와 짝이 되어 「마스터에게 곱게 끝내라고 하고, 5초 (`TimeoutStopSec=5`) 안에 안 끝나면 그룹 전체를 SIGKILL」이 된다. **왜 여기 나오나.** D-4a 에서 잰 reload 무중단(진행 중이던 42초 요청이 845361바이트를 온전히 받았다)과 **같은 성질이 종료에도 걸려 있다.** 다만 종료 쪽은 재보지 않았다. **확인.** ```bash systemctl show nginx -p KillMode -p KillSignal -p TimeoutStopUSec --value ``` **없거나 틀리면.** `KillMode=control-group` 에 SIGTERM 을 쓰면 마스터와 워커가 동시에 죽어 **진행 중이던 요청이 잘린다.** 반대로 `process` 로 두면 마스터만 죽고 워커가 고아로 남는다. nginx 가 `mixed` + SIGQUIT 인 것은 그 사이를 고른 결과다. #### cgroup v2 — 프로세스를 묶어 재고 제한한다 **무엇인가.** 커널이 프로세스를 계층 구조로 묶어 **자원을 측정하고 제한하는** 기능이다. 이 호스트는 v2(통합 계층)를 쓴다. ``` $ stat -fc %T /sys/fs/cgroup cgroup2fs $ cat /sys/fs/cgroup/cgroup.controllers cpuset cpu io memory hugetlb pids rdma misc dmem ``` **왜 여기 나오나.** systemd 는 서비스마다 cgroup 을 하나 만들고 그 안에 프로세스를 넣는다. 그래서 `systemctl status` 가 이것을 보여 준다. ``` CGroup: /system.slice/nginx.service ├─ 585 "nginx: master process /usr/bin/nginx" └─37252 "nginx: worker process" ``` **D-4 와 바로 연결된다.** 그때 「마스터 PID 유지 + 워커 PID 교체 = reload」를 `ps` 로 판정했는데, 이 블록이 같은 것을 바로 보여 준다 — 마스터 585 는 9월 3일 그대로이고 워커만 37252 로 바뀌어 있다. `status` 의 숫자는 전부 cgroup 파일에서 읽은 값이다. ``` /sys/fs/cgroup/system.slice/nginx.service/ cgroup.procs 585 37252 → status 의 CGroup 블록 pids.current 2 → Tasks: 2 pids.max 13938 → (limit: 13938) memory.current 7376896 → Memory: 7M memory.max max → 제한 없음 cpu.stat usage_usec 23222723 → CPU: 23.222s ``` **없거나 틀리면.** cgroup 없이 데몬을 관리하면 fork 한 자식을 놓친다. PID 파일 하나만 보고 `kill` 하던 옛 init 스크립트가 좀비 워커를 남기던 문제가 이것이고, **쿠버네티스의 컨테이너 자원 제한도 같은 메커니즘**이다. A-6 에서 파드에 건 메모리 제한이 결국 이 파일들에 쓰인다. **확인.** ```bash systemd-cgls /system.slice/nginx.service cat /sys/fs/cgroup/system.slice/nginx.service/memory.current ``` #### slice — cgroup 의 계층 **무엇인가.** systemd 는 cgroup 트리를 세 갈래로 나눠 쓴다. | slice | 무엇이 들어가나 | |---|---| | `system.slice` | 시스템 서비스 — nginx 는 여기 | | `user.slice` | 로그인 사용자 세션 | | `machine.slice` | VM 과 컨테이너 — **kc-lab-1/2 가 여기 들어간다** | 자원 제한은 계층을 따라 상속되므로, slice 에 제한을 걸면 그 아래 서비스 전부에 걸린다. VM 두 대의 메모리 재배분이 `machine.slice` 아래에서 일어난다. **왜 여기 나오나.** VM 두 대의 메모리를 실행 중에 재배분할 때 그 조정이 `machine.slice` 아래에서 일어난다. 호스트가 12GB 뿐이라 이 실험대에서는 게스트 메모리를 몇 번 옮겼다. **없거나 틀리면.** slice 에 제한을 걸어 두고 그 아래 서비스만 보면 원인을 못 찾는다. 서비스의 `MemoryMax` 가 `infinity` 인데도 OOM 이 나면 상위 slice 쪽을 봐야 한다. **확인.** ```bash systemd-cgls # 전체 트리 systemctl show nginx -p Slice --value cat /sys/fs/cgroup/machine.slice/memory.max # VM 들이 받은 상한 ``` #### journald — 로그는 어디로 가나 **무엇인가.** systemd 의 로그 수집기다. 서비스의 stdout·stderr 와 syslog 를 한곳에 모으고 **어느 유닛에서 나왔는지**를 메타데이터로 붙인다. 그래서 `-u` 로 유닛별 조회가 된다. ```bash journalctl -u nginx -f # 실시간 journalctl -u nginx --since '1 hour ago' -p err # 에러만 journalctl -u nginx -o json-pretty | head # 메타데이터까지 ``` **왜 여기 나오나 — 그리고 이 실험대가 치른 대가.** `systemctl status nginx` 가 하단에 최근 로그를 붙여 주는데, 거기 이것이 있다. ``` Sep 04 14:37:44 nginx[586]: [error] upstream sent too big header while reading response header from upstream, ... request: "GET /oauth2/callback?state=..." ``` **B-7 이 502 의 원인으로 지목한 것을 호스트 nginx 가 문장으로 적어 두었다.** B-7 은 계층을 나눠(traefik 을 직접 불러 nginx 를 우회) 원인을 좁혔다고 기록했는데, 증거는 저널에 있었고 증거 파일 147개 중 이것을 담은 것은 없다. `no live upstreams` 라인도 함께 찍혀 있다 — 노드를 잃었을 때 호스트에서 그렇게 보인다. **없거나 틀리면.** 파드 로그와 클러스터 지표만 보면 **호스트 계층에서 잘린 요청이 안 보인다.** B-7 의 502 가 그랬다. **확인.** ```bash journalctl -u nginx --since '1 hour ago' -p err # 에러만 journalctl --disk-usage # 얼마나 쌓였나 journalctl -u nginx --no-pager | grep 'too big header' # B-7 이 놓친 줄 ``` #### PID 1 의 시그널 보호 **무엇인가.** 커널은 PID 1 에게 **핸들러를 등록하지 않은 시그널을 전달하지 않는다.** SIGKILL·SIGSTOP 도 같은 네임스페이스 안에서는 무시된다. ``` $ ps -p 1 -o comm,args systemd /usr/lib/systemd/systemd --switched-root --system --deserialize=56 ``` **왜 여기 나오나.** A-3 에서 PostgreSQL 을 크래시시키려고 컨테이너 안에서 `kill -9 1` 을 보냈는데 아무 일도 없었다. 컨테이너의 PID 1 이 postmaster 였고, **자기 네임스페이스 안에서 온 SIGKILL 을 무시**했기 때문이다. **없거나 틀리면.** 「죽였는데 안 죽었다」를 「영향이 없다」로 읽게 된다. A-3 의 아홉 실패 중 하나가 이것이었다. **확인.** 백엔드 프로세스를 죽여 postmaster 가 `reinitialize` 하게 만들면 비로소 크래시 복구가 일어난다. ```bash kubectl exec deploy/postgres -- pkill -9 -f 'postgres: keycloak' kubectl logs deploy/postgres | grep -i 'not properly shut down\|redo starts' ``` #### `PrivateTmp=true` **무엇인가.** 서비스에 **자기만의 `/tmp`** 를 준다. 마운트 네임스페이스를 따로 만들어 다른 프로세스의 `/tmp` 와 격리한다. **왜 여기 나오나.** nginx 와 `certbot-renew.service` **양쪽 다 켜져 있다.** D-4 에서 certbot 출력을 `/tmp` 로 받아 읽으려 했다면 찾지 못했을 텐데, 실제로는 사람이 대화형으로 실행해 파일이 진짜 `/tmp` 에 떨어졌다. **확인.** ```bash systemctl show nginx -p PrivateTmp --value ``` **없거나 틀리면.** 서비스가 `/tmp` 에 쓴 파일을 밖에서 찾다가 없어서 헤맨다. 반대로 이 격리가 없으면 서로 다른 서비스가 `/tmp` 에서 충돌하거나, 예측 가능한 파일 이름을 통한 공격이 가능해진다. --- ### 2층. 네트워크 — netfilter 와 conntrack A층 실험의 주입이 전부 이 층에서 이루어졌고, 아홉 번의 조용한 실패 중 넷이 이 층을 몰라서 생겼다. #### conntrack — 연결을 기억하는 표 **무엇인가.** 커널이 지나간 연결을 기억하는 표다. 패킷 하나하나를 따로 보지 않고 **어느 연결에 속하는지**를 먼저 판정하며, 그 판정 결과가 `ctstate` 다. | 상태 | 뜻 | |---|---| | `NEW` | 이 연결의 첫 패킷 | | `ESTABLISHED` | 양방향이 오간 연결의 후속 패킷 | | `RELATED` | 기존 연결에 딸린 새 연결 (FTP 데이터 채널 등) | | `INVALID` | 어디에도 속하지 않음 | kc-lab-1 의 실물이다. ``` $ sudo conntrack -L | awk '{print $4}' | sort | uniq -c 229 TIME_WAIT 54 ESTABLISHED 5 CLOSE 총 311 / 상한 131072 ``` **왜 여기 나오나 — A-1 의 주입이 25분 동안 안 먹은 이유가 이것이다.** 쿠버네티스 규칙이 전부 `NEW` 에만 걸려 있다. ``` $ sudo iptables -S FORWARD -A FORWARD -m comment --comment "kube-router netpol ..." -j KUBE-ROUTER-FORWARD -A FORWARD -m conntrack --ctstate NEW -j KUBE-PROXY-FIREWALL -A FORWARD -m conntrack --ctstate NEW -j KUBE-SERVICES ``` 이미 성립한 JGroups 연결의 패킷은 `ESTABLISHED` 라서 **NetworkPolicy 평가 자체에 도달하지 않는다.** 규칙은 정확히 걸렸고 패킷이 그 앞에서 지나갔다. **얼마나 오래 버티나 — 이 숫자가 답이다.** ``` $ cat /proc/sys/net/netfilter/nf_conntrack_tcp_timeout_established 86400 ``` **24시간.** 오가는 패킷이 있으면 타이머가 계속 갱신되므로, JGroups 처럼 주기적으로 통신하는 연결은 **사실상 영원히** 표에 남는다. `cluster_size` 가 25분간 2로 남은 것이 이상한 일이 아니라 정상 동작이었다. **없거나 틀리면.** 「규칙을 넣었는데 아무 일도 없다」를 「영향이 없다」로 읽는다. A-1 에서 실제로 그럴 뻔했다. **확인.** ```bash sudo conntrack -L | grep 7800 # 항목이 남아 있으면 주입이 안 걸린다 sudo conntrack -D -p tcp -s -d --sport --dport ``` #### netfilter 처리 순서 — `raw` 가 먼저인 이유 **무엇인가.** 패킷 하나가 커널을 지나며 여러 테이블을 순서대로 통과한다. 들어오는 패킷 기준이다. ``` 패킷 도착 ↓ raw PREROUTING ← conntrack 보다 먼저 ↓ [ conntrack 이 여기서 상태를 붙인다 ] ↓ mangle PREROUTING ↓ nat PREROUTING ← DNAT ↓ 라우팅 판정 ↓ filter FORWARD ← NetworkPolicy · iptables 규칙 대부분 ``` **왜 여기 나오나.** A-5 에서 `filter` 로는 `ESTABLISHED` 를 막을 수 없다는 것이 확인된 뒤, **conntrack 이 상태를 붙이기 전에** 잡으려고 `raw` 테이블 PREROUTING 으로 옮겼다. 그러자 걸렸다. ```bash sudo iptables -t raw -I PREROUTING 1 -p tcp -d <파드IP> --dport 7800 -j DROP ``` **없거나 틀리면.** `filter` 에서 아무리 정확한 규칙을 써도 이미 성립한 연결에는 닿지 않는다. 테이블을 바꾸는 것이 규칙을 고치는 것보다 먼저다. **확인.** ```bash sudo iptables -t raw -S PREROUTING sudo iptables -t raw -L PREROUTING -v -n # 패킷 카운터가 오르는지 ``` #### kube-router 의 체인 재삽입 **무엇인가.** k3s 의 NetworkPolicy 컨트롤러가 자기 체인을 FORWARD **맨 위에** 유지한다. 사람이 그 위에 규칙을 넣어도 컨트롤러가 조정할 때 다시 밀려난다. ``` -A FORWARD -m comment --comment "kube-router netpol - TEMCG2JMHZYE7H7T" -j KUBE-ROUTER-FORWARD ``` **왜 여기 나오나.** A-5 에서 `iptables -I FORWARD 1` 로 넣은 규칙의 패킷 카운터가 0 이었다. 규칙이 사라진 것이 아니라 **kube-router 체인 아래로 내려가 도달하지 않았다.** **확인.** 규칙을 넣은 뒤 위치와 카운터를 둘 다 본다. ```bash sudo iptables -S FORWARD | head -3 # 내 규칙이 몇 번째인가 sudo iptables -L FORWARD -v -n | head -5 # 카운터가 0 이면 도달하지 않았다 ``` **없거나 틀리면.** 규칙이 목록에 보이므로 「넣었다」로 판단하고 결과를 읽는다. 목록에 있는 것과 패킷이 도달하는 것은 다르다. #### flannel VXLAN — 파드 IP 가 물리 인터페이스에 안 보이는 이유 **무엇인가.** 파드 사이 통신을 UDP 로 감싸 노드 사이를 건넌다. 물리 인터페이스(`enp1s0`)에서 보면 **노드 IP 사이의 UDP 패킷**이고 안쪽 파드 IP 는 캡슐 안에 있다. **왜 여기 나오나.** A-5 에서 `tc ... dev enp1s0` 로 파드 IP 를 필터하려 했는데 불가능했다. 캡슐화가 이미 끝난 뒤라 그 IP 가 헤더에 없기 때문이다. **`flannel.1`**(VXLAN 인터페이스)에서 필터해야 안쪽 주소가 보인다. 여기에 배포판 차이가 겹쳤다 — Debian 게스트의 인터페이스는 `eth0` 이 아니라 `enp1s0` 이다. 실패 하나에 원인이 둘이었다. **없거나 틀리면.** 물리 인터페이스에서 파드 IP 로 필터를 걸고 「걸렸다」고 믿게 된다. 규칙은 문법상 유효하고 매칭만 영원히 0 이다. **확인.** ```bash ip -d link show flannel.1 # vxlan id 와 물리 인터페이스 sudo tcpdump -i enp1s0 -n udp port 8472 -c 3 # 캡슐 바깥 — 노드 IP 만 보인다 sudo tcpdump -i flannel.1 -n -c 3 # 캡슐 안 — 파드 IP 가 보인다 ``` --- ### 3층. PostgreSQL — 성공 응답과 디스크 사이 A-3 이 잰 「200 을 받은 로그인 153건 중 4건이 DB 에 없다」가 이 층의 개념 셋으로 설명된다. #### WAL — 데이터 파일보다 로그를 먼저 쓴다 **무엇인가.** Write-Ahead Logging. 데이터 파일을 고치기 **전에** 변경 기록을 로그에 먼저 쓴다. 크래시 후에는 그 로그를 재생(redo)해 복구한다. A-3 에서 본 `not properly shut down` · `redo starts` 가 그 재생이다. 순서는 이렇다. ``` INSERT ↓ WAL 레코드를 공유 버퍼에 쓴다 ← 아직 메모리 ↓ COMMIT ↓ WAL 을 디스크에 flush ← synchronous_commit 이 정하는 지점 ↓ 클라이언트에 성공 응답 (데이터 파일 자체는 나중에 체크포인트에서) ``` **왜 여기 나오나.** A-3 에서 PostgreSQL 을 크래시시킨 뒤 로그에 나온 것이 이 재생 과정이다. ``` database system was not properly shut down; automatic recovery in progress redo starts at 0/... ``` **없거나 틀리면.** 「COMMIT 이 반환됐다」를 「디스크에 남았다」로 읽는다. 둘 사이에 flush 라는 단계가 있고, 그 단계를 건너뛸 수 있게 하는 설정이 바로 다음 항목이다. **확인.** ```bash kubectl logs deploy/postgres | grep -i 'redo starts\|not properly shut down' ``` #### `synchronous_commit` — 그 flush 를 기다릴 것인가 **무엇인가.** COMMIT 이 **WAL 디스크 flush 를 기다린 뒤** 반환할지 정한다. | 값 | COMMIT 이 반환되는 시점 | 잃을 수 있는 것 | |---|---|---| | `on` (기본) | WAL 이 디스크에 닿은 뒤 | 없음 | | `off` | 즉시. flush 는 나중에 | **최근 트랜잭션 일부** | | `local` | 로컬 flush 만 기다림 (복제 대기 안 함) | 복제본 지연분 | **왜 여기 나오나.** 서버 전역은 `on` 인데, **Keycloak 이 트랜잭션마다 `SET LOCAL synchronous_commit TO OFF` 를 건다.** 세션 쓰기를 빠르게 하려는 의도된 설계이고, A-3 은 그 대가를 숫자로 쟀다. **없거나 틀리면.** RPO 를 0 으로 가정하게 된다. 실제로는 「200 을 받았는데 없는」 세션이 생기고, 사용자에게는 방금 로그인했는데 다시 로그인하라는 화면으로 나타난다. **확인.** ```sql SHOW synchronous_commit; -- 전역값 -- 세션별로 다를 수 있으므로 문장 로깅으로 SET LOCAL 을 잡는다 ``` #### `wal_writer_delay` — 그 사이가 얼마나 되나 **무엇인가.** WAL writer 프로세스가 깨어나 버퍼를 flush 하는 주기다. `synchronous_commit=off` 일 때 **잃을 수 있는 시간의 크기**를 정한다. 이 실험대의 실측값은 **200ms**(기본값)였고, A-3 은 그것을 단언하지 않고 재서 확인했다. 처음 문서는 재지 않고 적었다가 나중에 고쳤다. **왜 여기 나오나.** `synchronous_commit=off` 에서 잃을 수 있는 양이 이 값으로 정해진다. A-3 의 유실 4건이 이 창 안에 들어온 로그인들이다. **없거나 틀리면.** RPO 를 재지 않고 「거의 0」으로 가정하게 된다. 값을 알면 「최악의 경우 200ms 분량」이라는 상한을 말할 수 있다. **확인.** ```bash kubectl exec deploy/postgres -- psql -U keycloak -tAc 'show wal_writer_delay' ``` #### fsync 와 페이지 캐시 **무엇인가.** `write()` 는 커널 페이지 캐시까지만 쓰고 끝난다. 디스크에 닿게 하려면 `fsync()` 가 따로 필요하다. **「썼다」와 「남았다」가 다르다.** **왜 여기 나오나.** B-5 에서 Redis 의 `appendonly yes` 가 아무것도 바꾸지 못한 것도 같은 계열이다. 거기서는 한 단계 더 밖 — `/data` 가 컨테이너 파일시스템이라 **fsync 를 해도 컨테이너와 함께 사라졌다.** **없거나 틀리면.** 벤치마크에서 「쓰기가 빠르다」는 결과를 얻고 실제 내구성은 그만큼 없는 상태로 운영에 올린다. B-5 의 Redis 가 그 모양이었다. **확인.** ```bash kubectl exec deploy/redis -- redis-cli config get appendfsync # everysec 이 기본 kubectl exec deploy/redis -- sh -c 'ls -la /data' # 볼륨인지 컨테이너 fs 인지 kubectl get pod -l app=redis -o jsonpath='{.items[0].spec.volumes}' ``` #### 낙관적 락과 `VERSION` 컬럼 **무엇인가.** 행을 잠그지 않고 읽은 뒤, 갱신할 때 `VERSION` 이 그대로인지 확인한다. 바뀌었으면 누가 먼저 고친 것이므로 충돌로 처리한다. **왜 여기 나오나.** A-6 에서 낙관적 락 충돌이 보일 것으로 예측했는데 **0건**이었다. 로그인은 세션 행을 **INSERT** 하지 UPDATE 하지 않아 경합할 대상이 없기 때문이다. 예측이 틀린 이유가 락 구현이 아니라 **연산의 종류**에 있었다. **없거나 틀리면.** 「동시 로그인이 많으면 락 충돌이 난다」로 예측하고 그것을 튜닝하려 든다. A-6 에서 예측이 빗나간 뒤에야 연산이 INSERT 라는 것이 보였다. **확인.** ```sql select count(*) from pg_stat_database_conflicts; -- 그리고 무엇이 UPDATE 되는지는 문장 로깅으로 본다 ``` #### Liquibase 와 `databasechangelog` **무엇인가.** 스키마 변경을 changeset 단위로 적용하고, 적용한 것을 `databasechangelog` 테이블에 기록한다. 각 행에는 **그 changeset 내용의 체크섬**이 들어간다. 기동할 때 파일의 체크섬과 테이블의 체크섬을 대조해 다르면 멈춘다. **왜 여기 나오나.** D-2 에서 26.7.3 으로 올렸다가 되돌릴 때 이것이 막았다. ``` liquibase ValidationFailedException: 1 changesets check sum ``` 새 버전이 남긴 행을 옛 버전이 자기 파일과 대조했는데 맞지 않았다. **그래서 판정 기준이 하나로 정해진다.** ```sql select count(*) from databasechangelog; -- 업그레이드 전후로 같으면 롤백된다 ``` 이것이 「롤백 불가」를 「스키마가 움직였을 때만 불가」로 정밀화한 근거다. **없거나 틀리면.** 「롤백 계획이 있다」고 적어 두고 실제로는 동작하지 않는다. D-2 에서 그 계획이 기동 단계에서 막혔다. **확인.** ```sql select count(*) from databasechangelog; -- 업그레이드 전후 비교 select id, author, md5sum from databasechangelog order by orderexecuted desc limit 3; ``` --- ### 4층. 쿠버네티스 — 죽은 것을 알아채기까지 #### 노드 축출 타이머 두 개 **무엇인가.** 노드가 죽었을 때 파드가 옮겨지기까지 두 단계를 거친다. | 설정 | 값 | 무엇을 정하나 | |---|---|---| | `node-monitor-grace-period` | 40초 | 컨트롤러가 노드를 `NotReady` 로 판정하기까지 | | `tolerationSeconds` | 300초 | `NotReady` taint 를 파드가 견디는 시간 | 합쳐서 **5분 40초**다. A-4 에서 잰 「장애 시간의 대부분은 복구가 아니라 알아채는 데 걸린 시간」이 이 숫자다. **없거나 틀리면.** 노드가 죽은 순간 파드가 옮겨질 것으로 기대하게 된다. 실제로는 6분 가까이 아무 일도 일어나지 않는다. **왜 여기 나오나.** A-4 에서 노드를 죽인 뒤 아무 일도 일어나지 않는 구간이 길었다. 고장이 아니라 이 두 타이머가 도는 중이었다. **확인.** ```bash kubectl get nodes -w # NotReady 로 바뀌는 시점 kubectl get pod -o jsonpath='{.spec.tolerations}' # tolerationSeconds ``` #### 죽은 파드가 더 건강해 보이는 이유 **무엇인가.** 파드 상태는 **그 노드의 kubelet 이 보고**한다. 노드가 죽으면 보고하는 주체가 사라지므로 **아무도 그 상태를 갱신하지 못한다.** 그래서 A-4 에서 죽은 노드의 파드가 `Running` 으로 보이고, 살아 있지만 DB 를 잃은 파드가 `CrashLoopBackOff` 로 보였다. **화면이 진실의 역순이었다.** **왜 여기 나오나.** A-4 에서 화면을 그대로 믿었다면 살아 있는 쪽을 장애로, 죽은 쪽을 정상으로 판단했을 것이다. **없거나 틀리면.** `kubectl get pods` 의 STATUS 를 실시간 진실로 읽는다. 그 값은 **마지막으로 보고된 것**이지 지금 상태가 아니다. **확인.** ```bash kubectl get pods -o wide # NODE 열을 함께 본다 kubectl get nodes # 그 노드가 Ready 인가 kubectl describe pod | grep -i 'last transition' ``` #### StatefulSet 이 대체 파드를 만들지 않는 것 **무엇인가.** StatefulSet 은 파드 이름이 안정적이어야 한다(`keycloak-0`). 같은 이름을 두 개 띄울 수 없으므로, `Terminating` 인 파드가 완전히 지워지기 전에는 대체를 만들지 않는다. 노드가 죽어 지워지지 못하면 **무한히 기다린다.** Deployment 는 이름이 임의라 이 제약이 없다. **워크로드 종류를 고른 것이 장애 시 동작을 고른 것이기도 하다.** **왜 여기 나오나.** A-4 에서 대체 파드를 기다렸는데 오지 않았다. 컨트롤러가 고장 난 것이 아니라 이름 규약을 지키고 있었다. **없거나 틀리면.** 「자동 복구가 안 된다」로 오진하고 컨트롤러를 의심한다. 실제로는 `Terminating` 을 풀어 주어야 한다. **확인.** ```bash kubectl get pods -l app=keycloak # Terminating 이 남아 있는가 kubectl delete pod keycloak-0 --grace-period=0 --force # 강제로 이름을 비운다 ``` #### NetworkPolicy 는 허용 목록이다 **무엇인가.** 「무엇을 막을지」가 아니라 **「무엇을 허용할지」**를 쓴다. 파드가 `policyTypes: [Ingress]` 를 가진 정책에 선택되는 순간, 규칙에 적힌 것 말고는 전부 막힌다. `deny 7800` 같은 규칙은 쓸 수 없다. **왜 여기 나오나.** A-1 은 8080·9000 만 허용하고 **7800 을 목록에서 빼는** 방식으로 막았다. 그래서 그 두 포트가 하중을 진다 — 9000(health·metrics)을 빠뜨리면 kubelet 이 파드를 죽여서 **분단이 아니라 죽은 Keycloak 을 재게 된다.** **없거나 틀리면.** 「7800 을 막는 규칙」을 찾다가 없어서 NetworkPolicy 로는 안 된다고 결론 내린다. 실제로는 빼는 방식으로 막는다. **확인.** ```bash kubectl -n keycloak-lab describe networkpolicy # 허용된 포트만 나온다 ``` #### `enableServiceLinks` **무엇인가.** 쿠버네티스는 같은 네임스페이스의 Service 마다 Docker link 시절의 환경변수를 자동 주입한다. ``` REDIS_PORT=tcp://10.43.57.116:6379 ``` **왜 여기 나오나.** B-1 에서 이것이 `application.yml` 의 `${REDIS_PORT:6379}` 를 덮어써 기동이 실패했다. ``` Failed to bind properties under 'spring.data.redis.port' to int: Value: "tcp://10.43.57.116:6379" ``` **이름을 바꿔 피하면 다음 사람이 같은 함정에 빠진다.** 주입 자체를 끄는 것이 근본 처방이다 — `enableServiceLinks: false`. **없거나 틀리면.** 설정 이름과 겹치는 Service 를 만드는 순간 기동이 깨지는데, 원인이 애플리케이션 설정처럼 보인다. **확인.** ```bash kubectl exec -- env | grep '_PORT=' # tcp:// 로 시작하면 주입된 것이다 ``` --- ### 5층. Keycloak — 세션과 토큰 #### refresh token rotation — 재사용이 감지되면 세션이 사라진다 **무엇인가.** 토큰 갱신에 성공하면 Keycloak 이 새 refresh token 을 발급하고 **옛것을 소비된 것으로 표시**한다. 소비된 토큰이 다시 오면 재사용으로 본다. | 설정 | 뜻 | |---|---| | `revokeRefreshToken` | 회전을 켠다. 옛 토큰을 소비 처리 | | `refreshTokenMaxReuse=0` | 한 번만 쓸 수 있다 (가장 엄격) | | `refreshTokenMaxReuse=1` | 같은 토큰을 두 번까지 허용 — 네트워크 재시도를 견디려는 값 | **왜 여기 나오나 — B-3 의 결과가 여기서 설명된다.** 재사용이 감지되면 Keycloak 은 그 토큰만 막는 것이 아니라 **SSO 세션 전체를 무효화한다.** 그래서 동시 5건 중 이긴 요청이 받은 새 토큰조차 쓸 수 없었다. 새 토큰이 잘못된 것이 아니라 **그 토큰이 속한 세션이 방금 지워졌기** 때문이다. 「하나는 성공하고 나머지가 실패한다」가 아니라 **전부 못 쓰게 된다**는 관측이 규격대로였다. **없거나 틀리면.** 재시도 로직을 「실패한 요청만 다시 보내면 된다」로 설계하게 된다. 실제로는 전부 재인증해야 한다. **확인.** ```bash kcadm get realms/ --fields revokeRefreshToken,refreshTokenMaxReuse ``` > `refreshTokenMaxReuse` 를 0 보다 크게 두는 것은 재시도를 견디려는 > 절충이며, 그만큼 탈취된 토큰의 재사용 창도 열린다. #### 세션은 두 겹이다 **무엇인가.** Keycloak 이 갖는 세션과 애플리케이션이 갖는 세션이 다르다. | | 어디에 | 무엇을 담나 | |---|---|---| | SSO 세션 | Keycloak | 이 브라우저가 누구로 로그인했는가. `KEYCLOAK_IDENTITY` 쿠키 | | 클라이언트 세션 | Keycloak | 그 SSO 세션이 어느 클라이언트에 대해 발급했는가 | | 애플리케이션 세션 | 앱 (BFF·oauth2-proxy) | 앱이 자기 사용자를 기억하는 것 | `sid` 는 SSO 세션의 식별자이고 **JWT·DB 행·관리 API 를 잇는 키**다. A-3 에서 RPO 를 잴 때 클라이언트가 받은 `sid` 를 DB 의 `OFFLINE_USER_SESSION.user_session_id` 와 대조할 때 이 연결을 썼다. **왜 여기 나오나.** B-7 에서 secret 을 바꿨을 때 사용자가 **로그인 화면을 보지 않고** 통과한 이유가 이 구조다. 애플리케이션 세션(oauth2-proxy 쿠키)은 죽었지만 SSO 세션은 살아 있어 조용히 재인증됐다. **없거나 틀리면.** 앱 세션을 지우고 「로그아웃됐다」고 판단한다. SSO 세션이 남아 있으면 다음 요청에서 조용히 다시 로그인된다. **확인.** ```bash # SSO 세션 쪽 kubectl exec deploy/postgres -- psql -U keycloak -tAc \ "select count(*) from offline_user_session where offline_flag='0'" # 앱 세션 쪽 kubectl exec deploy/redis -- redis-cli dbsize ``` #### `CLIENT_SCOPE_CLIENT` 와 `DEFAULT_SCOPE` **무엇인가.** 클라이언트가 갖는 스코프가 두 종류다. | | `DEFAULT_SCOPE` | 언제 붙나 | |---|---|---| | default scope | `t` | 항상 | | **optional scope** | **`f`** | 요청이 `scope=` 로 달라고 할 때만 | **왜 여기 나오나.** A-7a 에서 volatile 모드의 refresh 가 쏘는 SQL 이 딱 이 한 문장이었다. ```sql select cscme1_0.SCOPE_ID from CLIENT_SCOPE_CLIENT cscme1_0 where cscme1_0.CLIENT_ID=$1 and cscme1_0.DEFAULT_SCOPE=$2 -- $2 = 'f' ``` refresh 는 새 access token 에 어떤 스코프를 담을지 다시 계산하는데, 그 목록이 이 테이블에 있다. 로그인은 이미 결정된 것을 쓰므로 조회하지 않는다. **그래서 로그인은 SQL 0개, refresh 는 1개**가 된다. **없거나 틀리면.** refresh 가 DB 를 본다는 사실을 모르면 A-7a 의 500 을 세션 문제로 오진한다. 실제로는 스코프 조회가 막힌 것이다. **확인.** ```sql select client_id, default_scope, count(*) from client_scope_client group by 1,2; ``` #### 디스커버리와 트랜스포트 **무엇인가.** 노드가 서로를 **찾는 경로**와 실제로 **이야기하는 경로**가 다르다. ``` 디스커버리 PostgreSQL 의 JGROUPS_PING 테이블 트랜스포트 TCP 7800 ``` **왜 여기 나오나.** A-1 이 7800 만 막았을 때 둘 다 DB 에 등록된 채로 남아 서로 존재한다고 믿지만 메시지는 오가지 않는 상태가 만들어졌다. 그리고 세션은 DB 에 있으므로 교차 노드 refresh 는 200 을 유지했고, **로그아웃 무효화 통지만 끊겼다.** **없거나 틀리면.** 「클러스터가 형성됐다」를 「메시지가 오간다」로 읽는다. `JGROUPS_PING` 에 둘 다 있어도 7800 이 막혀 있으면 통지가 끊긴다. **확인.** ```bash kubectl exec deploy/postgres -- psql -U keycloak -c 'select name, ip from jgroups_ping' curl -s localhost:9000/metrics | grep vendor_cluster_size ``` #### 백채널 로그아웃 **무엇인가.** 사용자가 한 앱에서 로그아웃하면 IdP 가 **다른 앱에 서버 대 서버로 통지**해 그쪽 세션도 끝내는 규격이다. 양쪽이 다 있어야 한다. | 쪽 | 필요한 것 | |---|---| | IdP | 클라이언트의 `backchannelLogoutUrl` | | 앱 | 그 URL 을 받아 세션을 지우는 엔드포인트 | **왜 여기 나오나.** C-2 에서 **둘 다 없었다.** IdP 쪽만 채워도 앱 세션이 남는 이유가 이것이고, Keycloak 파드에서 앱 URL 로 요청하면 200 이 오므로 네트워크 문제와 구별된다. **없거나 틀리면.** IdP 쪽만 채우고 「설정했다」로 끝낸다. C-2 에서 그렇게 하면 앱 세션이 그대로 남는 것을 확인했다. **확인.** ```bash kcadm get clients -r --fields clientId,attributes | grep -i backchannel # 그리고 앱 쪽에 수신 엔드포인트가 있는지 소스에서 확인한다 ``` --- ### 6층. Spring — 두 저장 대상 #### 세션과 인가된 클라이언트는 조회 키가 다르다 **무엇인가.** Spring Security 가 로그인 뒤 유지하는 것이 둘이고, **찾는 방법이 다르다.** | | 담는 것 | 조회 키 | 기본 구현 | |---|---|---|---| | Application Session | 누가 로그인했는가 | **세션 id** | 서블릿 컨테이너 메모리 | | `OAuth2AuthorizedClient` | access · refresh token | **principal 이름** | `InMemoryOAuth2AuthorizedClientService` | B-0 에서 `/actuator/beans` 로 확인한 실물이다. ``` authorizedClientService → InMemoryOAuth2AuthorizedClientService authorizedClientRepository → AuthenticatedPrincipalOAuth2AuthorizedClientRepository SessionRepository → 없음 ``` **이름이 곧 설명이다** — `AuthenticatedPrincipal…Repository` 는 principal 기준으로 찾으므로 **조회 키에 세션 id 가 없다.** **왜 여기 나오나.** B-1 에서 `SPRING_SESSION_STORE_TYPE=redis` 로 세션만 옮겼을 때 토큰이 따라오지 않은 이유가 여기 있다. 저장소를 바꿔도 조회 경로가 다르므로 함께 움직이지 않는다. **없거나 틀리면.** 세션 저장소만 옮기고 「무상태가 됐다」고 판단한다. 토큰은 아직 인스턴스 메모리에 있어 다른 인스턴스로 가면 사라진다. **확인.** ```bash kubectl exec -- wget -qO- localhost:8083/actuator/beans \ | grep -o '"[a-zA-Z]*OAuth2AuthorizedClient[a-zA-Z]*"' | sort -u ``` #### 인가 클라이언트 테이블의 기본키 **무엇인가.** `JdbcOAuth2AuthorizedClientService` 의 기본 스키마다. ```sql PRIMARY KEY (client_registration_id, principal_name) ``` **세션 id 가 키에 없다.** 같은 사용자가 다른 브라우저로 로그인하면 같은 행을 쓰게 되고, **나중 로그인이 앞의 토큰을 덮어쓴다.** **왜 여기 나오나.** B-2 의 ③④ 가 저장소 선택으로 풀리지 않았던 이유다. Redis 로 옮기든 PostgreSQL 로 옮기든 이 키가 그대로면 같은 일이 일어난다. **저장소가 아니라 스키마 문제였다.** 그리고 로그아웃이 애플리케이션 세션(Redis)만 지우고 이 행은 남기므로, **평문 refresh token 이 한 행 남는다.** **없거나 틀리면.** 「같은 사용자가 두 브라우저를 쓰면 왜 한쪽이 풀리는가」를 세션 만료나 캐시 문제로 오진한다. 원인은 스키마다. **확인.** ```sql \d oauth2_authorized_client select principal_name, count(*) from oauth2_authorized_client group by 1; ``` #### Java 직렬화 `\xac\xed` **무엇인가.** Java 기본 직렬화의 매직 넘버가 `0xACED` 다. Redis 에 들어간 세션 값을 꺼내 보면 이 두 바이트로 시작한다. **왜 여기 나오나.** Spring Session 의 기본 직렬화가 Java 네이티브라, Redis 안의 값이 **사람이 읽을 수 없고 다른 언어에서도 못 읽는다.** 값을 확인하려면 같은 클래스패스의 JVM 이 필요하다. JSON 직렬화로 바꾸면 읽을 수 있게 되지만 클래스 구조 변경에 더 민감해진다. **없거나 틀리면.** Redis 안을 들여다보고 「값이 깨졌다」고 판단한다. 깨진 것이 아니라 Java 바이트다. **확인.** ```bash kubectl exec deploy/redis -- redis-cli --no-raw hget sessionAttr:... # \xac\xed 로 시작하면 Java 네이티브 직렬화다 ``` #### agroal 커넥션 풀 **무엇인가.** Quarkus(따라서 Keycloak)의 JDBC 커넥션 풀이다. 지표 이름이 `agroal_` 로 시작한다. | 지표 | 뜻 | |---|---| | `agroal_active_count` | 지금 쓰이는 커넥션 | | `agroal_max_used_count` | 최대로 썼던 수 | | `agroal_awaiting_count` | 커넥션을 기다리는 요청 수 | | `agroal_blocking_time_average_milliseconds` | 획득까지 걸린 평균 시간 | **왜 여기 나오나.** A-6 에서 200ms 지연이 22.2초가 된 두 번째 단계가 이 풀이다. 요청이 커넥션을 오래 붙들면 뒤의 요청이 기다리고, **획득 대기가 최대 20,000ms** 까지 올랐다. 지연이 왕복 횟수만큼 더해진 뒤 여기서 한 번 더 곱해진다. 평시에는 병목이 아니다 — 무주입 상태의 동시 20건에서 `max_used` 가 4, `awaiting` 이 0 이었다. **없거나 틀리면.** 응답이 느려질 때 DB 자체를 의심하는데, 실제로는 커넥션을 기다리는 시간일 수 있다. 둘은 대처가 다르다. **확인.** ```bash curl -s :9000/metrics \ | grep -E '^agroal_(active|awaiting|max_used|blocking_time)' ``` --- ### 7층. TLS 와 인증서 #### `fullchain.pem` vs `cert.pem` **무엇인가.** certbot 이 네 파일을 만든다. | 파일 | 담긴 것 | |---|---| | `cert.pem` | 서버 인증서 하나만 | | `chain.pem` | 중간 인증서들 | | **`fullchain.pem`** | **cert + chain** — nginx 가 써야 하는 것 | | `privkey.pem` | 개인키 | **왜 여기 나오나.** `cert.pem` 만 쓰면 중간 인증서가 빠져 체인이 끊긴다. 그런데 **브라우저 대부분은 중간 인증서를 캐시하거나 AIA 로 보완하므로 정상으로 보인다.** 캐시가 없는 클라이언트(일부 모바일·curl·서버 간 호출)에서만 깨지므로 발견이 늦다. 이 실험대의 설정은 `fullchain.pem` 이고 체인이 4단계로 나온다. ``` 0 s:CN = auth.hyeonworks.com i:Let's Encrypt YE2 1 s:Let's Encrypt YE2 i:ISRG Root YE 2 s:ISRG Root YE i:ISRG Root X2 3 s:ISRG Root X2 i:ISRG Root X1 Verify return code: 0 (ok) ``` **확인.** 단계가 1개로 나오면 `cert.pem` 을 쓰고 있다. ```bash echo | openssl s_client -connect :443 -servername 2>/dev/null \ | grep -E '^ *[0-9]+ s:|Verify return code' ``` **없거나 틀리면.** 브라우저에서는 정상으로 보이는데 서버 간 호출이나 오래된 클라이언트에서만 깨진다. 발견이 늦고 재현이 어렵다. #### certbot 훅 — `deploy` 와 `post` 는 다르다 | 디렉터리 | 언제 실행되나 | |---|---| | `pre/` | 갱신 **시도** 전 | | **`deploy/`** | **실제로 갱신된 인증서가 있을 때만** | | `post/` | 갱신 여부와 무관하게 매번 | **왜 여기 나오나.** 타이머는 하루 두 번 돈다. `post/` 에 reload 를 넣으면 갱신이 없는 날에도 하루 두 번 워커를 갈아치운다. `deploy/` 는 `RENEWED_LINEAGE` 가 있을 때만 돌므로 그것이 맞다. D-4a 에서 이 훅 하나로 갱신에서 서빙까지가 38분 25초에서 1~2초가 됐다. **없거나 틀리면.** `post/` 에 넣으면 갱신이 없는 날에도 하루 두 번 reload 가 돈다. 워커가 매번 교체되므로 keep-alive 연결이 그때마다 끊긴다. **확인.** ```bash sudo ls -la /etc/letsencrypt/renewal-hooks/{pre,deploy,post}/ sudo certbot renew --dry-run # 훅이 도는지 먼저 본다 ``` #### Let's Encrypt 의 `notBefore` 백데이트 **무엇인가.** Let's Encrypt 는 발급 시각보다 **정확히 1시간 앞선** 시각을 `notBefore` 로 넣는다. 클라이언트 시계가 조금 느려도 「아직 유효하지 않은 인증서」로 거부되지 않게 하려는 여유다. ([Let's Encrypt 커뮤니티](https://community.letsencrypt.org/t/certificates-issued-one-hour-too-early/166647)) **왜 여기 나오나.** D-4a 에서 `notBefore` 를 발급 시각으로 읽었다가 훅이 발급보다 먼저 실행된 것 같은 모순이 나왔다. 1시간을 되돌리고 나서야 시계 왜곡 106초가 드러났다. > **이 실험대가 시계 왜곡 때문에 겪은 일을, 인증서 규격은 이미 알고 > 설계에 넣어 두었다.** 백데이트의 이유가 바로 그 문제다. **없거나 틀리면.** `notBefore` 를 발급 시각으로 읽고 계산하면 1시간이 어긋난다. D-4a 에서 훅이 발급보다 먼저 실행된 것처럼 보인 이유가 그것이었다. **확인.** 발급 시각의 기준으로는 SCT 를 쓴다 — 다음 항목. #### SCT 와 Certificate Transparency **무엇인가.** 발급된 인증서를 공개 로그에 올려 누구나 감사할 수 있게 하는 체계다. CA 가 사전 인증서(precertificate)를 로그에 제출하면 로그가 **SCT** (Signed Certificate Timestamp)를 서명해 돌려주고, CA 가 그것을 최종 인증서에 박아 넣는다. 브라우저는 SCT 가 없는 인증서를 거부한다. D-4a 의 새 인증서에 두 개가 박혀 있다. ``` Signed Certificate Timestamp: Timestamp : Sep 4 12:27:49.054 2026 GMT Signed Certificate Timestamp: Timestamp : Sep 4 12:27:49.048 2026 GMT ``` **왜 여기 나오나.** SCT 는 **CT 로그의 시계**로 찍힌다 — dev 머신도 test-server 도 아닌 제3의 기준이다. D-4a 의 106초 보정이 맞는지를 이것으로 교차검증했고, 보정한 훅 시각이 SCT 의 1초 뒤에 정확히 놓였다. **그런데 crt.sh 는 이 이름을 0건으로 답했다.** 인증서에 SCT 가 박혀 있다는 것과 특정 검색 사이트가 그것을 색인했다는 것은 다르다. crt.sh 는 자기가 감시하는 로그만 수집하므로 모든 로그를 덮지 않는다. **없거나 틀리면.** 「crt.sh 에 없으니 발급되지 않았다」로 읽는다. A-2 의 `up` 지표와 같은 계열의 함정이다 — **관측 도구가 진실의 부분집합만 본다.** **확인.** ```bash echo | openssl s_client -connect :443 -servername 2>/dev/null \ | openssl x509 -noout -ext ct_precert_scts ``` #### JWKS 와 `kid` **무엇인가.** IdP 가 서명에 쓴 공개키를 JSON 으로 공개하는 엔드포인트가 JWKS 이고, 토큰 헤더의 `kid` 가 어느 키로 서명했는지 가리킨다. ``` /realms//protocol/openid-connect/certs ``` **왜 여기 나오나.** B-6 에서 realm 키를 회전하고 **JWKS 캐시의 유예 구간을 기대했는데 없었다.** `NimbusJwtDecoder` 는 모르는 `kid` 를 만나면 캐시 만료를 기다리지 않고 **곧바로 JWKS 를 다시 가져온다.** 예측이 틀렸고, 결과적으로 회전이 더 매끄러웠다. 키 회전은 우선순위로 한다 — 새 키를 더 높은 priority 로 추가하면 새 토큰은 새 키로 서명되고, 옛 키는 남아 있어 옛 토큰 검증이 계속된다. **없거나 틀리면.** 키 회전 후 옛 토큰이 갑자기 거부될 것을 걱정해 회전을 미룬다. 실제로는 옛 키를 남겨 두면 검증이 이어진다. **확인.** ```bash curl -s https:///realms//protocol/openid-connect/certs | jq '.keys[].kid' # 토큰 쪽 kid 는 헤더에 있다 echo "$TOKEN" | cut -d. -f1 | base64 -d 2>/dev/null | jq .kid ``` #### oauth2-proxy 의 티켓 **무엇인가.** Redis 세션 저장소를 쓰면 쿠키에 세션 전체가 아니라 **티켓**이 담긴다. ``` 티켓 = <세션 ID>.<암호화 키> │ └─ 값을 복호화할 키 └─ Redis 키 이름을 만든다 → _oauth2_proxy- ``` 티켓 전체가 `--cookie-secret` 으로 암호화되어 있다. **왜 여기 나오나.** secret 을 바꾸면 티켓을 열 수 없고, **세션 ID 조차 읽지 못하므로 어느 Redis 키를 지울지도 모른다.** B-7 의 「지우지 못했다」가 이 구조 때문이다. B-7a 가 그 앞을 재서, 프록시가 못 지울 뿐 운영자는 지울 수 있고 TTL 로 생성 시각을 역산해 고아만 골라낼 수 있다는 것을 확인했다. **없거나 틀리면.** secret 회전을 「사용자 재로그인」 비용으로만 계산한다. 서버 쪽에 지울 수 없는 세션이 남는 비용이 따로 있다. **확인.** ```bash kubectl exec deploy/redis -- redis-cli --scan --pattern '_oauth2_proxy-*' kubectl logs -l app=oauth2-proxy --since=2m | grep stored_session ``` --- ### 8층. 측정 — 시계와 지표 #### NTP 와 시계 왜곡 **무엇인가.** 시스템 시계는 그냥 두면 어긋난다. NTP 데몬이 외부 서버와 맞춘다. `systemd-timesyncd` 가 그 역할을 하며 상태를 이렇게 본다. ```bash timedatectl show -p NTP -p NTPSynchronized ``` **왜 여기 나오나.** test-server 는 `NTP=no` · `NTPSynchronized=no` 이고 **106초 빠르다.** dev 머신은 Google 및 Let's Encrypt ACME 응답과 0초 차다. 그 사실을 적지 않고 계산한 D-4 의 공백은 106초 짧았고(2199 → 2305초), 1~2초를 재는 D-4a 에서는 **훅이 인증서 발급보다 104초 먼저 실행된 것**이 되어 물리적으로 불가능해졌다. **없거나 틀리면.** 두 시계에서 온 값을 빼면서 그 사실을 적지 않으면 **자릿수가 아니라 방향까지 틀린다.** **확인.** 왕복 시간을 감안해 재고, 어느 쪽이 맞는지는 외부 기준으로 가른다. ```bash A=$(date -u +%s.%N); B=$(ssh 'date -u +%s.%N'); C=$(date -u +%s.%N) # 왜곡 ≈ B − (A+C)/2 # 어느 쪽이 맞나 — HTTP Date 헤더를 외부 기준으로 curl -sI https://www.google.com | grep -i '^date:' ``` #### `up` — 가장 중요하고 가장 오해받는 지표 **무엇인가.** Prometheus 가 스크레이프에 성공했는지를 스스로 만들어 붙이는 합성 지표다. 대상이 응답하면 1, 못 하면 0 이다. **왜 여기 나오나.** A-2 에서 **503 이 나는 동안에도 `up` 은 1** 이었다. 프로세스가 살아 있고 `/metrics` 가 응답하기만 하면 1 이므로, **「살아 있지만 쓸모없는」 상태를 보지 못한다.** **없거나 틀리면.** `up == 0` 만 경보로 걸면 이 실험대의 A-2 같은 장애를 놓친다. 기능 지표(로그인 성공률·에러율)를 함께 봐야 한다. **확인.** ```bash curl -s 'localhost:19090/api/v1/query?query=up' | jq '.data.result[].value' # up 만 보지 말고 기능 지표를 함께 본다 curl -s -o /dev/null -w '%{http_code}\n' https:///realms/master ``` #### exporter 패턴과 관측 공백 **무엇인가.** Prometheus 는 대상이 보내오는 것을 받지 않고 **자기가 긁어 온다**(pull). 지표를 내보내지 않는 대상은 exporter 를 앞에 두어야 한다. **왜 여기 나오나.** 이 실험대의 Prometheus 는 keycloak·kubelet· node-exporter·prometheus 만 긁는다. **Redis·BFF·PostgreSQL 은 대상에 없다.** 그래서 B층 실험 대부분에 Grafana 스크린샷이 없는데, 안 찍은 것이 아니라 띄울 화면이 없다. 이것을 「스크린샷 누락」이 아니라 **측정된 공백**으로 기록했다. **없거나 틀리면.** 「Grafana 에 안 보인다」를 「문제가 없다」로 읽는다. 대상에 없으면 문제가 있어도 안 보인다. **확인.** ```bash curl -s localhost:19090/api/v1/targets | jq -r '.data.activeTargets[].labels.job' | sort -u ``` --- ### 분해 계약과의 대응 이 프로젝트에는 주제 여섯과 글감 서른셋으로 분해 계약이 서 있다 ([`tech-log-studio/tech-log-tree.json`](../tech-log-studio/tech-log-tree.json)). 위 여덟 층은 그것과 나란한 별개 구조가 아니라 **각 주제가 서 있는 바닥**이다. | 계약의 주제 | 그 아래에 깔린 층 | |---|---| | `session-custody-across-nodes` | 5층 — 디스커버리 대 트랜스포트, 세션 두 겹 | | `losing-a-node-or-the-store` | 1층 전체 · 3층(WAL·`synchronous_commit`) · 4층(축출 타이머) | | `where-application-state-lives` | 6층 전체 · 5층(refresh token rotation) | | `trust-handed-over-at-the-edge` | 2층(conntrack·netfilter) · 7층(oauth2-proxy 티켓) | | `operations-that-report-success` | 1층(systemd 일체) · 7층(SCT·백데이트) · 3층(Liquibase) | | `when-the-measurement-lies` | 8층 전체 | `operations-that-report-success` 의 글감 둘(「새 인증서가 디스크에 있고 38분 25초 동안 옛 인증서가 나갔다」, 「deploy 훅 하나가 그 공백을 1~2초로 줄였다」)은 **systemd 를 설명하지 않고는 쓸 수 없다.** 이제 1층이 그것을 채운다. ### 조사하면서 확인한 것과 확인하지 못한 것 시스템에서 직접 확인한 값은 이렇다. | 확인한 것 | 값 | 어디서 | |---|---|---| | conntrack `ESTABLISHED` 타임아웃 | **86400초** | kc-lab-1 `/proc/sys/net/netfilter/` | | conntrack 현황 | 311건 / 상한 131072 | `conntrack -C` | | FORWARD 1번 체인 | `KUBE-ROUTER-FORWARD` | `iptables -S FORWARD` | | cgroup 버전 | v2 (`cgroup2fs`) | `stat -fc %T /sys/fs/cgroup` | | nginx 재시작 정책 | `on-failure` · 100ms · 5회/10초 | `systemctl show` | | 호스트별 `Type`·`KillMode` | 넷이 서로 다름 | `systemctl show` 5개 유닛 | | PID 1 의 정체 | `systemd --switched-root` | `ps -p 1` | 외부 사실은 출처를 달았다 — Let's Encrypt 의 1시간 백데이트와 그 이유, Keycloak 이 재사용 감지 시 SSO 세션 전체를 무효화한다는 것. **아직 재지 않은 것이 하나 남는다.** 1층의 `Restart=on-failure` 는 유닛 파일을 읽어 적은 것이지 nginx 를 죽여 확인한 것이 아니다. 이 기록이 스물여섯 번 배운 것이 「설정이 그렇다고 그렇게 동작하지는 않는다」이므로, 이 항목만은 **설정을 읽었다**고 적어 둔다. 재려면 호스트 sudo 로 마스터 프로세스를 죽이고 100ms 안에 살아나는지, 워커 PID 가 어떻게 바뀌는지, 그동안 외부 요청이 몇 건 떨어지는지를 보면 된다.