31.x pop account gets mail on startup, and then stops getting new mail. Fails with authentication via Kerberos, plain text auth works

UNCONFIRMED
Unassigned

Status

UNCONFIRMED
4 years ago
a year ago

People

(Reporter: actapenko, Unassigned)

Tracking

({regression, regressionwindow-wanted})

x86_64
Windows 7
regression, regressionwindow-wanted

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [regression:TB38?])

(Reporter)

Description

4 years ago
User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firefox/37.0
Build ID: 20150402191859

Steps to reproduce:

autoconfig get this settings for client:
try {
	lockPref("mail.shell.checkDefaultClient", false);				
	lockPref("toolkit.telemetry.rejected", true);					
	lockPref("toolkit.telemetry.enabled", false);					
	lockPref("toolkit.telemetry.prompted", 2);						
	lockPref("mailnews.database.global.indexer.enabled", true);		
	lockPref("mail.winsearch.enable", false);									
	lockPref("mail.winsearch.firstRunDone", true);				
	lockPref("mail.spam.manualMark", true);							
	lockPref("mail.spam.markAsReadOnSpam", false);					
	lockPref("mail.spam.logging.enabled", true);					
	lockPref("network.cookie.cookieBehavior", 2);					
	lockPref("privacy.donottrackheader.enabled", true);				
	lockPref("mailnews.start_page.enabled", false);					
	lockPref("mail.biff.show_alert", true);							
	lockPref("mail.biff.play_sound", true);						
	lockPref("mail.biff.play_sound.type", 0);					
	lockPref("mail.biff.show_tray_icon", true);						
	lockPref("mail.biff.alert.show_preview", false);			
	lockPref("alerts.totalOpenTime", 5000);							
	lockPref("mail.enable_autocomplete", true);					
	lockPref("mail.spellcheck.inline", true);					
	lockPref("spellchecker.dictionary", "ru");					
	lockPref("messenger.startup.action", 0);						
	lockPref("messenger.status.awayWhenIdle", false);			
	lockPref("messenger.status.reportIdle", false);					
	lockPref("purple.conversations.im.send_typing", false);		
	lockPref("browser.cache.disk.capacity", 524288);			
	lockPref("browser.cache.disk.smart_size.first_run", false);		
	lockPref("mail.purge.ask", true);							
	lockPref("mail.prompt_purge_threshhold", true);					
	lockPref("mail.purge_threshhold_mb", 25);						
	lockPref("mailnews.mark_message_read.auto", true);				
	lockPref("mailnews.mark_message_read.delay", true);				
	lockPref("mailnews.mark_message_read.delay.interval", 2);		
	lockPref("mail.openMessageBehavior", 2);						
	lockPref("general.autoScroll", true);							
	lockPref("general.smoothScroll", true);				
	
	lockPref("app.update.enabled", false);
	lockPref("app.update.auto", false);
	lockPref("extensions.update.enabled", false);
	lockPref("app.update.service.enabled", false);
	
	lockPref("ldap_2.autoComplete.directoryServer", "ldap_2.servers.MTS");
	lockPref("ldap_2.autoComplete.useDirectory", true);
	lockPref("ldap_2.servers.MTS.auth.dn", "");
	lockPref("ldap_2.servers.MTS.auth.saslmech", "");
	lockPref("ldap_2.servers.MTS.description", "MTS");
	lockPref("ldap_2.servers.MTS.filename", "ldap.mab");
	lockPref("ldap_2.servers.MTS.maxHits", 100);
	lockPref("ldap_2.servers.MTS.uri", "ldap://ldap:1389/dc=mts,%20dc=by??sub?(objectclass=*)");
	
	lockPref("mail.account.account1.identities", "id1");
	lockPref("mail.account.account1.server", "server1");
	lockPref("mail.account.account2.server", "server2");
	defaultPref("mail.accountmanager.accounts", "account1,account2");
	defaultPref("mail.accountmanager.defaultaccount", "account1");
	lockPref("mail.accountmanager.localfoldersserver", "server2");
	lockPref("mail.rights.version", 1);	
	
	lockPref("mail.identity.id1.archive_folder", "mailbox://statham@relay.inside.mts.by/Archives");
	lockPref("mail.identity.id1.directoryServer", "ldap_2.servers.MTS");
	lockPref("mail.identity.id1.doBcc", false);
	lockPref("mail.identity.id1.draft_folder", "mailbox://statham@relay.inside.mts.by/Drafts");
	lockPref("mail.identity.id1.drafts_folder_picker_mode", "0");
	lockPref("mail.identity.id1.encryptionpolicy", 0);
	lockPref("mail.identity.id1.fcc_folder", "mailbox://statham@relay.inside.mts.by/Sent");
	lockPref("mail.identity.id1.fcc_folder_picker_mode", "0");
	defaultPref("mail.identity.id1.fullName", "Джейсон Стэтхэм");
	lockPref("mail.identity.id1.organization", "СООО «Мобильные ТелеСистемы»");
	lockPref("mail.identity.id1.overrideGlobal_Pref", true);
	lockPref("mail.identity.id1.reply_on_top", 1);
	lockPref("mail.identity.id1.sign_mail", false);
	lockPref("mail.identity.id1.smtpServer", "smtp1");
	lockPref("mail.identity.id1.stationery_folder", "mailbox://statham@relay.inside.mts.by/Templates");
	lockPref("mail.identity.id1.tmpl_folder_picker_mode", "0");
	lockPref("mail.identity.id1.useremail", "statham@mts.by");
	lockPref("mail.identity.id1.valid", true);
	lockPref("mail.identity.id1.auto_quote", true);
	lockPref("mail.identity.id1.archives_folder_picker_mode", "0");
	lockPref("mail.identity.id1.archive_enabled", true);
	lockPref("mail.identity.id1.archive_granularity", 1);	
	lockPref("mail.identity.id1.archive_keep_folder_structure", false);	
	lockPref("mail.identity.id1.fcc", true);
	lockPref("mail.identity.id1.compose_html", true);
	lockPref("mail.identity.id1.sig_on_reply", true);
	lockPref("mail.identity.id1.sig_on_fwd", false);
	lockPref("mail.server.server1.limit_offline_message_size", false);
	
	lockPref("mail.server.server1.login_at_startup", true);
	lockPref("mail.server.server1.download_on_biff", true);		
	lockPref("mail.server.server1.check_time", 5);									
	lockPref("mail.server.server1.headers_only", false);								
	lockPref("mail.server.server1.check_new_mail", true);
	lockPref("mail.server.server1.directory-rel", "[ProfD]Mail/pop3");
	lockPref("mail.server.server1.hostname", "relay.inside.mts.by");
	lockPref("mail.server.server1.leave_on_server", false);
	lockPref("mail.server.server1.name", "statham@mts.by");
	lockPref("mail.server.server1.socketType", 0);
	lockPref("mail.server.server1.type", "pop3");
	lockPref("mail.server.server1.userName", "statham");
	lockPref("mail.server.server1.authMethod", 5);
	
	lockPref("mail.server.server1.daysToKeepHdrs", 365);
	lockPref("mail.server.server1.cleanupBodies", false);
	lockPref("mail.server.server1.downloadByDate", false);
	lockPref("mail.server.server1.downloadUnreadOnly", false);
	lockPref("mail.server.server1.keepUnreadOnly", false);
	lockPref("mail.server.server1.numHdrsToKeep", 2000);
	lockPref("mail.server.server1.retainBy", 2);
	lockPref("mail.server.server1.applyToFlaggedMessages", false);
	lockPref("mail.server.server1.spamLevel", "");
	lockPref("mail.server.server1.empty_trash_on_exit", true);

	lockPref("mail.server.server1.moveOnSpam", true);
	lockPref("mail.server.server1.moveTargetMode", 1);
	lockPref("mail.server.server1.spamActionTargetAccount", "mailbox://statham@relay.inside.mts.by");
	lockPref("mail.server.server1.spamActionTargetFolder", "mailbox://statham@relay.inside.mts.by/Junk");
	

	lockPref("mail.server.server1.purgeSpam", true);
	lockPref("mail.server.server1.purgeSpamInterval", 30);

	lockPref("mail.server.server2.directory-rel", "[ProfD]Mail/Local Folders");
	lockPref("mail.server.server2.hostname", "Local Folders");
	lockPref("mail.server.server2.name", "Локальные папки");
	lockPref("mail.server.server2.type", "none");
	lockPref("mail.server.server2.userName", "nobody");
	
	lockPref("mail.smtpserver.smtp1.authMethod", 5);
	lockPref("mail.smtpserver.smtp1.description", "SMTP сервер");
	lockPref("mail.smtpserver.smtp1.hostname", "relay.inside.mts.by");
	lockPref("mail.smtpserver.smtp1.port", 25);
	lockPref("mail.smtpserver.smtp1.try_ssl", 0);
	lockPref("mail.smtpserver.smtp1.username", "statham");
	lockPref("mail.smtpservers", "smtp1");
	lockPref("mail.smtp.defaultserver", "smtp1");

	lockPref("network.proxy.type", 4);
    lockPref("mailnews.start_page_override.mstone", "ignore");
	
} catch(e) {
    displayError("lockedPref", e);
}


