かんがるーさんの日記

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

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( 番外編 )( IntelliJ IDEA の画面上の文字化けを解消する )

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その2 )( Spring Boot を 2.1.4 → 2.1.11 へ、Gradle を 5.3.1 → 5.6.4 へバージョンアップする ) で build タスクのエラーが出た時に IntelliJ IDEA の画面上でエラーメッセージが文字化けしていました。

今でも build.gradle の copyDomaResources タスクをコメントアウトしてから、

//task copyDomaResources(type: Sync)  {
//    from sourceSets.main.resources.srcDirs
//    into compileJava.destinationDir
//    include "doma.compile.config"
//    include "META-INF/**/*.sql"
//    include "META-INF/**/*.script"
//}
//compileJava.dependsOn copyDomaResources

build タスクを実行すると IntelliJ IDEA の画面上のエラーメッセージは文字化けしたままです。

f:id:ksby:20200111235345p:plain

IntelliJ IDEA を 2019.2 にバージョンアップした頃からこの文字化けの現象が出ているのですが、解消方法が分かったので設定します。

IntelliJ IDEA のメインメニューから「Help」-「Edit Custom VM Options...」を選択します。

エディタで idea64.exe.vmoptions が開くので、-Dfile.encoding=UTF-8 を追加します。ついでに -Xms1024m-Xms8192m-Xmx2034m-Xmx8192m に変更します。

# custom IntelliJ IDEA VM options

-Xms8192m
-Xmx8192m
-XX:ReservedCodeCacheSize=240m
-XX:+UseConcMarkSweepGC
-XX:SoftRefLRUPolicyMSPerMB=50
-ea
-Dsun.io.useCanonCaches=false
-Djava.net.preferIPv4Stack=true
-Djdk.http.auth.tunneling.disabledSchemes=""
-XX:+HeapDumpOnOutOfMemoryError
-XX:-OmitStackTraceInFastThrow
-Dfile.encoding=UTF-8

起動時オプションを変更したので、IntelliJ IDEA を起動し直します。

再び build タスクを実行すると今度はエラーメッセージが文字化けしなくなりました。

f:id:ksby:20200112001347p:plain

履歴

2020/01/12
初版発行。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その12 )( spring.main.lazy-initialization を試してみる )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その11 )( Docker コンテナの image をバージョンアップする ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • Bean の生成タイミングを起動時ではなく必要になったタイミングにすることで起動時間を短縮するための spring.main.lazy-initialization という設定項目が追加されたので、どのくらい短縮できるのか試してみます。

参照したサイト・書籍

目次

  1. jar ファイルを作成して起動時間を短縮するためのオプションなしで実行してみる
  2. -Dspring.main.lazy-initialization=true を追加してみる
  3. -XX:TieredStopAtLevel=1 も追加してみる
  4. Multiple Spring Data modules found, entering strict repository configuration mode! とは?
  5. s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing のログがなぜ出力されるのか?
  6. -Dspring.main.lazy-initialization=true を設定すると /actuator/health が何も返さなくなる!?
  7. 最後に

手順

jar ファイルを作成して起動時間を短縮するためのオプションなしで実行してみる

まずは ksbysample-webapp-lending-2.2.2-RELEASE.jar を作成して、起動時間を短縮するためのオプションは何もつけない以下のコマンドで起動してみます。

set JAVA_HOME=D:\Java\jdk-11.0.5+10
set PATH=%JAVA_HOME%\bin;%PATH%
set WEBAPP_HOME=D:\webapps\ksbysample-webapp-lending
set WEBAPP_JAR=ksbysample-webapp-lending-2.2.2-RELEASE.jar
set LOGS_DIR=%WEBAPP_HOME%\logs
set PATH_HEAPDUMPFILE=%LOGS_DIR%\heapdump.hprof
set PATH_ERRORFILE=%LOGS_DIR%\hs_err.log

java -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseG1GC ^
     -Xlog:gc*=debug:logs/gc.log:time,level,tags:filesize=10m,filecount=5 ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dspring.profiles.active=product ^
     -jar lib\%WEBAPP_JAR%

5回実行して Started Application in ... seconds に表示された時間は 14.955、15.53、16.493、15.992、15.773(平均 15.7486)でした。

14.955 の時の Starting Application on ...Started Application in ... seconds までのログは以下のものでした。

2020-01-08 00:29:58.925  INFO 9200 --- [main] ksbysample.webapp.lending.Application    : Starting Application on PC-02 with PID 9200 (D:\webapps\ksbysample-webapp-lending\lib\ksbysample-webapp-lending-2.2.2-RELEASE.jar started by root in D:\webapps\ksbysample-webapp-lending)
2020-01-08 00:29:58.929  INFO 9200 --- [main] ksbysample.webapp.lending.Application    : The following profiles are active: product
2020-01-08 00:30:01.018  INFO 9200 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2020-01-08 00:30:01.021  INFO 9200 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
2020-01-08 00:30:01.084  INFO 9200 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 41ms. Found 0 Redis repository interfaces.
2020-01-08 00:30:01.938  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0' of type [org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.010  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.593  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.602  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'objectPostProcessor' of type [org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.611  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@6d1310f6' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.615  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:02.641  INFO 9200 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 00:30:03.758  INFO 9200 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-01-08 00:30:03.783  INFO 9200 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-01-08 00:30:03.783  INFO 9200 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.29]
2020-01-08 00:30:03.884  INFO 9200 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-01-08 00:30:03.884  INFO 9200 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 4848 ms
2020-01-08 00:30:04.743  INFO 9200 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService
2020-01-08 00:30:07.902  INFO 9200 --- [main] io.lettuce.core.EpollProvider            : Starting without optional epoll library
2020-01-08 00:30:07.905  INFO 9200 --- [main] io.lettuce.core.KqueueProvider           : Starting without optional kqueue library
2020-01-08 00:30:09.538  INFO 9200 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-01-08 00:30:10.537  INFO 9200 --- [main] o.f.c.internal.license.VersionPrinter    : Flyway Community Edition 6.1.3 by Redgate
2020-01-08 00:30:10.549  INFO 9200 --- [main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2020-01-08 00:30:10.759  INFO 9200 --- [main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2020-01-08 00:30:10.804  INFO 9200 --- [main] o.f.c.internal.database.DatabaseFactory  : Database: jdbc:postgresql://localhost/ksbylending (PostgreSQL 12.1)
2020-01-08 00:30:10.864  INFO 9200 --- [main] o.f.core.internal.command.DbValidate     : Successfully validated 2 migrations (execution time 00:00.033s)
2020-01-08 00:30:10.885  INFO 9200 --- [main] o.f.core.internal.command.DbMigrate      : Current version of schema "public": 1.1
2020-01-08 00:30:10.887  INFO 9200 --- [main] o.f.core.internal.command.DbMigrate      : Schema "public" is up to date. No migration necessary.
2020-01-08 00:30:11.364  INFO 9200 --- [main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: org.springframework.boot.actuate.autoconfigure.security.servlet.EndpointRequest$EndpointRequestMatcher@2484dbb7, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@111cba40, org.springframework.security.web.context.SecurityContextPersistenceFilter@696fad31, org.springframework.security.web.header.HeaderWriterFilter@4652c74d, org.springframework.security.web.csrf.CsrfFilter@238291d4, org.springframework.security.web.authentication.logout.LogoutFilter@6ad6443, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@55296b50, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@3c18942, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@2c48cede, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@48e41b5d, org.springframework.security.web.session.SessionManagementFilter@5ea7bc4, org.springframework.security.web.access.ExceptionTranslationFilter@c48b543, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@77083e41]
2020-01-08 00:30:11.419  INFO 9200 --- [main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: any request, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@5c448ef, org.springframework.security.web.context.SecurityContextPersistenceFilter@4a31ed12, org.springframework.security.web.header.HeaderWriterFilter@11810917, org.springframework.security.web.csrf.CsrfFilter@75bd28d, org.springframework.security.web.authentication.logout.LogoutFilter@49232c6f, org.springframework.security.web.authentication.UsernamePasswordAuthenticationFilter@5fb54740, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@3ab595c8, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@2365ea38, org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter@1ee40b5c, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@703e8050, org.springframework.security.web.session.SessionManagementFilter@13278a41, org.springframework.security.web.access.ExceptionTranslationFilter@129c4d19, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@5e3db14]
2020-01-08 00:30:11.676  INFO 9200 --- [main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 4 endpoint(s) beneath base path '/actuator'
2020-01-08 00:30:12.364  INFO 9200 --- [main] o.s.a.r.c.CachingConnectionFactory       : Attempting to connect to: [localhost:5672]
2020-01-08 00:30:12.464  INFO 9200 --- [main] o.s.a.r.c.CachingConnectionFactory       : Created new connection: rabbitConnectionFactory#70f31322:0/SimpleConnection@33d230ce [delegate=amqp://rabbitmq@127.0.0.1:5672/, localPort= 56784]
2020-01-08 00:30:12.469  INFO 9200 --- [main] o.s.amqp.rabbit.core.RabbitAdmin         : Auto-declaring a non-durable, auto-delete, or exclusive Queue (InquiringStatusOfBookQueue) durable:false, auto-delete:false, exclusive:false. It will be redeclared if the broker stops and is restarted while the connection factory is alive, but all messages will be lost.
2020-01-08 00:30:12.557  INFO 9200 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing
2020-01-08 00:30:12.605  INFO 9200 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-01-08 00:30:12.610  INFO 9200 --- [main] ksbysample.webapp.lending.Application    : Started Application in 14.955 seconds (JVM running for 15.936)

時間がかかっていると思われる箇所を取り出してみました。

  • 2020-01-08 00:30:01.018 INFO 9200 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!(約2秒)
  • 2020-01-08 00:30:03.758 INFO 9200 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)(約1秒)
  • 2020-01-08 00:30:04.743 INFO 9200 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService(約1秒)
  • 2020-01-08 00:30:07.902 INFO 9200 --- [main] io.lettuce.core.EpollProvider : Starting without optional epoll library(約3秒)
  • 2020-01-08 00:30:09.538 INFO 9200 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'(約1.5秒)
  • 2020-01-08 00:30:10.537 INFO 9200 --- [main] o.f.c.internal.license.VersionPrinter : Flyway Community Edition 6.1.3 by Redgate(約1秒)
  • 2020-01-08 00:30:12.364 INFO 9200 --- [main] o.s.a.r.c.CachingConnectionFactory : Attempting to connect to: [localhost:5672](約0.7秒)

-Dspring.main.lazy-initialization=true を追加してみる

今度は -Dspring.main.lazy-initialization=true を追加した以下のコマンドで起動してみます。

java -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseG1GC ^
     -Xlog:gc*=debug:logs/gc.log:time,level,tags:filesize=10m,filecount=5 ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dspring.profiles.active=product ^
     -Dspring.main.lazy-initialization=true ^
     -jar lib\%WEBAPP_JAR%

5回実行して Started Application in ... seconds に表示された時間は 11.479、12.201、12.216、11.865、11.346(平均 11.8214、▼3.9272)でした。

2020-01-08 23:24:29.483  INFO 20304 --- [main] ksbysample.webapp.lending.Application    : Starting Application on PC-02 with PID 20304 (D:\webapps\ksbysample-webapp-lending\lib\ksbysample-webapp-lending-2.2.2-RELEASE.jar started by root in D:\webapps\ksbysample-webapp-lending)
2020-01-08 23:24:29.486  INFO 20304 --- [main] ksbysample.webapp.lending.Application    : The following profiles are active: product
2020-01-08 23:24:31.506  INFO 20304 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2020-01-08 23:24:31.510  INFO 20304 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
2020-01-08 23:24:31.578  INFO 20304 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 43ms. Found 0 Redis repository interfaces.
2020-01-08 23:24:32.455  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0' of type [org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:32.529  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:33.135  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:33.150  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'objectPostProcessor' of type [org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:33.163  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@3228d990' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:33.168  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:33.191  INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:24:34.314  INFO 20304 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-01-08 23:24:34.361  INFO 20304 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-01-08 23:24:34.362  INFO 20304 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.29]
2020-01-08 23:24:34.549  INFO 20304 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-01-08 23:24:34.550  INFO 20304 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 4954 ms
2020-01-08 23:24:35.506  INFO 20304 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService
2020-01-08 23:24:37.141  INFO 20304 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.EpollProvider            : Starting without optional epoll library
2020-01-08 23:24:37.143  INFO 20304 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.KqueueProvider           : Starting without optional kqueue library
2020-01-08 23:24:39.653  INFO 20304 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing
2020-01-08 23:24:39.715  INFO 20304 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-01-08 23:24:39.724  INFO 20304 --- [main] ksbysample.webapp.lending.Application    : Started Application in 11.479 seconds (JVM running for 12.281)

時間がかかっていると思われる箇所を取り出してみました。★は1回目と比較して再度出てきたログに付けています。

  • 2020-01-08 23:24:31.506 INFO 20304 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!(約2秒★★)
  • 2020-01-08 23:24:32.455 INFO 20304 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0' of type [org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)(約1秒)
  • 2020-01-08 23:24:34.314 INFO 20304 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)(約1秒★★)
  • 2020-01-08 23:24:35.506 INFO 20304 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService(約1秒★★)
  • 2020-01-08 23:24:37.141 INFO 20304 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.EpollProvider : Starting without optional epoll library(約1.5秒★★)
  • 2020-01-08 23:24:39.653 INFO 20304 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing(約2.5秒)

