tWAS, Libertyでログ監視とJVMデバッグログ (trapit, Xtrace, Xdump)

# 目的

tWAS, Libertyのログ監視、デバッグログの取得方法をテストします。

# テスト環境の構築

用意したGitレポジトリをクローンします。
```
git clone https://github.com/pdprof/crash-heapdump.git
cd crash-heapdump/pdpro-docker
```

tWAS 9.0 イメージをビルドします。

```
./setup-was90.sh
```

tWAS 9.0 を起動します。

```
./was90-start.sh 
```

tWAS 9.0 を停止します。

```
docker stop was90-pdpro
```

Libertyのイメージをビルドします。

```
./setup-docker.sh
```

Libertyを起動します。

```
./pdpro-start.sh
```

Libertyを停止します。Libertyで続きをする場合は停止の必要無し。

```
docker stop pdpro
```


tWAS, Libertyの試したい方を起動します。
コンテナーのシェルを起動します。trapitはこのシェルで動かします。続きの内容はどちらでもできます。

```
docker exec -it pdpro bash        # Liberty
docker exec -it was90-pdpro bash  # tWAS
```

# trapitでログ検知

ログを監視して、指定したログ出力をもとにプログラムを実行したい場合にtrapitが使えます。

https://www.ibm.com/support/pages/using-trapit-script-watch-events

以下のサイトにアクセスして

http://localhost:9080/hang/

730秒（デフォルト ハング検知10分、モニター間隔2分から）程度を指定して Sleep Servletを呼び出します。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/fe93b785-ec07-e105-03a1-3846e9a7ca57.png)

この結果、WSVR0605Wのハング検知のログが出力されます。

```
[12/23/24 14:02:40:212 UTC] 000000bb SystemOut     O > MySleepServet.doTask()
[12/23/24 14:02:40:212 UTC] 000000bb SystemOut     O D MySleepServet.doTask() request.getParamter("sleeptime")
[12/23/24 14:02:40:213 UTC] 000000bb SystemOut     O D MySleepServet.doTask() looptime is 730000 milliseconds
[12/23/24 14:02:40:218 UTC] 000000bb SystemOut     O > MyLoop.doLoop() - sleep 730000 milliseconds
[12/23/24 14:13:31:355 UTC] 0000008f ThreadMonitor W   WSVR0605W: Thread "WebContainer : 2" (000000bb) has been active for 651156 milliseconds and may be hung.  There is/are 1 thread(s) in total in the server that may be hung.
	at java.lang.Thread.sleepImpl(Native Method)
	at java.lang.Thread.sleep(Thread.java:977)
	at java.lang.Thread.sleep(Thread.java:960)
	at pdpro.hang.MySleep.doSleep(MySleep.java:8)
	at pdpro.hang.MySleepServlet.doTask(MySleepServlet.java:44)
	at pdpro.hang.MySleepServlet.doPost(MySleepServlet.java:35)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1235)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:779)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:478)
	at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1134)
	at com.ibm.ws.webcontainer.webapp.WebApp.handleRequest(WebApp.java:4238)
	at com.ibm.ws.webcontainer.webapp.WebAppImpl.handleRequest(WebAppImpl.java:2210)
	at com.ibm.ws.webcontainer.webapp.WebGroup.handleRequest(WebGroup.java:304)
	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:1033)
	at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1817)
	at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:382)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:465)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:532)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:318)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:289)
	at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
	at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
	at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:175)
	at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
	at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
	at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
	at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
	at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
	at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
	at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1909)
[12/23/24 14:14:50:219 UTC] 000000bb SystemOut     O < MyLoop.doLoop()
[12/23/24 14:14:50:221 UTC] 000000bb SystemOut     O < MySleepServet.doTask()
[12/23/24 14:14:50:224 UTC] 000000bb ThreadMonitor W   WSVR0606W: Thread "WebContainer : 2" (000000bb) was previously reported to be hung but has completed.  It was active for approximately 730029 milliseconds.  There is/are 0 thread(s) in total in the server that still may be hung.
```

コンテナーのシェル中で、このログをもとに kill -3 で javacoreを出力させるように指定します。

```
cd /pdprof
export WAS_PID=`cat /logs/server1/server1.pid`
./trapit -e WSVR0605W -f /logs/server1/SystemOut.log -t "echo $WAS_PID; kill -3 $WAS_PID"
```

