From nakano.hiroaki ＠ nttcom.co.jp Mon Dec 1 11:39:44 2014 From: nakano.hiroaki ＠ nttcom.co.jp (Hiroaki Nakano) Date: Mon, 1 Dec 2014 11:39:44 +0900 Subject: [Ultramonkey-l7-develop 1080] Re: tmp_v3.1.2-1 upload In-Reply-To: <5475524C.30102@lab.ntt.co.jp> References: <54110A0F.2050109@nttcom.co.jp> <5412ABDA.2070909@lab.ntt.co.jp> <541A68D6.8010904@nttcom.co.jp> <542BA4B0.8010802@nttcom.co.jp> <542BAA09.5090803@nttcom.co.jp> <542D25BC.9040201@lab.ntt.co.jp> <5433A024.2010300@nttcom.co.jp> <5434DF5C.9000003@nttcom.co.jp> <54748F02.5020309@iwao.net> <5475524C.30102@lab.ntt.co.jp> Message-ID: <547BD4F0.9020500@nttcom.co.jp> 中野@幕張です。 ブランチmodify_ssl_shutdownをv3.1.2-develにマージしました。 リリース時には、CHANGESとかを整理してmasterにマージ予定です。 (2014/11/26 13:08), Hibari Michiro wrote: > たるすぴ様 > > 雲雀です。 > 詳細な解析ありがとうございます。 > >> https://sourceforge.jp/ticket/browse.php?group_id=1951&tid=34416 > チケットに添付しているpatchですが、まだgitには > 上がっていないので、適当にブランチを切ってそちらに > pushしたいと思います。 > > > (2014/11/25 23:15), Hiroaki Nakano wrote: >> たるすぴです。 >> >> Windows7上のChromeでF5をキーリピートで連打させると再現しました。 >> ただし、後ろのWebサーバはKeepAlive Onにしないとだめで、 >> KeepAliveのタイムアウトを過ぎたりすると、症状が治まったり >> しました。 >> >> そして、雲雀さんのパッチを適用したら再現しないことを確認しました。 >> >> >> (解析) >> Cpuコアの一つがほぼ100%usedになったところで、core dump。 >> 最初にifdef DEBUGを外したバイナリで実施すると、try_againの >> 中のdebug文用mallocのところでした。 >> ifdef DEBUGを復活させて再現させると、ecをとってくる手前の >> ec取得メソッド呼び出しで、SSL_shutdownはread途中、Unwindの中 >> にいました。 >> >> (gdb) p {SSL }0x7ff40c709170 >> $1 = { >> version = 769, >> type = 8192, >> method = 0x3261255840, >> rbio = 0x7ff40c02c860, >> wbio = 0x7ff40c02c860, >> bbio = 0x0, >> rwstate = 3, >> in_handshake = 0, >> handshake_func = 0x326101cd30, >> server = 1, >> new_session = 0, >> quiet_shutdown = 0, >> shutdown = 1, >> state = 3, >> rstate = 240, >> init_buf = 0x0, >> init_msg = 0x7ff40c73c1d4, >> init_num = 0, >> init_off = 0, >> packet = 0x7ff40c145773 "\027\003\001\001 ＠ ET /favicon.ico >> HTTP/1.1\r\nHost: 192.168.200.130\r\nConnection: keep-alive\r\nAccept: >> */*\r\nUser-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) >> AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.122 S"..., >> packet_length = 0, >> s2 = 0x0, >> s3 = 0x7ff40c0d3260, >> d1 = 0x0, >> read_ahead = 0, >> msg_callback = 0, >> msg_callback_arg = 0x0, >> hit = 1, >> param = 0x7ff40c066120, >> cipher_list = 0x0, >> cipher_list_by_id = 0x0, >> mac_flags = 0, >> enc_read_ctx = 0x7ff40c18e400, >> read_hash = 0x7ff40c018500, >> expand = 0x0, >> enc_write_ctx = 0x7ff40c4aa9a0, >> write_hash = 0x7ff40c641300, >> compress = 0x0, >> cert = 0x7ff40c002320, >> sid_ctx_length = 11, >> sid_ctx = "ultramonkey", '\000', >> session = 0x7ff40c72d770, >> generate_session_id = 0, >> verify_mode = 0, >> verify_callback = 0, >> info_callback = 0, >> error = 0, >> error_code = 0, >> kssl_ctx = 0x7ff40c282b20, >> psk_client_callback = 0, >> psk_server_callback = 0, >> ctx = 0x1c43e10, >> debug = 0, >> verify_result = 0, >> ex_data = { >> sk = 0x0, >> dummy = 0 >> }, >> client_CA = 0x0, >> references = 1, >> options = 18446744071578849271, >> mode = 3, >> max_cert_list = 102400, >> first_packet = 0, >> client_version = 769, >> max_send_fragment = 16384, >> tlsext_debug_cb = 0, >> tlsext_debug_arg = 0x0, >> tlsext_hostname = 0x0, >> servername_done = 0, >> tlsext_status_type = -1, >> tlsext_status_expected = 0, >> tlsext_ocsp_ids = 0x0, >> tlsext_ocsp_exts = 0x0, >> tlsext_ocsp_resp = 0x0, >> tlsext_ocsp_resplen = -1, >> tlsext_ticket_expected = 0, >> tlsext_opaque_prf_input = 0x0, >> tlsext_opaque_prf_input_len = 0, >> tlsext_session_ticket = 0x0, >> tls_session_ticket_ext_cb = 0, >> tls_session_ticket_ext_cb_arg = 0x0, >> tls_session_secret_cb = 0, >> tls_session_secret_cb_arg = 0x0, >> initial_ctx = 0x1c43e10 >> >> (gdb) p sys_error_code >> $10 = >> (gdb) p is_operation_done >> $11 = false >> (gdb) p is_read_needed >> $12 = >> (gdb) p is_write_needed >> $13 = false >> (gdb) p is_shut_down_received >> $15 = false >> (gdb) p is_shut_down_sent >> $16 = >> >> int start() >> { >> int rc = primitive_( session_ ); >> ... >> if (!is_operation_done&& !is_write_needed) >> { >> // We may have left over data that we can pass to SSL immediately >> >> >> if (recv_buf_.get_data_len()> 0) { >> // Pass the buffered data to SSL >> >> >> int written = ::BIO_write >> ( >> ssl_bio_, >> recv_buf_.get_data_start(), >> recv_buf_.get_data_len() >> ); >> >> if (written> 0) >> { >> if (!BIO_should_retry(ssl_bio_)) >> { >> // Some serios error with BIO.... >> >> >> return handler_(boost::asio::error::no_recovery, 0); >> } >> } >> >> return start(); } >> else if (is_read_needed || (is_shut_down_sent&& >> !is_shut_down_received)) >> { >> => return read_(); >> } >> } >> >> recv_buf_.get_data_len()が0以下でis_read_neededフラグがたつのが >> ちょっと変ですが、まあ大まかには間違ってなさそう。 >> ハーフクローズのclose notifyはreadで受け取ることが可能・・・なはず。 >> shutdownのハーフクローズはrecvバッファとは関係ないので、本来なら >> recvバッファが正かどうかとの排他にしちゃいかんとは思いますが。 >> >> さらに言うと、その前のis_operation_doneとis_write_neededの両方が >> falseのときっていう条件がいまいちです。 >> read/writeはともかくshutdownでは関係ない・・・ >> どっちかがtrueだとハーフクローズでclose notifyを受け取ることがなくなる。 >> 大体、is_operation_doneがtrueのときはwriteしようと思っても >> SSLソケットは閉じちゃっててwrite出来ないと思う。 >> >> SSL_shutdownの返り値が1,0,-1の3値なのを、booleanのtrueとfalseの >> 2値に丸めちゃって、状態をカバーしきれてない感じです。 >> あと、read/writeとshutdownはかなりリカバリ処理違うのに、無理やり >> 同じメソッドにまとめようとして、結果としてメソッド内にif文で場合分け >> してshutdownだけ別の処理を書くという・・・まるでconstractorに全処理を >> 書いちゃったかのような状態になっています。 >> >> いけてない・・・ >> >> このままclose notifyが失われて再送されてこないなら、asyncに >> して待機させておくのがいいかもですね。 >> >> ということで、雲雀さんのasync_shutdownにするパッチを対処案とするのが >> 現状では一番現実的な気がします。 >> >> (2014/10/08 15:53), Hiroaki Nakano wrote: >>> 中野@幕張です。 >>> >>> man 3 SSL_shudwonを見ていると、以下の記述がありました。 >>> >>> ------ >>> RETURN VALUES >>> The following return values can occur: >>> >>> ...(snip) >>> >>> 3. -1 >>> >>> The shutdown was not successful because a fatal error occurred either >>> at the protocol level or a connection failure occurred. It >>> can also occur if action is need to continue the operation for non-blocking BIOs. >>> Call SSL_get_error(3) with the return value ret to find out the reason. >>> ------ >>> >>> ということは、まだBIOの中にデータが残っているうちにshutdownが走っちゃいましたかね。 >>> >>> しかしBIOの中に残した状態を再現するとなると、難しくて思いつかない・・・ >>> >>> boost的にはBIO_writeしたあとなんで処理は終わってるんだけど、 >>> libsslの内部にあるBIOバッファからkernelのsocketシステムコールにはデータを >>> 書き込めてない状態でSSL_shutdownが走らないといけないんだよね。 >>> >>> 環境だけで作るのむずい。 >>> >>> (2014/10/07 17:11), Hiroaki Nakano wrote: >>>> 中野です。 >>>> おつです。 >>>> >>>> なかなか再現環境が組めないですorz >>>> 発見者はどんな環境で発生したんでしょう。。。 >>>> >>>> up_thread_client_disconnectが呼ばれているところを >>>> ピックアップしてみました。 >>>> >>>> 呼び出し箇所： >>>> up_thread_run >>>> 　接続失敗時(L861) >>>> up_thread_client_accept_fail_event >>>> 　handshake_error_codeがtry_againじゃないとき(L1233) >>>> up_thread_client_receive >>>> 　recv_size<=0のとき(L1354) >>>> 　ecがあってeofのとき(L1358) >>>> 　ecがあってeofじゃなくてtry_againじゃないとき(L1379) >>>> down_thread_client_disconnect >>>> 　正常ルート冒頭(L3186) >>>> up_thread_client_handle_async_read_some >>>> 　errorがあってtry_againじゃないとき(L3711, L3713) >>>> >>>> このあたりが発生しそうな環境を作ったらいけるかな？ >>>> 単純に高負荷掛けただけじゃ再現できませんでした。 >>>> >>>> 似たような事例を探してたら、TomcatのwriteのEAGAINでやっぱ >>>> AGAINループになってたみたいです。 >>>> https://issues.apache.org/bugzilla/show_bug.cgi?id=52856 >>>> >>>> こいつは対処でsleep入れてるなぁ・・・ >>>> >>>> 引き続き再現方法を探してみます。 >>>> >>>> (2014/10/02 19:15), Hibari Michiro wrote: >>>>> 雲雀です。 >>>>> >>>>> v3.1.2のリリースですが、 >>>>> もう一か所 直したい箇所があるので少々お待ちください。 >>>>> >>>>> その直したい箇所についてはチケット#34416で起票しました。 >>>>> https://sourceforge.jp/ticket/browse.php?group_id=1951&tid=34416 >>>>> >>>>> 以上、取り急ぎ。 >>>>> (2014/10/01 16:15), Hiroaki Nakano wrote: >>>>>> 中野@幕張です。 >>>>>> >>>>>> コミュニティリーダーからストップかかったので >>>>>> リリース遅らせます。 >>>>>> すみません。 >>>>>> >>>>>> 詳細は別途。 >>>>>> >>>>>> (2014/10/01 15:52), Hiroaki Nakano wrote: >>>>>>> 中野@幕張です。 >>>>>>> こんにちは。 >>>>>>> >>>>>>> とくに反応ないのでリリースしますね。 >>>>>>> >>>>>>> >>>>>>> (2014/09/18 14:08), Hiroaki Nakano wrote: >>>>>>>> 中野@幕張です。 >>>>>>>> こんにちは。 >>>>>>>> >>>>>>>> (2014/09/12 17:16), Hibari Michiro wrote: >>>>>>>>> 中野様 >>>>>>>>> >>>>>>>>> 雲雀です。 >>>>>>>>> お世話になっております。 >>>>>>>>> >>>>>>>>> v3.1.2-1のアップロードありがとうございました。 >>>>>>>>> 手元環境でざっと動作させてみたところ、 >>>>>>>>> 問題なく動作しているようでした。 >>>>>>>>> >>>>>>>>>>> 不具合等なかった場合、リリース前に太田さんに個別に >>>>>>>>>>> 連絡して、事象が直っているか確認を取ろうと思います。 >>>>>>>>> >>>>>>>>> そうですね。 >>>>>>>>> 何のため、太田様にもtmpに上げている >>>>>>>>> バイナリを共有し、事象が改善されたか >>>>>>>>> 確認していただくのが良いと思います。 >>>>>>>> >>>>>>>> 確認していただきました。事象が解消されたとのことです。 >>>>>>>> >>>>>>>> ということで、このバイナリをそのままv3.1.2-1として >>>>>>>> リリースしたいと思うのですが、いいでしょうか。 >>>>>>>> >>>>>>>> あと、gitツリーのmasterのHEADに、v3.1.2-1のタグを設定する >>>>>>>> つもりです。 >>>>>>>> >>>>>>>> # 個人的都合で、来週〜29日まで中野がrpmビルド環境を使えない >>>>>>>> # ので、明日か、それを過ぎたら10月になります。 >>>>>>>> >>>>>>>> >>>>>>>>> 以上、宜しくお願い致します。 >>>>>>>>> >>>>>>>>> (2014/09/11 11:33), Hiroaki Nakano wrote: >>>>>>>>>> UM-L7 開発者のみなさん >>>>>>>>>> >>>>>>>>>> 中野@幕張です。 >>>>>>>>>> こんにちは。 >>>>>>>>>> >>>>>>>>>> users MLで太田さんからご指摘のあった >>>>>>>>>> v3.1.0リリースで#30300がデグレードした件について、 >>>>>>>>>> 再度#30300の修正を入れなおしたv3.1.2-1版の >>>>>>>>>> x86_64 rpmバイナリを以下に置きました。 >>>>>>>>>> >>>>>>>>>> http://ultramonkey-l7.sourceforge.jp/_tmp/tmp_uml7_3_1_2-1 >>>>>>>>>> >>>>>>>>>> 不具合等無いか、ご確認ください。 >>>>>>>>>> >>>>>>>>>> 不具合等なかった場合、リリース前に太田さんに個別に >>>>>>>>>> 連絡して、事象が直っているか確認を取ろうと思います。 >>>>>>>>>> >>>>>>>>>> そのうえで、リリースという流れでいいでしょうか。 >>>>>>>>>> >>>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>> >>>>>>> >>>>>> >>>>>> >>>>> >>>>> >>>> >>>> >>> >>> >> >> _______________________________________________ >> Ultramonkey-l7-develop mailing list >> Ultramonkey-l7-develop ＠ lists.sourceforge.jp >> http://lists.sourceforge.jp/mailman/listinfo/ultramonkey-l7-develop >> >> > > -- 中野 宏朗 (NAKANO Hiroaki) NTTコムウェア 品質生産性技術本部 技術SE部 基盤ソフトSE・OSS部門 OSS・DB技術担当 Tel: 043-211-2452 (Ext: 特番+26-8341), Fax: 043-211-5086 Zip/Address: 261-0023 千葉県千葉市美浜区中瀬1-6 NTT幕張ビル21F-En From nakano.hiroaki ＠ nttcom.co.jp Mon Dec 1 11:43:05 2014 From: nakano.hiroaki ＠ nttcom.co.jp (Hiroaki Nakano) Date: Mon, 1 Dec 2014 11:43:05 +0900 Subject: [Ultramonkey-l7-develop 1081] Re: tmp_v3.1.2-1 upload In-Reply-To: <54110A0F.2050109@nttcom.co.jp> References: <54110A0F.2050109@nttcom.co.jp> Message-ID: <547BD5B9.30606@nttcom.co.jp> UM-L7 開発者のみなさん 中野@幕張です。 #30300に加え、#34416のパッチも加えてバイナリを作り直し、 上書きして置き直しました。 http://ultramonkey-l7.sourceforge.jp/_tmp/tmp_uml7_3_1_2-1 不具合等無いか、ご確認ください。 (2014/09/11 11:33), Hiroaki Nakano wrote: > UM-L7 開発者のみなさん > > 中野@幕張です。 > こんにちは。 > > users MLで太田さんからご指摘のあった > v3.1.0リリースで#30300がデグレードした件について、 > 再度#30300の修正を入れなおしたv3.1.2-1版の > x86_64 rpmバイナリを以下に置きました。 > > http://ultramonkey-l7.sourceforge.jp/_tmp/tmp_uml7_3_1_2-1 > > 不具合等無いか、ご確認ください。 > > 不具合等なかった場合、リリース前に太田さんに個別に > 連絡して、事象が直っているか確認を取ろうと思います。 > > そのうえで、リリースという流れでいいでしょうか。 > > -- 中野 宏朗 (NAKANO Hiroaki) NTTコムウェア 品質生産性技術本部 技術SE部 基盤ソフトSE・OSS部門 OSS・DB技術担当 Tel: 043-211-2452 (Ext: 特番+26-8341), Fax: 043-211-5086 Zip/Address: 261-0023 千葉県千葉市美浜区中瀬1-6 NTT幕張ビル21F-En