-XX:TieredStopAtLevel=1 も追加してみる

更に -XX:TieredStopAtLevel=1 を追加した以下のコマンドで起動してみます。

java -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseG1GC ^
     -Xlog:gc*=debug:logs/gc.log:time,level,tags:filesize=10m,filecount=5 ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dspring.profiles.active=product ^
     -Dspring.main.lazy-initialization=true ^
     -XX:TieredStopAtLevel=1 ^
     -jar lib\%WEBAPP_JAR%

5回実行して Started Application in ... seconds に表示された時間は 8.757、9.071、9.106、9.106、8.628(平均 8.9336、1回目から▼6.815、2回目から▼2.8878)でした。

2020-01-08 23:44:56.490  INFO 2728 --- [main] ksbysample.webapp.lending.Application    : Starting Application on PC-02 with PID 2728 (D:\webapps\ksbysample-webapp-lending\lib\ksbysample-webapp-lending-2.2.2-RELEASE.jar started by root in D:\webapps\ksbysample-webapp-lending)
2020-01-08 23:44:56.494  INFO 2728 --- [main] ksbysample.webapp.lending.Application    : The following profiles are active: product
2020-01-08 23:44:58.182  INFO 2728 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2020-01-08 23:44:58.186  INFO 2728 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
2020-01-08 23:44:58.241  INFO 2728 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 34ms. Found 0 Redis repository interfaces.
2020-01-08 23:44:58.960  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0' of type [org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.008  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.574  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.581  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'objectPostProcessor' of type [org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.588  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@74d7184a' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.591  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:44:59.605  INFO 2728 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-08 23:45:00.374  INFO 2728 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-01-08 23:45:00.392  INFO 2728 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-01-08 23:45:00.392  INFO 2728 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.29]
2020-01-08 23:45:00.483  INFO 2728 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-01-08 23:45:00.483  INFO 2728 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 3901 ms
2020-01-08 23:45:01.188  INFO 2728 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService
2020-01-08 23:45:02.203  INFO 2728 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.EpollProvider            : Starting without optional epoll library
2020-01-08 23:45:02.207  INFO 2728 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.KqueueProvider           : Starting without optional kqueue library
2020-01-08 23:45:04.128  INFO 2728 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing
2020-01-08 23:45:04.163  INFO 2728 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-01-08 23:45:04.167  INFO 2728 --- [main] ksbysample.webapp.lending.Application    : Started Application in 8.757 seconds (JVM running for 9.346)

