Go to Qiita Advent Calendar 2024 Top
LoginSignup
27
26

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 3 years have passed since last update.

闇の魔術に対する防衛術Advent Calendar 2020Day 20
@nfujita55a

よく知らないアプリケーションの性能と戦わないといけないときの防衛術（中編）

Last updated at Posted at 2020-12-19

よく知らないアプリケーションの性能と戦う、という状況(再掲)

私が設計したわけでもなく開発したわけでもなく、レビュー参加とかで辛うじて全体はわけるけど、いまからソース見る時間もないし、開発した方は性能面の対処が覚束ない。突然性能面で火を噴いてなぜか自分が召喚されて2~3時間でどうにかしたい、という闇な状況にどういうふうに対応していたっけ自分、というのを経験則100%で書いてみようと思います。

前編は道具の紹介(OS編)でした。
よく知らないアプリケーションの性能と戦わないといけないときの防衛術（前編）
https://qiita.com/nfujita55a/items/3760cd099ca890f5a4d4

この中編は道具の紹介(Java)、後編は道具の紹介(PostgreSQL)です。前編で特定した これがヤバそうというプロセスがJavaと特定できた後にどうしていたか を書いてみました。

※具体的なケースを書くと色々やばい＋今日、道具の紹介(PostgreSQL)まで書けなかったので構成を変更しました。

……変なところもあると思うので、ご指摘お待ちしております。

想定する環境(再掲)

仕事柄、想定する環境はすごくレガシーです。クラウド(AWS EC2)でもオンプレでもいいのですが

[Webサーバー Linux Apache]
｜
[APサーバー Linux Java+Tomcat+WEBアプリケーション、Java+バッチプログラム]
｜
[DBサーバー Linux PostgrteSQL]

という構成を想定しています。

1.Javaのプロセスを調べる

スレッドダンプ

Javaのアプリで性能面の問題が発生しているとき、まずはこれを取得します。 Javaプロセスに対しすべてのスレッドの状態とスタックトレースが出力されるので、取得した瞬間の各スレッドがどういう呼び出され方をして何を実行しているかが出力されます。

このような出力がプロセスの中の全スレッド分、得られます。これは HogeWorker というスレッドの出力例です。「State: RUNNABLE」と書いてあるのがスレッドの状態です。

"HogeWorer" daemon prio=10 tid=0x00007f5c2706d900 nid=0xdfb runnable [0x00007f5c3d760000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71)
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
    - locked <0x0000000529000980> (a org.postgresql.core.v3.QueryExecutorImpl)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:304)
    at com.example.a.b.c.DddEee.foo(DddEee.java:234)
    at com.example.a.b.c.DddEee.bar(DddEee.java:345)
    (略 com.example 以下がずらずら20行並んでいる)
    at com.example.h.i.j.KkkLll.foo(KkkLll.java:123)
    at com.example.h.i.j.KkkLll.baz(KkkLll.java:12)
    at java.lang.Thread.run(Thread.java:745)

取得方法

あっ、いま負荷かかっているな or 処理が遅いぃぃ、というそのときに躊躇せず取得します(大事)。 15秒とか間隔を空けて複数回(3~5回)取得します。複数回とるのは、いずれのときも同じ傾向の問題を示しているかを確認するためです。

