2017-07-20

Spring Boot + npm + Geb で入力フォームを作ってテストする ( その１ )( 概要 )

概要

記事一覧はこちらです。

下記の概要の Web アプリケーションを作成します。

今回は以下の方法を知るためにサンプルを作成します。
- Spring Boot のプロジェクトに npm を使用して Bootstrap や AdminLTE の CSS のライブラリをインストールする方法
- webpack を使用して各画面の js ファイルを生成する方法
- MySQL, PostgreSQL ではなく H2 Database を使用し、Flyway を使用してテーブルを作成する方法（別途 DB のソフトをインストールすることなく試せるサンプルを作成できるようになりたい）
- Geb でテストを作成する方法
Web で webpack に関する記事を見ていると CSS, Javascript, 画像ファイル等の複数ファイルを１ファイルにまとめてるのが本来の使い方のようなのですが、今回は CSS や画像ファイル等 Javascript 以外のファイルは１つにまとめずに npm-scripts でコピーするだけにし、Javascript のファイルだけ webpack で１つにまとめます。
以下の仕様の入力フォームを作成します。
- 入力画面１ → 入力画面２ → 入力画面３ → 確認画面 → 完了画面、の５画面構成にします。
- 確認画面から修正したい項目がある入力画面へ戻れるようにします。
- 入力されたデータは入力画面１～３、確認画面を遷移している時はセッションに保存します。
- 確認画面で確認ボタンが押されたら DB に保存してメールを送信した後、完了画面へ遷移します。
画面は Bootstrap + AdminLTE で作成します。AdminLTE は本来管理画面向けですが、この２つを組み合わせて npm でインストールするサンプルが欲しいので、この組み合わせで作成します。
jQuery は 3 系ではなく AdminLTE が使用している 2 系にします。
これまでは Bootstrap, jQuery, AdminLTE を build.gradle にスクリプトを書いてインストールしていましたが、今回は Node.js をインストールして npm + npm-scripts でインストールします。
Javascript は webpack を使用して各画面毎の js ファイルを生成するようにします。
画面のテストは Geb を使用してみます。Selenide にするか迷いましたが、個人的に Groovy を気に入っているので Geb を試すことにしました。
Project は ksbysample-boot-miscellaneous/boot-npm-geb-sample に作成します。
構成要素は、以下の想定です。
- Spring Boot 1.5
- Spring Session（Redis は使用せず spring.session.store-type=hash_map で設定します）
- Thymeleaf 3
- Doma 2
- FreeMarker
- Bootstrap
- AdminLTE
- jQuery
- H2 Database
- Flyway
以下の順序で進める予定です。
- Project の作成
- Node.js のインストール
- Bootstrap, AdminLTE のインストール
- URL の決定
- 画面の HTML + Controller クラスの作成
- テーブルの作成、Flyway によるテーブル作成処理の作成
- 入力画面の作成
- 確認画面の作成
- 完了画面の作成
- Geb によるテストの作成

履歴

2017/07/20
初版発行。
2017/08/13
* DB のマイグレーションツールを Liquibase → Flyway に変更しました。

2017-07-20

Spring Boot + npm + Geb で入力フォームを作ってテストする ( 大目次 )

GitHub は https://github.com/ksby/ksbysample-boot-miscellaneous

ここからフレームワーク（Spring Boot 2.1.x 等）や各種ライブラリのバージョンアップ編です。

ここからモジュールやツールの 2020/05 時点の最新バージョンアップ編です。

ここからモジュールやツールの 2021/10 時点の最新バージョンアップ編です。

2017-07-17

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( 感想 )

記事一覧はこちらです。

1.4系 → 1.5 系へのバージョンアップでは、ほとんど変更する点はありませんでした。
Thymeleaf を 2.1.5 → 3.0.6 へバージョンアップしましたが、HTML をそのままで解釈できるようになって本当に使いやすくなりました。タグの末尾に必ず “/” を付ける必要がなくなったし、個人的には新機能 Fragment Expressions が気に入りました。Spring Boot 1.5 系ではまだデフォルトでサポートされていませんが、Thymeleaf を使用するのであれば 3 系を使用することをお薦めします！
PMD は CheckStyle, FindBugs とチェック内容が重複するところもありますが、別の観点からも指摘してくれるので入れた方がよいですね。ただしデフォルトのままでは不要な点も大量に指摘してくるので、設定のカスタマイズは必須だと思います。このカスタマイズが結構面倒でした。。。
JUnit4 でテストを書く時も Groovy で書いた方が便利だとは思いませんでした。また Groovy SQL が便利すぎます。ユニットテストを Java で書くことは今後ないんじゃないだろうか、という気がします。

さて、次に何をやるかは考え中です。。。

2017-07-17

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１５ )( -XX:+ExitOnOutOfMemoryError と -XX:+CrashOnOutOfMemoryError オプションのどちらを指定すべきか？ )

概要

記事一覧はこちらです。

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１４ )( request, response のログを出力する RequestAndResponseLogger クラスを修正する ) の続きです。

今回の手順で確認できるのは以下の内容です。
- stackoverflow の Java - shutting down on Out of Memory Error の QA で 8u92 から -XX:+ExitOnOutOfMemoryError と -XX:+CrashOnOutOfMemoryError のオプションが追加になったと見かけて、そういえばどちらも指定していなかったことに気づきました。
- ただし、ほとんど似たようなオプションに見えてどちらを指定した方がよいのかよく分からなかったので、その調査をします。

参照したサイト・書籍

Java - shutting down on Out of Memory Error
https://stackoverflow.com/questions/12096403/java-shutting-down-on-out-of-memory-error
Print All JVM Flags
https://stackoverflow.com/questions/10486375/print-all-jvm-flags
Implement ExitOnOutOfMemory and CrashOnOutOfMemory in HotSpot
https://bugs.openjdk.java.net/browse/JDK-8138745
Release Note: New JVM Options: ExitOnOutOfMemoryError and CrashOnOutOfMemoryError
https://bugs.openjdk.java.net/browse/JDK-8152669
8u92 Update Release Notes
http://www.oracle.com/technetwork/java/javase/8u92-relnotes-2949471.html
terazzoの日記 - JavaでOutOfMemoryErrorを出す方法
http://d.hatena.ne.jp/terazzo/20130320/1363731368