時間がかかっていると思われる箇所を取り出してみました。

  • 2020-01-08 23:44:58.182 INFO 2728 --- [main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!(約1.5秒★★★)
  • 2020-01-08 23:45:00.374 INFO 2728 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)(約1.7秒★★★)
  • 2020-01-08 23:45:01.188 INFO 2728 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService(約0.7秒★★★)
  • 2020-01-08 23:45:02.203 INFO 2728 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.EpollProvider : Starting without optional epoll library(約1秒★★★)
  • 2020-01-08 23:45:04.128 INFO 2728 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing(約2秒★★)

Multiple Spring Data modules found, entering strict repository configuration mode! とは?

以下の Web ページによると Spring Data 系のモジュールが複数使用されている場合、strict repository configuration mode になるとのこと。例えば、複数の Spring Data 系モジュールを使用している場合 CrudRepository を継承するだけではどの Spring Data なのか判別できならしい。初耳です。。。

もう少し調べてみると Spring Data Redis の Repository 機能を見つけました。以下の Web ページに説明があります。なるほど、Spring Data 系ならば Repository 機能があるんですね。Spring Data JPA だけの機能だと思っていました。。。

Spring Data Redis は Spring Session のために使用しているだけなので -Dspring.data.redis.repositories.enabled=false を追加して Spring Data Redis の Repository 機能を無効にしてみます。

java -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseG1GC ^
     -Xlog:gc*=debug:logs/gc.log:time,level,tags:filesize=10m,filecount=5 ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dspring.profiles.active=product ^
     -Dspring.main.lazy-initialization=true ^
     -XX:TieredStopAtLevel=1 ^
     -Dspring.data.redis.repositories.enabled=false ^
     -jar lib\%WEBAPP_JAR%

5回実行して Started Application in ... seconds に表示された時間は 8.776、8.37、8.65、8.627、8.627(平均 8.61)でした。少しだけ短くなりますが、無効にする程ではないようです。