もし、下記の方法でスレッドダンプが取得できない(記録されないとかコマンドが返ってこない)ときは、もうJavaプロセス自体がOutOfMemoryError間近などでどうにもならないときが多いです。そういうときはJavaプロセスをいったん止めてからリカバリした方がいいと思います。(止めるにも # kill -KILL プロセスID でしか止まらないことが多い)

1. kill -3 プロセスID する

Javaプロセスの標準主力のリダイレクト先ファイルがあって分かっている場合（典型例：Tomcatのcatalina.out）、これが安易です。ただし -3 を間違えないように。これを忘れたり -HUP とか -TERM とか -KILL すると、Javaプロセスが止まってしまいます。

# ps auxww | grep java
で特定したJavaプロセスのPIDに対し
# kill -3 プロセスID

として取得します。プロセスのユーザーが誰でも root ユーザーで実行すれば、Javaプロセスの標準主力のリダイレクト先ファイルにスレッドダンプがドバッと追記されます。

2. jstack コマンド

このバッチの標準出力がどこか分からぬ、とか、kill コマンドはちょっと……と感じる人もいると思うので、そういうときは jstack コマンドでも取得できます。（こちらが正当な気がする）

# ps auxww | grep java
で特定したJavaプロセスのPIDとJavaのパス、そのプロセスの実行ユーザーを見て
# su - そのプロセスの実行ユーザー
でスイッチして
$ /path/to/java_home/bin/jps
を実行し、psコマンドで見ていたPIDが表示されるか確認し
(Tomcatだと 12345 BootStrap とか出てくるので、12345 は見たいプロセスだよね、と確認)
$ /path/to/java_home/bin/jstack プロセスID

でコマンドの実行結果にスタックトレースがドバッと出力されます。

もし、Java の実行ユーザーが nobody とかスイッチできない場合（nobodyで動かす方が、rootやシェル持ちユーザーで実行するよりセキュリティー上いい）

# ps auxww | grep java
で特定したJavaプロセスのPIDとJavaのパス、そのプロセスの実行ユーザーを見て
# su - -m そのプロセスの実行ユーザー -c '/path/to/java_home/bin/jps'
を実行し、psコマンドで見ていたPIDが表示されるか確認し
# su - -m そのプロセスの実行ユーザー -c '/path/to/java_home/bin/jstack プロセスID'

としてコマンドの実行結果にスタックトレースがドバッと出力させる方法もあります。
ターミナルがスタックトレースで埋まるので、「>」「>>」などリダイレクトしてファイルに書いた方がいいかもです。

3. (番外編)Windowsでサービスとして稼働するTomcat

Windowsサービスで稼働するTomcatは

  • Linuxのkill -3にあたるCtrl+Break
  • 単にjstackコマンドを実行する

いずれでもスレッドダンプは取得できませんので、システムトレイにある Tomcat アイコンから Thread Dump を押すと簡単に取得できます。

apache2.png

そうしたら Tomcatインストール先\logs\tomcatX-stdout今日の日付.log に出力されます。

見方

（対象のシステムがよく知らないけど調べる必要がある場合は特にですが）スレッドダンプを見るときは、

  • (念のため)JVMのメモリに余裕はあるか
  • 対象のスレッドの調査

の2段階で見ます。

1. (念のため)JVMのメモリに余裕はあるか

取得したスレッドダンプの最後には、このようなJavaのヒープメモリに関する出力があります。

Heap
 PSYoungGen      total 94208K, used 25568K [0x000000094aa90000, 0x000000094da80000, 0x0000000800000000)
  eden space 90112K, 30% used [0x000000094aa90000,0x000000094b800310,0x000000094d680000)
  from space 4096K, 46% used [0x000000094d880000,0x000000094d970000,0x000000094da80000)
  to   space 4096K, 0% used [0x000000094d680000,0x000000094d680000,0x000000094d880000)
 ParOldGen       total 732160K, used 587892K [0x0000000680000000, 0x0000000696580000, 0x000000094aa90000)
  object space 732160K, 80% used [0x0000000680000000,0x0000000691f0ea58,0x0000000696580000)
 Metaspace       used 2425K, capacity 4498K, committed 4864K, reserved 1056768K
  class space    used 262K, capacity 386K, committed 512K, reserved 1048576K

典型的なWEBアプリケーションやバッチ処理の場合、Javaの OutOfMemoryError（メモリ足りない）は、Old領域の不足です。「Javaプロセスの-Xmx指定によるヒープメモリの最大割り当て × -XX:NewRatio ÷ (-XX:NewRatio + 1)」がOld領域の最大値です。
（例：-Xmxが4Gで、-XX:NewRatio がServerVMのデフォルトの2なら、4GB×2÷3=2.66GB）

このOld領域の最大値に ParOldGen > used (上だと used 587892K)が近づいていないかを確認します。もし近くなっていて、vmstatでCPUが忙しく動いていたら、このJavaは OutOfMemoryError 間近で、GC処理回して本来の処理に能力を割けていないと判断します。このようなときは、一度Javaプロセス止めて（場合によってはOSにメモリを追加し）Javaヒープの最大値 Xmx を上げて再実行した方がいいのだと思います。中途半端な処理状況のハンドリングが厄介ですが、ただ好転しないか待っていても時間を浪費するだけです。

メモリヒープに問題なさそうならスレッドの調査へすすみます

2. 対象のスレッドの調査

TomcatなどWEBアプリケーションの場合(Spring BootでもTomcatを内包しているのでこのカテゴリ)、多数のスレッドが出力されます。まずは、

  1. スレッドの状態が WAITING や TIMED_WAITING のものは
  2. スレッドの状態が RUNNABLE だけど実は Tomcat のWorkerの待機

は無視していいです。こういうものが無視する典型です。

"http-bio-8080-exec-19" daemon prio=10 tid=0x00008d13e0003800 nid=0x4894 waiting on condition [0x00008d13fc2b7000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000009217dee78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
	at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)

"ajp-bio-8009-exec-123" daemon prio=10 tid=0x00008d13ec06d000 nid=0x3dfc runnable [0x00008d13d5ad5000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:152)
	at java.net.SocketInputStream.read(SocketInputStream.java:122)
	at org.apache.coyote.ajp.AjpProcessor.read(AjpProcessor.java:312)
	at org.apache.coyote.ajp.AjpProcessor.readMessage(AjpProcessor.java:367)
	at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:118)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:620)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
	- locked <0x000000092f13a8c0> (a org.apache.tomcat.util.net.SocketWrapper)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:745)

