Edu/Support

オンライン定期点検
サービス開始

クバネティス(Kubernetes) 環境で Redis-Cluster Java App 構築 ②

Failover テスト

🖧 Redis-Cluster ポッド(Pod) ダイアグラム

┌──────────────┐ ┌──────────────┐ ┌──────────────┐ │ Redis-0 │ │ Redis-1 │ │ Redis-2 │ │ 🟢Master-1 │ │ 🟢Master-2 │ │ 🟢Master-3 │ └──────┬───────┘ └──────┬───────┘ └──────┬───────┘ │ │ │ │ ┌────────────────│──────────────────┘ │ │ └──────────────────┐ └──────────────────┐ │ │ │ │ ▼ ▼ ▼ ┌──────────────┐ ┌──────────────┐ ┌──────────────┐ │ Redis-3 │ │ Redis-4 │ │ Redis-5 │ │ 🟡Replica-1 │ │ 🟡Replica-2 │ │ 🟡Replica-3 │ └──────────────┘ └──────────────┘ └──────────────┘

1. Failover(障害対応)テスト開始

SSH ターミナルを2つ開き、Terminal-1 では App ポッド(Pod) 生成、Redis ポッド(Pod) ダウンなどを実行し、 Terminal-2 で App ログを見ます。

1) Java(Spring) App ポッド(Pod) 生成

サーバ (Terminal-1 [~/kube/app/cluster/]) で実行
$ kubectl apply -f app-deployment.yaml -> ポッド(Pod) 生成

💻 App ログ

サーバ (Terminal-2 [~/kube/app/cluster]) で実行
$ kubectl logs -f -l app=spring-redis-cluster-app
1秒あたり10件ずつ入力([SUCCESS])されることを確認できます。

💻 Terminal-2

 :: Spring Boot :: (v3.4.3)
T11:04:25.996 : Starting KubeRedisClusterAsyncApplication v0.0.1-SNAPSHOT using Java 21.0.12 with PID 1 (/app/app.jar started by root in /app) 
T11:04:28.709 : Tomcat started on port 8080 (http) with context path '/'
T11:04:28.732 :📍Started KubeRedisClusterAsyncApplication in 3.328 seconds (process running for 3.885)
T11:04:28.736 : ----- クバネティス Redis-Cluster Async App(Spring Boot 3.4.3 / Lettuce, Java 21) ------
T11:04:29.624 :📍[SUCCESS] Key: keyA-00000010 -> Normal operation in progress...
T11:04:30.624 :  [SUCCESS] Key: keyA-00000020 -> Normal operation in progress...
T11:04:31.624 :  [SUCCESS] Key: keyA-00000030 -> Normal operation in progress...
... (繰り返し) 中間省略 ...
T11:04:46.623 :  [SUCCESS] Key: keyA-00000180 -> Normal operation in progress...
T11:04:47.623 :  [SUCCESS] Key: keyA-00000190 -> Normal operation in progress...
T11:04:48.623 :📍[SUCCESS] Key: keyA-00000200 -> Normal operation in progress...

2) Redis(Redis-0) 💥 ポッド(Pod) ダウン(delete)

Terminal-1) $ date; kubectl delete pod redis-cluster-0 -> 時刻: 11:04:49

💻 Redis-0 ログ

① 49秒 Redis ダウン (+0秒)
② 50秒 Redis 再起動 (+1秒)
③ 54秒マスター -> 複製へ転換 (+5秒)

📄 redis.log

1:M 11:04:49.302 *📍Redis ダウン: User requested shutdown...
1:M 11:04:50.862 *📍Redis 再起動: Server initialized
1:S 11:04:54.587 *📍マスター -> レプリカへ転換: Connecting to MASTER 10.42.0.175:18504

Redis-0 全ログ ▼

📄 redis.log

1:signal-handler (1788660289) Received SIGTERM scheduling shutdown...
1:M 11:04:49.302 *📍User requested shutdown...
1:M 11:04:49.302 * 1 of 1 replicas are in sync when shutting down.
1:M 11:04:49.302 * Calling fsync() on the AOF file.
1:M 11:04:49.307 * Removing the pid file.
1:M 11:04:49.307 # Redis is now ready to exit, bye bye...
1:C 11:04:50.859 # WARNING: Changing databases number from 16 to 1 since we are in cluster mode
1:C 11:04:50.859 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 11:04:50.859 * Redis version=8.8.1, bits=64, commit=00000000, modified=1, pid=1, just started
1:C 11:04:50.859 * Configuration loaded
1:M 11:04:50.859 * monotonic clock: POSIX clock_gettime
                   Redis Open Source            