Actual results:

Tried different versions of the client. The situation is the same.
Here are the logs of the client:
2015-04-15 14:01:18.473000 UTC - 0[210f140]: Setting server busy in nsPop3Protocol::LoadUrl
2015-04-15 14:01:18.551000 UTC - 0[210f140]: Entering NET_ProcessPop3 29
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 1
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 2
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 4
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: +OK POP3/IMAP server ready.
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 26
2015-04-15 14:01:18.551000 UTC - 0[210f140]: SEND: AUTH

2015-04-15 14:01:18.551000 UTC - 0[210f140]: Entering NET_ProcessPop3 30
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: +OK
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 27
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: GSSAPI
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 27
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: LOGIN
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 27
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: PLAIN
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 27
2015-04-15 14:01:18.551000 UTC - 0[210f140]: RECV: .
2015-04-15 14:01:18.551000 UTC - 0[210f140]: POP3: Entering state: 28
2015-04-15 14:01:18.551000 UTC - 0[210f140]: SendCapa()
2015-04-15 14:01:18.551000 UTC - 0[210f140]: SEND: CAPA

2015-04-15 14:01:18.567000 UTC - 0[210f140]: Entering NET_ProcessPop3 80
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: +OK
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: CAPA
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: TOP
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: UIDL
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: RESP-CODES
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: PIPELINING
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: USER
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: SASL GSSAPI LOGIN PLAIN
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 29
2015-04-15 14:01:18.567000 UTC - 0[210f140]: RECV: .
2015-04-15 14:01:18.567000 UTC - 0[210f140]: capa processed
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 30
2015-04-15 14:01:18.567000 UTC - 0[210f140]: ProcessAuth()
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP auth: server caps 0x121CAA, pref 0x100000, failed 0x0, avail caps 0x100000
2015-04-15 14:01:18.567000 UTC - 0[210f140]: (GSSAPI = 0x100000, CRAM = 0x2000, APOP = 0x4000, NTLM = 0x8000, MSN =  0x10000, PLAIN = 0x1000, LOGIN = 0x800, USER/PASS = 0x400)
2015-04-15 14:01:18.567000 UTC - 0[210f140]: trying auth method 0x100000
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP GSSAPI
2015-04-15 14:01:18.567000 UTC - 0[210f140]: POP3: Entering state: 42
2015-04-15 14:01:18.567000 UTC - 0[210f140]: AuthGSSAPI()
2015-04-15 14:01:18.770000 UTC - 0[210f140]: SEND: AUTH GSSAPI