調査するため目を付けるのは

  • プロジェクト特有のパッケージ名(自社や納品先の会社名とか)をスタックトレースに含み (言い換えると一般的なフレームワークやライブラリだけで構成されたものは対象から外す。例外、Javaプロセス内にインメモリDB(Hsql)とか重たいミドルを内包している場合)
  • スタックトレースが他のものと比べて長く
  • ステータスが RUNNABLE や BLOCKED のもの

です(慣れればすぐわかるようになる……と思う)。一度前にあげたスタックトレースである下記の例は、3つの条件を満たすので要調査対象です（com.example をプロジェクト特有のパッケージ名として例示しています）。

"HogeWorer" daemon prio=10 tid=0x00007f5c2706d900 nid=0xdfb runnable [0x00007f5c3d760000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71)
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
    - locked <0x0000000529000980> (a org.postgresql.core.v3.QueryExecutorImpl)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:304)
    at com.example.a.b.c.DddEee.foo(DddEee.java:234)
    at com.example.a.b.c.DddEee.bar(DddEee.java:345)
    (略 com.example 以下がずらずら20行並んでいる)
    at com.example.h.i.j.KkkLll.foo(KkkLll.java:123)
    at com.example.h.i.j.KkkLll.baz(KkkLll.java:12)
    at java.lang.Thread.run(Thread.java:745)

よく知らないシステムなので、プロジェクト特有の com.example の中身を見ても仕方ないです。 それより、上から順にたどったときプロジェクト特有の com.example を探して最初に出てきたところ（上の例だと fffGgg.java:234 ）から上の処理を見ます。

スタックトレース上は (※JNIでも使ってない限り)

  • javaやjavaxパッケージ → 一般的なライブラリ → プロジェクト特有のパッケージの最初の行
  • javaやjavaxパッケージ → プロジェクト特有のパッケージの最初の行

といった順に並ぶので、「javaやjavaxパッケージ・一般的なライブラリ」から処理内容を推測します。上の例はとても分かりやすく、

  • (fffGgg.java:234)の上は jdbc と postgresql があるので PostgreSQLのJDBCライブラリで
  • クエリを実行して(executeQuery)、実行していて(execute)(※DBとはコネクションが確立している)
  • バッファ(BufferedInputStream)に、読み込みしようとしてて(read)
  • ソケットから読み込もうとしている(SocketInputStream.read)

つまりDBにselect ...なSQLを投げて返りを待っているのか、と処理内容を特定します。もし、このようなスレッドたちでスレッドダンプが埋まっていたらDBMSに調査対象が移ります。（JavaプロセスはDBを待っている立場と判断する）

また、上のスタックトレースよく見ると、コネクションプーリングのライブラリが出てきません(Commns-DBCPとかTomcatのDBCPとか)。AP⇔DB間のTCPがどうなっているかも見るところです（DBMSが新規のTCP確立でアップアップかもしれない）

「JavaがDBの返りを待っている」は、WEBアプリケーションの性能対応時に出くわす典型例ですが、あと2つ注意する例を書きます

補足ケース1)排他でつっかえているとき

