読者です 読者をやめる 読者になる 読者になる

かんがるーさんの日記

最近自分が興味をもったものを調べた時の手順等を書いています。今は Spring Boot をいじっています。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その14 )( spring-boot-gradle-plugin は dependency-management-plugin を自動的に適用するので build.gradle に記述する必要がありませんでした )

概要

記事一覧はこちらです。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その13 )( RestTemplate で WebAPI を呼び出している処理に spring-retry でリトライ処理を入れる ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。

参照したサイト・書籍

目次

  1. まずは単に classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE") をコメントアウトしてみる
  2. dependencyManagement { ... } もコメントアウトするとどうなるのか?
  3. Spring IO Platform の POM を記述した場合と記述しない場合で何が違うのか?
  4. build.gradle を修正する
  5. 次回は。。。

手順

まずは単に classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE")コメントアウトしてみる

build.gradle から dependency-management-plugin に関する部分をコメントアウトしてみます。

buildscript {
    ext {
        springBootVersion = '1.4.4.RELEASE'
    }
    repositories {
        jcenter()
        maven { url "http://repo.spring.io/repo/" }
        maven { url "https://plugins.gradle.org/m2/" }
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
//        classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE")
        // for Error Prone ( http://errorprone.info/ )
        classpath("net.ltgt.gradle:gradle-errorprone-plugin:0.0.9")
        // for Grgit
        classpath("org.ajoberstar:grgit:1.8.0")
        // Gradle Download Task
        classpath("de.undercouch:gradle-download-task:3.2.0")
    }
}

apply plugin: 'java'
apply plugin: 'eclipse'
apply plugin: 'idea'
apply plugin: 'org.springframework.boot'
//apply plugin: 'io.spring.dependency-management'
apply plugin: 'de.undercouch.download'
apply plugin: 'groovy'
apply plugin: 'net.ltgt.errorprone'
apply plugin: 'checkstyle'
apply plugin: 'findbugs'
  • 以下の記述の行をコメントアウトします。
    • classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE")
    • apply plugin: 'io.spring.dependency-management'

コメントアウト後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新すると、エラーは出ずに終了しました。

clean タスク → Rebuild Project → build タスク も実行してみましたが、こちらも無事 “BUILD SUCCESSFUL” が表示されました。

f:id:ksby:20170324004205p:plain

gradlew dependencies コマンドを実行してみると checkstyle が依存する guava のバージョンが 21.0 になっています。Spring Boot 1.4.5 の Appendix F. Dependency versions には com.google.guava:guava の記述はないので、build.gradle に記述している dependencyManagement { imports { mavenBom("io.spring.platform:platform-bom:Athens-SR3") { ... } } } の BOM の内容が反映されていることが確認できます。

checkstyle - The Checkstyle libraries to be used for this project.
\--- com.puppycrawl.tools:checkstyle:7.5.1
     +--- antlr:antlr:2.7.7
     +--- org.antlr:antlr4-runtime:4.6
     +--- commons-beanutils:commons-beanutils:1.9.3
     |    \--- commons-collections:commons-collections:3.2.2
     +--- commons-cli:commons-cli:1.3.1
     \--- com.google.guava:guava:19.0 -> 21.0

よって、Spring IO Platform の BOM を利用したい場合には spring-boot-gradle-plugin だけ記述すればよく、dependency-management-plugin を記述する必要はありませんでした。

dependencyManagement { ... }コメントアウトするとどうなるのか?

更に build.gradle の dependencyManagement { ... } を削除するとどうなるのか興味が湧いたので、試してみます。

//dependencyManagement {
//    imports {
//        mavenBom("io.spring.platform:platform-bom:Athens-SR3") {
//            bomProperty 'commons-lang3.version', '3.5'
//            bomProperty 'guava.version', '21.0'
//        }
//    }
//}

コメントアウト後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新すると、以下のエラーが表示されました。

f:id:ksby:20170324010643p:plain

これだけでは原因が分からないので、コマンドラインから gradlew dependencies コマンドを実行してみると以下のエラーが表示されました。guava と commons-lang3 の依存性解決に失敗したのが原因でした。

f:id:ksby:20170324011130p:plain

Spring Boot 1.4.5 の Appendix F. Dependency versions には guava も commons-lang3 も記述されていないので当然と言えば当然ですね。

build.gradle の dependencies 内で guava と commons-lang3 にバージョン番号を明記してみます。

    compile("com.google.guava:guava:21.0")
    compile("org.apache.commons:commons-lang3:3.5")

変更後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新すると、エラーは出ずに終了しました。

clean タスク → Rebuild Project → build タスク を実行すると、無事 “BUILD SUCCESSFUL” が表示されました。ただしなんか足りないライブラリをダウンロードしています。

f:id:ksby:20170324013347p:plain

gradlew dependencies コマンドを実行してみると checkstyle が依存する Guava のバージョンは 19.0 のままでした。

checkstyle - The Checkstyle libraries to be used for this project.
\--- com.puppycrawl.tools:checkstyle:7.5.1
     +--- antlr:antlr:2.7.7
     +--- org.antlr:antlr4-runtime:4.6
     +--- commons-beanutils:commons-beanutils:1.9.3
     |    \--- commons-collections:commons-collections:3.2.2
     +--- commons-cli:commons-cli:1.3.1
     \--- com.google.guava:guava:19.0

Spring IO Platform の POM を記述した場合と記述しない場合で何が違うのか?

両方の場合の gradlew dependencies コマンドの出力結果を比較してみました。

checkstyle - The Checkstyle libraries to be used for this project.

component 記述した場合 記述しない場合
com.google.guava:guava 21.0 19.0

■errorprone

component 記述した場合 記述しない場合
com.google.guava:guava 21.0 20.0
com.google.code.findbugs:jsr305 3.0.1 3.0.0

findbugs - The FindBugs libraries to be used for this project.

component 記述した場合 記述しない場合
com.google.code.findbugs:jsr305 3.0.1 3.0.0

■上記以外

component 記述した場合 記述しない場合
javax.activation:activation 1.1.1 1.1
com.rabbitmq:amqp-client 3.6.6 3.6.5
org.objenesis:objenesis 2.4 2.1

guava, commons-lang3 以外にも BOM を記述した方がバージョンが上がるものがあります。

build.gradle を修正する

Spring IO Platform の BOM を記述した方が guava や commons-lang3 も依存性解決の対象になって個人的には好みなので、今回は単に dependency-management-plugin の記述だけを削除することにします。

build.gradle を リンク先の内容 に変更した後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新します。問題が出ないことは上に書きましたので、ここでは改めて記述しません。

次回は。。。

Spring Boot 1.4 で一番変更が入ったと聞いているテストクラスのアノテーションを見直します。

ソースコード

build.gradle

buildscript {
    ext {
        springBootVersion = '1.4.4.RELEASE'
    }
    repositories {
        jcenter()
        maven { url "http://repo.spring.io/repo/" }
        maven { url "https://plugins.gradle.org/m2/" }
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
        // for Error Prone ( http://errorprone.info/ )
        classpath("net.ltgt.gradle:gradle-errorprone-plugin:0.0.9")
        // for Grgit
        classpath("org.ajoberstar:grgit:1.8.0")
        // Gradle Download Task
        classpath("de.undercouch:gradle-download-task:3.2.0")
    }
}

apply plugin: 'java'
apply plugin: 'eclipse'
apply plugin: 'idea'
apply plugin: 'org.springframework.boot'
apply plugin: 'de.undercouch.download'
apply plugin: 'groovy'
apply plugin: 'net.ltgt.errorprone'
apply plugin: 'checkstyle'
apply plugin: 'findbugs'
  • classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE") を削除します。
  • apply plugin: 'io.spring.dependency-management' を削除します。

履歴

2017/03/24
初版発行。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( 番外編 )( IntelliJ IDEA に Request mapper Plugin をインストールする )

概要

記事一覧はこちらです。

今朝 Twitter を見ていたら、珍しく IntelliJ IDEA の Plugin に関するメッセージが流れてきました。

Request mapper という名称の Plugin で、@RequestMapping 系のアノテーションに記述した URL を検索・ジャンプすることができる Plugin のようです。

Spring Tool Window の MVC タブでも URL 一覧は表示できますが、Plugin を紹介している動画を見ていると軽快に検索・ジャンプできるように見えて便利そうだったので、入れて試してみたいと思います。

参照したサイト・書籍

目次

  1. Request mapper Plugin をインストールする
  2. Request mapper Plugin を使ってみる

手順

Request mapper Plugin をインストールする

  1. IntelliJ IDEA のメインメニューから「File」-「Settings…」を選択します。

  2. 「Settings」ダイアログが表示されます。画面左側のリストから「Plugins」を選択した後、画面中央下にある「Browse repositories…」ボタンをクリックします。

    f:id:ksby:20170322022832p:plain

  3. 「Browse Repositories」ダイアログが表示されます。左上の検索フィールドに “request mapper” と入力すると、その下のリストに Request mapper Plugin が表示されますので、画面右側に表示される「Install」ボタンをクリックします。

    f:id:ksby:20170322023029p:plain

    Plugin がダウンロードされた後「Install」ボタンが「Restart IntelliJ IDEA」ボタンに変わりますので、クリックします。

  4. 一旦「Settings」ダイアログに戻りますので、画面下の「OK」ボタンをクリックします。

  5. 「Platform and Plugin Updates」ダイアログが表示されますので「Restart」ボタンをクリックします。

  6. IntelliJ IDEA が再起動してインストールは完了です。

Request mapper Plugin を使ってみる

Ctrl+Shift+¥ を入力すると画面中央に検索フィールドが表示されます。

f:id:ksby:20170322024218p:plain

“/” だけ入力すると全ての URL がヒットするようです。URL 一覧を見てみるとテストクラスに記述した “/exceptionHandlerAdviceTest” もヒットしていました。src/main/java の下だけでなく src/main/test の下も対象になるようです。

f:id:ksby:20170322024629p:plain

中間一致検索もしてくれます。例えば “download” という文字を入力すると、URL に “download” という文字が含まれているものだけが表示されます。

f:id:ksby:20170322025026p:plain

またそのまま続けて “view” と入力すると、"download" と “view” という文字が含まれている URL だけが表示されました。大文字小文字の区別はされていないので、検索しやすそうです。

f:id:ksby:20170322025402p:plain

検索文字列のヒットには、途中に “/” が入っているとかは関係ないようです。"resultresponse" と入力すると “result” と “response” という文字が含まれる URL が表示されました。

f:id:ksby:20170322025708p:plain

ただし “result” + “oad” ( “download” の最後の3文字 ) = “resultoad” と入力すると何もヒットしませんでした。単語を区別して検索しているのでしょうか? URL がヒットしないと検索文字列が赤く表示されます。

f:id:ksby:20170322025851p:plain

単に “oad” だとヒットしますね。

f:id:ksby:20170322031011p:plain

検索文字列を他に試していたところ、"resultfile" と “resultby” はヒットするのに “resultdownload” はヒットしませんでした。最初に文字列をヒットした後は、キャメルケースになっているところでヒットするか否かを判断しているようです。

f:id:ksby:20170322030432p:plain f:id:ksby:20170322030537p:plain f:id:ksby:20170322030647p:plain

ヒットした URL 一覧からソースコードにジャンプしたい URL を選択して Enter キーを押すと、対応する箇所にジャンプします。

少し使ってみただけですが、動作が軽快でいいですね! 以前から欲しいと思っていた機能の Plugin なので、しばらく使ってみたいと思います。

履歴

2017/03/22
初版発行。

IntelliJ IDEA を 2016.3.4 → 2016.3.5 へ、Git for Windows を 2.11.1 → 2.12.0 へバージョンアップ

IntelliJ IDEA を 2016.3.4 → 2016.3.5 へバージョンアップする

IntelliJ IDEA の 2016.3.5 がリリースされたのでバージョンアップします。

※ksbysample-webapp-lending プロジェクトを開いた状態でバージョンアップしています。

  1. IntelliJ IDEA のメインメニューから「Help」-「Check for Updates…」を選択します。

  2. 「Platform and Plugin Updates」ダイアログが表示されます。左下に「Update and Restart」ボタンが表示されていますので、「Update and Restart」ボタンをクリックします。

    f:id:ksby:20170321233338p:plain

  3. 再び「Platform and Plugin Updates」ダイアログが表示され CheckStyle-IDEA, JRebel for IntelliJ のアップデートも表示されますので、そのまま「Update and Restart」ボタンをクリックします。

  4. Patch と Plugin がダウンロードされて IntelliJ IDEA が再起動します。

  5. メイン画面が表示されると画面下部に「Indexing…」のメッセージが表示されますので、終了するまで待機します。

    f:id:ksby:20170322001938p:plain

  6. 処理が終了すると Gradle Tool Window のツリーの表示が other グループしかない初期の状態に戻っていますので、左上の「Refresh all Gradle projects」ボタンをクリックして更新します。更新が完了すると build グループ等が表示されます。

  7. clean タスク実行 → Rebuild Project 実行をした後、build タスクを実行して “BUILD SUCCESSFUL” のメッセージが表示されることを確認します。

    f:id:ksby:20170322014357p:plain

  8. Project Tool Window で src/test を選択した後、コンテキストメニューを表示して「Run ‘All Tests’ with Coverage」を選択し、テストが全て成功することを確認します。

    f:id:ksby:20170322014714p:plain

Git for Windows を 2.11.1 → 2.12.0 へバージョンアップする

Git for Windows の 2.12.0 がリリースされていたのでバージョンアップします。

  1. https://git-for-windows.github.io/ の「Download」ボタンをクリックして Git-2.12.0-64-bit.exe をダウンロードします。

  2. Git-2.12.0-64-bit.exe を実行します。

  3. 「Git 2.12.0 Setup」ダイアログが表示されます。[Next >]ボタンをクリックします。

  4. 「Select Components」画面が表示されます。全てのチェックが外れたままであることを確認した後、[Next >]ボタンをクリックします。

  5. 「Adjusting your PATH environment」画面が表示されます。中央の「Use Git from the Windows Command Prompt」が選択されていることを確認後、[Next >]ボタンをクリックします。

  6. 「Configuring the line ending conversions」画面が表示されます。「Checkout Windows-style, commit Unix-style line endings」が選択されていることを確認した後、[Next >]ボタンをクリックします。

  7. 「Configuring the terminal emulator to use with Git Bash」画面が表示されます。「Use Windows'default console window」が選択されていることを確認した後、[Next >]ボタンをクリックします。

  8. 「Configuring extra options」画面が表示されます。「Enable file system caching」だけがチェックされていることを確認した後、[Install]ボタンをクリックします。

  9. インストールが完了すると「Completing the Git Setup Wizard」のメッセージが表示された画面が表示されます。中央の「View ReleaseNotes.html」のチェックを外した後、「Finish」ボタンをクリックしてインストーラーを終了します。

  10. コマンドプロンプトを起動して git のバージョンが git version 2.12.0.windows.1 になっていることを確認します。

    f:id:ksby:20170322015810p:plain

  11. git-cmd.exe を起動して日本語の表示・入力が問題ないかを確認します。

    f:id:ksby:20170322015945p:plain

  12. 特に問題はないようですので、2.12.0 で作業を進めたいと思います。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その13 )( RestTemplate で WebAPI を呼び出している処理に spring-retry でリトライ処理を入れる )

