MilkyStep Official Community

メルマガ・ステップメール配信ソフトMilkyStep利用者のコミュニティです。

バージョンアップしたら、メルマガ配信が不測のエラーで停止します…

最近、久しぶりにMilkyStepをバージョンアップしました。毎週金曜に行っているメルマガ配信を行ったところ、400通配信の200通強のところで、不測のエラーで停止してしまいます。午前と、午後と2回行いましたが、1回目は210通、2回目は204通目でダウンしています。サーバーはロリポップのチカッパプランで、一時間の制限メールは1000通です。10通発行後、72秒休んでいますので、制限よりかなり少なめです。また、20秒でプロセスを切り替えるようにしています。バージョンアップ以前と、この設定は変えていません。

金, 5月 25 2012 » ユーザからの投稿

10 Responses

  1. Igreks.Inc 5月 25 2012 @ 6:46 PM

    平素はMilkyStepをご利用いただきありがとうございます。

    大変恐縮ですが、基本的にバージョンアップによって配信ロジック、特にプロセスの保持に関してはほとんど変更は行っておりません。

    また他のご利用者からも、現在のところ同様の現象は報告されておりません。

    まず、最初にご確認いただきたいのは、配信履歴詳細画面から、「この記事を配信した読者一覧」のアイコンをクリックし、総件数が400通(配信予定の総数)とだいたい合っているかご確認ください。
    もしこれがおかしな数字だと、バージョンアップがうまくいっていない可能性も考えられます。

    また、配信面から考えると、200通まで送信されているということから、プロセスの自動切り替え時に問題が生じてはいないように思われます。
    仮にプロセス切替時に不具合があれば、20秒前後で不具合が発生すると思われます。

    それと、もし負荷の増大が原因でサーバが落ちてしまえば、コントロールパネルにもアクセスできなくなりますし、お客様のWEBサイトにも支障が出ると思われます。

    基本的に、「不測のエラー」の原因としては、配信中のプロセスがサーバ上に存在せず、かつ配信が最後まで完了していない場合に表示されます。

    配信順序は、読者リストの新しい方(最近登録された方)から配信されますので、もしリストの210件目以降の最初の方(古い方)にお客様の確認用のメールアドレスを登録されていて、そこに配信されていれば、「不測のエラー」になっているにも関わらず、実際は配信は継続されていたということになり、システムの不具合の可能性が高いと言えます。

    もしそうでなければ、2回とも同じ通数あたり、しかも200前後というある程度切りよい数字ので止まっていることから、外部からなんらかの規制が入ったのではないかと思われます。

    こちらのページ
    http://lolipop.jp/order/kinshi/
    を見る限り規制がかかる理由は無いように思われますが、最近チカッパがロリポップに統合されたこともあり、CGIなどから大量にメールを配信すること自体に何らかの上限を決めて監視している可能性もあります。

    大変お手数ですが、一度今回の現象を具体的にサーバ管理者に伝えていただき、管理者側で何らかの規制をかけていないかご確認いただければ幸いです。

  2. 齋藤@沖縄 5月 26 2012 @ 4:14 AM

    数日前、v1.44からv1.58へバージョンアップしました。操作画面が使い難くなったなと思いながら、午前中の配信を済ませたのですが、不測のエラーとなりました。そこで。v1.59のリリースを知ったので、バージョンアップして午後に再配信をしました。配信開始して、1時間程経過してから再度コントロールパネルを開くと、デザインが一新されていたのにまず驚きました。配信したときと、全く違う綺麗で洗練された操作画面になっていたからです。バージョンアップがうまく行っていないのでしょうか。

    「この記事を配信した読者一覧」で確認した総件数は、配信予定総数と「だいたい合って」はいますが、同じではありません。一割くらい少なめです。なぜ「だいたい」なのでしょう。

    こちらへの投稿後、ロリポップ側には何かの規制に触れていないか確認中です。

  3. 齋藤@沖縄 5月 26 2012 @ 11:01 AM

    訂正です。

    コントロールパネルに表示される、不測のエラーが起こったメルマガの配信履歴には、「到達部数/配信部数」が「204/376」、到着率が54.25%となっていますが、「この記事を配信した読者一覧」には、376名分全員が記載されています。これは、どういうことなんでしょう。「不測のエラー」と表示はされるが、配信はされたという意味でしょうか?

    また当方は、MilkyStepで4つのメルマガを管理しており、そのうち2つが標準メルマガ、もう2つはステップメールです。これらのメルマガの3つは、「20秒で自動的にプロセスを切り替える」設定になっていましたが、ステップメールのうちの1つが、プロセスを切り替える設定になっていませんでしたが、関係ありますでしょうか。このステップメールは、昨日のメルマガとは別物で、1ヶ月に一回だけ、数名に対して配信するものです。

    もしかして、4つのメルマガのプロセス切り替え設定時間の合計値が、サーバー規定の時間制限未満にする必要があるのでしょうか。だとすると、ロリポップは30秒ですので、1メルマガあたり7.5秒未満に設定する必要がありそうなんですが…。

  4. Igreks.Inc 5月 27 2012 @ 9:30 PM

    齋藤@沖縄 さま

    > 配信開始して、1時間程経過してから再度コントロールパネルを開くと、
    > デザインが一新されていたのにまず驚きました。配信したときと、
    > 全く違う綺麗で洗練された操作画面になっていたからです。
    > バージョンアップがうまく行っていないのでしょうか。

    1.58から1.59にかけてはデザインに関してはほとんど変更して
    おりませんので、おそらく1.44から1.58にバージョンアップ
    したときに変更されたデザインが、1.59にした後にキャッシュが
    再読み込みされて表示されたのだと思われます。
    従って、これをもってバージョンアップがうまくいっていないと
    いうわけではないと思われます。

    > 「この記事を配信した読者一覧」で確認した総件数は、
    > 配信予定総数と「だいたい合って」はいますが、同じではありません。
    > 一割くらい少なめです。なぜ「だいたい」なのでしょう。

    失礼いたしました。
    あまりにも数字が違うケースを考えて、「だいたい」と
    書いてしまいました。
    原則としては、配信予定読者数とぴったり合っていなければ
    なりません。

    > 訂正です。
    >
    > コントロールパネルに表示される、不測のエラーが起こったメルマガの
    > 配信履歴には、「到達部数/配信部数」が「204/376」、到着率が54.25%と
    > なっていますが、「この記事を配信した読者一覧」には、376名分全員が
    > 記載されています。これは、どういうことなんでしょう。
    > 「不測のエラー」と表示はされるが、配信はされたという意味でしょうか?

    ややこしくてすいません。
    これは、配信が開始される前の状態としては、正しい動作になります。

    「この記事を配信した読者一覧」に記録される読者は、配信処理が完了した
    順に順次データが追加されているわけではなく、配信直前に配信対象として
    抽出された読者のデータがそのまま一気にセットされます。

    従いまして、不測のエラーとなり到達数が中途半端な数字で止まっていた
    場合でも、「この記事を配信した読者一覧」には対象読者376名分が配信前に
    セットされていますので、表示の件数としては配信予定読者数と同じになり、
    正しいということになります。

    この「この記事を配信した読者一覧」を確認する機能を追加したのが
    1.44より後のバージョンでしたので、ここの表示がおかしい=バージョンアップが
    正しく行われていない、という懸念をしたまででございます。

    逆に「到達部数/配信部数」の分子の数は、1件1件の配信処理が終わるたびに
    数が追加されていきますので、ここに表示されている数が、実質の配信処理が
    完了した数と考えていただいて結構です。

    書き込みしていただいた状況からですと、バージョンアップがうまくいって
    いないと断定するいう判断材料もありませんので、今のところ配信前までは
    正常に動作していたが、配信中に何らかの原因によりプロセスが停止した
    いうのが妥当な線かもしれません。

    > もしかして、4つのメルマガのプロセス切り替え設定時間の合計値が、
    > サーバー規定の時間制限未満にする必要があるのでしょうか。
    > だとすると、ロリポップは30秒ですので、1メルマガあたり7.5秒未満に
    > 設定する必要がありそうなんですが…。

    「30秒」というのは1プロセス当たりの制限ですので、
    これはまずないかと思います。

  5. Igreks.Inc 5月 27 2012 @ 9:49 PM

    追記です。

    その他、可能性として考えられるのは、WEBサーバの生成する子プロセス数の制限です。

    当ソフトのプロセス切替処理では、子プロセスの生成に成功した場合に、実行中の自らのプロセスを切りますので、WEBサーバのプロセス同時実行数というよりは、純粋に作成数の制限と考えるべかと思います。

    また、共用サーバですので、自分が多くのプロセスを起動させていなくても、他の利用者が同時に多くのプロセスを走らせていた場合などで、これ以上WEBサーバや他のデーモンで新しいプロセスを作れない状況でMilkyStepがプロセス切替処理を行おうとした時、MilkyStepでは自動的に約1秒処理を引きのばして、子プロセスが作れるようになるまで待機します。
    これが繰り返されているうちに30秒が経過してプツンということはあるかと思います。

    仮にそうであった場合は、もはやアプリケーションのレベルではどうにもならないのが現状です。

    これらの発生した場合は、基本的にWEBサーバなどのエラーログに記録されるかと思います。

  6. 齋藤@沖縄 5月 29 2012 @ 1:38 PM

    ロリポップから返事がありました。

    —–ここから—–

    お問い合わせ頂いた、プロセスが強制終了されている現象について、調査いたしました。

    ・2012年5月25日 9時40分04秒に起動後、約1500秒後
    ・2012年5月25日 14時10分31秒に起動後、約1400秒後

    これらを調査した結果、サーバー上でご利用頂いたCGIは、弊社サーバー側で処理時間による停止は行なっていない事を確認いたしました。

    そのため、ご連絡い頂いた情報からの推測となりますが、CGIから何らかの問題が発生し、異常停止したものと思われます。

    お手数をお掛けしますが、CGIの開発配布元にて、ご確認頂くことをお勧めします。

    —–ここまで—–

    上記における約1500秒、約1400秒の論拠は、10通毎に72秒停止する設定から来るものです。

    1回目は、5月25日の午前9時40分04秒に起動したCGIで、210通のメールを配信してエラーになっており、

    また2回目は、同日の14時10分31秒に起動したCGIで、204通目にエラーになったからです。

    特に2回目の、10通の途中の4通目で切れているのが、意味があるような気がしてなりません。

    貴社が指摘されるような、プロセスの複雑な切り替えに依存する問題とは違う、もっとシンプルな問題なのではないでしょうか。バージョン1.44では、問題無かった事は確かなのですから。

    1.44にバージョンを戻すことは、できませんか?

  7. Igreks.Inc 5月 30 2012 @ 2:46 AM

    齋藤@沖縄 さま

    お問合せの返信内容をご提示いただきましてありがとうございました。
    この件について、弊社の方で再度調査させていただきました。

    結果といたしまして、当ソフトでのMySQLコネクションの取扱いに
    不備がありエラーが発生していた模様です。

    プロセスの強制停止を疑い、お客様のお手を煩わせてしまったこと、
    深くお詫び申し上げます。申し訳ございません。

    また、今回のご報告により結果的に当ソフトの品質向上に
    つながり、ご協力に対し併せて御礼申し上げます。

    調査の経緯といたしまして、まず、齋藤@沖縄さまの状況に
    なるべく近い条件で同様の現象が発生するかどうかを
    調査いたしました。

    読者数:400名弱
    送信設定:10通送信したら72秒待つ
    SMTPサーバ:指定しない(Localhost)
    プロセス切替:約20秒でプロセスを切り替える

    この条件で行ったところ、210通を超えたところでは不測のエラー
    にはなりませんでしたが、280通を超えたところで不測のエラーが
    発生いたしました。

    この時、配信履歴詳細画面をリロードしながら配信数を
    確認しておりましたが、280通を超えたところで
    「mysql failed: too many connections」
    エラーが発生し、apacheのログにも記録されました。

    このことから、MySQLコネクションの同時接続数が上限を
    超えたという疑いが発生し、逆算してみたところ、
    280通÷10通×72秒=2016秒(エラーが発生するまでに経過した秒数)
    2016秒÷20秒≒100(プロセス切替を行った回数)
    となりました。

    弊社のMySQL設定はデフォルトのため、MySQLのMax_Connectionは
    100となりますので、ほぼつじつまが合うことになります。

    もっと分かりやすく、
    プロセス切替:約2秒でプロセスを切り替える
    の条件で行ったところ、予想通り200秒を経過したあたりで
    同様のエラーが発生いたしました。

    本来であれば、プロセス切替時に、元々保持していたMySQL
    コネクションは破棄されなければならないところ、最近の
    バージョンアップにてコネクション処理の一部を改良したことが
    原因で、このコネクションが破棄されず、プロセス切替後も
    継続して保持されており、結果Max_Connection(上限値)を
    超えてしまったと思われます。

    プロセスの切り替えで、Unixのプロセス自体は継続して保持されて
    いませんでしたが、MySQLのサービス内で累積してセッションを
    張っていたと思われます。

    このことから、プロセス切替処理を行う際、子プロセス生成&
    変数のコピー後、今まで保持していたコネクション
    (データベースハンドル)を明示的にCloseするよう、新しく
    処理を追加、修正いたしました。

    この後、再度上記の条件のもと配信を行ったところ、
    280通を超えても処理が問題なく継続され、最後まで配信を
    完了することができました。

    齋藤@沖縄さまの環境の場合、210通あたりで不測のエラーと
    なっていることから、
    210通÷10通×72秒=1512秒(エラーが発生するまでに経過した秒数)
    1512秒÷20秒≒75(プロセス切替を行った回数)
    となり、Max_Connectionの値が70~80に設定されているのでは
    ないかと推測いたします。

    これにつきましては、すでに修正版をアップしておりますので、
    大変お手数ではございますが、再度最新バージョン(Ver1.59)へ
    バージョンアップしていただきますようお願いいたします。

    この度は、たびたびお手数をおかけいたしましてご迷惑を
    おかけいたしました。

    もし万が一状況が改善されない場合、再度ご報告をいただければ
    幸いです。

    なお、
    > 1.44にバージョンを戻すことは、できませんか?
    とのことですが、1.44時よりも現在の方が、かなり配信効率が
    改善されておりますので、サーバへの負荷低減および弊社の希望
    という点も踏まえまして、なるべく最新版をご利用いただければ
    幸いです。

  8. 齋藤@沖縄 5月 30 2012 @ 3:33 AM

    丁寧なご調査、有難うございました。
    1.59にバージョンアップし、次回配信日となる6月1日に試し、結果をご報告いたします。

  9. 齋藤@沖縄 6月 1 2012 @ 10:28 AM

    只今、無事配信を終えました。
    有難うございました。

    配信数:376
    10通送信したら72秒待つ
    約20秒でプロセスを切り替える

  10. Igreks.Inc 6月 1 2012 @ 11:03 AM

    齋藤@沖縄さま

    ご丁寧にご報告いただきありがとうございました。
    うまくいったようで幸いです。

Login