2015-04-15 14:01:18.785000 UTC - 0[210f140]: Entering NET_ProcessPop3 4
2015-04-15 14:01:18.785000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.785000 UTC - 0[210f140]: RECV: +
2015-04-15 14:01:18.785000 UTC - 0[210f140]: POP3: Entering state: 43
2015-04-15 14:01:18.785000 UTC - 0[210f140]: SEND: YIIF+AYJKoZIhvcSAQICAQBuggXnMIIF46ADAgEFoQMCAQ6iBwMFACAAAACjggRyYYIEbjCCBGqgAwIBBaEJGwdNVFMuTE9DoiUwI6ADAgECoRwwGhsDcG9wGxNyZWxheS5pbnNpZGUubXRzLmJ5o4IELzCCBCugAwIBF6EDAgEDooIEHQSCBBl5N+3lmwYe9PDp3xEb6iY579C0kC+UL4sd1c5YPncSnl+Paj7r++AU7XYDYRCJeS9fiV781xiUR0VDl3SlBnUYj6BDTJrsejlTlC1OINQJhiUQlLcfFP80h4INtEBY7cUiVS5y66d2WSvECbE2msqTvSEYtMIcXJYGLGK7UpbODA6g6QBVWOZeDOv17HyR5K4qjYC5kpshZBoBwFIrHqnmRWsalPx2hGDY6bd/F8Wvb3r83uGDp3HdOEGz7N6saDZ/94k39DU23TNJbOUHFsn5J1HcVXC25HTC7d3qALPqQ7IJ3Ww651o1uird3l1XFxA0wsjPgc2pv8wuZu2yIaZG8unPobz+CQ7e32IrjUKu84qx4CRR4CPawu94V++Pr/4EoKNDHw8BURFemWZbtdYgiP1ZzieJpFT+VT+FrLiNPHZlw4PPunJtnbrvNYzR7edmoCsNd40iAfnAHXxj5nBGUzDtvQA6+ebYV/u5yQwpn+xWtybef3oG1ig5QLJqNVn7f7zI0VbCFKy0fmvBvayBRixp6eZ40BT5TIlAOArTZEW5176cWuhmbgK++q+C69kaSQYvYWWoLBkefpFWjvuhGttbg6xlrwRKp3XcN3Y+ljPML6va0wb8AGNNVbqX5IM5wx+S8/naSlkfN2+/WBrBsAQF1+hp8wDbXj6qTo+548JvAoFcVRmlDkPLYN614DT1Wvn1hHGdBYUerfQkImffr0JgKKf+Aa0hh9j0xU2N+tTH8OYLz/KRjTFGTMtoWRcAL6UJVpiuuc9P1q7OI2JZ00NYxCY0jPmlkc49s/j7K5scvKsvT3j2o7LGBj+xpYyeyP1CEAjm3gJpjypvnp5j4uy1j3pQgajV0JYplI8++jlTpbIprRv7djb069Z6nkExKJ1tGMNv9lHJQdh4pYiSz4+lCPgSip6VmhOCF9NktChARKQmvQrcLSfKgnJy02Vxp69xABHcI/znqPK5hrPyuINgwKHBaD0bA3x2t77YIzsNZXtX9cXUEK531bK00FOep9Xb+zdRIpQm7HUwWkcBRjjTn1EBfloKXPvob2l134ziUu4YG2XlxuR1mVZWt8H5DPGCjSUwx9it8tTDJuhM6uPRq1/3eI9OLDDn/fvHdsWiepcUc+ucL6FgpzztlYcphAem3fQptnHwkYMgqzYqDDv8jhZ7Cnnx4YwGl6VCud8yTbOM0tytAEDq8VAiDLAvWbFfZo3lGvR4CQFciLVnvElohJ7xkr7U+nBjAd3n2M5kZHfjwUvknO7mqISknBXYkWbBy6QHMAWH6kQeOFMkjO0fAEfhWdUy+5xZIHk7J0iBb0yw+eJ2gseIccTSel/8ENUSUnv9u67jZAgc72Fajya2w+yzdSpEUOjo8kIiFYnolzjKdurIfKSCAVYwggFSoAMCAReiggFJBIIBRQvv88lbiH/DpnGav27qCBQ2fZkk84ku3TpPyFbSWGTID0RtVTJsg9W5IrWvyIlTLicdl2cH4dY5hw6TKSExr6w+kN+PJsu+ediyYpob/SC+8wq8OwPlYUrIqBqHHu/Z4DxeXAGaSc+3Z3ik2QTDKr/tVPWvjthN9E7tV/AS/O5DIWSmrpkpPXbOAwkOoEsGcxWRosqNwkdYbPpsQAseUM2vG8pZaljuWB2KedT2zfmaAd1Si2W0V4wP7QUpggi5udn4r2+VXUJPvEpx07Dy/8SyN/bCXgegZJ33Q2McQlg5Bwt3BPtZeF/nKqw/kGmOXGpYFW1EPjyUtoj8Q0W6F1kcV/1X6j6L5+heJA0LWY3AH1AhcIT5XeHfKFEOz5F0TDAoGu7Txm5YIWnoqYvy2FxWLJIquzckPfE1s9gyjbmT+G5sJfo=