2020-01-10 01:33:15.751  INFO 4628 --- [main] ksbysample.webapp.lending.Application    : Starting Application on PC-02 with PID 4628 (D:\webapps\ksbysample-webapp-lending\lib\ksbysample-webapp-lending-2.2.2-RELEASE.jar started by root in D:\webapps\ksbysample-webapp-lending)
2020-01-10 01:33:15.755  INFO 4628 --- [main] ksbysample.webapp.lending.Application    : The following profiles are active: product
2020-01-10 01:33:18.110  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0' of type [org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.161  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.688  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.696  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'objectPostProcessor' of type [org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.703  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@6e33c391' of type [org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.706  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:18.722  INFO 4628 --- [main] trationDelegate$BeanPostProcessorChecker : Bean 'methodSecurityMetadataSource' of type [org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-01-10 01:33:19.584  INFO 4628 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-01-10 01:33:19.608  INFO 4628 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-01-10 01:33:19.609  INFO 4628 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.29]
2020-01-10 01:33:19.707  INFO 4628 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-01-10 01:33:19.707  INFO 4628 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 3868 ms
2020-01-10 01:33:20.371  INFO 4628 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService
2020-01-10 01:33:21.572  INFO 4628 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.EpollProvider            : Starting without optional epoll library
2020-01-10 01:33:21.575  INFO 4628 --- [springSessionRedisMessageListenerContainer-1] io.lettuce.core.KqueueProvider           : Starting without optional kqueue library
2020-01-10 01:33:23.394  INFO 4628 --- [main] s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing
2020-01-10 01:33:23.432  INFO 4628 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-01-10 01:33:23.436  INFO 4628 --- [main] ksbysample.webapp.lending.Application    : Started Application in 8.776 seconds (JVM running for 9.375)

s.a.ScheduledAnnotationBeanPostProcessor : No TaskScheduler/ScheduledExecutorService bean found for scheduled processing のログがなぜ出力されるのか?

ksbysample-webapp-lending では @EnableScheduling アノテーションを付与して Spring のスケジューリング機能を有効にしていないにもかかわらず、スケジューリング機能が有効になっていると思われるログが出ています。

ScheduledAnnotationBeanPostProcessor は org.springframework.scheduling.annotation パッケージのクラスでした。クラスのコメントを見ると Bean post-processor that registers methods annotated with @{@link Scheduled} ... という記述があります。

「Find in Path」機能で EnableScheduling で検索してみると、org.springframework.session.data.redis.config.annotation.web.http.RedisHttpSessionConfiguration クラスの中の SessionCleanupConfiguration クラスに @EnableScheduling アノテーションが付与されていました。

f:id:ksby:20200110020509p:plain

f:id:ksby:20200110020803p:plain

Spring Session で Redis 上に保存されたセッションが有効期限が切れた後に削除されるのは Redis の機能だと思っていましたが、Spring のスケジューリング機能で削除するタスクが定期的(DEFAULT_CLEANUP_CRON = "0 * * * * *")に実行されていました。

-Dspring.main.lazy-initialization=true を設定すると /actuator/health が何も返さなくなる!?

Lazy Initialization in Spring Boot 2.2 によると spring.main.lazy-initialization=true は開発環境で設定すると良いとのこと。確かに起動時間が短縮されるのは魅力です。

そこで IntelliJ IDEA の Run/Debug Configuration ダイアログから VM Options に -Dspring.main.lazy-initialization=true を付けてみたのですが、

f:id:ksby:20200111210956p:plain

Spring Boot Actuator の Health Endpoint で何も表示されなくなりました。。。 Failed to retrieve 'health' endpoint data: javax.management.InstanceNotFoundException: org.springframework.boot:type=Endpoint,name=Health というメッセージが表示されます。

f:id:ksby:20200111211119p:plain

-Dspring.main.lazy-initialization=true を削除すると問題なく表示されます。

f:id:ksby:20200111211305p:plain

-Dspring.main.lazy-initialization=true を設定した時に http://localhost:8080/actuator/health にアクセスすると何が返ってくるのか PostmancurlGUI にしたようなアプリです)で確認してみたところ、ログイン画面が返ってきていました。

f:id:ksby:20200111223903p:plain

新規に demo アプリ(Spring Boot Actuator を導入+Spring Security は導入しない)を作成して動作を調査してみました。

  • ksbysample-webapp-lending と同様に -Dspring.main.lazy-initialization=true を設定すると IntelliJ IDEA の Health Endpoint には何も表示されない。
  • Postman でアクセスすると問題なくデータが取得できる! f:id:ksby:20200111225328p:plain

表示されない時のメッセージが javax.management.InstanceNotFoundException だったので、以下の Bean を追加したところ demo アプリでは IntelliJ IDEA の Health Endpoint にデータが表示されるようになりました。

    @Bean
    static LazyInitializationExcludeFilter jmxEndpointExporterLazyInitExcludeFilter() {
        return LazyInitializationExcludeFilter.forBeanTypes(JmxEndpointExporter.class);
    }

ksbysample-webapp-lending でもこの Bean を追加すれば IntelliJ IDEA の Health Endpoint にデータが表示されるようになりましたが、Postman で http://localhost:8080/actuator/health にアクセスした時にログイン画面が表示されるのは変わりませんでした。う~ん、さっぱり分かりません。。。

最後に

  • 短縮できるといっても 5~10秒程度です。Web アプリが起動後に利用可能になるためにロードバランサーで health check をしているような場合にはあまりメリットはない気がします。

  • -Dspring.main.lazy-initialization=true とは関係ありませんが、org.springframework.boot:spring-boot-starter-data-redisorg.springframework.session:spring-session-data-redis を導入するといろいろ処理が追加されて起動時に時間がかかることが分かりました。

履歴

2020/01/11
初版発行。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その11 )( Docker コンテナの image をバージョンアップする )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その10 )( SpotBugs プラグインの findsecbugs-plugin を導入する ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • Docker コンテナの image をバージョンアップします。

参照したサイト・書籍

  1. redis cluster with error "Couldn't connect to redis instance"
    https://github.com/oliver006/redis_exporter/issues/325

  2. Prometheus Configuration to Scrape Multiple Redis Hosts
    https://github.com/oliver006/redis_exporter#prometheus-configuration-to-scrape-multiple-redis-hosts

目次

  1. 現状の確認とバージョンアップの方針
  2. docker-compose.yml を変更する
  3. docker-compose.mail.yml を変更する
  4. .env を変更する
  5. docker-compose up -d コマンドを実行する
  6. Grafana の Spring Boot Statistics ダッシュボードにメトリックスが表示されない原因を解消する
  7. Grafana の Prometheus Redis ダッシュボードにメトリックスが表示されない原因を解消する

手順

現状の確認とバージョンアップの方針

現状を確認したところ、以下の状況でした。

  • Prometheus が動作していません。http://localhost:9090/ にアクセスしても何も表示されず、IntelliJ IDEA の Services Window を見ると確かに動作していません。panic: runtime error: slice bounds out of range というログが出ていました。

    f:id:ksby:20200105121116p:plain

  • Grafana は動作していますが、Prometheus が動作しておらずデータを取得できないためメトリックスが何も表示されません。

  • Redis Cluster は動作しています。
  • RabbitMQ は動作しています。
  • PostgreSQL、pgAdmin 4 は動作しています。
  • Flyway は動作しています。
  • docker-mailserver、rainloop は動作しています。

Prometheus が動作していない原因がよく分かりませんが、以下の方針でバージョンアップすることにします。

  • バージョンを明記している、あるいはバージョンを記載していない image は最新バージョンにする(明記する)。
  • latest を指定しているものは明確にバージョン番号を指定する。
  • 明確なバージョン番号がないものは lastest を指定する。

docker-compose.yml を変更する

services:
  prometheus:
    image: prom/prometheus:v2.15.1
    ..........

  grafana:
    image: grafana/grafana:6.5.2
    ..........

  redis_exporter:
    image: oliver006/redis_exporter:v1.3.5-alpine
    ..........

  haproxy:
    image: haproxy:2.1.2-alpine
    ..........

  haproxy-rsyslog:
    image: rafpe/docker-haproxy-rsyslog:latest
    ..........

  flyway:
    image: flyway/flyway:${FLYWAY_VERSION}-alpine
    ..........

  postgres_exporter:
    image: wrouesnel/postgres_exporter:v0.8.0
    ..........
  • prometheus で image: prom/prometheus:latestimage: prom/prometheus:v2.15.1 に変更します。
  • grafana で image: grafana/grafana:latestimage: grafana/grafana:6.5.2 に変更します。
  • redis_exporter で image: oliver006/redis_exporter:latestimage: oliver006/redis_exporter:v1.3.5-alpine に変更します。
  • haproxy で image: haproxy:1.8.14-alpineimage: haproxy:2.1.2-alpine に変更します。
  • haproxy-rsyslog で image: rafpe/docker-haproxy-rsyslogimage: rafpe/docker-haproxy-rsyslog:latest に変更します。
  • flyway で image: boxfuse/flyway:${FLYWAY_VERSION}-alpineimage: flyway/flyway:${FLYWAY_VERSION}-alpine に変更します。boxfuse/flyway は [DEPRECATED] になっていて、flyway/flyway が Official Flyway Docker images になっていました。
  • postgres_exporter で image: wrouesnel/postgres_exporterimage: wrouesnel/postgres_exporter:v0.8.0 に変更します。

docker-compose.mail.yml を変更する

  rainloop:
    image: hardware/rainloop:1.13.0
  • rainloop で image: hardware/rainloopimage: hardware/rainloop:1.13.0 に変更します。

.env を変更する

HOST_IP_ADDRESS=172.31.16.1
REDIS_VERSION=5.0.7
REDIS_CLUSTER_1_PORT=6379
REDIS_CLUSTER_2_PORT=6380
REDIS_CLUSTER_3_PORT=6381
REDIS_CLUSTER_4_PORT=6382
REDIS_CLUSTER_5_PORT=6383
REDIS_CLUSTER_6_PORT=6384

RABBITMQ_VERSION=3.8.2-management
RABBITMQ_ERLANG_COOKIE=Uzkm93w5e1Lz8AcP
RABBITMQ_DEFAULT_USER=rabbitmq
RABBITMQ_DEFAULT_PASS=12345678
RABBITMQ_DEFAULT_VHOST=/

POSTGRESQL_VERSION=12.1
PGADMIN4_VERSION=4.16

FLYWAY_VERSION=6.1.3
FLYWAY_URL=jdbc:postgresql://postgresql/ksbylending
FLYWAY_USER=ksbylending_user
FLYWAY_PASSWORD=xxxxxxxx

POSTGRES_EXPORTER_USER=postgres_exporter
POSTGRES_EXPORTER_PASSWORD=zzzzzzzz

MAILSERVER_VERSION=release-v6.2.1
  • REDIS_VERSION=5.0.2REDIS_VERSION=5.0.7 に変更します。
  • RABBITMQ_VERSION=3.7.8-managementRABBITMQ_VERSION=3.8.2-management に変更します。
  • POSTGRESQL_VERSION=11.1POSTGRESQL_VERSION=12.1 に変更します。
  • PGADMIN4_VERSION=3.6PGADMIN4_VERSION=4.16 に変更します。
  • FLYWAY_VERSION=5.2.4FLYWAY_VERSION=6.1.3 に変更します。
  • MAILSERVER_VERSION=release-v6.1.0MAILSERVER_VERSION=release-v6.2.1 に変更します。

docker-compose up -d コマンドを実行する

以下のコマンドを実行して docker image を更新・ダウンロードします(画面キャプチャはなし)。

  1. docker-compose build コマンドを実行し、Dockerfile で作成している image を更新します。
  2. docker-compose up -d コマンドを実行してコンテナ一式(メールサーバ・rainloop を除く)を起動します。
  3. docker-compose -f docker-compose.mail.yml up -d コマンドを実行してメールサーバ・rainloop のコンテナを起動します。
  4. docker-compose -f docker-compose.mail.yml down コマンドを実行してメールサーバ・rainloop のコンテナを停止・削除します。

正常に起動することが確認できたら、IntelliJ IDEA の Services Window から古い docker image を削除します。

Grafana の Spring Boot Statistics ダッシュボードにメトリックスが表示されない原因を解消する

http://localhost:9090/graph にアクセスすると今度は Prometheus の画面が表示されるようになりました。

f:id:ksby:20200105180910p:plain

しかし、今度は Grafana の Spring Boot Statistics ダッシュボードに何もメトリックスが表示されていないことに気づきました。以前は「Application」に Spring Boot のアプリケーションで設定している "lending" の文字が自動で選択されていたのですが、今は "None" という文字が表示されています。

f:id:ksby:20200105181127p:plain

また Prometheus Redis ダッシュボードもメトリックスが表示されていませんでした。

f:id:ksby:20200105181854p:plain

他の2つのダッシュボードは正常にメトリックスが表示されていました。

まずは Spring Boot Statistics ダッシュボードにメトリックスが表示されない原因を解消します。

ダッシュボード右上の「Dashboard settings」アイコン(歯車のアイコン)をクリックします。

f:id:ksby:20200105182422p:plain

「Settings」画面に遷移したら、画面左側の「Variables」をクリックします。

f:id:ksby:20200105182707p:plain

「Variables」の画面が表示されたら、一番上の $instance をクリックします。

f:id:ksby:20200105182844p:plain

$instance の編集画面が表示されます。「Query」を見ると label_values(jvm_classes_loaded, instance) と入力されており、Prometheus から取得するメトリックスの内 jvm_classes_loaded を見て $instance にセットする値を取得するよう設定されていますが、

f:id:ksby:20200105183009p:plain

Prometheus の画面で jvm_classes_loaded を入力すると、候補として表示されるのは jvm_classes_loaded_classesjvm_classes_loaded というメトリックスはなくなっていました。

f:id:ksby:20200105183454p:plain

jvm_classes_loaded_classes で検索するとデータが取得できて、application も instance も取得することができることが確認できます。

f:id:ksby:20200105183605p:plain

つまり取得元のメトリックス名が変更されたことが原因なので、$instance$application の編集画面でメトリックス名を jvm_classes_loadedjvm_classes_loaded_classes に変更すれば解決します。1点注意があって、下の画面キャプチャでは見えませんが、変更後に画面下の「Update」ボタンをクリックしてください(画面右側のスクロールバーで下に行けば表示されます)。

f:id:ksby:20200105184556p:plain f:id:ksby:20200105184239p:plain

「Variables」を変更したら「Save」ボタンをクリックします。

f:id:ksby:20200105184801p:plain

「Save changes」ダイアログが表示されるので、「Save current variables」をチェックして中央にコメントを入力した後「Save」ボタンをクリックします。

f:id:ksby:20200105185109p:plain

Spring Boot Statistics ダッシュボードの画面に戻るとメトリックスが表示されるようになりました。

f:id:ksby:20200105185308p:plain

Grafana の Prometheus Redis ダッシュボードにメトリックスが表示されない原因を解消する

Prometheus が Redis のメトリックスを取得するのに利用している redis_exporter のログを見ると Couldn't connect to redis instance というログが出ていました。

f:id:ksby:20200105190715p:plain

Web で検索すると redis cluster with error "Couldn't connect to redis instance" の Issue が見つかり、その中のリンク先に行くと Prometheus Configuration to Scrape Multiple Redis Hosts に複数の Redis からメトリックスを取得するための設定方法が記述されていました。

今回 redis_exporter のコンテナの image を image: oliver006/redis_exporter:latestimage: oliver006/redis_exporter:v1.3.5-alpine に変更しましたが、バージョンが 0.x から 1.x に変更されて設定方法も変わったようです。マニュアル記載の設定方法に変更します。

docker-compose.yml の redis_exporter の設定から environment の REDIS_ADDR の設定を削除します。

  redis_exporter:
    image: oliver006/redis_exporter:v1.3.5-alpine
    container_name: redis_exporter
    ports:
      - "9121:9121"

docker/prometheus/prometheus.yml に - job_name: 'redis_exporter_targets' の設定を追加します。ここにメトリックスを取得する Redis を列挙します。

scrape_configs:
..........
- job_name: 'redis_exporter_targets'
  static_configs:
    - targets:
        - redis://redis-cluster-6379:6379
        - redis://redis-cluster-6380:6379
        - redis://redis-cluster-6381:6379
        - redis://redis-cluster-6382:6379
        - redis://redis-cluster-6383:6379
        - redis://redis-cluster-6384:6379
  metrics_path: /scrape
  relabel_configs:
    - source_labels: [__address__]
      target_label: __param_target
    - source_labels: [__param_target]
      target_label: instance
    - target_label: __address__
      replacement: redis_exporter:9121

- job_name: 'redis_exporter'
  static_configs:
  - targets: ['redis_exporter:9121']

..........

Docker コンテナを再起動して Prometheus Redis ダッシュボードを表示すると、今度はメトリックスが表示されるようになりました。左上のパネル等の表示がおかしいのは1台の Redis からメトリックスを取得していることが前提の設定になっているものだからです。ここは作り変えない限りどうしようもないので、このままにします。

f:id:ksby:20200105224212p:plain

最後に clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると "BUILD SUCCESSFUL" のメッセージが出力されました。特に問題はなさそうです。

f:id:ksby:20200105225830p:plain

履歴

2020/01/05
初版発行。
2020/01/13
* haproxy の image を image: haproxy:2.1.2image: haproxy:2.1.2-alpine に変更しました。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その10 )( SpotBugs プラグインの findsecbugs-plugin を導入する )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その9 )( SpotBugs を 3.1.11 → 4.0.0-beta4 へバージョンアップする ) の続きです。

