6.0.0-beta1
7/17/25

[#11453] Very unstable IMAP client
Summary Very unstable IMAP client
Queue Horde Framework Packages
Queue Version Git master
Type Bug
State Resolved
Priority 3. High
Owners slusarz (at) horde (dot) org
Requester jan (at) horde (dot) org
Created 09/28/2012 (4675 days ago)
Due
Updated 10/15/2012 (4658 days ago)
Assigned 10/01/2012 (4672 days ago)
Resolved 10/05/2012 (4668 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch No

History
10/15/2012 08:42:38 PM Git Commit Comment #28 Reply to this comment
Changes have been made in Git (develop):

commit c37f6c6832d708743ccb1e41b4e432cf0ec5ff03
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Oct 4 15:41:47 2012 -0600

     Bug #11453: Fix grabbing the remaining string in a tokenizer stream

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |   38 
++++++++++----------
  .../Imap_Client/lib/Horde/Imap/Client/Tokenize.php |    2 +-
  .../test/Horde/Imap/Client/SocketTest.php          |    7 +++-
  3 files changed, 26 insertions(+), 21 deletions(-)

http://git.horde.org/horde-git/-/commit/c37f6c6832d708743ccb1e41b4e432cf0ec5ff03
10/15/2012 08:42:27 PM Git Commit Comment #27 Reply to this comment
Changes have been made in Git (develop):

commit db07b040d60942cb57a186802d5c69f924b084cd
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Oct 4 13:28:59 2012 -0600

     Bug #11453: Fix parsing bare response text codes

  .../lib/Horde/Imap/Client/Interaction/Server.php   |    6 +++++-
  .../test/Horde/Imap/Client/SocketTest.php          |   15 +++++++++++++++
  .../test/Horde/Imap/Client/Stub/Socket.php         |    8 ++++++++
  3 files changed, 28 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/db07b040d60942cb57a186802d5c69f924b084cd
10/15/2012 08:42:08 PM Git Commit Comment #26 Reply to this comment
Changes have been made in Git (develop):

commit 9fd6433e813fe55b8601a35b418cd5ac815fc17f
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Wed Oct 3 11:47:41 2012 -0600

     [mms] Store command that caused NO/BAD error in Exception, if it 
can be determined.

     Also, ignore untagged NO responses - these are warnings, not fatal, and
     generally will include response text codes that will be parsed elsewhere
     in the code.  Should fix Bug #11453

  .../Horde/Imap/Client/Exception/ServerResponse.php |   14 +++++++-
  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |   37 +++++++++++++++++--
  framework/Imap_Client/package.xml                  |    2 +
  3 files changed, 48 insertions(+), 5 deletions(-)

http://git.horde.org/horde-git/-/commit/9fd6433e813fe55b8601a35b418cd5ac815fc17f
10/15/2012 08:41:45 PM Git Commit Comment #25 Reply to this comment
Changes have been made in Git (develop):

commit 472a1e509d02de485104667e1637f57f14eb3993
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Mon Oct 1 15:39:40 2012 -0600

     Bug #11453: Correct fix for parsing a FETCH VANISHED response

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |    2 +-
  1 files changed, 1 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/472a1e509d02de485104667e1637f57f14eb3993
10/15/2012 08:41:40 PM Git Commit Comment #24 Reply to this comment
Changes have been made in Git (develop):

commit 6e2c84eca7368cc7a138a59a71f2733b3fc289f1
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Mon Oct 1 15:38:47 2012 -0600

     Bug #11453: Fix parsing a FETCH VANISHED response

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |    8 ++++----
  1 files changed, 4 insertions(+), 4 deletions(-)

http://git.horde.org/horde-git/-/commit/6e2c84eca7368cc7a138a59a71f2733b3fc289f1
10/05/2012 09:18:25 AM Jan Schneider Comment #23
State ⇒ Resolved
Reply to this comment
The original issues all seem to have been fixed now.
10/04/2012 09:42:32 PM Git Commit Comment #22 Reply to this comment
Changes have been made in Git (master):

commit c37f6c6832d708743ccb1e41b4e432cf0ec5ff03
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Oct 4 15:41:47 2012 -0600

     Bug #11453: Fix grabbing the remaining string in a tokenizer stream

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |   38 
++++++++++----------
  .../Imap_Client/lib/Horde/Imap/Client/Tokenize.php |    2 +-
  .../test/Horde/Imap/Client/SocketTest.php          |    7 +++-
  3 files changed, 26 insertions(+), 21 deletions(-)

http://git.horde.org/horde-git/-/commit/c37f6c6832d708743ccb1e41b4e432cf0ec5ff03
10/04/2012 08:45:24 PM Jan Schneider Comment #21 Reply to this comment
The errors are gone, but I still don't get warning notifications from
untagged responses.
This has been fixed.
Almost there, only the mailbox is missing. The notification text now 
is "is at xy% quota".
10/04/2012 07:29:54 PM Michael Slusarz Comment #20 Reply to this comment
The errors are gone, but I still don't get warning notifications 
from untagged responses.
This has been fixed.
10/04/2012 07:29:47 PM Git Commit Comment #19 Reply to this comment
Changes have been made in Git (master):

commit db07b040d60942cb57a186802d5c69f924b084cd
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Oct 4 13:28:59 2012 -0600

     Bug #11453: Fix parsing bare response text codes

  .../lib/Horde/Imap/Client/Interaction/Server.php   |    6 +++++-
  .../test/Horde/Imap/Client/SocketTest.php          |   15 +++++++++++++++
  .../test/Horde/Imap/Client/Stub/Socket.php         |    8 ++++++++
  3 files changed, 28 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/db07b040d60942cb57a186802d5c69f924b084cd
10/04/2012 07:16:47 PM Michael Slusarz Comment #18 Reply to this comment
This has nothing to do with the IMAP client though.  Please open 
another ticket.
In fact, this sounds exactly what I previously suggested in Ticket #11427.
10/04/2012 07:15:22 PM Michael Slusarz Comment #17 Reply to this comment
I still see the "Cannot open message" errors. I see those mostly 
when deleting messages. Could this be happening: I navigate to a 
message and hit Delete. The showMessage request is sent, the session 
is temporarily closed, the deleteMessages request is sent and 
executed immediately because the session is not locked. The delete 
request is completed faster than the showMessage request, so that 
some action on the message fails, like flagging as seen.
This has nothing to do with the IMAP client though.  Please open 
another ticket.
10/04/2012 03:07:21 PM Michael Rubinsky Comment #16 Reply to this comment
I still see the "Cannot open message" errors. I see those mostly when
deleting messages.
I can reliably reproduce this now, just hitting Down and Delete 
quickly after navigating to a mailbox.
Same here
10/04/2012 12:01:00 PM Jan Schneider Comment #15 Reply to this comment
I still see the "Cannot open message" errors. I see those mostly 
when deleting messages.
I can reliably reproduce this now, just hitting Down and Delete 
quickly after navigating to a mailbox.
10/04/2012 11:59:28 AM Jan Schneider Comment #14 Reply to this comment
I still see the "Cannot open message" errors. I see those mostly when 
deleting messages. Could this be happening: I navigate to a message 
and hit Delete. The showMessage request is sent, the session is 
temporarily closed, the deleteMessages request is sent and executed 
immediately because the session is not locked. The delete request is 
completed faster than the showMessage request, so that some action on 
the message fails, like flagging as seen.
10/04/2012 11:55:30 AM Jan Schneider Comment #13 Reply to this comment
The errors are gone, but I still don't get warning notifications from 
untagged responses.
10/03/2012 05:51:24 PM Michael Slusarz Comment #12 Reply to this comment
Could this be a parsing error with IMAP ALERTs?
No.  Instead the issue was that we were throwing exceptions on 
untagged NO responses, where this indicates a warning, not a fatal 
error.  This commit should fix that.
10/03/2012 05:49:48 PM Git Commit Comment #11 Reply to this comment
Changes have been made in Git (master):

commit 9fd6433e813fe55b8601a35b418cd5ac815fc17f
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Wed Oct 3 11:47:41 2012 -0600

     [mms] Store command that caused NO/BAD error in Exception, if it 
can be determined.

     Also, ignore untagged NO responses - these are warnings, not fatal, and
     generally will include response text codes that will be parsed elsewhere
     in the code.  Should fix Bug #11453

  .../Horde/Imap/Client/Exception/ServerResponse.php |   14 +++++++-
  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |   37 +++++++++++++++++--
  framework/Imap_Client/package.xml                  |    2 +
  3 files changed, 48 insertions(+), 5 deletions(-)

http://git.horde.org/horde-git/-/commit/9fd6433e813fe55b8601a35b418cd5ac815fc17f
10/03/2012 09:41:04 AM Jan Schneider Comment #10 Reply to this comment
Could this be a parsing error with IMAP ALERTs?

I'm currently always around the quota limit, and I just noticed that I 
didn't get quota warnings for a while. This would also explain why 
these errors come and go, because 1) sometimes I'm over, sometimes 
under the limit, and 2) the server doesn't respond each request with 
an ALERT. Example:
Timestamp: Wed, 03 Oct 2012 11:24:16 +0200
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE  XIMAPPROXY] neo 
Cyrus IMAP v2.4.12-Debian-2.4.12-2 server ready
C: [LOGIN Command - username: jan]
S: * OK [XPROXYREUSE] IMAP connection reused by imapproxy
S: 1 OK User logged in
C: 2 ENABLE QRESYNC
S: * ENABLED
S: 2 OK Completed
C: 3 SELECT "INBOX.Quarant&AOQ-ne" (CONDSTORE)
S: * 24 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen $forwarded $junk 
$notjunk)
S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen 
$forwarded $junk $notjunk \*)] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1240054819] Ok
S: * OK [UIDNEXT 56964] Ok
S: * OK [HIGHESTMODSEQ 7905] Ok
S: * OK [URLMECH INTERNAL] Ok
S: * NO [ALERT] Mailbox is at 91% of quota
C: 4 EXAMINE "INBOX.Quarant&AOQ-ne" (CONDSTORE)
S: 3 OK [READ-WRITE] Completed
Expired search results from cache (mailbox: INBOX.Quarantäne)
C: 5 UID THREAD REFERENCES US-ASCII ALL
S: * OK [CLOSED] Ok
S: * 24 EXISTS
S: * 0 RECENT
S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen $forwarded $junk 
$notjunk)
S: * OK [PERMANENTFLAGS ()] Ok
S: * OK [UNSEEN 1] Ok
S: * OK [UIDVALIDITY 1240054819] Ok
S: * OK [UIDNEXT 56964] Ok
S: * OK [HIGHESTMODSEQ 7905] Ok
S: * OK [URLMECH INTERNAL] Ok
S: 4 OK [READ-ONLY] Completed
Saved thread results to cache (mailbox: INBOX.Quarantäne; id: 
dc861924f5d0f35c6215ee03013aa8cc)
C: 6 STATUS "INBOX" (recent)
S: * THREAD 
(56941)((56940)(56942)(56950)(56953)(56954)(56958))((56943)(56944)(56947))((56945)(56946))(56948)(56949)(56951)(56952)(56955)((56956)(56963))(56957)((56959)(56961))(56960)(56962)
S: 5 OK Completed (24 msgs in 0.000 secs)
C: 7 STATUS "INBOX.horde.apps" (recent)
S: * STATUS INBOX (RECENT 0)
S: 6 OK Completed
C: 8 STATUS "INBOX.horde.bugs" (recent)
S: * STATUS INBOX.horde.apps (RECENT 0)
S: 7 OK Completed
C: 9 STATUS "INBOX.horde.cvs" (recent)
S: * STATUS INBOX.horde.bugs (RECENT 0)
S: 8 OK Completed
C: 10 STATUS "INBOX.horde.dev" (recent)
S: * STATUS INBOX.horde.cvs (RECENT 0)
S: 9 OK Completed
C: 11 STATUS "INBOX.horde.imp" (recent)
S: * STATUS INBOX.horde.dev (RECENT 0)
S: 10 OK Completed
C: 12 STATUS "INBOX.Privat" (recent)
S: * STATUS INBOX.horde.imp (RECENT 0)
S: 11 OK Completed
C: 13 LOGOUT
S: * STATUS INBOX.Privat (RECENT 0)
S: * BYE LOGOUT received
S: 13 OK Completed

