v6.46でIDLEコマンド終了時にエラーが出る - 秀丸メール情報交換会議室 - スレッド48723, 2015/10/26

v6.46でIDLEコマンド終了時にエラーが出る

ぴよさん　15/10/26 15:12

秀丸メール 6.44 では問題なく使えていたのですが、6.46 に更新した
ところIDLEコマンド終了時に時々エラーが出るようになりました。

直前のやりとり記録はこんな感じです。

****IMAP4受信:***@**** (高速化ON)
S DONE
I IDLEコマンド終了
R C0 OK IDLE completed
S C1 LIST "" *
I IMAPフォルダ一覧を取得中
R DONE NO Error in IMAP command received by server.
E IMAPの処理でエラーが発生しました。行番号=12772

メールアドレスはさくらインターネットのものを使っています。

RE:48723 v6.46でIDLEコマンド終了時にエ

秀まるお2 さん　15/10/26 17:17

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

　Version 6.46になってから性能アップのために少しいじった所があって、それ
のせいでうまくいってないようです。

　以前は、IDLEコマンドで監視中に何か受信しようとすると、IDLE用につながっ
てる通信回線（ソケット）を一回切って、接続＆ログインからやり直してました。
Version 6.46からは、「DONE」ってコマンドを送って正常応答があれば、そのま
まその回線を使って受信するようにしました。

　関係のケースは、IDLEコマンドを終了させるための「DONE」についてはちゃん
と応答してるのに、その後のコマンドでエラーが返ってきてしまうようです。

　とりあえず、さくらインターネットは２週間のお試し利用が可能なようなので、
それでテストしてみようと思います。今そちらの申し込みだけしましたので。

　少々お待ちください。

RE:48726 v6.46でIDLEコマンド終了時にエ

秀まるお2 さん　15/10/26 18:26

　さくらインターネットのお試し利用を申し込んでテストしたんですが、こちら
だとうまくいってしまいました。

開始時刻: 2015/10/26 18:22:23
****IMAP4受信:xxxxxxxxx@imaptest.sakura.ne.jp
S DONE
I IDLEコマンド終了
R C6 OK IDLE completed
S C1 LIST "" *
I IMAPフォルダ一覧を取得中
R * LIST (\HasNoChildren) "." "INBOX.Drafts"
* LIST (\HasNoChildren) "." "INBOX.Trash"
* LIST (\HasNoChildren) "." "INBOX.spam"
* LIST (\HasNoChildren) "." "INBOX.Sent"
* LIST (\HasNoChildren) "." "INBOX.Draft"
* LIST (\Unmarked \HasChildren) "." "INBOX"
C1 OK LIST completed
S C2 SELECT "INBOX"
I 既存メールからUIDLを取得します
・・・・・

　ってな具合でうまくいくようでした。

　Becky!での動作を見てみても、秀丸メールと同様に、「DONE」コマンドで成功
したら、その後普通にIMAPのコマンドを発行してやりとりしてるだけのようで、
ログインしなおさないとダメとかってことも無さそうです。

　とりあえずの対策として、DONEコマンドが成功した後の次のコマンドでエラー
になった場合は、一度回線を切ってからもう一度接続からやり直すようなことを
自動でやるようにしようと思います。それでいいですよね？

RE:48727 v6.46でIDLEコマンド終了時にエ

ぴよさん　15/10/26 20:01

わざわざ検証していただきありがとうございます。

こちらでも毎回そうなるわけではなく、時々・・・しばらく席を離れて
戻ってみるとエラーが出ている、という印象なので、むしろその辺が
関係しているのかもしれません。

>　とりあえずの対策として、DONEコマンドが成功した後の次のコマンドでエラー
>になった場合は、一度回線を切ってからもう一度接続からやり直すようなことを
>自動でやるようにしようと思います。それでいいですよね？

おそらくそれで解決するのだとは思いますが、個人的に気になるので
もう少しこのまま様子を見てみようと思います。

RE:48728 v6.46でIDLEコマンド終了時にエ