2015-04-15 14:01:18.817000 UTC - 0[210f140]: Entering NET_ProcessPop3 204
2015-04-15 14:01:18.817000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.817000 UTC - 0[210f140]: RECV: + YIGTBgkqhkiG9xIBAgICAG+BgzCBgKADAgEFoQMCAQ+idDByoAMCAReiawRpvpdaQb5mFIAxYasNy4d7iBLIVQPI2CKwt/9Y/RY6umH1k7vzzNIpUl/0Hrx83E20Ospz0R7CXb24epVoJXet8TRM/NFjwrw7Jj8unwrtUsV90wlyfH2UjdXmOH/CY82oL6UPeGa6WKff
2015-04-15 14:01:18.817000 UTC - 0[210f140]: POP3: Entering state: 44
2015-04-15 14:01:18.817000 UTC - 0[210f140]: GSSAPI step 2
2015-04-15 14:01:18.817000 UTC - 0[210f140]: SEND:

2015-04-15 14:01:18.817000 UTC - 0[210f140]: Entering NET_ProcessPop3 48
2015-04-15 14:01:18.817000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.817000 UTC - 0[210f140]: RECV: + BQQF/wAMAAAAAAAALRmA3QH///8tp0nNK/XVFsSauWg=
2015-04-15 14:01:18.817000 UTC - 0[210f140]: POP3: Entering state: 44
2015-04-15 14:01:18.817000 UTC - 0[210f140]: GSSAPI step 2
2015-04-15 14:01:18.832000 UTC - 0[210f140]: SEND: BQQE/wAMAAwAAAAAJLQykgr+uJqGSydaak7hDwEAAABzdGF0aGFt

