アカウントバイパス後の振り分け条件にhit - 秀丸メール情報交換会議室 - スレッド46014, 2014/04/16

アカウントバイパス後の振り分け条件にhit

suii さん　14/04/16 09:44

お世話になります。
x64 v6.24使用しております。

私は"spam"という名称のアカウントを一つ作成して、複数アカウントのそれ
ぞれの振り分け条件でspam判定メールをすべて"spam"アカウントにバイパス
し、"spam"アカウントの振り分け条件で「"X-Account:" が "(アカウント
名)" である」条件で、バイパスされてきたアカウントごとに色づけして一
覧にしております。

ず～っと以前より、この色づけ判定をすり抜けて色が変わらないメールが数
十通に一通程度発生しています。
その色の変わらないメールを選択して「振り分け(J)」を実行しますと色が
つきますので、バイパスされてきたときにまれに実行されないことがあるよ
うなのです。

filterlog.txt を取ってみますと色づけ失敗メールだけ
　2014/04/16 07:34:55　(バイパス元のアカウント)　受　コ　Message-Id:<abcdefg~
となっており、正常に色づけされたものは「受　コ」の部分が「受　自」と
なっているようです。
この意味が分からず、Googleで　「"filterlog.txt" 受自コ」　などとし
てみましたがヒントを得られませんでした。
ちなみに自動かな?コマンドかな? なんて妄想しましたが、すべて自動受信
で起きています。

色づけに失敗する原因が分かりますでしょうか?

RE:46014 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 10:58

　毎度お手数かけてすみません。

　まず、filterlog.txtの意味がどこにも書いてないので、ここで説明させいた
たきますと…

　"受"は、受信したメールの振り分けって意味になりまして、逆は、"送"で、送
信系メールの振り分けになります。

　"コ"は、コマンド、つまり、「振り分け」とかのコマンドを実行して振り分け
たって意味で、逆の"自"は、受信時または送信時の自動振り分けって意味になり
ます。

　この辺はまたヘルプの方にも追加させていただきます。

> 色づけに失敗する原因が分かりますでしょうか?

　振り分けを実行したけどヒットしなかった場合には、filterlog.txtに「振り
分け動作なし」が記録されるはずで、それが無いということは、振り分け自体が
うまく実行されなかったってことになると思います。

　うまく実行されなかった原因は、アカウントのバイパスが関係してるんだと思
いますが…。よく分からないので今からソースコードの見直しなどしてみます。
少々お待ちください。

RE:46016 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 11:56

　テストしてみたら、とりあえず２つ分かったことがありました。

■その１：手動振り分けで色が付かない

　受信時の自動振り分けじゃなくて、手動での振り分け時に色がつかないようで
す。

　たとえばバイパス元アカウントがＡでバイパス先がＢだとします。

　Ｂアカウントにバイパスされたメールを選択して「編集・振り分け」を実行す
ると、たしかに色が変わります。しかし、バイパス前のＡアカウント上でメール
を選択して「編集・振り分け」実行すると、そのメールはＢアカウントに
バイパスされますが、色は付かないようです。

　理由は…

　Ｂアカウントでの振り分け条件は、

"X-Account:"が"....."である

　みたいな条件になってると思いますが、手動振り分けでバイパスされた場合、
振り分け条件にマッチさせる用のメールデータには、まだ"X-Account:"ヘッダが
入ってませんでした。なので、それのせいでうまくヒットしてませんでした。

　ちなみにその場合は、filterlog.txtファイルには

2014/04/16 11:18:32 Ａ受コ From:XXX ヒット(N):迷惑メール
2014/04/16 11:18:32 Ｂ受コ From:XXX 振り分け動作なし

　のように、「振り分け動作なし」が出てくるようです。

　とりあえずこれはこれでバグなので修正させていただきます。

■その２：外国語メールだとダメ

　受信時の自動振り分けのテストをしたら、中国語の迷惑メールが１通、色が付
きませんでした。

　中国語だと、X-Account:ヘッダの中身が化けたような表示になってしまいまし
て、それでうまくヒットしないようでした。

　これはこれで、うまくヒットするように修正できると思います。さっそくその
辺トライしてみます。

------------------------------------------------------------------
　まとめ
------------------------------------------------------------------

　手動振り分けした場合か、または外国語メールの場合にうまくいかないようで
す。