ぴよさん　15/10/28 00:05

そういえば、「長時間にわたってサーバーからの応答がありません。」という
エラーになることもあります。

****IMAP4受信:**@**** (高速化ON)
S DONE
I IDLEコマンド終了
R + entering idle mode
I IDLEコマンド失敗につき、接続からやり直し
I サーバーを検索中 - ***.sakura.ne.jp
I 接続中 - ***.***.***.*** (port=993,IMAP4)
I 接続完了
E 長時間にわたってサーバーからの応答がありません。

正常に受信できた時とこれらのエラーが出るときのdump.txtを比較してみると、
DONEやIDLEに対する応答を受け取る前に受信処理がDONEを送信しているように見えま
す。

dump.txtはまだ残してあるので、必要でしたらお送りできます。

RE:48737 v6.46でIDLEコマンド終了時にエ

秀まるお2 さん　15/10/28 09:30

　昨日の午後くらいから５分間隔で定期受信する設定にしてテストしてたんです
が、今日dump.txtを見たら、現象の再現が確認出来てました。

18:33:39.184 (4789) Send ThreadCreated 3848
18:33:39.184 S DONE
18:33:39.184 (10328) 受信 - xxxxxxxxx@xxxxxxxx.sakura.ne.jp ... IDLEコマン
ド終了
R C0 OK IDLE completed
18:33:39.246 S C1 LIST "" *
18:33:39.246 (10328) MAPフォルダ一覧を取得中
R DONE NO Error in IMAP command received by server.
18:33:39.262 (10328) DONE直後のコマンドでエラーが返ったので接続からやり直します
18:33:39.262 (10328) サーバーを検索中 - imaptest.sakura.ne.jp
18:33:39.371 (10328) 接続中 - 112.78.112.18 (IMAP4)
18:33:42.418 (4789) Send ThreadCreated 776
18:33:42.418 (10328) 完了

　ってな具合でした。なので、とりあえず次のβ版で大丈夫になったかなぁと思
います。

> そういえば、「長時間にわたってサーバーからの応答がありません。」という
> エラーになることもあります。

　そういうこともあるってことになると、秀丸メール側で出来そうな対策として
は、DONEコマンド（またはその次のコマンド）でエラーになった後の再接続を、
少し待ってから行うくらいしか思いつかないです。

　せっかくなので、次のβ版にて少し待ってから接続しなおすようにしてみます。

> 正常に受信できた時とこれらのエラーが出るときのdump.txtを比較してみると、
> DONEやIDLEに対する応答を受け取る前に受信処理がDONEを送信しているように見えま
> す。

　僕の所で「DONE NO Error ...」が起きた時のログを見た限りでは、秀丸
メールが送ってるDONEコマンドのタイミングおよびそれに対する応答の処理の仕
方はおかしくないようでした。また、仮にこれがおかしかったとしても、再接続
した後にサーバーが応答しないのはまた別問題になると思います。

　確認するとしたら…。dump.txtの該当部分よりも前の、秀丸メールがIDLE
コマンドを送ってる所からのログを見ればはっきりすると思いますけども…。た
ぶん、

18:32:39.074 ( 275) C0 IDLE

18:32:39.121 ( 102) + entering idle mode

　みたいに「+ entering...」の応答があることを確認してから次の処理に行っ
てるはずなので、そうだとしたら、その辺は問題ないはずだと思います。

RE:48738 v6.46でIDLEコマンド終了時にエ

ぴよさん　15/10/28 10:44

以下の繰り返しがIDLE監視中なのだと思いますが、

275) C0 IDLE
102) + entering idle mode
275) DONE
102) C0 OK IDLE completed

正常なケースでは、この + entering idle mode の後に受信処理のDONEが送られてい
ます。

13:19:41.627 ( 102) + entering idle mode