2015-04-15 14:01:18.848000 UTC - 0[210f140]: Entering NET_ProcessPop3 16
2015-04-15 14:01:18.848000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.848000 UTC - 0[210f140]: RECV: +OK Logged in.
2015-04-15 14:01:18.848000 UTC - 0[210f140]: POP3: Entering state: 31
2015-04-15 14:01:18.848000 UTC - 0[210f140]: NextAuthStep()
2015-04-15 14:01:18.848000 UTC - 0[210f140]: login succeeded
2015-04-15 14:01:18.848000 UTC - 0[210f140]: POP3: Entering state: 7
2015-04-15 14:01:18.848000 UTC - 0[210f140]: SEND: STAT

2015-04-15 14:01:18.863000 UTC - 0[210f140]: Entering NET_ProcessPop3 9
2015-04-15 14:01:18.863000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.863000 UTC - 0[210f140]: RECV: +OK 0 0
2015-04-15 14:01:18.863000 UTC - 0[210f140]: POP3: Entering state: 8
2015-04-15 14:01:18.863000 UTC - 0[210f140]: BeginMailDelivery acquiring semaphore
2015-04-15 14:01:18.863000 UTC - 0[210f140]: Calling ReleaseFolderLock from AbortMailDelivery
2015-04-15 14:01:18.863000 UTC - 0[210f140]: ReleaseFolderLock haveSemaphore = TRUE
2015-04-15 14:01:18.879000 UTC - 0[210f140]: POP3: Entering state: 22
2015-04-15 14:01:18.879000 UTC - 0[210f140]: SEND: QUIT

2015-04-15 14:01:18.895000 UTC - 0[210f140]: Entering NET_ProcessPop3 18
2015-04-15 14:01:18.895000 UTC - 0[210f140]: POP3: Entering state: 3
2015-04-15 14:01:18.895000 UTC - 0[210f140]: RECV: +OK Logging out.
2015-04-15 14:01:18.895000 UTC - 0[210f140]: POP3: Entering state: 40
2015-04-15 14:01:18.895000 UTC - 0[210f140]: POP3: Entering state: 23
2015-04-15 14:01:18.895000 UTC - 0[210f140]: POP3: Entering state: 25
2015-04-15 14:01:18.895000 UTC - 0[210f140]: Clearing server busy in POP3_FREE
2015-04-15 14:01:18.895000 UTC - 0[210f140]: Clearing running protocol in POP3_FREE
2015-04-15 14:01:18.895000 UTC - 0[210f140]: Clearing server busy in OnStopRequest
2015-04-15 14:01:18.895000 UTC - 0[210f140]: ~nsPop3Protocol()
2015-04-15 14:01:18.895000 UTC - 0[210f140]: Calling ReleaseFolderLock from ~nsPop3Sink
2015-04-15 14:01:18.895000 UTC - 0[210f140]: ReleaseFolderLock haveSemaphore = FALSE

On Safe Mode with Network Drivers:
2015-04-15 14:26:24.340000 UTC - 0[b0f140]: Setting server busy in nsPop3Protocol::LoadUrl
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: Entering NET_ProcessPop3 29
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: POP3: Entering state: 1
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: POP3: Entering state: 2
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: POP3: Entering state: 4
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: RECV: +OK POP3/IMAP server ready.
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: POP3: Entering state: 26
2015-04-15 14:26:24.496000 UTC - 0[b0f140]: SEND: AUTH

2015-04-15 14:26:24.512000 UTC - 0[b0f140]: Entering NET_ProcessPop3 30
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: RECV: +OK
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 27
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: RECV: GSSAPI
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 27
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: RECV: LOGIN
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 27
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: RECV: PLAIN
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 27
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: RECV: .
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: POP3: Entering state: 28
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: SendCapa()
2015-04-15 14:26:24.512000 UTC - 0[b0f140]: SEND: CAPA