1:M 11:04:50.861 * Node configuration loaded, I'm aa8df00ebc2f7ac3001804dd01b75181249b16e1
1:M 11:04:50.862 *📍Server initialized
1:M 11:04:50.863 * Reading RDB base file on AOF loading...
1:M 11:04:50.863 * Loading RDB produced by version 8.8.1
1:M 11:04:50.863 * RDB age 1128089 seconds
1:M 11:04:50.863 * RDB memory usage when created 553.05 Mb
1:M 11:04:50.863 * RDB is base AOF
1:M 11:04:54.009 * Done loading RDB, keys loaded: 3240388, keys expired: 0.
1:M 11:04:54.009 * DB loaded from base file aof.2.base.rdb: 3.147 seconds
1:M 11:04:54.578 * DB loaded from incr file aof.2.incr.aof: 0.568 seconds
1:M 11:04:54.578 * DB loaded from append only file: 3.716 seconds
1:M 11:04:54.582 * Opening AOF incr file aof.2.incr.aof on server start
1:M 11:04:54.582 * Ready to accept connections tcp
1:M 11:04:54.587 * Configuration change detected. Reconfiguring myself as a replica of 11fae5f5710ff5dff65ea6c7865ca0a628458362 (redis-cluster-4)
1:S 11:04:54.587 * Before turning into a replica, using my own master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
1:S 11:04:54.587 *📍Connecting to MASTER 10.42.0.175:18504
1:S 11:04:54.587 * MASTER <-> REPLICA sync started
1:S 11:04:54.587 * Cluster state changed: ok
1:S 11:04:54.590 * Non blocking connect for SYNC fired the event.
1:S 11:04:54.597 * Master replied to PING, replication can continue...
1:S 11:04:54.598 * Trying a partial resynchronization (request fd41c9f456f555d2f81711f9d2367c254d4811e7:527152773).
1:S 11:04:54.598 * PSYNC is not possible, initialize RDB channel.
1:S 11:04:57.165 * Starting to receive RDB and replication stream in parallel.
1:S 11:04:57.186 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
1:S 11:04:59.286 * Discarding previously cached master state.
1:S 11:04:59.286 * MASTER <-> REPLICA sync: Loading DB in memory
1:S 11:04:59.293 * MASTER <-> REPLICA sync: Flushing old data
1:S 11:04:59.525 * Loading RDB produced by version 8.8.1
1:S 11:04:59.525 * RDB age 2 seconds
1:S 11:04:59.525 * RDB memory usage when created 371.71 Mb
1:S 11:05:00.978 * Done loading RDB, keys loaded: 1943407, keys expired: 0.
1:S 11:05:00.978 * Removing the RDB file obtained from the master. This replica has persistence disabled
1:S 11:05:00.978 * MASTER <-> REPLICA sync: Finished with success
1:S 11:05:00.978 * MASTER <-> REPLICA sync: Starting AOF after a successful sync
1:S 11:05:00.978 * Creating AOF incr file temp-aof.incr on background rewrite
1:S 11:05:00.984 * Background append only file rewriting started by pid 13
1:S 11:05:00.984 * MASTER <-> REPLICA sync: Starting to stream replication buffer into the db (463 bytes).
1:S 11:05:00.985 * MASTER <-> REPLICA sync: Successfully streamed replication buffer into the db (463 bytes in total)
13:C 11:05:03.114 * BGSAVE done, 1943407 keys saved, 0 keys skipped, 244865779 bytes written.
13:C 11:05:03.124 * Successfully created the temporary AOF base file temp-rewriteaof-bg-13.aof
13:C 11:05:03.129 * Fork CoW for AOF rewrite: current 1 MB, peak 1 MB, average 1 MB
1:S 11:05:03.197 * Background AOF rewrite terminated with success
1:S 11:05:03.197 * Successfully renamed the temporary AOF base file temp-rewriteaof-bg-13.aof into aof.3.base.rdb
1:S 11:05:03.197 * Successfully renamed the temporary AOF incr file temp-aof.incr into aof.3.incr.aof
1:S 11:05:03.202 * Removing the history file aof.2.incr.aof in the background
1:S 11:05:03.202 * Removing the history file aof.2.base.rdb in the background
1:S 11:05:03.208 * Background AOF rewrite finished successfully

💻 Redis-4 ログ

① 49秒マスターとの接続切断 (+0秒)
② 54秒複製 -> マスターへ転換(昇格) (+5秒)

📄 redis.log

1:S 11:04:49.335 *📍マスターとの接続切断: Connection with master lost.
1:M 11:04:54.557 *📍レプリカ -> マスターへ昇格: Discarding previously cached master state.

Redis-4 全ログ ▼

📄 redis.log

