Azure Database for PostgreSQLの一時的な接続エラーに対処する

はじめに

Azureが提供しているデータベースには、下記のドキュメントにあるように一時的な接続エラーに対処する必要があります。

• 一時的なエラーへの対応 - Azure SQL Database | Microsoft Docs
• 一時的な接続エラー - Azure Database for MySQL | Microsoft Docs
• Azure Database for PostgreSQL - Single Server の一時的な接続エラーに対処する | Microsoft Docs

この対処方法をSpring Bootで実装してみることにしました。

参考サイト

以下のサイトに参考となりそうな記事がありましたので、それを元に実装してみます。

www.linkedin.com

ライブラリの追加

Spring Boot向けのリトライを実装するライブラリとしてSpring Retryというものがあるのでこれを利用します。

github.com

Gradleではbuild.gradleにてdependenciesの中に以下の記述を追加すれば良いようです。

implementation 'org.springframework.retry:spring-retry:1.3.1'
runtimeOnly 'org.springframework.boot:spring-boot-starter-aop'

リトライ処理の実装

getConnectionメソッドに対して@Retryableでリトライするようにします。

public class RetryableDataSource extends AbstractDataSource {
    private final DataSource dataSource;

    public RetryableDataSource(DataSource dataSource) {
        this.dataSource = dataSource;
    }

    @Override
    @Retryable(maxAttempts = 12, backoff = @Backoff(delay = 5_000, maxDelay = 10_000))
    public Connection getConnection() throws SQLException {
        return dataSource.getConnection();
    }

    @Override
    @Retryable(maxAttempts = 12, backoff = @Backoff(delay = 5_000, maxDelay = 10_000))
    public Connection getConnection(String username, String password) throws SQLException {
        return dataSource.getConnection(username, password);
    }
}

上記のClassを使うようにします。

@Order(value = Ordered.HIGHEST_PRECEDENCE)
@Component
public class RetryableDatabasePostProcessor implements BeanPostProcessor {
    @Override
    public Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {
        if (bean instanceof DataSource) {
            return new RetryableDataSource((DataSource) bean);
        }
        return bean;
    }

    @Override
    public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
        return bean;
    }
}

アプリの実装

Spring BootのCommandLineRunnerを使って簡単なバッチ処理を実装します。1件ずつレコードをinsertして1秒スリープします。

@Service
public class MyService {
    private static final Logger log =
            LoggerFactory.getLogger(MyService.class);
    @Value("${app.records.num:100}")
    private int RECORDS_NUM;

    @Autowired
    JdbcTemplate jdbcTemplate;

    public void insert() {
        log.info("Start insert method...");
        for (int i = 0; i < RECORDS_NUM; i++) {
            String first_name = String.format("Josh%05d", i);
            String last_name = String.format("hogehoge%05d", i);
            log.info("Insert record. i = [" + i + "], first_name = [" + first_name + "], last_name = [" + last_name + "]");
            jdbcTemplate.update("INSERT INTO customers(first_name, last_name) VALUES (?, ?)", first_name, last_name);
            try {
                Thread.sleep(1_000);
            } catch (InterruptedException e) {
                log.info("Thread.sleep occurs InterruptedException. i = [" + i + "]");
            }
        }
        log.info("End insert method...");
    }
}

確認方法

一時的な接続エラーを確認する方法として、上記のドキュメントには、

たとえば、Azure Database for PostgreSQL サーバーのコンピューティング リソースをスケールアップまたはスケールダウンしているときに、実際のコードを実行してみましょう。

とあるので、プログラムが動いているときにスケールアップ／スケールダウンしてみます。ここではvCoreを変更します。

確認（リトライ処理なし）

リトライ処理を実装していないプログラムにおいて、スケールアップ／スケールダウンしてみます。スケールアップ／スケールダウンしたタイミングでHikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@xxxxxxxx (This connection has been closed.). Possibly consider using a shorter maxLifetime value.が出力されます。以下のように異常終了してしまいました。

2021-10-24 04:40:06.573  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [40], first_name = 
2021-10-24 04:40:07.590  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [41], first_name = 
2021-10-24 04:40:08.620  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [42], first_name = 
2021-10-24 04:40:09.635  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [43], first_name = 
2021-10-24 04:40:09.650  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.668  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.670  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.677  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.680  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.685  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.686  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.688  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.689  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:09.697  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate conn
2021-10-24 04:40:39.649  INFO 18 --- [           main] ConditionEvaluationReportLoggingListener : "
Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled."
    at org.postgresql.core.PGStream.receiveChar(PGStream.java:445) ~[postgresql-42.2.23.jar:42.2.23]"