確認の前に -XX:HeapDumpPath, -XX:ErrorFile で指定するファイル名に日時が付くようにする
-XX:+ExitOnOutOfMemoryError と -XX:+CrashOnOutOfMemoryError のオプションが追加されていることを確認する
実際に OutOfMemory が発生する処理を追加して相違点を確認する
まとめ
webapp_startup.bat を修正する

手順

確認の前に -XX:HeapDumpPath, -XX:ErrorFile で指定するファイル名に日時が付くようにする

/webapps/ksbysample-webapp-lending/bat/webapp_startup.bat は現在以下の内容ですが、

@echo on

setlocal
set JAVA_HOME=C:\Java\jdk1.8.0_131
set PATH=%JAVA_HOME%\bin;%PATH%
set WEBAPP_HOME=C:\webapps\ksbysample-webapp-lending
set WEBAPP_JAR=ksbysample-webapp-lending-1.5.4-RELEASE.jar

cd /d %WEBAPP_HOME%
java -server ^
     -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled ^
     -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=75 ^
     -XX:+ScavengeBeforeFullGC -XX:+CMSScavengeBeforeRemark ^
     -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps ^
     -Xloggc:%WEBAPP_HOME%/logs/gc.log ^
     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%WEBAPP_HOME%/logs/%date:~0,4%%date:~5,2%%date:~8,2%.hprof ^
     -XX:ErrorFile=%WEBAPP_HOME%/logs/hs_err_pid_%p.log ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dcom.sun.management.jmxremote ^
     -Dcom.sun.management.jmxremote.port=7900 ^
     -Dcom.sun.management.jmxremote.ssl=false ^
     -Dcom.sun.management.jmxremote.authenticate=false ^
     -Dspring.profiles.active=product ^
     -jar lib\%WEBAPP_JAR%

以下の問題があることに気づきました。

-XX:HeapDumpPath=%WEBAPP_HOME%/logs/%date:~0,4%%date:~5,2%%date:~8,2%.hprof だとファイルに日付しか付かず、同じ日に HeapDump が出力された場合に前のファイルが上書きされてしまう。
-XX:ErrorFile=%WEBAPP_HOME%/logs/hs_err_pid_%p.log の %p でプロセス ID が付くものと思っていましたが、Windows だからなのかプロセス ID ではなくただの “p” になってしまう。

どちらもファイル名に日時が付くように以下のように変更します。この修正はファイル生成時に日時を付けるものではなく、最終的には -XX:+CrashOnOutOfMemoryError オプションを付けて、java コマンドが終了した後に日時の付いたファイル名に rename する想定のものです。

@echo on

setlocal
set JAVA_HOME=C:\Java\jdk1.8.0_131
set PATH=%JAVA_HOME%\bin;%PATH%
set WEBAPP_HOME=C:\webapps\ksbysample-webapp-lending
set WEBAPP_JAR=ksbysample-webapp-lending-1.5.4-RELEASE.jar
set LOGS_DIR=%WEBAPP_HOME%\logs
set PATH_HEAPDUMPFILE=%LOGS_DIR%\heapdump.hprof
set PATH_ERRORFILE=%LOGS_DIR%\hs_err.log

cd /d %WEBAPP_HOME%
java -server ^
     -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled ^
     -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=75 ^
     -XX:+ScavengeBeforeFullGC -XX:+CMSScavengeBeforeRemark ^
     -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps ^
     -Xloggc:%WEBAPP_HOME%/logs/gc.log ^
     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dcom.sun.management.jmxremote ^
     -Dcom.sun.management.jmxremote.port=7900 ^
     -Dcom.sun.management.jmxremote.ssl=false ^
     -Dcom.sun.management.jmxremote.authenticate=false ^
     -Dspring.profiles.active=product ^
     -jar lib\%WEBAPP_JAR%

set YYYYMMDD=%date:~0,4%%date:~5,2%%date:~8,2%
set HHMMSS=%time:~0,8%
set HHMMSS=%HHMMSS::=%
set HHMMSS=%HHMMSS: =%
if exist %PATH_HEAPDUMPFILE% rename %PATH_HEAPDUMPFILE% heapdump_%YYYYMMDD%%HHMMSS%.hprof
if exist %PATH_ERRORFILE% rename %PATH_ERRORFILE% hs_err_%YYYYMMDD%%HHMMSS%.log

-XX:+ExitOnOutOfMemoryError と -XX:+CrashOnOutOfMemoryError のオプションが追加されていることを確認する

オプションが追加されたのは分かったのですが、実際に java.exe を実行する等してオプションを確認する方法があるのか気になったので調べて見ました。Print All JVM Flags を見ると java -XX:+UnlockDiagnosticVMOptions -XX:+PrintFlagsFinal を実行すれば表示されるようです。

8u131 で実行すると以下の行が出力されました。

     bool CrashOnOutOfMemoryError                   = false                               {product}
     bool ExitOnOutOfMemoryError                    = false                               {product}

実際に OutOfMemory が発生する処理を追加して相違点を確認する

OutOfMemory が発生する処理を追加する

src/main/java/ksbysample/webapp/lending/SampleController.java を以下のように変更します。-Xmx1024m と Java ヒープの最大サイズを 1024m で指定しているので、1024m の String を生成しようとすれば OutOfMemory になるはずです。

@Controller
@RequestMapping("/sample")
public class SampleController {

    ..........

    @RequestMapping("/outofmemory")
    @ResponseBody
    public void outofmemory() {
        String msg = StringUtils.repeat('x', 1024 * 1024 * 1024);
    }

}

clean タスク実行 → Rebuild Project 実行 → build タスクを実行して ksbysample-webapp-lending-1.5.4-RELEASE.jar を生成した後、C:\webapps\ksbysample-webapp-lending\lib の下へコピーします。

どちらのオプションも指定していない場合、どうなるのか？

webapp_startup.bat を実行して Tomcat を起動した後、http://localhost:8080/sample/outofmemory にアクセスすると OutOfMemoryError が発生します。

ログファイル ksbysample-webapp-lending.log には at ksbysample.webapp.lending.SampleController.outofmemory(SampleController.java:31) が出力されており、OutOfMemoryError が発生した原因の箇所が分かります。