1:S 11:04:49.335 *📍Connection with master lost.
1:S 11:04:49.335 * Caching the disconnected master state.
1:S 11:04:49.336 * Reconnecting to MASTER 10.42.0.174:18504
1:S 11:04:49.336 * MASTER <-> REPLICA sync started
1:S 11:04:49.336 # Error condition on socket for SYNC: Connection refused
1:S 11:04:50.129 * Connecting to MASTER 10.42.0.174:18504
1:S 11:04:50.130 * MASTER <-> REPLICA sync started
1:S 11:04:53.562 * FAIL message received from 6f50eafcd2a642c90b1b3d69cfb3b619342ae9ea (redis-cluster-1) about aa8df00ebc2f7ac3001804dd01b75181249b16e1 (redis-cluster-0)
1:S 11:04:53.644 * Start of election delayed for 817 milliseconds (rank #0, offset 527152772).
1:S 11:04:54.548 * Starting a failover election for epoch 12.
1:S 11:04:54.557 * Failover election won: I'm the new master.
1:S 11:04:54.557 * configEpoch set to 12 after successful failover
1:M 11:04:54.557 *📍Discarding previously cached master state.
1:M 11:04:54.557 * Setting secondary replication ID to 696ad08778fd3b3ef0f9151ef8f964d0cfed880b, valid up to offset: 527152773. New replication ID is 50b86caf74cae2c28d5e66e362f9e0fc4c1230da
1:M 11:04:54.583 * Address updated for node aa8df00ebc2f7ac3001804dd01b75181249b16e1 (redis-cluster-0), now 10.42.0.208:18504
1:M 11:04:54.590 * A failover occurred in shard 68bd5bbafb1ea037e69667f5c9cd85d514ddf106; node aa8df00ebc2f7ac3001804dd01b75181249b16e1 () lost 0 slot(s) to node 11fae5f5710ff5dff65ea6c7865ca0a628458362 (redis-cluster-4) with a config epoch of 12
1:M 11:04:54.598 * Replica 10.42.0.208:18504 asks for synchronization
1:M 11:04:54.598 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for 'fd41c9f456f555d2f81711f9d2367c254d4811e7', my replication IDs are '50b86caf74cae2c28d5e66e362f9e0fc4c1230da' and '696ad08778fd3b3ef0f9151ef8f964d0cfed880b')
1:M 11:04:54.598 * Replica 10.42.0.208:18504 is capable of rdb channel synchronization, and partial sync isn't possible. Full sync will continue with dedicated rdb channel.
1:M 11:04:54.598 * Replica 10.42.0.208:18504 asks for synchronization
1:M 11:04:54.598 * Full resync requested by replica 10.42.0.208:18504 (rdb-channel)
1:M 11:04:54.598 * Delay next BGSAVE for diskless SYNC
1:M 11:04:54.649 * Clear FAIL state for node aa8df00ebc2f7ac3001804dd01b75181249b16e1 (redis-cluster-0):replica is reachable again.
1:M 11:04:57.165 * Starting BGSAVE for SYNC with target: replicas sockets (rdb-channel)
1:M 11:04:57.165 * Starting to deliver RDB and replication stream to replica: 10.42.0.208:18504
1:M 11:04:57.173 * Background RDB transfer started by pid 26 to replica socket
26:C 11:04:59.267 * BGSAVE done, 1943407 keys saved, 0 keys skipped, 244865912 bytes written.
26:C 11:04:59.273 * Fork CoW for RDB: current 1 MB, peak 1 MB, average 1 MB
1:M 11:04:59.288 * Background RDB transfer terminated with success
1:M 11:04:59.288 * Synchronization with replica 10.42.0.208:18504 succeeded
1:M 11:04:59.288 * Streamed RDB transfer with replica 10.42.0.208:18504 succeeded (socket). Waiting for REPLCONF ACK from replica to enable streaming
1:M 11:04:59.288 * RDB transfer completed, rdb only replica (10.42.0.208:18504) should be disconnected asap
1:M 11:04:59.288 * Connection with replica (rdbchannel) 10.42.0.208:18504 lost.

💻 App ログ

Terminal-2) $ kubectl logs -f -l app=spring-redis-sentinel-app
① 49秒 Redis 接続切断 -> 再接続試行 (+0秒)
② 50秒 Redis-1,2 にはデータ入力される (+1秒) ③ 53秒~54秒 Redis-0 へ4件入力失敗 (+4秒~+5秒) の後、Redis-4 がマスターへ転換(昇格)し正常入力されます
④ 59秒 Redis-0 接続成功 -> 入力成功 (+10秒)

💻 Terminal-2

T11:04:49.396  INFO :📍Reconnecting, last destination was redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:50.623  INFO :📍[SUCCESS] Key: keyA-00000220 -> Normal operation in progress...
T11:04:53.342 ERROR :📍[FAIL] Key: keyA-00000207 -> Error after retries: Redis exception
T11:04:54.424 ERROR :📍[FAIL] Key: keyA-00000218 -> Error after retries: Redis exception
T11:04:59.096  INFO :📍Reconnected to redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504

App 全ログ ▼

💻 Terminal-2