Caused by: org.postgresql.util.PSQLException: The connection attempt failed."
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197) ~[HikariCP-4.0.3.jar:na]"
    at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.Driver.connect(Driver.java:264) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:960) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]"
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]"
    at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.run(SpringBootRetryDbApplication.java:19) ~[classes/:na]"
    at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:161) ~[postgresql-42.2.23.jar:42.2.23]"
    ... 15 common frames omitted"
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:315) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at com.zaxxer.hikari.pool.HikariPool.access$100(HikariPool.java:71) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1015) ~[spring-jdbc-5.3.10.jar:5.3.10]"
java.lang.IllegalStateException: Failed to execute CommandLineRunner"
    at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.Driver.makeConnection(Driver.java:465) ~[postgresql-42.2.23.jar:42.2.23]"
    at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) ~[HikariCP-4.0.3.jar:na]"
    at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364) ~[HikariCP-4.0.3.jar:na]"
    at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206) ~[HikariCP-4.0.3.jar:na]"
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]"
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) ~[workspace/:na]"
    at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:598) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:213) ~[postgresql-42.2.23.jar:42.2.23]"
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:794) ~[spring-boot-2.5.5.jar:2.5.5]"
Caused by: java.io.EOFException: null"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.main(SpringBootRetryDbApplication.java:14) ~[classes/:na]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:345) ~[spring-boot-2.5.5.jar:2.5.5]"
    at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476) ~[HikariCP-4.0.3.jar:na]"
2021-10-24 04:40:39.738 ERROR 18 --- [           main] o.s.boot.SpringApplication               : Application run failed"
    at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    ... 20 common frames omitted"
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) ~[workspace/:na]"
    at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:726) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:775) ~[spring-boot-2.5.5.jar:2.5.5]"
Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQL
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1025) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:791) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[workspace/:na]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[workspace/:na]"
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:82) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:646) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:712) ~[HikariCP-4.0.3.jar:na]"
    at com.github.miyohide.springbootretrydb.MyService.insert(MyService.java:30) ~[classes/:na]"
    ... 13 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30001ms.
2021-10-24 04:40:39.748  INFO 18 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-10-24 04:40:40.631  INFO 18 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.

確認（リトライ処理あり）

リトライ処理を実装しているプログラムにおいて、スケールアップ／スケールダウンしてみます。スケールアップ／スケールダウンしたタイミングでHikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@xxxxxxxx (This connection has been closed.). Possibly consider using a shorter maxLifetime value.が出力されます。ですが、リトライ処理が行われ以下のように正常終了しました。

2021-10-24 04:50:41.404  INFO 18 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
2021-10-24 04:50:42.452 DEBUG 18 --- [           main] o.s.retry.support.RetryTemplate          : Retry: count=0"
2021-10-24 04:50:42.452  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [40], first_name = [Josh00040], last_name = [hogehoge00040]"
2021-10-24 04:50:42.454  INFO 18 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
2021-10-24 04:50:42.472  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@40a72e
2021-10-24 04:50:44.535  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@59c70c
2021-10-24 04:50:44.538  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@46f902
2021-10-24 04:50:44.544  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@64f981
2021-10-24 04:50:44.546  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@361abd
2021-10-24 04:50:44.548  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@575b5f
2021-10-24 04:50:44.550  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@59bbb9
2021-10-24 04:50:44.556  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@7165d5
2021-10-24 04:50:44.568  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@12f49c
2021-10-24 04:50:44.571  WARN 18 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@1fd989
2021-10-24 04:51:21.001  INFO 18 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
2021-10-24 04:51:21.001 DEBUG 18 --- [           main] o.s.retry.support.RetryTemplate          : Retry: count=1"
2021-10-24 04:51:21.001 DEBUG 18 --- [           main] o.s.retry.support.RetryTemplate          : Checking for rethrow: count=1"
2021-10-24 04:51:26.592 DEBUG 18 --- [           main] o.s.retry.support.RetryTemplate          : Retry: count=0"
2021-10-24 04:51:26.592  INFO 18 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
2021-10-24 04:51:26.591  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [41], first_name = [Josh00041], last_name = [hogehoge00041]"
2021-10-24 04:51:27.603  INFO 18 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [42], first_name = [Josh00042], last_name = [hogehoge00042]"

トランザクションをかけてみる

これでOKかなと思いましたが、insertメソッドに@Transactionalをつけて動かし、PostgreSQLのスケールアップ／スケールダウンをすると異常終了してしまいました。

