Closed Bug 323520 Opened 19 years ago Closed 15 years ago

POP3 download stuck in "This folder is being processed" when server drops connection after RETR

Categories

(MailNews Core :: Networking: POP, defect)

Product:
MailNews Core
Component:
Networking: POP
Version:
1.8 Branch
Platform:
x86
Windows XP
Type:
defect
Priority:
Not set
Severity:
critical

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 466933

People

(Reporter: tomer, Unassigned)

Details

(Whiteboard: [has pop log])

User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8) Gecko/20051111 Firefox/1.5 Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8) Gecko/20051111 Firefox/1.5 I had this problem often with 1.0.x and the nightly builds. It was gone for a long while with 1.5RCx, but it just came back. Basic description: 1. Thunderbird starts. 2. TB downloads mail from a specific POP3 account (whether manually or automatically) 3. Server drops connection (see details below) before message is downloaded. TB appears to be stuck on downloading the first message 4. Local folders cannot be used further. IMAP accounts work fine; attempts to download mail from another POP3 account result in the following message: "The folder is being processed. Please wait until processing is complete to get messages." Reproducible: Always Steps to Reproduce: This has happened before and I was never sure as to the cause. This time I've done some actual research - see below. It might be easiest to reproduce this problem with a mock POP3 server which drops connection immediately after RETR. Offending account is accessible via webmail or other POP3 clients (like SimpleCheck). The mail server is Merak 7.5.2. I tried sniffing communication between the client and server using Ethereal; everything seems to be in order until the proper RETR command. What follows is a sequence of FIN/ACK packets after which the server drops the connection. This in itself is not a problem with TB as the same behaviour occurs via manual Telnet. I can post the capture file if it's of any relevance but it'll take some time as I need to filter out IP addresses, auth information etc. Bottom line, the dropped connection screws up TB somehow.
Version: unspecified → 1.5
Related to Core bug 240969 comment 2 and maybe Core bug 221350?
Correcting the summary to ease LXRing for this status message.
Summary: POP3 download stuck in "The folder is being processed" when server drops connection after RETR → POP3 download stuck in "This folder is being processed" when server drops connection after RETR
In nsPop3Protocol.cpp, in function WaitForStartOfConnectionResponse, we use ReadNextLine disregarding its nsresult out argument. Thus, we lose valuable information as to why the return value (the 'line') ended up null. Perhaps if the nsresult is not SUCCESS, we should call the sink's IncorporateAbort and/or AbortMailDelivery. Specifically, our impl. of AbortMailDelivery will call ReleaseFolderLock(), thus releasing the semaphore which causes this "This folder is being processed" message to appear.
I seem to have the same situation, but in Mozilla. I can't confirm what calls were being made inside Mozilla, but I do know my internet connection was dropped while downloading POP3 e-mail. Then I get the below ever-repeating error message when I attempt to get POP mail after the internet connection was dropped during my earlier-aborted attempt to get POP mail. Here's the complete message: "This folder is being processed. Please wait until processing is complete to get messages." Mozilla 1.7.13, Windows XP PRO SP2 (fully-patched as of last week) dial-up internet connection 768mb RAM, 600 mhz pIII
I've also got this issue, and can confirm that it happened in Mozilla. I switched from Mozilla to thunderbird after not being able to fix the issue. Thunderbird worked fine for about 6 months, and now it's happening again. Any progress in nailing this thing down?
I was screwing around with this tonight. I don't understand why, but if I delete the Inbox.msf file, which was 15kb, and restarted the program, it works just fine.
I am getting the same problem, but for only one of several email accounts. TB downloads the mail from the others but not from one account. I have deleted both the inbox and inbox.msf files and restarted, but the problem continues. I also emptied the send folder, deleted that folder and restarted. The problem persists.
SeaMonkey 1.1.4 Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.6) Gecko/20070802 Netscape/7.2 (ax) Firefox/2.0.0.4 SeaMonkey/1.1.2 POP Mail Server on Port 110 With SeaMonkey 1.1.3, I started getting the "This folder is being processed." problem on 3 Aug 2007. Went through all the recommended steps: delete *.msf files, compacted folders, emptied the Inbox, deleted lots of old and big local mail, defragged the disk, turned off the AVG e-mail check, emptied all web e-mail, power-off reboot - no help. Downloaded and installed SeaMonkey 1.1.4: no help. I can send e-mail and see it in my webmail account on sonic.net. They have not had any reports of this problem. Most discouraging. Windows XP PRO SP2 DSL internet connection 400 MHz Pentium II, 384 MB of RAM
Continuing my comment above about "This folder is being processed.": I created a new profile in SeaMonkey (Default User); same results. I installed Thunderbird version 2.0.0.6 (20070728) and imported settings from Mozilla; same results. Are there any ideas on fixing this problem?
Assignee: mscott → nobody
Component: General → Networking: POP
Product: Thunderbird → Core
QA Contact: general → networking.pop
Version: 1.5 → 1.8 Branch
To bug opener & all problem reporters: Can you get NSPR log when problem occurs? (A) http://www.mozilla.org/projects/netlib/http/http-debugging.html (B-1) http://kb.mozillazine.org/Session_logging_for_mail/news (B-2) http://www.mozilla.org/quality/mailnews/mail-troubleshoot.html#pop (See A for how to start logging when Mac OS X) I think following is helpful for problem analysis by developers, because network level error is involved. SET NSPR_LOG_MODULES=pop3:5,nsSocketTransport:5,nsHostResolver:5 NSPR logging doesn't have timesamp capability. But when MS Win, adding timestamp to NSPR log is possible by using DebugView. http://www.microsoft.com/technet/sysinternals/Utilities/DebugView.mspx SET NSPR_LOG_FILE=WinDebug See Bug 86396 Comment #7 for how to. And mail db(.msf)/file access(open/close) seems to be involved, but NSPR logging is not sufficient for analysis of this kind of issues. When MS Win, Process Monitor is convinient for this purpose. http://www.microsoft.com/technet/sysinternals/Utilities/processmonitor.mspx (filter condition) - Process Name/is/thunderbird.exe => include - Path/begins with/<Your Tb's Mail directory> => include Get NSPR log & Process Monitor log at same time.
SeaMonkey 1.1.4 Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.6) Gecko/20070802 Netscape/7.2 (ax) Firefox/2.0.0.4 SeaMonkey/1.1.2 When SeaMonkey starts up, open Mail & Newsgroups. Execution of runseamonkey.bat, which is: == set NSPR_LOG_MODULES=POP3:5 set NSPR_LOG_FILE=C:\nspr_log_file.txt start seamonkey.exe == Contents of nspr_log_file.txt: == 0[2842e8]: Entering NET_ProcessPop3 73 0[2842e8]: POP3: Entering state: 1 0[2842e8]: POP3: Entering state: 2 0[2842e8]: POP3: Entering state: 4 0[2842e8]: RECV: +OK AVG POP3 Proxy Server <64.142.7.148> 7.5.474/7.5.476 [269.11.8/941] 0[2842e8]: POP3: Entering state: 29 0[2842e8]: SEND: AUTH 0[2842e8]: Entering NET_ProcessPop3 23 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: -ERR Invalid command. 0[2842e8]: POP3: Entering state: 30 0[2842e8]: POP3: Entering state: 31 0[2842e8]: SEND: CAPA 0[2842e8]: Entering NET_ProcessPop3 100 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: +OK CAPA Follows 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: STLS 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: UIDL 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: LOGIN-DELAY 10 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: PIPELINING 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: USER 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: TOP 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: IMPLEMENTATION Sonic POP3d 0[2842e8]: POP3: Entering state: 32 0[2842e8]: RECV: . 0[2842e8]: POP3: Entering state: 33 0[2842e8]: SEND: STLS 0[2842e8]: Entering NET_ProcessPop3 34 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: -ERR Unknown command, try again. 0[2842e8]: POP3: Entering state: 45 0[2842e8]: POP3: Entering state: 33 0[2842e8]: SEND: STLS 0[2842e8]: Entering NET_ProcessPop3 34 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: -ERR Unknown command, try again. 0[2842e8]: POP3: Entering state: 45 0[2842e8]: POP3: Entering state: 33 0[2842e8]: SEND: STLS 0[2842e8]: Entering NET_ProcessPop3 34 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: -ERR Unknown command, try again. 0[2842e8]: POP3: Entering state: 45 0[2842e8]: POP3: Entering state: 33 0[2842e8]: SEND: STLS 0[2842e8]: Entering NET_ProcessPop3 34 0[2842e8]: POP3: Entering state: 3 0[2842e8]: RECV: -ERR Unknown command, try again. 0[2842e8]: POP3: Entering state: 45 0[2842e8]: POP3: Entering state: 33 0[2842e8]: SEND: STLS [snip of repeated results] == Execution of new runseamonkey.bat, which is now: == SET NSPR_LOG_MODULES=POP3:5,nsSocketTransport:5,nsHostResolver:5 set NSPR_LOG_FILE=C:\nspr_log_file.txt start seamonkey.exe == Contents of nspr_log_file.txt: == 3336[a53830]: nsSocketTransportService::Run 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransportService::PostEvent [event=17fe890] 3336[a53830]: ...returned after 8153 milliseconds 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransportService::PostEvent [event=20578e8] 3336[a53830]: ...returned after 7797 milliseconds 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: creating nsSocketTransport @20591d8 0[284310]: nsSocketTransport::Init [this=20591d8 host=pop.sonic.net:110 proxy=:0] 0[284310]: nsSocketTransport::PostEvent [this=20591d8 type=3 status=0 param=0] 0[284310]: nsSocketTransportService::PostEvent [event=20a26e0] 3336[a53830]: ...returned after 7705 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=3 status=0 param=0] 3336[a53830]: MSG_TIMEOUT_CHANGED 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransport::PostEvent [this=20591d8 type=3 status=0 param=0] 0[284310]: nsSocketTransportService::PostEvent [event=20a26e0] 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=3 status=0 param=0] 3336[a53830]: MSG_TIMEOUT_CHANGED 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransport::OpenOutputStream [this=20591d8 flags=1] 0[284310]: nsSocketTransportService::PostEvent [event=1b92070] 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransport::PostEvent [this=20591d8 type=0 status=0 param=0] 0[284310]: nsSocketTransportService::PostEvent [event=20a26e0] 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=0 status=0 param=0] 3336[a53830]: MSG_ENSURE_CONNECT 3336[a53830]: nsSocketTransport::ResolveHost [this=20591d8] 3336[a53830]: nsHostResolver::ResolveHost [host=pop.sonic.net] 3336[a53830]: advancing to STATE_RESOLVING 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0003] 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransport::OpenInputStream [this=20591d8 flags=0] 0[284310]: nsSocketTransportService::PostEvent [event=1b92070] 3336[a53830]: ...returned after 3 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 0[284310]: nsSocketTransport::PostEvent [this=20591d8 type=0 status=0 param=0] 0[284310]: nsSocketTransportService::PostEvent [event=209a858] 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=0 status=0 param=0] 3336[a53830]: MSG_ENSURE_CONNECT 3336[a53830]: ignoring redundant event 3336[a53830]: calling PR_Poll [active=0 idle=0] 3336[a53830]: timeout = -1 milliseconds 1888[1e1c928]: nsHostResolver::ThreadFunc entering 1888[1e1c928]: resolving pop.sonic.net ... 1888[1e1c928]: nsSocketTransport::PostEvent [this=20591d8 type=1 status=0 param=10b8810] 1888[1e1c928]: nsSocketTransportService::PostEvent [event=1f34908] 3336[a53830]: ...returned after 582 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=1 status=0 param=10b8810] 3336[a53830]: MSG_DNS_LOOKUP_COMPLETE 3336[a53830]: nsSocketTransport::InitiateSocket [this=20591d8] 3336[a53830]: nsSocketTransport::BuildSocket [this=20591d8] 3336[a53830]: pushing io layer [0:starttls] 3336[a53830]: [secinfo=1904ea0 callbacks=1058e68] 3336[a53830]: nsSocketTransportService::AttachSocket [handler=20591d8] 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=0 idle=1 3336[a53830]: advancing to STATE_CONNECTING 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0007] 3336[a53830]: trying address: 64.142.7.163 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=6 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 120 3336[a53830]: timeout = 120000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: advancing to STATE_TRANSFERRING 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0004] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 100 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=73] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4023] 3336[a53830]: calling PR_Read [count=4023] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4023] 3336[a53830]: calling PR_Read [count=4023] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: nsSocketTransport::PostEvent [this=20591d8 type=3 status=0 param=0] 0[284310]: nsSocketTransportService::PostEvent [event=2232540] 0[284310]: Entering NET_ProcessPop3 73 0[284310]: POP3: Entering state: 1 0[284310]: POP3: Entering state: 2 0[284310]: POP3: Entering state: 4 0[284310]: RECV: +OK AVG POP3 Proxy Server <64.142.7.149> 7.5.474/7.5.476 [269.11.8/941] 0[284310]: POP3: Entering state: 29 0[284310]: nsSocketTransportService::PostEvent [event=1b3ef98] 0[284310]: SEND: AUTH 3336[a53830]: ...returned after 8 milliseconds 3336[a53830]: nsSocketTransport::OnSocketEvent [this=20591d8 type=3 status=0 param=0] 3336[a53830]: MSG_TIMEOUT_CHANGED 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=-1] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 2 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=3] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0005] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=6 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 51 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=23] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4073] 3336[a53830]: calling PR_Read [count=4073] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4073] 3336[a53830]: calling PR_Read [count=4073] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: Entering NET_ProcessPop3 23 0[284310]: POP3: Entering state: 3 0[284310]: RECV: -ERR Invalid command. 0[284310]: POP3: Entering state: 30 0[284310]: POP3: Entering state: 31 0[284310]: nsSocketTransportService::PostEvent [event=1b3ef98] 0[284310]: SEND: CAPA 3336[a53830]: ...returned after 9 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=-1] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=3] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0005] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=6 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 49 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=18] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4078] 3336[a53830]: calling PR_Read [count=4078] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4078] 3336[a53830]: calling PR_Read [count=4078] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4078] 3336[a53830]: calling PR_Read [count=4078] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4078] 3336[a53830]: calling PR_Read [count=4078] 3336[a53830]: PR_Read returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4072] 3336[a53830]: calling PR_Read [count=4072] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4072] 3336[a53830]: calling PR_Read [count=4072] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: Entering NET_ProcessPop3 24 0[284310]: POP3: Entering state: 3 0[284310]: RECV: +OK CAPA Follows 0[284310]: POP3: Entering state: 32 0[284310]: RECV: STLS 0[284310]: POP3: Entering state: 32 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4090] 3336[a53830]: calling PR_Read [count=4090] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4090] 3336[a53830]: calling PR_Read [count=4090] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 4 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4090] 3336[a53830]: calling PR_Read [count=4090] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4090] 3336[a53830]: calling PR_Read [count=4090] 3336[a53830]: PR_Read returned [n=70] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4020] 3336[a53830]: calling PR_Read [count=4020] 0[284310]: Entering NET_ProcessPop3 6 0[284310]: POP3: Entering state: 32 0[284310]: RECV: UIDL 0[284310]: POP3: Entering state: 32 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4020] 3336[a53830]: calling PR_Read [count=4020] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: Entering NET_ProcessPop3 70 0[284310]: POP3: Entering state: 32 0[284310]: RECV: LOGIN-DELAY 10 0[284310]: POP3: Entering state: 32 0[284310]: RECV: PIPELINING 0[284310]: POP3: Entering state: 32 0[284310]: RECV: USER 0[284310]: POP3: Entering state: 32 0[284310]: RECV: TOP 0[284310]: POP3: Entering state: 32 0[284310]: RECV: IMPLEMENTATION Sonic POP3d 0[284310]: POP3: Entering state: 32 0[284310]: RECV: . 0[284310]: POP3: Entering state: 33 0[284310]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: ...returned after 9 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=-1] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0005] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=3] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=34] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: SEND: STLS 0[284310]: Entering NET_ProcessPop3 34 0[284310]: POP3: Entering state: 3 0[284310]: RECV: -ERR Unknown command, try again. 0[284310]: POP3: Entering state: 45 0[284310]: POP3: Entering state: 33 0[284310]: nsSocketTransportService::PostEvent [event=1f37b60] 0[284310]: SEND: STLS 3336[a53830]: ...returned after 11 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=-1] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=3] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0005] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=6 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=34] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: Entering NET_ProcessPop3 34 0[284310]: POP3: Entering state: 3 0[284310]: RECV: -ERR Unknown command, try again. 0[284310]: POP3: Entering state: 45 0[284310]: POP3: Entering state: 33 0[284310]: nsSocketTransportService::PostEvent [event=1b3ef98] 0[284310]: SEND: STLS 3336[a53830]: ...returned after 2 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=-1] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=3] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1b3ef98] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketOutputStream::Write [this=2059290 count=6] 3336[a53830]: calling PR_Write [count=6] 3336[a53830]: PR_Write returned [n=6] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0005] 3336[a53830]: nsSocketOutputStream::AsyncWait [this=2059290] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=7 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=6 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=2] 3336[a53830]: nsSocketOutputStream::OnSocketReady [this=2059290 cond=0] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 1 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4096] 3336[a53830]: calling PR_Read [count=4096] 3336[a53830]: PR_Read returned [n=34] 3336[a53830]: nsSocketTransport::SendStatus [this=20591d8 status=804b0006] 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketTransport::OnSocketReady [this=20591d8 outFlags=1] 3336[a53830]: nsSocketInputStream::OnSocketReady [this=2059270 cond=0] 3336[a53830]: nsSocketTransportService::PostEvent [event=1f37b60] 3336[a53830]: active [0] { handler=20591d8 condition=0 pollflags=0 } 3336[a53830]: nsSocketTransportService::AddToIdleList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromPollList [handler=20591d8] 3336[a53830]: index=0 mActiveCount=1 3336[a53830]: active=0 idle=1 3336[a53830]: calling PR_Poll [active=0 idle=1] 3336[a53830]: timeout = -1 milliseconds 3336[a53830]: ...returned after 0 milliseconds 3336[a53830]: nsSocketInputStream::Read [this=2059270 count=4062] 3336[a53830]: calling PR_Read [count=4062] 3336[a53830]: PR_Read returned [n=-1] 3336[a53830]: nsSocketInputStream::AsyncWait [this=2059270] 3336[a53830]: idle [0] { handler=20591d8 condition=0 pollflags=5 } 3336[a53830]: nsSocketTransportService::AddToPollList [handler=20591d8] 3336[a53830]: active=1 idle=1 3336[a53830]: nsSocketTransportService::RemoveFromIdleList [handler=20591d8] 3336[a53830]: active=1 idle=0 3336[a53830]: calling PR_Poll [active=1 idle=0] 3336[a53830]: poll timeout: 60 3336[a53830]: timeout = 60000 milliseconds 0[284310]: Entering NET_ProcessPop3 34 0[284310]: POP3: Entering state: 3 0[284310]: RECV: -ERR Unknown command, try again. 0[284310]: POP3: Entering state: 45 0[284310]: POP3: Entering state: 33 0[284310]: nsSocketTransportService::PostEvent [event=1f37b60] 0[284310]: SEND: STLS [snip of repeated results] == Please let me know if there is anything else I can do.
(In reply to comment #11) Please never paste long log data to this bug. It makes tracking of problem analysis status very very difficult(nearly equal to impossible). Attach log file to this bug.
(In reply to comment #12) > (In reply to comment #11) > Please never paste long log data to this bug. > It makes tracking of problem analysis status very very difficult(nearly equal > to impossible). > Attach log file to this bug. > The problem continues, but it is all right with me to remove (or truncate) my comment #11 [https://bugzilla.mozilla.org/show_bug.cgi?id=323520#c11]. How can this be done?
SeaMonkey 1.1.5 Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.8) Gecko/20071009 Netscape/7.2 (ax) Firefox/2.0.0.8 SeaMonkey/1.1.5 No response from this group, so I found a fix for me: I set up a new SeaMonkey e-mail account with IMAP Mail Server on Port 143 instead of POP Mail Server on Port 110. Now my new IMAP e-mail works. The old POP account still gets the "This folder is being processed" warning. As I said above, it is all right with me to remove (or truncate) my comment #11 [https://bugzilla.mozilla.org/show_bug.cgi?id=323520#c11]. Is anybody administering this thread? Cheers.
reporter writes "I've given up on Thunderbird a month or so after filing" jcf3 "switched from POP3 to IMAP."
Win 2000 SP4; Thuderbird 2.0.0.14 Dialup connection; POP3 I do not see this problem in Thunderbird 1.5; or its portable version. 1) If after starting Thunderbird I wait for 30 seconds, the problem will not be there. 2) If I manually click to get POP3 mail as soon as the Thuderbird window opens; then the Alert prompt message shows up. 3) So my conclusion is that the mouse pointer should be an hourglass while whatever is happening is happening. Then I would now how long to wait. However, reading the above comments, maybe the root cause is more complicated than what I thought. I am curious why that status of this bug is still UNCONFIRMED :) .
Mozilla Thunderbird version 2.0.0.17 (20080914) Problem severity: SEVERE Upon trying to collect email from 1 particular POP account (other 6 seem to work OK), get alert "This folder is being processed. Please wait until processing is complete to get messages." Message appears every time I press "GET MAIL". Sending mail from faulty POP account is normal. Went through all the recommended steps: deleted *.msf files, compacted folders, emptied the Inbox, deleted lots of old and big local mail, emptied all web e-mail, power-off reboot - no help. Deleted account; then created it with same logon parameters. TB seems to place a kind of lock on the mail folder in question that persists even after a Thunderbird or a complete computer restart. While this problem exists, cannot use Thunderbird, so had to switch to MS Outlook Express or similar for receiving mail from afflicted account. Windows XP SP2 DSL internet connection 2.61 GHz Athlon 2x 5000+, 1930 MB RAM
Product: Core → MailNews Core
I have had this problem and I deleted inbox.dbx. It seems that the probram does not properly zero out the mailbox when files are deleted, which results in a very high file size. Periodically, I delete the Inbox.dbx and move the sent folders to another file and delete that also. The sent folder will sometimes prevent files from being copied there because apparently it has reached a max size. I create a replacement sent folder copying and renaming the zero size trash.dbx folder.
Whiteboard: [has pop log]
david can you comment on the pop log ?
I'm getting this message after a period of inactivity. It refers to the selected folder. I can select a different folder and check the mail manually, no problem. After that I can switch back to the initially selected folder and check mail manually, without getting the message.
(In reply to comment #19) > david can you comment on the pop log ? yes, the user has configured the client to use TLS if available, and the server advertises TLS, so it's available, but the TLS command is failing. I would recommend configuring the client *NOT* to use TLS in this case. I'm not sure if we loop forever trying TLS and failing, and that's why we're keeping the inbox locked, since the user has edited the log. I doubt that his problem is the same as the others...
I get this error message on seamonkey-2.0.4 startup when the mailer is supposed to fetch two pop3 mailboxes via non-encrypted connection.
(In reply to comment #22) > I get this error message on seamonkey-2.0.4 startup when the mailer is supposed > to fetch two pop3 mailboxes via non-encrypted connection. My seamonkey is configured to start the browser upon startup. However, I see some pop3 traffic initiated while only browser window is up! I suspect because my pop3 server does some remote ident lookup of my client IP address (which has to timeout in 10 or 15 sec because port blocked on a firewall), it just takes a loong while to finish. Usually, after the browser window has been opened I click and open the mailer and the mailer is configured to fetch my 2 pop3 mailboxes (so that happens withing 10 seconds since I started seamonkey I guess). As I have already mentioned, there are background threads started by the "browser" window which for an unknown reason tried to connect to my pop3 servers. I believe that is why I get the error message. If I wait for a long time before opening the mailer window, the error message does not appear and email gets downloaded automatically as expected. I haven't seen this with 1.1.18 or earlier, only now with 2.0.4.
(In reply to comment #3) > In nsPop3Protocol.cpp, in function WaitForStartOfConnectionResponse, we use > ReadNextLine disregarding its nsresult out argument. Thus, we lose valuable > information as to why the return value (the 'line') ended up null. Perhaps if > the nsresult is not SUCCESS, we should call the sink's IncorporateAbort and/or > AbortMailDelivery. I don't think this is true right now. If ReadNextLine in WaitForStartOfConnectionResponse fails (i.e., NS_FAILED(rv)), then we return -1 and we'll get into the POP3_ERROR_DONE case.
To Tomer Gabel(bug opener) and all comment posters about next issue: - POP3 - "This folder is being processed" upon Get Msgs(manually, automatically) - "This folder is being processed" occurs after connection drop(and/or sleep/wakeup, suspend/resume. connection drop happens due to power off/on) - "This folder is being processed" won't disappear until restart of Tb. An almost same phenomenon as above of Tb 3.0 has been analyzed in bug 466933, with new logging by try server build, and a cause has been found in that bug. And, data for diagnosis of original problem of this bug is not provided yet. And, this bug is already very hard to track due to very long pasted NSPR log data. And, the only data for diagnosis which was pasted looks irrelevant to this bug. And, as written in comment #24, initial analysis in comment #3 on 2006-01-31 seems obsolete. I don't think continuous diagnosis in this bug is useful any more. So closing as DUP of bug 466933 for ease of tracking, instead of INCOMPLETE. If your problem of bug summary persists in your environment, read thru bug 466933 and get log required for diagnosis using try server build pointed in bug 466933. If your problem is different problem from bug 466933, please open separate bug, with attaching sufficient data for diagnosis. Cause may not be same in all cases, even if POP3 and "This folder is being processed" is same. (e.g. PC's IP address change by DHCP while Tb is running also can cause connection error. Server IP address change by DNS round robin may cause error upon next POP3 access due to old data in DNS cache.) If your problem is different from this bug and bug 466933, open separate bug, please.
Status: UNCONFIRMED → RESOLVED
Closed: 15 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.