はじめに

Azure Static Web Appsの検証が思いのほかサクサクできてしまったので、新しいテーマ。今回からはAzure Cache for Redisのベストプラクティスを検証していきたいと思います。

Azure Cache for Redisのドキュメントを見ていると、「接続の回復力に関するベストプラクティス」というドキュメントを見つけました。

docs.microsoft.com

以前、Spring BootアプリからAzure Cache for Redisへの接続をするためのブログ記事を載せたのですが、それをもう少し発展させてより有益な情報としていきたいと思います。

miyohide.hatenablog.com

サンプルアプリの挙動

今回、Azure Cache for Redisへの接続にはSpring Session Data Redisを使います。

spring.io

アプリケーションの挙動は以下の通りです。

/にGETでアクセスすると、セッションの情報（SessionInfoの値）を確認します
値があればそのデータをもとにGreetingオブジェクトを作成して返します
値が無ければセッションにIdやnameなどの値を保存し、Greetingオブジェクトを作成して返します

実装コードとしては以下の通り。

    @GetMapping("/")
    public Greeting greeting(@RequestParam(value = "name", defaultValue = "World") String name) {
        logger.info("GET to '/'. name = [" + name + "], sessionInfo = [" + sessionInfo.toString() + "]");
        if (sessionInfo.getName() == null) {
            sessionInfo.setId(counter.incrementAndGet());
            sessionInfo.setName(name);
            sessionInfo.setCreatedAt(new Date());
        }
        return new Greeting(sessionInfo.getId(), String.format(template, sessionInfo.getName()),
                sessionInfo.getCreatedAt());
    }

ブラウザ画面には次のように表示されます。

f:id:miyohide:20211205154048p:plain

アプリケーションのバージョンアップ

上記ブログで使っていたSpring Bootは2.3.1.RELEASEなので、まずはこれをバージョンアップします。今回使ったバージョンは2.5.7です。

前回検証した時は、SessionConfigクラスを作成する必要がありました。今回、Spring Bootを2.5.7に上げてSessionConfigクラスを消してAzure Cache for Redisに接続してみましたが、以下の例外が出力され起動に失敗しました。

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-12-05 14:59:11.427 ERROR 13036 --- [           main] o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'enableRedisKeyspaceNotificationsInitializer' defined in class path resource [org/springframework/boot/autoconfigure/session/RedisSessionConfiguration$SpringBootRedisHttpSessionConfiguration.class]: Invocation of init method failed; nested exception is org.springframework.data.redis.RedisConnectionFailureException: Unable to connect to Redis; nested exception is io.lettuce.core.RedisConnectionException: Unable to connect to hogehoge.redis.cache.windows.net:6380
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1804) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:944) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:918) ~[spring-context-5.3.13.jar:5.3.13]
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583) ~[spring-context-5.3.13.jar:5.3.13]
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145) ~[spring-boot-2.5.7.jar:2.5.7]
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:765) ~[spring-boot-2.5.7.jar:2.5.7]
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:445) ~[spring-boot-2.5.7.jar:2.5.7]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:338) ~[spring-boot-2.5.7.jar:2.5.7]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1354) ~[spring-boot-2.5.7.jar:2.5.7]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.7.jar:2.5.7]
        at com.example.demo.DemoApplication.main(DemoApplication.java:10) ~[main/:na]
Caused by: org.springframework.data.redis.RedisConnectionFailureException: Unable to connect to Redis; nested exception is io.lettuce.core.RedisConnectionException: Unable to connect to hogehoge.redis.cache.windows.net:6380
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.translateException(LettuceConnectionFactory.java:1689) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.getConnection(LettuceConnectionFactory.java:1597) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.getNativeConnection(LettuceConnectionFactory.java:1383) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$SharedConnection.getConnection(LettuceConnectionFactory.java:1366) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory.getSharedConnection(LettuceConnectionFactory.java:1093) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory.getConnection(LettuceConnectionFactory.java:421) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.session.data.redis.config.annotation.web.http.RedisHttpSessionConfiguration$EnableRedisKeyspaceNotificationsInitializer.afterPropertiesSet(RedisHttpSessionConfiguration.java:331) ~[spring-session-data-redis-2.5.3.jar:2.5.3]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1863) ~[spring-beans-5.3.13.jar:5.3.13]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1800) ~[spring-beans-5.3.13.jar:5.3.13]
        ... 16 common frames omitted
Caused by: io.lettuce.core.RedisConnectionException: Unable to connect to hogehoge.redis.cache.windows.net:6380
        at io.lettuce.core.RedisConnectionException.create(RedisConnectionException.java:78) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
        at io.lettuce.core.RedisConnectionException.create(RedisConnectionException.java:56) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
        at io.lettuce.core.AbstractRedisClient.getConnection(AbstractRedisClient.java:330) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
        at io.lettuce.core.RedisClient.connect(RedisClient.java:216) ~[lettuce-core-6.1.5.RELEASE.jar:6.1.5.RELEASE]
        at org.springframework.data.redis.connection.lettuce.StandaloneConnectionProvider.lambda$getConnection$1(StandaloneConnectionProvider.java:115) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at java.base/java.util.Optional.orElseGet(Optional.java:369) ~[na:na]
        at org.springframework.data.redis.connection.lettuce.StandaloneConnectionProvider.getConnection(StandaloneConnectionProvider.java:115) ~[spring-data-redis-2.5.7.jar:2.5.7]
        at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.getConnection(LettuceConnectionFactory.java:1595) ~[spring-data-redis-2.5.7.jar:2.5.7]
        ... 23 common frames omitted
