2016年08月24日

ServerIOTimeOut の弊害

更新何年ぶりだろな

相変わらず、WebSphereとかjavaとかしてますが、あまり目新しいことや
Tips的なの無いんですよね。(有っても書けないことのほうが多いからのう

今回はWASV6からだったか追加されてるServerIOTimeOutの挙動についての豆知識。
マニュアルなどからは読み取れない細かい話だけれども。

http://www-01.ibm.com/support/docview.wss?uid=jpn1J1000347
http://www-01.ibm.com/support/docview.wss?uid=jpn1J1012104

ここいらに書いてあるServerIOTimeOutのパラメータについて、
クラスタ構成で、正の値が指定されている場合、マークダウンせずに次のサーバーへ
リルートが行われる。

多重処理を防ぐために、PostBufferSizeをゼロにした時、
説明にはこうある。

"
PostBufferSizeが0であるためリクエストのコンテンツをバッファーせず、
更にServerIOTimeoutが正の値ですので、該当サーバーをマークダウンせず、
クライアントに500エラーを返します。
"


HTTP応答コードは最初の応答を返す前に付与される情報であるので、
例えばいくつかの応答を吐きだした後に、Webアプリケーションが張り付いた場合
クライアントには既にHTTP200といくらかの応答が返っているので、HTTP500を返すことはできない。
よって、応答コードだけをServerIOTimeOutが発生したかの判断に使うのは危険だと思う。

この少しだけ応答した場合のServerIOTimeOut有無はAccessLogの応答サイズや、
応答時間ぐらいしか判断材料がない。
http_plugin.logで確認するにはLogLevelをDEBUGまで上げる必要がある


http_plugin.log
[24/Aug/2016:16:01:28.65581] 00001df0 be1fc700 - DEBUG: mod_was_ap22_http: cb_write_body: In the write body callback writing 289
[24/Aug/2016:16:01:28.65601] 00001df0 be1fc700 - DEBUG: lib_htresponse: htresponseGetChunk: Getting the next chunk
[24/Aug/2016:16:01:28.65604] 00001df0 be1fc700 - TRACE: lib_rio: Blocking for read, waiting 45
[24/Aug/2016:16:01:29.22684] 00001e11 c8ed2700 - DEBUG: mod_was_ap22_http: as_child_init pid= 00001E11
[24/Aug/2016:16:02:13.66877] 00001df0 be1fc700 - DEBUG: lib_rio: wait_on_socket: ServerIOTimeout fired.
[24/Aug/2016:16:02:13.66883] 00001df0 be1fc700 - DEBUG: lib_rio.c line 894 : Read failed, rc=11

access.log
192.168.1.10 - - [24/Aug/2016:16:00:00 +0900] "GET /MyTestWeb/post.html HTTP/1.1" 200 409
192.168.1.10 - - [24/Aug/2016:16:01:28 +0900] "POST /MyTestWeb/IOTimeOutTest.jsp HTTP/1.1" 200 289

※ServerIOTimeOutを45秒に設定、アプリケーションで少し出力したあとに60秒sleepさせてみた結果


htresponseGetChunkのエラーで検知できるかもだが、ちょっと微妙過ぎる気がするぜ。
どうでもいいが、TimeOut発動時のログ、fired! ってのがちょっとかっこいいな
posted by koteitan at 22:34| Comment(0) | TrackBack(0) | WebSphere | このブログの読者になる | 更新情報をチェックする