From 8f99c6d58ce9f535344dcfed9a66bb54e9e00c17 Mon Sep 17 00:00:00 2001 From: Gene Smith Date: Sun, 11 Sep 2022 23:07:04 +0000 Subject: [PATCH] Bug 1776823 - Fix for autosync sometimes stops or doesn't occur at all. r=BenC - Fix parsing for imap UNSEEN in SELECT command -- it's not number of unseen. - Make sure only UNSEEN from imap STATUS is used -- it is number of unseen - Make sure imap STATUS has occurred before using the stored UNSEEN value. - Store imap untagged EXISTS and MESSAGES from imap STATUS to same variable. - Store imap untagged RECENT and RECENT from imap STATUS to same variable. - Avoid autosync lockup if folder update finds no new headers to fetch. - Force folder update if .msf is empty or missing on initial access. - Add more MOZ_LOG for better debugging. Differential Revision: https://phabricator.services.mozilla.com/D156392 --HG-- extra : moz-landing-system : lando --- mailnews/imap/public/nsIAutoSyncState.idl | 36 +++- mailnews/imap/src/nsAutoSyncManager.cpp | 142 +++++++++++--- mailnews/imap/src/nsAutoSyncManager.h | 7 +- mailnews/imap/src/nsAutoSyncState.cpp | 180 ++++++++++++++---- mailnews/imap/src/nsAutoSyncState.h | 1 + mailnews/imap/src/nsImapMailFolder.cpp | 42 +++- .../imap/src/nsImapServerResponseParser.cpp | 33 ++-- .../imap/src/nsImapServerResponseParser.h | 4 +- 8 files changed, 332 insertions(+), 113 deletions(-) diff --git a/mailnews/imap/public/nsIAutoSyncState.idl b/mailnews/imap/public/nsIAutoSyncState.idl index f3356caa5a..68a566a3fb 100644 --- a/mailnews/imap/public/nsIAutoSyncState.idl +++ b/mailnews/imap/public/nsIAutoSyncState.idl @@ -18,27 +18,38 @@ interface nsIAutoSyncState : nsISupports { * happen. */ - /** sync'd and no pending messages */ + /** Initial state. Returned to after new messages downloaded */ const long stCompletedIdle = 0; - /** STATUS issued. Will check to see if any counts changed since last STATUS */ + /** + * STATUS issued (URL "folderstatus"). Will check to see if new messages + * are present. + */ const long stStatusIssued = 1; /** - * Status found new messages. Update should be issued next. Status most - * likely was issued by non-autosync code (e.g., check other folders for - * new messages). + * Occurs when imap APPEND, COPY or MOVE imap command and adds messages that + * may not be detected in autosync stStatusIssued state. These are the + * "pending" messages referred to in the autosync code. + * Update (URL "select") will be issued next. */ const long stUpdateNeeded = 2; - /** Update issued. Will figure out if there are any bodies to download */ + /** + * Update issued (URL "select"). Will figure out if there are any bodies to + * download after new headers are fetched. + */ const long stUpdateIssued = 3; - /** Message body download in progress */ - const long stDownloadInProgress = 4; - /** ready to download the next group of messages */ - const long stReadyToDownload = 5; + const long stReadyToDownload = 4; + + /** + * Fetch body issued (URL "fetch"). Group of message bodies download in + * progress. If more are needed, next state is stReadyToDownload; otherwise, + * next state is stCompleteIdle. + */ + const long stDownloadInProgress = 5; /** * Puts the download queue offset to its previous position. @@ -97,6 +108,11 @@ interface nsIAutoSyncState : nsISupports { */ unsigned long processExistingHeaders(in unsigned long aNumberOfHeadersToProcess); + /** + * Tests whether the download queue is empty. + */ + boolean isDownloadQEmpty(); + /** * Last time the existing headers are completely processed. */ diff --git a/mailnews/imap/src/nsAutoSyncManager.cpp b/mailnews/imap/src/nsAutoSyncManager.cpp index d7327b962d..dee9d0cefe 100644 --- a/mailnews/imap/src/nsAutoSyncManager.cpp +++ b/mailnews/imap/src/nsAutoSyncManager.cpp @@ -257,7 +257,7 @@ void nsAutoSyncManager::TimerCallback(nsITimer* aTimer, void* aClosure) { autoSyncMgr->StopTimer(); } - // process folders within the discovery queue + // process a folder in the discovery queue if (autoSyncMgr->mDiscoveryQ.Count() > 0) { nsCOMPtr autoSyncStateObj(autoSyncMgr->mDiscoveryQ[0]); if (autoSyncStateObj) { @@ -279,6 +279,14 @@ void nsAutoSyncManager::TimerCallback(nsITimer* aTimer, void* aClosure) { autoSyncMgr, OnFolderRemovedFromQ, (nsIAutoSyncMgrListener::DiscoveryQueue, folder)); } + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: processed discovery q for folder=%s, " + "msgs left to process in folder=%d", + __func__, folderName.get(), leftToProcess)); + } } } @@ -303,6 +311,13 @@ void nsAutoSyncManager::TimerCallback(nsITimer* aTimer, void* aClosure) { (folder)); } } + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: process update q for folder=%s", __func__, + folderName.get())); + } } } } @@ -318,8 +333,14 @@ void nsAutoSyncManager::TimerCallback(nsITimer* aTimer, void* aClosure) { if (folder) NOTIFY_LISTENERS_STATIC(autoSyncMgr, OnFolderRemovedFromQ, (nsIAutoSyncMgrListener::UpdateQueue, folder)); + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Error)) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Error, + ("%s: update q init failed for folder=%s", __func__, + folderName.get())); + } } - } // endif } @@ -527,11 +548,13 @@ NS_IMETHODIMP nsAutoSyncManager::Observe(nsISupports*, const char* aTopic, SetIdleState(appIdle); if (prevIdleState != notIdle) return NS_OK; + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("%s: in app idle", __func__)); return StartIdleProcessing(); } // we're back from appIdle - if already notIdle, just return; if (GetIdleState() == notIdle) return NS_OK; + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("%s: out of app idle", __func__)); SetIdleState(notIdle); NOTIFY_LISTENERS(OnStateChanged, (false)); @@ -549,6 +572,7 @@ NS_IMETHODIMP nsAutoSyncManager::Observe(nsISupports*, const char* aTopic, if (GetIdleState() != appIdle) { SetIdleState(notIdle); NOTIFY_LISTENERS(OnStateChanged, (false)); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("%s: out of idle", __func__)); } return NS_OK; } else // we've gone system idle @@ -564,6 +588,7 @@ NS_IMETHODIMP nsAutoSyncManager::Observe(nsISupports*, const char* aTopic, // in appIdle state. if (GetIdleState() != appIdle) SetIdleState(systemIdle); if (WeAreOffline()) return NS_OK; + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("%s: in sys idle", __func__)); return StartIdleProcessing(); } return NS_OK; @@ -572,6 +597,7 @@ NS_IMETHODIMP nsAutoSyncManager::Observe(nsISupports*, const char* aTopic, nsresult nsAutoSyncManager::StartIdleProcessing() { if (mPaused) return NS_OK; + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("enter %s", __func__)); StartTimerIfNeeded(); // Ignore idle events sent during the startup @@ -630,6 +656,14 @@ nsresult nsAutoSyncManager::StartIdleProcessing() { autoSyncStateObj->GetOwnerFolder(getter_AddRefs(folder)); if (folder) NOTIFY_LISTENERS(OnDownloadCompleted, (folder)); + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder=%s has no pending msgs, " + "remove from priority q", + __func__, folderName.get())); + } autoSyncStateObj->SetState(nsAutoSyncState::stCompletedIdle); if (mPriorityQ.RemoveObject(autoSyncStateObj)) @@ -648,6 +682,7 @@ nsresult nsAutoSyncManager::AutoUpdateFolders() { nsresult rv; // iterate through each imap account and update offline folders automatically + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, ("enter %s", __func__)); nsCOMPtr accountManager = do_GetService(NS_MSGACCOUNTMANAGER_CONTRACTID, &rv); @@ -669,10 +704,23 @@ nsresult nsAutoSyncManager::AutoUpdateFolders() { if (!type.EqualsLiteral("imap")) continue; - // if we haven't logged onto this server yet, then skip this server. + // If we haven't logged onto this server yet during this session, then skip + // this server. This is needed to avoid MOZ_LOG error + // "IMAP: password prompt failed or user canceled it" since there is no + // window available for a potential password prompt during the unattended + // biff-like autosync activities. bool passwordRequired; incomingServer->GetServerRequiresPasswordForBiff(&passwordRequired); - if (passwordRequired) continue; + if (passwordRequired) { + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString serverName; + incomingServer->GetHostName(serverName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: server |%s| can't autosync; not yet logged in", __func__, + serverName.get())); + } + continue; + } nsCOMPtr rootFolder; @@ -683,6 +731,27 @@ nsresult nsAutoSyncManager::AutoUpdateFolders() { nsTArray> allDescendants; rv = rootFolder->GetDescendants(allDescendants); + // Get the update time in minutes for each folder of this account/server. + // It will be the user configured biff time for server even if user has + // disabled "Check for new messages every X minutes" for the account. + // Update time will default to 10 minutes if an invalid value is set or + // if there are errors obtaining it. + // Specifically, the value used here is mail.server.serverX.check_time + // or the default mail.server.default.check_time. + int32_t updateMinutes = -1; + rv = incomingServer->GetBiffMinutes(&updateMinutes); + if (NS_FAILED(rv) || updateMinutes < 1) + updateMinutes = kDefaultUpdateInterval; + PRTime span = updateMinutes * (PR_USEC_PER_SEC * 60UL); + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString serverName; + incomingServer->GetHostName(serverName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: Update time set to |%d| minutes for " + "folders in account |%s|", + __func__, updateMinutes, serverName.get())); + } + for (auto folder : allDescendants) { uint32_t folderFlags; rv = folder->GetFlags(&folderFlags); @@ -717,25 +786,57 @@ nsresult nsAutoSyncManager::AutoUpdateFolders() { int32_t state; rv = autoSyncState->GetState(&state); + nsCString folderName; + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + folder->GetURI(folderName); + MOZ_LOG( + gAutoSyncLog, LogLevel::Debug, + ("%s: folder=%s, state=%d", __func__, folderName.get(), state)); + } if (NS_SUCCEEDED(rv) && nsAutoSyncState::stCompletedIdle == state) { - // ensure that we wait for at least nsMsgIncomingServer::BiffMinutes - // between each update of the same folder + // ensure that we wait for at least the "span" time set above between + // each update of the same folder PRTime lastUpdateTime; rv = autoSyncState->GetLastUpdateTime(&lastUpdateTime); - PRTime span = - GetUpdateIntervalFor(autoSyncState) * (PR_USEC_PER_SEC * 60UL); if (NS_SUCCEEDED(rv) && ((lastUpdateTime + span) < PR_Now())) { if (mUpdateQ.IndexOf(autoSyncState) == -1) { mUpdateQ.AppendObject(autoSyncState); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder=%s added to update q", __func__, + folderName.get())); if (folder) NOTIFY_LISTENERS(OnFolderAddedIntoQ, (nsIAutoSyncMgrListener::UpdateQueue, folder)); } } + } else { + // Handle the case where imap STATUS triggered an update but nothing + // found to download when folder SELECTed after waiting the "span" + // time set above. + if (state == nsAutoSyncState::stUpdateIssued) { + PRTime lastUpdateTime; + rv = autoSyncState->GetLastUpdateTime(&lastUpdateTime); + if (NS_SUCCEEDED(rv) && ((lastUpdateTime + span) < PR_Now())) { + bool downloadQEmpty = false; + autoSyncState->IsDownloadQEmpty(&downloadQEmpty); + if (downloadQEmpty) { + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: nothing to download for folder %s, " + "set state to stCompletedIdle", + __func__, folderName.get())); + autoSyncState->SetState(nsAutoSyncState::stCompletedIdle); + OnStopRunningUrl(nullptr, NS_OK); + } else { + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: downloadQ not empty. Why?", __func__)); + } + } + } } - // check last sync time + // Check if time to add folder to discovery q on kAutoSyncFreq (1 hour) + // time base. PRTime lastSyncTime; rv = autoSyncState->GetLastSyncTime(&lastSyncTime); if (NS_SUCCEEDED(rv) && ((lastSyncTime + kAutoSyncFreq) < PR_Now())) { @@ -743,6 +844,9 @@ nsresult nsAutoSyncManager::AutoUpdateFolders() { // and discover messages not downloaded yet if (mDiscoveryQ.IndexOf(autoSyncState) == -1) { mDiscoveryQ.AppendObject(autoSyncState); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder=%s added to discovery q", __func__, + folderName.get())); if (folder) NOTIFY_LISTENERS( OnFolderAddedIntoQ, @@ -928,26 +1032,6 @@ nsresult nsAutoSyncManager::HandleDownloadErrorFor( return NS_OK; } -uint32_t nsAutoSyncManager::GetUpdateIntervalFor( - nsIAutoSyncState* aAutoSyncStateObj) { - nsCOMPtr folder; - nsresult rv = aAutoSyncStateObj->GetOwnerFolder(getter_AddRefs(folder)); - if (NS_FAILED(rv)) return kDefaultUpdateInterval; - - nsCOMPtr server; - rv = folder->GetServer(getter_AddRefs(server)); - if (NS_FAILED(rv)) return kDefaultUpdateInterval; - - if (server) { - int32_t interval; - rv = server->GetBiffMinutes(&interval); - - if (NS_SUCCEEDED(rv)) return (uint32_t)interval; - } - - return kDefaultUpdateInterval; -} - NS_IMETHODIMP nsAutoSyncManager::GetGroupSize(uint32_t* aGroupSize) { NS_ENSURE_ARG_POINTER(aGroupSize); *aGroupSize = mGroupSize; diff --git a/mailnews/imap/src/nsAutoSyncManager.h b/mailnews/imap/src/nsAutoSyncManager.h index 946bf4d8e0..e4d61918c2 100644 --- a/mailnews/imap/src/nsAutoSyncManager.h +++ b/mailnews/imap/src/nsAutoSyncManager.h @@ -77,6 +77,8 @@ * for any messages it previously determined it should download). Then it sets * a timer, and in the timer callback, it processes the update q, by calling * InitiateAutoSync on the first folder in the update q. + * + * See additional info near the bottom of this file. */ // clang-format on @@ -175,9 +177,6 @@ class nsAutoSyncManager final : public nsIObserver, void StopTimer(); void StartTimerIfNeeded(); - /// pref helpers - uint32_t GetUpdateIntervalFor(nsIAutoSyncState* aAutoSyncStateObj); - protected: nsCOMPtr mMsgStrategyImpl; nsCOMPtr mFolderStrategyImpl; @@ -246,6 +245,8 @@ different imap servers are simultaneous. ii) Parallel: All folders at the same time, using all cached-connections - a.k.a 'Folders gone wild' mode. +Note: The "Chained" mode is currently in use: mDownloadModel = dmChained; + The order the folders are added into the mPriorityQ doesn't matter since every time a batch completed for an imap server, nsAutoSyncManager adjusts the order. So, lets say that updating a sub-folder starts downloading message immediately, diff --git a/mailnews/imap/src/nsAutoSyncState.cpp b/mailnews/imap/src/nsAutoSyncState.cpp index 712c28f042..257237306b 100644 --- a/mailnews/imap/src/nsAutoSyncState.cpp +++ b/mailnews/imap/src/nsAutoSyncState.cpp @@ -84,6 +84,7 @@ nsAutoSyncState::nsAutoSyncState(nsImapMailFolder* aOwnerFolder, mRetryCounter(0U) { mOwnerFolder = do_GetWeakReference(static_cast(aOwnerFolder)); + mHaveAStatusResponse = false; } nsAutoSyncState::~nsAutoSyncState() {} @@ -294,7 +295,10 @@ NS_IMETHODIMP nsAutoSyncState::GetNextGroupOfMessages( } /** - * Usually called by nsAutoSyncManager when the last sync time is expired. + * Called by nsAutoSyncManager::TimerCallback to process message headers for a + * folder in the discovery queue. The queue is created on the kAutoSyncFreq + * time base (1 hour). Headers lacking offline store are placed in download + * queue. */ NS_IMETHODIMP nsAutoSyncState::ProcessExistingHeaders( uint32_t aNumOfHdrsToProcess, uint32_t* aLeftToProcess) { @@ -334,9 +338,10 @@ NS_IMETHODIMP nsAutoSyncState::ProcessExistingHeaders( if (!msgKeys.IsEmpty()) { nsCString folderName; folder->GetURI(folderName); - MOZ_LOG(gAutoSyncLog, LogLevel::Debug, - ("%zu messages will be added into the download q of folder %s\n", - msgKeys.Length(), folderName.get())); + MOZ_LOG( + gAutoSyncLog, LogLevel::Debug, + ("%s: %zu messages will be added into the download q of folder %s\n", + __func__, msgKeys.Length(), folderName.get())); rv = PlaceIntoDownloadQ(msgKeys); if (NS_FAILED(rv)) mProcessPointer = lastIdx; @@ -350,8 +355,27 @@ NS_IMETHODIMP nsAutoSyncState::ProcessExistingHeaders( mExistingHeadersQ.Clear(); mProcessPointer = 0; folder->SetMsgDatabase(nullptr); - } + // Handle the case where imap STATUS triggered an update but nothing found + // to download when folder SELECTed. + if ((mSyncState != stCompletedIdle) && mDownloadQ.IsEmpty()) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: nothing to download for folder %s, " + "set state to stCompletedIdle", + __func__, folderName.get())); + SetState(stCompletedIdle); + // Set autosync manager back to completed state. + nsCOMPtr autoSyncMgr = + do_GetService(NS_AUTOSYNCMANAGER_CONTRACTID, &rv); + NS_ENSURE_SUCCESS(rv, rv); + nsCOMPtr autoSyncMgrListener = + do_QueryInterface(autoSyncMgr, &rv); + NS_ENSURE_SUCCESS(rv, rv); + autoSyncMgrListener->OnStopRunningUrl(nullptr, NS_OK); + } + } return rv; } @@ -414,37 +438,96 @@ NS_IMETHODIMP nsAutoSyncState::OnStopRunningUrl(nsIURI* aUrl, imapFolder->GetServerUnseen(&serverUnseen); imapFolder->GetServerRecent(&serverRecent); imapFolder->GetServerNextUID(&serverNextUID); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: serverUnseen=%d lastServerUnseen=%d", __func__, serverUnseen, + mLastServerUnseen)); if (serverNextUID != mLastNextUID || serverTotal != mLastServerTotal || - serverUnseen != mLastServerUnseen || - serverRecent != mLastServerRecent) { + serverRecent != mLastServerRecent || + ((serverUnseen != mLastServerUnseen) && mLastServerUnseen > -1)) { + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + ownerFolder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder %s status changed serverNextUID=%d lastNextUID=%d", + __func__, folderName.get(), serverNextUID, mLastNextUID)); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: serverTotal = %d lastServerTotal = %d serverRecent = %d " + "lastServerRecent = %d\n", + __func__, serverTotal, mLastServerTotal, serverRecent, + mLastServerRecent)); + } + SetServerCounts(serverTotal, serverRecent, serverUnseen, serverNextUID); + SetState(nsAutoSyncState::stUpdateIssued); + rv = imapFolder->UpdateFolderWithListener(nullptr, autoSyncMgrListener); + } else // folderstatus detected no change + { + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + ownerFolder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder %s status or noop issued, no change", __func__, + folderName.get())); + } + // Status detected no change. This may be due to an previously deleted and + // now empty database so changes above are compared to folder cache. If + // so, force an update which will re-populate the database (.msf) and + // download all the message to mbox/maildir store. This check is only + // needed after the first imap STATUS response after start-up. Note: A + // restart is required when .msf (the folder database) and mbox/maildir + // storage are manually deleted in filesystem by the user. + if (!mHaveAStatusResponse) { + nsCOMPtr database; + ownerFolder->GetMsgDatabase(getter_AddRefs(database)); + bool hasHeader = false; + if (database) { + nsCOMPtr hdrs; + database->EnumerateMessages(getter_AddRefs(hdrs)); + if (hdrs) hdrs->HasMoreElements(&hasHeader); + } + if (!hasHeader) { + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + ownerFolder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: folder %s has empty DB, force an update", __func__, + folderName.get())); + } + SetServerCounts(serverTotal, serverRecent, serverUnseen, + serverNextUID); + SetState(nsAutoSyncState::stUpdateIssued); + rv = imapFolder->UpdateFolderWithListener(nullptr, + autoSyncMgrListener); + } + } + if (mSyncState == stStatusIssued) { + // Didn't force an update above so transition back to stCompletedIdle + ownerFolder->SetMsgDatabase(nullptr); + // nothing more to do. + SetState(nsAutoSyncState::stCompletedIdle); + // autoSyncMgr needs this notification, so manufacture it. + rv = autoSyncMgrListener->OnStopRunningUrl(nullptr, NS_OK); + } + } // end no change detected + mHaveAStatusResponse = true; + } else // URL not folderstatus but FETCH of message body + { + // XXXemre how we recover from this error? + rv = ownerFolder->ReleaseSemaphore(ownerFolder); + NS_ASSERTION(NS_SUCCEEDED(rv), "*** Cannot release folder semaphore"); + + nsCOMPtr mailUrl = do_QueryInterface(aUrl); + if (mailUrl) rv = mailUrl->UnRegisterListener(this); + + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { nsCString folderName; ownerFolder->GetURI(folderName); MOZ_LOG(gAutoSyncLog, LogLevel::Debug, - ("folder %s status changed serverNextUID = %x lastNextUID = %x\n", - folderName.get(), serverNextUID, mLastNextUID)); - MOZ_LOG(gAutoSyncLog, LogLevel::Debug, - ("serverTotal = %x lastServerTotal = %x serverRecent = %x " - "lastServerRecent = %x\n", - serverTotal, mLastServerTotal, serverRecent, mLastServerRecent)); - SetServerCounts(serverTotal, serverRecent, serverUnseen, serverNextUID); - SetState(nsAutoSyncState::stUpdateIssued); - return imapFolder->UpdateFolderWithListener(nullptr, autoSyncMgrListener); + ("%s: URL for FETCH of msg body/bodies complete, folder %s", + __func__, folderName.get())); } - - ownerFolder->SetMsgDatabase(nullptr); - // nothing more to do. - SetState(nsAutoSyncState::stCompletedIdle); - // autoSyncMgr needs this notification, so manufacture it. - return autoSyncMgrListener->OnStopRunningUrl(nullptr, NS_OK); + rv = autoSyncMgr->OnDownloadCompleted(this, aExitCode); } - // XXXemre how we recover from this error? - rv = ownerFolder->ReleaseSemaphore(ownerFolder); - NS_ASSERTION(NS_SUCCEEDED(rv), "*** Cannot release folder semaphore"); - - nsCOMPtr mailUrl = do_QueryInterface(aUrl); - if (mailUrl) rv = mailUrl->UnRegisterListener(this); - - return autoSyncMgr->OnDownloadCompleted(this, aExitCode); + return rv; } NS_IMETHODIMP nsAutoSyncState::GetState(int32_t* aState) { @@ -453,9 +536,16 @@ NS_IMETHODIMP nsAutoSyncState::GetState(int32_t* aState) { return NS_OK; } -const char* stateStrings[] = {"idle", "status issued", - "update needed", "update issued", - "downloading", "ready to download"}; +// clang-format off +const char* stateStrings[] = { + "stCompletedIdle:0", // Initial state + "stStatusIssued:1", // Imap STATUS or NOOP to occur to detect new msgs + "stUpdateNeeded:2", // Imap SELECT to occur due to "pending" msgs + "stUpdateIssued:3", // Imap SELECT to occur then fetch new headers + "stReadyToDownload:4", // Ready to download a group of new messages + "stDownloadInProgress:5" // Download, go to 4 if more msgs then 0 when all done +}; +// clang-format on NS_IMETHODIMP nsAutoSyncState::SetState(int32_t aState) { mSyncState = aState; @@ -477,9 +567,9 @@ NS_IMETHODIMP nsAutoSyncState::SetState(int32_t aState) { ownerFolder->SetMsgDatabase(nullptr); } } - nsCString logStr("Sync State set to "); + nsCString logStr("Sync State set to |"); logStr.Append(stateStrings[aState]); - logStr.AppendLiteral(" for "); + logStr.AppendLiteral("| for "); LogOwnerFolderName(logStr.get()); return NS_OK; } @@ -571,6 +661,15 @@ NS_IMETHODIMP nsAutoSyncState::IsSibling(nsIAutoSyncState* aAnotherStateObj, return rv; } +/** + * Test whether the download queue is empty. + */ +NS_IMETHODIMP nsAutoSyncState::IsDownloadQEmpty(bool* aResult) { + NS_ENSURE_ARG_POINTER(aResult); + *aResult = mDownloadQ.IsEmpty(); + return NS_OK; +} + NS_IMETHODIMP nsAutoSyncState::DownloadMessagesForOffline( nsTArray> const& messages) { nsresult rv; @@ -591,10 +690,13 @@ NS_IMETHODIMP nsAutoSyncState::DownloadMessagesForOffline( rv = folder->AcquireSemaphore(folder); NS_ENSURE_SUCCESS(rv, rv); - nsCString folderName; - folder->GetURI(folderName); - MOZ_LOG(gAutoSyncLog, LogLevel::Debug, - ("downloading %s for %s", messageIds.get(), folderName.get())); + if (MOZ_LOG_TEST(gAutoSyncLog, LogLevel::Debug)) { + nsCString folderName; + folder->GetURI(folderName); + MOZ_LOG(gAutoSyncLog, LogLevel::Debug, + ("%s: downloading UIDs %s for folder %s", __func__, + messageIds.get(), folderName.get())); + } // start downloading rv = imapService->DownloadMessagesForOffline(messageIds, folder, this, nullptr); diff --git a/mailnews/imap/src/nsAutoSyncState.h b/mailnews/imap/src/nsAutoSyncState.h index 712cffecab..d04ad016c2 100644 --- a/mailnews/imap/src/nsAutoSyncState.h +++ b/mailnews/imap/src/nsAutoSyncState.h @@ -100,6 +100,7 @@ class nsAutoSyncState final : public nsIAutoSyncState, public nsIUrlListener { nsTHashtable mDownloadSet; nsTArray mDownloadQ; nsTArray mExistingHeadersQ; + bool mHaveAStatusResponse; }; #endif diff --git a/mailnews/imap/src/nsImapMailFolder.cpp b/mailnews/imap/src/nsImapMailFolder.cpp index 072c307648..0fb7501100 100644 --- a/mailnews/imap/src/nsImapMailFolder.cpp +++ b/mailnews/imap/src/nsImapMailFolder.cpp @@ -227,7 +227,7 @@ nsImapMailFolder::nsImapMailFolder() m_boxFlags = 0; m_uidValidity = kUidUnknown; m_numServerRecentMessages = 0; - m_numServerUnseenMessages = 0; + m_numServerUnseenMessages = -1; // -1 indicates not yet set to a valid value m_numServerTotalMessages = 0; m_nextUID = nsMsgKey_None; m_hierarchyDelimiter = kOnlineHierarchySeparatorUnknown; @@ -1877,7 +1877,11 @@ NS_IMETHODIMP nsImapMailFolder::ReadFromFolderCacheElem( m_aclFlags = kAclInvalid; // init to invalid value. element->GetCachedUInt32("aclFlags", &m_aclFlags); element->GetCachedInt32("serverTotal", &m_numServerTotalMessages); - element->GetCachedInt32("serverUnseen", &m_numServerUnseenMessages); + // Init m_numServerUnseenMessages to cached "totalUnreadMsgs" since + // cached "serverUnseen" may be incorrect due to imap NOOP occurring instead + // of STATUS when url folderstatus occurs during autosync. NOOP doesn't always + // report UNSEEN changes. + element->GetCachedInt32("totalUnreadMsgs", &m_numServerUnseenMessages); element->GetCachedInt32("serverRecent", &m_numServerRecentMessages); element->GetCachedInt32("nextUID", &m_nextUID); int32_t lastSyncTimeInSec; @@ -1900,7 +1904,12 @@ NS_IMETHODIMP nsImapMailFolder::WriteToFolderCacheElem( element->SetCachedString("onlineName", m_onlineFolderName); element->SetCachedUInt32("aclFlags", m_aclFlags); element->SetCachedInt32("serverTotal", m_numServerTotalMessages); - element->SetCachedInt32("serverUnseen", m_numServerUnseenMessages); + // Don't save "serverUnseen" to cache unless we have a valid value indicated + // by m_numServerUnseenMessages > -1. + int32_t tmp; + element->GetCachedInt32("serverUnseen", &tmp); + if (m_numServerUnseenMessages > -1 || tmp < 0) + element->SetCachedInt32("serverUnseen", m_numServerUnseenMessages); element->SetCachedInt32("serverRecent", m_numServerRecentMessages); if (m_nextUID != (int32_t)nsMsgKey_None) element->SetCachedInt32("nextUID", m_nextUID); @@ -2480,7 +2489,9 @@ NS_IMETHODIMP nsImapMailFolder::UpdateImapMailboxInfo( ChangeNumPendingTotalMessages(-mNumPendingTotalMessages); ChangeNumPendingUnread(-mNumPendingUnreadMessages); m_numServerRecentMessages = 0; // clear this since we selected the folder. - m_numServerUnseenMessages = 0; // clear this since we selected the folder. + // m_numServerUnseenMessages = 0; // clear this since we selected the folder. + // Actually, setting to zero may cause wrong unseen count since select doesn't + // return number of unseen but the first unseen message sequence number. if (!mDatabase) GetDatabase(); @@ -2633,11 +2644,14 @@ NS_IMETHODIMP nsImapMailFolder::UpdateImapMailboxInfo( } int32_t numUnreadFromServer; aSpec->GetNumUnseenMessages(&numUnreadFromServer); + // Set to zero if unread from server is unknown (no imap STATUS yet) + if (numUnreadFromServer == -1) numUnreadFromServer = 0; bool partialUIDFetch; flagState->GetPartialUIDFetch(&partialUIDFetch); // For partial UID fetches, we can only trust the numUnread from the server. + // But can't really "trust" it until imap STATUS occurs if (partialUIDFetch) numNewUnread = numUnreadFromServer; // If we are performing biff for this folder, tell the @@ -2677,6 +2691,9 @@ NS_IMETHODIMP nsImapMailFolder::UpdateImapMailboxInfo( return rv; } +/* + * Called after successful imap STATUS response occurs. Have valid unseen value. + */ NS_IMETHODIMP nsImapMailFolder::UpdateImapMailboxStatus( nsIImapProtocol* aProtocol, nsIMailboxSpec* aSpec) { NS_ENSURE_ARG_POINTER(aSpec); @@ -2688,14 +2705,15 @@ NS_IMETHODIMP nsImapMailFolder::UpdateImapMailboxStatus( aSpec->GetNextUID(&m_nextUID); bool summaryChanged = false; - // If m_numServerUnseenMessages is 0, it means + // If m_numServerUnseenMessages is -1, it usually means // this is the first time we've done a Status. // In that case, we count all the previous pending unread messages we know // about as unread messages. We may want to do similar things with total // messages, but the total messages include deleted messages if the folder // hasn't been expunged. + // Don't set previouUnread to -1 (yet unknown unseen count). int32_t previousUnreadMessages = - (m_numServerUnseenMessages) + (m_numServerUnseenMessages > 0) ? m_numServerUnseenMessages : mNumPendingUnreadMessages + mNumUnreadMessages; if (numUnread != previousUnreadMessages || m_nextUID != prevNextUID) { @@ -5292,8 +5310,12 @@ void nsImapMailFolder::UpdatePendingCounts() { // count the moves that were unread int numUnread = m_copyState->m_unreadCount; if (numUnread) { - m_numServerUnseenMessages += - numUnread; // adjust last status count by this delta. + // At this point, if unseen is unknown (negative), set to numUnread; + // otherwise, increment it by numUnread + if (m_numServerUnseenMessages < 0) + m_numServerUnseenMessages = numUnread; + else + m_numServerUnseenMessages += numUnread; ChangeNumPendingUnread(numUnread); } SummaryChanged(); @@ -8732,7 +8754,7 @@ NS_IMETHODIMP nsImapMailFolder::InitiateAutoSync(nsIUrlListener* aUrlListener) { nsCString folderName; GetURI(folderName); MOZ_LOG(gAutoSyncLog, mozilla::LogLevel::Debug, - ("Updating folder: %s", folderName.get())); + ("%s: Updating folder: %s", __func__, folderName.get())); // HACK: if UpdateFolder finds out that it can't open // the folder, it doesn't set the url listener and returns @@ -8743,7 +8765,7 @@ NS_IMETHODIMP nsImapMailFolder::InitiateAutoSync(nsIUrlListener* aUrlListener) { if (!canOpenThisFolder) { MOZ_LOG(gAutoSyncLog, mozilla::LogLevel::Debug, - ("Cannot update folder: %s", folderName.get())); + ("%s: Cannot update folder: %s", __func__, folderName.get())); return NS_ERROR_FAILURE; } diff --git a/mailnews/imap/src/nsImapServerResponseParser.cpp b/mailnews/imap/src/nsImapServerResponseParser.cpp index 621897f024..861e4c6fb9 100644 --- a/mailnews/imap/src/nsImapServerResponseParser.cpp +++ b/mailnews/imap/src/nsImapServerResponseParser.cpp @@ -27,7 +27,7 @@ nsImapServerResponseParser::nsImapServerResponseParser( fCurrentFolderReadOnly(false), fCurrentLineContainedFlagInfo(false), fServerIsNetscape3xServer(false), - fNumberOfUnseenMessages(0), + fSeqNumOfFirstUnseenMsg(0), fNumberOfExistingMessages(0), fNumberOfRecentMessages(0), fSizeOfMostRecentMessage(0), @@ -52,10 +52,8 @@ nsImapServerResponseParser::nsImapServerResponseParser( fFolderUIDValidity = 0; fHighestModSeq = 0; fAuthChallenge = nullptr; - fStatusUnseenMessages = 0; - fStatusRecentMessages = 0; + fStatusUnseenMessages = -1; // -1 indicates UNSEEN response has yet to occur fStatusNextUID = nsMsgKey_None; - fStatusExistingMessages = 0; fReceivedHeaderOrSizeForUID = nsMsgKey_None; fCondStoreEnabled = false; // Seems to be unused! fUtf8AcceptEnabled = false; @@ -549,7 +547,7 @@ void nsImapServerResponseParser::response_data() { } else if (!PL_strcasecmp(fNextToken, "MESSAGES")) { AdvanceToNextToken(); if (fNextToken) { - fStatusExistingMessages = strtoul(fNextToken, nullptr, 10); + fNumberOfExistingMessages = strtoul(fNextToken, nullptr, 10); // if this token ends in ')', then it is the last token // else we advance if (*(fNextToken + strlen(fNextToken) - 1) == ')') @@ -567,7 +565,7 @@ void nsImapServerResponseParser::response_data() { } else if (!PL_strcasecmp(fNextToken, "RECENT")) { AdvanceToNextToken(); if (fNextToken) { - fStatusRecentMessages = strtoul(fNextToken, nullptr, 10); + fNumberOfRecentMessages = strtoul(fNextToken, nullptr, 10); // if this token ends in ')', then it is the last token // else we advance if (*(fNextToken + strlen(fNextToken) - 1) == ')') @@ -1724,7 +1722,11 @@ void nsImapServerResponseParser::resp_text_code() { } else if (!PL_strcasecmp(fNextToken, "UNSEEN")) { AdvanceToNextToken(); if (ContinueParse()) { - fNumberOfUnseenMessages = strtoul(fNextToken, nullptr, 10); + // Note: As a response code, "UNSEEN" is NOT the number of + // unseen/unread messages. It is the lowest sequence number of the first + // unseen/unread message in the mailbox. Go ahead and save the value for + // possible future use but currently not used. + fSeqNumOfFirstUnseenMsg = strtoul(fNextToken, nullptr, 10); AdvanceToNextToken(); } } else if (!PL_strcasecmp(fNextToken, "UIDNEXT")) { @@ -2871,10 +2873,6 @@ int32_t nsImapServerResponseParser::NumberOfRecentMessages() { return fNumberOfRecentMessages; } -int32_t nsImapServerResponseParser::NumberOfUnseenMessages() { - return fNumberOfUnseenMessages; -} - int32_t nsImapServerResponseParser::FolderUID() { return fFolderUIDValidity; } void nsImapServerResponseParser::SetCurrentResponseUID(uint32_t uid) { @@ -2920,16 +2918,13 @@ nsImapServerResponseParser::CreateCurrentMailboxSpec( returnSpec->mHierarchySeparator = (ns) ? ns->GetDelimiter() : '/'; } - returnSpec->mFolderSelected = - !mailboxName; // if mailboxName is null, we're doing a Status + // If mailboxName null, we're doing imap SELECT; otherwise doing STATUS + returnSpec->mFolderSelected = !mailboxName; returnSpec->mFolder_UIDVALIDITY = fFolderUIDValidity; returnSpec->mHighestModSeq = fHighestModSeq; - returnSpec->mNumOfMessages = - (mailboxName) ? fStatusExistingMessages : fNumberOfExistingMessages; - returnSpec->mNumOfUnseenMessages = - (mailboxName) ? fStatusUnseenMessages : fNumberOfUnseenMessages; - returnSpec->mNumOfRecentMessages = - (mailboxName) ? fStatusRecentMessages : fNumberOfRecentMessages; + returnSpec->mNumOfMessages = fNumberOfExistingMessages; + returnSpec->mNumOfUnseenMessages = fStatusUnseenMessages; // Will be >= -1 + returnSpec->mNumOfRecentMessages = fNumberOfRecentMessages; returnSpec->mNextUID = fStatusNextUID; returnSpec->mSupportedUserFlags = fSupportsUserDefinedFlags; diff --git a/mailnews/imap/src/nsImapServerResponseParser.h b/mailnews/imap/src/nsImapServerResponseParser.h index 9515ec3086..84f8813633 100644 --- a/mailnews/imap/src/nsImapServerResponseParser.h +++ b/mailnews/imap/src/nsImapServerResponseParser.h @@ -223,7 +223,7 @@ class nsImapServerResponseParser : public nsImapGenericParser { uint16_t fSettablePermanentFlags; int32_t fFolderUIDValidity; - int32_t fNumberOfUnseenMessages; + int32_t fSeqNumOfFirstUnseenMsg; // Not used int32_t fNumberOfExistingMessages; int32_t fNumberOfRecentMessages; uint32_t fCurrentResponseUID; @@ -234,9 +234,7 @@ class nsImapServerResponseParser : public nsImapGenericParser { int32_t fTotalDownloadSize; int32_t fStatusUnseenMessages; - int32_t fStatusRecentMessages; uint32_t fStatusNextUID; - uint32_t fStatusExistingMessages; int fNumberOfTaggedResponsesExpected;