13:19:41.627 (8508) IDTIMER_TRANS_START kill
13:19:41.628 ( 348) ImapIdle Delete
13:19:41.628 (4789) Send ThreadCreated 13056
====== 2015/10/26 13:19:41 mode=IMAP4受信 account=***@****
13:19:41.628 S DONE
13:19:41.629 (10279) 受信 - ***@**** ... IDLEコマンド終了
R C0 OK IDLE completed
13:19:41.643 S C1 LIST "" *
13:19:41.643 (10279) MAPフォルダ一覧を取得中

一方、「IMAPの処理でエラーが発生しました。」となる場合は
IDLE監視のDONEに対する応答を待たずに受信処理のDONEが、

14:19:47.374 ( 275) DONE

14:19:47.375 (8508) IDTIMER_TRANS_START kill
14:19:47.375 ( 348) ImapIdle Delete
14:19:47.375 (4789) Send ThreadCreated 16024
====== 2015/10/26 14:19:47 mode=IMAP4受信 account=***@***
14:19:47.376 S DONE
14:19:47.376 (10279) 受信 - ***@*** ... IDLEコマンド終了
R C0 OK IDLE completed
14:19:47.388 S C1 LIST "" *
14:19:47.388 (10279) MAPフォルダ一覧を取得中
R DONE NO Error in IMAP command received by server.
14:19:47.399 E IMAPの処理でエラーが発生しました。行番号=12772

「長時間にわたってサーバーからの応答がありません。」の場合は
IDLE監視のC0 IDLEに対する応答を待たずに受信処理のDONEが、

21:19:44.917 ( 102) C0 OK IDLE completed

21:19:44.917 ( 275) C0 IDLE

21:19:44.926 (8508) IDTIMER_TRANS_START kill
21:19:44.927 ( 348) ImapIdle Delete
21:19:44.927 (4789) Send ThreadCreated 17848
====== 2015/10/26 21:19:44 mode=IMAP4受信 account=***@***
21:19:44.927 S DONE
21:19:44.928 (10279) 受信 - ***@*** ... IDLEコマンド終了
R + entering idle mode
21:19:44.933 (10279) 失敗につき、接続からやり直し

送信され、IDLE監視のIDLE/DONEに対する応答を
受信処理のDONEの応答として受け取っているのでは？と思った次第です。

>　また、仮にこれがおかしかったとしても、再接続
>した後にサーバーが応答しないのはまた別問題になると思います。

それは確かにそうですね。
再接続時のdump.txtには「SSL初期化中」とか「アカウント/パスワードを送信」とか
出ていませんが、これは問題ないでしょうか？

RE:48739 v6.46でIDLEコマンド終了時にエ

秀まるお2 さん　15/10/28 11:13

　状況理解できました。たしかにおっしゃる通り、「C0 IDLE」コマンドの応答
を待たずに「DONE」を送ってるケースでおかしくなってるようです。

　IDLE中の接続がおおよそ６分以上経過すると、自動的に「DONEを送ってもう一
度IDLEやり直し」って処理をするんですが、その処理の途中で受信が始まってし
まうとダメなようでした。なんとかうまく対処させていただきます。

> それは確かにそうですね。
> 再接続時のdump.txtには「SSL初期化中」とか「アカウント/パスワードを送信」とか
> 出ていませんが、これは問題ないでしょうか？

　すみません。これまたバグのようです。僕の所ではSSLはOFFでテストしてて問
題無かったんですが、SSLをONにしたらダメでした。

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

RE:48740 v6.46でIDLEコマンド終了時にエ

ぴよさん　15/10/29 21:28

早速 6.47b6 に更新してみたところ、見事にエラーが発生しなくなりました。

また、以下のようなログも確認できました。

****IMAP4受信:***@*** (高速化ON)
I IDLEコマンド応答待ち
R + entering idle mode
S DONE
I IDLEコマンド終了
R C0 OK IDLE completed
S C1 LIST "" *
I IMAPフォルダ一覧を取得中

というわけで、無事解決したと思います。ありがとうございました。

RE:48748 v6.46でIDLEコマンド終了時にエ

秀まるお2 さん　15/10/30 10:08

　確認ありがとうございます。

　なるべく早めに正式版としてアップロードさせていただきます。