2015-04-15 14:26:24.527000 UTC - 0[b0f140]: Entering NET_ProcessPop3 80
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: +OK
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: CAPA
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: TOP
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: UIDL
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: RESP-CODES
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: PIPELINING
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: USER
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: SASL GSSAPI LOGIN PLAIN
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 29
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: RECV: .
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: capa processed
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 30
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: ProcessAuth()
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP auth: server caps 0x121CAA, pref 0x100000, failed 0x0, avail caps 0x100000
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: (GSSAPI = 0x100000, CRAM = 0x2000, APOP = 0x4000, NTLM = 0x8000, MSN =  0x10000, PLAIN = 0x1000, LOGIN = 0x800, USER/PASS = 0x400)
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: trying auth method 0x100000
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP GSSAPI
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: POP3: Entering state: 42
2015-04-15 14:26:24.527000 UTC - 0[b0f140]: AuthGSSAPI()
2015-04-15 14:26:24.621000 UTC - 0[b0f140]: SEND: AUTH GSSAPI

2015-04-15 14:26:24.637000 UTC - 0[b0f140]: Entering NET_ProcessPop3 4
2015-04-15 14:26:24.637000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.637000 UTC - 0[b0f140]: RECV: +
2015-04-15 14:26:24.637000 UTC - 0[b0f140]: POP3: Entering state: 43
2015-04-15 14:26:24.637000 UTC - 0[b0f140]: SEND: YIIF+AYJKoZIhvcSAQICAQBuggXnMIIF46ADAgEFoQMCAQ6iBwMFACAAAACjggRyYYIEbjCCBGqgAwIBBaEJGwdNVFMuTE9DoiUwI6ADAgECoRwwGhsDcG9wGxNyZWxheS5pbnNpZGUubXRzLmJ5o4IELzCCBCugAwIBF6EDAgEDooIEHQSCBBk2FUmP6W36dhSLFnKoqKm6yHI2WjSEnbrjvmmfHLUDTtj/pe0CA5sXHc5+APf4LDOsak3YkvYAXERWgeEMbFV4dkWSGBIlYcdG7dWbrxvit733jEt1/qqjJD7eLiKvru1OIe2c1bv7ZjlEiVskXN4pLNLfI7xAwdeyvgiNlWN2b7tvDaFnS4G1vEWwe+H/p3Fth+XJ0nqIhdOaFWtJ87u5HdXhvPslCCxbXxxEU18Lwm7FKbQEQPd45mD/xuijTs//L5zRfhWPozJsK5ECf0wq+lnLArbK/Uh3W6bD0OuqPFpK4Ny8IbOXE088M3Q6wFnpZGg9HBCV8qK8mhbGHz447tKTj3qAV1p1wcMErHfIDEUdJNqxADnQqoyZGAWtO+dBfbP5jGomDWFFAxnzRM0J6uuM6CGtWxP7M3ymky8zFdHl1V1udOZkc+3eXv0PN2mqQWzKiQU+g6K/1SSkMsz10UsDAwPKO7MchyDunZeCy4sxw9Dvfhu95KCjQ4exd6Rg6c1HgwGCImBLkxVrC8NeQsqduFVLGEKBeKFn6RSxtbU53aKLN6YSZjCispR2J8U18FjbDIgZO4KxAfgEaWowjF7kBnXmEF+nErxxjXg0ZdNqncOyTl/wRaiEuzaQ+MxO4NmSHwtpI2f0aDrIYEgz2rmlzCvSxetImUCTVALWYv5nefHgbwSO/kPq5ac66o/rCh2RTWLIgex5NcbRgavvb0b3tnDdl6M/k96ETx64MIPsNvbLAvwdkXBE2tJAcoGIPGy7UlxFLjErpXUG7+Lvdq9kJ2IjfmVcXOYkr9BeFzm7Y3vuS7YL3PeL8dchRwK+dwYlFgHoFEjnknvcRF/yVF+NBzxj5mN/4qxdRMRzukukLM9HY5POeSz1JRI0aMKkW2wRgRbV51pA3BdO1WMSNamETh5527zi8eDUblXkLTOYHyJi4v5/AMheARUyGhSK5D+t3JaPw3zHfRCcZerq4hTxcV2dRtjlJELbd+2gvjmm+2WROvXMPjUuKQ6NjySMfCa+sZ9bQfkVYU6oGV2Bgd1rX3JvOAQrmTolaAy6XMhF8UQawzI3EYnhWw3IHHcABdB+xUKxtLdqLsJ5FFbn/l/I4V5p3nKCTWBmUZVSMg4BX8ivfof4gpJjHaguOEhESmrK4u9gVHQbM3USqbhtIifD5TaQJMcF9731nQ3PtGXcMY/8Y1vzaIWMNWjuvnpSnsoGBK7Z0yueL6oySTt7Kfb+cHeC2zMZPr1bXyCztUC5Eo1/YgrN++jIXKZ6iisAw6DJDN7g8mBAjnZTP5KlzK4wOoFshhn54iVpzy/8Ggct/3POBSQq91tCIE0RyeOH1pV1HzyDKR20ghny+tt4qMX4A3nem4G38y4jM6rm/m1BCTDdvOttzqSCAVYwggFSoAMCAReiggFJBIIBRfNJgiVTPONiFxESUEcQaJBdPsfQ9iRA1HF4h30VO9fqwg29VKtaplKXF59ZVo/T3dXRQUTRtztSbDqnovCaDtiM86NUvOqOsC/OWYdCCL1GWsW/OAFBQyb3KtIvn6zRL2DFBiaii/BjBKc7BdsXOKlRgnDvNAUVGAKiZ3pHU5g0HciMxYrefwHAfAPfs2tgMOfcltDo4EnS5os12jkT4yGg/2dU3ZwnniGPblOBBa5GVFPZbclzG2s7O49Ob4aPcAU03Jd9UX1XKtlFCE7WSCeCIxZPn/KT9D3sd4bNhA0CYHNuteHUseiAzg+608w/H3/9YMv0oJkqOePvKRHIiykZqq/T3bQ0YO39YJhNb2ZIjxxokTzHTTh/46TzE8EB31Czh0IegDJZpnHyLBkAovoi2BFoSruj66jHVO78zism4/zjFYU=