概要

記事一覧はこちらです。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その12 )( RestTemplateBuilder を使用するように変更したらテストが失敗するようになった理由とは? ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • 前回の検証で WebAPI を呼び出している処理にリトライ処理を入れればテストが成功することが分かったので、spring-retry でリトライ処理を入れます。
    • @Retryable アノテーションではなく RetryTemplate クラスで実装します。
    • リトライ処理は、以下のルールにします。
      • Exception.class ( あるいはその継承クラス ) が throw されたらリトライします。
      • 最大5回リトライします。
      • リトライ間隔は5秒固定にします。
      • リトライが全てエラーになった場合には、発生した例外がそのまま throw されるようにします。
  • spring-retry の処理については以前書いた以下の記事を参考にして実装します。

参照したサイト・書籍

目次

  1. build.gradle を変更する
  2. spring-retry でリトライ処理を入れる
  3. 動作確認
  4. メモ書き

手順

build.gradle を変更する

gradlew dependencies を実行すると org.springframework.boot:spring-boot-starter-amqp の依存関係で spring-retry は入っていることが確認できたのですが、

compile - Dependencies for source set 'main'.
..........
+--- org.springframework.boot:spring-boot-starter-amqp: -> 1.4.4.RELEASE
|    +--- org.springframework.boot:spring-boot-starter:1.4.4.RELEASE (*)
|    +--- org.springframework:spring-messaging:4.3.6.RELEASE
|    |    +--- org.springframework:spring-beans:4.3.6.RELEASE (*)
|    |    +--- org.springframework:spring-context:4.3.6.RELEASE (*)
|    |    \--- org.springframework:spring-core:4.3.6.RELEASE
|    \--- org.springframework.amqp:spring-rabbit:1.6.7.RELEASE
|         +--- org.springframework:spring-web:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework.retry:spring-retry:1.1.5.RELEASE
|         |    \--- org.springframework:spring-core:4.0.4.RELEASE -> 4.3.6.RELEASE
|         +--- org.springframework:spring-messaging:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework:spring-context:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework:spring-tx:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- com.rabbitmq:http-client:1.0.0.RELEASE
|         |    +--- org.apache.httpcomponents:httpclient:4.3.6 -> 4.5.2
|         |    |    +--- org.apache.httpcomponents:httpcore:4.4.4 -> 4.4.6
|         |    |    \--- commons-codec:commons-codec:1.9 -> 1.10
|         |    \--- com.fasterxml.jackson.core:jackson-databind:2.5.1 -> 2.8.6 (*)
|         +--- org.springframework.amqp:spring-amqp:1.6.7.RELEASE
|         |    \--- org.springframework:spring-core:4.2.9.RELEASE -> 4.3.6.RELEASE
|         \--- com.rabbitmq:amqp-client:3.6.5 -> 3.6.6
..........

明示的に build.gradle に記述することにします。

  1. build.gradle を リンク先の内容 に変更します。変更後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新します。

spring-retry でリトライ処理を入れる

  1. src/main/java/ksbysample/webapp/lending/config/ApplicationConfig.javaリンク先の内容 に変更します。

  2. src/main/java/ksbysample/webapp/lending/service/calilapi/CalilApiService.javaリンク先の内容 に変更します。

動作確認

  1. clean タスク → Rebuild Project → build タスク を実行して “BUILD SUCCESSFUL” が表示されることを確認します。

    f:id:ksby:20170320190250p:plain

  2. Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行して、テストが全て成功することを確認します。

    f:id:ksby:20170320190701p:plain

メモ書き

メソッドに @Retryable アノテーションを付けるだけでリトライしてくれる訳ではないらしい。@Retryable アノテーションでリトライさせるための条件を忘れているな。。。

ソースコード

build.gradle

dependencies {
    ..........

    // dependency-management-plugin によりバージョン番号が自動で設定されるもの
    // Appendix A. Dependency versions ( http://docs.spring.io/platform/docs/current/reference/htmlsingle/#appendix-dependency-versions ) 参照
    ..........
    compile("org.springframework.session:spring-session")
    compile("org.springframework.retry:spring-retry")
    compile("com.fasterxml.jackson.datatype:jackson-datatype-jsr310")
    ..........
  • compile("org.springframework.retry:spring-retry") を追加します。

ApplicationConfig.java

@Configuration
public class ApplicationConfig {

    ..........

    @Bean
    public RetryTemplate simpleRetryTemplate() {
        RetryTemplate retryTemplate = new RetryTemplate();
        retryTemplate.setRetryPolicy(
                new SimpleRetryPolicy(5, singletonMap(Exception.class, true)));
        FixedBackOffPolicy fixedBackOffPolicy = new FixedBackOffPolicy();
        fixedBackOffPolicy.setBackOffPeriod(5000);
        retryTemplate.setBackOffPolicy(fixedBackOffPolicy);

        return retryTemplate;
    }

}
  • simpleRetryTemplate メソッドを追加します。

CalilApiService.java

@Service
@PropertySource("classpath:calilapi.properties")
public class CalilApiService {

    ..........

    private final RestTemplate restTemplateForCalilApi;

    private final RestTemplate restTemplateForCalilApiByXml;

    private final RetryTemplate simpleRetryTemplate;

    public CalilApiService(@Qualifier("restTemplateForCalilApi") RestTemplate restTemplateForCalilApi
            , @Qualifier("restTemplateForCalilApiByXml") RestTemplate restTemplateForCalilApiByXml
            , @Qualifier("simpleRetryTemplate") RetryTemplate simpleRetryTemplate) {
        this.restTemplateForCalilApi = restTemplateForCalilApi;
        this.restTemplateForCalilApiByXml = restTemplateForCalilApiByXml;
        this.simpleRetryTemplate = simpleRetryTemplate;
    }

    ..........

    public Libraries getLibraryList(String pref) throws Exception {
        // 図書館データベースAPIを呼び出して XMLレスポンスを受信する
        ResponseEntity<String> response = getForEntityWithRetry(this.restTemplateForCalilApi
                , URL_CALILAPI_LIBRALY, String.class, this.calilApiKey, pref);

        // 受信した XMLレスポンスを Javaオブジェクトに変換する
        Serializer serializer = new Persister();
        Libraries libraries = serializer.read(Libraries.class, response.getBody());

        return libraries;
    }

    public LibrariesForJackson2Xml getLibraryListByJackson2Xml(String pref) throws Exception {
        // 図書館データベースAPIを呼び出して XMLレスポンスを受信する
        ResponseEntity<LibrariesForJackson2Xml> response = getForEntityWithRetry(this.restTemplateForCalilApiByXml
                , URL_CALILAPI_LIBRALY, LibrariesForJackson2Xml.class, this.calilApiKey, pref);
        return response.getBody();
    }

    public List<Book> check(String systemid, List<String> isbnList) {
        ..........

        ResponseEntity<CheckApiResponse> response = null;
        String url = URL_CALILAPI_CHECK;
        for (int retry = 0; retry < RETRY_MAX_CNT; retry++) {
            // 蔵書検索APIを呼び出して蔵書の有無と貸出状況を取得する
            response = getForEntityWithRetry(this.restTemplateForCalilApiByXml, url, CheckApiResponse.class, vars);
            logger.info("カーリルの蔵書検索API を呼び出し、レスポンスを取得しました。{}", response.getBody().toString());
            if (response.getBody().getContinueValue() == 0) {
                break;
            }

            ..........
        }

        return response.getBody().getBookList();
    }

    private <T> ResponseEntity<T> getForEntityWithRetry(RestTemplate restTemplate, String url
            , Class<T> responseType, Object... uriVariables) {
        ResponseEntity<T> response = this.simpleRetryTemplate.execute(context -> {
            if (context.getRetryCount() > 0) {
                logger.info("★★★ リトライ回数 = " + context.getRetryCount());
            }
            ResponseEntity<T> innerResponse = restTemplate.getForEntity(url, responseType, uriVariables);
            return innerResponse;
        });

        return response;
    }
  • private final RetryTemplate simpleRetryTemplate; を追加し、コンストラクタインジェクションの処理も追加します。
  • getForEntityWithRetry メソッドを追加します。
  • 以下のメソッド内で RestTemplate#getForEntity を呼び出しているところを getForEntityWithRetry メソッドを使用するように変更します。
    • getLibraryList メソッド
    • getLibraryListByJackson2Xml メソッド
    • check メソッド

履歴

2017/03/20
初版発行。
2017/03/22
* @Retryable アノテーションで実装したのですが、例外が throw されてもリトライしないことに気付いたので、RetryTemplate クラスを使用する方法に修正しました。

Spring Boot + Spring Integration でいろいろ試してみる ( その21 )( MessageChannel に Redis を使用する2 )

概要

記事一覧はこちらです。

参照したサイト・書籍

目次

  1. org.springframework.integration.redis package の Diagram を作成してみる
  2. Redis へ保存する時のフォーマットを JSON にしてみる
  3. 1プロセス内で受信・出力側をマルチスレッドにしてみる
  4. メモ書き
    1. build.gradle に記述する compile("org.springframework.integration:spring-integration-...") に何があるかは、どこを見ると分かるのか?
    2. Spring IO Platform の BOM の後に Spring Cloud の BOM を記述すると Gradle の checkstyle plugin に適用される Guava のバージョンが 21.0 にならない

手順

org.springframework.integration.redis package の Diagram を作成してみる

Spring Integration Reference Manual - 24. Redis Support の説明は XML ベースで、Spring Integration が Redis 用に用意しているクラスがよく分からないので、IntelliJ IDEA で org.springframework.integration.redis package の Diagram を生成してみます。

RedisChannelMessageStore クラスのソースを表示した後、import 文の “redis” の部分にカーソルを移動してから、コンテキストメニューを表示して「Diagrams」-「Show Diagram…」を選択します。

f:id:ksby:20170319173618p:plain

Diagram が作成されますが package しか表示されていないので展開します。Ctrl+A で全て選択した後、コンテキストメニューを表示して「Expand Nodes」を選択します。

f:id:ksby:20170319180552p:plain

クラスやインターフェースが表示されます。

f:id:ksby:20170319181053p:plain f:id:ksby:20170319181201p:plain

Redis へ保存する時のフォーマットを JSON にしてみる

Redis に保存される時のフォーマットが今のままでは見にくかったので、別のフォーマットにしてみます。

org.springframework.integration.redis.store.RedisChannelMessageStore のソースを見ると、以下のように実装されていました。

  • Key, Value で異なる Serializer がセットされている。
  • Key は RedisTemplate#setKeySerializer で StringRedisSerializer クラスがセットされている。ただし RedisChannelMessageStore には KeySerializer を変更するメソッドは用意されていない。
  • Value は RedisTemplate#setValueSerializer で JdkSerializationRedisSerializer クラスがセットされている。RedisChannelMessageStore にも RedisChannelMessageStore#setValueSerializer が用意されている。

~RedisSerializer クラスが何種類かあるようなので、org.springframework.data.redis.serializer package を Diagram で表示してみます。

f:id:ksby:20170319183944p:plain

Jackson2JsonRedisSerializer というクラスがあったので、これを使用して Value を JSON フォーマットで保存してみます。

src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。

    @Bean
    public RedisChannelMessageStore redisMessageStore() {
        RedisChannelMessageStore messageStore = new RedisChannelMessageStore(this.redisConnectionFactory);
        messageStore.setValueSerializer(new Jackson2JsonRedisSerializer<>(SampleData.class));
        return messageStore;
    }

clean タスク → Rebuild Project → build タスクを実行した後 bootRun を実行すると、以下の例外が出力されました。

2017-03-19 19:38:10.014  INFO [redisqueue,,,] 2864 --- [ask-scheduler-2] o.s.integration.handler.LoggingHandler   : GenericMessage [payload=FlowConfig.SampleData(id=0, createDateTime=2017-03-19T19:38:09.963, message=idGenerator = 02017/03/19 19:38:09 に生成されました), headers={id=439e6e05-e1e5-7db0-f2e1-70e3f0d78b80, timestamp=1489919890012}]
2017-03-19 19:38:10.296 ERROR [redisqueue,de805a358b6b6e2b,de805a358b6b6e2b,true] 2864 --- [ask-scheduler-1] o.s.integration.handler.LoggingHandler   : org.springframework.data.redis.serializer.SerializationException: Could not read JSON: Unrecognized field "payload" (class ksbysample.eipapp.redisqueue.FlowConfig$SampleData), not marked as ignorable (3 known properties: "id", "createDateTime", "message"])
 at [Source: [B@59d3beef; line: 1, column: 1374] (through reference chain: ksbysample.eipapp.redisqueue.FlowConfig$SampleData["payload"]); nested exception is com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "payload" (class ksbysample.eipapp.redisqueue.FlowConfig$SampleData), not marked as ignorable (3 known properties: "id", "createDateTime", "message"])
 at [Source: [B@59d3beef; line: 1, column: 1374] (through reference chain: ksbysample.eipapp.redisqueue.FlowConfig$SampleData["payload"])
    at org.springframework.data.redis.serializer.Jackson2JsonRedisSerializer.deserialize(Jackson2JsonRedisSerializer.java:73)
    at org.springframework.data.redis.core.AbstractOperations.deserializeValue(AbstractOperations.java:315)
    at org.springframework.data.redis.core.AbstractOperations$ValueDeserializingRedisCallback.doInRedis(AbstractOperations.java:55)
    at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:204)
    at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:166)
    at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:88)
    at org.springframework.data.redis.core.DefaultListOperations.rightPop(DefaultListOperations.java:161)
    at org.springframework.data.redis.core.DefaultBoundListOperations.rightPop(DefaultBoundListOperations.java:88)
    at org.springframework.integration.redis.store.RedisChannelMessageStore.pollMessageFromGroup(RedisChannelMessageStore.java:138)
    at org.springframework.integration.store.MessageGroupQueue.doPoll(MessageGroupQueue.java:318)
    at org.springframework.integration.store.MessageGroupQueue.poll(MessageGroupQueue.java:162)
    at org.springframework.integration.store.MessageGroupQueue.poll(MessageGroupQueue.java:49)
    at org.springframework.integration.channel.QueueChannel.doReceive(QueueChannel.java:116)
    at org.springframework.integration.channel.AbstractPollableChannel.receive(AbstractPollableChannel.java:105)
    at org.springframework.integration.endpoint.PollingConsumer.receiveMessage(PollingConsumer.java:192)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint.doPoll(AbstractPollingEndpoint.java:245)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint.access$000(AbstractPollingEndpoint.java:58)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:190)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:186)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:353)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:55)
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:51)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:344)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "payload" (class ksbysample.eipapp.redisqueue.FlowConfig$SampleData), not marked as ignorable (3 known properties: "id", "createDateTime", "message"])
 at [Source: [B@59d3beef; line: 1, column: 1374] (through reference chain: ksbysample.eipapp.redisqueue.FlowConfig$SampleData["payload"])
    at com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException.from(UnrecognizedPropertyException.java:62)
    at com.fasterxml.jackson.databind.DeserializationContext.handleUnknownProperty(DeserializationContext.java:834)
    at com.fasterxml.jackson.databind.deser.std.StdDeserializer.handleUnknownProperty(StdDeserializer.java:1093)
    at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperty(BeanDeserializerBase.java:1485)
    at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperties(BeanDeserializerBase.java:1439)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeUsingPropertyBased(BeanDeserializer.java:487)
    at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeFromObjectUsingNonDefault(BeanDeserializerBase.java:1198)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserializeFromObject(BeanDeserializer.java:314)
    at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:148)
    at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3798)
    at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2967)
    at org.springframework.data.redis.serializer.Jackson2JsonRedisSerializer.deserialize(Jackson2JsonRedisSerializer.java:71)
    ... 32 more

