Apple Mail.app not playing nicely with Cyrus on large mailboxes

Gregory Harris gharris at math.ku.edu
Thu Jan 20 11:17:24 EST 2005


Okay guys.  Thanks for your help in pointing me to do verbose logging on 
a per-user basis..  I didn't know this exists and.. this is an 
incredibly useful feature!

-- Version Information --
The version of Cyrus I am using is 2.2.9.  It is Simon Matter's SRPM 
recompiled on the box i'm running it on.  I am running Scientific Linux 
3.02 (which is basically RHEL3 recompiled with some extra stuff added 
in).  Now looking at the version, I'm seeing a security advisory that 
there is a buffer overflow for that version.  I guess I should be 
updating it, as a side note, do i have to worry about upgrading the 
databases when i update the RPM?

-- How I migrated --
Next, the way I migrated it was through direct file manipulation.  Using 
IMAP to transfer the messages would have taken way too long for my 
userbase.  (It took 5 hours doing it directly!)  I basically followed 
the instructions on ONID's migration site, 
http://www.onid.orst.edu/docs/technical/cyrusmigration.shtml.  I used 
their scripts and modified them slightly to suit my needs.  I added 
another script to touch the date of each message file based on the From: 
line (on the first line of the message) before calling the Cyrus 
reconstruct command to get the INTERNALDATE's right.  (For some reason 
Apple's Mail.app uses INTERNALDATE rather than the real message dates in 
the index listing).  Then I borrowed and significantly modified a python 
script to fix all of the flags by selecting X-Status and Status header 
fields and updating them through IMAP.  Since python's IMAP proxy 
feature is broken, I had to fake the password backend during this 
process by adding a hash for each user to /etc/shadow, so it would 
override kerberos for authentication.

-- Debugging test this morning --
I was able to recreate cyrus closing the connection by telnetting to 
port 143 of the cyrus server and entering some of the same commands that 
I found in the telemetry logs.  This is what caused the crash:

[root at bayes bozenna]# telnet localhost 143
Trying 127.0.0.1...
Connected to localhost.localdomain (127.0.0.1).
Escape character is '^]'.
* OK bayes Cyrus IMAP4 v2.2.9-Invoca-RPM-2.2.9-1 server ready
1 login bozenna *****************
1 OK User logged in
2 SELECT INBOX
* FLAGS (\Answered \Flagged \Draft \Deleted \Seen NotJunk Junk $MDNSent 
$Forwarded)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NotJunk 
Junk $MDNSent $Forwarded \*)]
* 271 EXISTS
* 0 RECENT
* OK [UNSEEN 40]
* OK [UIDVALIDITY 1105857209]
* OK [UIDNEXT 1025]
2 OK [READ-WRITE] Completed
3 UID FETCH 340:365 (INTERNALDATE UID RFC822.SIZE FLAGS 
BODY.PEEK[HEADER.FIELDS (date subject from to message-id in-reply-to 
x-spam-flag)])
Connection closed by foreign host.

Now, I don't understand where Mail.app gets the UID FETCH 340:365 
command.  Nor do I understand where Mail.app gets the UID 338 from. 
This is the command sent before the command that causes it to crash: 
"UID FETCH 338:*" The relevant Mail.app session I captured from the 
telemetry log is as follows:

---------- bozenna Thu Jan 20 10:08:07 2005

 >1106237287>1 OK User logged in
<1106237287<2 CAPABILITY
 >1106237287>* CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ 
MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT 
CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES 
ANNOTATEMORE IDLE LOGINDISABLED LISTEXT LIST-SUBSCRIBED X-NETSCAPE
2 OK Completed
<1106237287<3 SELECT INBOX
 >1106237287>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen NotJunk 
Junk $MDNSent $Forwarded)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen NotJunk 
Junk $MDNSent $Forwarded \*)]
* 271 EXISTS
* 0 RECENT
* OK [UNSEEN 40]
* OK [UIDVALIDITY 1105857209]
* OK [UIDNEXT 1025]
3 OK [READ-WRITE] Completed
<1106237287<4 UID FETCH 338:* (UID FLAGS)
 >1106237287>* 185 FETCH (FLAGS (\Seen $MDNSent) UID 340)