2021-10-24 05:02:50.882  INFO 20 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [47], first_name = [Josh00047],
2021-10-24 05:02:51.976  INFO 20 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [48], first_name = [Josh00048],
2021-10-24 05:02:52.981  INFO 20 --- [           main] c.g.m.springbootretrydb.MyService        : Insert record. i = [49], first_name = [Josh00049],
    at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source) ~[na:na]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:791) ~[spring-boot-2.5.5.jar:2.5.5]"
    at java.base/java.io.BufferedOutputStream.flush(Unknown Source) ~[na:na]"
    at com.github.miyohide.springbootretrydb.MyService.insert(MyService.java:30) ~[classes/:na]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332) ~[spring-boot-2.5.5.jar:2.5.5]"
    at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(Unknown Source) ~[na:na]"
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.10.jar:5.3.10]"
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.10.
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.run(SpringBootRetryDbApplication.java:21) ~[classes/:na]"
    at com.github.miyohide.springbootretrydb.MyService$$FastClassBySpringCGLIB$$4d334926.invoke(<generated>) ~[classes/:na]"
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) ~[workspace/:na]"
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar:na]"
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481) ~[postgresql-42.2.23.jar:42.2.23]"
2021-10-24 05:02:53.020  WARN 20 --- [           main] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Connection org.postgresql.jdbc.PgCo
Caused by: java.net.SocketException: Connection reset by peer (Write failed)"
    at java.base/java.net.SocketOutputStream.write(Unknown Source) ~[na:na]"
    at org.postgresql.core.PGStream.flush(PGStream.java:665) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401) ~[postgresql-42.2.23.jar:42.2.23]"
    at java.base/java.net.SocketOutputStream.socketWrite(Unknown Source) ~[na:na]"
    at java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(Unknown Source) ~[na:na]"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.main(SpringBootRetryDbApplication.java:13) ~[classes/:na]"
    at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:130) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:775) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:349) ~[postgresql-42.2.23.jar:42.2.23]"
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:960) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.10.jar:5.3.10]"
    at java.base/java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:na]"
    at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1025) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[workspace/:na]"
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]"
    at com.github.miyohide.springbootretrydb.MyService$$EnhancerBySpringCGLIB$$df81f8ea.insert(<generated>) ~[classes/:na]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.postgresql.core.v3.QueryExecutorImpl.sendSync(QueryExecutorImpl.java:1469) ~[postgresql-42.2.23.jar:42.2.23]"
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:320) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.10.jar:5.3.10]"
org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend."
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1015) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[workspace/:na]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:345) ~[spring-boot-2.5.5.jar:2.5.5]"
    ... 39 common frames omitted"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:164) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.10.jar:5.3.10]"
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) ~[workspace/:na]"
2021-10-24 05:02:53.606  INFO 20 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
2021-10-24 05:02:53.606 DEBUG 20 --- [           main] o.s.retry.support.RetryTemplate          : Retry: count=0"
2021-10-24 05:02:53.613  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.626  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.631  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.640  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.643  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.644  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.646  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.654  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:02:53.656  WARN 20 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.p
2021-10-24 05:03:31.336 DEBUG 20 --- [           main] o.s.retry.support.RetryTemplate          : Checking for rethrow: count=1"
2021-10-24 05:03:31.339 DEBUG 20 --- [           main] o.s.retry.support.RetryTemplate          : Retry: count=1"
2021-10-24 05:03:31.340  INFO 20 --- [           main] c.g.m.s.config.RetryableDataSource       : getting connection ..."
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) ~[workspace/:na]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:960) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at java.base/java.io.BufferedOutputStream.flush(Unknown Source) ~[na:na]"
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:70) ~[spring-jdbc
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:345) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:791) ~[spring-boot-2.5.5.jar:2.5.5]"
    at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(Unknown Source) ~[na:na]"
    at java.base/java.io.BufferedOutputStream.flushBuffer(Unknown Source) ~[na:na]"
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:164) ~[postgresql-42.2.23.jar:42.2.23]"
    ... 31 common frames omitted"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1015) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79) ~[spring-jdbc
    at java.base/java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:na]"
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79) ~[spring-jdbc
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779) ~[spring-aop-5.3.10.jar:5.3.10]"
    ... 39 common frames omitted"
    at java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(Unknown Source) ~[na:na]"
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar:na]"
    at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:130) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.10.
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[workspace/:na]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.10.jar:5.3.10]"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.run(SpringBootRetryDbApplication.java:21) ~[classes/:na]"
    at java.base/java.net.SocketOutputStream.write(Unknown Source) ~[na:na]"
    at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:775) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[workspace/:na]"
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]"
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:667) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at com.github.miyohide.springbootretrydb.MyService$$FastClassBySpringCGLIB$$4d334926.invoke(<generated>) ~[classes/:na]"
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:349) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.core.v3.QueryExecutorImpl.sendSync(QueryExecutorImpl.java:1469) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.core.PGStream.flush(PGStream.java:665) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) ~[workspace/:na]"
    at com.github.miyohide.springbootretrydb.MyService$$EnhancerBySpringCGLIB$$df81f8ea.insert(<generated>) ~[classes/:na]"