10/02/2012 09:22:52 PM Michael Rubinsky Comment #9 Reply to this comment
After pulling today, my issue has been resolved.
10/01/2012 09:40:25 PM Michael Slusarz Comment #8 Reply to this comment
There was an issue parsing the response EARLIER data, but that would 
not have affected you since you were getting no VANISHED response.   
This issue has been fixed.
10/01/2012 09:39:52 PM Git Commit Comment #7 Reply to this comment
Changes have been made in Git (master):

commit 472a1e509d02de485104667e1637f57f14eb3993
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Mon Oct 1 15:39:40 2012 -0600

     Bug #11453: Correct fix for parsing a FETCH VANISHED response

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |    2 +-
  1 files changed, 1 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/472a1e509d02de485104667e1637f57f14eb3993
10/01/2012 09:39:00 PM Git Commit Comment #6 Reply to this comment
Changes have been made in Git (master):

commit 6e2c84eca7368cc7a138a59a71f2733b3fc289f1
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Mon Oct 1 15:38:47 2012 -0600

     Bug #11453: Fix parsing a FETCH VANISHED response

  .../Imap_Client/lib/Horde/Imap/Client/Socket.php   |    8 ++++----
  1 files changed, 4 insertions(+), 4 deletions(-)

http://git.horde.org/horde-git/-/commit/6e2c84eca7368cc7a138a59a71f2733b3fc289f1
10/01/2012 09:35:13 PM Michael Slusarz Comment #5
State ⇒ Feedback
Reply to this comment
$vanished = $imap->vanished($mbox, 573852);
[snip]
var_dump($vanished->ids);