T11:04:49.396  INFO [xecutorLoop-1-4] i.l.core.protocol.ConnectionWatchdog     :📍Reconnecting, last destination was redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:49.399  WARN [xecutorLoop-1-4] i.l.core.protocol.ConnectionWatchdog     : Cannot reconnect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: Connection refused: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:50.623  INFO [         task-8] c.r.K.RedisOperationService              :📍[SUCCESS] Key: keyA-00000220 -> Normal operation in progress...
T11:04:51.284  WARN [ioEventLoop-4-3] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:51.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000230 -> Normal operation in progress...
T11:04:52.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000240 -> Normal operation in progress...
T11:04:53.283  WARN [ioEventLoop-4-7] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:53.342 ERROR [         task-7] c.r.K.RedisOperationService              :📍[FAIL] Key: keyA-00000207 -> Error after retries: Redis exception
T11:04:53.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000250 -> Normal operation in progress...
T11:04:53.624 ERROR [         task-4] c.r.K.RedisOperationService              :  [FAIL] Key: keyA-00000210 -> Error after retries: Redis exception
T11:04:54.024 ERROR [         task-6] c.r.K.RedisOperationService              :  [FAIL] Key: keyA-00000214 -> Error after retries: Redis exception
T11:04:54.424 ERROR [         task-2] c.r.K.RedisOperationService              :📍 [FAIL] Key: keyA-00000218 -> Error after retries: Redis exception
T11:04:54.896  WARN [ioEventLoop-4-3] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:54.993  INFO [xecutorLoop-1-5] i.l.core.protocol.ConnectionWatchdog     : Reconnecting, last destination was redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504
T11:04:55.623  INFO [         task-4] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000270 -> Normal operation in progress...
T11:04:55.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000260 -> Normal operation in progress...
T11:04:55.995  WARN [ioEventLoop-4-5] i.l.core.protocol.ConnectionWatchdog     : Cannot reconnect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:55.996  WARN [ioEventLoop-4-6] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:56.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000280 -> Normal operation in progress...
T11:04:57.196  WARN [ioEventLoop-4-2] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:57.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000290 -> Normal operation in progress...
T11:04:58.284  WARN [ioEventLoop-4-4] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-0.redis-cluster-service.default.svc.cluster.local/10.42.0.174:18504
T11:04:58.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000300 -> Normal operation in progress...
T11:04:59.096  INFO [ioEventLoop-4-7] i.l.core.protocol.ReconnectionHandler    :📍Reconnected to redis-cluster-0.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504
T11:04:59.623  INFO [         task-7] c.r.K.RedisOperationService              :📍[SUCCESS] Key: keyA-00000310 -> Normal operation in progress...
T11:05:00.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000320 -> Normal operation in progress...
T11:05:01.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000330 -> Normal operation in progress...
T11:05:02.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000340 -> Normal operation in progress...
T11:05:03.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000350 -> Normal operation in progress...
T11:05:04.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000360 -> Normal operation in progress...
T11:05:05.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000370 -> Normal operation in progress...
T11:05:06.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000380 -> Normal operation in progress...
T11:05:07.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000390 -> Normal operation in progress...
T11:05:08.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000400 -> Normal operation in progress...
T11:05:09.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000410 -> Normal operation in progress...
T11:05:10.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000420 -> Normal operation in progress...
T11:05:11.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000430 -> Normal operation in progress...
T11:05:12.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000440 -> Normal operation in progress...
T11:05:13.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000450 -> Normal operation in progress...
T11:05:14.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000460 -> Normal operation in progress...
T11:05:15.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000470 -> Normal operation in progress...
T11:05:16.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000480 -> Normal operation in progress...
T11:05:17.622  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000490 -> Normal operation in progress...
T11:05:18.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000500 -> Normal operation in progress...
T11:05:19.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000510 -> Normal operation in progress...
T11:05:20.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000520 -> Normal operation in progress...
T11:05:21.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000530 -> Normal operation in progress...
T11:05:22.622  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000540 -> Normal operation in progress...
T11:05:23.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000550 -> Normal operation in progress...
T11:05:24.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000560 -> Normal operation in progress...
T11:05:25.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000570 -> Normal operation in progress...
T11:05:26.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000580 -> Normal operation in progress...
T11:05:27.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000590 -> Normal operation in progress...
T11:05:28.623  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000600 -> Normal operation in progress...
T11:05:29.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000610 -> Normal operation in progress...
T11:05:30.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000620 -> Normal operation in progress...
T11:05:31.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000630 -> Normal operation in progress...
T11:05:32.626  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000640 -> Normal operation in progress...
T11:05:33.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000650 -> Normal operation in progress...
T11:05:34.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000660 -> Normal operation in progress...
T11:05:35.623  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000670 -> Normal operation in progress...
T11:05:36.622  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000680 -> Normal operation in progress...
T11:05:37.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000690 -> Normal operation in progress...
T11:05:38.624  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000700 -> Normal operation in progress...
T11:05:39.622  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000710 -> Normal operation in progress...
T11:05:40.622  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000720 -> Normal operation in progress...
T11:05:41.622  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000730 -> Normal operation in progress...
T11:05:42.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000740 -> Normal operation in progress...
T11:05:43.622  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000750 -> Normal operation in progress...
T11:05:44.622  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000760 -> Normal operation in progress...
T11:05:45.622  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000770 -> Normal operation in progress...
T11:05:46.622  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000780 -> Normal operation in progress...
T11:05:47.622  INFO [         task-7] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000790 -> Normal operation in progress...
T11:05:48.622  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000800 -> Normal operation in progress...
T11:05:49.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000810 -> Normal operation in progress...

🖧 Redis-Cluster ポッド(Pod) ダイアグラム: Failover 状態 (Redis-4 Master-1)

┌──────────────┐ ┌──────────────┐ ┌──────────────┐ │ Redis-0 │ │ Redis-1 │ │ Redis-2 │ │ 🟡Replica-2 │ │ 🟢Master-2 │ │ 🟢Master-3 │ └──────┬───────┘ └──────┬───────┘ └──────┬───────┘ ▲ │ │ │ ┌────────────────│──────────────────┘ │ │ └──────────────────┐ └──────────────────┐ │ │ │ │ ▼ │ ▼ ┌──────────────┐ ┌──────────────┐ ┌──────────────┐ │ Redis-3 │ │ Redis-4 │ │ Redis-5 │ │ 🟡Replica-1 │ │ 🟢Master-1 │ │ 🟡Replica-3 │ └──────────────┘ └──────────────┘ └──────────────┘

2. Failback(原状回復)テスト

1) Redis(Redis-4) ポッド(Pod) 💥 ダウン(delete)

💻 Terminal-1

$ date; kubectl delete pod redis-cluster-4	-> 時刻: 11:05:49

💻 Redis-4 ログ

① 49秒 Redis ダウン (+0秒)
② 52秒 Redis 再起動 (+3秒)
③ 55秒マスター -> 複製へ転換 (+6秒)

📄 redis.log

