JavaでHTTP通信をやろうとすると、必ずと言っていいほど登場する、Apache HttpClient4（以前は、Jakarta Commons HttpClient3）ですが、これでちょっとハマっていた事象を見かけたので、軽くメモを。
あ、その時に使われていたのは、Jakarta Commons HttpClient3の方です。んで、ソケットのクローズ漏れでハマってました。
これ、チュートリアルだけを信じて実装すると、ハマるんですよねぇ…。
http://hc.apache.org/httpclient-3.x/tutorial.html
チュートリアルの中に
// Release the connection.
method.releaseConnection();
みたいなことが書いてあって、いかにもコネクションをクローズしてくれそうな雰囲気がありますが、これは意味が違います。HttpClientが持つ、HttpConnectionManagerのインスタンスにコネクションを返却しますよ、という意味であって、別にコネクションを閉じてくれるわけではないんですよね。
割と当たり前の情報？
これを検証するために、以下のようなコードを用意してみました。
build.sbt
name := "httpclient3-example" version := "0.0.1" organization := "littlewings" libraryDependencies += "commons-httpclient" % "commons-httpclient" % "3.1"
HttpClient3Example.java
import java.io.IOException; import org.apache.commons.httpclient.HttpClient; import org.apache.commons.httpclient.HttpException; import org.apache.commons.httpclient.HttpMethod; import org.apache.commons.httpclient.HttpStatus; import org.apache.commons.httpclient.methods.GetMethod; public class HttpClient3Example { private static final String URL = "http://localhost:8080/index.html"; private static final int EXEC_COUNT = 10; public static void main(String[] args) { for (int i = 0; i < EXEC_COUNT; i++) { executeHttpMethod(); try { long sleepTime = 5 * 1000L; System.out.printf("Sleeping %dmsec...%n", sleepTime); Thread.sleep(sleepTime); } catch (InterruptedException e) { } } } public static void executeHttpMethod() { HttpClient client = new HttpClient(); HttpMethod method = new GetMethod(URL); try { System.out.printf("Access URL[%s]%n", URL); int statusCode = client.executeMethod(method); String body = new String(method.getResponseBody(), "UTF-8"); System.out.printf("Status Code = %d%n", statusCode); System.out.printf("Response Body = %s%n", body); } catch (HttpException e) { e.printStackTrace(); } catch (IOException e) { e.printStackTrace(); } finally { method.releaseConnection(); } } }
んで、前回作成した簡易HTTPサーバを起動しまして
$ groovy LightHttpd.groovy LightHttpd Startup. Sat Oct 13 17:18:30 JST 2012
実行してみます。
$ sbt [info] Set current project to httpclient3-example (in build file:/xxxxx/httpclient3-example/) > run [info] Compiling 1 Java source to /xxxxx/httpclient3-example/target/scala-2.9.2/classes... [info] Running HttpClient3Example Access URL[http://localhost:8080/index.html] Status Code = 200 Response Body = Accessed URL = /index.html Accessed Date = Sat Oct 13 17:19:10 JST 2012 Sleeping 5000msec... Access URL[http://localhost:8080/index.html] Status Code = 200 Response Body = Accessed URL = /index.html Accessed Date = Sat Oct 13 17:19:15 JST 2012 〜省略〜 Access URL[http://localhost:8080/index.html] Status Code = 200 Response Body = Accessed URL = /index.html Accessed Date = Sat Oct 13 17:19:55 JST 2012 Sleeping 5000msec... [success] Total time: 53 s, completed 2012/10/13 17:20:00
この間に、別のコンソールでnetstatを使ってソケットの状態を監視してみます。
$ netstat -an | grep 127.0.0.1:8080 tcp6 0 0 127.0.0.1:50398 127.0.0.1:8080 ESTABLISHED tcp6 0 0 127.0.0.1:8080 127.0.0.1:46391 FIN_WAIT2 tcp6 0 0 127.0.0.1:42644 127.0.0.1:8080 ESTABLISHED tcp6 0 0 127.0.0.1:8080 127.0.0.1:47286 FIN_WAIT2 tcp6 0 0 127.0.0.1:8080 127.0.0.1:56907 FIN_WAIT2 tcp6 0 0 127.0.0.1:40523 127.0.0.1:8080 ESTABLISHED tcp6 0 0 127.0.0.1:8080 127.0.0.1:60165 ESTABLISHED tcp6 1 0 127.0.0.1:56907 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:58088 127.0.0.1:8080 ESTABLISHED tcp6 0 0 127.0.0.1:60165 127.0.0.1:8080 ESTABLISHED tcp6 1 0 127.0.0.1:47286 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:53817 FIN_WAIT2 tcp6 1 0 127.0.0.1:46391 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:50398 ESTABLISHED tcp6 0 0 127.0.0.1:8080 127.0.0.1:40523 ESTABLISHED tcp6 0 0 127.0.0.1:8080 127.0.0.1:58088 ESTABLISHED tcp6 1 0 127.0.0.1:53817 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:42644 ESTABLISHED
サーバ側とクライアント側の接続が見えていますが、バラバラとESTABLISHED、CLOSE_WAIT、FIN_WAIT2となってますね。
もう少し待つと、CLOSE_WAITとFIN_WAIT2だけになります。
$ netstat -an | grep 127.0.0.1:8080 tcp6 1 0 127.0.0.1:50398 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:46391 FIN_WAIT2 tcp6 1 0 127.0.0.1:42644 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:47286 FIN_WAIT2 tcp6 0 0 127.0.0.1:8080 127.0.0.1:56907 FIN_WAIT2 tcp6 1 0 127.0.0.1:40523 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:38467 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:60165 FIN_WAIT2 tcp6 1 0 127.0.0.1:56907 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:58088 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:60165 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:47286 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:53817 FIN_WAIT2 tcp6 1 0 127.0.0.1:46391 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:50398 FIN_WAIT2 tcp6 0 0 127.0.0.1:8080 127.0.0.1:38467 FIN_WAIT2 tcp6 0 0 127.0.0.1:8080 127.0.0.1:40523 FIN_WAIT2 tcp6 0 0 127.0.0.1:8080 127.0.0.1:58088 FIN_WAIT2 tcp6 1 0 127.0.0.1:53817 127.0.0.1:8080 CLOSE_WAIT tcp6 0 0 127.0.0.1:8080 127.0.0.1:42644 FIN_WAIT2
最後には、CLOSE_WAITだけになります。
$ netstat -an | grep 127.0.0.1:8080 tcp6 1 0 127.0.0.1:50398 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:42644 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:40523 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:38467 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:56907 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:58088 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:60165 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:47286 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:46391 127.0.0.1:8080 CLOSE_WAIT tcp6 1 0 127.0.0.1:53817 127.0.0.1:8080 CLOSE_WAIT
さらにず〜っと放ったらかしにしておくと、netstatからは消えますがlsofで見ると「can't identify protocol」と表記されるような状態になってしまいます。
こうなると、HTTP通信を実行する度にファイルディクリプタを使用量が増え続け、Tomcat上で動かすようなサーバ系のプログラムとして組んでいた場合は、Too many open filesエラーを引いてサーバの停止に追い込まれます。
まあ、結論だけ言うとソケットをクローズしていないことが原因です。
ソケットがFIN_WAIT2として見えているのはHTTPサーバ側の方で、CLOSE_WAITとなっているのはクライアント側の方です。で、CLOSE_WAITは相手はクローズしたけど、自分のクローズ命令を待っている状態なので、要は「早く自分の持っているソケットをクローズしましょうね」と言っているわけです。
なので、これに対処するには以下のどちらかの修正を行います。
１）HttpConnectionManagerの持つ、アイドル状態のコネクションをクローズする
HttpMethod#releaseConnectionでHttpConnectionManagerのプールに戻されたコネクションをクローズするため、finally句の部分を以下のように修正します。
} finally { method.releaseConnection(); client.getHttpConnectionManager().closeIdleConnections(0); }
２）HTTPヘッダに「Connection: close」を追加する
HttpClient client = new HttpClient(); HttpMethod method = new GetMethod(URL); method.addRequestHeader("Connection", "close");
このいずれかの対処を行うと、HttpClientでソケットのクローズを行ってくれます。
実行すると、今度はTIME_WAITに遷移するようになります。
$ netstat -an | grep 127.0.0.1:8080 tcp6 0 0 127.0.0.1:57912 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:44164 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:39976 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:43772 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:55436 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:45129 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:51501 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:57594 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:48916 127.0.0.1:8080 TIME_WAIT tcp6 0 0 127.0.0.1:38695 127.0.0.1:8080 TIME_WAIT
TIME_WAITなので、少し放っておくと開放されます。
最後に、Apache HttpClient4版で。
Quick Startを見て実装すると
http://hc.apache.org/httpcomponents-client-ga/quickstart.html
こんな感じになって
build.sbt
name := "httpclient4-example" version := "0.0.1" libraryDependencies += "org.apache.httpcomponents" % "httpclient" % "4.2.1"
HttpClient4Example.java
import java.io.IOException; import org.apache.http.HttpEntity; import org.apache.http.HttpResponse; import org.apache.http.util.EntityUtils; import org.apache.http.client.HttpClient; import org.apache.http.client.methods.HttpGet; import org.apache.http.impl.client.DefaultHttpClient; public class HttpClient4Example { private static final String URL = "http://localhost:8080/index.html"; private static final int EXEC_COUNT = 10; public static void main(String[] args) { for (int i = 0; i < EXEC_COUNT; i++) { executeHttpMethod(); try { long sleepTime = 5 * 1000L; System.out.printf("Sleeping %dmsec...%n", sleepTime); Thread.sleep(sleepTime); } catch (InterruptedException e) { } } } public static void executeHttpMethod() { HttpClient client = new DefaultHttpClient(); HttpGet getMethod = new HttpGet(URL); try { System.out.printf("Access URL[%s]%n", URL); HttpResponse response = client.execute(getMethod); HttpEntity entity = response.getEntity(); String body = EntityUtils.toString(entity, "UTF-8"); System.out.printf("Status Line = %s%n", response.getStatusLine()); System.out.printf("Response Body = %s%n", body); } catch (IOException e) { e.printStackTrace(); } finally { getMethod.releaseConnection(); } } }
このコードだと、ソケットがCLOSE_WAITで止まってしまい、やっぱりハマります。
ここは、Examplesの「Manual connection release」
http://hc.apache.org/httpcomponents-client-ga/examples.html
もしくはTutrialの「Connection manager shutdown」
http://hc.apache.org/httpcomponents-client-ga/tutorial/html/connmgmt.html#d5e635
のどちらかを参考に、finally句を以下のように修正します。
} finally { // getMethod.releaseConnection(); => こっちは要らない client.getConnectionManager().shutdown(); }
Apache HttpClient4の場合は、HttpClientインターフェースのAPIにも書いているんですが…
http://hc.apache.org/httpcomponents-client-ga/httpclient/apidocs/org/apache/http/client/HttpClient.html
なんでQuick StartはreleaseConnectionの方しか書いてないんでしょうね？
割と当たり前の話かもしれませんが、起動して処理が終わるとプロセスも終了するバッチプログラムならいいんですが、サーバ系だとけっこう問題になると思うので一応書いてみます。