org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: Java heap space
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:982)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:317)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:127)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:167)
    at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.OutOfMemoryError: Java heap space
    at org.apache.commons.lang3.StringUtils.repeat(StringUtils.java:6087)
    at ksbysample.webapp.lending.SampleController.outofmemory(SampleController.java:31)
    at ksbysample.webapp.lending.SampleController$$FastClassBySpringCGLIB$$709005bd.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    at ksbysample.webapp.lending.aspect.logging.RequestAndResponseLogger.logginRequestAndResponse(RequestAndResponseLogger.java:79)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:618)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673)
    at ksbysample.webapp.lending.SampleController$$EnhancerBySpringCGLIB$$a1afe1d0.outofmemory(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)

コンソールには Heap dump file created のログが出力されるだけで、Web アプリケーションは終了しません。

f:id:ksby:20170717154509p:plain

C:\webapps\ksbysample-webapp-lending\logs の下には heapdump.hprof が作成されています。

f:id:ksby:20170717154620p:plain

コンソールで Ctrl+C を押して Tomcat を停止します。

`-XX:+ExitOnOutOfMemoryError` オプションを指定するとどうなるか？

webapp_startup.bat を以下のように変更します。

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%WEBAPP_HOME%/logs/%date:~0,4%%date:~5,2%%date:~8,2%.hprof ^ オプションを削除します。
-XX:+ExitOnOutOfMemoryError を追加します。

     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+ExitOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^

webapp_startup.bat を実行して Tomcat を起動した後、http://localhost:8080/sample/outofmemory にアクセスして OutOfMemoryError を発生させます。

ログファイル ksbysample-webapp-lending.log には何も出力されませんでした。

コンソールには Terminating due to java.lang.OutOfMemoryError: Java heap space と出力されて Web アプリケーションは終了しています。

f:id:ksby:20170717155253p:plain

C:\webapps\ksbysample-webapp-lending\logs の下には何も作成されません。

f:id:ksby:20170717155352p:plain

`-XX:+CrashOnOutOfMemoryError` オプションを指定するとどうなるか？

webapp_startup.bat を以下のように変更します。

-XX:+ExitOnOutOfMemoryError を削除して、-XX:+CrashOnOutOfMemoryError を追加します。

     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^

webapp_startup.bat を実行して Tomcat を起動した後、http://localhost:8080/sample/outofmemory にアクセスして OutOfMemoryError を発生させます。

-XX:+ExitOnOutOfMemoryError オプションの時と同じくログファイル ksbysample-webapp-lending.log には何も出力されません。

コンソールには Aborting due to java.lang.OutOfMemoryError: Java heap space と出力されて Web アプリケーションは終了しています。

f:id:ksby:20170717160028p:plain

C:\webapps\ksbysample-webapp-lending\logs の下には hs_err_20170717155857.log というファイルが作成されて、

f:id:ksby:20170717160226p:plain

hs_err_20170717155857.log を開くと以下のようなログが出力されています。このログファイルだとクラスとメソッドは分かりますが、行数までは分かりません。

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (debug.cpp:308), pid=10920, tid=0x0000000000002d64
#  fatal error: OutOfMemory encountered: Java heap space
#
# JRE version: Java(TM) SE Runtime Environment (8.0_131-b11) (build 1.8.0_131-b11)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode windows-amd64 compressed oops)
# Failed to write core dump. Minidumps are not enabled by default on client versions of Windows
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#

---------------  T H R E A D  ---------------

Current thread (0x000000005f7b4000):  JavaThread "http-nio-8080-exec-1" daemon [_thread_in_vm, id=11620, stack(0x0000000065f00000,0x0000000066000000)]

Stack: [0x0000000065f00000,0x0000000066000000]
[error occurred during error reporting (printing stack bounds), id 0xc0000005]

Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  org.apache.commons.lang3.StringUtils.repeat(CI)Ljava/lang/String;+8
j  ksbysample.webapp.lending.SampleController.outofmemory()V+4
..........

まとめ

-XX:+ExitOnOutOfMemoryError オプションを指定すると何もログを出力せずに Web アプリケーションが終了します。
-XX:+CrashOnOutOfMemoryError オプションを指定すると -XX:ErrorFile オプションで指定されたファイルにエラーファイルが生成されて Web アプリケーションが終了します。-XX:ErrorFile オプションを指定していない場合にはデフォルトの設定場所（ksbysample-webapp-lending の場合は C:\webapps\ksbysample-webapp-lending でした）に生成されます。このファイルを見ると OutOfMemory が発生したクラスとメソッドは分かりますが、行数までは分かりません。
-XX:+ExitOnOutOfMemoryError あるいは -XX:+CrashOnOutOfMemoryError オプションを指定すると Web アプリケーションのログファイルには Caused by: java.lang.OutOfMemoryError: Java heap space のログは出力されません。
どちらのオプションも指定しなければ Web アプリケーションは終了しません。また Web アプリケーションのログファイルに Caused by: java.lang.OutOfMemoryError: Java heap space のログが出力されます。このログが出力されると OutOfMemory が発生したファイルと行数が分かります。
HeapDump は -XX:+ExitOnOutOfMemoryError あるいは -XX:+CrashOnOutOfMemoryError オプションの有無とは全く関係がなく、-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=... オプションを指定すれば出力されます。

個人的な感想としては、

OutOfMemory 発生時に Web アプリケーションのログファイルに発生箇所のファイル名、行番号のログが出力された方がよくて、かつ Web アプリケーションが終了せずエラーが発生し続けても構わないのであれば -XX:+ExitOnOutOfMemoryError も -XX:+CrashOnOutOfMemoryError も指定しません。
Web アプリケーションが終了すれば自動的に再起動する仕組みがあり、Web アプリケーションのログファイルに発生箇所のファイル名、行番号のログが出力される必要がないのであれば -XX:+CrashOnOutOfMemoryError を指定して終了するようにして、エラーファイルが生成されるようにします。
-XX:+ExitOnOutOfMemoryError あるいは -XX:+CrashOnOutOfMemoryError オプションを指定する／しないに関わらず、-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=... オプションは指定して HeapDump は出力した方がよいです。
-XX:+ExitOnOutOfMemoryError は存在意義がよく分かりませんでした。HeapDump だけで OutOfMemory の原因を調査するのは難しい気がします。今回出力された HeapDump を Memory Analyzer で開いてみましたが、今回のような実装が原因であれば Caused by: java.lang.OutOfMemoryError: Java heap space のログが出てくれた方が分かりやすいかな、と思いました。

webapp_startup.bat を修正する