Caused by: java.io.IOException: Connection reset by peer
        at java.base/sun.nio.ch.FileDispatcherImpl.read0(Native Method) ~[na:na]
        at java.base/sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) ~[na:na]
        at java.base/sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:276) ~[na:na]
        at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:233) ~[na:na]
        at java.base/sun.nio.ch.IOUtil.read(IOUtil.java:223) ~[na:na]
        at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:356) ~[na:na]
        at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:253) ~[netty-buffer-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132) ~[netty-buffer-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:350) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) ~[netty-transport-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[netty-common-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.70.Final.jar:4.1.70.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.70.Final.jar:4.1.70.Final]
        at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]

そのため、まだapplication.propertiesにてspring.redis.ssl=trueを設定し、以下のようなSessionConfigクラスを作ってあげる必要があります。（前回掲載のコードから少しリファクタリング）。

package com.example.demo;

// import文は省略

@Configuration
@EnableRedisHttpSession
public class SessionConfig extends AbstractHttpSessionApplicationInitializer {
  @Bean
  public RedisSerializer<Object> springSessionDefaultRedisSerializer() {
      return new GenericJackson2JsonRedisSerializer();
  }
  @Bean
  public static ConfigureRedisAction configureRedisAction() {
      return ConfigureRedisAction.NO_OP;
  }
}

注）当初、connectionFactoryメソッドも実装していましたが、spring.redis.ssl=trueをapplication.propertiesに設定しておくだけでOKでした。

再起動を実施する

マイクロソフトのドキュメントには、

再起動を使用して修正プログラムをシミュレートし、接続の中断に対するシステムの回復性をテストします。

とあるので、再起動を実施します。

再起動はAzure Portal上から簡単に実施できます。Standard以上ですと複数台のマシンでAzure Cache for Redisが動いているので、再起動対象を一つ選んで「再起動」をクリックするだけです。ここでは「プライマリ」を選択して再起動してみます。

f:id:miyohide:20211205151058p:plain

Azure Portalの画面に表示されますが、「再起動」をクリックしてもすぐに再起動が行われるわけではなく、最大で2分ほど待たされるようです。

f:id:miyohide:20211205151332j:plain

アプリの挙動

再起動を実施してから定期的にブラウザをリロードしてみてセッションの情報を参照するようにしてみます。

ログを見ると再起動して少し待ったタイミングで「Reconnectiong」とか「Reconnected to」という文言が見え再起動による再接続が行われていることがわかります。

2021-12-05 15:37:23.316  INFO 13111 --- [nio-8080-exec-9] com.example.demo.GreetingController      : GET to '/'. name = [World], sessionInfo = [SessionInfo id=[1], name=[ThisIsATest], createdAt=[Sun Dec 05 15:23:32 JST 2021]]
2021-12-05 15:37:23.658  INFO 13111 --- [xecutorLoop-1-1] i.l.core.protocol.ConnectionWatchdog     : Reconnecting, last destination was hogehoge.redis.cache.windows.net/52.253.104.134:6380
2021-12-05 15:37:23.658  INFO 13111 --- [xecutorLoop-1-8] i.l.core.protocol.ConnectionWatchdog     : Reconnecting, last destination was hogehoge.redis.cache.windows.net/52.253.104.134:6380
2021-12-05 15:37:24.082  INFO 13111 --- [ioEventLoop-6-5] i.l.core.protocol.ReconnectionHandler    : Reconnected to hogehoge.redis.cache.windows.net:6380
2021-12-05 15:37:24.094  INFO 13111 --- [io-8080-exec-10] com.example.demo.GreetingController      : GET to '/'. name = [World], sessionInfo = [SessionInfo id=[1], name=[ThisIsATest], createdAt=[Sun Dec 05 15:23:32 JST 2021]]
2021-12-05 15:37:24.362  INFO 13111 --- [ioEventLoop-6-6] i.l.core.protocol.ReconnectionHandler    : Reconnected to hogehoge.redis.cache.windows.net:6380
2021-12-05 15:37:26.834  INFO 13111 --- [nio-8080-exec-1] com.example.demo.GreetingController      : GET to '/'. name = [World], sessionInfo = [SessionInfo id=[1], name=[ThisIsATest], createdAt=[Sun Dec 05 15:23:32 JST 2021]]

また、再接続後もセッションに入っているデータは（今回は）失われていないようでした。ただ、再起動の画面には「データが失われる可能性があります」ということなので、今回はたまたまだったのかもしれません。

なお、今回は再起動時に「プライマリ」を選択しました。今回のように「Reconnectiong」とか「Reconnected to」は「プライマリ」を選択した時に起きる挙動で「レプリカ」を再起動の対象としてもとくに再接続をしているような挙動は見受けられませんでした。