参照したサイト・書籍

  1. Find Security Bugs
    https://find-sec-bugs.github.io/

目次

  1. build.gradle を変更する
  2. 検知された警告に対応する
    1. 整合性のない暗号(暗号はデータの整合性を提供していません。)
    2. Spring の制限のない RequestMapping による CSRF(Spring の制限のない RequestMapping は,このメソッドを CSRF 攻撃 に対して脆弱にします。)
    3. Information Exposure Through An Error Message(Information Exposure Through An Error Message)
    4. ログの潜在的な CRLF インジェクション(org/slf4j/Logger.info(Ljava/lang/String;)V を使用すると CRLF 文字をログメッセージに含めることができます。)
    5. Freemarker の潜在的なテンプレートインジェクション(Freemarker テンプレートの潜在的なテンプレートインジェクションです。)
    6. ハードコードされたパスワード(ハードコードされたパスワードを発見)

手順

build.gradle を変更する

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

    // for SpotBugs
    compileOnly("com.github.spotbugs:spotbugs:${spotbugsVersion}")
    compileOnly("net.jcip:jcip-annotations:1.0")
    compileOnly("com.github.spotbugs:spotbugs-annotations:${spotbugsVersion}")
    testImplementation("com.google.code.findbugs:jsr305:3.0.2")
    spotbugsStylesheets("com.github.spotbugs:spotbugs:${spotbugsVersion}")
    spotbugsPlugins("com.h3xstream.findsecbugs:findsecbugs-plugin:1.10.1")
}
  • dependencies block に spotbugsPlugins("com.h3xstream.findsecbugs:findsecbugs-plugin:1.10.1") を追加します。

Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新した後、clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると "BUILD SUCCESSFUL" のメッセージは出力されましたが、The following classes needed for analysis were missing:SpotBugs rule violations were found. See the report at: ... のメッセージも出力されました。

f:id:ksby:20200104231606p:plain f:id:ksby:20200104231710p:plain

The following classes needed for analysis were missing: のメッセージについては Lambda methods reported as missing classes の Issue が上がっていますが、まだ Open の状態でしたので今回は特に何もしません。

SpotBugs rule violations were found. See the report at: ... のメッセージの方はレポートファイルを開くと High Priority Warnings が 27件、Medium Priority Warnings が 4件検知されていました。1つずつ見て対応します。

f:id:ksby:20200104232241p:plain

検知された警告に対応する

整合性のない暗号(暗号はデータの整合性を提供していません。)

レポートファイルに出力されていたのは以下の内容で 1件検知されていました。

f:id:ksby:20200104234057p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Cipher with no integrity のことでした。レポートファイルから Bugs Patterns の該当する Bug Pattern への直接のリンクがないのでちょっと探しずらいですね。

該当箇所 BrowfishUtils.java:[line 38] を見ると以下のソースで、ECB を使用しているために検知されています。

@SuppressWarnings({"PMD.HardCodedCryptoKey"})
public class BrowfishUtils {

    ..........
    private static final String TRANSFORMATION = "Blowfish/ECB/PKCS5Padding";

    public static String encrypt(String str)
            throws NoSuchPaddingException, NoSuchAlgorithmException, InvalidKeyException
            , BadPaddingException, IllegalBlockSizeException {
        ..........
        Cipher cipher = Cipher.getInstance(TRANSFORMATION);
        ..........
    }

}

ここでは ECB に脆弱性があることは知っていて使用しているので、BrowfishUtils クラスに @SuppressFBWarnings("CIPHER_INTEGRITY") を付与して警告が出ないようにします。