1:signal-handler (1788660349) Received SIGTERM scheduling shutdown...
1:M 11:05:49.852 *📍Redis ダウン: User requested shutdown...
1:M 11:05:52.004 *📍Redis 再起動: Server initialized
1:S 11:05:55.865 *📍マスター -> レプリカへ転換: Before turning into a replica, ...

Redis-4 全ログ ▼

📄 redis.log

1:signal-handler (1788660349) Received SIGTERM scheduling shutdown...
1:M 11:05:49.852 *📍User requested shutdown...
1:M 11:05:49.852 * Waiting for replicas before shutting down.
1:M 11:05:50.054 * 1 of 1 replicas are in sync when shutting down.
1:M 11:05:50.054 * Calling fsync() on the AOF file.
1:M 11:05:50.060 * Removing the pid file.
1:M 11:05:50.060 # Redis is now ready to exit, bye bye...
1:C 11:05:52.001 # WARNING: Changing databases number from 16 to 1 since we are in cluster mode
1:C 11:05:52.001 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 11:05:52.001 * Redis version=8.8.1, bits=64, commit=00000000, modified=1, pid=1, just started
1:C 11:05:52.001 * Configuration loaded
1:M 11:05:52.002 * monotonic clock: POSIX clock_gettime
                   Redis Open Source
1:M 11:05:52.003 * Node configuration loaded, I'm 11fae5f5710ff5dff65ea6c7865ca0a628458362
1:M 11:05:52.004 *📍Server initialized
1:M 11:05:52.005 * Reading RDB base file on AOF loading...
1:M 11:05:52.005 * Loading RDB produced by version 8.8.1
1:M 11:05:52.005 * RDB age 1127569 seconds
1:M 11:05:52.005 * RDB memory usage when created 553.06 Mb
1:M 11:05:52.005 * RDB is base AOF
1:M 11:05:55.187 * Done loading RDB, keys loaded: 3240388, keys expired: 0.
1:M 11:05:55.187 * DB loaded from base file aof.3.base.rdb: 3.183 seconds
1:M 11:05:55.856 * DB loaded from incr file aof.3.incr.aof: 0.668 seconds
1:M 11:05:55.856 * DB loaded from append only file: 3.851 seconds
1:M 11:05:55.860 * Opening AOF incr file aof.3.incr.aof on server start
1:M 11:05:55.860 * Ready to accept connections tcp
1:M 11:05:55.865 * Configuration change detected. Reconfiguring myself as a replica of aa8df00ebc2f7ac3001804dd01b75181249b16e1 (redis-cluster-0)
1:S 11:05:55.865 *📍Before turning into a replica, using my own master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
1:S 11:05:55.865 * Connecting to MASTER 10.42.0.208:18504
1:S 11:05:55.865 * MASTER <-> REPLICA sync started
1:S 11:05:55.866 * Cluster state changed: ok
1:S 11:05:55.870 * Non blocking connect for SYNC fired the event.
1:S 11:05:55.874 * Master replied to PING, replication can continue...
1:S 11:05:55.874 * Trying a partial resynchronization (request c663cc92a44ee197afdeb6e737aa6dde6ddbcb29:527159456).
1:S 11:05:55.875 * PSYNC is not possible, initialize RDB channel.
1:S 11:05:58.085 * Starting to receive RDB and replication stream in parallel.
1:S 11:05:58.094 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
1:S 11:06:00.140 * Discarding previously cached master state.
1:S 11:06:00.140 * MASTER <-> REPLICA sync: Loading DB in memory
1:S 11:06:00.145 * MASTER <-> REPLICA sync: Flushing old data
1:S 11:06:00.380 * Loading RDB produced by version 8.8.1
1:S 11:06:00.380 * RDB age 2 seconds
1:S 11:06:00.380 * RDB memory usage when created 332.27 Mb
1:S 11:06:02.021 * Done loading RDB, keys loaded: 1943407, keys expired: 0.
1:S 11:06:02.021 * Removing the RDB file obtained from the master. This replica has persistence disabled
1:S 11:06:02.021 * MASTER <-> REPLICA sync: Finished with success
1:S 11:06:02.021 * MASTER <-> REPLICA sync: Starting AOF after a successful sync
1:S 11:06:02.021 * Creating AOF incr file temp-aof.incr on background rewrite
1:S 11:06:02.033 * Background append only file rewriting started by pid 19
1:S 11:06:02.033 * MASTER <-> REPLICA sync: Starting to stream replication buffer into the db (463 bytes).
1:S 11:06:02.034 * MASTER <-> REPLICA sync: Successfully streamed replication buffer into the db (463 bytes in total)
19:C 11:06:04.126 * BGSAVE done, 1943407 keys saved, 0 keys skipped, 244865779 bytes written.
19:C 11:06:04.130 * Successfully created the temporary AOF base file temp-rewriteaof-bg-19.aof
19:C 11:06:04.139 * Fork CoW for AOF rewrite: current 152 MB, peak 152 MB, average 80 MB
1:S 11:06:04.245 * Background AOF rewrite terminated with success
1:S 11:06:04.246 * Successfully renamed the temporary AOF base file temp-rewriteaof-bg-19.aof into aof.4.base.rdb
1:S 11:06:04.246 * Successfully renamed the temporary AOF incr file temp-aof.incr into aof.4.incr.aof
1:S 11:06:04.248 * Removing the history file aof.3.incr.aof in the background
1:S 11:06:04.248 * Removing the history file aof.3.base.rdb in the background
1:S 11:06:04.251 * Background AOF rewrite finished successfully

