diff --git a/.playwright-mcp/console-2026-09-04T00-53-39-252Z.log b/.playwright-mcp/console-2026-09-04T00-53-39-252Z.log new file mode 100644 index 0000000..7402e20 --- /dev/null +++ b/.playwright-mcp/console-2026-09-04T00-53-39-252Z.log @@ -0,0 +1,22 @@ +[ 1289ms] [WARNING] is deprecated. Please include @ https://app2.hyeonworks.com/login:0 +[ 1417ms] [VERBOSE] [DOM] Input elements should have autocomplete attributes (suggested: "username"): (More info: https://goo.gl/9p2vKq) %o @ https://app2.hyeonworks.com/login:0 +[ 9024ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 9130ms] [WARNING] is deprecated. Please include @ https://app2.hyeonworks.com/:0 +[ 9456ms] [WARNING] Deprecation warning: value provided is not in a recognized RFC2822 or ISO format. moment construction falls back to js Date(), which is not reliable across all browsers and versions. Non RFC2822/ISO date formats are discouraged. Please refer to http://momentjs.com/guides/#/warnings/js-date/ for more info. +Arguments: +[0] _isAMomentObject: true, _isUTC: false, _useUTC: false, _l: undefined, _i: Thu, 27 Aug 2026 13:03:49, _f: undefined, _strict: undefined, _locale: [object Object] +Error + at a.createFromInputFallback (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:3) + at an (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:25647) + at un (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:29355) + at aa (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:29221) + at on (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:28938) + at sa (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:29715) + at A (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:624:29748) + at a (https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:621:89) + at f (https://app2.hyeonworks.com/public/build/3719.c065b2e146c4c8347d51.js:1:4635) + at u (https://app2.hyeonworks.com/public/build/322.177b4bb01c5d74f9b28f.js:2473:47448) @ https://app2.hyeonworks.com/public/build/6029.0549a3fcb50e73c4b256.js:620 +[ 9605ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 10620ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 11527ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 13875ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 diff --git a/.playwright-mcp/console-2026-09-04T00-53-54-407Z.log b/.playwright-mcp/console-2026-09-04T00-53-54-407Z.log new file mode 100644 index 0000000..89aee66 --- /dev/null +++ b/.playwright-mcp/console-2026-09-04T00-53-54-407Z.log @@ -0,0 +1,7 @@ +[ 144ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 153ms] [WARNING] is deprecated. Please include @ https://app2.hyeonworks.com/explore:0 +[ 1077ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 2101ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 2922ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 7323ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 9370ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 diff --git a/.playwright-mcp/console-2026-09-04T00-54-13-939Z.log b/.playwright-mcp/console-2026-09-04T00-54-13-939Z.log new file mode 100644 index 0000000..c061400 --- /dev/null +++ b/.playwright-mcp/console-2026-09-04T00-54-13-939Z.log @@ -0,0 +1,8 @@ +[ 271ms] [WARNING] is deprecated. Please include @ https://app2.hyeonworks.com/explore?schemaVersion=1&orgId=1&panes=%7B%22a%22%3A%7B%22datasource%22%3A%22PBFA97CFB590B2093%22%2C%22queries%22%3A%5B%7B%22refId%22%3A%22A%22%2C%22expr%22%3A%22vendor_statistics_approximate_entries_unique%7Bcache%3D%5C%22sessions%5C%22%7D%22%2C%22range%22%3Atrue%2C%22instant%22%3Afalse%2C%22editorMode%22%3A%22code%22%2C%22legendFormat%22%3A%22%7B%7Bpod%7D%7D%20on%20%7B%7Bnode%7D%7D%22%2C%22datasource%22%3A%7B%22type%22%3A%22prometheus%22%2C%22uid%22%3A%22PBFA97CFB590B2093%22%7D%7D%5D%2C%22range%22%3A%7B%22from%22%3A%22now-15m%22%2C%22to%22%3A%22now%22%7D%7D%7D:0 +[ 346ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 1512ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 2433ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 6941ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 13188ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 21578ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 +[ 25998ms] [ERROR] WebSocket connection to 'wss://app2.hyeonworks.com/api/live/ws' failed: Error during WebSocket handshake: Unexpected response code: 400 @ https://app2.hyeonworks.com/public/build/1518.a3f1f690c084a37f01c7.js:362 diff --git a/.playwright-mcp/console-2026-09-04T00-54-40-326Z.log b/.playwright-mcp/console-2026-09-04T00-54-40-326Z.log new file mode 100644 index 0000000..5774735 --- /dev/null +++ b/.playwright-mcp/console-2026-09-04T00-54-40-326Z.log @@ -0,0 +1,7 @@ +[ 766ms] [WARNING] An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing. @ https://auth.hyeonworks.com/realms/master/protocol/openid-connect/3p-cookies/step1.html:0 +[ 781ms] [WARNING] An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing. @ https://auth.hyeonworks.com/realms/master/protocol/openid-connect/3p-cookies/step2.html:0 +[ 17929ms] [WARNING] An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing. @ https://auth.hyeonworks.com/realms/master/protocol/openid-connect/3p-cookies/step1.html:0 +[ 17949ms] [WARNING] An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing. @ https://auth.hyeonworks.com/realms/master/protocol/openid-connect/3p-cookies/step2.html:0 +[ 17981ms] [WARNING] An iframe which has both allow-scripts and allow-same-origin for its sandbox attribute can escape its sandboxing. @ https://auth.hyeonworks.com/realms/master/protocol/openid-connect/login-status-iframe.html:0 +[ 18447ms] [WARNING] For accessibility reasons an aria-label should be specified on nav groups if a title isn't @ https://auth.hyeonworks.com/resources/9v5yc/admin/keycloak.v2/assets/main-BbID33M6.js:7 +[ 18462ms] [WARNING] For accessibility reasons an aria-label should be specified on nav groups if a title isn't @ https://auth.hyeonworks.com/resources/9v5yc/admin/keycloak.v2/assets/main-BbID33M6.js:7 diff --git a/.playwright-mcp/page-2026-09-04T00-53-40-561Z.yml b/.playwright-mcp/page-2026-09-04T00-53-40-561Z.yml new file mode 100644 index 0000000..c07d1c0 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-53-40-561Z.yml @@ -0,0 +1,2 @@ +- main [ref=e7]: + - status "Loading" [ref=e10] \ No newline at end of file diff --git a/.playwright-mcp/page-2026-09-04T00-53-48-279Z.yml b/.playwright-mcp/page-2026-09-04T00-53-48-279Z.yml new file mode 100644 index 0000000..25ab018 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-53-48-279Z.yml @@ -0,0 +1 @@ +- main [ref=f3e7] \ No newline at end of file diff --git a/.playwright-mcp/page-2026-09-04T00-53-54-595Z.yml b/.playwright-mcp/page-2026-09-04T00-53-54-595Z.yml new file mode 100644 index 0000000..9f6bb91 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-53-54-595Z.yml @@ -0,0 +1,2 @@ +- main [ref=f6e7]: + - status "Loading" [ref=f6e10] \ No newline at end of file diff --git a/.playwright-mcp/page-2026-09-04T00-54-14-322Z.yml b/.playwright-mcp/page-2026-09-04T00-54-14-322Z.yml new file mode 100644 index 0000000..f5d59a2 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-54-14-322Z.yml @@ -0,0 +1,104 @@ +- generic [ref=f9e4]: + - link "Skip to main content" [ref=f9e5] [cursor=pointer]: + - /url: "#pageContent" + - banner [ref=f9e7]: + - generic [ref=f9e8]: + - link [ref=f9e10] [cursor=pointer]: + - /url: / + - img "Grafana" [ref=f9e11] + - generic [ref=f9e14]: + - button "Search or jump to..." [ref=f9e18] [cursor=pointer] + - generic [ref=f9e19]: ctrl+k + - generic [ref=f9e23]: + - button "New" [ref=f9e24] [cursor=pointer] + - button "Help" [ref=f9e30] [cursor=pointer] + - button "News" [ref=f9e33] [cursor=pointer] + - button "Profile" [ref=f9e36] [cursor=pointer]: + - img "User avatar" [ref=f9e37] + - generic [ref=f9e38]: + - button "Open menu" [ref=f9e40] [cursor=pointer] + - navigation "Breadcrumbs" [ref=f9e43]: + - list [ref=f9e44]: + - listitem [ref=f9e45]: + - link "Home" [ref=f9e46] [cursor=pointer]: + - /url: / + - listitem [ref=f9e50]: + - link "Explore" [ref=f9e51] [cursor=pointer]: + - /url: /explore + - listitem [ref=f9e55]: + - generic "Prometheus" [ref=f9e56] + - generic [ref=f9e57]: + - button "Show more items" [ref=f9e60] [cursor=pointer] + - button "Toggle top search bar" [ref=f9e64] [cursor=pointer] + - main [ref=f9e70]: + - generic [ref=f9e72]: + - heading "Explore" [level=1] [ref=f9e73] + - generic [ref=f9e78]: + - navigation "Explore toolbar" [ref=f9e80]: + - navigation "Search links" [ref=f9e82]: + - generic [ref=f9e83]: + - button "Content outline" [expanded] [ref=f9e85] [cursor=pointer]: + - generic [ref=f9e88]: Outline + - generic [ref=f9e93] [cursor=pointer]: + - img "Prometheus logo" [ref=f9e95] + - textbox "Select a data source" [ref=f9e96]: + - /placeholder: "" + - button "Show more items" [ref=f9e102] [cursor=pointer] + - generic [ref=f9e106]: + - generic [ref=f9e110]: + - button "Collapse outline" [expanded] [ref=f9e112] [cursor=pointer]: + - img "arrow-from-right" [ref=f9e113] + - button "Queries" [ref=f9e116] [cursor=pointer]: + - img "arrow" [ref=f9e117] + - generic [ref=f9e124]: + - generic [ref=f9e126]: + - generic "Query editor row" [ref=f9e129]: + - generic [ref=f9e130]: + - generic [ref=f9e132]: + - generic [ref=f9e133]: + - button "Collapse query row" [expanded] [ref=f9e134] [cursor=pointer] + - generic [ref=f9e137]: + - button "Query editor row title A" [ref=f9e138] [cursor=pointer]: + - generic [ref=f9e139]: A + - emphasis [ref=f9e140]: (Prometheus) + - generic [ref=f9e141]: + - button "Show data source help" [ref=f9e143] [cursor=pointer] + - button "Duplicate query" [ref=f9e147] [cursor=pointer] + - button "Hide response" [ref=f9e151] [cursor=pointer] + - button "Remove query" [ref=f9e155] [cursor=pointer] + - button "Drag and drop to reorder" [ref=f9e158]: + - img "Drag and drop to reorder" [ref=f9e159] + - generic [ref=f9e162]: + - generic [ref=f9e163]: + - button "Kick start your query" [ref=f9e164] [cursor=pointer] + - generic [ref=f9e167]: + - generic [ref=f9e168] [cursor=pointer]: Explain + - generic [ref=f9e169]: + - checkbox "Explain Toggle switch" [ref=f9e170] + - generic "Toggle switch" [ref=f9e171] [cursor=pointer] + - radiogroup [ref=f9e176]: + - generic [ref=f9e177]: + - radio "Builder" [ref=f9e178] [cursor=pointer] + - generic [ref=f9e179] [cursor=pointer]: Builder + - generic [ref=f9e180]: + - radio "Code" [checked] [ref=f9e181] [cursor=pointer] + - generic [ref=f9e182] [cursor=pointer]: Code + - generic [ref=f9e184]: + - generic [ref=f9e186]: + - button "Loading metrics..." [disabled] [ref=f9e187] [cursor=pointer] + - generic [ref=f9e190]: Loading editor + - 'button "Options Legend: {{pod}} on {{node}} Format: Time series Step: auto Type: Range Exemplars: false" [ref=f9e198] [cursor=pointer]': + - generic [ref=f9e202]: + - heading "Options" [level=6] [ref=f9e203] + - generic [ref=f9e204]: + - generic [ref=f9e205]: "Legend: {{pod}} on {{node}}" + - generic [ref=f9e206]: "Format: Time series" + - generic [ref=f9e207]: "Step: auto" + - generic [ref=f9e208]: "Type: Range" + - generic [ref=f9e209]: "Exemplars: false" + - generic [ref=f9e210]: + - button "Add query" [ref=f9e211] [cursor=pointer] + - button "Query history" [ref=f9e215] [cursor=pointer] + - button "Query inspector" [ref=f9e219] [cursor=pointer] + - generic: + - main \ No newline at end of file diff --git a/.playwright-mcp/page-2026-09-04T00-54-40-837Z.yml b/.playwright-mcp/page-2026-09-04T00-54-40-837Z.yml new file mode 100644 index 0000000..65cfdc6 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-54-40-837Z.yml @@ -0,0 +1,4 @@ +- main [ref=f12e3]: + - generic [ref=f12e4]: + - progressbar "Contents" [ref=f12e5] + - paragraph [ref=f12e8]: Loading the Administration Console \ No newline at end of file diff --git a/.playwright-mcp/page-2026-09-04T00-54-58-719Z.yml b/.playwright-mcp/page-2026-09-04T00-54-58-719Z.yml new file mode 100644 index 0000000..4950df9 --- /dev/null +++ b/.playwright-mcp/page-2026-09-04T00-54-58-719Z.yml @@ -0,0 +1,4 @@ +- generic [active] [ref=f15e1]: + - progressbar "Loading" [ref=f15e4] + - generic: + - list \ No newline at end of file diff --git a/deploy/lab/scripts/experiment-cache-ownership.sh b/deploy/lab/scripts/experiment-cache-ownership.sh new file mode 100755 index 0000000..a7c2f65 --- /dev/null +++ b/deploy/lab/scripts/experiment-cache-ownership.sh @@ -0,0 +1,55 @@ +#!/usr/bin/env bash +# Experiment 0c — where does a session entry actually live? +# +# Experiment 0b showed keycloak-1's session cache never moved when keycloak-0 +# handled a login. That leaves two explanations: +# +# (a) a DISTRIBUTED cache with owners=1 — entries are spread across nodes by +# consistent hashing, and this one happened to land on keycloak-0; +# (b) a LOCAL cache — each node only ever caches what it handled itself. +# +# They are distinguished by driving logins at the OTHER node. Under (a) the +# entries would keep landing on both nodes regardless of who was asked. Under +# (b) the count rises only on the node that received the request. +set -uo pipefail + +NS="${NS:-keycloak-lab}" +N="${N:-5}" +K0_IP=$(kubectl -n "$NS" get pod keycloak-0 -o jsonpath='{.status.podIP}') +K1_IP=$(kubectl -n "$NS" get pod keycloak-1 -o jsonpath='{.status.podIP}') +ADMIN_PW=$(kubectl -n "$NS" get secret keycloak-lab-secrets \ + -o jsonpath='{.data.KC_BOOTSTRAP_ADMIN_PASSWORD}' | base64 -d) + +echo "수집 시각: $(date '+%Y-%m-%d %H:%M:%S %Z')" +echo " keycloak-0 = $K0_IP ($(kubectl -n "$NS" get pod keycloak-0 -o jsonpath='{.spec.nodeName}'))" +echo " keycloak-1 = $K1_IP ($(kubectl -n "$NS" get pod keycloak-1 -o jsonpath='{.spec.nodeName}'))" +echo + +kubectl -n "$NS" run kc-own --rm -i --restart=Never \ + --image=curlimages/curl:8.11.1 --quiet --command -- sh -c " +O=/tmp/o; : > \$O +ent() { + curl -s --retry 3 --max-time 20 http://\$1:9000/metrics \ + | grep -E '^vendor_statistics_approximate_entries_unique.cache=.sessions' \ + | awk '{print \$NF}' +} +login() { i=0; while [ \$i -lt $N ]; do + curl -s -o /dev/null -X POST http://\$1:8080/realms/master/protocol/openid-connect/token \ + -d grant_type=password -d client_id=admin-cli \ + -d username=admin -d 'password=$ADMIN_PW' + i=\$((i+1)); done; sleep 5; } +{ + printf '%-32s %12s %12s\n' '단계' 'k0 entries' 'k1 entries' + printf '%-32s %12s %12s\n' '시작' \"\$(ent $K0_IP)\" \"\$(ent $K1_IP)\" + login $K1_IP + printf '%-32s %12s %12s\n' 'keycloak-1 에 로그인 ${N}회' \"\$(ent $K0_IP)\" \"\$(ent $K1_IP)\" + login $K0_IP + printf '%-32s %12s %12s\n' 'keycloak-0 에 로그인 ${N}회' \"\$(ent $K0_IP)\" \"\$(ent $K1_IP)\" +} >> \$O +cat \$O +" 2>&1 | grep -v '^pod .* deleted$' + +echo +echo "=== 대조: PostgreSQL 에는 몇 건인가 ===" +kubectl -n "$NS" exec deploy/postgres -- psql -U keycloak -d keycloak -tAc \ + "select count(*) from offline_user_session where offline_flag='0'" 2>/dev/null | sed 's/^/ online 세션 /' diff --git a/deploy/lab/scripts/experiment-cache-replication-delta.sh b/deploy/lab/scripts/experiment-cache-replication-delta.sh new file mode 100755 index 0000000..c2b16b7 --- /dev/null +++ b/deploy/lab/scripts/experiment-cache-replication-delta.sh @@ -0,0 +1,83 @@ +#!/usr/bin/env bash +# Experiment 0b — does the Infinispan cache itself replicate, or do both nodes +# merely agree because they read the same database? +# +# Experiment 0 proved the two nodes give the same answers. That alone does NOT +# prove Infinispan replicated anything: with persistent-user-sessions (the +# Keycloak 26 default) the session is written to PostgreSQL, so two nodes reading +# one database would agree even with the cache disabled entirely. +# +# This script separates the two by measuring the cache counters on BOTH nodes +# around a single login. If the write on keycloak-0 shows up as cache activity +# on keycloak-1, the replication is real and not a database artifact. +set -uo pipefail + +NS="${NS:-keycloak-lab}" +K0_IP=$(kubectl -n "$NS" get pod keycloak-0 -o jsonpath='{.status.podIP}') +K1_IP=$(kubectl -n "$NS" get pod keycloak-1 -o jsonpath='{.status.podIP}') +ADMIN_PW=$(kubectl -n "$NS" get secret keycloak-lab-secrets \ + -o jsonpath='{.data.KC_BOOTSTRAP_ADMIN_PASSWORD}' | base64 -d) + +echo "수집 시각: $(date '+%Y-%m-%d %H:%M:%S %Z')" +echo + +# 파드 출력을 스트리밍으로 받으면 조각이 유실된다. 실제로 첫 시도에서 +# keycloak-1 의 스냅샷과 그 다음 마커가 통째로 사라져 델타가 0 으로 보였다. +# 파드 안에서 파일로 모았다가 마지막에 한 번만 내보낸다. +kubectl -n "$NS" run kc-delta --rm -i --restart=Never \ + --image=curlimages/curl:8.11.1 --quiet --command -- sh -c " +set -u +K0='http://$K0_IP'; K1='http://$K1_IP' +O=/tmp/o.txt; : > \$O +snap() { + curl -s --retry 3 --retry-connrefused --max-time 20 \$1:9000/metrics \ + | grep -E '^vendor_(statistics_(stores|hits|misses|approximate_entries_unique)|rpc_manager_replication_count)\{cache=\"(sessions|clientSessions)\"' \ + | sed 's/,cache_manager=\"keycloak\"//; s/,node=\"[^\"]*\"//' >> \$O +} +echo '###BEFORE_K0' >> \$O; snap \$K0 +echo '###BEFORE_K1' >> \$O; snap \$K1 +echo '###LOGIN' >> \$O +curl -s -o /dev/null -w 'http_code=%{http_code}\n' -X POST \ + \"\$K0:8080/realms/master/protocol/openid-connect/token\" \ + -d grant_type=password -d client_id=admin-cli \ + -d username=admin -d 'password=$ADMIN_PW' >> \$O +sleep 5 +echo '###AFTER_K0' >> \$O; snap \$K0 +echo '###AFTER_K1' >> \$O; snap \$K1 +echo '###END' >> \$O +cat \$O +" 2>&1 | grep -v '^pod .* deleted$' > /tmp/cache-delta.txt + +python3 - /tmp/cache-delta.txt <<'PY' +import re, sys +raw = open(sys.argv[1]).read() +blocks, cur = {}, None +for line in raw.splitlines(): + if line.startswith('###'): + cur = line[3:]; blocks[cur] = {} + elif cur and '{' in line: + m = re.match(r'(\S+?)\{cache="(\w+)"\}\s+(\S+)', line) + if m: + blocks[cur][(m.group(1), m.group(2))] = float(m.group(3)) + +print('=== 로그인은 keycloak-0 에만 보냈다 ===') +code = [l for l in raw.splitlines() if l.startswith('http_code=')] +print(' 로그인 응답: ' + (code[0] if code else '없음')) +for n in ('BEFORE_K0','BEFORE_K1','AFTER_K0','AFTER_K1'): + if not blocks.get(n): + print(f' !! {n} 스냅샷이 비었다 — 델타를 신뢰할 수 없다') +print() +hdr = f" {'계수기':<42} {'캐시':<15} {'전':>8} {'후':>8} {'증가':>7}" +for node in ('K0', 'K1'): + who = 'keycloak-0 (로그인을 받은 노드)' if node == 'K0' else 'keycloak-1 (아무 요청도 받지 않은 노드)' + print(f'=== {who} ===') + print(hdr) + b, a = blocks.get(f'BEFORE_{node}', {}), blocks.get(f'AFTER_{node}', {}) + for k in sorted(set(b) | set(a)): + before, after = b.get(k[0:2], 0.0), a.get(k[0:2], 0.0) + d = after - before + mark = ' ←' if d else '' + name = k[0].replace('vendor_statistics_', '').replace('vendor_rpc_manager_', 'rpc.') + print(f" {name:<42} {k[1]:<15} {before:>8.0f} {after:>8.0f} {d:>+7.0f}{mark}") + print() +PY diff --git a/deploy/lab/scripts/experiment-session-replication.sh b/deploy/lab/scripts/experiment-session-replication.sh new file mode 100755 index 0000000..7734060 --- /dev/null +++ b/deploy/lab/scripts/experiment-session-replication.sh @@ -0,0 +1,207 @@ +#!/usr/bin/env bash +# Experiment 0 — is a session created on one Keycloak node usable on the other? +# +# Forming a cluster is not the same as sharing session state. The Infinispan log +# says "cluster view (2)", but that only proves the members found each other. +# +# Design notes, learned the hard way: +# +# * Every probe has a CONTROL. A result from the far node means nothing unless +# the same call against the issuing node is also measured. The first version +# of this script reported "403 on keycloak-1" as if it were a replication +# failure; the issuing node returned 403 too, and the cause was a missing +# openid scope. Measure both, always. +# +# * Sessions are tracked by SID, not by count. Both the test login and the +# admin API calls create sessions for the same user, so counts are noisy. +# A specific session id either appears in a node's answer or it does not. +# +# * The probe is the REFRESH TOKEN grant, not userinfo. userinfo only validates +# a signature and can succeed on a node that knows nothing about the session. +# Refreshing requires the node to find the session, check it is alive, and +# write back a new refresh time — it actually touches the session store. +# +# Talks to pod IPs directly: going through nginx/Traefik would hide which node +# handled each request, which is the entire question. +# +# ./deploy/lab/scripts/experiment-session-replication.sh +set -uo pipefail + +NS="${NS:-keycloak-lab}" +OUT="${OUT:-/tmp/session-replication}" +mkdir -p "$OUT" + +PSQL="kubectl -n $NS exec deploy/postgres -- psql -U keycloak -d keycloak -tAc" + +echo "수집 시각: $(date '+%Y-%m-%d %H:%M:%S %Z')" +echo + +K0_IP=$(kubectl -n "$NS" get pod keycloak-0 -o jsonpath='{.status.podIP}') +K1_IP=$(kubectl -n "$NS" get pod keycloak-1 -o jsonpath='{.status.podIP}') +K0_NODE=$(kubectl -n "$NS" get pod keycloak-0 -o jsonpath='{.spec.nodeName}') +K1_NODE=$(kubectl -n "$NS" get pod keycloak-1 -o jsonpath='{.spec.nodeName}') +ADMIN_PW=$(kubectl -n "$NS" get secret keycloak-lab-secrets \ + -o jsonpath='{.data.KC_BOOTSTRAP_ADMIN_PASSWORD}' | base64 -d) + +echo "=== 대상 ===" +printf ' keycloak-0 %-14s %s\n' "$K0_IP" "$K0_NODE" +printf ' keycloak-1 %-14s %s\n' "$K1_IP" "$K1_NODE" +echo + +echo "=== [0] 실험 전 DB 세션 ===" +$PSQL "select offline_flag, count(*) from offline_user_session group by offline_flag" 2>/dev/null \ + | sed 's/^/ offline_flag=/' || echo " (없음)" +echo + +# 파드 하나 안에서 전 단계를 실행한다. 단계마다 파드를 새로 띄우면 토큰을 +# 단계 사이로 넘길 수 없다. +kubectl -n "$NS" run kc-probe --rm -i --restart=Never \ + --image=curlimages/curl:8.11.1 --quiet --command -- sh -c " +set -u +K0='http://$K0_IP:8080'; K1='http://$K1_IP:8080' +TOKEN_EP='/realms/master/protocol/openid-connect/token' +jget() { sed -n \"s/.*\\\"\$1\\\":\\\"\\([^\\\"]*\\)\\\".*/\\1/p\"; } + +# ── [1] keycloak-0 에서 로그인. 이 노드가 세션의 출생지다 ────────────────── +LOGIN=\$(curl -s -X POST \"\$K0\$TOKEN_EP\" \ + -d grant_type=password -d client_id=admin-cli \ + -d username=admin -d 'password=$ADMIN_PW') +echo '###STEP1_LOGIN'; echo \"\$LOGIN\" + +AT=\$(echo \"\$LOGIN\" | jget access_token) +RT=\$(echo \"\$LOGIN\" | jget refresh_token) + +# ── [2] 관리 API 조회용 토큰. 세션 오염을 피하려고 따로 하나만 더 만든다 ── +ADMTOK=\$(curl -s -X POST \"\$K0\$TOKEN_EP\" \ + -d grant_type=password -d client_id=admin-cli \ + -d username=admin -d 'password=$ADMIN_PW' | jget access_token) +CID=\$(curl -s -H \"Authorization: Bearer \$ADMTOK\" \ + \"\$K0/admin/realms/master/clients?clientId=admin-cli\" | jget id | head -1) + +# ── [3] 두 노드에 같은 질문을 한다: admin-cli 의 세션 목록 ──────────────── +echo '###STEP3_SESSIONS_K0' +curl -s -H \"Authorization: Bearer \$ADMTOK\" \ + \"\$K0/admin/realms/master/clients/\$CID/user-sessions?max=100\" +echo +echo '###STEP3_SESSIONS_K1' +curl -s -H \"Authorization: Bearer \$ADMTOK\" \ + \"\$K1/admin/realms/master/clients/\$CID/user-sessions?max=100\" +echo + +# ── [4] 대조군: keycloak-0 이 발급한 refresh token 을 keycloak-0 에 쓴다 ── +# 먼저 반대편에 써야 하므로 여기서는 쓰지 않고, 순서를 [5] 뒤로 미룬다. +# refresh token 은 회전(rotation)되므로 한 번 쓰면 옛 것이 무효가 된다. +# 따라서 '반대편 먼저'가 유일하게 의미 있는 순서다. + +# ── [5] 시험군: keycloak-0 이 발급한 refresh token 을 keycloak-1 에 쓴다 ── +echo '###STEP5_REFRESH_ON_K1' +curl -s -w '\nhttp_code=%{http_code}\n' -X POST \"\$K1\$TOKEN_EP\" \ + -d grant_type=refresh_token -d client_id=admin-cli -d \"refresh_token=\$RT\" + +RT2=\$(curl -s -X POST \"\$K1\$TOKEN_EP\" \ + -d grant_type=refresh_token -d client_id=admin-cli -d \"refresh_token=\$RT\" \ + | jget refresh_token) + +# ── [6] 무효화가 반대 방향으로도 전파되는가 ─────────────────────────────── +# keycloak-1 에서 로그아웃시키고, keycloak-0 에서 갱신을 시도한다. +echo '###STEP6_LOGOUT_VIA_K1' +curl -s -o /dev/null -w 'http_code=%{http_code}\n' -X POST \"\$K1/realms/master/protocol/openid-connect/logout\" \ + -d client_id=admin-cli -d \"refresh_token=\$RT2\" + +echo '###STEP7_REFRESH_ON_K0_AFTER_LOGOUT' +curl -s -w '\nhttp_code=%{http_code}\n' -X POST \"\$K0\$TOKEN_EP\" \ + -d grant_type=refresh_token -d client_id=admin-cli -d \"refresh_token=\$RT2\" +echo '###END' +" > "$OUT/raw.txt" 2>&1 + +sed -i '/^pod .* deleted$/d' "$OUT/raw.txt" + +python3 - "$OUT/raw.txt" <<'PY' | tee "$OUT/report.txt" +import base64, json, sys + +raw = open(sys.argv[1]).read() +blocks, cur = {}, None +for line in raw.splitlines(): + if line.startswith('###'): + cur = line[3:]; blocks[cur] = [] + elif cur is not None: + blocks[cur].append(line) +get = lambda k: '\n'.join(blocks.get(k, [])).strip() + +def j(s): + try: return json.JSONDecoder().raw_decode(s.strip())[0] + except Exception: return None + +def claims(tok): + p = tok.split('.')[1]; p += '=' * (-len(p) % 4) + return json.loads(base64.urlsafe_b64decode(p)) + +login = j(get('STEP1_LOGIN')) +if not login or 'access_token' not in login: + print('로그인 실패:', get('STEP1_LOGIN')[:300]); sys.exit(1) + +ac = claims(login['access_token']) +rc = claims(login['refresh_token']) +SID = ac['sid'] +print('=== [1] keycloak-0 에서 로그인 ===') +print(f" sid {SID}") +print(f" sub {ac.get('sub')}") +print(f" iss {ac.get('iss')}") +print(f" access 수명 {ac['exp']-ac['iat']}초") +print(f" refresh 수명 {rc['exp']-rc['iat']}초 typ={rc.get('typ')}") +print(f" refresh jti {rc.get('jti')}") + +print() +print('=== [3] 같은 sid 가 두 노드 모두에서 보이는가 ===') +for step, who in (('STEP3_SESSIONS_K0', 'keycloak-0 (발급 노드)'), + ('STEP3_SESSIONS_K1', 'keycloak-1 (반대편)')): + d = j(get(step)) + if d is None: + print(f' {who:24} 파싱 실패: {get(step)[:120]}'); continue + ids = [s.get('id') for s in d] + mark = '보임 ✔' if SID in ids else '없음 ✘' + print(f' {who:24} 세션 {len(ids)}개 중 대상 sid → {mark}') + for s in d: + if s.get('id') == SID: + print(f" ipAddress={s.get('ipAddress')} start={s.get('start')} lastAccess={s.get('lastAccess')}") + +def show(step, title, expect): + print(); print(f'=== {title} ===') + body = get(step) + code = [l for l in body.splitlines() if l.startswith('http_code=')] + code = code[0].split('=')[1] if code else '?' + d = j(body) + ok = '기대대로' if code == expect else f'기대({expect})와 다름' + print(f' HTTP {code} ← {ok}') + if d and 'access_token' in d: + c = claims(d['access_token']) + same = '동일 ✔' if c.get('sid') == SID else f"다름 ✘ ({c.get('sid')})" + print(f' 새 토큰의 sid → {same}') + elif d: + print(f" error {d.get('error')}") + print(f" error_description {d.get('error_description')}") + +show('STEP5_REFRESH_ON_K1', + '[5] keycloak-0 이 발급한 refresh token 을 keycloak-1 에 사용', '200') + +print(); print('=== [6] keycloak-1 을 통해 로그아웃 ===') +print(' ' + get('STEP6_LOGOUT_VIA_K1').strip()) + +show('STEP7_REFRESH_ON_K0_AFTER_LOGOUT', + '[7] 로그아웃 후 keycloak-0 에서 갱신 시도 (무효화 전파)', '400') + +open('/tmp/session-replication/sid.txt','w').write(SID) +PY + +SID=$(cat /tmp/session-replication/sid.txt 2>/dev/null) +echo +echo "=== [8] PostgreSQL 에서 그 sid 를 직접 확인 ===" +echo " 대상 sid: $SID" +$PSQL "select user_session_id, offline_flag, created_on, last_session_refresh + from offline_user_session where user_session_id='$SID'" 2>/dev/null \ + | sed 's/^/ /' | grep -q . \ + && $PSQL "select user_session_id||' | flag='||offline_flag||' | created='||created_on||' | refresh='||last_session_refresh + from offline_user_session where user_session_id='$SID'" 2>/dev/null | sed 's/^/ /' \ + || echo " 행 없음 — 로그아웃으로 삭제되었다" +echo +echo " 전체 세션 수: $($PSQL 'select count(*) from offline_user_session' 2>/dev/null)" diff --git a/docs/evidence/session-replication/01-cross-node-session.txt b/docs/evidence/session-replication/01-cross-node-session.txt new file mode 100644 index 0000000..3381c13 --- /dev/null +++ b/docs/evidence/session-replication/01-cross-node-session.txt @@ -0,0 +1,52 @@ +=================================================================== + 실험 0 — 한 노드에서 만든 세션이 다른 노드에서 쓰이는가 +=================================================================== + +### 사전 확인: 클러스터가 2 멤버로 형성되었는가 +2026-09-04 00:52:09,294 INFO [org.infinispan.CLUSTER] (executor-thread-1) ISPN000094: Received new cluster view for channel ISPN: [keycloak-1-48749(v=16.0.12)|5] (2) [keycloak-1-48749(v=16.0.12), keycloak-0-30843(v=16.0.12)] + name | ip | coord +------------------+-----------------+------- + keycloak-1-48749 | 10.42.0.35:7800 | t + keycloak-0-30843 | 10.42.1.43:7800 | f +(2 rows) + + +수집 시각: 2026-09-04 09:54:29 KST + +=== 대상 === + keycloak-0 10.42.1.43 kc-lab-2 + keycloak-1 10.42.0.35 kc-lab-1 + +=== [0] 실험 전 DB 세션 === + +=== [1] keycloak-0 에서 로그인 === + sid jiv3rVZi1VeaO07oVJkL_MYW + sub None + iss https://auth.hyeonworks.com/realms/master + access 수명 60초 + refresh 수명 1800초 typ=Refresh + refresh jti 7669cc49-4778-851f-3c49-65f76964ae8e + +=== [3] 같은 sid 가 두 노드 모두에서 보이는가 === + keycloak-0 (발급 노드) 세션 2개 중 대상 sid → 보임 ✔ + ipAddress=10.42.1.44 start=1788483164000 lastAccess=1788483164000 + keycloak-1 (반대편) 세션 2개 중 대상 sid → 보임 ✔ + ipAddress=10.42.1.44 start=1788483164000 lastAccess=1788483164000 + +=== [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: jiv3rVZi1VeaO07oVJkL_MYW + 행 없음 — 로그아웃으로 삭제되었다 + + 전체 세션 수: 1 diff --git a/docs/evidence/session-replication/02-cache-delta.txt b/docs/evidence/session-replication/02-cache-delta.txt new file mode 100644 index 0000000..fd37f31 --- /dev/null +++ b/docs/evidence/session-replication/02-cache-delta.txt @@ -0,0 +1,35 @@ +=================================================================== + 실험 0b — Infinispan 이 복제한 것인가, DB 를 같이 본 것인가 +=================================================================== + +수집 시각: 2026-09-04 09:54:41 KST + +=== 로그인은 keycloak-0 에만 보냈다 === + 로그인 응답: http_code=200 + +=== keycloak-0 (로그인을 받은 노드) === + 계수기 캐시 전 후 증가 + rpc.replication_count clientSessions 1 1 +0 + rpc.replication_count sessions 1 1 +0 + approximate_entries_unique clientSessions 1 2 +1 ← + approximate_entries_unique sessions 1 2 +1 ← + hits clientSessions 2 2 +0 + hits sessions 2 2 +0 + misses clientSessions 2 3 +1 ← + misses sessions 3 4 +1 ← + stores clientSessions 2 3 +1 ← + stores sessions 2 3 +1 ← + +=== keycloak-1 (아무 요청도 받지 않은 노드) === + 계수기 캐시 전 후 증가 + rpc.replication_count clientSessions 7 7 +0 + rpc.replication_count sessions 7 7 +0 + approximate_entries_unique clientSessions 0 0 +0 + approximate_entries_unique sessions 0 0 +0 + hits clientSessions 4 4 +0 + hits sessions 4 4 +0 + misses clientSessions 0 0 +0 + misses sessions 0 0 +0 + stores clientSessions 1 1 +0 + stores sessions 1 1 +0 + diff --git a/docs/evidence/session-replication/03-cache-ownership.txt b/docs/evidence/session-replication/03-cache-ownership.txt new file mode 100644 index 0000000..5ff35f4 --- /dev/null +++ b/docs/evidence/session-replication/03-cache-ownership.txt @@ -0,0 +1,15 @@ +=================================================================== + 실험 0c — 세션 엔트리는 어느 노드에 있는가 (로컬 캐시인가 분산인가) +=================================================================== + +수집 시각: 2026-09-04 09:54:54 KST + keycloak-0 = 10.42.1.43 (kc-lab-2) + keycloak-1 = 10.42.0.35 (kc-lab-1) + +단계 k0 entries k1 entries +시작 2.0 0.0 +keycloak-1 에 로그인 5회 2.0 5.0 +keycloak-0 에 로그인 5회 7.0 5.0 + +=== 대조: PostgreSQL 에는 몇 건인가 === + online 세션 12 diff --git a/docs/evidence/session-replication/README.md b/docs/evidence/session-replication/README.md new file mode 100644 index 0000000..da6e7f6 --- /dev/null +++ b/docs/evidence/session-replication/README.md @@ -0,0 +1,17 @@ +# 실험 0 — 세션 복제 증거 + +수집: 2026-09-04 09:54 KST · Keycloak 26 / Infinispan 16.0.12 / PostgreSQL 16 +해설: [`docs/experiment-00-session-replication.md`](../../experiment-00-session-replication.md) + +| 파일 | 무엇을 보여주는가 | +|---|---| +| `01-cross-node-session.txt` | 클러스터 2멤버 확인 → keycloak-0 로그인 → 같은 sid 가 양쪽에서 보임 → **keycloak-1 이 refresh 성공(200)** → keycloak-1 로그아웃 → **keycloak-0 갱신 실패(400)** → DB 행 삭제 확인 | +| `02-cache-delta.txt` | 로그인 하나를 사이에 둔 양쪽 노드의 캐시 계수기. **keycloak-1 은 전부 +0** | +| `03-cache-ownership.txt` | 로그인을 반대편에 몰아준 결과. **요청을 받은 노드에서만 엔트리가 는다.** 캐시 합 7+5 = DB 12 | +| `session-cache-entries-per-pod.png` | 위 사실의 시계열. 파란 선(keycloak-1)이 0에 붙어 있는 동안 초록 선(keycloak-0)만 14까지 오른다 | +| `keycloak-admin-sessions.png` | 관리 콘솔의 Sessions 화면. 브라우저는 nginx→Traefik 을 거쳐 두 파드 중 하나에 닿지만 **어느 파드가 만든 세션이든 전부 보인다** | + +## 핵심 한 줄 + +클러스터는 형성되지만 **세션 엔트리는 노드를 건너가지 않는다.** +두 노드가 같은 답을 하는 이유는 Infinispan 복제가 아니라 **같은 PostgreSQL** 이다. diff --git a/docs/evidence/session-replication/keycloak-admin-sessions.png b/docs/evidence/session-replication/keycloak-admin-sessions.png new file mode 100644 index 0000000..4e4d919 Binary files /dev/null and b/docs/evidence/session-replication/keycloak-admin-sessions.png differ diff --git a/docs/evidence/session-replication/session-cache-entries-per-pod.png b/docs/evidence/session-replication/session-cache-entries-per-pod.png new file mode 100644 index 0000000..309ba16 Binary files /dev/null and b/docs/evidence/session-replication/session-cache-entries-per-pod.png differ diff --git a/docs/experiment-00-session-replication.md b/docs/experiment-00-session-replication.md new file mode 100644 index 0000000..634b3da --- /dev/null +++ b/docs/experiment-00-session-replication.md @@ -0,0 +1,489 @@ +# 실험 0 — 한 노드에서 만든 세션이 다른 노드에서 쓰이는가 + +로드맵 A-0. 이후 모든 장애 실험의 기준선이다. + +- 실행 스크립트 — [`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) +- 증거 — [`docs/evidence/session-replication/`](evidence/session-replication/) +- 수집 시각 — 2026-09-04 09:54 KST, Keycloak 26 / Infinispan 16.0.12 / PostgreSQL 16 + +--- + +## 0. 결론부터 + +| 물음 | 답 | +|---|---| +| 한 노드에서 만든 세션을 다른 노드가 쓸 수 있는가 | **그렇다** | +| 로그아웃이 반대 방향으로 전파되는가 | **그렇다** | +| **그 공유는 Infinispan 복제 덕분인가** | **아니다** | +| 그럼 무엇이 공유하는가 | **PostgreSQL** | + +**클러스터가 형성됐다는 것과 세션이 복제된다는 것은 다른 얘기였다.** +로그에는 `(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`은 +> `` 뿐이고, +> Keycloak 26은 캐시를 **코드에서** 만든다. 그래서 위 결론은 설정을 읽어서가 +> 아니라 **동작을 측정해서** 얻었다. + +--- + +## 6. 그래서 무엇이 세션을 공유하는가 + +``` + 로그인 (keycloak-0) + │ + ├──▶ PostgreSQL OFFLINE_USER_SESSION ← 진실의 원천. 양쪽이 본다 + │ + └──▶ keycloak-0 로컬 캐시 ← 자기 것만. 건너가지 않는다 + + keycloak-1 이 그 세션을 물으면 + │ + └──▶ 자기 캐시에 없음 → PostgreSQL 에서 읽는다 +``` + +| 계층 | 역할 | 노드 간 공유 | +|---|---|---| +| **PostgreSQL** | 진실의 원천 | **여기서 일어난다** | +| **Infinispan `sessions`** | 자기 노드가 처리한 세션의 룩어사이드 캐시 | **일어나지 않는다** | +| **Infinispan 클러스터** | 무효화 메시지, `work` 캐시 등 | 형성은 되어 있다 | + +이건 **Keycloak 26의 의도된 설계**다. `persistent-user-sessions`가 기본이 되면서 +DB가 진실의 원천이 됐고, 세션 캐시는 **복제할 이유가 없어졌다.** 복제를 하면 +네트워크와 메모리를 쓰면서 DB와 캐시 두 벌을 정합하게 유지해야 한다. + +--- + +## 7. 개념 + +### 7-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 +``` + +### 7-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 = ''; +``` + +**이름이 내용을 배신하는 스키마다.** 운영에서 "온라인 세션이 DB 어디 있냐"를 +찾을 때 이걸 모르면 한참 헤맨다. + +### 7-3. `sid` — 토큰과 DB를 잇는 열쇠 + +``` +JWT access_token 의 sid jiv3rVZi1VeaO07oVJkL_MYW + ↕ 같은 값 +DB user_session_id jiv3rVZi1VeaO07oVJkL_MYW + ↕ 같은 값 +Admin API 세션 목록의 id jiv3rVZi1VeaO07oVJkL_MYW +``` + +세 곳에서 같은 문자열이다. **장애를 추적할 때 이 값 하나로 토큰·DB·관리 API를 +꿰뚫을 수 있다.** 백채널 로그아웃의 `sid` 클레임도 이것이다. + +### 7-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 +엔드포인트다. **두 현상은 하나의 원인**이다. + +### 7-5. 룩어사이드(lookaside) 캐시 + +``` + 읽기: 캐시 확인 → 없으면 DB → 캐시에 채움 + 쓰기: DB 에 쓰고 → 캐시에도 씀 +``` + +캐시가 **DB 앞에 서 있되 DB를 대체하지 않는** 구조. 캐시를 통째로 날려도 +정확성은 유지되고 느려지기만 한다. Keycloak 26의 세션 캐시가 이 모양이다. + +이 성질이 **노드 상실 실험(A-3)의 결과를 미리 결정한다** — 노드가 죽으면 +그 노드의 캐시는 사라지지만 세션은 DB에 있으므로 살아남아야 한다. + +--- + +## 8. 다음 실험에 대한 예측 + +기준선이 생겼으므로 **틀릴 수 있는 예측**을 세울 수 있다. 예측이 빗나가면 +그것이야말로 배울 거리다. + +| 실험 | 예측 | 근거 | +|---|---|---| +| **A-1** TCP 7800 차단 | **세션 공유는 안 깨진다.** 대신 무효화 전파와 `work` 캐시가 깨진다 | 세션은 7800으로 오가지 않는다 | +| **A-2** DB 손실 | **즉시 전면 장애.** 캐시에 있는 세션도 못 쓴다 | DB가 진실의 원천 | +| **A-3** 노드 상실 (kc-lab-2) | **세션은 살아남는다.** 죽은 노드의 캐시만 사라진다 | 룩어사이드 | +| **A-4** volatile 비교 | 7800 차단이 **A-1과 정반대로** 치명적이 된다 | 그때는 캐시가 진실의 원천 | + +특히 A-1은 **직관과 어긋나는 예측**이다. "클러스터 포트를 막으면 세션이 +깨진다"가 상식이지만, 이 기준선이 맞다면 안 깨져야 한다. + +--- + +## 9. 겪은 함정 + +### 9-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} 스냅샷이 비었다 — 델타를 신뢰할 수 없다') +``` + +**계측 코드는 자기가 실패했는지 스스로 말해야 한다.** + +### 9-2. DB에서 직접 지우면 캐시는 남는다 + +정리하려고 `delete from offline_user_session`을 실행했더니, **캐시 엔트리는 +그대로 남아** 캐시 합계(19)와 DB 총계(15)가 어긋났다. + +> 운영에서 세션 테이블을 직접 손대면 캐시와 DB가 갈라진다. 세션을 지울 때는 +> 관리 API(`logout-all`)를 쓰거나, DB를 건드렸다면 **파드를 재시작**해야 한다. + +이 실험의 최종 수치는 **파드 재시작 후** 다시 잰 것이다. + +### 9-3. Keycloak 이미지에는 `curl`이 없다 + +`kubectl exec keycloak-0 -- curl` 은 실패한다. 임시 `curlimages/curl` 파드를 +띄워 파드 네트워크 안에서 호출했다. 파드 IP는 클러스터 밖에서 닿지 않으므로 +이 방법이 사실상 유일하다. + +### 9-4. 중첩 셸의 변수 치환 + +`ssh host '... $VAR ...'` 안에 다시 `sh -c "..."` 를 넣으면 인용이 세 겹이 되어 +치환이 조용히 깨진다. 첫 시도에서 파드 IP가 빈 문자열이 되어 아무 출력도 +나오지 않았다. + +**스크립트 파일로 만들어 `scp` 로 옮기는 쪽이 옳다.** 재현도 되고 저장소에 +남는다. `deploy/lab/scripts/` 아래 세 스크립트가 그 결과다. + +--- + +## 10. 재현 + +```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://:9000/metrics \ + | grep 'approximate_entries_unique{cache="sessions"' +```