org.springframework.dao.DataAccessResourceFailureException: PreparedStatementCallback; SQL [INSERT INTO customers(first_name, last_name) VALUES (?, 
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.10.jar:5.3.10]"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.main(SpringBootRetryDbApplication.java:13) ~[classes/:na]"
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:320) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1025) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:107) ~[spring-jdbc-5.3.10.jar:5
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar:na]"
    at com.github.miyohide.springbootretrydb.MyService.insert(MyService.java:30) ~[classes/:na]"
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481) ~[postgresql-42.2.23.jar:42.2.23]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.10.jar:5.3.10]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.10.jar:5.3.10]"
Caused by: java.net.SocketException: Connection reset by peer (Write failed)"
2021-10-24 05:03:36.548 ERROR 20 --- [           main] o.s.t.i.TransactionInterceptor           : Application exception overridden by rollback excep
    at java.base/java.net.SocketOutputStream.socketWrite(Unknown Source) ~[na:na]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]"
    at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1541) ~[spring-jdbc-5.3.10.jar:5.3.10]"
Caused by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend."
Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled."
2021-10-24 05:03:36.581  INFO 20 --- [           main] ConditionEvaluationReportLoggingListener : "
    at com.sun.proxy.$Proxy53.rollback(Unknown Source) ~[na:na]"
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) ~[workspace/:na]"
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.10.jar:5.3.10]"
2021-10-24 05:03:36.758 ERROR 20 --- [           main] o.s.boot.SpringApplication               : Application run failed"
    at com.zaxxer.hikari.pool.ProxyConnection.rollback(ProxyConnection.java:396) ~[HikariCP-4.0.3.jar:na]"
java.lang.IllegalStateException: Failed to execute CommandLineRunner"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) ~[workspace/:na]"
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[workspace/:na]"
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:835) ~[sprin
    at com.zaxxer.hikari.pool.HikariProxyConnection.rollback(HikariProxyConnection.java) ~[HikariCP-4.0.3.jar:na]"
    at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]"
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.10.jar:5.3.10]"
    at com.github.miyohide.springbootretrydb.MyService$$EnhancerBySpringCGLIB$$df81f8ea.insert(<generated>) ~[classes/:na]"
Caused by: org.springframework.transaction.TransactionSystemException: JDBC rollback failed; nested exception is java.sql.SQLException: Connection i
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332) ~[spring-boot-2.5.5.jar:2.5.5]"
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]"
    at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:775) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:794) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:392) ~[spring-tx-5.3
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    ... 24 common frames omitted"
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:348) ~[spring-jdbc-5.3.10.jar:5.3
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:809) ~[spring-tx-5.
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]"
    at org.springframework.jdbc.support.JdbcTransactionManager.translateException(JdbcTransactionManager.java:188) ~[spring-jdbc-5.3.10.jar:5.3.10]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:345) ~[spring-boot-2.5.5.jar:2.5.5]"
