HP-UXでTCPソケットプログラミングのCPUが高騰

572 views
Skip to first unread message

Billiards Sanchan

unread,
Mar 5, 2012, 4:17:14 AM3/5/12
to java-ja
HP-UXでJAVAプログラムのプロセスIDのCPU使用率が高騰して
いて、原因が分からず困っています。

●サーバ側
JAVA：
# /opt/java6/jre/bin/java -version
java version "1.6.0.13"
Java(TM) SE Runtime Environment (build 1.6.0.13-
jinteg_01_dec_2011_03_39-b00)
Java HotSpot(TM) Server VM (build 20.3-b02-jre1.6.0.13-rc1b1, mixed
mode)


機種：RX2620(1CPU メモリ2G)
OS：HP-UX 11.23
OS環境パラメータ：tcp_ip_abort_cinterval=75000ミリ秒


テスト用プログラム：
テスト用に作成したTCPソケットのプログラム。
サーバの特定ポート（8188を使用）でソケットを取得して
クライアントであるIEの画面にhtmlファイルを表示させるプログラム。


accept()した後で
socket.setSoTimeout(SO_TIMEOUT);
socket.setSoLinger(true, SO_LINGER);
でSO_TIMEOUT、SO_LINGERで設定とを行っています。


その後、read()、write()しています。


取得したソケットは、つどクローズせずに同じソケットを使いまわすように
作っています。


●クライアント側
WinXP
IE6.0 SP3


●事象
クライアントのIEから目的のhtmlファイルを表示後にクライアント側でF5ボタンを
押下し続けると、接続切断を繰り返した後にサーバ側でnetstat -anで
8188ポートの状態を観察していると、"SYN_RCVD"の状態となります。


F5から手を離します。


tcp_ip_abort_cinterval=75000ミリ秒
時間SYN_RCVDの状態は続くのですが、


SYN_RCVDとなった時点から
socket.setSoTimeout(SO_TIMEOUT);
で設定された時間経過すると、CPUの高騰が発生します。


SO_TIMEOUTの時間は10秒、20秒、30秒、40秒と変えてみましたが
全て設定した時間経過後にCPUの高騰が始まります。


tcp_ip_abort_cinterval=75000ミリ秒経過した後に
SYN_RCVD
の状態が解消されるまで、CPU使用率が90%台まで上昇し、
SYN_RCVDが解消されるとCPUの使用率が一気に0.3%程度に下がり、
テスト用プログラムでは、
Read timed out
が表示されます。（事象A）
---
事象Aが発生している最中にOS側のsarコマンドを使ってCPUの使用率を
計測すると以下のように%sys（OS側）の処理でCPUを食っているように見えます。


17:40:19 SYN_RCVD発生


17:40:26 %usr %sys %wio %idle
17:40:27 0 1 0 99
17:40:28 0 0 0 100
17:40:29 0 1 3 96
17:40:30 0 0 1 99
17:40:31 0 0 0 100
17:40:32 0 1 0 99
17:40:33 0 0 0 100
17:40:34 0 0 0 100
17:40:35 0 1 0 99
17:40:36 0 0 0 100
17:40:37 0 0 0 100
17:40:38 0 1 0 99
17:40:39 0 0 0 100
17:40:40 0 0 0 100
17:40:41 0 1 0 99
17:40:42 0 0 0 100
17:40:43 0 0 0 100
17:40:44 1 0 0 99
17:40:45 0 0 0 100
17:40:46 0 0 0 100
17:40:47 0 1 0 99
17:40:48 0 0 0 100
17:40:49 0 0 0 100


（SYN_RCVD発生から必ずSETSOTIMEOUT=30秒後からCPUの高騰が始まります。）


17:40:50 0 79 0 21
17:40:51 0 100 0 0
17:40:52 0 100 0 0
17:40:53 0 100 0 0
17:40:54 0 100 0 0
17:40:55 0 100 0 0
17:40:56 21 79 0 0
17:40:57 0 100 0 0
17:40:58 0 100 0 0
17:40:59 0 100 0 0
17:41:00 0 100 0 0
17:41:01 0 100 0 0
17:41:02 0 100 0 0
17:41:03 0 100 0 0
17:41:04 0 100 0 0
17:41:05 0 100 0 0
17:41:06 0 100 0 0
17:41:07 0 100 0 0
17:41:08 1 99 0 0
17:41:09 0 100 0 0
17:41:10 0 100 0 0
17:41:11 1 99 0 0
17:41:12 0 100 0 0
17:41:13 0 100 0 0
17:41:14 0 100 0 0
17:41:15 0 100 0 0
17:41:16 12 88 0 0
17:41:17 0 100 0 0
17:41:18 0 100 0 0
17:41:19 0 100 0 0
17:41:20 0 100 0 0
17:41:21 0 100 0 0
17:41:22 0 100 0 0
17:41:23 0 100 0 0
17:41:24 0 100 0 0
17:41:25 0 100 0 0
17:41:26 0 100 0 0
17:41:27 0 100 0 0
17:41:28 0 100 0 0
17:41:29 0 100 0 0
17:41:30 0 100 0 0
17:41:31 0 100 0 0
17:41:32 0 100 0 0
17:41:33 0 100 0 0
17:41:34 0 100 0 0
17:41:35 0 100 0 0
17:41:36 0 43 0 57