Caused by: com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "payload" (class ksbysample.eipapp.redisqueue.FlowConfig$SampleData), not marked as ignorable (3 known properties: "id", "createDateTime", "message"]) というエラーメッセージが出ています。

Redis を見ると Message は入っていました。

f:id:ksby:20170319194436p:plain

Redis に格納されている Message を以下の操作を行って整形してみます。

  • コマンドプロンプトから文字列をコピーする。
  • 不要な改行コードを削除して 1行にする。
  • \"" へ置換する。
  • 一番最初と最後の " を削除する。
  • IntelliJ IDEA で拡張子が .json のファイルを作成し、そこに編集した文字列をペーストした後、Ctrl+Alt+L を押して整形する。
{
  "payload": {
    "id": 58,
    "createDateTime": {
      "dayOfMonth": 19,
      "dayOfWeek": "SUNDAY",
      "dayOfYear": 78,
      "month": "MARCH",
      "monthValue": 3,
      "year": 2017,
      "hour": 19,
      "minute": 38,
      "nano": 243000000,
      "second": 22,
      "chronology": {
        "id": "ISO",
        "calendarType": "iso8601"
      }
    },
    "message": "idGenerator = 58 \xe3\x81\xaf 2017/03/19 19:38:22 \xe3\x81\xab\xe7\x94\x9f\xe6\x88\x90\xe3\x81\x95\xe3\x82\x8c\xe3\x81\xbe\xe3\x81\x97\xe3\x81\x9f"
  },
  "headers": {
    "X-B3-ParentSpanId": "59580c3007f1dfc4",
    "X-Message-Sent": true,
    "messageSent": true,
    "spanName": "message:redisQueue",
    "spanTraceId": "59580c3007f1dfc4",
    "spanId": "ed3685c62127a187",
    "spanParentSpanId": "59580c3007f1dfc4",
    "X-Span-Name": "message:redisQueue",
    "X-B3-SpanId": "ed3685c62127a187",
    "currentSpan": {
      "begin": 1489919902245,
      "name": "message:redisQueue",
      "traceId": 6437909067757379524,
      "parents": [
        6437909067757379524
      ],
      "spanId": -1353747551971991161,
      "exportable": true,
      "tags": {
        "message/payload-type": "ksbysample.eipapp.redisqueue.FlowConfig.SampleData"
      },
      "logs": [
        {
          "timestamp": 1489919902245,
          "event": "sr"
        }
      ]
    },
    "X-B3-Sampled": "1",
    "X-B3-TraceId": "59580c3007f1dfc4",
    "id": "45f64e56-471e-a2c2-2fe5-09bffc92670a",
    "X-Current-Span": {
      "begin": 1489919902245,
      "name": "message:redisQueue",
      "traceId": 6437909067757379524,
      "parents": [
        6437909067757379524
      ],
      "spanId": -1353747551971991161,
      "exportable": true,
      "tags": {
        "message/payload-type": "ksbysample.eipapp.redisqueue.FlowConfig.SampleData"
      },
      "logs": [
        {
          "timestamp": 1489919902245,
          "event": "sr"
        }
      ]
    },
    "spanSampled": "1",
    "timestamp": 1489919902245
  }
}
  • Redis には入っていることから送信はできるが受信ができていない。
  • JdkSerializationRedisSerializer クラスの場合には問題なかったが、Jackson2JsonRedisSerializer クラスに変えただけだとこの問題が発生する。