Caused by: java.sql.SQLException: Connection is closed"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.main(SpringBootRetryDbApplication.java:13) ~[classes/:na]"
    ... 13 common frames omitted"
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.5.jar:2.5.5]"
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.10.jar:5.3.10]"
    at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:672) ~[spri
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.translateException(DataSourceTransactionManager.java:435) ~[spring-jdbc-5.3.10
    at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:515) ~[HikariCP-4.0.3.jar:na]"
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doRollback(DataSourceTransactionManager.java:351) ~[spring-jdbc-5.3.10.jar:5.3
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[workspace/:na]"
    at com.github.miyohide.springbootretrydb.SpringBootRetryDbApplication.run(SpringBootRetryDbApplication.java:21) ~[classes/:na]"
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:791) ~[spring-boot-2.5.5.jar:2.5.5]"
2021-10-24 05:03:36.767  INFO 20 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated..."
2021-10-24 05:03:37.197  INFO 20 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed."

この対応についてはもう少し検討してみたいと思います。とりあえず今日はここまで。 続きを書きました。

miyohide.hatenablog.com

Azure Container InstanceでSpring Batchのアプリを動かす（5）ログをAzure Monitorログに送る

Azure Container InstanceでSpring Batchのアプリを動かすことをやっています。過去の内容は以下を参照してください。

• Azure Container InstanceでSpring Batchのアプリを動かす（2） - miyohide's blog
• Azure Container InstancesでSpring Batchのアプリを動かす - miyohide's blog
• Azure Container InstanceでSpring Batchのアプリを動かす（3）Azure ファイル共有をマウントする - miyohide's blog
• Azure Container InstanceでSpring Batchのアプリを動かす（4）Azure Container Instance上のアプリを定期実行する - miyohide's blog

今回は、ログをAzure Monitorログ（Log Analytics ワークスペース）に送ることをやってみます。

参考記事

マイクロソフトのドキュメントに参考となる記事があります。その記事を参考にして作業を進めます。

docs.microsoft.com

TerraformでLog Analytics ワークスペースを作成する

これまでTerraformで環境を作っていたので、ここでもTerraformで環境を作ります。Log Analytics ワークスペースを作成するには以下のように記述します。

resource "azurerm_log_analytics_workspace" "log" {
  location            = azurerm_resource_group.rg.location
  name                = var.log_analytics_workspace_name
  resource_group_name = azurerm_resource_group.rg.name
}

上記では名前とリソースグループ名、ロケーションだけを指定しています。これだけでも動きますが、細かい設定をするために参考となるドキュメントは以下にあります。

https://registry.terraform.io/providers/hashicorp/azurerm/latest/docs/resources/log_analytics_workspace

Container Instanceと紐づける

作成したAzure Monitorログ（Log Analytics ワークスペース）とContainer Instanceとを紐づけます。azurerm_container_groupの中でdiagnosticsブロックの下にlog_analyticsブロックをつくり、そこでAzure Monitorログ（Log Analytics ワークスペース）のidやキーを指定します。Terraformでの設定例は以下の通り。

data "azurerm_log_analytics_workspace" "log" {
  name                = var.log_analytics_workspace_name
  resource_group_name = var.app_resource_group_name
}

resource "azurerm_container_group" "aci" {
  location            = var.app_resource_group_location
  name                = var.container_instance_name
  os_type             = "linux"
  resource_group_name = var.app_resource_group_name
  # 省略
  # Log Analytics Workspaceの設定
  diagnostics {
    log_analytics {
      workspace_id = data.azurerm_log_analytics_workspace.log.workspace_id
      workspace_key = data.azurerm_log_analytics_workspace.log.primary_shared_key
    }
  }
}

動かしてみる

これで準備は完了。Spring Batchのアプリを動かすと、ログがAzure Monitorログ（Log Analytics ワークスペース）に送られます。プログラムとしてAzure Monitorログ（Log Analytics ワークスペース）に送信ために特別なことは何もしておらず、標準出力に出力された内容がそのままAzure Monitorログ（Log Analytics ワークスペース）に送信されます。

また、上記のドキュメントにも書かれていますが、Azure Monitorログ（Log Analytics ワークスペース）にログが送信されるようになるには最大で10分ほど待つ必要があるので、慌てずにじっくり待ちましょう。

Container Instance起動後、Azure Monitorログ（Log Analytics ワークスペース）を確認するとContainerInstanceLog_CLの中身を確認すると、以下のようにログが送信されていました。

メッセージを確認したいので、project演算子を使って時刻とメッセージを確認します。

docs.microsoft.com

結果は以下の通り。

プログラムやSpring Batchによるログ出力が確認できました。

Azure Container InstanceでSpring Batchのアプリを動かす（4）Azure Container Instance上のアプリを定期実行する

Azure Container InstanceでSpring Batchのアプリを動かすことをやっています。過去の内容は以下を参照してください。

• Azure Container InstanceでSpring Batchのアプリを動かす（2） - miyohide's blog
• Azure Container InstancesでSpring Batchのアプリを動かす - miyohide's blog
• Azure Container InstanceでSpring Batchのアプリを動かす（3）Azure ファイル共有をマウントする - miyohide's blog

今回作ったSpring BatchアプリはCSVファイルを読み取ってデータベースに追記する処理を行うものです。このアプリを定期実行することをやってみます。

Logic Appsを使ってみる

定期実行する仕組みは色々あるかと思いますが、今回はLogic Appsを利用することにします。

docs.microsoft.com

Azure Portal上でLogic Appsを作ると、以下のような画面が出てLogic Appsの操作がわかるようになっています。

画面をスクロールするといろいろとテンプレートが表示されるのですが、今回は「空のテンプレート」を選択します。こんな画面になりました。

スケジュールトリガーとAzure Container Instanceコネクタの利用

目的の定期実行を達成するには、スケジュールトリガーとAzure Container Instanceコネクタを利用すると良さそうです。ドキュメントは以下のものを参考にしました。

スケジュールトリガーは以下のもの。 docs.microsoft.com

Azure Container Instanceコネクタは以下のもの。 docs.microsoft.com

コネクタにはたくさんありますが、「コンテナー グループ内のコンテナーを開始する」を使いました。

作成結果は以下の通り。

5分ごとに起動するようにしました。

実行

5分ごとに起動するように設定したので、その動作を確認します。設定通り5分ごとに処理が行われています。

それぞれの行をクリックすると各ステップごとの実行時間などがわかるようです。

Azure Container Instance自身もLogic Appsのタイミングで起動しています。

やってみてわかりましたが、実行ごとにイメージの取得から行うようです。大きいイメージの場合は実際の処理時間とずれが顕著に現れるかもしれません。

Azure Container InstanceでSpring Batchのアプリを動かす（3）Azure ファイル共有をマウントする

Azure Container InstanceでSpring Batchのアプリを動かすことをやっています。過去の内容は以下を参照してください。

• Azure Container InstanceでSpring Batchのアプリを動かす（2） - miyohide's blog
• Azure Container InstancesでSpring Batchのアプリを動かす - miyohide's blog

このSpring Batchアプリはクラスパス内に置いたCSVファイルを読み取ってデータベースに追記する処理を行います。CSVファイルがクラスパス内にあるのはあまり使い勝手が良くないので、外出しすることを考えます。

そこで使えるのがAzureファイル共有です。Azure Container Instanceは以下のドキュメント通りAzureファイル共有をマウントすることができます。

docs.microsoft.com

ここではこの機能を使ってCSVファイルをAzureファイル共有から読み取るようにします。

準備

Terraformを使ってAzure Container InstanceでAzureファイル共有をマウントすることを実装します。まず、ファイル共有を作成します。

# Storage Accountの作成
resource "azurerm_storage_account" "sa" {
  account_replication_type = "LRS"
  account_tier             = "Standard"
  location                 = data.azurerm_resource_group.rg.location
  name                     = var.storage_account_name
  resource_group_name      = data.azurerm_resource_group.rg.name
}

# File Shareの作成
resource "azurerm_storage_share" "ss" {
  name                 = var.file_share_name
  storage_account_name = azurerm_storage_account.sa.name
  quota                = 10
}

このデータを使ってAzure Container Instanceにマウントします。volumeブロックに必要事項を記述すればOKです。

resource "azurerm_container_group" "aci" {
  location            = data.azurerm_resource_group.rg.location
  name                = var.aci_name
  os_type             = "linux"
  resource_group_name = data.azurerm_resource_group.rg.name
  # 省略

  container {
    cpu    = 0.5
    image  = "${data.azurerm_container_registry.acr.login_server}/batch_processing:latest"
    memory = 1.5
    name   = "miyohidebatchapp"
    # 省略

    # File Volumeの設定
    volume {
      mount_path = "/opt/batchapp"
      name       = "filesharevolume"
      read_only  = false
      share_name = azurerm_storage_share.ss.name
      storage_account_name = azurerm_storage_account.sa.name
      storage_account_key = azurerm_storage_account.sa.primary_access_key
    }
  }
}

このTerraformを実行すると、以下のようにファイル共有がマウントされます。

動作確認

プログラムの修正

読み込むCSVファイルのパスを修正します。これまでは、以下のようにClassPathResourceメソッドを使っていましたが、

    @Bean
    public FlatFileItemReader<Person> reader() {
        return new FlatFileItemReaderBuilder<Person>()
                .name("personItemReader")
                .resource(new ClassPathResource("sample-data.csv"))
                .delimited()
                .names("firstName", "lastname")
                .fieldSetMapper(new BeanWrapperFieldSetMapper<>() {{
                    setTargetType(Person.class);
                }})
                .build();
    }

代わりにFileSystemResourceメソッドを使います。上記のTerraformにおいてmount_pathを/opt/batchappにしましたので、その直下にsample-data.csvにあるファイルを読み込ませることにします。

    @Bean
    public FlatFileItemReader<Person> reader() {
        return new FlatFileItemReaderBuilder<Person>()
                .name("personItemReader")
                .resource(new FileSystemResource("/opt/batchapp/sample-data.csv"))
                .delimited()
                .names("firstName", "lastname")
                .fieldSetMapper(new BeanWrapperFieldSetMapper<>() {{
                    setTargetType(Person.class);
                }})
                .build();
    }

読み込むファイルの内容の修正

読み込むファイルの内容に変化を加えて、マウントしたファイル共有からファイルを読み込んでいることを確認します。

Jill,Doe
Joe,Doe
Justin,Doe
Jane,Doe
John,Doe
Atsushi,Nohmi
Kyuji,Fujikawa
Takashi,Toritani

最後3行追加しています。

ファイルをアップロード

修正したファイルをファイル共有にアップロードします。

実行する

Azure Container Instanceを動かしてログを確認すると、無事追加したデータが処理されていることがわかります。

ソース

ここまでのソースは以下の通りです。

github.com

Azure Container InstanceでSpring Batchのアプリを動かす（2）

はじめに

先日、Azure Container InstanceでSpring Batchのアプリを動かすことをやってみました。

miyohide.hatenablog.com

上記の記事ではAzure Portal上で作業をしたのですが、できるだけ自動化したいので今回はTerraformを使って環境の自動化をしてみました。

事前準備

今回のアプリは、Dockerイメージの格納先としてAzure Container Registry、データベースにPostgreSQLを使っていますので、まずはそれらを作成します。データベースのユーザ名やパスワードはKeyVaultに格納しておきます。PostgreSQLの作成については以下の記事でやりました。

miyohide.hatenablog.com

Azure Container Registryについては以下のように書けば良さそうです。

# Azure Container Registryの作成
resource "azurerm_container_registry" "acr" {
  location            = azurerm_resource_group.rg.location
  name                = "いい感じの名前"
  resource_group_name = azurerm_resource_group.rg.name
  sku = "Basic"
  admin_enabled = true
}

Azure Container Instanceを作成する

先程の事前準備のリソースとは別ファイルにAzure Container Instanceを作成するためのTerraform設定ファイルを書きます。Azure Container Instanceの作成にあたってAzure Container Registryなどのデータを使う必要があります。Terraformにて既存のリソースのデータを参照するためには、Data Sourceというものを使えば良いようです。

www.terraform.io

以下のように宣言します。

data "azurerm_resource_group" "rg" {
  name = "rg-batch001"
}

data "azurerm_container_registry" "acr" {
  name                = "いい感じの名前"
  resource_group_name = data.azurerm_resource_group.rg.name
}

# RDBMSのユーザ名とパスワードの参照のために既存のKeyVaultを参照
data "azurerm_key_vault" "kv" {
  name                = var.kv_name
  resource_group_name = var.kv_rg
}

data "azurerm_key_vault_secret" "db-user" {
  key_vault_id = data.azurerm_key_vault.kv.id
  name         = "app-db-user"
}

data "azurerm_key_vault_secret" "db-password" {
  key_vault_id = data.azurerm_key_vault.kv.id
  name         = "app-db-password"
}

その後Azure Container Instanceを作成します。公式ドキュメントを拠り所にします。

https://registry.terraform.io/providers/hashicorp/azurerm/latest/docs/resources/container_group

今回の例ではイメージの取得先はAzure Container Registryですので、image_registry_credentialにて以下のように設定します。

  image_registry_credential {
    password = data.azurerm_container_registry.acr.admin_password
    server   = data.azurerm_container_registry.acr.login_server
    username = data.azurerm_container_registry.acr.admin_username
  }

環境変数の設定はenvironment_variablesかsecure_environment_variablesにて設定できますが、パスワードなどの情報が含まれているためここではsecure_environment_variablesを使います。

    secure_environment_variables = {
      "SPRING_PROFILES_ACTIVE" = "prod",
      "MYAPP_DATASOURCE_URL" = "jdbc:postgresql://${local.postgresql.name}.postgres.database.azure.com:5432/${local.postgresql.dbname}"
      "MYAPP_DATASOURCE_USERNAME" = "${data.azurerm_key_vault_secret.db-user.value}@${local.postgresql.name}",
      "MYAPP_DATASOURCE_PASSWORD" = data.azurerm_key_vault_secret.db-password.value
    }

Azure Portal上では以下のスクリーンショットのようにIPアドレスを「なし」に設定できるのですが、

Terraform上ではPublicかPrivateかの設定しかできなかったので、今回はPublicにしました。

Port番号は指定しないとterraform applyコマンドが失敗しましたので、適当なものを指定しておきました。

    ports {
      port = 443
      protocol = "TCP"
    }

PostgreSQLへの接続情報など、繰り返し同じ値を記述したくはないので、variables.tfにて定数を設定します。

variable "kv_name" {
  type = string
}

variable "kv_rg" {
  type = string
}

locals {
  postgresql = {
    name = "PostgreSQLの名前"
    dbname = "データベースの名前"
  }
}

結果、Azure Container Instanceの設定は以下の通りとなりました。

resource "azurerm_container_group" "aci" {
  location            = data.azurerm_resource_group.rg.location
  name                = "Azure Container Instanceの名前"
  os_type             = "linux"
  resource_group_name = data.azurerm_resource_group.rg.name
  ip_address_type = "Public"
  restart_policy = "Never"

  image_registry_credential {
    password = data.azurerm_container_registry.acr.admin_password
    server   = data.azurerm_container_registry.acr.login_server
    username = data.azurerm_container_registry.acr.admin_username
  }

  container {
    cpu    = 0.5
    image  = "${data.azurerm_container_registry.acr.login_server}/batch_processing:latest"
    memory = 1.5
    name   = "miyohidebatchapp"
    ports {
      port = 443
      protocol = "TCP"
    }
    secure_environment_variables = {
      "SPRING_PROFILES_ACTIVE" = "prod",
      "MYAPP_DATASOURCE_URL" = "jdbc:postgresql://${local.postgresql.name}.postgres.database.azure.com:5432/${local.postgresql.dbname}"
      "MYAPP_DATASOURCE_USERNAME" = "${data.azurerm_key_vault_secret.db-user.value}@${local.postgresql.name}",
      "MYAPP_DATASOURCE_PASSWORD" = data.azurerm_key_vault_secret.db-password.value
    }
  }
}

以上の設定を行うことで、無事Spring Batchのアプリを動かすことができました。

AZ-400 Microsoft DevOpsソリューションの設計と実装に合格した

2021年9月20日に「AZ-400 Microsoft DevOpsソリューションの設計と実装」を受験し、合格しました。

Azure系の認定資格試験はAZ-104とAZ-204を取得していたのですが、さらに上位の認定資格が欲しくなってきたこともあり、馴染みがあったDevOps関係の知識を活かせることができるAZ-400を受けました。

試験勉強

まずはMicrosoft Learnを活用しました。AZ-400で検索してヒットしたものを一通り実施。

docs.microsoft.com

合わせて関連ドキュメントを参照。名前の通り基本はAzure DevOpsが中心ですので、まずは以下のページからドキュメントに目を通すようにしました。

docs.microsoft.com

ただ、多くのドキュメントが機械翻訳っぽいものが多いので、英語のものと合わせて読むと良いかもしれません。

また、Azure DevOpsは無償で結構いろんなことができるので、実際に色々とやってみました。これが一番効果があったような気がします。

Azure DevOpsを一通り触った後はMicrosoft Learnの内容やすでに受験された人のブログ記事などから「これも押さえておいたほうがいいんじゃないかな？」と思ったものを1回は触ってみることにしました。

問題集を解いてみる

力試しという意味合いを込めて、measure upにあるOfficial Practice Testを購入して解いてみることにしました。

www.measureup.com

当然のことながら、問題も解答も解説も全て英語です。私は英語ができる人ではないので、わからない単語や文章が出てきたら辞書を引きながら意味を取るようにしました。

最初の数回は合格ラインに届きませんでしたが、復習などをして知識の定着を図ることにしました。また、ノートに書いたほうが覚えられそうな気がしたので、ノートに各種用語を書くようにしました。

試験

試験はテストセンターで。移動がちょっと面倒くさく常時マスク着用が求められますが、当然誰も喋らずブースで区切られていますし消毒も定期的に実施されているようです。また、私が受けたテストセンターは、最近移転して綺麗な場所でしたので安心感が増しました。

試験の形式は以下のページにあるようにいろいろな形式のものが出ました。

docs.microsoft.com

注意が必要なところは事前に案内が出るので、調子に乗ってサクサクボタンを押すと後で面食らうかもしれません。

時間は2時間弱ありましたが、答えていったら見直し含めても40分ぐらいで終了。海外のベンダーが主催する試験では、英語から日本語への翻訳があまりこなれていないことが多いのですが、この試験は全体的に違和感を覚えることはありませんでした。

試験に対する手応えは半分半分と行った感じ。後半になればなるほど問題の難しさが増した気がしたので、最後の「完了」ボタンを押すのは結構勇気が必要でした。最後は落ちたら落ちたでいいやと思いえいや！と「完了」ボタンを押したら「合格」という文字が見えたのでほっとしました。

今後

とりあえず合格できて一安心と言ったところ。試験勉強の日々から解放されるということでほっとしました。他にもいろんな認定資格の種類があるので、徐々にスキルを伸ばして行けたらいいなと思っています。

Azure Container InstancesでSpring Batchのアプリを動かす

毎週Azure系のネタを書いていたのですが、先週はワクチン2回目接種の副反応で全然動けず。今週からまた再開。

はじめに

コンテナアプリを簡単に動かせるAzure Container Instancesというサービスがあります。

azure.microsoft.com

各種チュートリアルは簡単なWebアプリを動かす例が多いのですが、バッチアプリも動かせたらサーバーレスバッチ環境ができて嬉しくね？と思いやってみました。

題材

バッチアプリの題材として、Spring Guideにあった「Creating a Batch Service」を使ってみます。Spring Batchというバッチフレームワークを使ってCSVファイルを読み込み、簡単な処理を施してRDBMSへ書き込みを行うものです。

spring.io

題材ではHyperSQL Databaseを使っていますが、ここではPostgreSQLを使ってみることにします。RDBMSの変更により少しコードに変更が必要でしたが、あまり本質ではないのでここでは詳細を省略します。

Azure Container Instancesを作成する

右も左も分からないので、Azure Portal上で作成してみます。Webアプリのように外部公開しないので、ネットワークオプションは「なし」を選択しました。

環境変数も作成時の段階で設定します。RDBMSの接続先などをここで指定しておきます。

あとで設定変更できるかなと思っていたのですが、少なくともAzure Portal上では参照のみで追加や編集はできませんでした。

実行する

Azure Container Instancesを作成するとその時点でバッチ処理が動き始めます。ログもAzure Portalから参照することができました。

お馴染みのSpringのロゴが見えます。

無事処理が完了しました。

今後

今回はAzure Portalで色々とやってみましたが、やはり面倒くさいのでAzure CLIやTerraformなどを使って自動化を図りたいと思います。また、Azure File共有をマウントできるようなので、現在はクラスパス内で固定で持たせてある読み込みファイルを外部から読み込めるようにしようかと思っています。

docs.microsoft.com