* 186 FETCH (FLAGS (\Seen) UID 344)
* 187 FETCH (FLAGS (\Seen) UID 345)
* 188 FETCH (FLAGS (\Seen) UID 346)
* 189 FETCH (FLAGS (\Seen) UID 349)
* 190 FETCH (FLAGS (\Seen) UID 350)
* 191 FETCH (FLAGS (\Seen) UID 353)
* 192 FETCH (FLAGS (\Seen) UID 365)
* 193 FETCH (FLAGS (\Seen) UID 367)
* 194 FETCH (FLAGS (\Seen $Forwarded) UID 389)
* 195 FETCH (FLAGS (\Seen $Forwarded) UID 418)
* 196 FETCH (FLAGS (\Seen) UID 419)
* 197 FETCH (FLAGS (\Seen) UID 425)
* 198 FETCH (FLAGS (\Seen) UID 435)
* 199 FETCH (FLAGS (\Seen) UID 473)
* 200 FETCH (FLAGS (\Seen) UID 475)
* 201 FETCH (FLAGS (\Seen) UID 487)
* 202 FETCH (FLAGS (\Seen) UID 488)
* 203 FETCH (FLAGS (\Seen) UID 502)
* 204 FETCH (FLAGS (\Seen) UID 508)
* 205 FETCH (FLAGS (\Seen) UID 513)
* 206 FETCH (FLAGS (\Seen) UID 514)
* 207 FETCH (FLAGS (\Seen) UID 525)
* 208 FETCH (FLAGS (\Seen) UID 534)
* 209 FETCH (FLAGS (\Seen) UID 540)
* 210 FETCH (FLAGS (\Seen) UID 552)
* 211 FETCH (FLAGS (\Seen NotJunk) UID 575)
* 212 FETCH (FLAGS (\Seen NotJunk) UID 637)
* 213 FETCH (FLAGS (\Seen NotJunk) UID 647)
* 214 FETCH (FLAGS (\Seen NotJunk) UID 790)
* 215 FETCH (FLAGS (\Seen NotJunk) UID 816)
* 216 FETCH (FLAGS (\Seen NotJunk) UID 817)
* 217 FETCH (FLAGS (\Seen NotJunk) UID 836)
* 218 FETCH (FLAGS (\Seen NotJunk $MDNSent) UID 838)
* 219 FETCH (FLAGS (\Seen NotJunk) UID 851)
* 220 FETCH (FLAGS (\Seen NotJunk) UID 863)
* 221 FETCH (FLAGS (\Seen NotJunk) UID 867)
* 222 FETCH (FLAGS (\Seen NotJunk) UID 872)
* 223 FETCH (FLAGS (\Seen NotJunk) UID 877)
* 224 FETCH (FLAGS (\Seen NotJunk) UID 878)
* 225 FETCH (FLAGS (\Seen NotJunk) UID 883)
* 226 FETCH (FLAGS (\Seen NotJunk) UID 894)
* 227 FETCH (FLAGS (\Seen NotJunk) UID 896)
* 228 FETCH (FLAGS (\Answered \Seen NotJunk) UID 899)
* 229 FETCH (FLAGS (\Seen NotJunk) UID 900)
* 230 FETCH (FLAGS (\Seen NotJunk) UID 902)
* 231 FETCH (FLAGS (\Seen NotJunk) UID 904)
* 232 FETCH (FLAGS (\Seen NotJunk) UID 908)
* 233 FETCH (FLAGS (\Seen) UID 934)
* 234 FETCH (FLAGS (\Seen) UID 936)
* 235 FETCH (FLAGS (\Seen) UID 938)
* 236 FETCH (FLAGS (\Seen) UID 947)
* 237 FETCH (FLAGS (\Seen) UID 948)
* 238 FETCH (FLAGS (\Answered \Seen) UID 955)
* 239 FETCH (FLAGS (\Seen) UID 956)
* 240 FETCH (FLAGS (\Answered \Seen) UID 961)
* 241 FETCH (FLAGS (\Seen) UID 963)
* 242 FETCH (FLAGS (\Answered \Seen) UID 967)
* 243 FETCH (FLAGS (\Seen) UID 970)
* 244 FETCH (FLAGS (\Seen) UID 980)
* 245 FETCH (FLAGS (\Seen) UID 983)
* 246 FETCH (FLAGS (\Seen) UID 984)
* 247 FETCH (FLAGS (\Seen) UID 994)
* 248 FETCH (FLAGS (\Seen) UID 996)
* 249 FETCH (FLAGS (\Deleted \Seen) UID 998)
* 250 FETCH (FLAGS (\Answered \Seen) UID 1002)
* 251 FETCH (FLAGS (\Deleted \Seen) UID 1003)
* 252 FETCH (FLAGS (\Deleted \Seen) UID 1004)
* 253 FETCH (FLAGS (\Seen) UID 1005)
* 254 FETCH (FLAGS (\Deleted \Seen) UID 1006)
* 255 FETCH (FLAGS (\Deleted \Seen) UID 1007)
* 256 FETCH (FLAGS (\Deleted \Seen) UID 1008)
* 257 FETCH (FLAGS (\Deleted \Seen) UID 1009)
* 258 FETCH (FLAGS (\Deleted \Seen) UID 1010)
* 259 FETCH (FLAGS (\Deleted \Seen) UID 1011)
* 260 FETCH (FLAGS (\Deleted \Seen) UID 1012)
* 261 FETCH (FLAGS (\Deleted \Seen) UID 1014)
* 262 FETCH (FLAGS (\Deleted \Seen) UID 1015)
* 263 FETCH (FLAGS (\Answered \Seen) UID 1016)
* 264 FETCH (FLAGS (\Deleted \Seen) UID 1017)
* 265 FETCH (FLAGS (\Deleted \Seen) UID 1018)
* 266 FETCH (FLAGS (\Deleted \Seen) UID 1019)
* 267 FETCH (FLAGS (\Deleted \Seen) UID 1020)
* 268 FETCH (FLAGS (\Deleted \Seen) UID 1021)
* 269 FETCH (FLAGS (\Seen) UID 1022)
* 270 FETCH (FLAGS (\Deleted \Seen) UID 1023)
* 271 FETCH (FLAGS (\Deleted \Seen) UID 1024)
4 OK Completed (0.000 sec)
<1106237287<5 UID FETCH 340:365 (INTERNALDATE UID RFC822.SIZE FLAGS 
BODY.PEEK[HEADER.FIELDS (date subject from to message-id in-reply-to 
x-spam-flag)])