　他にも条件があるかもしれないですけども、とりあえず、外国語メールじゃな
いのに色が付いてないのがあるかどうか、あと、filterlog.txtで、たしかに
「振り分け動作なし」が出てるかどうかも見てみてほしいです。

　メールの文字コードは、メールを選択して「編集・メールのプロパティ」を実
行すると分かります。「保存先=」の最後に「lang=XXXX」って形で文字コード種
別が表示されます。

RE:46018 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 12:02

> ■その２：外国語メールだとダメ

　外国語メールの場合だと、「編集・振り分け」で再度振り分けを実行してもや
はり色は付かないようです。

　今回の件はこれとは別のようです。

RE:46019 アカウントバイパス後の振り分け

suii さん　14/04/16 12:45

お手数おかけします。
こちらではご確認いただいたのとは違う条件で頻出しています。

> ■その１：手動振り分けで色が付かない

この点は先にも書きましたように自動受信の時に"コ"が記録されており、こ
の時だけバイパス後の振り分けがうまくいってないのです。
誤記録でなければ内部的に手動振り分けに飛んでしまっているのでしょうか。

その後は秀まるお様が書かれた
> 振り分け条件にマッチさせる用のメールデータには、まだ"X-Account:"ヘッダが
> 入ってませんでした。なので、それのせいでうまくヒットしてませんでした。
の動作に当てはまるように見えますが、
　2014/04/16 11:18:32 Ｂ受コ From:XXX 振り分け動作なし
のような、「振り分け動作なし」は一切記録されずに「受信」フォルダに届
きます。ちょっと補足すると、色づけだけではなくフォルダ振り分けなども
無視されます。

もしかしてfilter.logを「詳細に」の設定が必要とかありますか？
今からONにしてみます。。。

> ■その２：外国語メールだとダメ

朝の投稿後、既に4通が振り分け(色づけ)失敗になっているので確認しまし
たが、すべて日本発のようです。
> 1 JP 日本
です。
今まで色づけ失敗したメールをそのまま振り分け実行したら失敗することな
く色づけされてきましたので、X-Account: ヘッダの文字化けなどではない
と思います。

RE:46020 アカウントバイパス後の振り分け

suii さん　14/04/16 12:49

> すべて日本発のようです。
>> 1 JP 日本
> です。

日本発だけでなくて、内容も日本語でございます、、、念のため(汗)

RE:46021 アカウントバイパス後の振り分け

suii さん　14/04/16 13:07

出ました！
> もしかしてfilter.logを「詳細に」の設定が必要とかありますか？
> 今からONにしてみます。。。
詳細にチェックしたら「振り分け動作なし」が記録されました。

自動受信でspamがバンバン届くので検証が早くて助かりますが、
やっぱり自動受信なのにfilter.logではコで記録されています。
(手動振り分けしたという記録ですよね)

2014/04/16 12:53:26 (Aアカウント) 受コ From:--- 移動:アカウントのバイパス:
(Bアカウント)
2014/04/16 12:53:26 (Bアカウント) 受コ From:--- 振り分け動作なし

こんな感じです。
詳しくは分かりませんが、自動受信なのに手動受信の処理に飛んでいるような？

RE:46022 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 14:28

> やっぱり自動受信なのにfilter.logではコで記録されています。
> (手動振り分けしたという記録ですよね)

　添付ファイルで届く「.eml」ファイルを、振り分けアクションによって
インポートされたって可能性が１つあるかなぁと思います。

　それの他の可能性だとしたら…

　「全般的な設定・上級者向け・動作の記録」の「秀丸メールの動作をdump.txt
に記録する」と「すべての送受信内容」の両方をONにしてログを取っていただく
と、それで何が実行されてるのか分かりそうな気がしますが、そうするとメール
データの中身全部分かってしまうの、それで取れたログをそのまま僕に送ってい
ただくのはちょっと難しいです。

　とりあえず上記設定でログを取って、それで、問題の「コ」が出てくる振り分
け実行時の周辺を見て何か分からないでしょうか。

　filterlog.txtファイルに振り分け実行の時刻も出るので、それで、dump.txt
の該当箇所は特定できると思います。

RE:46025 アカウントバイパス後の振り分け

suii さん　14/04/16 17:35

お手数おかけします。
x64 v6.25b2 にupして検証しています。