出力結果は以下になります。(make コマンドを使える必要があるので確認しておきましょう。なくてもエラーにはならず検知してくれなかったのでちょっとはまりました。）

```console
[root@46b56e16f406 pdprof]# ./trapit -e WSVR0605W -f /logs/server1/SystemOut.log -t "echo $WAS_PID; kill -3 $WAS_PID"
trapit: Match found in /logs/server1/SystemOut.log
194
```

```native_stderr.log(tWAS) docker logs(Liberty)
JVMDUMP032I JVM requested Java dump using '/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/javacore.20241223.150944.194.0002.txt' in response to an event
JVMDUMP010I Java dump written to /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/javacore.20241223.150944.194.0002.txt
JVMDUMP013I Processed dump event "user", detail "".
```

SystemOut.log に出力があるとすぐに検知してしまうので、新たなログを検知させる場合にはサーバーを停止、ログを削除、サーバーを起動するなどして実行します。

WSVR0605W は Liberty では出力されませんが、TRAS0112W, TRAS0114W などが使えます。

https://www.ibm.com/docs/en/was-liberty/base?topic=liberty-slow-hung-request-detection

コマンド
```
/pdprof/trapit -e TRAS0112W -f /logs/messages.log -i 2 -t /pdprof/mustgather.sh
```

出力例
```console
bash-4.4$ /pdprof/trapit -e TRAS0112W -f /logs/messages.log -i 2 -t /pdprof/mustgather.sh
trapit: Match found in /logs/messages.log
/pdprof/linperf.sh: line 362: hostname: command not found
2024-12-24 00:16:11 \tTemporary directory /pdprof/share/linperf_RESULTS.20241224.001611 created on .
2024-12-24 00:16:11 \tlinperf version: 2024.12.10.
2024-12-24 00:16:11 \tProvided PID: 1
2024-12-24 00:16:11 \tSCRIPT_SPAN = 240
2024-12-24 00:16:11 \tJAVACORE_INTERVAL = 30
2024-12-24 00:16:11 \tTOP_INTERVAL = 60
2024-12-24 00:16:11 \tTOP_DASH_H_INTERVAL = 5
...
```

tWAS, Libertyともにハングのログであれば、ログイベントでjavacoreを出力させるなどの設定が追加されていますが、他のログの場合にもつかえるところが良いです。




# XtraceでSystem.gcの呼び出し元をみつける

System.gc()などメソッドが実行されたタイミングで呼び出しもとのメソッドを確認するのにスタックトレースやjavacoreを出力させることができます。

System.gc()の呼び出し元を特定したい前提で設定をします。引数を決めるのは以下のサイトが便利です。

[Xtrace Option Builder](https://eclipse.dev/openj9/tools/xtrace_option_builder.html?tracepoint_component_0=tp_dest_select_0%3Dmaximal%26tp_comp_select_0%3Dmt%26tp_level_select_0%3D9%26tp_type_0%3D1%26tp_type_select_0%3Dall%26tp_group_select_0%3Dall&method_0=meth_text_0%3Dcom%252Fmycompany%252Finternals%252F*%26meth_args_0%3D1&trigger_method_0=trig_meth_spec_0%3Dcom%252Fmycompany%252Finternals%252FImportantClass.veryImportantMethod%26trig_meth_ent_0%3Dresumethis%26trig_meth_ex_0%3Dsuspendthis&trigger_method_1=trig_meth_spec_1%3Dcom%252Fmycompany%252Finternals%252FImportantClass.veryImportantMethod%26trig_meth_ent_1%3Djstacktrace%26trig_meth_ex_1%3Dnone&buffer_size_units=k&disable_predefined=1&trace_initially_disabled=1&sleep_time=30000&buffer_size=8&dynamic_buffers=1&file_text=importantMethod_%25p.trc&output_size=100&output_generations=1&wrap_in_quotes=0)

System.gc()のスタック(jstacktrace)をとるのには最初からトレースが有効（ Trace initially stoppedのチェックを外す、もしくは呼び出し時にトレースを有効にする）である必要があります。

設定は

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/182034c1-30d9-d045-2b76-73d890198ea1.png)

Copy option したもの
```
-Xtrace:print=mt,methods=java/lang/System.gc(),trigger=method{java/lang/System.gc,jstacktrace}
```

[Copy Link](https://eclipse.dev/openj9/tools/xtrace_option_builder.html?tracepoint_component_0=tp_dest_select_0%3Dprint%26tp_comp_select_0%3Dmt%26tp_level_select_0%3D9%26tp_type_0%3D1%26tp_type_select_0%3Dall%26tp_group_select_0%3Dall%26tp_trace_0%3D1%26tp_count_0%3D0&method_0=meth_text_0%3Djava%252Flang%252FSystem.gc%26meth_args_0%3D1&trigger_method_0=trig_meth_spec_0%3Djava%252Flang%252FSystem.gc%26trig_meth_ent_0%3Djstacktrace%26trig_meth_ex_0%3Dnone&buffer_size_units=k&disable_predefined=0&trace_initially_disabled=0&sleep_time=30000&buffer_size=8&dynamic_buffers=1&output_size=100&output_generations=1&wrap_in_quotes=0) したものです。

これをtWASであれば汎用JVM引数、Libertyであればjvm.optionsに指定します。

現象を再現させる場合には

http://localhost:9080/hang/

にアクセスして Call GC Servlet を Submit します。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/69c44520-bd2e-8dcd-fdcd-96bff9b1a9c3.png)

native_stderr.log に以下のようなログが出力されていれば設定成功です。

```native_stderr.log(tWAS) docker logs(Liberty)
13:46:47.618*0x1b0cd00              mt.3        > java/lang/System.gc()V bytecode static method
13:46:47.618 0x1b0cd00       j9trc_aux.0        - jstacktrace:
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [1] java.lang.System.gc (System.java:382)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [2] pdpro.hang.MyGCServlet.doTask (MyGCServlet.java:43)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [3] pdpro.hang.MyGCServlet.doGet (MyGCServlet.java:30)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [4] javax.servlet.http.HttpServlet.service (HttpServlet.java:687)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [5] javax.servlet.http.HttpServlet.service (HttpServlet.java:790)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [6] com.ibm.ws.webcontainer.servlet.ServletWrapper.service (ServletWrapper.java:1235)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [7] com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest (ServletWrapper.java:779)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [8] com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest (ServletWrapper.java:478)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [9] com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest (ServletWrapperImpl.java:179)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [10] com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters (WebAppFilterManager.java:1134)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [11] com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest (CacheServletWrapper.java:82)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [12] com.ibm.ws.webcontainer.WebContainer.handleRequest (WebContainer.java:966)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [13] com.ibm.ws.webcontainer.WSWebContainer.handleRequest (WSWebContainer.java:1817)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [14] com.ibm.ws.webcontainer.channel.WCChannelLink.ready (WCChannelLink.java:382)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [15] com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination (HttpInboundLink.java:465)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [16] com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest (HttpInboundLink.java:532)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [17] com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest (HttpInboundLink.java:318)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [18] com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready (HttpInboundLink.java:289)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [19] com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators (NewConnectionInitialReadCallback.java:214)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [20] com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete (NewConnectionInitialReadCallback.java:113)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [21] com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted (AioReadCompletionListener.java:175)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [22] com.ibm.io.async.AbstractAsyncFuture.invokeCallback (AbstractAsyncFuture.java:217)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [23] com.ibm.io.async.AsyncChannelFuture$1.run (AsyncChannelFuture.java:205)
13:46:47.618 0x1b0cd00       j9trc_aux.1        - [24] com.ibm.ws.util.ThreadPool$Worker.run (ThreadPool.java:1909)
13:46:47.810 0x1b0cd00              mt.9        < java/lang/System.gc()V bytecode static method
```

用意したアプリケーションはGCを呼び出しているメソッドやクラスが分かっていますが、呼び出し元が不明な場合に使えます。注意する点としては、mt で jstacktrace の trigger にしたいメソッドがトレースされている必要があります。


# XdumpでException throw時の資料収集

Exception が throw されたタイミングでjavacoreなどのログを出力させる設定ができます。
以下のNumberFommatExceptionを元に設定をします。

```
java.lang.NumberFormatException: For input string: "NumberFormatException"
	at java.lang.NumberFormatException.forInputString(NumberFormatException.java:76)
	at java.lang.Integer.parseInt(Integer.java:592)
	at java.lang.Integer.parseInt(Integer.java:627)
	at pdpro.exception.MyExceptionServlet.callException(MyExceptionServlet.java:79)
	at pdpro.exception.MyExceptionServlet.doTask(MyExceptionServlet.java:48)
	at pdpro.exception.MyExceptionServlet.doPost(MyExceptionServlet.java:36)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1235)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:779)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:478)
	at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:179)
	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1134)
	at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:82)
	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:966)
	at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1817)
	at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:382)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:465)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewRequest(HttpInboundLink.java:532)
	at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.processRequest(HttpInboundLink.java:318)
	at com.ibm.ws.http.channel.inbound.impl.HttpICLReadCallback.complete(HttpICLReadCallback.java:88)
	at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:175)
	at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
	at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
	at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
	at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:204)
	at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:775)
	at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:905)
	at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1909)
```


設定する引数を決めるのは以下のサイトが便利です。

[Xdump Option Builder](https://eclipse.dev/openj9/tools/xdump_option_builder.html)

条件に 
- 例外は java.lang.NumberFormatException
- 呼び出し元のメソッドの6番目は pdpro.exception.MyExceptionServlet.doPost
- 例外発生時に stderr に実行スレッドのスタックを出力

を指定します。注意するのは6番目の指定が 0から数えるので5になっているところ位ですjava.lang.NumberFormatException.forInputString が0として数えます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/886ad842-799a-ba1d-2e86-5b9b084eff0d.png)

Copy option したもの
```
-Xdump:stack:events=throw+systhrow,filter=java/lang/NumberFormatException#pdpro/exception/MyExceptionServlet.doPost#5
```

[Copy link](https://eclipse.dev/openj9/tools/xdump_option_builder.html?event_vmstop_filter=&event_slow_filter=50&event_allocation_filter_size_min=256&event_allocation_filter_size_max=512&event_throw=1&event_systhrow=1&event_throwable_class=java%2Flang%2FNumberFormatException&event_throwable_method=pdpro%2Fexception%2FMyExceptionServlet.doPost&event_throwable_offset=5&agent_stack=1&tool_wait=0&request_exclusive=0&request_compact=0&request_prepwalk=0&request_serial=0&request_preempt=0&range_first=1&range_last=0&priority=&wrap_in_quotes=1) したものです。

これをtWASであれば汎用JVM引数、Libertyであればjvm.optionsに指定します。

現象を再現させる場合には

http://localhost:9080/exception/index.html

にアクセスして NumberFormatExceptionを選択して submit します。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/6d253348-ceb5-b099-3a03-133941f5d92e.png)

native_stderr.log に以下のようなログが出力されていれば設定成功です。
```native_stderr.log(tWAS) docker logs(Liberty)
JVMDUMP055I Processing dump event "throw", detail "java/lang/NumberFormatException", exception "For input string: "NumberFormatException"" at 2024/12/23 00:44:38 - please wait.
Thread=WebContainer : 1 (00007FCE1802B300) Status=Running
	at java/lang/Integer.parseInt(Ljava/lang/String;I)I (Integer.java:592) (Compiled Code)
	at java/lang/Integer.parseInt(Ljava/lang/String;)I (Integer.java:627) (Compiled Code)
	at pdpro/exception/MyExceptionServlet.callException(Ljava/lang/String;)Ljava/lang/Exception; (MyExceptionServlet.java:79)
	at pdpro/exception/MyExceptionServlet.doTask(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V (MyExceptionServlet.java:48)
	at pdpro/exception/MyExceptionServlet.doPost(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V (MyExceptionServlet.java:36)
	at javax/servlet/http/HttpServlet.service(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V (HttpServlet.java:707)
	at javax/servlet/http/HttpServlet.service(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (HttpServlet.java:790)
/ServletRequest;Ljavax/servlet/ServletResponse;Lcom/ibm/ws/webcontainer/webapp/WebAppServletInvocationEvent;)V (ServletWrapper.java:1235)
	at com/ibm/ws/webcontainer/servlet/ServletWrapper.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;Lcom/ibm/ws/webcontainer/webapp/WebAppDispatcherContext;)V (ServletWrapper.java:779)
	at com/ibm/ws/webcontainer/servlet/ServletWrapper.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (ServletWrapper.java:478)
	at com/ibm/ws/webcontainer/servlet/ServletWrapperImpl.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (ServletWrapperImpl.java:179)
	at com/ibm/ws/webcontainer/filter/WebAppFilterManager.invokeFilters(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;Lcom/ibm/wsspi/webcontainer/servlet/IServletContext;Lcom/ibm/wsspi/webcontainer/RequestProcessor;Ljava/util/EnumSet;)Z (WebAppFilterManager.java:1134)
	at com/ibm/ws/webcontainer/webapp/WebApp.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (WebApp.java:4238)
	at com/ibm/ws/webcontainer/webapp/WebAppImpl.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (WebAppImpl.java:2210)
	at com/ibm/ws/webcontainer/webapp/WebGroup.handleRequest(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V (WebGroup.java:304)
ontainer.java:1033)ws/webcontainer/WebContainer.handleRequest(Lcom/ibm/websphere/servlet/request/IRequest;Lcom/ibm/websphere/servlet/response/IResponse;)V (WebC--More--(89%)
	at com/ibm/ws/webcontainer/WSWebContainer.handleRequest(Lcom/ibm/websphere/servlet/request/IRequest;Lcom/ibm/websphere/servlet/response/IResponse;)V (WSWebContainer.java:1817)
	at com/ibm/ws/webcontainer/channel/WCChannelLink.ready(Lcom/ibm/wsspi/channel/framework/VirtualConnection;)V (WCChannelLink.java:382)
	at com/ibm/ws/http/channel/inbound/impl/HttpInboundLink.handleDiscrimination()V (HttpInboundLink.java:465)
	at com/ibm/ws/http/channel/inbound/impl/HttpInboundLink.handleNewRequest()V (HttpInboundLink.java:532)
	at com/ibm/ws/http/channel/inbound/impl/HttpInboundLink.processRequest()V (HttpInboundLink.java:318)
	at com/ibm/ws/http/channel/inbound/impl/HttpICLReadCallback.complete(Lcom/ibm/wsspi/channel/framework/VirtualConnection;Lcom/ibm/wsspi/tcp/channel/TCPReadRequestContext;)V (HttpICLReadCallback.java:88)
	at com/ibm/ws/tcp/channel/impl/AioReadCompletionListener.futureCompleted(Lcom/ibm/io/async/IAbstractAsyncFuture;Ljava/lang/Object;)V (AioReadCompletionListener.java:175)
	at com/ibm/io/async/AbstractAsyncFuture.invokeCallback(Lcom/ibm/io/async/ICompletionListener;Lcom/ibm/io/async/AbstractAsyncFuture;Ljava/lang/Object;)V (AbstractAsyncFuture.java:217)
	at com/ibm/io/async/AsyncChannelFuture.fireCompletionActions()V (AsyncChannelFuture.java:161)
        at com/ibm/io/async/AsyncFuture.completed(J)V (AsyncFuture.java:138)
	at com/ibm/io/async/ResultHandler.complete(Lcom/ibm/io/async/AsyncFuture;II)V (ResultHandler.java:204)
	at com/ibm/io/async/ResultHandler.runEventProcessingLoop(Z)V (ResultHandler.java:775)
	at com/ibm/io/async/ResultHandler$2.run()V (ResultHandler.java:905)
	at com/ibm/ws/util/ThreadPool$Worker.run()V (ThreadPool.java:1909)
JVMDUMP013I Processed dump event "throw", detail "java/lang/NumberFormatException".
```

用意したアプリケーションは例外の出力元がわかるようにログ出力してますが、例外メッセージのみ出力されている場合や、呼び出し元を限定して別のログ（coreなど）を出力するのに使えます。引数にあるpdpro/exception/MyExceptionServlet.doPost#5 の 5 を 4や6に変えるだけで条件に一致しなくなるので出力されなくなります。jstacktraceのスタックをみると呼び出しのメソッドが変わっていますが、もとのログをもとに設定するので問題ありません。


Method の offset 参考
```
java.lang.NumberFormatException: For input string: "NumberFormatException"
#0	at java.lang.NumberFormatException.forInputString(NumberFormatException.java:76)
#1	at java.lang.Integer.parseInt(Integer.java:592)
#2	at java.lang.Integer.parseInt(Integer.java:627)
#3	at pdpro.exception.MyExceptionServlet.callException(MyExceptionServlet.java:79)
#4	at pdpro.exception.MyExceptionServlet.doTask(MyExceptionServlet.java:48)
#5	at pdpro.exception.MyExceptionServlet.doPost(MyExceptionServlet.java:36)
#6	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
#7	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
```

Xdumpについては以下の記事も参考になります。

https://qiita.com/kazumaxamuzak/items/41fed44cf8c8340acbc5


# おまけ Linux上のCrashやNativeOOMがテストできます

使用しているアプリケーションはPD職人のころからのものを使いました。Linux用のNative Library (libpdpro.native.so) をDockerイメージのビルド時に tWASでは /usr/lib64/ に Libertyでは /config/libs/ に コピーしています。

https://qiita.com/rinaxsumomo/items/d871534208e4fe5975bd

で試していただいてたもので、Linux用のライブラリが作成できていたので紹介になります。コンテナー環境だとcoreファイル出力に調整が必要だったりするのですが、その事は別の記事で書きます。

Crashの呼び出しは以下のページでsubmitです。

http://localhost:9080/crash/index.html

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/262366/1588ee92-af47-12a8-7580-3f68e9739c2e.png)