returns an empty array.
[snip]
C: 4 UID FETCH 1:* UID (VANISHED CHANGEDSINCE 573852)
S: * 37 FETCH (UID 138721 MODSEQ (573857))
S: 4 OK Fetch completed.
C: 5 LOGOUT
S: * BYE LOGOUT received
S: 5 OK Completed
That code is running perfect.  There is no VANISHED response, so no 
messages have been deleted between those MODSEQs according to the 
server.

I can verify this works fine on my server.  E.g.:

C: 4 UID FETCH 1:* UID (VANISHED CHANGEDSINCE 34240)
S: * VANISHED (EARLIER) 14199,14239,14242
S: * 37 FETCH (UID 14211 MODSEQ (34251))
S: * 38 FETCH (UID 14212 MODSEQ (34250))
S: * 39 FETCH (UID 14243 MODSEQ (34249))
S: 4 OK Fetch complete

Shot in the dark: try this change in _vanished():

         $cmd = $this->_clientCommand(array(
             'UID',
             'FETCH',
             $ids->all ? '1:*' : strval($ids),
-           'UID',
+           new Horde_Imap_Client_Data_Format_List('UID'),
             new Horde_Imap_Client_Data_Format_List(array(
                 'VANISHED',
                 'CHANGEDSINCE',
                 new Horde_Imap_Client_Data_Format_Number($modseq)
             ))
         ));