Thanks for all your help guys.

Greg


Sebastian Hagedorn wrote:
> Hi,
> 
> --On 19. Januar 2005 14:56:42 Uhr -0600 Gregory Harris 
> <gharris at math.ku.edu> wrote:
> 
>> Last Sunday I migrated all of my users mailboxes from a traditional BSD
>> unix mail setup to Cyrus-IMAP.
> 
> 
> which version?
> 
>>  The majority of my users use the Apple
>> Mail.app client.  I am having problems with a couple of them (one in
>> particular that has a huge INBOX, some with attachments).  When she opens
>> her e-mail, the client fails to retreive her mail, and drops the
>> connection.  The logs say something similar to:
>>
>> Jan 18 15:31:32 bayes imap[31658]: accepted connection
>> Jan 18 15:31:33 bayes imap[31539]: accepted connection
>> Jan 18 15:31:33 bayes imap[31539]: login: bozenna.math.ku.edu
>> [129.237.130.170] bozenna GSSAPI User logged in
>> Jan 18 15:31:33 bayes imap[31539]: open: user bozenna opened INBOX
>> Jan 18 15:31:33 bayes imap[31539]: open: user bozenna opened INBOX
>> Jan 18 15:31:33 bayes imap[31658]: accepted connection
>> Jan 18 15:31:33 bayes imap[31658]: login: bozenna.math.ku.edu
>> [129.237.130.170] bozenna GSSAPI User logged in
>> Jan 18 15:31:33 bayes master[4894]: process 31539 exited, signaled to
>> death by 6
>> Jan 18 15:31:33 bayes master[4894]: service imap pid 31539 in BUSY state:
>> terminated abnormally
>>
>> I increased the prefork value from 5 to 50 (in slow increments) and it
>> appears to be able to download more headers but still drops the
>> connection.
> 
> 
> That must be coincidence, IMO. Preforking has nothing to do with that.
> 
>> I have had a similar problem with one user that uses Ximian Evolution
>> 1.4.6.  Same error message on the server side, on the client side, says
>> something to the effect of "connection unexpectedly dropped".  I know
>> this is probably related to bad IMAP programming on the client side,
> 
> 
> I'm not so sure. It's not as though Cyrus has no bugs ...
> 
>> I would greatly appreciate any help you could provide on this matter.
> 
> 
> Try logging telemetry data to find out which commands are causing the 
> server to drop the connection. You need to create a directory with the 
> user's username in (e.g.) /var/lib/imap/log. After that you will find 
> one file for each PID, containing the entire exchange between client and 
> server. Report back to the list with the results.
> 
> Cheers, Sebastian
> -- 
> Sebastian Hagedorn M.A. - RZKR-R1 (Gebäude 52), Zimmer 18
> Zentrum für angewandte Informatik - Universitätsweiter Service RRZK
> Universität zu Köln / Cologne University - Tel. +49-221-478-5587

-- 

Gregory Harris
Network Specialist
Department of Mathematics
The University of Kansas
gharris at math.ku.edu
(785) 864-7311

---
Cyrus Home Page: http://asg.web.cmu.edu/cyrus
Cyrus Wiki/FAQ: http://cyruswiki.andrew.cmu.edu
List Archives/Info: http://asg.web.cmu.edu/cyrus/mailing-list.html




More information about the Info-cyrus mailing list