ということでしょうか。。。

そしていろいろ調べた結果、分かったことは。。。簡単にやるのは無理!ということでした。

  • Jackson2JsonRedisSerializer クラスは Spring Data Redis の機能として用意されているクラスであり、Spring Integration の Redis Support 用に作られたものではない。
  • serializer に Jackson2JsonRedisSerializer クラスを指定した場合、Message の serialize は行われるが deserialize で引っかかる。いろいろ試してみたら payload はまだ何とかなるが、MessageHeaders クラスの deserialize がうまくいかない。Jackson 用に専用の converter か何かを作り込めば何とかなるのかもしれないが、そこまではやりたくないな。。。

とりあえず現時点での結論は、Redis に Message を入れる時はデフォルトでセットされている JdkSerializationRedisSerializer クラスをそのまま使いましょう、ということにします。

1プロセス内で受信・出力側をマルチスレッドにしてみる

マルチプロセスでの受信・出力は問題なかったので、今度は1つのプロセス内でマルチスレッドで受信・出力してみます。

上で org.springframework.integration.redis package の Diagram を作成した時に RedisQueueMessageDrivenEndpoint クラスというのを見つけました。コードを見てみると MessageProducerSupport の継承クラスでしたので、MessageProducer として使えそうです。今回はこれを使用してみます。

src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。

@Slf4j
@Configuration
public class FlowConfig {

    private static final String REDIS_LISTS_NAME = "REDIS_QUEUE";

    ..........

    @Bean
    public QueueChannel redisQueue() {
        return MessageChannels.queue("redisQueue", redisMessageStore(), REDIS_LISTS_NAME).get();
    }

    @Bean
    public MessageProducerSupport redisMessageProducer() {
        RedisQueueMessageDrivenEndpoint messageProducer
                = new RedisQueueMessageDrivenEndpoint(REDIS_LISTS_NAME, this.redisConnectionFactory);
        messageProducer.setTaskExecutor(Executors.newFixedThreadPool(5));
        messageProducer.setRecoveryInterval(1000);
        // setExpectMessage(true) を入れないと Redis Lists から取得したデータ ( headers + SampleData オブジェクトの payload )
        // が全て payload にセットされる
        messageProducer.setExpectMessage(true);
        return messageProducer;
    }