17:41:36 Read timed outがAMEEのログに発生し、
以降CPU使用率が下がる


---
試しに
tcp_ip_abort_cinterval=20000ミリ秒
SO_TIMEOUT=30秒
とした場合には、CPUの高騰は発生しません。
---


テストプログラムで、
socket.setSoLinger(true, SO_LINGER);
をコメントアウトした場合にもCPUの高騰は発生しません。


---


そこで、質問です。
（１）CPUが高騰するメカニズムがよくわかりません。
うまく説明できる方いませんでしょうか？


SYN_RCVDとなったことは、JAVAのプログラムからは直接見えるレイヤでは
ないので、関係ないと思うのですが、SETSOTIMEOUTの値に引っ張られることや、
setSoLinger(true, SO_LINGER);
の有無でCPUが高騰したりしなかったりする


（２）setSoLinger(true, SO_LINGER);ってTCPソケットのプラグラムでなんのために
使われるものなのでしょうか？


（３）setSoLinger(true, SO_LINGER);の引数の解釈の仕方がHP-UXはLINUX、Windowsなど
と異なるような記述もあるのですが、詳しい方いないでしょうか？


（４）この問題を解決するためにはどのような方法で何を調べれば良いでしょうか？


以上よろしくお願いいたします。


Takayoshi Kimura

unread,
Mar 5, 2012, 5:39:52 AM3/5/12
to jav...@googlegroups.com
きむらです。

サーバがテスト用プログラムで、IEがクライアントの直接接続、という認識で間違いないでしょうか。

サーバ側はaccept()を一回しかしていない、クライアントは(IEで更新を連打して)サーバに対してソケットをいっぱい張っている、ということですからaccept()されてないソケットたちがbacklog越えてしまってSYN_RECVなソケットができる、という状況のように読めます。ここまでは単に「テスト用プログラム」の不具合に見えますが、これは意図的にそういう状況をテストしたい、という意味で行っているのでしょうか？

SO_LINGERの設定によりCPUが回ってしまう、という現象の理由は今のところ見えないのですが、上記を直して発生しなくなるのであればそれで良い、ということであれば深追いする必要は無い気がします。SO_LINGERについてはとりあえず以下のURLなどを参照してみてください。

http://docs.oracle.com/javase/7/docs/api/java/net/SocketOptions.html#SO_LINGER
http://linuxjm.sourceforge.jp/html/LDP_man-pages/man7/socket.7.html

Socket#setSoLinger()のパラメータはドキュメントの通りひとつめがon/off、ふたつめがタイムアウトです。これ自体はOSごとに意味が異なるということはないと思います。

http://docs.oracle.com/javase/7/docs/api/java/net/Socket.html#setSoLinger%28boolean,%20int%29

Regards,
Takayoshi

Billiards Sanchan

unread,
Mar 8, 2012, 4:20:43 AM3/8/12
to java-ja
きむらさん、ご丁寧な回答ありがとうございます。
インラインにて返信させていただきます。


> サーバがテスト用プログラムで、IEがクライアントの直接接続、という認識で間違いないでしょうか。

まちがいないです。


> サーバ側はaccept()を一回しかしていない、クライアントは(IEで更新を連打して)サーバに対してソケットをいっぱい張っている、ということですからa ccept()されてないソケットたちがbacklog越えてしまってSYN_RECVなソケットができる、という状況のように読めます。ここまでは単に「テス ト用プログラム」の不具合に見えますが、これは意図的にそういう状況をテストしたい、という意味で行っているのでしょうか？

意図的に作っています。
本当に調べたいプログラムは別にあるのですが、仕様の開示が
行われないプログラムなのです。
逆〇〇〇〇〇して中身を見て見よう見まねで作成しました。


> SO_LINGERの設定によりCPUが回ってしまう、という現象の理由は今のところ見えないのですが、上記を直して発生しなくなるのであればそれで良い、とい うことであれば深追いする必要は無い気がします。


上記の通り、ホントの調査対象のプログラムは簡単に変更できないです。

> SO_LINGERについてはとりあえず以下のURLなどを参照してみてください。


ありがとうございます。
調べてみます。


> Socket#setSoLinger()のパラメータはドキュメントの通りひとつめがon/off、ふたつめがタイムアウトです。これ自体はOSごとに意味が 異なるということはないと思います。

そうですかぁ。。
となると、ますます謎が深まるばかりです。(笑)

また何かわかれば教えてください。
参考になることも多く、大変助かります。

Takayoshi Kimura

unread,
Mar 8, 2012, 4:31:40 AM3/8/12
to jav...@googlegroups.com
きむらです。

2012/3/8 Billiards Sanchan <sugi...@tb4.so-net.ne.jp>:

> 意図的に作っています。
> 本当に調べたいプログラムは別にあるのですが、仕様の開示が
> 行われないプログラムなのです。

なるほど、ありがちなシチュエーションですね。現象からすると問題はHP-UXのカーネルやHP-UXのJavaの要素が強いですね。LinuxやOpenJDKだとソース追えばそこそこは調査できると思いますが、僕はHP-UXはほとんど触ったことがないですしHP-UXはオープンソースでもないのでどうにも手出しできないですね。

HP-UXのサポートにテストプログラムを渡してなぜそうなるのかを聞くのが良いと思います。

Regards,
Takayoshi
Senior Software Maintenance Engineer, Red Hat

Reply all
Reply to author
Forward
0 new messages