下記のようにプロジェクト特有のパッケージ名をスタックトレースに含み、その スレッドのステータスが BLOCKED で、しかもそのようなスレッドが多数あれば排他で詰まっています。

"ajp-bio-8009-exec-124" daemon prio=10 tid=0x00008d13ec06d000 nid=0x3dfc runnable [0x00009d13d5ad5000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.example.zzz.YyyXxx.foo(YyyXxx.java:345)
	- waiting to lock <0x0000000123456789> (a java.lang.Object)
        at com.example.zzz.YyyXxx.bar(YyyXxx.java:567)
        （以下ずらずら）
    at java.lang.Thread.run(Thread.java:745)

このような場合、「waiting to lock <0x0000000123456789>」の 0x0000000123456789 をスレッドダンプ内で探すと、(デッドロックを除き)どこかに locked <0x0000000123456789> となっているスレッドがあるので、そのスレッドを調べます。スレッドのステータスが RUNNABLE なら、その処理を調査します。（これが渋滞の先頭）。そのスレッドのステータスも BLOCKED だと連鎖的に排他待ちしているので、同じように調べていけば、どこかで渋滞の先頭な RUNNABLE のスレッドに辿り着きます。
その先頭のスレッドが性能稼げない要因を何とかするか、排他をしないようプログラムを改修するか、どちらかです。

補足ケース2)正規表現

これは見た瞬間に食欲が減るやばいパターンなのですが、下記のようにスレッドのステータスが RUNNABLE で、スタックトレースの先頭は regexのときは、正規表現で性能の問題がおきています。正規表現はパターンとマッチする文字列の組み合わせで1回のマッチにとんでもない時間がかかるときがあります。なんでもなさそうな正規表現(20文字くらい)に特定の文字列(80文字)を入れたら、match で3時間かかったことも見たことがあります。特に、WEBのリクエストを正規表現に入れるときは注意しましょう。ReDosに近い状況ですね。

あわせて、他にCPUを食いそうな処理がスタックトレースに見当たらず、そのスタックトレースを取得したAPサーバーのvmstatでusが高負荷なら、問題の原因としては確実です。もうこればっかりは、プログラムを改修しないといけない域です。（WAFとかでひどいことになるリクエストを切ってしまう考えもあるけど）

"ajp-bio-8009-exec-123" daemon prio=10 tid=0x00008d13ec06d000 nid=0x3dfc runnable [0x00008d13d5ad5000]
   java.lang.Thread.State: RUNNABLE
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
    at java.util.regex.Pattern$Curly.match1(Pattern.java:4287)
    at java.util.regex.Pattern$Curly.match(Pattern.java:4236)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
    (略)
    at com.example.zzz.YyyXxx.foo(YyyXxx.java:345)
    (略)

2.Tomcatのアクセスログ

(みんなだいすき)Tomcatで動いているよく知らないシステムについて簡単にできて性能の問題に対応するとき効果がある設定を2つ書きます。夜中に起こされて、これ設定するの辛いから、みんな書いておいてね。（宛先の分からない発言）

アクセスログに項目を追加する

TomcatのAccessLogの設定は既定でこんなふうになっています

Tomcat_8.5.61_server.xml
    <Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"
          prefix="localhost_access_log" suffix=".txt"
          pattern="%h %l %u %t &quot;%r&quot; %s %b" />

こんな出力です。

192.168.0.1 - - [19/Dec/2020:22:01:02 +0900] "GET /foo/1 HTTP/1.1" 200 12345
192.168.0.1 - - [19/Dec/2020:22:01:05 +0900] "GET /bar/2 HTTP/1.1" 200 23456
192.168.0.1 - - [19/Dec/2020:22:01:07 +0900] "GET /baz/3 HTTP/1.1" 200 34567
192.168.0.1 - - [19/Dec/2020:22:01:14 +0900] "GET /foo/4 HTTP/1.1" 200 11234
192.168.0.1 - - [19/Dec/2020:22:02:09 +0900] "GET /bar/5 HTTP/1.1" 200 22345
192.168.0.1 - - [19/Dec/2020:22:02:12 +0900] "GET /baz/6 HTTP/1.1" 200 33456

ここに**「セッションID」「処理時間(ミリ秒)」「スレッド名」**を加えたいのでこうします