@SuppressWarnings({"PMD.HardCodedCryptoKey"})
@SuppressFBWarnings("CIPHER_INTEGRITY")
public class BrowfishUtils {

Spring の制限のない RequestMapping による CSRF(Spring の制限のない RequestMapping は,このメソッドを CSRF 攻撃 に対して脆弱にします。)

レポートファイルに出力されていたのは以下の内容で 26件検知されていました。

f:id:ksby:20200105000755p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Spring CSRF unrestricted RequestMapping のことでした。

これは指摘された通りなので、以下のように対応します。

  • 基本的には @RequestMapping ではなく @GetMapping か @PostMapping に変更します。
  • 以下のメソッドは GET も POST も受け付ける必要があるので、@RequestMapping@RequestMapping(method = {RequestMethod.GET, RequestMethod.POST}) に変更して、SpotBugs の検知対象外になるよう @SuppressFBWarnings("SPRING_CSRF_UNRESTRICTED_REQUEST_MAPPING") も付与します。
    • ksbysample.webapp.lending.web.LoginController#index メソッド
    • ksbysample.webapp.lending.web.sessionsample.SessionSampleController#index メソッド

Information Exposure Through An Error Message(Information Exposure Through An Error Message)

レポートファイルに出力されていたのは以下の内容で 1件検知されていました。

f:id:ksby:20200105103001p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Information Exposure Through An Error Message のことでした。

該当箇所 ExceptionHandlerAdvice.java:[line 85] を見ると以下のソースでした。