2015-04-15 14:26:24.668000 UTC - 0[b0f140]: Entering NET_ProcessPop3 204
2015-04-15 14:26:24.668000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.668000 UTC - 0[b0f140]: RECV: + YIGTBgkqhkiG9xIBAgICAG+BgzCBgKADAgEFoQMCAQ+idDByoAMCAReiawRpXQJMSDLYFkifLkeK39lS5MbQtWB2FZqH6bnBfGCC6DoVppxJ+NkB96b5xJO2wG+ihb8XYEwkF2/HIcoptKhVnQjH9dobQH2oPRN4Rap3/GPh6FTjk9Yth23/Xpp5y6KdtQdkl2POD9px
2015-04-15 14:26:24.668000 UTC - 0[b0f140]: POP3: Entering state: 44
2015-04-15 14:26:24.668000 UTC - 0[b0f140]: GSSAPI step 2
2015-04-15 14:26:24.668000 UTC - 0[b0f140]: SEND:

2015-04-15 14:26:24.715000 UTC - 0[b0f140]: Entering NET_ProcessPop3 48
2015-04-15 14:26:24.715000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.715000 UTC - 0[b0f140]: RECV: + BQQF/wAMAAAAAAAAIoZakQH////RrkQ7tlL0DbBtliA=
2015-04-15 14:26:24.715000 UTC - 0[b0f140]: POP3: Entering state: 44
2015-04-15 14:26:24.715000 UTC - 0[b0f140]: GSSAPI step 2
2015-04-15 14:26:24.777000 UTC - 0[b0f140]: SEND: BQQE/wAMAAwAAAAAJz1f/ChHpPDLUckS0fBFsAEAAABzdGF0aGFt

2015-04-15 14:26:24.808000 UTC - 0[b0f140]: Entering NET_ProcessPop3 16
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: RECV: +OK Logged in.
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: POP3: Entering state: 31
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: NextAuthStep()
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: login succeeded
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: POP3: Entering state: 7
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: SEND: STAT

2015-04-15 14:26:24.808000 UTC - 0[b0f140]: Entering NET_ProcessPop3 9
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: RECV: +OK 0 0
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: POP3: Entering state: 8
2015-04-15 14:26:24.808000 UTC - 0[b0f140]: BeginMailDelivery acquiring semaphore
2015-04-15 14:26:24.824000 UTC - 0[b0f140]: Calling ReleaseFolderLock from AbortMailDelivery
2015-04-15 14:26:24.824000 UTC - 0[b0f140]: ReleaseFolderLock haveSemaphore = TRUE
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: POP3: Entering state: 22
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: SEND: QUIT

