Closed Bug 215776 Opened 22 years ago Closed 22 years ago

Mozilla stops sending IMAP command to server after a while, then resumes some 20-25 minutes later

Categories

(MailNews Core :: Networking: IMAP, defect)

Product:
MailNews Core
Component:
Networking: IMAP
Platform:
PowerPC
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: patrick.stadelmann, Assigned: Bienvenu)

Details

Attachments

(1 file)

proposed fix
602 bytes, patch
sspitzer
: review+
sspitzer
: superreview+
sspitzer
: approval1.5b+
Details | Diff | Splinter Review
User-Agent: Mozilla/5.0 (Macintosh; U; PPC Mac OS X; en) AppleWebKit/85.7 (KHTML, like Gecko) Safari/85.5 Build Identifier: Mozilla/5.0 (Macintosh; U; PPC Mac OS X Mach-O; en-US; rv:1.5b) Gecko/20030810 Mozilla seems to be unable to send IMAP commands after a while (eg if a IMAP folder is selected, the list of messages is displayed, but not refreshed and the watch cursor stays on). This was observed by looking at the TCP/IP packets exchanged with the server. However, the connectivity is not lost. If I leave Mozilla open, it will starts sending command again after 20-30 minutes Here's a an excerpt of the TCP/IP log : 10:25:36 Mozilla sends a FETCH command with ID 3 10:25:36: The server send it's reply, ending with "3 OK FETCH" comleted. Now, for 25 minutes, no packets is sent, even if I manually click "Get mail" or display the content of various folder on the server. Using netstat, I see that there are 5 IMAP connections established with the server (Mozilla is the only IMAP client running). And then 10:51:35: Mozilla sends "4 logout" 10:51:35: Server sends "4 OK LOGOUT completed." 10:51:35: Mozilla open a new connexion 10:51:35: Server sends greeting message then Mozilla fetches the new messages and then checks for new messages every minute as set in the preferences. It does this between 10:52:35 and 10:55:36, after that it will again stop sending command for another 20-25 minutes. Reproducible: Sometimes Steps to Reproduce: 1. Connect to IMAP server 2. Perform various IMAP operations (get mail, display folder...) Actual Results: Mozilla exhibits behaviour described above after a few seconds or minutes (variable). Expected Results: Continue sending IMAP commands. This is the greeting message from our IMAP server : OK Microsoft Exchange 2000 IMAP4rev1 server version 6.0.6249.0 The problem occurs whether SSL is used or not. It does not occur in 1.4 final, but I've observed in the three 1.5b builds I've used. Also, this problem does not occur if IMAP logging is turned on !!! This the output of the Mac OS X "sampler" tool executed while Mozilla was not sending IMAP commands : Analysis of sampling pid 784 every 10 milliseconds Call graph: 500 Thread_0e03 500 start 500 _start 500 main 500 main1(int, char**, nsISupports*) 500 nsAppShell::Run() 500 nsMacMessagePump::DoMessagePump() 500 nsMacMessagePump::GetEvent(EventRecord&) 500 WaitNextEvent 500 WNEInternal 500 GetNextEventMatchingMask 500 RunCurrentEventLoopInMode 500 CFRunLoopRunSpecific 498 __CFRunLoopRun 498 mach_msg 498 mach_msg_trap 498 mach_msg_trap [STACK TOP] 1 CFRunLoopRunSpecific [STACK TOP] 1 __CFRunLoopDoObservers 1 FlushAllBuffers(__CFRunLoopObserver*, CFRunLoopActivity, void*) 1 FlushAllWindows 1 QDFlushPortBuffer 1 QDPlatformFlushWindow 1 QDPlatformFlushWindow [STACK TOP] 500 Thread_0f03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsSocketTransportService::Run() 500 _pr_poll_with_poll 500 poll 500 select 500 select [STACK TOP] 500 Thread_1003 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsDNSService::Run() 500 nsDNSService::DequeuePendingQ() 500 PR_WaitCondVar 500 _pthread_cond_wait 500 semaphore_wait_signal_trap 500 semaphore_wait_signal_trap [STACK TOP] 500 Thread_1103 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JNI_CreateJavaVM_Impl 500 JNI_CreateJavaVM_Impl 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1203 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JNI_CreateJavaVM_Impl 500 JVM_Send 500 JVM_FillInStackTrace 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1303 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JVM_FindClassFromClass 500 JVM_GetMethodIxExceptionTableEntry 500 JVM_IsSameClassPackage 500 JVM_FindClassFromClass 500 JVM_CurrentTimeMillis 500 typeinfo name for std::bad_exception 500 0x42d468c 500 0x42d468c 500 0x42d6678 500 JVM_MonitorWait 500 JVM_MonitorNotify 500 JVM_ArrayCopy 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1403 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JVM_FindClassFromClass 500 JVM_GetMethodIxExceptionTableEntry 500 JVM_IsSameClassPackage 500 JVM_FindClassFromClass 500 JVM_CurrentTimeMillis 500 typeinfo name for std::bad_exception 500 0x42d45cc 500 0x42d45cc 500 0x42d468c 500 0x42d6678 500 JVM_MonitorWait 500 JVM_MonitorNotify 500 JVM_ArrayCopy 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1503 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JVM_GetClassLoader 500 JVM_GetClassLoader 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1603 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JVM_FindClassFromClass 500 JVM_InitProperties 500 JVM_InitProperties 500 JVM_FillInStackTrace 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1703 500 _pthread_body 500 JVM_GetClassMethodsCount 500 JVM_FindClassFromClass 500 JVM_FindLoadedClass 500 JVM_StartThread 500 JVM_FillInStackTrace 500 JVM_NewInstance 500 mach_msg 500 mach_msg_trap 500 mach_msg_trap [STACK TOP] 500 Thread_1803 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 TimerThread::Run() 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1903 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsThreadPoolRunnable::Run() 500 nsThreadPool::GetRequest(nsIThread*) 500 PR_WaitCondVar 500 _pthread_cond_wait 500 semaphore_wait_signal_trap 500 semaphore_wait_signal_trap [STACK TOP] 500 Thread_1a03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsImapProtocol::Run() 500 nsImapProtocol::ImapThreadMainLoop() 500 PR_Wait 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1b03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsImapProtocol::Run() 500 nsImapProtocol::ImapThreadMainLoop() 500 PR_Wait 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1c03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsImapProtocol::Run() 500 nsImapProtocol::ImapThreadMainLoop() 500 PR_Wait 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1d03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsImapProtocol::Run() 500 nsImapProtocol::ImapThreadMainLoop() 500 PR_Wait 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1e03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsImapProtocol::Run() 500 nsImapProtocol::ImapThreadMainLoop() 500 PR_Wait 500 PR_WaitCondVar 500 pt_TimedWait 500 _pthread_cond_wait 500 semaphore_timedwait_signal_trap 500 semaphore_timedwait_signal_trap [STACK TOP] 500 Thread_1f03 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsLDAPConnectionLoop::Run() 500 PR_Sleep 497 PR_WaitCondVar 497 pt_TimedWait 495 _pthread_cond_wait 490 semaphore_timedwait_signal_trap 490 semaphore_timedwait_signal_trap [STACK TOP] 3 gettimeofday 3 __ppc_gettimeofday 3 __ppc_gettimeofday [STACK TOP] 2 _pthread_cond_remove 2 _pthread_cond_remove [STACK TOP] 2 gettimeofday 2 __ppc_gettimeofday 2 __ppc_gettimeofday [STACK TOP] 2 _PR_UNIX_GetInterval 2 gettimeofday 2 __ppc_gettimeofday 2 __ppc_gettimeofday [STACK TOP] 1 PR_IntervalNow 1 PR_IntervalNow [STACK TOP] 500 Thread_2003 500 _pthread_body 500 _pt_root 500 nsThread::Main(void*) 500 nsLDAPConnectionLoop::Run() 499 PR_Sleep 495 PR_WaitCondVar 494 pt_TimedWait 491 _pthread_cond_wait 488 semaphore_timedwait_signal_trap 488 semaphore_timedwait_signal_trap [STACK TOP] 2 gettimeofday 2 __ppc_gettimeofday 2 __ppc_gettimeofday [STACK TOP] 1 _pthread_cond_wait [STACK TOP] 3 gettimeofday 3 __ppc_gettimeofday 3 __ppc_gettimeofday [STACK TOP] 1 PR_GetCurrentThread 1 pthread_getspecific 1 __gcc_bcmp 1 __gcc_bcmp [STACK TOP] 3 _PR_UNIX_GetInterval 3 gettimeofday 3 __ppc_gettimeofday 3 __ppc_gettimeofday [STACK TOP] 1 __gcc_bcmp 1 __gcc_bcmp [STACK TOP] 1 nsLDAPConnection::Release() 1 __gcc_bcmp 1 __gcc_bcmp [STACK TOP] Total number in stack (recursive counted multiple, when >=5): 18 _pthread_body 11 _pt_root 11 nsThread::Main(void*) 10 PR_WaitCondVar 10 _pthread_cond_wait 8 mach_msg 8 mach_msg_trap 8 pt_TimedWait 8 semaphore_timedwait_signal_trap 7 JVM_GetClassMethodsCount 6 JVM_FindClassFromClass 6 JVM_NewInstance 6 __ppc_gettimeofday 6 gettimeofday 5 PR_Wait 5 nsImapProtocol::ImapThreadMainLoop() 5 nsImapProtocol::Run() Sort by top of stack, same collapsed (when >= 5): mach_msg_trap [STACK TOP] 3998 semaphore_timedwait_signal_trap [STACK TOP] 3978 semaphore_wait_signal_trap [STACK TOP] 1000 select [STACK TOP] 500 __ppc_gettimeofday [STACK TOP] 15
I'm also seeing strange things happening, but not when protocol logging is turned on :-( This is recent. I'm wondering if it's related to the change I made to check if a transport is alive before trying to use it (I don't think that change was in 1.4). Or maybe something changed in necko...
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
Attached patch proposed fix — — Splinter Review
I removed this line earlier, because I didn't realize the side effect of calling it was what we wanted. So I restored the line and added a comment.
Comment on attachment 129596 [details] [diff] [review] proposed fix r/sr/a=sspitzer
Attachment #129596 - Flags: superreview+
Attachment #129596 - Flags: review+
Attachment #129596 - Flags: approval1.5b+
fix checked in - Scott, I think this should fix the problem you were seeing. You need to turn off imap protocol logging in order to see if the fix worked, because imap protocol logging has the side-effect of fixing this. Also, if the copying to the sent folder problem starts happening again, that would be a big clue as to the nature of that problem...
Status: ASSIGNED → RESOLVED
Closed: 22 years ago
Resolution: --- → FIXED
Product: MailNews → Core
Product: Core → MailNews Core
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: