帳票出力について

現在、Javaを使用したWebアプリ開発を行っており
下記の処理でローカル環境(開発用PC)では正常にいくが、サーバ環境では異常終了
となる事象が発生しております。
どなたか対応策をご存じな方がいましたらご回答よろしくお願い致します。

また未実施調査もあり、その調査方法が不明なため合わせてご回答よろしく
お願い致します。

■処理概要
画面に帳票ボタンがあり、そのボタンを押下すると別ブラウザに
帳票(PDF)が出力される。

■処理内容（帳票ボタン押下）
(1)DBから帳票出力対象となるデータを抽出
(2)(1)で抽出したデータを加工
(3)(2)で加工した帳票データを、帳票定義体とバインド
(4)(3)でバインドした帳票を別ブラウザに表示

■異常終了概要
押下されたボタンによって出力する帳票が異なり、
帳票出力対象データが大量にある場合、ある１つの帳票だけが
1時間ほど待っても出力結果がかえってこなかった。
そのためログを確認すると「java.net.SocketException: Broken pipe」が発生していた。
※それ以外の帳票については正常に帳票出力される。

■異常終了発生箇所について
サーバ環境でログを確認したところ、処理内容の(3)までは正常に処理されており
(4)の別ブラウザに表示する際に異常終了となっていた。

(4)の詳細処理内容として、(3)で作成した帳票データ(バインド済み帳票)を
javax.servlet.HttpServletResponse.getOutputStreamで取得したOutputStreamに
書き込み、そのOutputStreamをflushする処理になっている。
※異常終了は「帳票データをOutputStreamに書き込み」時に発生している。

＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝

現在、異常終了となる帳票処理について調査した結果以下の事が判明した。

■調査内容
・大量データ時に異常終了となる帳票は、データを減らすと正常に帳票出力される。

・他帳票と比べ、帳票データ作成時間が長い。
※１．帳票データ作成時間は、帳票データをOutputStreamに書き込む時間は含んでいない。
※２．上記帳票はデータを減らし調査している。

・他帳票と比べ、帳票のファイルサイズは小さい

・１つのPCをWebサーバ、APサーバ、DBサーバとしている。サーバ環境内容として
OS：Linux(CentOS)
Web：Apache
AP：Tomcat
DB：PostgreSQL

・帳票データ作成時間が5分を越える場合、当事象(broken pipeエラー)が発生する。
※１．帳票データ処理にJavaのSleepメソッドで5分超える/越えない時間を設定し調査した。
※２．Tomcat、Apacheの設定ファイル(Web.xml,Server.xml,httpd.conf)を確認したが
5分(300秒、600000ミリ秒)の記載箇所は見つからなかった。
※３．帳票データ作成時間が5分を超える＝サーバからクライアントへの応答が5分以上ない

・IEの仕様で「サーバーからデータが返されるまでのタイムアウト時間(5分)が設定されている」
との記事があり、レジストリを修正しタイムアウト時間を60分にしたが解決しなかった。

・対象データに問題がない(Linuxで扱えない文字などはない)事を確認した。

■調査方法不明
・Linux側(サーバ)でクライアントへ5分応答がない場合、コネクションを切断しているのでは
ないかと考えた(ネットワークの設定など)が、どの設定ファイルを確認すればよいか分からない。
※もしそれが原因だった場合の対応方法についても

No.11 回答者： NARH 回答日時： 2011/02/24 13:22

どうもです。

>> 利用されているコネクタは mod_proxy_ajp でしょうか？
> →利用しているコネクタはmod_jkです。

mod_jk の version は幾つでしょうか？ChangeLogを見てみると、1.2.27 あたりで

Added socket_connect_timeout directive for setting the connect timeout for the socket. This enables to have low connection timeout but higher operational timeouts.

と、socket_connect_timeout ディレクティブが追加されましたと、それっぽい変更があったようです。

mod_jk の timeout に関してはそれようのページが英語ですが用意されているようです。
http://tomcat.apache.org/connectors-doc/generic_ …

この辺で切れられていると、ブラウザからはサーバ側が切断している。アプリケーションからはブラウザ側が切断しているように見えるので、現象にマッチしているように思えます。



また、アプリケーションの仕様変更を予定されているようですが、

> ※実装方法が不明な箇所は、「スレッドIDを使い、それを元に現在動作しているスレッドを取得する」方法について。

この実現方法は、アプリケーションで共通的な（アプリケーションスコープな）ThreadPool を作成し、そこから取得するというのが、パッと思いつく方法です。
重たい処理のようなので、サーバリソースが限られているときはThreadPoolに入れられる上限をコントロールすることで、
ユーザに対して通知のようなことも出来るかもしれません。

＃思いつきなので、一般的かどうかはわかりません。

僕なら、重たい作業はスケールアウトさせたいので、Queue を使った処理系を作るかもしれませんし。
ただ、PDF作成というのが、どの程度の重要性と頻度があるかによって、求められることが違ってくるので、それに合わせて手数が少なくてすむ戦略を取っちゃうというのが良いと思いますね。

この回答への補足

NARHさん。長い間ご連絡をせず申し訳ありません。

>>mod_jk の version は幾つでしょうか？ChangeLogを見てみると、1.2.27 あたりで
はい。mod_jkのversionは1.2.27を使用しております。

>>socket_connect_timeout ディレクティブが追加されましたと、それっぽい変更があったようです。
workers.propertiesにsocket_connect_timeoutを記載したところ、apache側でエラーとなりました。

またTomcat, Apache, Linuxの環境面での対応策が見つけられない状態のため、5分経過しても対応できるようにコード修正を行いました。結果5分経過しても問題なく帳票出力することができました。
修正内容を下記の「コード修正内容」に記載します。

しかし、同時に2台の端末から帳票出力を行った場合、「NullPointerException」が発生致しました。
エラーログを下記の「エラーログ内容」に記載します。
ネットで同様の障害については発見できのですが、対応策が見つからず手詰まり状態となっております。
対応策についてご存じでしたら、ご教授よろしくお願い致します。

■コード修正内容
帳票出力画面(親画面)から帳票出力結果画面(別ウィンドウ：子画面)を開くと、帳票データ作成スレッドが動作します。
帳票データ作成スレッドは帳票データ作成が完了するとセッションに完了フラグ、作成した帳票データを設定します。

帳票出力結果画面は、一定間隔でセッションの完了フラグを確認(onloadイベントを使い完了フラグの有無を確かめ、完了フラグがない場合、画面をリロードする)し、完了していた場合、セッションより帳票データを取得し画面に表示します。

■エラーログ内容
Exception in thread "Thread-45" java.lang.NullPointerException
at sun.font.GlyphLayout$EngineRecord.init(GlyphLayout.java:603)
at sun.font.GlyphLayout.nextEngineRecord(GlyphLayout.java:477)
at sun.font.GlyphLayout.layout(GlyphLayout.java:409)
at sun.font.ExtendedTextSourceLabel.createGV(ExtendedTextSourceLabel.java:267)
at sun.font.ExtendedTextSourceLabel.getGV(ExtendedTextSourceLabel.java:252)
at sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:522)
at sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:451)
at sun.font.ExtendedTextSourceLabel.getLineBreakIndex(ExtendedTextSourceLabel.java:397)
at java.awt.font.TextMeasurer.calcLineBreak(TextMeasurer.java:313)

=================省略==============