Tomcat_8.5.61_server.xml(変更後)
    <Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"
          prefix="localhost_access_log" suffix=".txt"
          pattern="%h %l %u %t &quot;%r&quot; %s %b %S %D %I" />

これにより

192.168.0.1 - - [19/Dec/2020:22:01:02 +0900] "GET /foo/1 HTTP/1.1" 200 12345 0123456789ABCDEF0123456789ABCDEF 254 ajp-bio-8009-exec-123
192.168.0.1 - - [19/Dec/2020:22:01:05 +0900] "GET /foo/1 HTTP/1.1" 200 23456 ABCDEF0123456789ABCDEF0123456789 10245 ajp-bio-8009-exec-112
192.168.0.1 - - [19/Dec/2020:22:01:07 +0900] "GET /baz/3 HTTP/1.1" 200 34567 0123456789ABCDEF0123456789ABCDEF 547 ajp-bio-8009-exec-157
192.168.0.1 - - [19/Dec/2020:22:01:14 +0900] "GET /foo/4 HTTP/1.1" 200 11234 0123456789ABCDEF0123456789ABCDEF 286 ajp-bio-8009-exec-114
192.168.0.1 - - [19/Dec/2020:22:02:09 +0900] "GET /baz/3 HTTP/1.1" 200 22345 ABCDEF0123456789ABCDEF0123456789 34578 ajp-bio-8009-exec-118
192.168.0.1 - - [19/Dec/2020:22:02:12 +0900] "GET /baz/6 HTTP/1.1" 200 33456 0123456789ABCDEF0123456789ABCDEF 125 ajp-bio-8009-exec-129

と変わります。

すると、アクセスログを見るとき

  1. 右から2番目の応答にかかったミリ秒が大きいものに注意する(例だと2行目や5行目)。特定のURLで問題がおきてないか
  2. 応答にかかったリクエストのセッションIDで検索すれば応答に時間を要しているセッションがどんなURL遷移をしているかが分かる（セキュリティーなどでログイン時のセッションID変更を除く）→特定の経路から始まる遷移で応答が大きい場合、その経路を一時的に塞いでもいいかもしれない……
  3. スレッドダンプと突合できるタイミングがあれば、スレッドダンプで時間をかかっていたスレッドに対応するURLが分かる。（例えば、上から5番目のリクエストは 22:01:35~22:02:09の間処理している。、22:02:00のスレッドダンプがあれば、①スレッドダンプからの処理内容、②リクエストURL、③セッションIDからその前後のアクセス履歴 が分かる）

といったアクションが可能になります。

StuckThreadDetectionValve を設定する

といっても、常時スレッドダンプを叩けるわけでもないので、問題が発生したら、そのTomcatに StuckThreadDetectionValve を設定します（問題が発生する前に必ず入れておくのが個人的な推奨です）。

StuckThreadDetectionValve は、Tomcat 7.0.13 からある処理に時間がかかっているリクエストのスタックトレースを自動で出力してくれるという優れものです。

server.xml で以下のように変更します(Host要素内に入れたいので)、20は「処理に時間がかかっている」とみなす閾値の秒数です。

ただし、10秒おきでTomcatは「処理に時間がかかっている」かをチェックするので、20と書いた場合、最小で20秒、最大で30秒以上処理に時間を要しているリクエストのスタックトレースを出力、となります。

参考）Tomcatでリクエストの処理遅延の検知する
https://qiita.com/tamura__246/items/dae31a6a7e24c756b756

Tomcat_8.5.61_server.xml
      <Host name="localhost"  appBase="webapps"
            unpackWARs="true" autoDeploy="true">
          <!-- 略 -->
      </Host>

こう変更します

Tomcat_8.5.61_server.xml(変更後)
      <Host name="localhost"  appBase="webapps"
            unpackWARs="true" autoDeploy="true">
          <!-- 略 -->
          <Valve className="org.apache.catalina.valves.StuckThreadDetectionValve" threshold="20" />
      </Host>

すると、スタックトレースがスレッド名とともに出力されます。TomcatのWARNレベルなので、

  • CATALINA_HOME/logs/localhost.YYYY-MM-DD.log
  • CATALINA_HOME/logs/catalina.YYYY-MM-DD.log

あたりに出力されます。このスタックトレースから問題の処理は何をしているのか調査を行います。

後編でようやく、PostgreSQLの話に移ります。

27
26
1

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
27
26

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?