dump.txtの記録をONにしてからアカウントBで振り分けが無視されたメール
がまだ4通でサンプルが少ないのですが、dump.txtを取る前からの振り分け
無視メールを確認してみましたらすべて
　　X-TuruKame-Filter: spam (UrlChecker: spam-site)
で、dump.txtの記録開始後に失敗した4通とも、受信直後に
　　I 迷惑メールフィルターの遅延処理開始:xx
が挿入されていました。
振り分け問題のないメールには「迷惑メールフィルターの遅延処理」などの
一行は入っていないようです。
※定かではないですが、色づけ失敗はURLチェッカーのダイアログが開いて
いるときに受信したメールの時に集中して発生していたかもしれません。

メール本文受信後のおしゃべりを抜き出します。

【失敗1】
15:53:51.888 R ...(1920バイト)
15:53:51.888 (9523) 1 / 3 済み (1.8K / 7Kバイト)
I 迷惑メールフィルターの遅延処理開始:12
15:53:51.903 (4826) filterlog.txt succeeded offset=3738384
15:53:51.932 (5660) Appended (Aアカウント)/6/ file=受信ログ201404_10.txt off
set1=1576773 offset2=1576771 size=1958
15:53:51.932 (5677) (Aアカウント),6 cEach=0
15:53:51.934 S DELE 1
15:53:51.934 (5660) Appended (Aアカウント)/0/ file=受信201404_27.txt offset1
=19161 offset2=19159 size=1605
15:53:52.022 R +OK

【成功1】
15:53:52.406 R ...(1095バイト)
15:53:52.406 (9523) 2 / 3 済み (2.9K / 7Kバイト)
15:53:52.411 (4634) filter action=00000001
15:53:52.412 (4826) filterlog.txt succeeded offset=3738615
15:53:52.412 (4634) filter action=00054001
15:53:52.412 (4826) filterlog.txt succeeded offset=3738829
15:53:52.415 (5660) Appended (Aアカウント)/6/ file=受信ログ201404_10.txt off
set1=1578733 offset2=1578731 size=1133
15:53:52.416 (5677) (Aアカウント),6 cEach=0
15:53:52.417 S DELE 2
15:53:52.417 (5660) Appended (Bアカウント)/0/(Bアカウント) file=(Bアカウン
ト)201404_01.txt offset1=227517 offset2=227515 size=1134
15:53:52.492 R +OK

↓filter.logでは、先に【失敗2】の振り分け処理後に【成功2】を処理していますが
dump.txtでは前後しています。
【成功2】
16:55:29.488 R ...(3475バイト)
16:55:29.489 (9523) 4 / 4 済み (7.4K / 7Kバイト)
16:55:29.493 (4634) filter action=00000001
16:55:29.493 (4826) filterlog.txt succeeded offset=3751207
16:55:29.494 (4634) filter action=00054001
16:55:29.494 (4826) filterlog.txt succeeded offset=3751429
16:55:29.496 (5660) Appended (Aアカウント)/6/ file=受信ログ201404_10.txt off
set1=1631023 offset2=1631021 size=3513
16:55:29.496 (5677) (Aアカウント),6 cEach=0
16:55:29.497 S DELE 4
16:55:29.498 (5660) Appended (Bアカウント)/0/(Bアカウント) file=(Bアカウン
ト)201404_01.txt offset1=292078 offset2=292076 size=3586
16:55:29.623 R +OK

【失敗2】
16:55:27.939 R ...(1229バイト)
16:55:27.940 (9523) 1 / 4 済み (1.1K / 7Kバイト)
I 迷惑メールフィルターの遅延処理開始:13
16:55:27.962 (4826) filterlog.txt succeeded offset=3749890
16:55:27.966 (5660) Appended (Aアカウント)/6/ file=受信ログ201404_10.txt off
set1=1626724 offset2=1626722 size=1267
16:55:27.966 (5677) (Aアカウント),6 cEach=0
16:55:27.967 S DELE 1
16:55:27.968 (5660) Appended (Aアカウント)/0/ file=受信201404_27.txt offset1
=19161 offset2=19159 size=1206
16:55:28.052 R +OK

↓こちらは一つのメールがfilter.logに3段表示されて振り分け失敗していました。
【失敗3　filter.log】
2014/04/16 17:07:41　(Aアカウント)　受　自　From:○ <**@**.biz>　Message-Id:
<xxx>　振り分け動作なし
2014/04/16 17:07:42　(Aアカウント)　受　コ　From:○ <**@**.biz>　Message-Id:
<xxx>　ヒット(19):迷惑メール　(SPAM)で始まる,(ZIP DELETED)を含まない　移動:
アカウントのバイパス:(Bアカウント)
2014/04/16 17:07:42　(Bアカウント)　受　コ　From:○ <**@**.biz>　Message-Id:
<xxx>　振り分け動作なし