at net.sf.jasperreports.engine.fill.JRBaseFiller.fill(JRBaseFiller.java:879)
at net.sf.jasperreports.engine.fill.JRBaseFiller.fill(JRBaseFiller.java:801)
at net.sf.jasperreports.engine.fill.JRFiller.fillReport(JRFiller.java:89)
at net.sf.jasperreports.engine.JasperFillManager.fillReport(JasperFillManager.java:601)
at net.sf.jasperreports.engine.JasperFillManager.fillReport(JasperFillManager.java:517

補足日時：2011/03/03 01:15

No.10 回答者： tonchi911 回答日時： 2011/02/24 11:53

No.9 の回答の者です。

あ、Timeout も確認済みでしたか。
失礼しました。
しかし、5分でコネクションが切れるとなるとどうも引っかかります。

#途中で割り込むと見落としが多くていけません。

No.9 回答者： tonchi911 回答日時： 2011/02/24 11:09

No.6 の補足を見ておもったのですが…

それって、　apache 1.3 /apache 2.x 系の　Timeout のデフォルト値(300秒)の問題では？

明示的に定義するか、Include してありますか？

参考URL：http://httpd.apache.org/docs/2.0/ja/mod/core.htm …

No.8 回答者： tonchi911 回答日時： 2011/02/23 10:04

回答　No.7の者です。

サーバサイドのIPコネクションを調査されてたのでしたね。
失礼しました。

この回答への補足

tonchi911さん。回答ありがとうございます。

>>サーバサイドのIPコネクションを調査されてたのでしたね。
はい。問題がないことを確認しております。
また、No.6の補足に記載しておりますが当初は環境設定を変更することで対応したいと思っていましたが解決方法が現在に至るまで見つからない状態なので、コードの修正を行う事にしました。
しかし修正にあたりNo.6の補足にある問題が発生しております。
もしご存じでしたらご教授お願いします。

補足日時：2011/02/24 01:23

No.7 回答者： tonchi911 回答日時： 2011/02/23 09:53

google経由で検索の最中に目に付いたので、

ちょこっと気になったこの点を

他の方もかかれてますが…

＞自分で iptables と書いていてふと思ったのですが、
＞ iptables で netfilter を使っていれば、timeout させることも出来るみたいです。

本番環境でのブラウザとサーバの間にもし、マスカレードするルータや
ファイアーフォールの類が
あるようであれば、そのセッション保持時間も調査する必要がありそうですね。

No.6 回答者： NARH 回答日時： 2011/02/22 10:21

自分で iptables と書いていてふと思ったのですが、 iptables で netfilter を使っていれば、timeout させることも出来るみたいです。

でも、その場合は意図して設定しているので、もう気づいているはずでしょうね～。

この回答への補足

NARHさん。回答ありがとうございます。

>>iptables で netfilter を使っていれば、timeout させることも出来るみたいです。
iptablesについて環境構築担当者に確認したのですが特に設定はしていないとの事でした。

また、現在発生している障害(5分経過するとコネクションが切れ、サーバからクライアントへの応答がかえってこない)について以前、別の機能にも同じようなが現象が発生していたとの連絡がありました。
その当時は処理を非同期にさせる対応(サーバで該当処理をスレッドにし、クライアントからサーバへある時間が経過するたびに処理が完了しているかを確認する)に変更したとの事でした。

そのため現在に至るまで、環境設定変更での対応方法について不明のままなので、上記と同じような処理を帳票出力処理に組み込む事にし、昨日からその対応にあたっております。

しかし、その対応にあたり、下記の点でまた新たな問題点が発生しました。
もし下記の問題点についてご存じでしたらご教授お願いします。

■対応内容
サーバ側でJavaのthreadを使い非同期処理(帳票データ作成)をさせ、クライアント側(JSP)では常にサーバ側の処理完了確認(javascriptのsetTimeout(3秒毎など)を使用し帳票データが作成できたか)をさせる。

もし帳票データ作成が完了していた場合、クライアントはサーバに「帳票データを出力させる」アクションを呼び出し、クライアント上で帳票データを出力させる。

■問題点
threadの処理中(帳票データ作成中)に、クライアント側でブラウザの×(閉じる)ボタンを押下した場合、threadの処理(帳票データ作成)が残ってしまう。

■質問
そのためブラウザの×(閉じる)ボタンを押下した場合、threadの処理を終了させたい。
上記の対応にあたり下記の対応を想定していたが実装方法が不明。

■想定内容
threadをstartした際に、threadのgetIdメソッド(スレッドが一意で特定できるIDを取得)を使いスレッドIDを取得、セッションに保存させる。
ブラウザの×(閉じる)ボタンを押下した場合、javascriptのonunloadイベントでアクションを呼び出し
アクションで、事前に保存させていたスレッドIDを使い、それを元に現在動作しているスレッドを取得し終了させる。
※実装方法が不明な箇所は、「スレッドIDを使い、それを元に現在動作しているスレッドを取得する」方法について。

補足日時：2011/02/24 01:17

No.5 回答者： NARH 回答日時： 2011/02/22 10:11

> その場合、Linuxのコネクションに関する設定をネットや書籍などから探しているのですが

見当たらない状態です。

ここが、一番懸念されているようですので、java で簡単な Server プログラムを書いて検証してみました。(ServerSocket で検索するとサンプルは見つかると思います）

その際 timeout の設定はしないようにします。これで java もしくは Linux のデフォルトタイムアウトがあるとすれば、そちらの値になるはずです。

結果、接続後 10分以上たっても接続は timeout しませんでした。
(/proc/sys/net および iptables によるfirewallの設定はデフォルトとしています）

なので、Linuxのtimeout の設定は心配しなくてもいいと思います。
（気になるようでしたら、ネットワーク管理者とLinuxの管理者の方に、そういった設定を明示的にしたかどうかだけ確認すればいいと思います。デフォルトのままであれば気にしなくて良いので）

mod_jk を利用されているということは、少し古めのtomcatでしょうか？tomcat 5.5?

可能であれば、tomcat のバージョンを上げてみるか、 mod_proxy_ajp が使える物に変えてみるというのも試してみる価値はあるかもしれません。( tomcat の socket を握っているのがこの辺なので）

また、flush ですがデータが途中であっても、複数回に分けて flush しても大丈夫ですが、ブラウザがデータの終端をしらなくてはならないので、Contents-length を設定しなくてはならず、実装次第では、結局 wait しなければいけないのかもしれませんね。
application/octet-stream として download させてしまう（ファイルの保存をさせる）なら Content-length なしでも行けるかもしれませんが。。希望されている動作では無いのかもしれませんね。

5分以上待たされると、ユーザが不安になって×ボタンを押してしまったりするので、アプリケーションの振舞を変えるという変更が可能であれば、そちらの方がベターなのかなとは思います。

この回答への補足

NARHさん。回答ありがとうございます。

>>、java で簡単な Server プログラムを書いて検証してみました。
私が開発しているサーバ環境と同様な環境構築し、javaでServer プログラムを作成/確認までしていただき、本当にありがとうございます。
これで私の一番懸念していたLinuxのtimeoutについての疑問が解消されました。

>>mod_jk を利用されているということは、少し古めのtomcatでしょうか？tomcat 5.5?
>>可能であれば、tomcat のバージョンを上げてみるか、 mod_proxy_ajp が使える物に変えてみる
>>というのも試してみる価値はあるかもしれません
はい。tomcat5.5を利用しております。またtomcatのversionアップや、mod_proxy_ajpが使える物に変えるなどはせずに対応したいと考えております。

補足日時：2011/02/24 00:31

No.4 回答者： NARH 回答日時： 2011/02/21 02:04

お疲れ様です。

その後の進展はいかがですか？

stack trace を見せていただいので、僕の方でも Tomcat のソースを 5.5, 6.0 7.0 と見てみましたが、Http11 コネクタでデフォルトのタイムアウトが 300000(後 UPLOAD_TIMEOUT も）にされている以外はそれらしい記述はありませんでした。

利用されているコネクタは mod_proxy_ajp でしょうか？
こちらのタイムアウトは httpd.conf Timeout をみるようですが、個別にも設定できるようです。（未検証ですが）

ClientAbortException などで、検索するとちょいちょい起きている現象のようですが、積極的な解決方法は見当たりませんでした。

Linux での soket timeout のデフォルト値は man socket, man connect を見ても無さそうに思えます。
しかし、man socket によると切断に関する SIGPIPE シグナルというものがあります。これを受け取った vm が tomcat に IOException を発生させているような気がします。
（さすがに vm のソースを見みても対策に繋がる気がしないので、推測です）

Linuxサーバサイドの目線ではクライアントによって切断されたように見えている気がしています。

windows 側で firefox + firebug を使って接続のタブや、windows 側での netstat の様子で、どちらが切断したのか、（もしくは変わったデータを投げているとか？）を明らかにすることからアプローチする方が原因究明にはいいかもしれません。

また、ブラウザに対して一気に flush ではなく、バッファに適当なサイズたまった時点で flush しても同じでしょうか？
　

この回答への補足

NARHさん。回答ありがとうございます。
何度も回答させてしまい申し訳ありません。本当に助かります。

>>利用されているコネクタは mod_proxy_ajp でしょうか？
→利用しているコネクタはmod_jkです。

>>Linuxサーバサイドの目線ではクライアントによって切断されたように見えている気がしています。
→IE6の仕様でサーバからレスポンスが5分越えてもかえってこない場合、コネクションを切断するという
記事があり、その対応(レジストリを修正する)したのですが解決できませんでした。

>>windows 側での netstat の様子で、どちらが切断したのか
→windows(クライアント)、Linux(サーバ)でどちらもnetstatをしてみた結果、クライアント上には
サーバの接続先の情報がブラウザを閉じるまで表示されていました。
しかしサーバ上では最初はクライアントの接続先が表示されていましたが、帳票ボタン押下後、
時間が経つと表示されなくなりました。これはサーバ(Linux)が切断しているという認識で
よろしいのでしょうか？
その場合、Linuxのコネクションに関する設定をネットや書籍などから探しているのですが
見当たらない状態です。

>>ブラウザに対して一気に flush ではなく、バッファに適当なサイズたまった時点で flush しても同じでしょうか？
→「flush=outputstreamに書き込んだデータをブラウザに表示する」という認識です。
そのため、出力するデータを全てoutputstreamに書き込んだ後にflushしないといけないのかと
思い、現状はoutputstreamに全て書き込んだ後にflushをしております。

また、今回処理でエラーとなっている箇所は、ブラウザに表示する帳票データをoutputstreamに
書き込もうとした際に、書き込む前の処理が5分以上かかった場合に発生しております。
そのため書き込む前の処理の効率改善を行ったのですが、どうしも書き込む前までに
処理が5分以上かかってしまいます。

現在、Linuxでのコネクション切断の起因となっている設定が見つからない状態のため
帳票出力処理を非同期で行う案が出ています。
できれば既存コードを修正してデグレ発生をさせたくないため(お恥ずかしながらプログラミング
不慣れなため)、設定ファイル(Linuxなど)修正で解決できるならば、その対応を行いたいです。

■帳票出力処理を非同期で行う案について
一旦クライアントに応答し、サーバ側では帳票データを作成しておく、
クライアントは常にサーバ側の帳票データ作成が完了しているかを確認し
完了していたら、ブラウザに帳票データを表示させる。

補足日時：2011/02/21 23:25

No.3 回答者： NARH 回答日時： 2011/02/20 00:33

すみません。

先ほどの No. 2の回答ですが、 httpd.conf は確認済みだそうですが、

http://httpd.apache.org/docs/2.2/ja/mod/core.htm …

を見るとデフォルトが 300 なので、記述がなくデフォルトしているかもしれない事もあるので、念のため確認してみてください。

この回答への補足

補足回答ありがとうございます。

>>httpd.conf は確認済みだそうですがTimeOutのデフォルトが 300 なので、記述がなくデフォルトし>>ているかもしれない事もあるので、念のため確認してみてください。
→httpd.confのTimeOutについて確認してみましたが1800(30分)となっていたため、httpd.confには
問題ないと判断しました。
※httpd.confのKeepAliveについてもONになっており、KeepAliveTimeoutを長くしても
同様のエラーが発生しました。
また、Apache側がコネクションを切断しているのかと思い、Tomcatに
直接アクセス(ポート指定：8080)し帳票出力させました。その結果、
次は「connection reset」というエラーが発生しました。
おそらくTomcatでは「connection reset」になりApacheにその結果を返した際にApache側で
「broken pipe」というエラーにしていると思われます。

上記の事からTomcat又はLinux側がコネクションを切断しているという想定をしておりますが
コネクションタイムアウトさせている設定箇所が不明のため解決できない状態です。

補足日時：2011/02/20 04:01

No.2 回答者： NARH 回答日時： 2011/02/20 00:18

Exception の stack trace があるともう少し状況がわかりそうですが、

java.net.SocketException: Broken pipe

が Exception なのですよね？
同じ java.net パッケージには SocketTimeoutException というものがあります。
もし Timeout に起因するものでしたらこちらの Exception が投げられるのではないでしょうか？
また、Broken pipe というメッセージから、開かれたsocket が（おそらく相手側の都合により）閉じられたため、流しこむデータの行き先がなくなったよとの意味合いに感じます。

Linux OS 側では /proc/sys/net カーネルパラメータを見てみましたが、バッファサイズのチューニングはありますが、タイムアウトに関してはアプリケーションに任せていると思います。


ふと思ったのですが、apache にも Timeout がありますが、ブラウザと Tomcat を橋渡ししている Apache が待ちきれなかったって事はないでしょうか？

この回答への補足

回答ありがとうございます。

>>Exception の stack trace があるともう少し状況がわかりそうですが、
→すみません。かんじんのログを記述しておりませんでした。以下がエラー時のログです。※ログが長くて入りきれないので短縮します。

/print/ReportForm/Validate.do
ExceptionConverter: ClientAbortException: java.net.SocketException: Broken pipe
at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:370)
at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:432)
at org.apache.tomcat.util.buf.ByteChunk.append(ByteChunk.java:347)
at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:396)
at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:385)
at org.apache.catalina.connector.CoyoteOutputStream.write

＝＝＝＝＝＝＝＝＝＝＝＝短縮＝＝＝＝＝＝＝＝＝＝＝＝＝

at net.sf.jasperreports.engine.JasperExportManager.exportReportToPdfStream(JasperExportManager.java:167)
at jp.dogsManagement.common.util.PrintUtil.printPreview(PrintUtil.java:79)
at jp.dogsManagement.controller.action.print.ReportAction.pushMainBook(ReportAction.java:845)

＝＝＝＝＝＝＝＝＝＝＝＝短縮＝＝＝＝＝＝＝＝＝＝＝＝＝

Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.apache.jk.common.ChannelSocket.send(ChannelSocket.java:538)
at org.apache.jk.common.JkInputStream.doWrite(JkInputStream.java:162)
at org.apache.coyote.Response.doWrite(Response.java:560)
at org.apache.catalina.connector.OutputBuffer.realWrite

>>Broken pipe というメッセージから、開かれたsocket が（おそらく相手側の都合により）閉じられたため、流しこむデータの行き先がなくなったよとの意味合いに感じます。
→相手側(クライアント)の都合により閉じられたと当初は思っていたのですがIEの原因でもない
みたいで…。そのためサーバ(Linux)がコネクションを閉じてると思ったのですが、どの箇所を
見ればいいか分からなくて…。

>>タイムアウトに関してはアプリケーションに任せていると思います
→アプリケーションの設定を見たのですがこれといってタイムアウトの原因となるのが
見つかりません。/proc/sys/net カーネルパラメータ以外に考えられる箇所はあります
でしょうか?よろしくお願いします。

補足日時：2011/02/20 03:47