Monday, May 26, 2014

IMAP UID Error: "Your Server reported a UID that does not comply with the IMAP standard. This typically indicates a Server Bug. Your program may not function properly after this."

This post might be helpful for those working on IMAP Server.
In this post I will try to explain why this error occurs.


Error Text.
Your Server reported a UID that does not comply with the IMAP
standard. This typically indicates a Server Bug. Your program may
not function properly after this.

Account: youremail@yourdomain.com
MsgSeqNum 147, New UID 3193, Prev UID:3193, Next UID:0,
Protocol: IMAP
Server: the email server name you are using
Port: 993 or 143
Error Code: 0x800CCCDC


Error Dialog Box Image.


[1] Background For Understanding This Error.
To understand this error we need to first understand 3 things:
[1.1] The NOOP Command.
[1.2] Outlook Behaviour.
[1.3] UID Of A Message In IMAP.

[1.1] The NOOP Command.
RFC 3501 - INTERNET MESSAGE ACCESS PROTOCOL - VERSION 4rev1
http://tools.ietf.org/html/rfc3501#section-6.1.2

6.1.2. NOOP Command
Arguments:  none
Responses:  no specific responses for this command (but see below)
Result:     OK - noop completed
            BAD - command unknown or arguments invalid

   The NOOP command always succeeds.  It does nothing.
   Since any command can return a status update as untagged data, the
   NOOP command can be used as a periodic poll for new messages or
   message status updates during a period of inactivity (this is the
   preferred method to do this).  The NOOP command can also be used
   to reset any inactivity autologout timer on the server.

Example:    C: a002 NOOP
            S: a002 OK NOOP completed
               . . .
            C: a047 NOOP
            S: * 22 EXPUNGE
            S: * 23 EXISTS
            S: * 3 RECENT
            S: * 14 FETCH (FLAGS (\Seen \Deleted))
            S: a047 OK NOOP completed
              
* [MsgSeqNum] EXPUNGE
Gives info(Message Sequence Number) of message deleted.

* [TotalMsg] EXISTS
Gives info of Total Messages currently in mail box.

* [TotalNewMsg] RECENT
Gives info of Total number of New Messages in mail box.

[1.2] Outlook Behaviour.
Outlook fires NOOP command to get the latest details of mailbox in order to refresh its MailList.

[1.3] UID Of A Message In IMAP.
2.3.1.1. Unique Identifier (UID) Message Attribute
RFC 3501 - INTERNET MESSAGE ACCESS PROTOCOL - VERSION 4rev1
http://tools.ietf.org/html/rfc3501#section-2.3.1.1

If IMAP Server have assigned a message a particular UID "U", then
that UID "U" MUST NOT refer to any other message in the mailbox or any
subsequent mailbox with the same name forever.


[2] Main Cause Of This UID Error.
This error can be caused by discrepancies among the UID of messages on IMAP Server and IMAP Client side.
In my case IMAP Server was at fault.

[3] Details Of My IMAP Server System.
Whenever a command is received on IMAP Server for
- Message Delete
- Message state change, i.e making it UNREAD or READ
- etc..
it updates a separate remote Message Storage and Indexing Server.

Also whenever a NOOP command is received the
* EXPUNGE
* EXISTS
* RECENT
information which is required to be send in response to NOOP command, is prepared using this remote Message Storage and Indexing Server.

In IMAP Server, some local data structures are also maintained for satisfying various IMAP commands.
After updating local data structures, the separate remotely maintained Message Storage and Indexing Server is updated in background.
But the response of a command is send to IMAP Client after updating local data structures while Message Storage and Indexing Server gets updated in background.
This way of maintaining all the message information using local and remote data structures was not a problem before I encountered this UID Error.

[4] How The Error Was Traced?
I SELECTed the "Trash" Folder in Outlook and deleted the latest or most recent message from the Folder.
I logged request-response communication which was happening between IMAPServer and IMAPClient.

< means from IMAPClient(Outlook) fired command to IMAPServer.
> means IMAPServer send response of a command to IMAPClient(Outlook).

IMAP Server received following 5 command from Outlook one after another.

2014-05-20 12:16:24.174617500 29397 < 1kaf SELECT "Trash"
2014-05-20 12:16:24.214836500 29397 > * FLAGS (\Draft \Answered \Flagged \Deleted \Seen \Recent)
2014-05-20 12:16:24.214837500 29397 > * OK [PERMANENTFLAGS (\Draft \Answered \Flagged \Deleted \Seen)] Limited
2014-05-20 12:16:24.214838500 29397 > * 147 EXISTS
2014-05-20 12:16:24.214839500 29397 > * 5 RECENT
2014-05-20 12:16:24.214839500 29397 > * OK [UIDVALIDITY 1377145668] Ok
2014-05-20 12:16:24.214854500 29397 > 1kaf OK [READ-WRITE] Ok

2014-05-20 12:16:24.441563500 29397 < b3dq FETCH 147 (UID)
2014-05-20 12:16:24.441578500 29397 > * 147 FETCH (UID 3193)
2014-05-20 12:16:24.441579500 29397 > b3dq OK FETCH completed.

