280523 - imap hangs on largish (>30K) messages from GroupWise server

Status: VERIFIED INVALID

(Thunderbird :: General, defect)

Description

[FZiegler]

See below for "steps to reproduce". Happens with both the latest Thunderbird and
Mozilla 1.7.2.

Comment 1

[FZiegler]

Preface:
I suspect this is caused by the server, and not a Mozilla/Thunderbird bug. If so
I will be happy to close the bug as invalid. That said, I'm hoping the
forthcoming logs could help tracking what's going wrong.

Reproducibility: Almost always.
Steps to reproduce:
1) Have a GroupWise server (6.5.3, configured to serve IMAP through GWIA; for
details see http://www.novell.com/documentation/gw65/gw65_admin/data/a2zvblk.html)
2) Log in and click to display an inbox message whose headers+body size exceeds
30K or so. The size of any mime attachments doesn't seem to matter.

Expected result: The message displays.
Actual result: It doesn't. The progress bar stalls half-way. The only way to
stop the throbber or display anything else in the inbox is to relaunch
Mozilla/Thunderbird.

Any message that fails to display once, will fail almost always. I'll next
attach an IMAP log taken when one fails, and another caught in the rare event of
success. In both cases we see that the entire message *does* arrive from the
server, the only difference is that failure ends like:

S-INBOX:CreateNewLineFromSocket: )
ReadNextLine [stream=91adc28 nb=27 needmore=0]
S-INBOX:CreateNewLineFromSocket: 17 OK UID FETCH completed

whereas success ends like:

S-INBOX:CreateNewLineFromSocket: )
S-INBOX:STREAM:CLOSE: Normal Message End Download Stream
ReadNextLine [stream=91aeda8 nb=27 needmore=0]
S-INBOX:CreateNewLineFromSocket: 72 OK UID FETCH completed
BODYSHELL:  Adding shell to cache.


In case of failure, an OS X Sampler.app report (also attached below) shows
Mozilla spending all this time in a call stack that involves 

..
 nsImapServerResponseParser::ProcessOkCommand()
  nsIMAPBodyShell::Generate()
    .....
        nsImapServerResponseParser::msg_fetch()
         nsImapServerResponseParser::msg_fetch_content()
          nsImapServerResponseParser::msg_fetch_literal()
           .....
               nsPipeInputStream::Wait()
                ...

So far as I can tell, what we have is one of the above methods failing to call
http://lxr.mozilla.org/seamonkey/ident?i=NormalMessageEndDownload, and what I
can't figure out is what Mozilla is missing in order make this call.

Help!

Comment 2

[FZiegler]

Attachment: IMAP log when message display fails

Added timestamps show where it hangs. (See very bottom of the file.) After a
minute I give up and try to diplay other messages, but this has no effect.
Eventually I have to quit Mozilla.

Comment 3

[FZiegler]

Attachment: IMAP log when message display succeeds

Rare case of success on the same message. At the end I just quit normally.

Comment 4

[FZiegler]

Attachment: Sampler.app report when display fails

Comment 5

[David :Bienvenu]

yeah, I'd bet a lot of money that the imap server is not returning all the data
they promised, when fetching by chunks. In your success case, we fetch the whole
message; in the failure case, we're fetching by chunks. You can edit your
prefs.js and add a pref or prefs that will disable fetching by chunks - I'll go
find out for sure what prefs those are because I've heard reports that the prefs
I thought would work don't work.

Comment 6

[David :Bienvenu]

yes, this should turn off fetching by chunks.

Shutdown thunderbird
Add the following to prefs.js (or user.js)

user_pref("mail.server.server2.fetch_by_chunks", false);

restart.

where <server2> is your imap server (you'll need to look through prefs.js to
figure out which server is your imap server)

Comment 7

[David :Bienvenu]

please close as invalid if setting this pref works for you. Going forward, I'm
adding timeouts to the imap code so at least you'll get a message that the
server timed out in this situation...

Comment 8

[Hans-Andreas Engel]

An analysis of the failure case:

In the broken case (Attachment 172959 [details]), the server replies 
* 454 FETCH (UID 1381 RFC822.SIZE 36033 BODY[]<12288> {12288}
followed by 11458 bytes of data and then 
) 17 OK UID FETCH completed

With "{12288}" the server claims that the following 12288 bytes form an IMAP
literal, however, it then only sends 11458 bytes (namely the rest of the
message).  So this bug is definitely due to the server.


This problem arises when the client ask for data at offset 12288
("BODY[]<12288.12288>").  Then the server returns the message with an offset of
24576!  This is just 12288+12288, indicating a glitch in the server that should
be easy to fix.

Comment 9

[FZiegler]

Attachment: The message in question (for the record)

Comment 10

[FZiegler]

Man! You guys rock (again).

Needless to say, the pref change works like a charm. This is going to save me *lots* of aggravation. 
Immediate relief, thanks David :-)

And right on: as I failed to notice, in the broken case we are *not* receiving the entire message 
(attached above for the record). There ought to be 3 chunks,

(1)  12288 bytes from 'Mime-Version'  to  'gmichals'
(2)  12288 bytes from '@georgiasouthern.edu>, "Gustavo'  to  'Veng Kou'
(3)  11457 bytes from 'ch" <vkouch'  to  'University\n'

totaling 36033, but (2) is missing entirely! We just receive (1), then (3).

At the risk of veering further off topic: Another problem I had with this server, and wrongly assumed 
related, was SLOW navigation between imap folders. This seems in fact due to slow authentication on 
the *first 5* folders opened (of course I rarely open more...), and [...best?...] cured by changing 5 to 1 in 
the default

user_pref("mail.server.server2.max_cached_connections", 5);

Comment 11

[FZiegler]

closing as invalid :-)

Comment 12

[John G. Myers]

Perhaps a release note would be appropriate?

Comment 13

[David :Bienvenu]

adding relnote keyword

re caching imap connections, if you set that pref to 1, we'll re-use the same
connection for each folder, which may speed up opening the five folders the
first time, but if you revisit folders you've already opened, that will be
slower because we have to build up the selected state information for that
folder, which can take time on larger folders.

Comment 14

[Hans-Andreas Engel]

Novell is now informed about this GroupWise bug.

I hope that Novell will eventually list this problem on
http://search.novell.com/NSearch/SearchServlet?template=ResultListTerseTemplate.html&numhits=40&theme=support&query=imap+and+fetch&filter=(/Product_Class=Groupware+OR+/Product_Class=GroupWise%20Client/Admin+OR+/Product_Class=Groupwise%20Gateway)&collection=Support

Comment 15

[FZiegler]

Thanks Hansres. Novell have now answered in novell.support.groupwise.6x.gwia
(http://support.novell.com/forums/2gw.html):

> There is a fix for this in the upcoming 6.5.4 release.  The current FTF for
> 6.5.4 does not have this fix in it however.  Option 1 -  wait for 6.5.4 to
> ship (in the next couple weeks)  Option 2 -  call support and get them to
> supply a new FTF with this fix available.