485767 - Mail application is stuck (working against Zimbra server) with 'failed creating protocol instance to play queued url'

Status: RESOLVED WORKSFORME

(MailNews Core :: Networking: IMAP, defect)

Description

[Yaniv Kaul]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b3) Gecko/20090305 Firefox/3.1b3
Build Identifier: version 2.0.0.21 (20090302)

I'm working with IMAP, against a Zimbra email server. Thunderbird on Windows XP get stuck when loaded. The critical sections of the log show:
3672[32b8fc0]: 32c2390:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 612 FETCH (UID 26876 FLAGS (\Seen)) 3672[32b8fc0]: ReadNextLine [stream=3221e10 nb=60 needmore=0]
3672[32b8fc0]: 32c2390:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 613 FETCH (UID 26901 FLAGS ($Forwarded Forwarded \Seen)) 3672[32b8fc0]: ReadNextLine [stream=3221e10 nb=49 needmore=0]
3672[32b8fc0]: 32c2390:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 614 FETCH (UID 26902 FLAGS (\Answered \Seen)) 3672[32b8fc0]: ReadNextLine [stream=3221e10 nb=39 needmore=0]
3672[32b8fc0]: 32c2390:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 615 FETCH (UID 26921 FLAGS (\Seen)) 3672[32b8fc0]: ReadNextLine [stream=3221e10 nb=39 needmore=0]
3672[32b8fc0]: 32c2390:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 616 FETCH (UID 26993 FLAGS (\Seen)) 0[2846c0]: queuing url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: considering playing queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: creating protocol instance to play queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: failed creating protocol instance to play queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: queuing url:imap://[e-mail]:993/fetch>UID>/INBOX>41490
0[2846c0]: considering playing queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: dooming url:imap://[e-mail]:993/fetch>UID>/INBOX>41445
0[2846c0]: considering playing queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41490
0[2846c0]: creating protocol instance to play queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41490
0[2846c0]: failed creating protocol instance to play queued url:imap://[e-mail]:993/fetch>UID>/INBOX>41490


I have some suspicion that on Windows, it happens after I tried earlier opening the mail with Thunderbird on Fedora 10 (which is also stuck).

I can only escape this (it'll get stuck whenever I ran TB) if I delete some message (none in particular) using the Zimbra Web UI and open TB again. If it didn't get stuck, I suspect rebuilding the inbox would have helped too.

Reproducible: Sometimes

Steps to Reproduce:
1. Open Thunderbird
2.
3.
Actual Results:  
1. Cannot read email.
2. TB is stuck (which is just as annoying and needs to be fixed - not just the root cause of the problem).

Expected Results:  
I 

I can also be contacted at y k a u l <-at-> r e d h a t . com

Comment 1

[Ludovic Hirlimann [:Usul]]

Yaniv do you also have the issue if your run 3.0Beta2 ? Could you attach the log using the add an attachment button (just keeping the bits above is fine) ?

Comment 2

[Yaniv Kaul]

With 3.0b2, I do see the failures, but TB is not stuck - and later on seems to succeed. Relevant parts of the log:
0[172c140]: queuing url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: considering playing queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: creating protocol instance to play queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: failed creating protocol instance to play queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: considering playing queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: creating protocol instance to play queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
0[172c140]: playing queued url:imap://[e-mail]:993/addmsgflags>UID>/INBOX>44006>1
1472[31489c0]: 38ee000:mail.corp.redhat.com:S-INBOX:ProcessCurrentURL: entering
1472[31489c0]: 38ee000:mail.corp.redhat.com:S-INBOX:ProcessCurrentURL:imap://[e-mail]:993/addmsgflags%3EUID%3E/INBOX%3E44006%3E1:  = currentUrl
1472[31489c0]: 38ee000:mail.corp.redhat.com:S-INBOX:SendData: 385 uid store 44006 +Flags (\Seen)

1472[31489c0]: ReadNextLine [stream=34c8d48 nb=47 needmore=0]
1472[31489c0]: 38ee000:mail.corp.redhat.com:S-INBOX:CreateNewLineFromSocket: * 790 FETCH (FLAGS (\Seen \Recent) UID 44006)

1472[31489c0]: ReadNextLine [stream=34c8d48 nb=28 needmore=0]

Comment 3

[David :Bienvenu]

Sometimes urls have to wait for previous urls to finish, so that we don't try to do two things at the same time to an imap folder on the server. But w/o more of the log, I don't really know what it's waiting for.

Comment 4

[Yaniv Kaul]

Any way to reduce 'CreateNewLineFromSocket' ? I can try 'grep -v' on it, but will it provide you enough info?

Comment 5

[David :Bienvenu]

it's probably best just to leave all the info in - but only up to the previous INBOX:ProcessCurrentURL: entering

that will tell me what the previous url is.

It's not necessarily indicative of any error - sometimes our code runs two urls in quick succession, knowing that the url queue will queue them correctly.

Comment 6

[Wayne Mery (:wsmwk)]

Yaniv, when you attach/post the log information, please remove [needs protocol log] from whiteboard. thanks

Comment 7

[Yaniv Kaul]

I don't see it anymore, closing.