オプションを忘れないようにするために、webapp_startup.bat には -XX:+CrashOnOutOfMemoryError を追加することにします。

@echo on

setlocal
set JAVA_HOME=C:\Java\jdk1.8.0_131
set PATH=%JAVA_HOME%\bin;%PATH%
set WEBAPP_HOME=C:\webapps\ksbysample-webapp-lending
set WEBAPP_JAR=ksbysample-webapp-lending-1.5.4-RELEASE.jar
set LOGS_DIR=%WEBAPP_HOME%\logs
set PATH_HEAPDUMPFILE=%LOGS_DIR%\heapdump.hprof
set PATH_ERRORFILE=%LOGS_DIR%\hs_err.log

cd /d %WEBAPP_HOME%
java -server ^
     -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled ^
     -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=75 ^
     -XX:+ScavengeBeforeFullGC -XX:+CMSScavengeBeforeRemark ^
     -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps ^
     -Xloggc:%WEBAPP_HOME%/logs/gc.log ^
     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%PATH_HEAPDUMPFILE% ^
     -XX:+CrashOnOutOfMemoryError ^
     -XX:ErrorFile=%PATH_ERRORFILE% ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dcom.sun.management.jmxremote ^
     -Dcom.sun.management.jmxremote.port=7900 ^
     -Dcom.sun.management.jmxremote.ssl=false ^
     -Dcom.sun.management.jmxremote.authenticate=false ^
     -Dspring.profiles.active=product ^
     -jar lib\%WEBAPP_JAR%

set YYYYMMDD=%date:~0,4%%date:~5,2%%date:~8,2%
set HHMMSS=%time:~0,8%
set HHMMSS=%HHMMSS::=%
set HHMMSS=%HHMMSS: =%
if exist %PATH_HEAPDUMPFILE% rename %PATH_HEAPDUMPFILE% heapdump_%YYYYMMDD%%HHMMSS%.hprof
if exist %PATH_ERRORFILE% rename %PATH_ERRORFILE% hs_err_%YYYYMMDD%%HHMMSS%.log

履歴

2017/07/17
初版発行。

2017-07-13

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１４ )( request, response のログを出力する RequestAndResponseLogger クラスを修正する )

概要

記事一覧はこちらです。

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１３ )( jar ファイルを作成して動作確認する ) の続きです。

今回の手順で確認できるのは以下の内容です。
- request, response のデータを出力する ksbysample.webapp.lending.aspect.logging.RequestAndResponseLogger を作成していますが、以下２つの問題があることに気づきました。今回はそれを修正します。
  - ログを出力する対象を @RequestMapping アノテーションが付加されたメソッドとしていたのですが、この条件だと Spring Framework 4.3 から追加された @GetMapping, @PostMapping アノテーションが付加されたメソッドではログが出力されないことに気づきました。ログが出力されるよう変更します。
  - @RequestMapping アノテーションが付加されたメソッドで例外が throw されて、応答を返すのが @ExceptionHandler メソッドが付加されたメソッドになった時に response のログが出力されないことに気づきました。こちらもログが出力されるよう変更します。

参照したサイト・書籍

Spring Aspectj @Before all rest method
http://techqa.info/programming/question/42642681/Spring-Aspectj–Before-all-rest-method

今回の修正・動作確認のための前準備
1. 今回の動作確認で使用する SampleController クラスを Spring Security による認証の対象外にする
2. RequestAndResponseLogger の対象となるパッケージを ksbysample.webapp.lending.web → ksbysample.webapp.lending へ変更する
@GetMapping, @PostMapping アノテーションが付加されたメソッドでも request, response のログが出力されるようにする
エラーが発生して @ExceptionHandler アノテーションを付加したメソッドが応答を返す時でも response のログが出力されるようにする

手順

今回の修正・動作確認のための前準備

今回の動作確認で使用する SampleController クラスを Spring Security による認証の対象外にする

今回の RequestAndResponseLogger クラスの修正では、動作確認に ksbysample.webapp.lending.SampleController クラスを使用することにします。ただし SampleController クラスに関連付けている URL /sample は Spring Security の認証が必要な状態なので、認証の対象外にします。

src/main/java/ksbysample/webapp/lending/config/WebSecurityConfig.java を以下のように変更します。

@Configuration
@Order(SecurityProperties.ACCESS_OVERRIDE_ORDER)
public class WebSecurityConfig extends WebSecurityConfigurerAdapter {

    ..........