    ..........

    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisMessageProducer())
                .<SampleData>handle((p, h) -> {
                    log.info("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }

}
  • クラスに @Slf4j アノテーションを付加します。
  • redisQueue メソッドと redisMessageProducer メソッドで同じ MessageChannel を指定するので、private static final String REDIS_LISTS_NAME = "REDIS_QUEUE"; を追加します。
  • redisQueue メソッド内で "REDIS_QUEUE"REDIS_LISTS_NAME へ変更します。
  • redisMessageProducer メソッドを追加します。メソッド内で messageProducer.setTaskExecutor(Executors.newFixedThreadPool(5)); を記述して5スレッドでメッセージを受信するようにします。
  • printFlow メソッドの以下の点を変更します。
    • .from(redisQueue()).from(redisMessageProducer()) へ変更します。
    • .bridge(e -> e.poller(Pollers.fixedDelay(1000))) を削除します。
    • System.out.println("★★★ " + p.getMessage());log.info("★★★ " + p.getMessage()); へ変更し、スレッド名がログに出力されるようにします。

clean タスク → Rebuild Project → build タスクを実行した後 bootRun を実行します。

f:id:ksby:20170320081003p:plain

Message は受信できていますが、全然マルチスレッドになっていませんね。。。 全て [pool-1-thread-1] でした。

この後送受信の時間を変更したりもしてみましたが、結果は同じでマルチスレッドにはなりませんでした。RedisQueueMessageDrivenEndpoint#setTaskExecutor に Executors.newFixedThreadPool(5) とかをセットしてもマルチスレッドにはならないようです。

src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更すれば、Message の受信は1スレッドですが、その後の処理はマルチスレッドにはなります。

    @Bean
    public MessageProducerSupport redisMessageProducer() {
        RedisQueueMessageDrivenEndpoint messageProducer
                = new RedisQueueMessageDrivenEndpoint(REDIS_LISTS_NAME, this.redisConnectionFactory);
        messageProducer.setRecoveryInterval(1000);
        // setExpectMessage(true) を入れないと Redis Lists から取得したデータ ( headers + SampleData オブジェクトの payload )
        // が全て payload にセットされる
        messageProducer.setExpectMessage(true);
        return messageProducer;
    }

    ..........

    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisMessageProducer())
                .log()
                .channel(c -> c.executor(Executors.newFixedThreadPool(5)))
                .<SampleData>handle((p, h) -> {
                    log.info("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }
  • redisMessageProducer メソッドから messageProducer.setTaskExecutor(Executors.newFixedThreadPool(5)); を削除します。
  • printFlow メソッドの以下の点を変更します。
    • .from(...) の直後に .log().channel(c -> c.executor(Executors.newFixedThreadPool(5))) を追加します。

bootRun を実行してみます。

f:id:ksby:20170320082154p:plain

メッセージの受信は全て [hannel-adapter1] ですが、その後の処理は全て異なるスレッドになりました。

MessageChannel からの受信処理をマルチスレッドにする方法が調べてもよく分かりませんでした。上の結果も当初の想定とは異なりますが、今回はこれで終了にします。

メモ書き

build.gradle に記述する compile("org.springframework.integration:spring-integration-...") に何があるかは、どこを見ると分かるのか?

どこかに一覧があるのか探してみたところ、spring-projects/spring-integration-java-dslbuild.gradle の dependencies に記載がありました。通常はこれを見るのが早そうです。

また、この build.gradle の dependencies ですが、[ ... ].each { compile( ... ) } という書き方が出来ることを初めて知りました。それ以外にも、

  • apply from: "${rootProject.projectDir}/publish-maven.gradle" という記述があり、publish-maven.gradle も見た感じでは Maven への公開を Gradle で書く方法のようです。
  • Spring Integration の 8.7 Scripting support の関連だと思いますが、org.jruby:jrubyorg.python:jython-standalone が書いてありました。これを入れると Ruty や Python で書いたものが実行できるのでしょうか?

Spring IO Platform の BOM の後に Spring Cloud の BOM を記述すると Gradle の checkstyle plugin に適用される Guava のバージョンが 21.0 にならない

最初 build.gradle の dependencyManagement に以下のように記述していたのですが、

dependencyManagement {
    imports {
        mavenBom("io.spring.platform:platform-bom:Athens-SR4") {
            bomProperty 'commons-lang3.version', '3.5'
            bomProperty 'guava.version', '21.0'
        }
        mavenBom("org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE")
    }
}

この状態で gradlew dependencies を実行してみたところ、checkstyle plugin の Guava のバージョンが 21.0 ではなく 18.0 になっていました。bomProperty 'guava.version', '21.0' の変更がなぜか反映されなくなっています。

checkstyle - The Checkstyle libraries to be used for this project.
\--- com.puppycrawl.tools:checkstyle:7.6
     +--- antlr:antlr:2.7.7
     +--- org.antlr:antlr4-runtime:4.6
     +--- commons-beanutils:commons-beanutils:1.9.3
     |    \--- commons-collections:commons-collections:3.2.2
     +--- commons-cli:commons-cli:1.3.1
     \--- com.google.guava:guava:19.0 -> 18.0

試しに BOM の順番を以下のように変更したところ、

dependencyManagement {
    imports {
        mavenBom("org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE")
        mavenBom("io.spring.platform:platform-bom:Athens-SR4") {
            bomProperty 'commons-lang3.version', '3.5'
            bomProperty 'guava.version', '21.0'
        }
    }
}

checkstyle plugin の Guava のバージョンが 21.0 になりました。

checkstyle - The Checkstyle libraries to be used for this project.
\--- com.puppycrawl.tools:checkstyle:7.6
     +--- antlr:antlr:2.7.7
     +--- org.antlr:antlr4-runtime:4.6
     +--- commons-beanutils:commons-beanutils:1.9.3
     |    \--- commons-collections:commons-collections:3.2.2
     +--- commons-cli:commons-cli:1.3.1
     \--- com.google.guava:guava:19.0 -> 21.0

そもそも BOM を複数書いているサンプルを見たことがなく、BOM を書く順番ってあるのかな?とは思っていましたが、あるようです。

ソースコード

履歴

2017/03/20
初版発行。

Spring Boot + Spring Integration でいろいろ試してみる ( その20 )( MessageChannel に Redis を使用する )

概要

記事一覧はこちらです。

参照したサイト・書籍

  1. Spring Integration Reference Manual - 24. Redis Support
    http://docs.spring.io/spring-integration/reference/html/redis.html

  2. RDB技術者のためのNoSQLガイド

    RDB技術者のためのNoSQLガイド

    RDB技術者のためのNoSQLガイド

  3. logback+MDCでWebアプリのリクエスト内容を簡単にログに出力する方法
    http://qiita.com/namutaka/items/c35c437b7246c5e4d729

目次

  1. ksbysample-eipapp-redisqueue プロジェクトを作成する
  2. サンプルの Flow を作成する
  3. 動作確認
  4. Deprecated trace headers detected. Please upgrade Sleuth to 1.1 or start sending headers present in the TraceMessageHeaders class というログが出力される理由とは?
  5. X-B3-TraceId, X-B3-SpanId がログに出力されない理由とは?
  6. 動作確認2
  7. 動作確認3 ( Message の送信側と受信・出力側を別プロセスにしてみる )
  8. 続く。。。

手順

ksbysample-eipapp-redisqueue プロジェクトを作成する

  1. IntelliJ IDEA で Gradle プロジェクトを作成し、build.gradle を リンク先の内容 に変更します。

  2. ksbysample-eipapp-wiretap プロジェクトのルート直下に config/checkstyle, config/findbugs ディレクトリを作成します。

  3. config/checkstyle の下に ksbysample-eipapp-messaginggateway プロジェクトの config/checkstyle の下にある google_checks.xml をコピーします。

  4. config/findbugs の下に findbugs-exclude.xml を新規作成し、リンク先の内容 の内容に変更します。

  5. src/main/java の下に ksbysample.eipapp.redisqueue パッケージを作成します。

  6. src/main/java/ksbysample/eipapp/redisqueue の下に Application.java を作成し、リンク先の内容 を記述します。

  7. src/main/resources の下に application.properties を作成し、リンク先の内容 を記述します。

  8. src/main/resources の下に logback-spring.xml を作成し、リンク先のその1の内容 を記述します。

サンプルの Flow を作成する

  1. src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を新規作成し、リンク先の内容 を記述します。

動作確認

  1. まずは clean タスク → Rebuild Project → build タスクを実行して正常終了することを確認します。

    f:id:ksby:20170318091131p:plain

  2. http://zipkin.io/pages/quickstart.html から最新の ZipkinServer ( zipkin-server-1.21.0-exec.jar ) をダウンロードして C:\zipkin に保存した後、起動します。今回は起動するだけです。

  3. redis-cli コマンドで Redis の中にデータが入っていないことを確認します。

    f:id:ksby:20170318092849p:plain

  4. bootRun を実行して ksbysample-eipapp-redisqueue を起動します。

    起動後 sampleDataMessageSource() から Message を受信して出力するところまで動いてはいるようですが、その確認の前に以下2点の問題が出ていることに気づきました。

    • Deprecated trace headers detected. Please upgrade Sleuth to 1.1 or start sending headers present in the TraceMessageHeaders class という WARN ログが出力されています。
    • traceId, spanId がログに出力されていません。

    f:id:ksby:20170318133056p:plain

    先にこの2点の問題を解消します。

Deprecated trace headers detected. Please upgrade Sleuth to 1.1 or start sending headers present in the TraceMessageHeaders class というログが出力される理由とは?

Web で検索すると spring-cloud/spring-cloud-sleuth の Deprecated trace headers #467 の Issue がヒットしました。いろいろ書かれていますが、WARN なので気にしなくてよいようです。ログを出さないようにします。

src/main/resources/logback-spring.xmlリンク先のその2の内容 に変更します。

clean タスク → Rebuild Project → build タスクを実行した後、bootRun を実行すると今度はログは出ませんでした。

f:id:ksby:20170318161134p:plain

X-B3-TraceId, X-B3-SpanId がログに出力されない理由とは?

logback+MDCでWebアプリのリクエスト内容を簡単にログに出力する方法 の記事を見つけました。%X{...} は MDC のデータを出力するためのもののようなので、%X{X-B3-TraceId:-} で値が出力されないということは MDC に X-B3-TraceId がセットされていないということでしょうか?

MDC の値を出力してみます。src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。

    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisQueue())
                .bridge(e -> e.poller(Pollers.fixedDelay(30000)))
                .<SampleData>handle((p, h) -> {
                    // MDC のデータを出力する
                    Map<String, String> mdcMap = MDC.getCopyOfContextMap();
                    mdcMap.entrySet().forEach(entry -> System.out.println("[MDC ] " + entry.getKey() + " = " + entry.getValue()));

                    System.out.println("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }

bootRun を実行して MDC にセットされているデータを出力してみましたが、X-B3-TraceId, X-B3-SpanId はセットされていますね。。。

f:id:ksby:20170318184923p:plain

.<SampleData>handle((p, h) -> {...} の中で log.info(...) でログを出力してみます。src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。

@Slf4j
@Configuration
public class FlowConfig {

    ..........

    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisQueue())
                .bridge(e -> e.poller(Pollers.fixedDelay(30000)))
                .<SampleData>handle((p, h) -> {
                    log.info("●●●");

                    System.out.println("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }

}

bootRun を実行すると、今度は X-B3-TraceId, X-B3-SpanId が出力されました。

f:id:ksby:20170318200509p:plain

MessageSource からデータを取得した時 ( GenericMessage [payload=... のログが出力される時 ) から X-B3-TraceId, X-B3-SpanId が出力されるものと思い込んでいましたが、このタイミングではまだ出力されないようです。FlowConfig#printFlow の方でもログを出力していなかったので、X-B3-TraceId, X-B3-SpanId が出力されないのは単に出力されない実装になっていたからでした。

今回は X-B3-TraceId, X-B3-SpanId を確認する必要はないので、このまま進めます。上で修正した内容は元に戻します。

動作確認2

動作確認に戻ります。

  1. redis-cli コマンドで Redis の中にデータが入っていないことを確認します。

    f:id:ksby:20170318203012p:plain

  2. bootRun を実行して ksbysample-eipapp-redisqueue を起動します。Redis にどのようにデータが格納されるのか確認したいので、Message が1~2個 Redis に格納されたと思われるタイミングで ksbysample-eipapp-redisqueue を停止します。

    f:id:ksby:20170318203439p:plain

    Message が2個 Redis に入ったタイミングで停止しました。Redis の状態を確認してみます。

    f:id:ksby:20170318204143p:plain

    “REDIS_QUEUE” という名称の list が作成されており、データが2件存在します。2件のデータを表示してみます。

    f:id:ksby:20170318212143p:plain

    Message が header, payload 全て入っているようですが、これでは内容がほとんど分かりませんね。。。

  3. 再び bootRun を実行して ksbysample-eipapp-redisqueue を起動します。Redis にメッセージが2個入っている状態で起動するので、起動時にデフォルトで出力される最初の1個と合わせて計3個出力されるはずです。

    f:id:ksby:20170318212911p:plain

    Redis に残っていた ID = 1, 2 のデータと、今回起動時に追加された ID = 0 のデータの計3個出力されました。

  4. Redis に残っているデータを削除します。

    f:id:ksby:20170318213508p:plain

動作確認3 ( Message の送信側と受信・出力側を別プロセスにしてみる )

Message を Redis に入れるようにしたので、Message の送信側と受信・出力側を別プロセスにしても動作するはずです。試してみます。

最初に jar ファイルを入れる C:\eipapp\ksbysample-eipapp-redisqueue ディレクトリを作成します。

次に送信側の jar ファイルを作成します。build.gradle を以下のように変更します。

group 'ksbysample'
version '1.0.0-RELEASE-send'

src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。FlowConfig#printFlow をコメントアウトし、送信タイミングを 200ミリ秒へ、受信タイミングを 1000ミリ秒へ変更します。

    @Bean
    public IntegrationFlow mainFlow() {
        return IntegrationFlows
                .from(sampleDataMessageSource()
                        , e -> e.poller(Pollers.fixedDelay(200)))
                .log()
                .channel(redisQueue())
                .get();
    }

//    @Bean
//    public IntegrationFlow printFlow() {
//        return IntegrationFlows
//                .from(redisQueue())
//                .bridge(e -> e.poller(Pollers.fixedDelay(1000)))
//                .<SampleData>handle((p, h) -> {
//                    System.out.println("★★★ " + p.getMessage());
//                    return null;
//                })
//                .get();
//    }

clean タスク → Rebuild Project → build タスクを実行して ksbysample-eipapp-redisqueue-1.0.0-RELEASE-send.jar を作成した後、C:\eipapp\ksbysample-eipapp-redisqueue へコピーします。

受信・出力側の jar ファイルを作成します。build.gradle を以下のように変更します。

group 'ksbysample'
version '1.0.0-RELEASE-recv'

src/main/java/ksbysample/eipapp/redisqueue/FlowConfig.java を以下のように変更します。今度は FlowConfig#mainFlow をコメントアウトします。

//    @Bean
//    public IntegrationFlow mainFlow() {
//        return IntegrationFlows
//                .from(sampleDataMessageSource()
//                        , e -> e.poller(Pollers.fixedDelay(200)))
//                .log()
//                .channel(redisQueue())
//                .get();
//    }

    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisQueue())
                .bridge(e -> e.poller(Pollers.fixedDelay(1000)))
                .<SampleData>handle((p, h) -> {
                    System.out.println("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }

clean タスク → Rebuild Project → build タスクを実行して ksbysample-eipapp-redisqueue-1.0.0-RELEASE-recv.jar を作成した後、C:\eipapp\ksbysample-eipapp-redisqueue へコピーします。

実行してみます。コマンドプロンプトを3つ開き、1つは送信側の jar ファイルを起動し、残りの2つは受信・出力側の jar ファイルを起動します。

f:id:ksby:20170318222520p:plain

一定数出力されたところで送信側の jar ファイルを止めます。結果を見ると、

  • Message は重複して受信・出力されることはありませんでした。片方が受信した Message はもう片方では受信されません。
  • 標準出力に出力するだけの処理で時間がほとんどかからないので、Message の受信は一方のプロセスに偏ってしまいました。

f:id:ksby:20170318223243p:plain

続く。。。

もう少しいろいろ試してみたいことがあるので、続きます。

ソースコード

build.gradle

group 'ksbysample'
version '1.0.0-RELEASE'

buildscript {
    ext {
        springBootVersion = '1.4.5.RELEASE'
    }
    repositories {
        mavenCentral()
        maven { url "http://repo.spring.io/repo/" }
        maven { url "https://plugins.gradle.org/m2/" }
    }
    dependencies {
        classpath("org.springframework.boot:spring-boot-gradle-plugin:${springBootVersion}")
        classpath("io.spring.gradle:dependency-management-plugin:0.6.1.RELEASE")
        // for Error Prone ( http://errorprone.info/ )
        classpath("net.ltgt.gradle:gradle-errorprone-plugin:0.0.9")
    }
}

apply plugin: 'java'
apply plugin: 'eclipse'
apply plugin: 'idea'
apply plugin: 'org.springframework.boot'
apply plugin: 'io.spring.dependency-management'
apply plugin: 'groovy'
apply plugin: 'net.ltgt.errorprone'
apply plugin: 'checkstyle'
apply plugin: 'findbugs'

sourceCompatibility = 1.8
targetCompatibility = 1.8

[compileJava, compileTestGroovy, compileTestJava]*.options*.compilerArgs = ['-Xlint:all,-options,-processing,-path']
compileJava.options.compilerArgs += ['-Xep:RemoveUnusedImports:WARN']

idea {
    module {
        inheritOutputDirs = false
        outputDir = file("$buildDir/classes/main/")
    }
}

checkstyle {
    configFile = file("${rootProject.projectDir}/config/checkstyle/google_checks.xml")
    toolVersion = '7.6'
    sourceSets = [project.sourceSets.main]
}

findbugs {
    toolVersion = '3.0.1'
    sourceSets = [project.sourceSets.main]
    ignoreFailures = true
    effort = "max"
    excludeFilter = file("${rootProject.projectDir}/config/findbugs/findbugs-exclude.xml")
}

tasks.withType(FindBugs) {
    reports {
        xml.enabled = false
        html.enabled = true
    }
}

repositories {
    mavenCentral()
    maven { url "http://repo.spring.io/repo/" }
}

dependencyManagement {
    imports {
        // Spring Could の BOM を先に書かないと Spring IO Platform の bomProperty でのバージョン変更が適用されない
        mavenBom("org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE")
        mavenBom("io.spring.platform:platform-bom:Athens-SR4") {
            bomProperty 'commons-lang3.version', '3.5'
            bomProperty 'guava.version', '21.0'
        }
    }
}

dependencies {
    def spockVersion = "1.1-groovy-2.4-rc-3"
    def lombokVersion = "1.16.12"
    def errorproneVersion = '2.0.15'

    // dependency-management-plugin によりバージョン番号が自動で設定されるもの
    // Appendix A. Dependency versions ( http://docs.spring.io/platform/docs/current/reference/htmlsingle/#appendix-dependency-versions ) 参照
    compile("org.springframework.boot:spring-boot-starter-integration")
    compile("org.springframework.boot:spring-boot-starter-data-redis")
    compile("org.springframework.integration:spring-integration-redis")
    compile("org.codehaus.janino:janino")
    compile("org.apache.commons:commons-lang3")
    compile("com.google.guava:guava")
    testCompile("org.springframework.boot:spring-boot-starter-test")

    // org.springframework.cloud:spring-cloud-dependencies によりバージョン番号が自動で設定されるもの
    // http://projects.spring.io/spring-cloud/ の「Release Trains」参照
    compile("org.springframework.cloud:spring-cloud-starter-zipkin") {
        exclude module: 'spring-boot-starter-web'
    }

    // dependency-management-plugin によりバージョン番号が自動で設定されないもの、あるいは最新バージョンを指定したいもの
    compile("org.springframework.integration:spring-integration-java-dsl:1.2.1.RELEASE")
    testCompile("org.assertj:assertj-core:3.6.2")
    testCompile("org.spockframework:spock-core:${spockVersion}")
    testCompile("org.spockframework:spock-spring:${spockVersion}")

    // for lombok
    compileOnly("org.projectlombok:lombok:${lombokVersion}")
    testCompileOnly("org.projectlombok:lombok:${lombokVersion}")

    // for Error Prone ( http://errorprone.info/ )
    errorprone("com.google.errorprone:error_prone_core:${errorproneVersion}")
    compileOnly("com.google.errorprone:error_prone_annotations:${errorproneVersion}")
}
  • 24. Redis Support を使用するため、以下の2行を記述します。
    • compile(“org.springframework.boot:spring-boot-starter-data-redis”)
    • compile(“org.springframework.integration:spring-integration-redis”)

findbugs-exclude.xml

<?xml version="1.0" encoding="UTF-8"?>
<FindBugsFilter>
</FindBugsFilter>

Application.java

package ksbysample.eipapp.redisqueue;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class Application {

    public static void main(String[] args) {
        SpringApplication.run(Application.class, args);
    }

}

application.properties

spring.application.name=redisqueue
spring.zipkin.base-url=http://localhost:9411/
spring.sleuth.sampler.percentage=1.0

spring.redis.sentinel.master=mymaster
spring.redis.sentinel.nodes=localhost:6381,localhost:6382,localhost:6383
  • Redis への接続設定として以下の2行を記述します。
    • spring.redis.sentinel.master
    • spring.redis.sentinel.nodes

logback-spring.xml

■その1

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>

    <springProperty scope="context" name="springAppName" source="spring.application.name"/>
    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${level:-%5p}) %clr([${springAppName:-},%X{X-B3-TraceId:-},%X{X-B3-SpanId:-},%X{X-Span-Export:-}]){yellow} %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>
</configuration>

■その2

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    ..........

    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>
    <logger name="org.springframework.cloud.sleuth" level="ERROR"/>
</configuration>
  • <logger name="org.springframework.cloud.sleuth" level="ERROR"/> を追加します。

FlowConfig.java

package ksbysample.eipapp.redisqueue;

import lombok.AllArgsConstructor;
import lombok.Data;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.data.redis.connection.RedisConnectionFactory;
import org.springframework.integration.channel.QueueChannel;
import org.springframework.integration.core.MessageSource;
import org.springframework.integration.dsl.IntegrationFlow;
import org.springframework.integration.dsl.IntegrationFlows;
import org.springframework.integration.dsl.channel.MessageChannels;
import org.springframework.integration.dsl.core.Pollers;
import org.springframework.integration.redis.store.RedisChannelMessageStore;
import org.springframework.integration.support.MessageBuilder;
import org.springframework.messaging.Message;

import java.io.Serializable;
import java.time.LocalDateTime;
import java.time.format.DateTimeFormatter;
import java.util.concurrent.atomic.AtomicInteger;

@Configuration
public class FlowConfig {

    private final RedisConnectionFactory redisConnectionFactory;

    public FlowConfig(RedisConnectionFactory redisConnectionFactory) {
        this.redisConnectionFactory = redisConnectionFactory;
    }

    /**
     * Message の palyload にセットする SampleData クラス
     */
    @Data
    @AllArgsConstructor
    public static class SampleData implements Serializable {

        private static final long serialVersionUID = 6103271054731633658L;

        private Integer id;

        private LocalDateTime createDateTime;

        private String message;

    }

    /**
     * SampleData オブジェクトを送信する MessageSource
     */
    public static class SampleDataMessageSource implements MessageSource<SampleData> {

        private AtomicInteger idGenerator = new AtomicInteger(0);

        @Override
        public Message<SampleData> receive() {
            Integer id = idGenerator.getAndIncrement();
            LocalDateTime createDateTime = LocalDateTime.now();
            String message = String.format("idGenerator = %d は %s に生成されました"
                    , id, createDateTime.format(DateTimeFormatter.ofPattern("uuuu/MM/dd HH:mm:ss")));

            SampleData sampleData = new SampleData(id, createDateTime, message);
            return MessageBuilder.withPayload(sampleData).build();
        }

    }

    @Bean
    public MessageSource<SampleData> sampleDataMessageSource() {
        return new SampleDataMessageSource();
    }

    @Bean
    public RedisChannelMessageStore redisMessageStore() {
        return new RedisChannelMessageStore(this.redisConnectionFactory);
    }

    @Bean
    public QueueChannel redisQueue() {
        return MessageChannels.queue("redisQueue", redisMessageStore(), "REDIS_QUEUE").get();
    }

    /**
     * メインフロー
     * 10秒毎に {@link SampleDataMessageSource} から SampleData オブジェクトが payload にセットされた Message を受信し、
     * {@link FlowConfig#redisQueue()} へ送信する
     *
     * @return {@link IntegrationFlow} オブジェクト
     */
    @Bean
    public IntegrationFlow mainFlow() {
        return IntegrationFlows
                .from(sampleDataMessageSource()
                        , e -> e.poller(Pollers.fixedDelay(10000)))
                .log()
                .channel(redisQueue())
                .get();
    }

    /**
     * {@link SampleData} オブジェクトが payload にセットされた Message を受信し、
     * {@link SampleData#getMessage()} の出力結果を標準出力に出力する
     *
     * @return {@link IntegrationFlow} オブジェクト
     */
    @Bean
    public IntegrationFlow printFlow() {
        return IntegrationFlows
                .from(redisQueue())
                .bridge(e -> e.poller(Pollers.fixedDelay(30000)))
                .<SampleData>handle((p, h) -> {
                    System.out.println("★★★ " + p.getMessage());
                    return null;
                })
                .get();
    }

}

履歴

2017/03/18
初版発行。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その12 )( RestTemplateBuilder を使用するように変更したらテストが失敗するようになった理由とは? )

概要

記事一覧はこちらです。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その11 )( Error Prone を 2.0.15 → 2.0.18 へバージョンアップ。。。できませんでした ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • RestTemplate オブジェクトを生成するのに RestTemplateBuilder を使用するように変更したら、 ksbysample.webapp.lending.webapi.library.LibraryControllerTest#間違った都道府県を指定した場合にはエラーが返る のテストが時々失敗する ( 成功する時もある ) ようになったので、その原因を調べます。

参照したサイト・書籍

  1. Spring Boot 1.4+でRestTemplate(HTTPクライアント)を使う
    http://qiita.com/kazuki43zoo/items/7cf3c8ca4f6f2283cefb

  2. square/okhttp
    https://github.com/square/okhttp

目次

  1. どこで、どのようなエラーが発生しているのか?
  2. RestTemplate オブジェクトの生成処理を以前の処理に戻してみる
  3. 失敗するテストを単独で実行してみる
  4. テストが成功する SimpleClientHttpRequestFactory を使った RestTemplate オブジェクトの中身を見てみる
  5. テストが失敗する RestTemplateBuilder を使った RestTemplate オブジェクトの中身を見てみる
  6. 2つの RestTemplate オブジェクトの違いは?
  7. RestTemplateBuilder#detectRequestFactory で RestTemplateBuilder の自動検出を無効にして HttpURLConnection を使うようにしたらテストは成功するのか?
  8. OkHttp 3 だとテストは成功するのか?
  9. Apache HttpComponents HttpClient でもリトライ処理を入れればテストは成功するのか?
  10. ログのレベルを DEBUG に変更してみる
  11. 結局どうするか?

手順

どこで、どのようなエラーが発生しているのか?

clean タスク → Rebuild Project → build タスクを実行すると以下のエラーメッセージが出力されます。

f:id:ksby:20170307234243p:plain

失敗しているテストは以下のコードです。

    @Test
    public void 間違った都道府県を指定した場合にはエラーが返る() throws Exception {
        mvc.noauth.perform(get("/webapi/library/getLibraryList?pref=東a京都"))
                .andExpect(status().isOk())
                .andExpect(content().contentType("application/json;charset=UTF-8"))
                .andExpect(jsonPath("$.errcode", is(-2)))
                .andExpect(jsonPath("$.errmsg", is("都道府県名が正しくありません。")))
                .andExpect(jsonPath("$.content", hasSize(0)));
    }

コンソールの最後に There were failing tests. See the report at: file:///C:/project-springboot/ksbysample-webapp-lending/build/reports/tests/index.html と出力されていますので、このファイルを見てみます。

f:id:ksby:20170308000306p:plain f:id:ksby:20170308000444p:plain

-2 が返ってくるはずが -1 が返ってきたのでテスト失敗と判定されています。

リクエストを送信している /webapi/library/getLibraryList のソース  src/main/java/ksbysample/webapp/lending/webapi/library/LibraryController.java を見ると、ValueRequiredException ではなくそれ以外の例外が throw されたので errorcode が -1 になっているようです。

    @RequestMapping("/getLibraryList")
    public CommonWebApiResponse<List<Library>> getLibraryList(String pref) throws Exception {
        CommonWebApiResponse<List<Library>> response = new CommonWebApiResponse<>();
        response.setContent(Collections.emptyList());

        try {
            Libraries libraries = calilApiService.getLibraryList(pref);
            response.setContent(libraries.getLibraryList());
        } catch (ValueRequiredException e) {
            response.setErrcode(-2);
            response.setErrmsg("都道府県名が正しくありません。");
        } catch (Exception e) {
            logger.error("システムエラーが発生しました。", e);
            response.setErrcode(-1);
            response.setErrmsg("システムエラーが発生しました。");
        }

        return response;
    }

発生している例外を調べます。コンソールにログが出力されるようにするために src/main/resources/logback-unittest.xml を以下のように修正します。

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <!--<root level="OFF"/>-->
    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>
</included>

build タスクではコンソールに INFO ログは出力されないので、Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行します。

f:id:ksby:20170308002854p:plain

発生している例外は Caused by: java.net.SocketTimeoutException: Read timed out でした。タイムアウトの時間は以前とは変えていないのですが。。。

また他のテストを見ていて気づきましたが、src/main/test/ksbysample/webapp/lending/service/calilapi/CalilApiServiceTest.java で同じテストをしているはずなのに、こちらは ValueRequiredException が発生しています。

    @Test
    public void testGetLibraryList_都道府県名が間違っている場合() throws Exception {
        assertThatThrownBy(() -> {
            Libraries libraries = calilApiService.getLibraryList("東a京都");
        }).isInstanceOf(ValueRequiredException.class);
    }

RestTemplate オブジェクトの生成処理を以前の処理に戻してみる

src/main/java/ksbysample/webapp/lending/service/calilapi/CalilApiService.java で今回失敗している処理用の RestTemplate オブジェクトを生成している処理を以前の処理に戻してみます。

        @Bean
        public RestTemplate restTemplateForCalilApi() {
//            return this.restTemplateBuilder
//                    .setConnectTimeout(CONNECT_TIMEOUT)
//                    .setReadTimeout(READ_TIMEOUT)
//                    .rootUri(URL_CALILAPI_ROOT)
//                    .build();

            SimpleClientHttpRequestFactory factory = new SimpleClientHttpRequestFactory();
            factory.setConnectTimeout(CONNECT_TIMEOUT);
            factory.setReadTimeout(READ_TIMEOUT);
            RestTemplate restTemplate = new RestTemplate(factory);
            return restTemplate;
        }

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を何度も実行してみましたが1度もエラーになりません。

f:id:ksby:20170308010357p:plain

RestTemplateBuilder を使うコードにしてみると、

        @Bean
        public RestTemplate restTemplateForCalilApi() {
            return this.restTemplateBuilder
                    .setConnectTimeout(CONNECT_TIMEOUT)
                    .setReadTimeout(READ_TIMEOUT)
                    .rootUri(URL_CALILAPI_ROOT)
                    .build();

//            SimpleClientHttpRequestFactory factory = new SimpleClientHttpRequestFactory();
//            factory.setConnectTimeout(CONNECT_TIMEOUT);
//            factory.setReadTimeout(READ_TIMEOUT);
//            RestTemplate restTemplate = new RestTemplate(factory);
//            return restTemplate;
        }

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行してみますが、5回実行して5回全てテストが失敗しました。

f:id:ksby:20170308011618p:plain

同じ処理だと思っていたのですが、何が違うんでしょうか?

失敗するテストを単独で実行してみる

単独でテストを実行するとどうなるのか、確認してみます。

f:id:ksby:20170311125150p:plain

何回繰り返しても全て成功します。ということは単独では成功するが、全てのテストを通しで実行するとエラーになる現象のようです。

f:id:ksby:20170311125531p:plain

テストが成功する SimpleClientHttpRequestFactory を使った RestTemplate オブジェクトの中身を見てみる

breakpoint を設定した後、LibraryControllerTest#間違った都道府県を指定した場合にはエラーが返る テストメソッドを Debug 実行して生成された RestTemplate オブジェクトがどのような構成になっているのかを確認します。

f:id:ksby:20170308012306p:plain f:id:ksby:20170308013234p:plain

restTemplateForCalilApi の中身を見ていると以下の内容でした。

f:id:ksby:20170308210033p:plain f:id:ksby:20170308210159p:plain

テストが失敗する RestTemplateBuilder を使った RestTemplate オブジェクトの中身を見てみる

RestTemplateBuilder を使った場合の restTemplateForCalilApi の中身を見ていると以下の内容でした。

f:id:ksby:20170308210752p:plain f:id:ksby:20170308210951p:plain f:id:ksby:20170308211112p:plain

2つの RestTemplate オブジェクトの違いは?

  • messageConverters の数が違います。成功する方は size = 7 なのに対し、失敗する方は size = 10 でした。失敗する方は以下の点が違っていました。
    • StringHttpMessageConverter が2つありますが、片方は defaultCharset = “UTF-8” で、もう片方は defaultCharset = “ISO-8859-1” です。ちなみに成功する方にあるのは defaultCharset = “ISO-8859-1” の方です。
    • MappingJackson2HttpMessageConverter, MappingJackson2XmlHttpMessageConverter もそれぞれ2つずつありますが、こちらはどちらも defaultCharset = “UTF-8” で、インスタンスが異なるだけで内容は同じオブジェクトです。
  • uriTemplateHandler も DefaultUriTemplateHandler と RootUriTemplateHandler の違いがありますが、これは RestTemplateBuilder を使うように変更した時に RestTemplateBuilder#rootUri を追加したためと思われます。
  • requestFactory も異なっており、成功する方は SimpleClientHttpRequestFactory、失敗する方は HttpComponentsClientHttpRequestFactory でした。

タイムアウトしているという状況を考えると requestFactory の違いが影響しているように思えます。SimpleClientHttpRequestFactory と HttpComponentsClientHttpRequestFactory がそれぞれ何なのか調べてみたところ、

Apache HttpComponents HttpClient を build.gradle に記述していないので入れていないつもりでいたのですが、どうも classpath に存在して RestTemplateBuilder により検知されて使用するよう設定されているようです。

gradlew dependencies コマンドを実行して確認したところ、org.springframework.boot:spring-boot-starter-amqp を入れると依存関係で org.apache.httpcomponents:httpclient が入っていました ( この中に org.apache.http.client.HttpClient クラスがあります。 )。

compile - Dependencies for source set 'main'.
..........
+--- org.springframework.boot:spring-boot-starter-amqp: -> 1.4.4.RELEASE
|    +--- org.springframework.boot:spring-boot-starter:1.4.4.RELEASE (*)
|    +--- org.springframework:spring-messaging:4.3.6.RELEASE
|    |    +--- org.springframework:spring-beans:4.3.6.RELEASE (*)
|    |    +--- org.springframework:spring-context:4.3.6.RELEASE (*)
|    |    \--- org.springframework:spring-core:4.3.6.RELEASE
|    \--- org.springframework.amqp:spring-rabbit:1.6.7.RELEASE
|         +--- org.springframework:spring-web:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework.retry:spring-retry:1.1.5.RELEASE
|         |    \--- org.springframework:spring-core:4.0.4.RELEASE -> 4.3.6.RELEASE
|         +--- org.springframework:spring-messaging:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework:spring-context:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- org.springframework:spring-tx:4.2.9.RELEASE -> 4.3.6.RELEASE (*)
|         +--- com.rabbitmq:http-client:1.0.0.RELEASE
|         |    +--- org.apache.httpcomponents:httpclient:4.3.6 -> 4.5.2
|         |    |    +--- org.apache.httpcomponents:httpcore:4.4.4 -> 4.4.6
|         |    |    \--- commons-codec:commons-codec:1.9 -> 1.10
|         |    \--- com.fasterxml.jackson.core:jackson-databind:2.5.1 -> 2.8.6 (*)
|         +--- org.springframework.amqp:spring-amqp:1.6.7.RELEASE
|         |    \--- org.springframework:spring-core:4.2.9.RELEASE -> 4.3.6.RELEASE
|         \--- com.rabbitmq:amqp-client:3.6.5 -> 3.6.6
..........

RestTemplateBuilder#detectRequestFactory で RestTemplateBuilder の自動検出を無効にして HttpURLConnection を使うようにしたらテストは成功するのか?

Spring Boot 1.4+でRestTemplate(HTTPクライアント)を使う の記事によると、RestTemplateBuilder#detectRequestFactory(false) を呼べば RestTemplateBuilder の自動検出が無効になり HttpURLConnection が使われるようになるようです。HttpURLConnection にすれば RestTemplateBuilder を使用する場合でもテストが成功するのか確認してみます。

src/main/java/ksbysample/webapp/lending/service/calilapi/CalilApiService.java の CalilApiConfig.restTemplateForCalilApi メソッドを以下のように変更します。

        @Bean
        public RestTemplate restTemplateForCalilApi() {
            return this.restTemplateBuilder
                    .detectRequestFactory(false)
                    .setConnectTimeout(CONNECT_TIMEOUT)
                    .setReadTimeout(READ_TIMEOUT)
                    .rootUri(URL_CALILAPI_ROOT)
                    .build();

//            SimpleClientHttpRequestFactory factory = new SimpleClientHttpRequestFactory();
//            factory.setConnectTimeout(CONNECT_TIMEOUT);
//            factory.setReadTimeout(READ_TIMEOUT);
//            RestTemplate restTemplate = new RestTemplate(factory);
//            return restTemplate;
        }
  • .detectRequestFactory(false) を追加します。

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を何度も実行してみましたが1度もエラーになりませんでした。

f:id:ksby:20170311130905p:plain

ここまでの確認結果をまとめてみると、

  • RestTemplateBuilder の問題ではなく Apache HttpComponents HttpClient の問題のようです。JDK 標準の HttpURLConnection だと発生しません。
  • テスト単独で実行すると発生しない。全てのテストを通しで実行した時だけ発生する問題のようです ( ただしたまに成功します )。

OkHttp 3 だとテストは成功するのか?

Apache HttpComponents HttpClient 以外のライブラリでも同じ現象が出るのか、OkHttp 3 で確認してみます。

build.gradle を以下のように変更します。変更後、Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新します。

dependencies {
    ..........

    // dependency-management-plugin によりバージョン番号が自動で設定されるもの
    // Appendix A. Dependency versions ( http://docs.spring.io/platform/docs/current/reference/htmlsingle/#appendix-dependency-versions ) 参照
    ..........
    compile("org.codehaus.janino:janino")
    compile("com.squareup.okhttp3:okhttp")
    testCompile("org.springframework.boot:spring-boot-starter-test")
    ..........
  • compile("com.squareup.okhttp3:okhttp") を追加します。OkHttp 3 は Spring IO Platform の BOM に記載されているのでバージョン番号の記述は不要です。

src/main/java/ksbysample/webapp/lending/service/calilapi/CalilApiService.java の CalilApiConfig.restTemplateForCalilApi メソッドを以下のように変更します。

        @Bean
        public RestTemplate restTemplateForCalilApi() {
            return this.restTemplateBuilder
                    .setConnectTimeout(CONNECT_TIMEOUT)
                    .setReadTimeout(READ_TIMEOUT)
                    .rootUri(URL_CALILAPI_ROOT)
                    .requestFactory(new OkHttp3ClientHttpRequestFactory())
                    .build();

//            SimpleClientHttpRequestFactory factory = new SimpleClientHttpRequestFactory();
//            factory.setConnectTimeout(CONNECT_TIMEOUT);
//            factory.setReadTimeout(READ_TIMEOUT);
//            RestTemplate restTemplate = new RestTemplate(factory);
//            return restTemplate;
        }
  • .requestFactory(new OkHttp3ClientHttpRequestFactory()) を追加します。

clean タスク → Rebuild Project を実行します。

問題の出るテストを単独で実行すると、これは何度試しても成功します。

f:id:ksby:20170316004333p:plain

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行してみると、5回実行して5回全てテストが失敗しました。エラーの原因も Caused by: java.net.SocketTimeoutException: Read timed out でした。

f:id:ksby:20170316005629p:plain

Apache HttpComponents HttpClient と変わりませんでした。変更したファイルは一旦元に戻します。

Apache HttpComponents HttpClient でもリトライ処理を入れればテストは成功するのか?

リトライを入れても失敗するのか確認してみます。簡単に試してみたいだけなので spring-retry ではなく for 文で実装します。

src/main/java/ksbysample/webapp/lending/service/calilapi/CalilApiService.java の getLibraryList メソッドを以下のように変更します。

    public Libraries getLibraryList(String pref) throws Exception {
        // 図書館データベースAPIを呼び出して XMLレスポンスを受信する
        ResponseEntity<String> response = null;
        for (int i = 1; i <= 5; i++) {
            try {
                response = this.restTemplateForCalilApi.getForEntity(URL_CALILAPI_LIBRALY
                        , String.class, this.calilApiKey, pref);
            } catch (Exception e) {
                if (i <= 4) {
                    logger.warn("★★★ リトライ = {} 回目: {}", i, e.getCause().getMessage());
                } else {
                    throw e;
                }
            }
        }

        // 受信した XMLレスポンスを Javaオブジェクトに変換する
        Serializer serializer = new Persister();
        Libraries libraries = serializer.read(Libraries.class, response.getBody());

        return libraries;
    }

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行してみるとテストは常に成功するようになりました。ただし、ログを見ると常に1回リトライしていました。

f:id:ksby:20170316012319p:plain

ログのレベルを DEBUG に変更してみる

ログのレベルを DEBUG に変更して状況を見てみます。src/main/resources/logback-unittest.xml を以下のように修正します。

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <!--<root level="OFF"/>-->
    <root level="DEBUG">
        <appender-ref ref="CONSOLE"/>
    </root>
</included>

Project Tool Window の src/test から「Run ‘All Tests’ with Coverage」を実行すると以下のログが出力されました。

2017-03-17 00:39:36.438  INFO : call : ksbysample.webapp.lending.service.calilapi.CalilApiService#getLibraryList({東a京都})
2017-03-17 00:39:36.438 DEBUG : Created GET request for "http://api.calil.jp/library?....."
2017-03-17 00:39:36.438 DEBUG : Setting request Accept header to [.....]
2017-03-17 00:39:36.438 DEBUG : CookieSpec selected: default
2017-03-17 00:39:36.438 DEBUG : Auth cache not set in the context
2017-03-17 00:39:36.438 DEBUG : Connection request: [route: {}->http://api.calil.jp:80][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]
2017-03-17 00:39:36.470 DEBUG : http-outgoing-0 << "[read] I/O error: Read timed out"
2017-03-17 00:39:36.470 DEBUG : Connection leased: [id: 0][route: {}->http://api.calil.jp:80][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10]
2017-03-17 00:39:36.470 DEBUG : http-outgoing-0: set socket timeout to 5000
2017-03-17 00:39:36.470 DEBUG : Executing request GET /library?..... HTTP/1.1
2017-03-17 00:39:36.470 DEBUG : Target auth state: UNCHALLENGED
2017-03-17 00:39:36.470 DEBUG : Proxy auth state: UNCHALLENGED
2017-03-17 00:39:36.470 DEBUG : http-outgoing-0 >> GET /library?..... HTTP/1.1
..........
2017-03-17 00:39:41.482 DEBUG : http-outgoing-0 << "[read] I/O error: Read timed out"
2017-03-17 00:39:41.482 DEBUG : http-outgoing-0: Close connection
2017-03-17 00:39:41.482 DEBUG : http-outgoing-0: Shutdown connection
2017-03-17 00:39:41.482 DEBUG : Connection discarded
2017-03-17 00:39:41.482 DEBUG : Connection released: [id: 0][route: {}->http://api.calil.jp:80][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10]
2017-03-17 00:39:41.482  WARN : ★★★ リトライ = 1 回目: Read timed out
2017-03-17 00:39:41.482 DEBUG : Created GET request for "http://api.calil.jp/library?....."
2017-03-17 00:39:41.482 DEBUG : Setting request Accept header to [.....]
2017-03-17 00:39:41.482 DEBUG : CookieSpec selected: default
2017-03-17 00:39:41.482 DEBUG : Auth cache not set in the context
2017-03-17 00:39:41.482 DEBUG : Connection request: [route: {}->http://api.calil.jp:80][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10]
2017-03-17 00:39:41.482 DEBUG : Connection leased: [id: 2][route: {}->http://api.calil.jp:80][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10]
2017-03-17 00:39:41.482 DEBUG : Opening connection {}->http://api.calil.jp:80
2017-03-17 00:39:41.482 DEBUG : Connecting to api.calil.jp/160.16.122.86:80
2017-03-17 00:39:41.501 DEBUG : Connection established 192.168.2.100:58940<->160.16.122.86:80
2017-03-17 00:39:41.501 DEBUG : http-outgoing-2: set socket timeout to 5000
2017-03-17 00:39:41.502 DEBUG : Executing request GET /library?..... HTTP/1.1
2017-03-17 00:39:41.502 DEBUG : Target auth state: UNCHALLENGED
2017-03-17 00:39:41.502 DEBUG : Proxy auth state: UNCHALLENGED
2017-03-17 00:39:41.502 DEBUG : http-outgoing-2 >> GET /library?..... HTTP/1.1
..........
2017-03-17 00:39:41.866 DEBUG : http-outgoing-2 << "HTTP/1.1 200 OK[\r][\n]"

失敗時と成功時の違いを比較してみると、

  • 失敗時は total kept alive: 1 と出力されており、既存の接続済のコネクションを利用していますが、成功時は total kept alive: 0 と接続済のコネクションがないため、Connecting to api.calil.jp/160.16.122.86:80Connection established 192.168.2.100:58940<->160.16.122.86:80 と新規に接続しています。

結局どうするか?

ここまで調べた結果をまとめてみると、

  • 接続済のコネクションを再利用しようとすると失敗するときがある。失敗した時に発生している例外は java.net.SocketTimeoutException: Read timed out
  • リトライすれば2回目には成功する。3回目以降までリトライすることはない。
  • java.net.SocketTimeoutException: Read timed out の原因は分からず。デバッガで追ってもみたが、本当に単に time out しているだけだった。。。
  • JDK の HttpURLConnection で必ず成功するのは、おそらくコネクションプーリングの仕組みがないため。都度接続するので成功するのだろう。

という感じでしょうか。ライブラリの問題というより自分のところのネットワークの問題のような気がしてきました。WiFiiPhoneTwitter を見ていると、外では決して出ることがない「ツイートを読み込めません」というエラーメッセージがよく出ることがあり、同じように接続済のコネクションを再利用しようとして問題が発生しているものと思われます。RestTemplateBuilder や Apache HttpComponents HttpClient に問題がある訳ではないという結論です。

エラーが出ないようにするには JDK の HttpURLConnection を使うか、リトライ処理を入れるかするしかないようです。今回はリトライ処理を入れて対応します。

リトライ処理は上で入れた for 文の方式ではなく spring-retry で入れようと思います。長くなったのでリトライ処理は次回に入れます。またこれまで入れた修正は全て元に戻します。

ソースコード

履歴

2017/03/18
初版発行。