💻 Redis-0 ログ

① 50秒マスターとの接続切断 (+1秒)
② 55秒複製 -> マスターへ転換 (+5秒)

📄 redis.log

1:S 11:05:50.092 *📍Connection with master lost.
1:M 11:05:55.784 *📍Discarding previously cached master state.

Redis-0 全ログ ▼

📄 redis.log

1:S 11:05:50.092 *📍Connection with master lost.
1:S 11:05:50.092 * Caching the disconnected master state.
1:S 11:05:50.092 * Reconnecting to MASTER 10.42.0.175:18504
1:S 11:05:50.092 * MASTER <-> REPLICA sync started
1:S 11:05:50.092 # Error condition on socket for SYNC: Connection refused
1:S 11:05:51.053 * Connecting to MASTER 10.42.0.175:18504
1:S 11:05:51.053 * MASTER <-> REPLICA sync started
1:S 11:05:54.777 * FAIL message received from 9eba06300dd9acd8f994aa9faa8765009c7de4e9 (redis-cluster-2) about 11fae5f5710ff5dff65ea6c7865ca0a628458362 (redis-cluster-4)
1:S 11:05:54.869 * Start of election delayed for 869 milliseconds (rank #0, offset 527159455).
1:S 11:05:55.773 * Starting a failover election for epoch 13.
1:S 11:05:55.784 * Failover election won: I'm the new master.
1:S 11:05:55.784 * configEpoch set to 13 after successful failover
1:M 11:05:55.784 *📍Discarding previously cached master state.
1:M 11:05:55.784 * Setting secondary replication ID to 50b86caf74cae2c28d5e66e362f9e0fc4c1230da, valid up to offset: 527159456. New replication ID is 9f1b65b33a8f3f098ce81e49a44dba0863e1ee65
1:M 11:05:55.862 * Address updated for node 11fae5f5710ff5dff65ea6c7865ca0a628458362 (redis-cluster-4), now 10.42.0.209:18504
1:M 11:05:55.870 * A failover occurred in shard 68bd5bbafb1ea037e69667f5c9cd85d514ddf106; node 11fae5f5710ff5dff65ea6c7865ca0a628458362 () lost 0 slot(s) to node aa8df00ebc2f7ac3001804dd01b75181249b16e1 (redis-cluster-0) with a config epoch of 13
1:M 11:05:55.874 * Clear FAIL state for node 11fae5f5710ff5dff65ea6c7865ca0a628458362 (redis-cluster-4):replica is reachable again.
1:M 11:05:55.874 * Replica 10.42.0.209:18504 asks for synchronization
1:M 11:05:55.874 * Partial resynchronization not accepted: Replication ID mismatch (Replica asked for 'c663cc92a44ee197afdeb6e737aa6dde6ddbcb29', my replication IDs are '9f1b65b33a8f3f098ce81e49a44dba0863e1ee65' and '50b86caf74cae2c28d5e66e362f9e0fc4c1230da')
1:M 11:05:55.874 * Replica 10.42.0.209:18504 is capable of rdb channel synchronization, and partial sync isn't possible. Full sync will continue with dedicated rdb channel.
1:M 11:05:55.875 * Replica 10.42.0.209:18504 asks for synchronization
1:M 11:05:55.875 * Full resync requested by replica 10.42.0.209:18504 (rdb-channel)
1:M 11:05:55.875 * Delay next BGSAVE for diskless SYNC
1:M 11:05:58.085 * Starting BGSAVE for SYNC with target: replicas sockets (rdb-channel)
1:M 11:05:58.085 * Starting to deliver RDB and replication stream to replica: 10.42.0.209:18504
1:M 11:05:58.089 * Background RDB transfer started by pid 20 to replica socket
20:C 11:06:00.135 * BGSAVE done, 1943407 keys saved, 0 keys skipped, 244865912 bytes written.
20:C 11:06:00.139 * Fork CoW for RDB: current 1 MB, peak 1 MB, average 1 MB
1:M 11:06:00.202 * Background RDB transfer terminated with success
1:M 11:06:00.202 * Synchronization with replica 10.42.0.209:18504 succeeded
1:M 11:06:00.202 * Streamed RDB transfer with replica 10.42.0.209:18504 succeeded (socket). Waiting for REPLCONF ACK from replica to enable streaming
1:M 11:06:00.202 * RDB transfer completed, rdb only replica (10.42.0.209:18504) should be disconnected asap
1:M 11:06:00.202 * Connection with replica (rdbchannel) 10.42.0.209:18504 lost.

💻 App ログ

① 50秒 Redis-4 接続切断 (+1秒)
② 54秒~56秒 5件入力失敗 (+4秒~+6秒) の後、Redis-0 がマスターへ転換(昇格)し正常入力されます
③ 59秒 Redis-4 接続成功 (+10秒)

💻 Terminal-2

T11:05:50.193  INFO 📍Reconnecting, last destination was redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504  
T11:05:54.723 ERROR 📍[FAIL] Key: keyA-00000821 -> Error after retries: Redis exception
T11:05:56.223 ERROR 📍[FAIL] Key: keyA-00000836 -> Error after retries: Redis exception
T11:05:59.896  INFO 📍Reconnected to redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504

App 全ログ ▼

💻 Terminal-2

T11:05:50.193  INFO [xecutorLoop-1-1] i.l.core.protocol.ConnectionWatchdog     :📍Reconnecting, last destination was redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:50.194  WARN [ioEventLoop-4-8] i.l.core.protocol.ConnectionWatchdog     : Cannot reconnect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: Connection refused: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:50.623  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000820 -> Normal operation in progress...
T11:05:51.284  WARN [ioEventLoop-4-5] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:51.623  INFO [         task-8] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000830 -> Normal operation in progress...
T11:05:52.622  INFO [         task-4] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000840 -> Normal operation in progress...
T11:05:53.283  WARN [ioEventLoop-4-1] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:53.622  INFO [         task-8] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000850 -> Normal operation in progress...
T11:05:54.597  WARN [ioEventLoop-4-5] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:54.723 ERROR [         task-2] c.r.K.RedisOperationService              :📍[FAIL] Key: keyA-00000821 -> Error after retries: Redis exception
T11:05:55.123 ERROR [         task-6] c.r.K.RedisOperationService              :  [FAIL] Key: keyA-00000825 -> Error after retries: Redis exception
T11:05:55.523 ERROR [         task-7] c.r.K.RedisOperationService              :  [FAIL] Key: keyA-00000829 -> Error after retries: Redis exception
T11:05:55.697  WARN [ioEventLoop-4-8] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:55.793  INFO [xecutorLoop-1-5] i.l.core.protocol.ConnectionWatchdog     : Reconnecting, last destination was redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504
T11:05:55.823 ERROR [         task-3] c.r.K.RedisOperationService              :  [FAIL] Key: keyA-00000832 -> Error after retries: Redis exception
T11:05:56.223 ERROR [         task-5] c.r.K.RedisOperationService              :📍[FAIL] Key: keyA-00000836 -> Error after retries: Redis exception
T11:05:56.225  INFO [         task-5] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000870 -> Normal operation in progress...
T11:05:56.795  WARN [ioEventLoop-4-6] i.l.core.protocol.ConnectionWatchdog     : Cannot reconnect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:56.796  WARN [ioEventLoop-4-3] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:56.832  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000880 -> Normal operation in progress...
T11:05:57.124  INFO [         task-6] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000860 -> Normal operation in progress...
T11:05:57.623  INFO [         task-4] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000890 -> Normal operation in progress...
T11:05:57.995  WARN [ioEventLoop-4-6] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:58.623  INFO [         task-8] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000900 -> Normal operation in progress...
T11:05:59.284  WARN [ioEventLoop-4-8] i.l.c.c.t.DefaultClusterTopologyRefresh  : Unable to connect to [redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504]: connection timed out after 1000 ms: redis-cluster-4.redis-cluster-service.default.svc.cluster.local/10.42.0.175:18504
T11:05:59.622  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000910 -> Normal operation in progress...
T11:05:59.896  INFO [ioEventLoop-4-7] i.l.core.protocol.ReconnectionHandler    :📍Reconnected to redis-cluster-4.redis-cluster-service.default.svc.cluster.local/<unresolved>:18504
T11:06:00.623  INFO [         task-4] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000920 -> Normal operation in progress...
T11:06:01.622  INFO [         task-1] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000930 -> Normal operation in progress...
T11:06:02.622  INFO [         task-8] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000940 -> Normal operation in progress...
T11:06:03.623  INFO [         task-3] c.r.K.RedisOperationService              :  [SUCCESS] Key: keyA-00000950 -> Normal operation in progress...

🖧 Redis-Cluster ポッド(Pod) ダイアグラム: 原状回復状態 (Redis-0 Master-1)

🧑‍💻 テスト検討と核心まとめ

今回の障害対応(Failover/Failback)テストで、クバネティス(Kubernetes) 環境の Redis-Cluster と Java(Spring Boot / Lettuce) アプリケーション間の実際の障害対応動作とクラスタトポロジー再構成過程を検証しました。

⏱️ 障害対応タイムライン (Timeline)

区分	時刻 (相対時間)	Redis Cluster ノード(Node) 動作	Java (Spring) App 動作
障害発生	11:04:49 (+0秒)	Master(Redis-0) ポッド(Pod) 終了 (delete)	Redis-0 接続切断とバックグラウンド再接続試行。 📍正常ノード(Node)(Redis-1, 2)向けデータは Async 処理によりブロッキングなく入力成功し続ける (11:04:50~)
再試行上限到達	11:04:53~54 (+4~5秒)	Replica(Redis-4) が障害検知後、昇格投票(Election) 進行中	Redis-0 スロット向けの一部リクエスト(4件)がバックグラウンド 5回(5秒)再試行しきい値を超えて最終失敗(FAIL)処理
Failover 完了	11:04:54 (+5秒)	投票完了後 Replica(Redis-4) を新規 Master へ昇格	クラスタトポロジー更新試行 (ClusterTopologyRefresh)
完全正常化	11:04:55 (+6秒)	新規 Master(Redis-4) が該当スロット(0~5460)の書き込み/読み取り開始	変更トポロジーが適用されすべてのスロットへのデータが再び100%正常(SUCCESS)書き込み再開
旧マスター再起動	11:04:59 (+10秒)	再起動した旧マスター(Redis-0)が新規マスター(Redis-4)の Replica ノード(Node)へ再構成	Redis-0 ノード(Node) 接続再確立(Reconnected) 完了

💡 実務適用のための核心示唆 (Key Takeaways) ▼

1. Redis-0 マスターがダウンしても、生きている Redis-1,2 には正常に入力されます
2. Cluster ノード(Node)間の障害検知と昇格時間 (約4~5秒):
Master ノード(Node)がダウンすると、残りのノード(Node)が cluster-node-timeout の間状態を確認(FAIL 判定)したあと、Replica ノード(Node)が自動昇格するまで 約4~5秒のダウンタイムが発生します。
3. Spring / Lettuce クライアントの Dynamic Topology Refresh(トポロジー自動更新)の重要性:
Redis Cluster 環境では Master ノード(Node)が変わると、そのノード(Node)が担当していたハッシュスロット(Hash Slot)の所有権が移ります。 Spring App(Lettuce)の クラスタトポロジー自動更新オプションが動き、変わった Master IP とスロット情報をリアルタイムで検知したため、別途のサービス再起動なしで連携が維持されました。
4. Client-Side Retry(5秒)の効果と限界:
1回目のテスト(Redis-0 ダウン)では App の Retry(5秒)範囲内である5秒時点で Failover が完了し、成功率100%(消失0件)でした。一方、2回目のテスト(Redis-4 ダウン)ではトポロジー再調整時間の差で1件の失敗リクエスト(keyA-00000607)が発生しました。したがって実務では App Retry だけでなく、非同期キュー処理と再試行メカニズムを合わせて設計しなければ完全な無停止は保証できません。
5. Cluster の自動ノード(Node)役割再構成(Re-configuration):
復旧した旧 Master(Redis-0) ノード(Node)が再び起動すると、クラスタバス経由で変わったノード(Node)状態を受け取り、自動で新規 Master(Redis-4)の Replica ノード(Node)へ転換します。したがって管理者の手動介入なしでも、クラスタ全体の HA(高可用性)ターゲット数が復旧します。
6. ユーザ体験(UX)とタイムアウトの考慮事項:
クライアント観点では、障害発生時に約4~5秒の応答遅延(Latency)が発生します。 Web/App フロントエンド API 呼び出し時にユーザ画面が止まらないよう、Front-end Timeout と Circuit Breaker(Resilience4j など)を適切に組み合わせることを推奨します。

🛡️ Front-end Timeout と Circuit Breaker の説明 ▼

🛡️ Redis 障害時にシステム麻痺を防ぐ安全装置

Sentinel の障害対応(Failover)中に発生する 4~5秒の応答遅延(Latency) は、バックエンドサーバとユーザ画面へ障害が伝わる連鎖障害(Cascading Failure)を起こし得ます。これを防ぐため、実務では次の2つの安全装置を必ず組み合わせて構築します。

1. Front-end Timeout (フロントエンドタイムアウト)

ユーザのブラウザやモバイルアプリがバックエンド API を呼んだあと、「応答が来ないときに無限待ちせず、リクエストを諦める最大時間」です。

問題状況 (Timeout 未設定時): Redis 障害中に4秒応答が止まると、焦ったユーザが '再読み込み' や 'ボタン' を連打します。これによりバックエンド Tomcat/Spring スレッド(Thread)が枯渇し、Web サーバ全体がダウンします。
解決策 (2~3秒 Timeout 適用): 2秒以内に応答がなければ直ちにリクエストを止め、「一時的なネットワーク遅延です。しばらくして再試行してください」 という案内を出してバックエンド暴走を遮断します。

2. Circuit Breaker (サーキットブレーカ - Resilience4j)

電気盤の '遮断器' のようにバックエンド(Spring) アプリケーション内部に置き、Redis 障害検知時に 遮断器を開いて(Open) Redis への接続試行を直ちに止めるライブラリです。

[正常状態] 🟢 CLOSED ──(エラー/遅延の急増)──► 🔴 OPEN [遮断状態: 直ちに Fallback 実行] ▲ │ │ │ (設定した待機時間後) └────────────── (成功検証) ─────────── 🟡 HALF-OPEN [少数リクエストのテスト]

🟢 CLOSED (正常): すべてのキャッシュ/データリクエストを Redis へ正常に渡します。
🔴 OPEN (遮断): Redis 遅延/エラー率が指定値を超えると遮断器を開き、 Redis 呼び出しを試みず、あらかじめ準備した代替ロジック(Fallback: 例: Main RDB 直接照会)を直ちに実行します。
🟡 HALF-OPEN (検証): Redis が復旧したか確認するため少数のリクエストだけ送り、正常動作が確認できれば再び 🟢 CLOSED 状態へ戻します。

🔄 障害発生時の2技術の連携プロセス

0秒 (Redis Master ダウン): Sentinel が Failover を始め、応答遅延が発生
1~2秒 (Circuit Breaker 作動): Spring App の Resilience4j がエラー/遅延を検知し、遮断器を 🔴 OPEN へ転換 ➔ Redis の代わりに RDB 照会またはデフォルト値返却(Fallback)
2秒 (Front-end Timeout 作動): フロントエンドがリクエストを安全に切り、無限ローディングとユーザ連打による WAS 暴走を防止
4~5秒 (Failover 完了 & 自動復旧): Sentinel が新規 Master 昇格を完了すると、Resilience4j がそれを検知して 🟢 CLOSED に戻し、キャッシュサービスを自動正常化

<< K8s Redis-Cluster App ①	K8s Redis-Sentinel 準備 ① >>

Email 返事がかかってなれば、メールでお知らせします。