    @Override
    protected void configure(HttpSecurity http) throws Exception {
        http.authorizeRequests()
                // 認証の対象外にしたいURLがある場合には、以下のような記述を追加します
                // 複数URLがある場合はantMatchersメソッドにカンマ区切りで対象URLを複数列挙します
                // .antMatchers("/country/**").permitAll()
                ..........
                .antMatchers("/sample/**").permitAll()
                .anyRequest().authenticated();
        ..........

.antMatchers("/sample/**").permitAll() を追加します。

RequestAndResponseLogger の対象となるパッケージを `ksbysample.webapp.lending.web` → `ksbysample.webapp.lending` へ変更する

ksbysample.webapp.lending.SampleController クラスを使用するので、RequestAndResponseLogger の対象となるパッケージを ksbysample.webapp.lending.web → ksbysample.webapp.lending へ変更します。

src/main/java/ksbysample/webapp/lending/aspect/logging/RequestAndResponseLogger.java を以下のように変更します。

@Aspect
@Component
public class RequestAndResponseLogger {

    ..........

    /**
     * @param pjp ???
     * @return ???
     * @throws Throwable
     */
    @Around(value = "execution(* ksbysample.webapp.lending..*.*(..))"
            + "&& @annotation(org.springframework.web.bind.annotation.RequestMapping)")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {

execution(* ksbysample.webapp.lending.web..*.*(..)) → execution(* ksbysample.webapp.lending..*.*(..)) へ変更します。

@GetMapping, @PostMapping アノテーションが付加されたメソッドでも request, response のログが出力されるようにする

例えば ksbysample.webapp.lending.SampleController クラスに @RequestMapping アノテーションを付加したメソッドを追加し、

@Controller
@RequestMapping("/sample")
public class SampleController {

    ..........

    /**
     * {@link RequestMapping}, {@link GetMapping}, {@link PostMapping} アノテーションを付加
     * したメソッドが呼び出された時に {@link RequestAndResponseLogger} クラスで request, response
     * が出力されることを確認するための動作確認用のメソッド
     *
     * @return 画面に出力する文字列
     */
    @RequestMapping("/hello")
    @ResponseBody
    public String hello() {
        return "hello";
    }

}

Tomcat を起動して http://localhost:8080/sample/hello にアクセスすると、RequestAndResponseLogger クラスにより request, response のログが出力されます。

f:id:ksby:20170713002633p:plain

hello メソッドに付加するアノテーションを @GetMapping に変更すると、

    @GetMapping("/hello")
    @ResponseBody
    public String hello() {
        return "hello";
    }

request, response のログが出力されません。

f:id:ksby:20170713003220p:plain

@GetMapping は以下の実装の composed annotation ですが、AspectJ で @annotation(org.springframework.web.bind.annotation.RequestMapping) という Pointcut の指定では @GetMapping は対象にならないようです。

f:id:ksby:20170713003759p:plain

単純に対象にしたいアノテーションを || で結合して指定すると request, response のログが出力されるようにはなるのですが、出来れば @RequestMapping アノテーションを使用した composed annotation をシンプルに指定できるようにしたいです。

    @Around(value = "execution(* ksbysample.webapp.lending..*.*(..))"
            + " && (@annotation(org.springframework.web.bind.annotation.RequestMapping)"
            + " || @annotation(org.springframework.web.bind.annotation.GetMapping)"
            + " || @annotation(org.springframework.web.bind.annotation.PostMapping)"
            + " || @annotation(org.springframework.web.bind.annotation.PutMapping)"
            + " || @annotation(org.springframework.web.bind.annotation.DeleteMapping)"
            + " || @annotation(org.springframework.web.bind.annotation.PatchMapping))")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {

指定する方法がないか調べてみたところ、Spring Aspectj @Before all rest method という記事を見つけました。execution(@(@org.springframework.web.bind.annotation.RequestMapping *) * *(..)) と指定すれば @RequestMapping アノテーションを使用した composed annotation が付加されたメソッドが全て対象になるようです。

ただしこの条件だけだと @RequestMapping アノテーションが対象に含まれないので、以下のように変更することにします。

@Aspect
@Component
public class RequestAndResponseLogger {

    ..........

    /**
     * {@link RequestMapping} アノテーションが付加されたメソッドを Join Point にする Pointcut
     */
    @Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
    public void requestMappingAnnotation() {
    }

    /**
     * {@link GetMapping}, {@link PostMapping} 等 {@link RequestMapping} アノテーションを使用した
     * composed annotation が付加されたメソッドを Join Point にする Pointcut
     */
    @Pointcut("execution(@(@org.springframework.web.bind.annotation.RequestMapping *) * *(..))")
    public void requestMappingComposedAnnotations() {
    }

    /**
     * @param pjp ???
     * @return ???
     * @throws Throwable
     */
    @Around(value = "execution(* ksbysample.webapp.lending..*.*(..))"
            + " && (requestMappingAnnotation() || requestMappingComposedAnnotations())")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {

これで @RequestMapping の時でも request, response のログが出力され、

    @RequestMapping("/hello")
    @ResponseBody
    public String hello() {
        return "hello";
    }

f:id:ksby:20170713011034p:plain

@GetMapping の時でも request, response のログが出力されます。

    @GetMapping("/hello")
    @ResponseBody
    public String hello() {
        return "hello";
    }

f:id:ksby:20170713011351p:plain

エラーが発生して @ExceptionHandler アノテーションを付加したメソッドが応答を返す時でも response のログが出力されるようにする

ksbysample.webapp.lending.SampleController クラスに以下の hello メソッド、handlerException メソッドを追加し、hello メソッドでリクエストを受けて handlerException メソッドでレスポンスが返るようにします。

    @GetMapping("/hello")
    @ResponseBody
    public String hello() {
        if (true) {
            throw new RuntimeException();
        }
        return "hello";
    }

    @ExceptionHandler(RuntimeException.class)
    @ResponseBody
    public String handlerException() {
        return "RuntimeException";
    }

Tomcat を起動して http://localhost:8080/sample/hello にアクセスすると、RequestAndResponseLogger クラスにより request のログは出力されますが、response のログは出力されません。

f:id:ksby:20170713013930p:plain

RequestAndResponseLogger クラスに @ExceptionHandler アノテーションが付加されたメソッドが呼び出された後に response のログを出力するための After Returning Advice のメソッドを追加します。以下のように変更します。

@Aspect
@Component
public class RequestAndResponseLogger {

    private static final Logger logger = LoggerFactory.getLogger(RequestAndResponseLogger.class);

    private static final String POINTCUT_ALL_CLASS_AND_METHOD_UNDER_APPLICATION_PACKAGE
            = "execution(* ksbysample.webapp.lending..*.*(..))";

    ..........

    /**
     * Web アプリケーションの package 配下の全てのクラスのメソッドを Join Point にする Pointcut
     */
    @Pointcut(POINTCUT_ALL_CLASS_AND_METHOD_UNDER_APPLICATION_PACKAGE)
    public void allClassAndMethodUnderApplicationPackage() {
    }

    ..........

    @Around(value = "allClassAndMethodUnderApplicationPackage()"
            + " && (requestMappingAnnotation() || requestMappingComposedAnnotations())")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {
        ..........
    }

    @After(value = "allClassAndMethodUnderApplicationPackage()"
            + " && @annotation(org.springframework.web.bind.annotation.ExceptionHandler)")
    public void logginResponseAfterExceptionHandler() {
        HttpServletResponse response
                = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getResponse();
        loggingResponse(response);
    }

Web アプリケーションの package 配下の全てのクラスのメソッドを対象にする PointCut 式 execution(* ksbysample.webapp.lending..*.*(..)) を今回追加する After Returning Advice のメソッドでも使用したいので、定数文字列 POINTCUT_ALL_CLASS_AND_METHOD_UNDER_APPLICATION_PACKAGE と allClassAndMethodUnderApplicationPackage メソッドを追加します。
logginRequestAndResponse メソッドの @Around アノテーションに指定する Pointcut 式を allClassAndMethodUnderApplicationPackage() に変更します。
@ExceptionHandler アノテーションが付加されたメソッドが呼び出された後に処理を行う @After アノテーションが付加された logginResponseAfterExceptionHandler メソッドを追加します。

再度 Tomcat を起動して http://localhost:8080/sample/hello にアクセスすると、今度は reponse のログも出力されました。

f:id:ksby:20170713023614p:plain

最後に src/main/java/ksbysample/webapp/lending/aspect/logging/RequestAndResponseLogger.java のソースを記載します。

ソースコード

RequestAndResponseLogger.java

package ksbysample.webapp.lending.aspect.logging;

import com.google.common.collect.Iterators;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Arrays;
import java.util.Map;
import java.util.stream.StreamSupport;

/**
 * ???
 */
@Aspect
@Component
public class RequestAndResponseLogger {

    private static final Logger logger = LoggerFactory.getLogger(RequestAndResponseLogger.class);

    private static final String POINTCUT_ALL_CLASS_AND_METHOD_UNDER_APPLICATION_PACKAGE
            = "execution(* ksbysample.webapp.lending..*.*(..))";

    private static final String LOG_REQUEST_INFO = "[req][info  ] ";
    private static final String LOG_REQUEST_HEADER = "[req][header] ";
    private static final String LOG_REQUEST_COOKIE = "[req][cookie] ";
    private static final String LOG_REQUEST_PARAMETER = "[req][param ] ";

    private static final String LOG_RESPONSE_INFO = "[res][info  ] ";
    private static final String LOG_RESPONSE_HEADER = "[res][header] ";

    /**
     * Web アプリケーションの package 配下の全てのクラスのメソッドを Join Point にする Pointcut
     */
    @Pointcut(POINTCUT_ALL_CLASS_AND_METHOD_UNDER_APPLICATION_PACKAGE)
    public void allClassAndMethodUnderApplicationPackage() {
    }

    /**
     * {@link RequestMapping} アノテーションが付加されたメソッドを Join Point にする Pointcut
     */
    @Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
    public void requestMappingAnnotation() {
    }

    /**
     * {@link GetMapping}, {@link PostMapping} 等 {@link RequestMapping} アノテーションを使用した
     * composed annotation が付加されたメソッドを Join Point にする Pointcut
     */
    @Pointcut("execution(@(@org.springframework.web.bind.annotation.RequestMapping *) * *(..))")
    public void requestMappingComposedAnnotations() {
    }

    /**
     * @param pjp ???
     * @return ???
     * @throws Throwable
     */
    @Around(value = "allClassAndMethodUnderApplicationPackage()"
            + " && (requestMappingAnnotation() || requestMappingComposedAnnotations())")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {
        HttpServletRequest request
                = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
        loggingRequest(request);
        Object ret = pjp.proceed();
        HttpServletResponse response
                = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getResponse();
        loggingResponse(response);

        return ret;
    }

    /**
     * ???
     */
    @After(value = "allClassAndMethodUnderApplicationPackage()"
            + " && @annotation(org.springframework.web.bind.annotation.ExceptionHandler)")
    public void logginResponseAfterExceptionHandler() {
        HttpServletResponse response
                = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getResponse();
        loggingResponse(response);
    }

    private void loggingRequest(HttpServletRequest request) {
        loggingRequestInfo(request);
        loggingRequestHeaders(request);
        loggingRequestCookies(request);
        loggingRequestParameters(request);
    }

    private void loggingResponse(HttpServletResponse response) {
        loggingResponseInfo(response);
        loggingResponseHeaders(response);
    }

    private void loggingRequestInfo(HttpServletRequest request) {
        StringBuilder sb = new StringBuilder();
        append(sb, "REQUEST_URI", request.getRequestURI());
        append(sb, ", SERVLET_PATH", request.getServletPath());
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "CHARACTER_ENCODING", request.getCharacterEncoding());
        append(sb, ", CONTENT_LENGTH", String.valueOf(request.getContentLength()));
        append(sb, ", CONTENT_TYPE", request.getContentType());
        append(sb, ", LOCALE", String.valueOf(request.getLocale()));
        append(sb, ", SCHEME", request.getScheme());
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "REMOTE_ADDR", request.getRemoteAddr());
        append(sb, ", REMOTE_HOST", request.getRemoteHost());
        append(sb, ", SERVER_NAME", request.getServerName());
        append(sb, ", SERVER_PORT", String.valueOf(request.getServerPort()));
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "CONTEXT_PATH", request.getContextPath());
        append(sb, ", REQUEST_METHOD", request.getMethod());
        append(sb, ", QUERY_STRING", request.getQueryString());
        append(sb, ", PATH_INFO", request.getPathInfo());
        append(sb, ", REMOTE_USER", request.getRemoteUser());
        logging(LOG_REQUEST_INFO, null, sb.toString());
    }

    private void loggingRequestHeaders(HttpServletRequest request) {
        Iterable<String> headerNameList = () -> Iterators.forEnumeration(request.getHeaderNames());
        StreamSupport.stream(headerNameList.spliterator(), false)
                .filter(headerName -> !StringUtils.equals(headerName, "cookie"))
                .forEach(headerName -> {
                    Iterable<String> headerList = () -> Iterators.forEnumeration(request.getHeaders(headerName));
                    headerList.forEach(header -> logging(LOG_REQUEST_HEADER, headerName, header));
                });
    }

    private void loggingRequestCookies(HttpServletRequest request) {
        if (request.getCookies() != null) {
            Arrays.asList(request.getCookies()).forEach(cookie -> {
                StringBuilder sb = new StringBuilder();
                sb.append("name = ")
                        .append(cookie.getName())
                        .append(", value = ")
                        .append(cookie.getValue())
                        .append(", domain = ")
                        .append(cookie.getDomain())
                        .append(", path = ")
                        .append(cookie.getPath())
                        .append(", maxage = ")
                        .append(cookie.getMaxAge())
                        .append(", secure = ")
                        .append(cookie.getSecure())
                        .append(", httponly = ")
                        .append(cookie.isHttpOnly());
                logging(LOG_REQUEST_COOKIE, null, sb.toString());
            });
        }
    }

    private void loggingRequestParameters(HttpServletRequest request) {
        Map<String, String[]> parameterMap = request.getParameterMap();
        parameterMap.forEach((key, values) -> {
            Arrays.asList(values).forEach(value -> logging(LOG_REQUEST_PARAMETER, key, value));
        });
    }

    private void loggingResponseInfo(HttpServletResponse response) {
        StringBuilder sb = new StringBuilder();
        append(sb, "RESPONSE_STATUS", String.valueOf(response.getStatus()));
        append(sb, ", CHARACTER_ENCODING", response.getCharacterEncoding());
        append(sb, ", CONTENT_TYPE", response.getContentType());
        append(sb, ", LOCALE", String.valueOf(response.getLocale()));
        logging(LOG_RESPONSE_INFO, null, sb.toString());
    }

    private void loggingResponseHeaders(HttpServletResponse response) {
        response.getHeaderNames().forEach(headerName -> {
            response.getHeaders(headerName).forEach(header -> logging(LOG_RESPONSE_HEADER, headerName, header));
        });
    }

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

    private void append(StringBuilder sb, String name, String value) {
        sb.append(name);
        sb.append(" = ");
        sb.append(value);
    }

}

履歴

2017/07/13
初版発行。

2017-07-09

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１３ )( jar ファイルを作成して動作確認する )

概要

記事一覧はこちらです。

Spring Boot 1.4.x の Web アプリを 1.5.x へバージョンアップする ( その１２ )( build.gradle への PMD の導入２ ) の続きです。

今回の手順で確認できるのは以下の内容です。
- jar ファイルを作成して動作確認する。

参照したサイト・書籍

手順

jar ファイルを作成、配置する

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

C:\project-springboot\ksbysample-webapp-lending\build\libs の下に ksbysample-webapp-lending-1.5.4-RELEASE.jar が作成されますので、C:\webapps\ksbysample-webapp-lending\lib の下に配置します。

webapps/ksbysample-webapp-lending/bat/webapp_startup.bat をリンク先の内容に変更した後、C:\webapps\ksbysample-webapp-lending\bat の下にコピーします。

サービスに登録する

コマンドプロンプトを「管理者として実行…」モードで起動した後、以下のコマンドを実行します。

> cd /d C:\webapps\ksbysample-webapp-lending\nssm
> nssm.exe install ksbysample-webapp-lending

「NSSM service installer」画面が表示されます。以下の画像の値を入力した後、「Install service」ボタンをクリックします。サービスの登録に成功すると「Service “ksbysample-webapp-lending” installed successfully!」のダイアログが表示されますので「OK」ボタンをクリックします。

f:id:ksby:20170709120507p:plain

「Path」に C:\webapps\ksbysample-webapp-lending\bat\webapp_startup.bat を入力します。
「Startup directory」に C:\webapps\ksbysample-webapp-lending\bat を入力します。

動作確認

動作確認前に DB のデータを以下の状態にします。
- user_info, user_role テーブルのデータは開発時のままにします。
- lending_app, lending_book, library_forsearch テーブルのデータはクリアします。
サービス画面を開きます。サービス一覧から「ksbysample-webapp-lending」を選択し、「サービスの開始」リンクをクリックしてサービスを開始します。
C:\webapps\ksbysample-webapp-lending\logs の下の ksbysample-webapp-lending.log をエディタで開き、最後に “Started Application in …” のログが出力されていることを確認します。
メールを受信するので smtp4dev を起動します。
以下の手順で動作確認します ( 画面キャプチャは省略します )。
- ブラウザを起動して http://localhost:8080/ にアクセスしてログイン画面を表示します。tanaka.taro@sample.com / taro でログインします。
- 検索対象図書館登録画面が表示されます。"東京都" で検索した後、一覧表示されている図書館から「国立国会図書館東京本館」を選択します。
- ログアウトします。
- ログイン画面に戻るので suzuki.hanako@test.co.jp / hanako でログインします。
- 貸出希望書籍 CSV ファイルアップロード画面が表示されます。以下の内容が記述された CSV ファイルをアップロードします。
  “ISBN”,“書名”
  “978-4-7741-6366-6”,“GitHub実践入門”
  “978-4-7741-5377-3”,“JUnit実践入門”
  “978-4-7973-8014-9”,“Java最強リファレンス”
  “978-4-7973-4778-4”,“アジャイルソフトウェア開発の奥義”
  “978-4-87311-704-1”,“Javaによる関数型プログラミング”
- 「貸出状況を確認しました」のメールが送信されるので、メールに記述されている URL にアクセスします。
- 貸出申請画面が表示されます。３冊程「申請する」を選択して申請します。
- ログアウトします。
- 「貸出申請がありました」のメールが送信されるので、メールに記述されている URL にアクセスします。ログイン画面が表示されるので、tanaka.taro@sample.com / taro でログインします。
- 貸出承認画面が表示されます。「承認」あるいは「却下」を選択して確定させます。
- ログアウトします。
- 「貸出申請が承認・却下されました」のメールが送信されるので、メールに記述されている URL にアクセスします。ログイン画面が表示されるので、suzuki.hanako@test.co.jp / hanako でログインします。
- 貸出申請結果確認画面が表示されるので内容を確認します。
動作確認は特に問題ありませんでした。
smtp4dev を終了します。
サービス画面で「ksbysample-webapp-lending」サービスを停止します。

サービスから削除する

サービスを削除します。管理者モードで起動しているコマンドプロンプトから以下のコマンドを実行します。

> nssm.exe remove ksbysample-webapp-lending

「Remove the service?」のダイアログが表示されますので、「はい」ボタンをクリックします。サービスが削除されると「Service “ksbysample-webapp-lending” removed successfully!」のダイアログが表示されますので「OK」ボタンをクリックします。

feature/130-issue -> 1.5.x へ Pull Request、1.5.x へマージ、feature/130-issue ブランチを削除

feature/130-issue -> 1.5.x へ Pull Request、1.5.x へマージ、feature/130-issue ブランチを削除します。

1.5.x -> master へもマージします。

次回は。。。

この後は感想を書いて完了させる予定です。もしかすると番外編を入れるかもしれません。

ソースコード

webapp_startup.bat

@echo on

setlocal
set JAVA_HOME=C:\Java\jdk1.8.0_131
set PATH=%JAVA_HOME%\bin;%PATH%
set WEBAPP_HOME=C:\webapps\ksbysample-webapp-lending
set WEBAPP_JAR=ksbysample-webapp-lending-1.5.4-RELEASE.jar

cd /d %WEBAPP_HOME%
java -server ^
     -Xms1024m -Xmx1024m ^
     -XX:MaxMetaspaceSize=384m ^
     -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled ^
     -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=75 ^
     -XX:+ScavengeBeforeFullGC -XX:+CMSScavengeBeforeRemark ^
     -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps ^
     -Xloggc:%WEBAPP_HOME%/logs/gc.log ^
     -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M ^
     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=%WEBAPP_HOME%/logs/%date:~0,4%%date:~5,2%%date:~8,2%.hprof ^
     -XX:ErrorFile=%WEBAPP_HOME%/logs/hs_err_pid_%p.log ^
     -Dsun.net.inetaddr.ttl=100 ^
     -Dcom.sun.management.jmxremote ^
     -Dcom.sun.management.jmxremote.port=7900 ^
     -Dcom.sun.management.jmxremote.ssl=false ^
     -Dcom.sun.management.jmxremote.authenticate=false ^
     -Dspring.profiles.active=product ^
     -jar lib\%WEBAPP_JAR%

履歴

2017/07/09
初版発行。

2017-07-08

IntelliJ IDEA を 2017.1.4 → 2017.1.5 へ、Git for Windows を 2.13.1(2) → 2.13.2 へバージョンアップ

IntelliJ IDEA を 2017.1.4 → 2017.1.5 へバージョンアップする

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

IntelliJ IDEA 2017.1.5 Release Notes
https://confluence.jetbrains.com/display/IDEADEV/IntelliJ+IDEA+2017.1.5+Release+Notes

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

IntelliJ IDEA のメインメニューから「Help」-「Check for Updates…」を選択します。
「Platform and Plugin Updates」ダイアログが表示されます。左下に「Update and Restart」ボタンが表示されていますので、「Update and Restart」ボタンをクリックします。
Plugin の update も表示されました。「Error-prone Compiler Integration」はバージョンアップすると動かなくなりますので、これだけチェックを外して「Update and Restart」ボタンをクリックします。
Patch がダウンロードされて IntelliJ IDEA が再起動します。
メイン画面が表示されます。IntelliJ IDEA が起動すると画面下部に「Indexing…」のメッセージが表示されますので、終了するまで待機します。
処理が終了すると Gradle Tool Window のツリーの表示が other グループしかない初期の状態に戻っていますので、左上の「Refresh all Gradle projects」ボタンをクリックして更新します。更新が完了すると build グループ等が表示されます。
IntelliJ IDEA のメインメニューから「Help」-「About」を選択し、2017.1.5 へバージョンアップされていることを確認します。
clean タスク実行 → Rebuild Project 実行をした後、build タスクを実行して “BUILD SUCCESSFUL” のメッセージが表示されることを確認します。
Project Tool Window で src/test を選択した後、コンテキストメニューを表示して「Run ‘All Tests’ with Coverage」を選択し、テストが全て成功することを確認します。

Git for Windows を 2.13.1(2) → 2.13.2 へバージョンアップする

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

https://git-for-windows.github.io/ の「Download」ボタンをクリックして Git-2.13.2-64-bit.exe をダウンロードします。
Git-2.13.2-64-bit.exe を実行します。
「Git 2.13.2 Setup」ダイアログが表示されます。[Next >]ボタンをクリックします。
「Select Components」画面が表示されます。「Git LFS(Large File Support)」だけチェックした状態で [Next >]ボタンをクリックします。
「Adjusting your PATH environment」画面が表示されます。中央の「Use Git from the Windows Command Prompt」が選択されていることを確認後、[Next >]ボタンをクリックします。
「Choosing HTTPS transport backend」画面が表示されます。「Use the OpenSSL library」が選択されていることを確認後、[Next >]ボタンをクリックします。
「Configuring the line ending conversions」画面が表示されます。「Checkout Windows-style, commit Unix-style line endings」が選択されていることを確認した後、[Next >]ボタンをクリックします。
「Configuring the terminal emulator to use with Git Bash」画面が表示されます。「Use Windows'default console window」が選択されていることを確認した後、[Next >]ボタンをクリックします。
「Configuring extra options」画面が表示されます。「Enable file system caching」だけがチェックされていることを確認した後、[Install]ボタンをクリックします。
インストールが完了すると「Completing the Git Setup Wizard」のメッセージが表示された画面が表示されます。中央の「View Release Notes」のチェックを外した後、「Finish」ボタンをクリックしてインストーラーを終了します。
コマンドプロンプトを起動して git のバージョンが git version 2.13.2.windows.1 になっていることを確認します。
git-cmd.exe を起動して日本語の表示・入力が問題ないかを確認します。
特に問題はないようですので、2.13.2 で作業を進めたいと思います。

概要

履歴

概要

参照したサイト・書籍

目次

手順

確認の前に -XX:HeapDumpPath, -XX:ErrorFile で指定するファイル名に日時が付くようにする

-XX:+ExitOnOutOfMemoryError と -XX:+CrashOnOutOfMemoryError のオプションが追加されていることを確認する

実際に OutOfMemory が発生する処理を追加して相違点を確認する

OutOfMemory が発生する処理を追加する

どちらのオプションも指定していない場合、どうなるのか？

-XX:+ExitOnOutOfMemoryError オプションを指定するとどうなるか？

-XX:+CrashOnOutOfMemoryError オプションを指定するとどうなるか？

まとめ

webapp_startup.bat を修正する

履歴

概要

参照したサイト・書籍

目次

手順

今回の修正・動作確認のための前準備

今回の動作確認で使用する SampleController クラスを Spring Security による認証の対象外にする

RequestAndResponseLogger の対象となるパッケージを ksbysample.webapp.lending.web → ksbysample.webapp.lending へ変更する

@GetMapping, @PostMapping アノテーションが付加されたメソッドでも request, response のログが出力されるようにする

エラーが発生して @ExceptionHandler アノテーションを付加したメソッドが応答を返す時でも response のログが出力されるようにする

履歴

概要

参照したサイト・書籍

目次

手順

jar ファイルを作成、配置する

サービスに登録する

動作確認

サービスから削除する

feature/130-issue -> 1.5.x へ Pull Request、1.5.x へマージ、feature/130-issue ブランチを削除

次回は。。。

履歴

IntelliJ IDEA を 2017.1.4 → 2017.1.5 へバージョンアップする

Git for Windows を 2.13.1(2) → 2.13.2 へバージョンアップする

`-XX:+ExitOnOutOfMemoryError` オプションを指定するとどうなるか？

`-XX:+CrashOnOutOfMemoryError` オプションを指定するとどうなるか？

RequestAndResponseLogger の対象となるパッケージを `ksbysample.webapp.lending.web` → `ksbysample.webapp.lending` へ変更する