ログ出力の参考
```native_stderr.log(tWAS) docker logs(Liberty)
Unhandled exception
Type=Segmentation error vmState=0x00040000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
Handler1=00007F8FD5454BF0 Handler2=00007F8FD4CFACD0 InaccessibleAddress=FFFFFFFFFFFFFFFD
RDI=00000000FFFFFFFD RSI=00007F8FB8781880 RAX=FFFFFFFFFFFFFFFD RBX=0000000000000010
RCX=0000000000001000 RDX=00007F8FD6EF1860 R8=0000000000001A71 R9=0000000000094000
R10=0000000000000003 R11=00007F8FB87817C8 R12=0000000000000001 R13=0000000000000008
R14=00007F8FB89C0480 R15=00007F8FD551FAD4
RIP=00007F8FB87817DC GS=0000 FS=0000 RSP=00007F8FB89C0280
EFlags=0000000000010206 CS=0033 RBP=00007F8FB89C0280 ERR=0000000000000007
TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=FFFFFFFFFFFFFFFD
xmm0 705f6176614a203e (f: 1632247808.000000, d: 1.948765e+233)
xmm1 736172635f6f7270 (f: 1601139328.000000, d: 6.099341e+247)
xmm2 dddddd00494e4a76 (f: 1229867648.000000, d: -1.456651e+144)
xmm3 00000000004e4a76 (f: 5130870.000000, d: 2.534987e-317)
xmm4 dddddddddddd0049 (f: 3722248192.000000, d: -1.456816e+144)
xmm5 4e203a656c696620 (f: 1818846720.000000, d: 2.187545e+68)
xmm6 6572616873206e65 (f: 1931505280.000000, d: 4.766886e+180)
xmm7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm8 6f707075736e7500 (f: 1936618752.000000, d: 6.231030e+228)
xmm9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm10 5c732f392f2f3d30 (f: 791625024.000000, d: 2.231042e+137)
xmm11 00000000407feb52 (f: 1082125184.000000, d: 5.346409e-315)
xmm12 3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
xmm13 40a8200000000000 (f: 0.000000, d: 3.088000e+03)
xmm14 3fefae147ae147ae (f: 2061584256.000000, d: 9.900000e-01)
xmm15 412d579fda5c8a47 (f: 3663497728.000000, d: 9.614879e+05)
Module=/usr/lib64/libpdpro.native.so
Module_base_address=00007F8FB8781000 Symbol=gensegv
Symbol_address=00007F8FB87817C8
Target=2_90_20230908_57744 (Linux 5.14.0-352.el9.x86_64)
CPU=amd64 (8 logical CPUs) (0x7bd8be000 RAM)
----------- Stack Backtrace -----------
gensegv+0x14 (0x00007F8FB87817DC [libpdpro.native.so+0x7dc])
Java_pdpro_crash_MySigSegv_doSigSegvJNI+0x26 (0x00007F8FB8781807 [libpdpro.native.so+0x807])
ffi_call_unix64+0x52 (0x00007F8FD54FC8DA [libj9vm29.so+0x1778da])
ffi_call_int+0x1fc (0x00007F8FD54F8D6C [libj9vm29.so+0x173d6c])
_ZN37VM_DebugBytecodeInterpreterCompressed3runEP10J9VMThread+0x1b264 (0x00007F8FD53D2A44 [libj9vm29.so+0x4da44])
debugBytecodeLoopCompressed+0xd4 (0x00007F8FD53B77D4 [libj9vm29.so+0x327d4])
 (0x00007F8FD548F4F2 [libj9vm29.so+0x10a4f2])
---------------------------------------
JVMDUMP039I Processing dump event "gpf", detail "" at 2024/12/23 16:34:54 - please wait.
```

実行するとコンテナーが異常停止します。


# まとめ

tWAS, Libertyの環境を構築してログ監視やJavaのデバッグオプションのテストをしました。