Very annoying IMAP problem (cyrus + Outlook)

Fri Sep 19 13:08:20 EDT 2008

At the end, we solved the problem by simply doing in Outlook something 
like "Deleted messages marked as being deleted" and no more problem !!!

Denis

Denis BUCHER a écrit :
> Strange but it doesn't appear in the transaction logs.
> 
> Anyway, we think we solved the problem by deleting messages marked as 
> being deleted ! ("Expunge" AFAIK ?)
> 
> I'll keep you posted in case of new information/discoveries/solutions
> 
> Denis
> 
> Wesley Craig a écrit :
>> On 01 Sep 2008, at 14:50, Denis BUCHER wrote:
>>> What should I do next to solve my problem ?
>> There are actually a couple of places cyrus might give the fatal error 
>> "word too long".  The prot routines should be recording the interactions 
>> before passing the data up to the imap layer where the parsing error 
>> occurs.  Are there any long lines in your telemetry?  The bad line 
>> should directly proceed "* BYE Fatal error: word too long" in the 
>> telemetry (if I'm reading imapd's fatal() routine correctly).
>>
>> AFAIK, there's nothing to be done other than adjusting the MAXWORD 
>> and/or MAXQUOTED limits.  That means upgrading or recompiling the old 
>> version that you're on.
>>
>> :wes
>>
>>> Denis BUCHER a écrit :
>>>> David Carter a écrit :
>>>>> On Fri, 22 Aug 2008, Denis BUCHER wrote:
>>>>>> As far as I understand, the cause of the problem is : * "Outlook is
>>>>>> sending either a token or quoted string that is longer than 8K bytes."
>>>>> Your problem is a mailbox which contains several thousand messages.
>>>>> Possibly several thousand messages which Outlook hasn't seen 
>>>>> previously.
>>>>>
>>>>> Outlook tries to construct a single IMAP command of the form:
>>>>>
>>>>>  UID FETCH uid,uid,uid,... <some set of fields>
>>>>>
>>>>> where the list of UIDs is larger than 8 KBytes in size.
>>>> Ok that's what I have :
>>>>
>>>> a) Logs are present
>>>> # ls -l /var/lib/imap/log/dbucher
>>>> total 2508
>>>> -rw------- 1 cyrus mail 355147 Aug 22 14:43 20235
>>>> -rw------- 1 cyrus mail   5327 Aug 22 14:43 25058
>>>> -rw------- 1 cyrus mail  10654 Aug 22 14:54 25415
>>>> -rw------- 1 cyrus mail 355241 Aug 22 15:24 25416
>>>> -rw------- 1 cyrus mail 355537 Aug 22 15:03 25417
>>>> -rw------- 1 cyrus mail 355147 Aug 22 14:48 25576
>>>> -rw------- 1 cyrus mail   5327 Aug 22 14:59 26381
>>>> -rw------- 1 cyrus mail   5327 Aug 22 15:04 26763
>>>> -rw------- 1 cyrus mail 355443 Aug 22 15:15 26765
>>>> -rw------- 1 cyrus mail   5327 Aug 22 15:09 27095
>>>> -rw------- 1 cyrus mail   5327 Aug 22 15:14 27752
>>>> -rw------- 1 cyrus mail 360146 Aug 22 15:19 28135
>>>> -rw------- 1 cyrus mail   5327 Aug 22 15:24 28463
>>>> -rw------- 1 cyrus mail   5327 Aug 22 15:29 29125
>>>> -rw------- 1 cyrus mail 355147 Aug 22 15:29 29127
>>>>
>>>> b) That's the UID FETCH :
>>>> # grep "UID FETCH" *
>>>> 20235:<1219408982<jbf7 UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 20235:<1219408982<eke2 UID FETCH 1:7135 (UID FLAGS)
>>>> 25416:<1219411440<kb1u UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 25416:<1219411440<qv47 UID FETCH 1:7135 (UID FLAGS)
>>>> 25417:<1219409521<1ozq UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 25417:<1219409521<h7ki UID FETCH 1:7135 (UID FLAGS)
>>>> 25576:<1219409287<ukf6 UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 25576:<1219409287<9vks UID FETCH 1:7135 (UID FLAGS)
>>>> 26765:<1219410214<y8b2 UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 26765:<1219410214<b685 UID FETCH 1:7135 (UID FLAGS)
>>>> 28135:<1219411131<7bfi UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 28135:<1219411131<dkkx UID FETCH 1:7135 (UID FLAGS)
>>>> 29127:<1219411745<4g4y UID FETCH 7136:* (UID FLAGS RFC822.SIZE
>>>> BODY.PEEK[HEADER] INTERNALDATE)
>>>> 29127:<1219411745<cos6 UID FETCH 1:7135 (UID FLAGS)
>>>>
>>>> c) Most sessions in the logs seem to finish correctly :
>>>> ...
>>>> <1219411787<DONE
>>>> ZZZZ LOGOUT
>>>>> 1219411787>5mk6 OK Completed
>>>> * BYE LOGOUT received
>>>> ZZZZ OK Completed
>>>>
>>>> d) But not all :
>>>> ==> 30887 <==
>>>>> 1219413279>91rc OK Completed
>>>> <1219413279<6leo IDLE
>>>>> 1219413279>+ idling
>>>> <1219413343<DONE
>>>>> 1219413343>6leo OK Completed
>>>> <1219413343<351h UID STORE 7136 +FLAGS (\Deleted \Seen)
>>>>> 1219413343>* 7136 FETCH (FLAGS (\Deleted \Seen) UID 7136)
>>>> 351h OK Completed
>>>> <1219413343<dpau IDLE
>>>>> 1219413343>+ idling
>>>> [end of file]
>>>>
>>>> e) And there are many "Fatal error: word too long" but not with same
>>>> number...
>>>> Aug 22 14:43:03 atlantic imaps[25050]: Fatal error: word too long
>>>> Aug 22 14:48:08 atlantic imaps[25063]: Fatal error: word too long
>>>> Aug 22 14:53:24 atlantic imaps[17518]: Fatal error: word too long
>>>> Aug 22 14:58:28 atlantic imaps[26379]: Fatal error: word too long
>>>> Aug 22 15:03:34 atlantic imaps[26776]: Fatal error: word too long
>>>> Aug 22 15:08:40 atlantic imaps[27118]: Fatal error: word too long
>>>> Aug 22 15:13:45 atlantic imaps[27749]: Fatal error: word too long
>>>> Aug 22 15:18:51 atlantic imaps[27174]: Fatal error: word too long
>>>> Aug 22 15:24:01 atlantic imaps[28464]: Fatal error: word too long
>>>> Aug 22 15:29:06 atlantic imaps[29123]: Fatal error: word too long
>>>>
>>>> Normally the watched account having had "Fatal error", I should find a
>>>> fatal error in the transactions logs ? Or is nothing written in case of
>>>> a Fatal error ? (Which I hope not ;-)
> 
> 
> Denis Bucher
> 

Denis Bucher

-- 

Denis Bucher   Horus Digital Solutions sàrl  Each problem has a solution
___________________________________________________________________________
    Tél. +41-22-8000625     Fax: +41-22-8000622      www.hsolutions.ch