09/28/2012 04:31:02 PM Michael Rubinsky Comment #4 Reply to this comment
Sample Code:

$imap = $registry->mail->imapOb();
$mbox = new Horde_Imap_Client_Mailbox('INBOX');
$status_flags = Horde_Imap_Client::STATUS_HIGHESTMODSEQ |
                 Horde_Imap_Client::STATUS_UIDVALIDITY |
                 Horde_Imap_Client::STATUS_UIDNEXT;

$status = $imap->status($mbox, $status_flags);
var_dump($status);

// At this point, modseq is reported as 573852
// I delete some email(s) from the INBOX, verify they are deleted by 
accessing the same INBOX on another client then:

$vanished = $imap->vanished($mbox, 573852);
var_dump($vanished->ids);

returns an empty array.


The following IMAP log is generated during the vanished call:

S: * OK [CAPABILITY IMAP4rev1 LITERAL+ LOGIN-REFERRALS ID ENABLE   
XIMAPPROXY] Dovecot ready.
C: [LOGIN Command - username: mike]
S: * OK [XPROXYREUSE] IMAP connection reused by imapproxy
S: 1 OK User logged in
C: 2 STATUS "INBOX" (uidnext uidvalidity highestmodseq)
S: * STATUS "INBOX" (UIDNEXT 138723 UIDVALIDITY 1292457115 
HIGHESTMODSEQ 573857)
S: 2 OK Status completed.
C: 3 EXAMINE "INBOX" (QRESYNC (1292457115 573857 
112036,119945:119946,123483,126397,127831,128044,130389,130457,132128,135833,136202,136302,136317,137188,137688,137690,137817,138171,138188,138214,138233,138238:138239,138254,138266:138267,138271:138273,138282,138309,138311,138314,138479:138673,138675:138708,138713:138717,138721:138722))
S: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft $Junk $NotJunk 
$Forwarded Test_Tso test_one JunkRecorded $mdnsent)
S: * OK [PERMANENTFLAGS ()] Read-only mailbox.
S: * 38 EXISTS
S: * 0 RECENT
S: * OK [UNSEEN 38] First unseen.
S: * OK [UIDVALIDITY 1292457115] UIDs valid
S: * OK [UIDNEXT 138723] Predicted next UID
S: * OK [HIGHESTMODSEQ 573857] Highest
S: 3 OK [READ-ONLY] Select completed.
C: 4 UID FETCH 1:* UID (VANISHED CHANGEDSINCE 573852)
S: * 37 FETCH (UID 138721 MODSEQ (573857))
S: 4 OK Fetch completed.
C: 5 LOGOUT
S: * BYE LOGOUT received
S: 5 OK Completed
09/28/2012 04:10:57 PM Michael Rubinsky Comment #3 Reply to this comment
Has anything changed in the way vanished messages are reported? Since 
the recent refactoring ActiveSync is no longer picking up on expunged 
messages.
09/28/2012 04:02:51 PM Michael Slusarz Comment #2 Reply to this comment
I ran the new code for about a day on my local machine, with both the 
horde/error log and IMAP debugging in the background, and I was not 
seeing any issues. Used the smartmobile view for about 10 minutes 
earlier and didn't have any issues either.  So IMAP logs of the issues 
will be necessary.

FYI: these IMAP changes have been verified to fix the DoS issue that 
was the initial reason why all of this was rewritten.
09/28/2012 11:46:06 AM Jan Schneider Comment #1
Priority ⇒ 3. High
State ⇒ Assigned
Patch ⇒ No
Milestone ⇒
Assigned to Michael Slusarz
Summary ⇒ Very unstable IMAP client
Type ⇒ Bug
Queue ⇒ Horde Framework Packages
Reply to this comment
Since the refactoring, I have all kinds of random, intermittent errors 
like "Cannot open mailbox foo", "Folder structure changed on the 
server", "Cannot open message" etc. Sometimes IMP recovers with the 
next request, sometimes one has to reload IMP completely.

Saved Queries