        if (e != null) {
            try (
                    StringWriter sw = new StringWriter();
                    PrintWriter pw = new PrintWriter(sw)
            ) {
                e.printStackTrace(pw);  // ← ここ
                ..........

ここはこのままにします。@SuppressFBWarnings("INFORMATION_EXPOSURE_THROUGH_AN_ERROR_MESSAGE") を付与して SpotBugs に検知されないようにします。

    @SuppressFBWarnings("INFORMATION_EXPOSURE_THROUGH_AN_ERROR_MESSAGE")
    @ExceptionHandler(Exception.class)
    public ModelAndView handleException(Exception e

ログの潜在的な CRLF インジェクション(org/slf4j/Logger.info(Ljava/lang/String;)V を使用すると CRLF 文字をログメッセージに含めることができます。)

レポートファイルに出力されていたのは以下の内容で 1件検知されていました。

f:id:ksby:20200105104517p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Potential CRLF Injection for logs のことでした。

ログに CRLF が出力されないようにした方が良いらしい。ログは ksbysample.webapp.lending.aspect.logging.RequestAndResponseLogger#logging メソッドで出力しているので、出力時のコードを logger.info(sb.toString()); → `` に変更して CRLF が出力されないようにします。

    private void logging(String title, String name, String value) {
        StringBuilder sb = new StringBuilder(title);
        if (name != null) {
            sb.append(name)
                    .append(" = ");
        }
        sb.append(value);
        logger.info(sb.toString().replaceAll("[\r\n]",""));
    }

Freemarker潜在的なテンプレートインジェクション(Freemarker テンプレートの潜在的なテンプレートインジェクションです。)

レポートファイルに出力されていたのは以下の内容で 1件検知されていました。

f:id:ksby:20200105110427p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Potential template injection with Freemarker のことでした。

エンドユーザーが Freemarker のテンプレートを直接編集できる訳ではないので、ksbysample.webapp.lending.helper.freemarker.FreeMarkerHelper#process メソッドに @SuppressFBWarnings("TEMPLATE_INJECTION_FREEMARKER") を付与して SpotBugs の検知対象外にします。

    @SuppressFBWarnings("TEMPLATE_INJECTION_FREEMARKER")
    private String process(Template template, Map<String, Object> model) {

ハードコードされたパスワード(ハードコードされたパスワードを発見)

レポートファイルに出力されていたのは以下の内容で 1件検知されていました。

f:id:ksby:20200105113005p:plain

findsecbugs-plugin の Bugs Patterns のページで確認したところ Hard coded password のことでした。

該当箇所 WebSecurityConfig.java:[line 163] を見ると以下のソースでした。

    @SuppressWarnings("PMD.SignatureDeclareThrowsException")
    @Autowired
    public void configAuthentication(AuthenticationManagerBuilder auth
            , ApplicationEventPublisher applicationEventPublisher) throws Exception {
        auth.inMemoryAuthentication()
                .withUser(ACTUATOR_USERNAME)
                .password("{noop}xxxxxxxx")  // ←ここ
                .roles("ENDPOINT_ADMIN");
        auth.authenticationEventPublisher(new CustomAuthenticationEventPublisher(applicationEventPublisher))
                .userDetailsService(userDetailsService);
    }

ここは故意に平文でパスワードを書いているので、@SuppressFBWarnings("HARD_CODE_PASSWORD") を付与して SpotBugs の検知対象外にします。

    @SuppressWarnings("PMD.SignatureDeclareThrowsException")
    @SuppressFBWarnings("HARD_CODE_PASSWORD")
    @Autowired
    public void configAuthentication(AuthenticationManagerBuilder auth
            , ApplicationEventPublisher applicationEventPublisher) throws Exception {

以上の対応で SpotBugs で何も検知されなくなりました。

f:id:ksby:20200105115453p:plain

今回導入してみて思いましたが、SpotBugs を入れるなら findsecbugs-plugin も合わせて入れた方がいいですね。

履歴

2020/01/05
初版発行。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その9 )( SpotBugs を 3.1.11 → 4.0.0-beta4 へバージョンアップする )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その8 )( Error Prone を 2.3.3 → 2.3.4 へバージョンアップする ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • SpotBugs を 3.1.11 → 4.0.0-beta4 へバージョンアップします。
    • https://mvnrepository.com/artifact/com.github.spotbugs/spotbugs を見ると安定版?(beta が付いていないもの)の最新版が 3.1.12(Mar, 2019)、その後 4.0.0 が beta で開発が進んでいて最新版が 4.0.0-beta4(Sep, 2019)でした。今回は 4.0.0-beta4 にバージョンアップします。

参照したサイト・書籍

  1. default.xsl declares it is a 2.0 stylesheet, but it appears to have issues with a 2.0 processor
    https://github.com/spotbugs/spotbugs/issues/958

目次

  1. build.gradle を変更する
  2. 警告の原因を取り除く(かもしれない)
    1. SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
    2. Warning at xsl:variable on line 348 column 57 of default.xsl: SXWN9001: A variable with no following sibling instructions has no effect
  3. 各スタイルシートの HTML のレポートファイルのサンプルを作成してみる
    1. color.xsl
    2. fancy.xsl
    3. fancy-hist.xsl
    4. plain.xsl
    5. summary.xsl

手順

build.gradle を変更する

コメントアウトしていた SpotBugs の設定を元に戻した後、以下の点を変更します。

plugins {
    ..........
    id "com.github.spotbugs" version "3.0.0"
    ..........
}

..........

spotbugs {
    toolVersion = "4.0.0-beta4"
    ignoreFailures = true
    effort = "max"
    spotbugsTest.enabled = false
}
tasks.withType(com.github.spotbugs.SpotBugsTask) {
    reports {
        xml.enabled = false
        html.enabled = true
    }
}

..........

dependencies {
    ..........
    def spotbugsVersion = "4.0.0-beta4"
  • plugins block の以下の点を変更します。
    • id "com.github.spotbugs" version "1.6.9"id "com.github.spotbugs" version "3.0.0"
  • spotbugs block の以下の点を変更します。
    • toolVersion = "3.1.11"toolVersion = "4.0.0-beta4"
  • dependencies block の以下の点を変更します。
    • def spotbugsVersion = "3.1.11"def spotbugsVersion = "4.0.0-beta4"

Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新した後、clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると "BUILD SUCCESSFUL" のメッセージは出力されますが2種類の警告も出力されました。

f:id:ksby:20200102164715p:plain

> Task :spotbugsMain
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
Warning at xsl:variable on line 348 column 57 of default.xsl:
  SXWN9001: A variable with no following sibling instructions has no effect
Warning at xsl:variable on line 351 column 57 of default.xsl:
  SXWN9001: A variable with no following sibling instructions has no effect

警告の原因を取り除く(かもしれない)

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".

ログに出力されている http://www.slf4j.org/codes.html#StaticLoggerBinder を見ると slf4j-nop.jar slf4j-simple.jar, slf4j-log4j12.jar, slf4j-jdk14.jar or logback-classic.jar のいずれかの jar ファイルが classpath に含まれていればこのメッセージは出力されなくなると書かれています。

が、build.gradle の dependencies block に以下のいずれかを追加しても SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". のメッセージは消えず、testJUnit4AndSpock タスクまで java.lang.IllegalArgumentException が発生してテストが多数失敗しました。compileOnly → implementation に変更しても結果は同じでした。

  • compileOnly("org.slf4j:slf4j-nop")
  • compileOnly("org.slf4j:slf4j-simple")
  • compileOnly("org.slf4j:slf4j-log4j12")
  • compileOnly("org.slf4j:slf4j-jdk14")
  • compileOnly("ch.qos.logback:logback-classic")

f:id:ksby:20200102190137p:plain

分からない。。。と思って Web で検索したところ、spotbugs/spotbugs-gradle-plugin の Issue に SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder" があり、まだ Open の状態でした。

動作には支障がないようなので、このメッセージは出したままにします。

Warning at xsl:variable on line 348 column 57 of default.xsl: SXWN9001: A variable with no following sibling instructions has no effect

default.xsl declares it is a 2.0 stylesheet, but it appears to have issues with a 2.0 processor に対応方法のサンプルが書かれているので、これを参考に変更します。

build.gradle を以下のように変更して、SpotBugs の HTML のレポートファイルが使用するスタイルシートを default.xsl → color.xsl に変更します。

configurations {
    ..........

    // for SpotBugs
    spotbugsStylesheets { transitive = false }
}

..........

spotbugs {
    toolVersion = "4.0.0-beta4"
    ignoreFailures = true
    effort = "max"
    spotbugsTest.enabled = false
}
tasks.withType(com.github.spotbugs.SpotBugsTask) {
    reports {
        xml.enabled = false
        html.enabled = true
        html.stylesheet = resources.text.fromArchiveEntry(configurations.spotbugsStylesheets, "color.xsl")
    }
}

..........

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

    // for SpotBugs
    compileOnly("com.github.spotbugs:spotbugs:${spotbugsVersion}")
    compileOnly("net.jcip:jcip-annotations:1.0")
    compileOnly("com.github.spotbugs:spotbugs-annotations:${spotbugsVersion}")
    testImplementation("com.google.code.findbugs:jsr305:3.0.2")
    spotbugsStylesheets("com.github.spotbugs:spotbugs:${spotbugsVersion}")
}
  • configurations block の以下の点を変更します。
    • spotbugsStylesheets { transitive = false } を追加します。
  • tasks.withType(com.github.spotbugs.SpotBugsTask) { ... } の以下の点を変更します。
    • html.stylesheet = resources.text.fromArchiveEntry(configurations.spotbugsStylesheets, "color.xsl") を追加します。
  • dependencies block の以下の点を変更します。
    • spotbugsStylesheets("com.github.spotbugs:spotbugs:${spotbugsVersion}") を追加します。

Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新した後、clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると メッセージは消えて "BUILD SUCCESSFUL" のメッセージも出力されました。

f:id:ksby:20200104111318p:plain

com.github.spotbugs:spotbugs:4.0.0-beta4 の中を見ると、スタイルシートは default.xsl 以外に以下のものがあります。

f:id:ksby:20200104110138p:plain

スタイルシートでどのようなレポートファイルが出力されるのかサンプルを作成してみます。SpotBugs の 検知可能なバグの詳細 を見て SpotBugs に検知されるバグを含んだソースを作成します。

src/main/java/ksbysample/webapp/lending/BugSample.java を新規作成し、以下の内容を記述します。NP: 戻り型が Boolean のメソッドが明示的に null を返している (NP_BOOLEAN_RETURN_NULL) の bug を含んだサンプルです。

package ksbysample.webapp.lending;

public class BugSample {

    public Boolean func() {
        return null;
    }

}

スタイルシートの HTML のレポートファイルのサンプルを作成してみる

作成してみた感想としては、bug の数が少ないならば1ページにすべて表示できる color.xsl が使い勝手が良さそうで、数が出そうなら fancy.xsl、fancy-hist.xsl の方が便利でしょうか? summary.xsl は普段は使用しない気がします。

個人的には color.xsl が好みですね。

color.xsl

f:id:ksby:20200104115941p:plain f:id:ksby:20200104120231p:plain

fancy.xsl

f:id:ksby:20200104120605p:plain f:id:ksby:20200104120704p:plain

fancy-hist.xsl

f:id:ksby:20200104121811p:plain f:id:ksby:20200104122142p:plain

plain.xsl

plain.xsl は以下のエラーが出て使えませんでした。

Warning at xsl:variable on line 277 column 56 of plain.xsl:
  SXWN9001: A variable with no following sibling instructions has no effect
Warning at xsl:variable on line 280 column 59 of plain.xsl:
  SXWN9001: A variable with no following sibling instructions has no effect
Error evaluating ((<head {(<title {text{"SpotBugs Report"}}/>, ...)}/>, ...)) on line 44 column 8 of plain.xsl:
  SEPM0009: Values of 'standalone' and 'omit-xml-declaration' conflict
  In template rule with match="/" on line 42 of plain.xsl
The following errors occurred during analysis:
  Could not generate HTML output
    net.sf.saxon.trans.XPathException: Values of 'standalone' and 'omit-xml-declaration' conflict
      At net.sf.saxon.serialize.XMLEmitter.writeDeclaration(XMLEmitter.java:271)
      At net.sf.saxon.serialize.XMLEmitter.openDocument(XMLEmitter.java:188)
      At net.sf.saxon.serialize.XMLEmitter.characters(XMLEmitter.java:644)
      At net.sf.saxon.serialize.XMLIndenter.indent(XMLIndenter.java:327)
      At net.sf.saxon.serialize.XMLIndenter.startElement(XMLIndenter.java:115)
      At net.sf.saxon.event.ProxyReceiver.startElement(ProxyReceiver.java:132)
      At net.sf.saxon.event.SequenceNormalizer.startElement(SequenceNormalizer.java:88)
      At net.sf.saxon.event.NamespaceReducer.startElement(NamespaceReducer.java:75)
      At net.sf.saxon.event.ComplexContentOutputter.startContent(ComplexContentOutputter.java:640)
      At net.sf.saxon.event.ComplexContentOutputter.startElement(ComplexContentOutputter.java:271)
      At net.sf.saxon.expr.instruct.ElementCreator.processLeavingTail(ElementCreator.java:345)
      At net.sf.saxon.expr.instruct.ElementCreator.processLeavingTail(ElementCreator.java:299)
      At net.sf.saxon.expr.instruct.Block.processLeavingTail(Block.java:735)
      At net.sf.saxon.expr.instruct.Instruction.process(Instruction.java:132)
      At net.sf.saxon.expr.instruct.ElementCreator.processLeavingTail(ElementCreator.java:352)
      At net.sf.saxon.expr.instruct.ElementCreator.processLeavingTail(ElementCreator.java:299)
      At net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:352)
      At net.sf.saxon.trans.Mode.applyTemplates(Mode.java:532)
      At net.sf.saxon.trans.XsltController.applyTemplates(XsltController.java:747)
      At net.sf.saxon.s9api.AbstractXsltTransformer.applyTemplatesToSource(AbstractXsltTransformer.java:347)
      At net.sf.saxon.s9api.XsltTransformer.transform(XsltTransformer.java:349)
      At net.sf.saxon.jaxp.TransformerImpl.transform(TransformerImpl.java:71)
      At edu.umd.cs.findbugs.HTMLBugReporter.finish(HTMLBugReporter.java:73)
      At edu.umd.cs.findbugs.DelegatingBugReporter.finish(DelegatingBugReporter.java:89)
      At edu.umd.cs.findbugs.DelegatingBugReporter.finish(DelegatingBugReporter.java:89)
      At edu.umd.cs.findbugs.FindBugs2.analyzeApplication(FindBugs2.java:1165)
      At edu.umd.cs.findbugs.FindBugs2.execute(FindBugs2.java:309)
      At com.github.spotbugs.internal.spotbugs.SpotBugsExecutor.runSpotbugs(SpotBugsExecutor.java:23)
      At java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      At java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      At java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      At java.base/java.lang.reflect.Method.invoke(Method.java:566)
      At org.gradle.process.internal.worker.request.WorkerAction$1.call(WorkerAction.java:129)
      At org.gradle.process.internal.worker.child.WorkerLogEventListener.withWorkerLoggingProtocol(WorkerLogEventListener.java:41)
      At org.gradle.process.internal.worker.request.WorkerAction.run(WorkerAction.java:126)
      At org.gradle.process.internal.worker.request.WorkerAction.runThenStop(WorkerAction.java:105)
      At java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      At java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      At java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      At java.base/java.lang.reflect.Method.invoke(Method.java:566)
      At org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
      At org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
      At org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)
      At org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)
      At org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:412)
      At org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
      At org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
      At java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      At java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      At org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
      At java.base/java.lang.Thread.run(Thread.java:834)

summary.xsl

f:id:ksby:20200104123203p:plain

このレポートは「Bugs By Package」の下にパッケージ毎の結果が出力されるので、かなり長いです。

履歴

2020/01/04
初版発行。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その8 )( Error Prone を 2.3.3 → 2.3.4 へバージョンアップする )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その7 )( PMD を 6.13.0 → 6.20.0 へバージョンアップする ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • Error Prone を 2.3.3 → 2.3.4 へバージョンアップします。

参照したサイト・書籍

目次

  1. build.gradle を変更する

手順

build.gradle を変更する

plugins {
    id "java"
    id "eclipse"
    id "idea"
    id "org.springframework.boot" version "2.2.2.RELEASE"
    id "io.spring.dependency-management" version "1.0.8.RELEASE"
    id "groovy"
    id "checkstyle"
//    id "com.github.spotbugs" version "1.6.9"
    id "pmd"
    id "net.ltgt.errorprone" version "1.1.1"
    id "com.gorylenko.gradle-git-properties" version "2.2.0"
}

..........

dependencies {
    def jdbcDriver = "org.postgresql:postgresql:42.2.9"
    def spockVersion = "1.3-groovy-2.5"
    def domaVersion = "2.26.0"
    def lombokVersion = "1.18.10"
    def errorproneVersion = "2.3.4"
    def powermockVersion = "2.0.4"
//    def spotbugsVersion = "3.1.11"

    ..........
  • plugins block の以下の点を変更します。
    • id "net.ltgt.errorprone" version "0.7.1"id "net.ltgt.errorprone" version "1.1.1"
  • dependencies block の以下の点を変更します。
    • def errorproneVersion = "2.3.3"def errorproneVersion = "2.3.4"

Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新した後、clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると "BUILD SUCCESSFUL" のメッセージが出力されました。

f:id:ksby:20200102090955p:plain

https://github.com/google/error-prone/releases を見ると新しいチェックが結構追加されていますが、「The problem」にソースコードサンプルがあまり書かれていなくてどんな問題をチェックしているのか分からないものが多いです。。。

履歴

2020/01/01
初版発行。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その7 )( PMD を 6.13.0 → 6.20.0 へバージョンアップする )

概要

記事一覧はこちらです。

Spring Boot 2.1.x の Web アプリを 2.2.x へバージョンアップする ( その6 )( Checkstyle を 8.19 → 8.28 へバージョンアップする ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • PMD を 6.13.0 → 6.20.0 へバージョンアップします。

参照したサイト・書籍

  1. PMD 6.20.0 - Java Rules - Code Style - UseShortArrayInitializer
    https://pmd.github.io/pmd-6.20.0/pmd_rules_java_codestyle.html#useshortarrayinitializer

  2. Baeldung - Initializing Arrays in Java - 3. At the Time of Declaration
    https://www.baeldung.com/java-initialize-array#at-the-time-of-declaration

目次

  1. build.gradle を変更する
  2. 警告の原因を取り除く
    1. int[] x = new int[] { 1, 2, 3 };int[] x = { 1, 2, 3 }; と書いてもいいの!?

手順

build.gradle を変更する

pmd {
    toolVersion = "6.20.0"
    sourceSets = [project.sourceSets.main]
    ignoreFailures = true
    consoleOutput = true
    ruleSetFiles = rootProject.files("/config/pmd/pmd-project-rulesets.xml")
    ruleSets = []
}
  • toolVersion = "6.13.0"toolVersion = "6.20.0" に変更します。

Gradle Tool Window の左上にある「Refresh all Gradle projects」ボタンをクリックして更新した後、clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると PMD で警告が出ました。

f:id:ksby:20200101192227p:plain

警告の原因を取り除く

int[] x = new int[] { 1, 2, 3 };int[] x = { 1, 2, 3 }; と書いてもいいの!?

生成されたレポートファイル build/reports/pmd/main.html をブラウザで開くと2箇所指摘されており、どちらも Problem には Array initialization can be written shorter が表示されていました。

f:id:ksby:20200101192951p:plain

Array initialization can be written shorter を開くと以下のページが開きました。

f:id:ksby:20200101195731p:plain

int[] x = new int[] { 1, 2, 3 };int[] x = { 1, 2, 3 }; と書いてもいいらしい。初耳です。。。

Web で検索してみると Baeldung に Initializing Arrays in Java - 3. At the Time of Declaration という記事が出ていました。確かにここにも記載されています。

型の指定が不要ならば記載しないように変更します。

src/main/java/ksbysample/webapp/lending/helper/download/booklistcsv/BookListCsvDownloadHelper.java の以下の点を変更します。

public class BookListCsvDownloadHelper implements DataDownloadHelper {

    private static final String[] CSV_HEADER = {"ISBN", "書名", "申請理由", "承認/却下", "却下理由"};
    private static final String CSV_FILE_NAME_FORMAT = "booklist-%s.csv";
  • new String[]{"ISBN", "書名", "申請理由", "承認/却下", "却下理由"}{"ISBN", "書名", "申請理由", "承認/却下", "却下理由"} に変更します。

src/main/java/ksbysample/webapp/lending/view/BookListCsvView.java の以下の点を変更します。

@Component(value = "BookListCsvView")
public class BookListCsvView extends AbstractView {

    private static final String[] CSV_HEADER = {"ISBN", "書名", "申請理由", "承認/却下", "却下理由"};
    private static final String CSV_FILE_NAME_FORMAT = "booklist-%s.csv";
  • new String[]{"ISBN", "書名", "申請理由", "承認/却下", "却下理由"}{"ISBN", "書名", "申請理由", "承認/却下", "却下理由"} に変更します。

clean タスク実行 → Rebuild Project 実行 → build タスクを実行すると無事 "BUILD SUCCESSFUL" のメッセージが出力されました。本当にエラーにならないんですね。。。

f:id:ksby:20200101202135p:plain

ちなみに引数の場合には型を指定する必要があります。以下のような変更を行うと IntelliJ IDEA のエディタ上で赤波線が表示されますし、build するとエラーになります。

errors.reject("UploadBooklistForm.fileupload.lengtherr"
        , new Object[]{line, csvdata.length}, null);

 ↓

errors.reject("UploadBooklistForm.fileupload.lengtherr"
        , {line, csvdata.length}, null);

履歴

2020/01/01
初版発行。