現象
- ブラウザからWebアプリにアクセスしても応答がない。
- /usr/local/tomcat/logs/catalina.out に以下のエラーメッセージが出力されている。
2010-08-27 10:25:56 (TP-Processor3) ...
Exception in thread "TP-Processor23" java.lang.OutOfMemoryError: Java heap space
2010-08-27 11:10:33 (TP-Processor3) ...
- /usr/local/apache2/logs/mod_jk.log に以下のエラーメッセージが出力されている。
[Fri Aug 27 10:21:30 2010][32366:2836394064] [info] ajp_process_callback::jk_ajp_common.c (1788): Writing to client aborted or client network problems
[Fri Aug 27 10:21:30 2010][32366:2836394064] [info] ajp_service::jk_ajp_common.c (2447): (tomcat1) sending request to tomcat failed (unrecoverable), because of client write error
(attempt=1)
[Fri Aug 27 10:21:31 2010][32366:2836394064] [info] service::jk_lb_worker.c (1384): service failed, worker tomcat1 is in local error state
[Fri Aug 27 10:21:31 2010][32366:2836394064] [info] service::jk_lb_worker.c (1403): unrecoverable error 200, request failed. Client failed in the middle of request, we can't recov
er to another instance.
[Fri Aug 27 10:21:31 2010]loadbalance ****.**.****.co.jp 1638.165461
[Fri Aug 27 10:21:31 2010][32366:2836394064] [info] jk_handler::mod_jk.c (2608): Aborting connection for worker=loadbalance
...
[Fri Aug 27 10:34:40 2010][32366:2836394064] [info] ajp_connection_tcp_get_message::jk_ajp_common.c (1150): (tomcat1) can't receive the response header message from tomcat, networ
k problems or tomcat (127.0.0.1:8009) is down (errno=104)
[Fri Aug 27 10:34:40 2010][32366:2836394064] [error] ajp_get_reply::jk_ajp_common.c (1962): (tomcat1) Tomcat is down or refused connection. No response has been sent to the client
(yet)
[Fri Aug 27 10:34:40 2010][32366:2836394064] [info] ajp_service::jk_ajp_common.c (2447): (tomcat1) sending request to tomcat failed (recoverable), (attempt=1)
[Fri Aug 27 10:39:37 2010][21606:2836394064] [info] ajp_connection_tcp_get_message::jk_ajp_common.c (1143): (tomcat1) can't receive the response header message from tomcat, tomcat (127.0.0.1:8009) has forced a connection close for socket 14
[Fri Aug 27 10:39:37 2010][21606:2836394064] [error] ajp_get_reply::jk_ajp_common.c (1962): (tomcat1) Tomcat is down or refused connection. No response has been sent to the client (yet)
[Fri Aug 27 10:39:37 2010][21606:2836394064] [info] ajp_service::jk_ajp_common.c (2447): (tomcat1) sending request to tomcat failed (recoverable), (attempt=1)
[Fri Aug 27 10:42:58 2010][610:2836394064] [info] ajp_connection_tcp_get_message::jk_ajp_common.c (1143): (tomcat1) can't receive the response header message from tomcat, tomcat (127.0.0.1:8009) has forced a connection close for socket 14
[Fri Aug 27 10:42:58 2010][610:2836394064] [error] ajp_get_reply::jk_ajp_common.c (1962): (tomcat1) Tomcat is down or refused connection. No response has been sent to the client (yet)
[Fri Aug 27 10:42:58 2010][610:2836394064] [info] ajp_service::jk_ajp_common.c (2447): (tomcat1) sending request to tomcat failed (recoverable), (attempt=1)
[Fri Aug 27 10:43:14 2010][1544:2836394064] [info] ajp_connection_tcp_get_message::jk_ajp_common.c (1143): (tomcat1) can't receive the response header message from tomcat, tomcat (127.0.0.1:8009) has forced a connection close for socket 14
[Fri Aug 27 10:43:14 2010][1544:2836394064] [error] ajp_get_reply::jk_ajp_common.c (1962): (tomcat1) Tomcat is down or refused connection. No response has been sent to the client (yet)
- SYN_RECV 状態の接続がある。コネクションの接続要求であるSYNパケットを受け取り、応答となるACKパケットを返していない状態。Tomcatが処理できる以上に新規コネクションが要求されており、接続要求がキューに積まれている。
$ netstat -na |grep 8009
tcp 0 0 127.0.0.1:8009 127.0.0.1:52320 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52318 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52319 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52321 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52323 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52314 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52317 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52315 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52313 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52316 SYN_RECV
tcp 0 0 127.0.0.1:8009 127.0.0.1:52322 SYN_RECV
tcp 0 0 127.0.0.1:51517 127.0.0.1:8009 ESTABLISHED
tcp 0 0 127.0.0.1:51516 127.0.0.1:8009 ESTABLISHED
tcp 0 0 127.0.0.1:51515 127.0.0.1:8009 ESTABLISHED
- Tomcat Manager でサーバの状態を見ると、jk-8009 に Stage が S: Service な接続が多い。
- 8080 ポートで Tomcat Manager などにアクセスすると問題なし。Tomcatは直接リクエストを受け付けるためのport（8080）とApache-mod_jk経由のリクエストを受け付けるport（8009）それぞれにスレッドプールを持っているため。
- /usr/local/tomcat/conf/server.xml の maxThreads の設定。何も記述されていない。
<Connector port="8009" protocol="AJP/1.3" redirectPort="8443" URIEncoding="UTF-8" />
原因
- 最近、Apache の Timeout 設定を1時間にしたことにより、Apache プロセスと Tomcat スレッド間の接続が長時間残り、Tomcatの持つスレッドプールが最大スレッド数（maxThreads）を超え、新しい接続を受け付けられなくなったため。
