From c39b8cc631c74abefcb8981d4925103013fb5dfd Mon Sep 17 00:00:00 2001 From: Chris Wilson Date: Thu, 17 Apr 2014 20:56:57 +0000 Subject: Rewrite backup idle/poll loop for clarity. Add helpful debugging messages about why the decision was taken to sleep or start a backup, and how long the system will wait until the next backup. Flatten the code to avoid the double loop. --- bin/bbackupd/BackupDaemon.cpp | 174 ++++++++++++++++++++++++------------------ 1 file changed, 99 insertions(+), 75 deletions(-) (limited to 'bin') diff --git a/bin/bbackupd/BackupDaemon.cpp b/bin/bbackupd/BackupDaemon.cpp index 7f883e21..6dc877b0 100644 --- a/bin/bbackupd/BackupDaemon.cpp +++ b/bin/bbackupd/BackupDaemon.cpp @@ -567,80 +567,105 @@ void BackupDaemon::Run2() bool doSync = false; bool mDoSyncForcedByCommand = false; + box_time_t currentTime = GetCurrentBoxTime(); + + // Check whether we should be stopping, and if so, + // don't hang around waiting on the command socket. + if(StopRun()) + { + BOX_INFO("Skipping command socket polling " + "due to shutdown request"); + break; + } + // Is a delay necessary? - box_time_t currentTime; + currentTime = GetCurrentBoxTime(); + box_time_t requiredDelay = (mNextSyncTime < currentTime) + ? (0) : (mNextSyncTime - currentTime); - do + if (mDoSyncForcedByPreviousSyncError) { - // Check whether we should be stopping, - // and don't run a sync if so. - if(StopRun()) break; - - currentTime = GetCurrentBoxTime(); - - // Pause a while, but no more than - // MAX_SLEEP_TIME seconds (use the conditional - // because times are unsigned) - box_time_t requiredDelay = - (mNextSyncTime < currentTime) - ? (0) - : (mNextSyncTime - currentTime); - - // If there isn't automatic backup happening, - // set a long delay. And limit delays at the - // same time. - if(!automaticBackup && !mDoSyncForcedByPreviousSyncError) - { - requiredDelay = SecondsToBoxTime(MAX_SLEEP_TIME); - } - else if(requiredDelay > SecondsToBoxTime(MAX_SLEEP_TIME)) - { - requiredDelay = SecondsToBoxTime(MAX_SLEEP_TIME); - } + BOX_INFO("Last backup was not successful, " + "next one starting at " << + FormatTime(mNextSyncTime, false)); + } + else if (automaticBackup) + { + BOX_INFO("Automatic backups are enabled, " + "next one starting at " << + FormatTime(mNextSyncTime, false)); + } + else + { + BOX_INFO("No automatic backups, waiting for " + "bbackupctl snapshot command"); + requiredDelay = SecondsToBoxTime(MAX_SLEEP_TIME); + } - // Only delay if necessary - if(requiredDelay > 0) - { - // Sleep somehow. There are choices - // on how this should be done, - // depending on the state of the - // control connection - if(mapCommandSocketInfo.get() != 0) - { - // A command socket exists, - // so sleep by waiting on it - WaitOnCommandSocket(requiredDelay, - doSync, mDoSyncForcedByCommand); - } - else - { - // No command socket or - // connection, just do a - // normal sleep - time_t sleepSeconds = - BoxTimeToSeconds(requiredDelay); - ::sleep((sleepSeconds <= 0) - ? 1 : sleepSeconds); - } - } - - if ((automaticBackup || mDoSyncForcedByPreviousSyncError) - && currentTime >= mNextSyncTime) - { - doSync = true; - } + if(requiredDelay > SecondsToBoxTime(MAX_SLEEP_TIME)) + { + requiredDelay = SecondsToBoxTime(MAX_SLEEP_TIME); } - while(!doSync && !StopRun()); - // Time of sync start, and if it's time for another sync - // (and we're doing automatic syncs), set the flag - mCurrentSyncStartTime = GetCurrentBoxTime(); - if((automaticBackup || mDoSyncForcedByPreviousSyncError) && - mCurrentSyncStartTime >= mNextSyncTime) + // Only delay if necessary + if(requiredDelay == 0) { - doSync = true; + // No sleep necessary, so don't listen on the command + // socket at all right now. } - + else if(mapCommandSocketInfo.get() != 0) + { + // A command socket exists, so sleep by waiting for a + // connection or command on it. + WaitOnCommandSocket(requiredDelay, doSync, + mDoSyncForcedByCommand); + } + else + { + // No command socket or connection, just do a normal + // sleep. + time_t sleepSeconds = + BoxTimeToSeconds(requiredDelay); + ::sleep((sleepSeconds <= 0) + ? 1 : sleepSeconds); + } + + if(StopRun()) + { + BOX_INFO("Stopping idle loop due to shutdown request"); + break; + } + else if(doSync) + { + BOX_INFO("Starting a backup immediately due to " + "bbackupctl sync command"); + } + else if(currentTime < mNextSyncTime) + { + BOX_TRACE("Sleeping again because next sync time " + "has not arrived"); + continue; + } + else if(mDoSyncForcedByPreviousSyncError) + { + BOX_INFO("Last backup was not successful, next one " + "starting now"); + } + else if(automaticBackup) + { + BOX_INFO("Automatic backups are enabled, next one " + "starting now"); + } + else + { + BOX_TRACE("Sleeping again because automatic backups " + "are not enabled"); + continue; + } + + // If we pass this point, or exit the loop, we should have + // logged something at INFO level or higher to explain why. + // Use a script to see if sync is allowed now? if(!mDoSyncForcedByCommand && doSync && !StopRun()) { @@ -650,21 +675,20 @@ void BackupDaemon::Run2() // Script has asked for a delay mNextSyncTime = GetCurrentBoxTime() + SecondsToBoxTime(d); - doSync = false; + BOX_INFO("Impending backup stopped by " + "SyncAllowScript, next attempt " + "scheduled for " << + FormatTime(mNextSyncTime, false)); + continue; } } - // Ready to sync? (but only if we're not supposed - // to be stopping) - if(doSync && !StopRun()) - { - RunSyncNowWithExceptionHandling(); - } + RunSyncNowWithExceptionHandling(); // Set state SetState(storageLimitExceeded?State_StorageLimitExceeded:State_Idle); - - } while(!StopRun()); + } + while(!StopRun()); // Make sure we have a clean start next time round (if restart) DeleteAllLocations(); -- cgit v1.2.3