Imap.GetMailMessage call throws ImapException "timeout" when confronted with a specific mail

Question

Hello there,

we are using the Rebex Imap class (version 2012 R3, assembly version of Rebex.Imap.dll 2.0.47000.0) to connect to a Lotus Notes mailbox and download mails with their attachments from it.

Encountering a specific mail, the call of Imap.GetMailMessage causes an ImapException "Timeout exceeded" to be thrown. I increased the timeout to 4 minutes with no effect.

The mail causing this problem does not seem to be any special, it contains an attachment which is not very big (the complete mail needs 144KB of space). In Lotus Notes itself, the mail and its attachment can be opened and viewed without problems.

This is the debug log the imap component created while encountering the problem:

  2017-11-16 08:11:15.635 Opening log file.
  2017-11-16 08:11:15.675 INFO Imap(1)[9] Info: Connecting to *SERVERNAMEREMOVED*:143 using Imap 2.0.4700.0.
  2017-11-16 08:11:15.703 DEBUG Imap(1)[9] Info: Connection succeeded.
  2017-11-16 08:11:15.712 INFO Imap(1)[9] Response: * OK Domino IMAP4 Server Release 9.0.1FP9 HF139 ready Thu, 16 Nov 2017 08:11:13 +0100
  2017-11-16 08:11:15.729 INFO Imap(1)[9] Command: R00001 CAPABILITY
  2017-11-16 08:11:15.729 INFO Imap(1)[9] Response: * CAPABILITY IMAP4rev1 AUTH=PLAIN LITERAL+ QUOTA UIDPLUS
  2017-11-16 08:11:15.729 INFO Imap(1)[9] Response: R00001 OK CAPABILITY completed
  2017-11-16 08:11:15.740 INFO Imap(1)[9] Command: R00002 AUTHENTICATE PLAIN
  2017-11-16 08:11:15.740 INFO Imap(1)[9] Response: + 
  2017-11-16 08:11:15.740 INFO Imap(1)[9] Command: ****************************
  2017-11-16 08:11:15.785 INFO Imap(1)[9] Response: R00002 OK AUTHENTICATE completed
  2017-11-16 08:11:15.913 INFO Imap(1)[9] Command: R00003 LIST "" Inbox
  2017-11-16 08:11:15.916 INFO Imap(1)[9] Response: * LIST (\Noinferiors \HasNoChildren) "\\" Inbox
  2017-11-16 08:11:15.916 INFO Imap(1)[9] Response: R00003 OK LIST completed
  2017-11-16 08:11:15.925 INFO Imap(1)[9] Command: R00004 STATUS Inbox (UNSEEN)
  2017-11-16 08:11:15.942 INFO Imap(1)[9] Response: * STATUS Inbox (UNSEEN 0)
  2017-11-16 08:11:15.942 INFO Imap(1)[9] Response: R00004 OK STATUS completed
  2017-11-16 08:11:15.943 INFO Imap(1)[9] Command: R00005 SELECT Inbox
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * 1 EXISTS
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * 0 RECENT
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * OK [UIDVALIDITY 9] UIDs valid
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * OK [UIDNEXT 40339] Predicted next UID
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * FLAGS (\Flagged \Seen \Answered \Deleted \Draft)
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: * OK [PERMANENTFLAGS (\Flagged \Seen \Answered \Deleted \Draft \*)] Permanent flags
  2017-11-16 08:11:15.944 INFO Imap(1)[9] Response: R00005 OK [READ-WRITE] SELECT completed
  2017-11-16 08:11:15.957 INFO Imap(1)[9] Command: R00006 FETCH 1:* (UID RFC822.SIZE FLAGS INTERNALDATE BODY.PEEK[HEADER])
  2017-11-16 08:11:16.026 INFO Imap(1)[9] Response: * 1 FETCH (UID 40338 RFC822.SIZE 198862 INTERNALDATE "09-Nov-2017 22:44:05 +0000" BODY[HEADER] {3484}
  2017-11-16 08:11:16.030 INFO Imap(1)[9] Response: ...3484 bytes...
  2017-11-16 08:11:16.030 INFO Imap(1)[9] Response:  FLAGS (\Seen))
  2017-11-16 08:11:16.030 INFO Imap(1)[9] Response: R00006 OK FETCH completed
  2017-11-16 08:11:16.184 INFO Imap(1)[9] Command: R00007 UID FETCH 40338 (UID BODY[])
  2017-11-16 08:11:16.186 INFO Imap(1)[9] Response: * 1 FETCH (UID 40338 BODY[] {198862}
  2017-11-16 08:11:16.197 INFO Imap(1)[9] Response: ...198862 bytes...
  2017-11-16 08:11:16.197 INFO Imap(1)[9] Response:  completed
  2017-11-16 08:11:32.246 ERROR Imap(1)[9] Info: Rebex.Net.ImapException: Timeout exceeded.
     bei Rebex.Net.Imap.dufNZZ()
     bei gbMKS.1aSfK6.1IsOQMZ(Byte[] , Int32 , Int32 )
     bei gbMKS.1aSfK6.ywUDZZ(Int32& )
     bei Rebex.Net.Imap.1dH3Qs()
     bei Rebex.Net.Imap.1WiTOoZ(String , ArrayList )
     bei Rebex.Net.Imap.1SAJuN(String , 1YxU2Z , String , Boolean )
     bei Rebex.Net.Imap.1q27zkZ(ImapMessageSet , Int32 , UInt32 , Boolean , String )
     bei Rebex.Net.Imap.OKEf9(ImapMessageCollection , ImapMessageSet , Int32 , UInt32 , Boolean , String , Int64 )
     bei Rebex.Net.Imap.fbC0l(ImapMessageSet , Int32 , Boolean , Int64 , Int32 )

I am aware that we are using a rather outdated version of Rebex, the error might be already fixed in newer versions. However, i checked wether the problem would disappear with a current download of your 30-day trial files. The problem seems to persist with the Rebex.Imap.dll version 2.0.6508.0.

Any help is greatly appreciated!

Best regards,

Andreas

Answer 1

Hello,

The log suggests that this is most likely a bug in the IMAP server. In response to FETCH command (used by GetMailMessage method), the server indicated it's sending a message of 198862 bytes, but sent slightly less message data, which caused the IMAP client to treat the first few bytes of the expected "R00007 OK FETCH completed" response as message data:

Response: R00006 OK FETCH completed
Command: R00007 UID FETCH 40338 (UID BODY[])
Response: * 1 FETCH (UID 40338 BODY[] {198862}
Response: ...198862 bytes...
Response:  completed

Note the last line that contains the ending part of the expected response.

To verify this is indeed the case, set logging level to LogLevel.Verbose before calling the GetMailMessage method, making it possible to inspect the actual message data and confirm this is indeed a server-side bug. Alternatively, use a network protocol analyzer such as Wireshark to capture and inspect the communication at the network level.

Does Lotus Notes use IMAP to receive the e-mail? If not, that would explain why it doesn't suffer from the same issue.

In the past, some of our clients encountered very similar issues with Lotus Notes, although less severe. We added a workaround for that, but it was not effective for the more severe form of the bug you encountered.

If this is confirmed to be a server bug (and that looks very likely), the proper solution would be to fix the server. Implementing a workaround at the client-side is another option, but this is non-trivial, outside the scope of Rebex support and futher complicated by the fact that we are unable to reproduce this ourselves. If you would like to pursue this solution, please get in touch with us at support@rebex.net.

Comments

Thank you very much for the swift and helpful answer! With the analyzation of the log file created with verbose level and the raw data shown there, i could indeed calculate that there are 18 bytes of the payload missing that should have been sent from the server.

Best regards,

Andreas