【失敗3　dump.log】
17:07:41.042 R ...(1435バイト)
17:07:41.042 (9523) 1 / 1 済み (1.4K / 1Kバイト)
I 迷惑メールフィルターの遅延処理開始:14
17:07:41.055 (4826) filterlog.txt succeeded offset=3754786
17:07:41.059 (5660) Appended (Aアカウント)/6/ file=受信ログ201404_10.txt off
set1=1652994 offset2=1652992 size=1473
17:07:41.059 (5677) (Aアカウント),6 cEach=0
17:07:41.061 S DELE 1
17:07:41.061 (5660) Appended (Aアカウント)/0/ file=受信201404_27.txt offset1
=30539 offset2=30537 size=1382
17:07:41.143 R +OK
17:07:41.143 S QUIT
17:07:41.254 R +OK
17:07:41.254 (9533) tid=5116 ThreadExit 5116
17:07:41.255 (9523) 迷惑メールフィルターの遅延処理待ち
I 迷惑メールフィルターの遅延処理終了:14
17:07:42.489 (9523) 受信フォルダ中の新着メールを振り分け直し
17:07:42.491 (27249) URL-Checker filter 1,1018
17:07:42.491 (9326) SetWaitCursor 0
17:07:42.491 (1127) InitializeFilter
17:07:42.493 (10849) AlterSave (Aアカウント)/0/ file=受信201404_27.txt offse
t=30539 prevsize=1382
17:07:42.493 (4634) filter action=00000001
17:07:42.494 (4826) filterlog.txt succeeded offset=3754948
17:07:42.494 (4826) filterlog.txt succeeded offset=3755185
17:07:42.494 (7822) MailFileOperation ope=5 (Aアカウント)/0/ count=1 file=受
信201404_27.txt offset=30539
17:07:42.494 (7825) dest=(Bアカウント)/0/
17:07:42.494 (9326) SetWaitCursor 1
17:07:42.499 (9417) RestoreWaitCursor 1
17:07:42.499 (7822) MailFileOperation ope=0 (Aアカウント)/0/ count=1 file=受
信201404_27.txt offset=30539
17:07:42.499 (9326) SetWaitCursor 1
17:07:42.499 (9417) RestoreWaitCursor 1
17:07:42.499 (9326) SetWaitCursor 1
17:07:42.500 (15363) NotifyListCacheOffsetMoved 101F5FA3,-176,0,0,0
17:07:42.500 (9417) RestoreWaitCursor 1
17:07:42.501 (9417) RestoreWaitCursor 0
17:07:42.501 (27252) done 1017
17:07:42.501 (9523) 振り分け 1通/1通
17:07:42.503 (8029) IDTIMER_SOCKET_END received
17:07:42.503 (8091) IDTIMER_TRANS_START post
17:07:42.503 (7776) IDTIMER_TRANS_START kill
17:07:42.503 (9523) 終了

RE:46026 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 17:56

　詳しく調べていただきありがとうございます。

　URLチェッカーで遅延して振り分けされる時は、すみませんがこの場合は手動
での振り分け扱いとしてfilterlog.txtファイルに記録されます。

　ということで、そういう場合の手動扱いの振り分けで、X-Account:ヘッダがう
まくセットされてなくて、振り分け（色つけ）に失敗してるってことのようです。

　ということで、おかげさまで、完全に謎が解けました。

　どっちにしても秀丸メールのバグなのですが…。

　またV6.25β3としてアップロードさせていただきます。

　少々お待ちください。

RE:46027 アカウントバイパス後の振り分け

suii さん　14/04/16 18:08

長年の、再現パターンが分からずに報告できなかった不便から解放されます(^^
楽しみにしています。

RE:46028 アカウントバイパス後の振り分け

秀まるお2 さん　14/04/16 18:36

　もう１つすみません。

　URLチェッカーによる遅延振り分けが「自動」じゃなくて「手動」扱いになる
のは、これはこれでバグのようです。

　手動振り分け扱いだと、振り分け条件での「振り分けコマンドの時のみ有効」
や「自動振り分け時のみ有効」がうまくいかないです。

　これまた修正させていただきます。