2015-04-15 14:26:24.839000 UTC - 0[b0f140]: Entering NET_ProcessPop3 18
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: POP3: Entering state: 3
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: RECV: +OK Logging out.
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: POP3: Entering state: 40
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: POP3: Entering state: 23
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: POP3: Entering state: 25
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: Clearing server busy in POP3_FREE
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: Clearing running protocol in POP3_FREE
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: Clearing server busy in OnStopRequest
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: ~nsPop3Protocol()
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: Calling ReleaseFolderLock from ~nsPop3Sink
2015-04-15 14:26:24.839000 UTC - 0[b0f140]: ReleaseFolderLock haveSemaphore = FALSE


Expected results:

But the client receives mail only at startup, But it should be checked every 5 minutes
Sorry for my bad English!
Thank you!

Updated

4 years ago
Group: core-security

Updated

4 years ago
Component: Preferences → Networking: POP
Product: Thunderbird → MailNews Core

Comment 1

3 years ago
Do you still see the problem?

(This shouldn't be related to autoconfig)
Flags: needinfo?(actapenko)
(Reporter)

Comment 2

3 years ago
nothing changed
I check on Thunderbird 38.1.0
Flags: needinfo?(actapenko)

Comment 3

3 years ago
(In reply to Максим from comment #2)
> nothing changed
> I check on Thunderbird 38.1.0

did you check your firewall?
Flags: needinfo?(actapenko)
Whiteboard: [closeme 2015-09-01]
(Reporter)

Comment 4

3 years ago
Firewall disabled
Flags: needinfo?(actapenko)

Updated

3 years ago
Summary: POP3 with autoconfig do not automatically fetches mail → 31.x pop account gets mail on startup, and then stops getting new mail
Whiteboard: [closeme 2015-09-01]

Comment 5

3 years ago
I was running 40.0.2 on windows 8.1 64bit and had similar issue, no mail or newsgroup messages after sleep.
If all add-on extensions are disabled it works.  But any one add-on like 'mark all read' or 'minimize on start and close' enabled makes it fail to auto update.   Any appearance add-ons has no effect.

Reverted to 38.1.0 and all works fine.

Comment 6

3 years ago
I apologize for the error,  I loaded 38.2.0 and that seems to be a working version.

Comment 7

3 years ago
Totally disregard comment 5 and 6.   The testing seems to have a flaw in it and is incorrect.
(Reporter)

Comment 8

3 years ago
Maybe I should give you my autoconfig?

Comment 9

3 years ago
I'm happy now.   Reverted to 31.8.0 and not only is it working, the "All Address Books" modification they put in the compose window is gone.   I'm staying here till I read they fix the program.

Comment 10

3 years ago
> Reverted to 31.8.0 and not only is it working
In that case you are in the wrong bug, because, per the title, this bug describes a problem that exists in version 31. (unless Максим stated the wrong version when filing the bug)

Your sleep issue is being worked on in bug 1196662.  You might cc: there to learn when it gets fixed, but no additional comments are needed as the issue is well understood

Comment 11

3 years ago
Максим, does this reproduce for you in more current versions?
Flags: needinfo?(actapenko)
Keywords: regression, regressionwindow-wanted
Whiteboard: [regression:TB38?]
(Reporter)

Comment 12

3 years ago
(In reply to Wayne Mery (:wsmwk, use Needinfo for questions) from comment #11)
> Максим, does this reproduce for you in more current versions?

Tested on version 38.6.0 has not changed
Flags: needinfo?(actapenko)

Comment 13

2 years ago
(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #10)
> (In reply to Al Knepper from comment #5)
> > Reverted to 31.8.0 and not only is it working
> In that case you are in the wrong bug, because, per the title, this bug
> describes a problem that exists in version 31. (unless Максим stated the
> wrong version when filing the bug)

Also, hotmail (and some other ISP) often has issues that are not caused by Thunderbird. You might try version 45.

 
> Your sleep issue is being worked on in bug 1196662. 

This was fixed in 38.7.2
(Reporter)

Comment 14

2 years ago
> Also, hotmail (and some other ISP) often has issues that are not caused by
> Thunderbird. You might try version 45.

With version 45 is the same. It seems the problem only when the authentication via Kerberos. If I use authentication Plain text everything works as expected. Maybe there are ideas how to fix Kerberos?

Updated

a year ago
Summary: 31.x pop account gets mail on startup, and then stops getting new mail → 31.x pop account gets mail on startup, and then stops getting new mail. Fails with authentication via Kerberos, plain text auth works
You need to log in before you can comment on or make changes to this bug.