2014-05-20 12:17:50.343603500 29397 < zuvi UID STORE 3170 +FLAGS (\Deleted \Seen)
2014-05-20 12:17:50.504073500 29397 > * 141 FETCH (FLAGS (\Deleted \Seen) UID 3170)
2014-05-20 12:17:50.504075500 29397 > * 141 EXPUNGE
2014-05-20 12:17:50.504075500 29397 > * 146 EXISTS
2014-05-20 12:17:50.504076500 29397 > zuvi OK STORE completed.

2014-05-20 12:17:50.579307500 29397 < l1md NOOP
2014-05-20 12:17:50.623917500 29397 > * 147 EXISTS
2014-05-20 12:17:50.623918500 29397 > * 5 RECENT
2014-05-20 12:17:50.623918500 29397 > * 141 FETCH (FLAGS (\Seen))
2014-05-20 12:17:50.623919500 29397 > l1md OK NOOP completed

2014-05-20 12:17:50.799548500 29397 < bgl4 FETCH 147 (UID)
2014-05-20 12:17:50.799550500 29397 > * 147 FETCH (UID 3193)
2014-05-20 12:17:50.799576500 29397 > bgl4 OK FETCH completed.

Let's analyse these 5 command:
[a]
2014-05-20 12:16:24.174617500 29397 < 1kaf SELECT "Trash"
2014-05-20 12:16:24.214838500 29397 > * 147 EXISTS
< IMAPClient selected Folder "Trash".
> IMAPServer said the folder has 147 messages in it.

[b]
2014-05-20 12:16:24.441563500 29397 < b3dq FETCH 147 (UID)
2014-05-20 12:16:24.441578500 29397 > * 147 FETCH (UID 3193)
< IMAPClient tried to fetch UID of Message whose sequence number is 147.
> IMAPServer said UID of Message with sequence number 147 is 3193.

[c]
2014-05-20 12:17:50.343603500 29397 < zuvi UID STORE 3170 +FLAGS (\Deleted \Seen)
2014-05-20 12:17:50.504073500 29397 > * 141 FETCH (FLAGS (\Deleted \Seen) UID 3170)
2014-05-20 12:17:50.504075500 29397 > * 141 EXPUNGE
2014-05-20 12:17:50.504075500 29397 > * 146 EXISTS
< IMAPClient send a command "STORE" to delete a message whose UID is 3170.
> IMAPServer successfully deleted the message and told the IMAPClient that now there are 146 mails in the Trash Folder.

[d]
2014-05-20 12:17:50.579307500 29397 < l1md NOOP
2014-05-20 12:17:50.623917500 29397 > * 147 EXISTS
2014-05-20 12:17:50.623918500 29397 > * 5 RECENT
2014-05-20 12:17:50.623918500 29397 > * 141 FETCH (FLAGS (\Seen))
< IMAPClient send a NOOP command.
> IMAPServer told IMAPClient that there are 147 messages and the flags of message number 141 has changed.

[e]
2014-05-20 12:17:50.799548500 29397 < bgl4 FETCH 147 (UID)
2014-05-20 12:17:50.799550500 29397 > * 147 FETCH (UID 3193)
< IMAPClient tried to fetch the UID of message whose sequence number is 147.
> IMAPServer told IMAPClient that UID of message with sequence number 147 is 3193.

In between these 5 commands no new mails were delivered to "Trash Folder".
In third command[c] after deleting message with UID 3170 when the IMAPServer told that there EXISTS 146 messages in Trash Folder then, in the response of next NOOP command[d] IMAPServer should have told that there EXISTS 146 messages.
But IMAPServer replied that there EXISTS 147 messages, as can be seen in the response of commmand[d].
So IMAPClient might have thought that 1 new message has been arrived in the mailbox.
Therefore in the next command[e] IMAPClient tried to fetch the UID of new message and IMAPServer replied with UID of 3193.
Now UID 3193 was previously send by IMAPServer as can be seen in the response of command[b].
And as per IMAP standard the UID of new messages should increase and should not have been be used previously.

[5] Why I Encountered This UID Error?
I encountered this UID error due to some delay or latency in updating the remote Message Storags and Indexing Server.
Time difference between STORE command[c] response send from IMAPServer and the next NOOP command[d] received on IMAPServer was 75231000 nsec [579307500 - 504076500].
In such a small time frame of 75231000 nsec the Message Storage and Indexing Server was not updated in background.
The message with UID 3170 was deleted from local data structures and corresponding informations was posted to remote Message Storage and Indexing Server.
Before the Message Storage and Indexing Server could get updated, Outlook fired NOOP. And as NOOP response is prepared using Message Storage and Indexing Server in my IMAP Server System, the response included the deleted message with UID 3170.

[6] What Exactly Was The Problem?
There was no problem in IMAPServer with respect to assigning new UID to new messages.
The real problem happened due to very small time gap between successive commands received on iMAPServer.

Also the problem was related to synchronization of local and remote data structures on IMAPServer side.
This error does not occurs frequently because exactly when NOOP will be fired from Outlook is not predictable after a message is deleted.

[7] How To Reproduce This Problem?
This UID Error can occur in any Folder.

If IMAP Server System uses some local caches and remote storage for message data then this error might pop up due to delay as explained above.
Send some 50 test mails to an account. Now keep deleting them one by one at a time gap of 2 sec.
In my case Outlook fires NOOP at an interval of 60 seconds.


[8] Some Quick Resolutions w.r.t This Error For IMAPClients.
http://support.microsoft.com/kb/294779