Forums: POPFile 初学者専用 (Thread #13255)

いつの間にか終了してしまいます (2006-12-27 18:50 by gen11 #26830)

あちこち検索してみたのですが、それらしい情報を見つけられませんでしたので、こちらにご相談させていただきます。

pop3サーバー機(Linux)にインストールして、pop3プロキシとして使用しています。
稼動をはじめて一週間くらいしますが、気が付くとPOPFileが終了しています。
日に数回あるので、毎回冷や汗ながら再起動しています。

popクライアントが100以上ありますので、もしかしたら負荷が高すぎなのでしょうか。
テスト的に運用した時は(別サーバーでクライアント数はもっと少なかったとはいえ)このような現象はありませんでした。

logレベルを2に上げて、プロセス終了に気づいた時のlogを見てみましたが、エラーらしきものはありません。
以下、最終の10行です。
> 2006/12/27 15:16:34 17872: mq: 377: post CMPLT (29553)
> 2006/12/27 15:16:34 17872: mq: 388: dropping post CMPLT (29553)
> 2006/12/27 15:16:34 17872: mq: 258: Done with 29553 (1 to go)
> 2006/12/27 15:16:34 29551: pop3: 209: Command: --QUIT--
> 2006/12/27 15:16:34 29551: pop3: 301: QUIT[0d][0a]
> 2006/12/27 15:16:34 29551: pop3: 658: Read slurp data +OK Pop server at ***.*******.co.jp signing off.[0d][0a]
> 2006/12/27 15:16:34 29551: pop3: 301: +OK Pop server at ***.*******.co.jp signing off.[0d][0a]
> 2006/12/27 15:16:34 29551: mq: 377: post CMPLT (29551)
> 2006/12/27 15:16:34 29551: mq: 392: sending post CMPLT (29551) to parent GLOB(0xacb6884)
> 2006/12/27 15:16:34 29551: pop3: 668: POP3 proxy done

クライアントが多すぎて、どのタイミングで終了してしまうのか把握できていませんが、どこか確認するべきことはあるでしょうか。

環境:
Linux:RedHatEnterpriseLinuxES4
popfile:0.22.4
kakasi:2.3.4
perl:v5.8.5 built for i386-linux-thread-multi
DBI:1.40
DBD::SQLite:0.31
Digest::base:1.00
Digest::MD5:2.33
HTML::Tagset:3.03
MIME::Base64:3.01
MIME::QuotedPrint:3.01
Date::Parse:2.27
HTML::Template:2.8
Text::Kakasi:2.04
Encode:2.01
起動スクリプトは↓ページのを使っています。
http://popfile.sourceforge.net/cgi-bin/wiki.pl?RedHat

Reply to #26830×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2006-12-27 19:14 by amatubu #26831)

原因はわからないですが、POPFile が終了してしまうと
いうことは、POPFile のプロセスが止まってしまっている
ということですよね。そうすると、なんらかの原因で
Perl のエラーが起こっているのではないかと思います。

そうだとすると、POPFile が出力するログからは原因を
調べることは困難ですので、起動スクリプトを使うのでは
なく、コンソールから POPFile を起動して、コンソールに
エラーメッセージなどが出力されないかどうか確認して
みていただけますでしょうか。

Encode のバージョンがちょっと古いことが若干気には
なりますが、まずは上記でエラーメッセージを取得し、
それから原因を調べていくのがよいのではないかと
思います。
Reply to #26830

Reply to #26831×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2006-12-28 10:08 by gen11 #26837)

amatubuさん、こんにちは。
素早い対応ありがとうございます。

昨日の夜からコンソールへログ出力しながら使用を始めています。
が、今日に限ってなのか、年末で負荷が軽くなっているのか、未だにプロセスが終了する現象は出ていません。

ということは、起動スクリプトに問題があるのでしょうか。
何の気なしにそのまま使ってしまいましたが、素人なりに何が違うのか考えると、shellくらいしか思い浮かびません。
ログインで使用するのはbashなので、スクリプトも書き換えてのテストもしてみようと思います。
が、なにせ年末なので、現象が確認できるのは来年になりそうです。

何か変化がありましたらまたご相談させて下さい。
よろしくお願い致します。
Reply to #26830

Reply to #26837×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2006-12-28 12:33 by amatubu #26839)

スクリプトをざっと見てみましたが、特に問題はないように
思います。
問題が起こるまでしばらく様子を見てみていただけますでしょうか。
よろしくお願いします。
Reply to #26837

Reply to #26839×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-09 12:33 by gen11 #27015)

あけましておめでとうございます。
年明け2~3日は問題なかったのですが、やはり出てしまいました。
が、今回はプロセスが一つ残った状態で止まっています。
クライアントからの受信はエラーになっていました。
ログを見ると直前になにやら怪しそうなのがあります。

2007/1/9 09:29:46 17855: bayes: 733: Attempting to connect to dbi:SQLite:dbname=/usr/local/popfile/popfile.db (1)
2007/1/9 09:29:46 17855: bayes: 739: Using SQLite library version 2.8.12
2007/1/9 09:29:46 17855: pop3: 301: +OK POP3 POPFile (v0.22.4) server ready[0d][0a]
2007/1/9 09:29:46 17855: pop3: 194: Regexps: ^USER XXXXXX
2007/1/9 09:29:46 17855: pop3: 209: Command: --USER XXXXXX--
2007/1/9 09:29:46 17855: pop3: 513: Connected to localhost:110 timeout 60
2007/1/9 09:29:46 17855: pop3: 551: Connection returned: +OK ready <17856.1168302586@pop3.hogehoge.co.jp>[0d][0a]
*** glibc detected *** free(): invalid pointer: 0x09550648 ***
2007/1/9 09:29:46 17855: pop3: 301: USER XXXXXX
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK Password required for user.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK Password required for user.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 209: Command: --PASS XXXXXX--
2007/1/9 09:29:46 17855: pop3: 301: PASS XXXXXX
アボートしました
[root@pop3 popfile]# 2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK user has 11 visible messages (0 hidden) in 218643 octets.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK user has 11 visible messages (0 hidden) in 218643 octets.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 209: Command: --STAT--
2007/1/9 09:29:46 17855: pop3: 301: STAT[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK 11 218643[0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK 11 218643[0d][0a]
2007/1/9 09:29:46 17855: pop3: 209: Command: --LIST--
2007/1/9 09:29:46 17855: pop3: 301: LIST[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK 11 visible messages (218643 octets)[0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK 11 visible messages (218643 octets)[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data 1 20216[0d][0a]2 52010[0d][0a]3 3900[0d][0a]4 1170[0d][0a]5 1217[0d][0a]6 2090[0d][0a]7 1412[0d][0a]8 3709[0d][0a]9 77213[0d][0a]10 21138[0d][0a]11 34568[0d][0a].[0d][0a]
2007/1/9 09:29:46 17855: pop3: 209: Command: --UIDL 1--
2007/1/9 09:29:46 17855: pop3: 301: UIDL 1[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK 1 "bh!!`)L"!0hE"!Sh7"![0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK 1 "bh!!`)L"!0hE"!Sh7"![0d][0a]
2007/1/9 09:29:46 17855: pop3: 209: Command: --UIDL--
2007/1/9 09:29:46 17855: pop3: 301: UIDL[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data +OK uidl command accepted.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 301: +OK uidl command accepted.[0d][0a]
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data 1 "bh!!`)L"!0hE"!Sh7"![0d][0a]2 k/p"!0db!!Ufk"!<l+!![0d][0a]3 gXF!!CZW"![*T!!-[G!![0d][0a]4 L%+#!:T_"!g[%#!^5G"![0d][0a]5 Lk;"!OTL"!'YS"!=Q-!![0d][0a]6 an7"!_F3"!<Y%"!9d:"![0d][0a]7 ,Lk!!?WH!!b]j!
2007/1/9 09:29:46 17855: pop3: 658: Read slurp data !VTg"![0d][0a]8 /bN!!fcm!!*6'#!321!![0d][0a]9 8>Z"!]6X"!hKK"!?ha!![0d][0a]10 `Z^"!E)D!!?dG!!'A;"![0d][0a]11 TYA"!@7Y"!6`[!!eD9!![0d][0a].[0d][0a]
2007/1/9 09:29:47 17855: pop3: 209: Command: --QUIT--
2007/1/9 09:29:47 17855: pop3: 301: QUIT[0d][0a]
2007/1/9 09:29:47 17855: pop3: 658: Read slurp data +OK Pop server at pop3.hogehoge.co.jp signing off.[0d][0a]
2007/1/9 09:29:47 17855: pop3: 301: +OK Pop server at pop3.hogehoge.co.jp signing off.[0d][0a]
2007/1/9 09:29:47 17855: mq: 377: post CMPLT (17855)
2007/1/9 09:29:47 17855: mq: 392: sending post CMPLT (17855) to parent GLOB(0x95b42b0)
2007/1/9 09:29:47 17855: pop3: 668: POP3 proxy done

ログはここで停止していました。
プロセスを見てみると、popfileは一つ残った状態でした。

こんな情報ですが、何か手がかりになりますでしょうか。
よろしくお願い致します。



P.S.
過去ログを片っ端から見ていくと、「起動時にWARNING: POPFile may require Perl module ***; it is needed for "Japanese Language Support"というエラーがないか」という質問を拝見します。
そういえば何か見たことあるような…と思って起動した時のログを見てみましたが、今回の起動時には出てませんでした。
もしかすると起動スクリプト経由だと出るのかもしれませんが、今回はコンソールからの直接起動でした。
Reply to #26839

Reply to #27015×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-10 18:05 by amatubu #27047)

ログの確認ありがとうございます。
拝見したところ、POPFile のログとコンソールへ出力
されたエラーメッセージが混在しているようですが、
ログもコンソールへ出力する設定にされているという
ことでしょうか。

エラーの部分は

*** glibc detected *** free(): invalid pointer: 0x09550648 ***
アボートしました

というところのようですが、これだけでは残念ながら
原因はわからないですね。いずれかの Perl モジュールに
おいて問題が発生しているのは確かなようですが……。

この部分以前の、プロセス番号(日付、時刻の右の番号)
17855 以外のログには何か残っていませんか?
(おそらく、エラーで終了したのは 17855 以外の
 プロセスだと思いますので……)

また、確認していませんでしたが、「POP3 同時接続の許可」
は「はい」になっていますか?

モジュールがエラーを起こしているとなると、POPFile
側での対処は難しそうな感じです。まずは、どの
モジュールでエラーが起こっているのかを調べていく
必要があると思いますが、ちょっと見当がつかない
ですね。
もしかすると、
http://www.namazu.org/pipermail/kakasi-dev/2007-January/000056.html
このあたりの問題が関係しているのかもしれませんが、
ちょっとなんとも言えないですね。

まずは、切り分けを行うために、Kakasi を使わずに
使用してみるくらいでしょうか。実運用されている
環境に手を入れるのは困難だと思いますが、例えば、
http://sourceforge.jp/tracker/index.php?func=detail&aid=8561&group_id=759&atid=2945
のパッチをあて、文字種による分割を使うことによって
切り分けができるかもしれません。

あるいは、バージョンが最新でない Perl モジュールを
バージョンアップしてみるというのもひとつの方法です。

とりあえず、ログの内容を今一度確認していただけ
ますでしょうか。そこから何かわかるかもしれません。
Reply to #27015

Reply to #27047×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-11 10:14 by gen11 #27063)

いつもありがとうございます。

落ちるタイミングに何か意味があるかと思い、popfileのログも一緒に出力しておりました。
ログをさかのぼってみましたが、この他にそれらしきエラーは残っていませんでした。
とはいえ、1分間に4,000行以上ログが吐き出されてまして、残っている部分より以前に何か兆候があるのかもしれません。

「POP3 同時接続の許可」とはpop3_force_forkのことでしょうか。
それでしたら値は1(新しいプロセスを実行する)になっています。

ご指摘のように、どうもモジュールが問題なような気がしまして、以前テスト環境に使ったサーバーとモジュールのバージョンを比較してみました。
結果、DBIだけが1.40と古かったので、1.53にバージョンアップして、再度稼動を始めております。
以前Encodeが古いとご指摘を受けましたが、テストサーバーでも同じバージョンでしたので、こちらはそのままとしました。

パッチの適用はかなり難しそうです。
最終手段として考えてみます。

いろいろとご対応いただき、ありがとうございます。
しばらくこのまま運用してみて、何かありましたらまた相談させていただきます。
今後ともよろしくお願い致します。
Reply to #27047

Reply to #27063×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-13 01:25 by amatubu #27089)

> 落ちるタイミングに何か意味があるかと思い、popfileのログも一緒に出力しておりました。
> ログをさかのぼってみましたが、この他にそれらしきエラーは残っていませんでした。

エラーは起こっていなくても、その前に記録されたログから、
「どのあたりでエラーがおこっているのか」を推測することは
できるのではないかと思っています。
もしよろしければ、ログの該当部分を amatubu@mac.com まで
送付いただけますでしょうか。こちらでも調べてみようと
思います。

> 「POP3 同時接続の許可」とはpop3_force_forkのことでしょうか。
> それでしたら値は1(新しいプロセスを実行する)になっています。

その通りです。あるいは、設定タブでも確認できます。

> 結果、DBIだけが1.40と古かったので、1.53にバージョンアップして、再度稼動を始めております。

了解です。それで解決するとよいのですが。

> パッチの適用はかなり難しそうです。
> 最終手段として考えてみます。

了解です。
次のメジャーリリース(0.23 でしょうか)では、
Kakasi がなくても動作するような機能を追加したいと
思っています。

> しばらくこのまま運用してみて、何かありましたらまた相談させていただきます。

了解しました。
また何かありましたらご連絡ください。
Reply to #27063

Reply to #27089×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-18 18:54 by gen11 #27196)

amatubuさん、こんばんは。
いつもありがとうございます。
遅くなって申し訳ありません。

前回のログについてはpopfileから吐き出すログが膨大(クライアントが多すぎ)でとてもお渡しできそうもありません。
で、再度初心に返って、標準エラー出力のみを取ろうと思いますが、狙っているとなかなか落ちないものです。

実は、まだ落ちてはいませんが、エラーは出ています。

> readline() on closed filehandle $reader at /usr/local/popfile/POPFile/MQ.pm line 306.

この一行だけです。
今のところ特に問題なく稼動を続けています。

また何か変化ありましたらご報告いたします。
よろしくお願い致します。
Reply to #27089

Reply to #27196×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-18 23:34 by amatubu #27200)

了解です。
また何か起こりましたら教えてください。

エラーの記録されているところを見てみましたが、
ちょっと原因はわかりませんでした。

POPFile のプロセスの使用メモリやハンドル、スレッド
数などを監視してみるという手もあるかもしれません。
Reply to #27196

Reply to #27200×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-24 17:17 by gen11 #27301)

いつもお世話になっております。

以前みたいにプロセスが全滅してしまう現象はまだありませんが、最近は子プロセスを残して親が死んでしまうようです。
今度はメール受信できなくなってしまいました。
その時点でのpopfileのエラー表示です。

readline() on closed filehandle $reader at /usr/local/popfile/POPFile/MQ.pm line 306.
  :
(複数行)
  :
readline() on closed filehandle $reader at /usr/local/popfile/POPFile/MQ.pm line 306.
Not a GLOB reference at /usr/local/popfile/POPFile/MQ.pm line 203.
Attempt to free unreferenced scalar: SV 0x9f15cb0, Perl interpreter: 0x922e008 during global destruction.

再度popfileを起動しようとしたら、子プロセスが残っている旨の表示がありました。

A copy of POPFile appears to be running.
Attempting to signal the previous copy.
Waiting 10 seconds for a reply.

popfileが起動したところ、また正常に使用できています。
が、

readline() on closed filehandle $reader at /usr/local/popfile/POPFile/MQ.pm line 306.

このエラーはやはり複数出てしまいます。

お手数をおかけして申し訳ありません。
何かアドバイスありましたらお願いします。
Reply to #27200

Reply to #27301×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-01-25 20:17 by amatubu #27320)

警告が出ているあたりを再度確認してみましたが、何が原因なのかは
残念ながらわかりませんでした。プロセス間通信のところで何らかの
問題が起こっていることは確かなようですが……。

しかし、これらのメッセージは、あくまで「警告」レベルのものであり、
これが原因でプロセスが終了してしまうというのは考えにくいです。
何らかの原因によりプロセスが落ちてしまっているところに、通信を
行おうとして警告が発生しているような気がしています。
とはいえ、その原因がなんなのかはわかっていないのですが……。

どうやらちょっと私の手には負えない問題のようですので、本家
フォーラムで相談されるのがよいのではないかと思います。
https://sourceforge.net/forum/?group_id=63137
Reply to #27301

Reply to #27320×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-02-22 10:17 by gen11 #27772)

こんにちは。
ご連絡が遅れて申し訳ありません。

まだ一週間に一回くらいの頻度で親プロセスが落ちます。
どうしようもないので、エラー出力を監視してpopfileが落ちたらrestartをかけるようにしました(汗)。

さすがに本家は敷居が高いので、とりあえずの力技。
情けないですが、今はこれが私の精一杯です(泣)。
時間がある時に少しずつ勉強しつつ調査していきたいと思います。
その際はまた何かお世話になるかもしれません。
今後ともよろしくお願い致します。
Reply to #27320

Reply to #27772×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login

RE: いつの間にか終了してしまいます (2007-02-22 18:15 by amatubu #27788)

どのモジュールで問題が起こっているのかだけでもわかれば
原因究明につながるかなと思うのですが、そういうことを
調べられるのかどうかも含めて私には知識がありません。

よく知らないのですが、Linux でクラッシュレポートのような
ものを得ることはできませんでしょうか。
あるいは、前にも書きましたが、プロセスの使用メモリ等の
状況をチェックしてみると何かわかってくるかもしれません。

また何か新しい情報があれば教えてください。
Reply to #27772

Reply to #27788×

You can not use Wiki syntax
You are not logged in. To discriminate your posts from the rest, you need to pick a nickname. (The uniqueness of nickname is not reserved. It is possible that someone else could use the exactly same nickname. If you want assurance of your identity, you are recommended to login before posting.) Login