#538 IMAP store time-out

[Roel van de Kraats]

Hi Mickaël,

I'm trying to copy a local folder containing some larger mails (few MB) to a DavMail-IMAP-EWS folder using Thunderbird 17 and DavMail 4.3.3-2164-trunk. But after a minute Thunderbird aborts with a time-out. I have selected setting 'Enable KeepAlive'.

I see there's a class 'MessageLoadThread' that prevents IMAP timeouts for loading large messages. But should there be a separate 'MessageSendThread' or so for this situation?

Thanks!
Roel

[Mickael Guessant]

Well, I could but I would need to find a way to let client wait...
Did you try to change Thunderbird timeout settings ?

[Roel van de Kraats]

I see, so the 'keep alive' trick that you use in MessageLoadThread can't easily be used for storing messages. That's a pity.

Yes, I tried to change the Thunderbird timeout settings, but that doesn't help. E.g. the mail.server.server*.timeout value jumps back to '29'.

Would it be possible to have DavMail read from the tcp socket slower (in chunks) so the sending side (Thunderbird) would be more 'in pace' with the communication with Exchange? I don't know if would help, considering the large network buffers that are used everywhere. I also don't know if DavMail is able to properly forward a message that it only received partly.

[Roel van de Kraats]

I was playing a bit with throttling the socket read, but it doesn't seem to work. Also after calling AbstractServer.serverSocket.setReceiveBufferSize() with a small value (1024) and doing small read()'s and a sleep() in AbstractConnection.readContent(), TB still times-out. Only after a long time (indicating some large buffer somewhere) I finally get an 'End of stream reached reading content' exception.

By the way, in AbstractConnection.readContent() I see that 'in.read()' is called. Since I think 'in' is the FilterInputStream original stream, this will by-pass the pushback buffer. Shouldn't it therefore just be 'read()'?

[Roel van de Kraats]

Regarding 'a way to let client wait', would it be possible to send some untagged status update, like '* CAPABILITY ..' (http://tools.ietf.org/html/rfc3501#section-7.2.1)?

[Mickael Guessant]

Didn't work:
4164[d175320]: e12b800:localhost:S-Drafts:PARSER:Internal Syntax Error on line: %s: * Still loading message

=> Thunderbird does not expect an untagged response

[Roel van de Kraats]

Perhaps it should be a valid msg, like the 'CAPABILITY ..' I suggested?

[Mickael Guessant]

Seems to work, could you please test latest svn revision ?

Make sure you enable davmail.enableKeepAlive

[Roel van de Kraats]

Thanks for your support, Mikael!

At first glance the 'untagged response' trick seems to work; the original TB time-out after about a minute no longer occurs.

But with a very large mail, the connection is still closes after 5 minutes. This is what the TB log shows:

2013-09-16 17:49:34.502014 UTC - -1695549696[7f098b179ad0]: ReadNextLine [stream=a6bfd410 nb=45 needmore=0]
2013-09-16 17:49:34.502086 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:CreateNewLineFromSocket: * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 17:49:54.504763 UTC - -1695549696[7f098b179ad0]: ReadNextLine [stream=a6bfd410 nb=45 needmore=0]
2013-09-16 17:49:54.505081 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:CreateNewLineFromSocket: * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 17:50:14.507017 UTC - -1695549696[7f098b179ad0]: ReadNextLine [stream=a6bfd410 nb=45 needmore=0]
2013-09-16 17:50:14.507074 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:CreateNewLineFromSocket: * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 17:50:34.508313 UTC - -1695549696[7f098b179ad0]: ReadNextLine [stream=a6bfd410 nb=0 needmore=1]
2013-09-16 17:50:34.508367 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:CreateNewLineFromSocket: clearing IMAP_CONNECTION_IS_OPEN - rv = 804b000e
2013-09-16 17:50:34.508552 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:TellThreadToDie: close socket connection
2013-09-16 17:50:34.508590 UTC - -1695549696[7f098b179ad0]: 9c8c4000:mail.xxx.com:A:CreateNewLineFromSocket: (null)

davmail.log shows:

2013-09-16 19:49:34,501 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - Still loading message, send capabilities untagged response to avoid timeout
2013-09-16 19:49:34,501 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 19:49:54,504 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - Still loading message, send capabilities untagged response to avoid timeout
2013-09-16 19:49:54,504 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 19:50:14,506 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - Still loading message, send capabilities untagged response to avoid timeout
2013-09-16 19:50:14,506 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 19:50:34,508 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - Still loading message, send capabilities untagged response to avoid timeout
2013-09-16 19:50:34,508 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 19:50:54,509 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - Still loading message, send capabilities untagged response to avoid timeout
2013-09-16 19:50:54,509 DEBUG [ImapConnection-49478] davmail.exchange.MessageCreateThread  - * CAPABILITY IMAP4REV1 AUTH=LOGIN IDLE MOVE
2013-09-16 19:50:54,510 WARN  [ImapConnection-49478] davmail.imap.ImapConnection  - Client closed connection

In TB I can't find any config parameter that seems to be related to this 5 minute time-out.

Anyway, the situation has improved, seemingly without any (problematic) side-effects. But there's still some next burden to take...

[Mickael Guessant]

Are you sure you didn't set mailnews.tcptimeout to 5 minutes ?

Anyway, this is probably the best I can do on DavMail side

[Roel van de Kraats]

Nope, it's not mailnews.tcptimeout. I'll try to figure out who closes the connection and why.

[Roel van de Kraats]

I'm not able to reproduce this problem. Copying the same large messages now gives an 'Insufficient Storage' exception. AFAIK the only difference with the previous time is that my internet connection's speed is higher now. Anyway, I think this ticket can be closed.