Changeset 2302


Ignore:
Timestamp:
26/09/2008 23:18:35 (3 years ago)
Author:
chris
Message:

Add file logging support (LogFile and LogFileLevel config options).

Ensure that backup-finish is always called, and add a new event,
backup-ok, which is called just before backup-finish when the backup
run was successful.

Keep track of the last backup status notification sent (excluding
backup-start and backup-finish) and send a notification whenever it
changes.

Add a new boolean option, NotifyAlways?, to override that check and
always send notifications to the NotifyScript after every backup run,
for notify scripts which do their own state tracking or otherwise
require notification on every event.

Location:
box/trunk
Files:
5 edited

Legend:

Unmodified
Added
Removed

  • box/trunk/bin/bbackupd/BackupClientDirectoryRecord.cpp

    r2301 r2302  
    15311531                rContext.UnManageDiffProcess(); 
    15321532 
    1533                 if(e.GetType() == ConnectionException::ExceptionType && e.GetSubType() == ConnectionException::Protocol_UnexpectedReply) 
     1533                if(e.GetType() == ConnectionException::ExceptionType && 
     1534                        e.GetSubType() == ConnectionException::Protocol_UnexpectedReply) 
    15341535                { 
    15351536                        // Check and see what error the protocol has, 
    … …  
    15421543                                { 
    15431544                                        // The hard limit was exceeded on the server, notify! 
    1544                                         rParams.mrSysadminNotifier.NotifySysadmin(BackupDaemon::NotifyEvent_StoreFull); 
     1545                                        rParams.mrSysadminNotifier.NotifySysadmin( 
     1546                                                SysadminNotifier::StoreFull); 
    15451547                                        // return an error code instead of 
    15461548                                        // throwing an exception that we 

  • box/trunk/bin/bbackupd/BackupClientDirectoryRecord.h

    r2245 r2302  
    3737        public: 
    3838        virtual ~SysadminNotifier() { } 
    39         virtual void NotifySysadmin(int Event) = 0; 
     39 
     40        typedef enum 
     41        { 
     42                StoreFull = 0, 
     43                ReadError, 
     44                BackupError, 
     45                BackupStart, 
     46                BackupFinish, 
     47                BackupOK, 
     48                MAX 
     49                // When adding notifications, remember to add 
     50                // strings to NotifySysadmin() 
     51        } 
     52        EventCode; 
     53 
     54        virtual void NotifySysadmin(EventCode Event) = 0; 
    4055}; 
    4156 
    … …  
    195210         
    196211                bool StopRun() { return mrRunStatusProvider.StopRun(); } 
    197                 void NotifySysadmin(int Event)  
     212                void NotifySysadmin(SysadminNotifier::EventCode Event)  
    198213                {  
    199214                        mrSysadminNotifier.NotifySysadmin(Event);  

  • box/trunk/bin/bbackupd/BackupDaemon.cpp

    r2285 r2302  
    124124          mDeleteRedundantLocationsAfter(0), 
    125125          mpCommandSocketInfo(0), 
     126          mLastNotifiedEvent(SysadminNotifier::MAX), 
    126127          mDeleteUnusedRootDirEntriesAfter(0), 
    127128          mClientStoreMarker(BackupClientContext::ClientStoreMarker_NotKnown), 
    … …  
    149150        SSLLib::Initialise(); 
    150151         
    151         // Initialise notification sent status 
    152         for(int l = 0; l < NotifyEvent__MAX; ++l) 
    153         { 
    154                 mNotificationsSent[l] = false; 
    155         } 
    156  
    157152        #ifdef WIN32 
    158153                // Create the event object to signal from main thread to 
    … …  
    866861void BackupDaemon::RunSyncNowWithExceptionHandling() 
    867862{ 
     863        OnBackupStart(); 
     864 
    868865        // Do sync 
    869866        bool errorOccurred = false; 
    … …  
    895892                errorOccurred = true; 
    896893        } 
     894 
     895        // do not retry immediately without a good reason 
     896        mDoSyncForcedByPreviousSyncError = false; 
    897897         
    898898        if(errorOccurred) 
    … …  
    926926                                << "/" << errorSubCode  
    927927                                << ") due to signal"); 
     928                        OnBackupFinish(); 
    928929                        return; 
    929930                } 
     931 
     932                NotifySysadmin(SysadminNotifier::BackupError); 
    930933 
    931934                // If the Berkely db files get corrupted, 
    … …  
    933936                if(isBerkelyDbFailure) 
    934937                { 
    935                         BOX_ERROR("Berkely db inode map files corrupted, deleting and restarting scan. Renamed files and directories will not be tracked until after this scan."); 
     938                        BOX_ERROR("Berkely db inode map files corrupted, " 
     939                                "deleting and restarting scan. Renamed files " 
     940                                "and directories will not be tracked until " 
     941                                "after this scan."); 
    936942                        ::sleep(1); 
    937943                } 
    … …  
    940946                        // Not restart/terminate, pause and retry 
    941947                        // Notify administrator 
    942                         NotifySysadmin(NotifyEvent_BackupError); 
    943948                        SetState(State_Error); 
    944                         BOX_ERROR("Exception caught (" 
    945                                 << errorString 
    946                                 << " " << errorCode 
    947                                 << "/" << errorSubCode 
    948                                 << "), reset state and " 
    949                                 "waiting to retry..."); 
     949                        BOX_ERROR("Exception caught (" << errorString << 
     950                                " " << errorCode << "/" << errorSubCode << 
     951                                "), reset state and waiting to retry..."); 
    950952                        ::sleep(10); 
    951953                        mNextSyncTime = mCurrentSyncStartTime +  
    … …  
    955957                } 
    956958        } 
     959        // Notify system administrator about the final state of the backup 
     960        else if(mReadErrorsOnFilesystemObjects) 
     961        { 
     962                NotifySysadmin(SysadminNotifier::ReadError); 
     963        } 
     964        else if(mStorageLimitExceeded) 
     965        { 
     966                NotifySysadmin(SysadminNotifier::StoreFull); 
     967        } 
    957968        else 
    958969        { 
    959                 // Unset the read error flag, so the 
    960                 // error is reported again if it 
    961                 // happens again 
    962                 mNotificationsSent[NotifyEvent_BackupError] = false; 
    963         } 
    964  
    965         // If we were retrying after an error, 
    966         // now would be a good time to stop :-) 
     970                NotifySysadmin(SysadminNotifier::BackupOK); 
     971        } 
     972         
     973        // If we were retrying after an error, and this backup succeeded, 
     974        // then now would be a good time to stop :-) 
    967975        mDoSyncForcedByPreviousSyncError = errorOccurred; 
    968976 
    969         // Log the stats 
    970         BOX_NOTICE("File statistics: total file size uploaded " 
    971                 << BackupStoreFile::msStats.mBytesInEncodedFiles 
    972                 << ", bytes already on server " 
    973                 << BackupStoreFile::msStats.mBytesAlreadyOnServer 
    974                 << ", encoded size " 
    975                 << BackupStoreFile::msStats.mTotalFileStreamSize); 
    976         BackupStoreFile::ResetStats(); 
    977  
    978         // Tell anything connected to the command socket 
    979         SendSyncStartOrFinish(false /* finish */); 
    980  
    981         // Touch a file to record times in filesystem 
    982         TouchFileInWorkingDir("last_sync_finish"); 
     977        OnBackupFinish(); 
    983978} 
    984979 
    985980void BackupDaemon::RunSyncNow() 
    986981{ 
    987         // Touch a file to record times in filesystem 
    988         TouchFileInWorkingDir("last_sync_start"); 
    989  
    990         // Tell anything connected to the command socket 
    991         SendSyncStartOrFinish(true /* start */); 
    992          
    993         // Reset statistics on uploads 
    994         BackupStoreFile::ResetStats(); 
    995          
    996982        // Delete the serialised store object file, 
    997983        // so that we don't try to reload it after a 
    … …  
    1012998        mDeleteStoreObjectInfoFile = false; 
    1013999 
    1014         // Notify administrator 
    1015         NotifySysadmin(NotifyEvent_BackupStart); 
    1016  
    1017         // Set state and log start 
    1018         SetState(State_Connected); 
    1019         BOX_NOTICE("Beginning scan of local files"); 
    1020  
    10211000        const Configuration &conf(GetConfiguration()); 
     1001 
     1002        std::auto_ptr<FileLogger> fileLogger; 
     1003 
     1004        if (conf.KeyExists("LogFile")) 
     1005        { 
     1006                Log::Level level = Log::INFO; 
     1007                if (conf.KeyExists("LogFileLevel")) 
     1008                { 
     1009                        level = Logging::GetNamedLevel( 
     1010                                conf.GetKeyValue("LogFileLevel")); 
     1011                } 
     1012                fileLogger.reset(new FileLogger(conf.GetKeyValue("LogFile"), 
     1013                        level)); 
     1014        } 
    10221015 
    10231016        std::string extendedLogFile; 
    … …  
    11231116        params.mMaxUploadWait = maxUploadWait; 
    11241117        params.mFileTrackingSizeThreshold =  
    1125                 conf.GetKeyValueInt( 
    1126                 "FileTrackingSizeThreshold"); 
     1118                conf.GetKeyValueInt("FileTrackingSizeThreshold"); 
    11271119        params.mDiffingUploadSizeThreshold =  
    1128                 conf.GetKeyValueInt( 
    1129                 "DiffingUploadSizeThreshold"); 
     1120                conf.GetKeyValueInt("DiffingUploadSizeThreshold"); 
    11301121        params.mMaxFileTimeInFuture =  
    1131                 SecondsToBoxTime( 
    1132                         conf.GetKeyValueInt( 
    1133                                 "MaxFileTimeInFuture")); 
     1122                SecondsToBoxTime(conf.GetKeyValueInt("MaxFileTimeInFuture")); 
    11341123        mDeleteRedundantLocationsAfter = 
    1135                 conf.GetKeyValueInt( 
    1136                         "DeleteRedundantLocationsAfter"); 
     1124                conf.GetKeyValueInt("DeleteRedundantLocationsAfter"); 
    11371125        mStorageLimitExceeded = false; 
    11381126        mReadErrorsOnFilesystemObjects = false; 
    … …  
    12061194        } 
    12071195         
    1208         // Errors reading any files? 
    1209         if(params.mReadErrorsOnFilesystemObjects) 
    1210         { 
    1211                 // Notify administrator 
    1212                 NotifySysadmin(NotifyEvent_ReadError); 
    1213         } 
    1214         else 
    1215         { 
    1216                 // Unset the read error flag, so the                                            // error is reported again if it 
    1217                 // happens again 
    1218                 mNotificationsSent[NotifyEvent_ReadError] = false; 
    1219         } 
    1220          
    12211196        // Perform any deletions required -- these are 
    12221197        // delayed until the end to allow renaming to  
    … …  
    12451220        CommitIDMapsAfterSync(); 
    12461221 
    1247         // Log 
    1248         BOX_NOTICE("Finished scan of local files"); 
    1249  
    1250          
    1251         // Errors reading any files? 
    1252         if(mReadErrorsOnFilesystemObjects) 
    1253         { 
    1254                 // Notify administrator 
    1255                 NotifySysadmin(NotifyEvent_ReadError); 
    1256         } 
    1257         else 
    1258         { 
    1259                 // Unset the read error flag, so the 
    1260                 // error is reported again if it 
    1261                 // happens again 
    1262                 mNotificationsSent[NotifyEvent_ReadError] = false; 
    1263         } 
    1264          
    1265         // Check the storage limit 
    1266         if(mStorageLimitExceeded) 
    1267         { 
    1268                 // Tell the sysadmin about this 
    1269                 NotifySysadmin(NotifyEvent_StoreFull); 
    1270         } 
    1271         else 
    1272         { 
    1273                 // unflag the storage full notify flag 
    1274                 // so that next time the store is full, 
    1275                 // an alert will be sent 
    1276                 mNotificationsSent[NotifyEvent_StoreFull] = false; 
    1277         } 
    1278          
    12791222        // Calculate when the next sync run should be 
    12801223        mNextSyncTime = mCurrentSyncStartTime +  
    … …  
    12831226                SYNC_PERIOD_RANDOM_EXTRA_TIME_SHIFT_BY); 
    12841227 
    1285         // Notify administrator 
    1286         NotifySysadmin(NotifyEvent_BackupFinish); 
    1287  
    12881228        // -------------------------------------------------------------------------------------------- 
    12891229 
    … …  
    12971237 
    12981238        // -------------------------------------------------------------------------------------------- 
     1239} 
     1240 
     1241void BackupDaemon::OnBackupStart() 
     1242{ 
     1243        // Touch a file to record times in filesystem 
     1244        TouchFileInWorkingDir("last_sync_start"); 
     1245 
     1246        // Reset statistics on uploads 
     1247        BackupStoreFile::ResetStats(); 
     1248         
     1249        // Tell anything connected to the command socket 
     1250        SendSyncStartOrFinish(true /* start */); 
     1251         
     1252        // Notify administrator 
     1253        NotifySysadmin(SysadminNotifier::BackupStart); 
     1254 
     1255        // Set state and log start 
     1256        SetState(State_Connected); 
     1257        BOX_NOTICE("Beginning scan of local files"); 
     1258} 
     1259 
     1260void BackupDaemon::OnBackupFinish() 
     1261{ 
     1262        // Log 
     1263        BOX_NOTICE("Finished scan of local files"); 
     1264 
     1265        // Notify administrator 
     1266        NotifySysadmin(SysadminNotifier::BackupFinish); 
     1267 
     1268        // Tell anything connected to the command socket 
     1269        SendSyncStartOrFinish(false /* finish */); 
     1270 
     1271        // Log the stats 
     1272        BOX_NOTICE("File statistics: total file size uploaded " 
     1273                << BackupStoreFile::msStats.mBytesInEncodedFiles 
     1274                << ", bytes already on server " 
     1275                << BackupStoreFile::msStats.mBytesAlreadyOnServer 
     1276                << ", encoded size " 
     1277                << BackupStoreFile::msStats.mTotalFileStreamSize); 
     1278 
     1279        // Reset statistics again 
     1280        BackupStoreFile::ResetStats(); 
     1281 
     1282        // Touch a file to record times in filesystem 
     1283        TouchFileInWorkingDir("last_sync_finish"); 
    12991284} 
    13001285 
    … …  
    24402425// 
    24412426// -------------------------------------------------------------------------- 
    2442 void BackupDaemon::NotifySysadmin(int Event) 
     2427void BackupDaemon::NotifySysadmin(SysadminNotifier::EventCode Event) 
    24432428{ 
    24442429        static const char *sEventNames[] =  
    … …  
    24492434                "backup-start", 
    24502435                "backup-finish", 
     2436                "backup-ok", 
    24512437                0 
    24522438        }; 
    … …  
    24552441        // BOX_TRACE("sizeof(*sEventNames) == " << sizeof(*sEventNames)); 
    24562442        // BOX_TRACE("NotifyEvent__MAX == " << NotifyEvent__MAX); 
    2457         ASSERT((sizeof(sEventNames)/sizeof(*sEventNames)) == NotifyEvent__MAX + 1); 
    2458  
    2459         if(Event < 0 || Event >= NotifyEvent__MAX) 
     2443        ASSERT((sizeof(sEventNames)/sizeof(*sEventNames)) == SysadminNotifier::MAX + 1); 
     2444 
     2445        if(Event < 0 || Event >= SysadminNotifier::MAX) 
    24602446        { 
    24612447                BOX_ERROR("BackupDaemon::NotifySysadmin() called for " 
    … …  
    24682454                sEventNames[Event]); 
    24692455 
    2470         // Don't send lots of repeated messages 
    2471         if(mNotificationsSent[Event] && 
    2472                 Event != NotifyEvent_BackupStart && 
    2473                 Event != NotifyEvent_BackupFinish) 
    2474         { 
    2475                 BOX_WARNING("Suppressing duplicate notification about " << 
    2476                         sEventNames[Event]); 
    2477                 return; 
     2456        if(!GetConfiguration().KeyExists("NotifyAlways") || 
     2457                !GetConfiguration().GetKeyValueBool("NotifyAlways")) 
     2458        { 
     2459                // Don't send lots of repeated messages 
     2460                if(mLastNotifiedEvent == Event) 
     2461                { 
     2462                        BOX_WARNING("Suppressing duplicate notification about " << 
     2463                                sEventNames[Event]); 
     2464                        return; 
     2465                } 
    24782466        } 
    24792467 
    … …  
    24832471        { 
    24842472                // Log, and then return 
    2485                 if(Event != NotifyEvent_BackupStart && 
    2486                         Event != NotifyEvent_BackupFinish) 
     2473                if(Event != SysadminNotifier::BackupStart && 
     2474                        Event != SysadminNotifier::BackupFinish) 
    24872475                { 
    24882476                        BOX_ERROR("Not notifying administrator about event " 
    … …  
    25042492        // Then do it 
    25052493        int returnCode = ::system(script.c_str()); 
    2506         if (returnCode != 0) 
     2494        if(returnCode != 0) 
    25072495        { 
    25082496                BOX_ERROR("Notify script returned error code: " << 
    25092497                        returnCode << " ('" << script << "')"); 
    25102498        } 
    2511  
    2512         // Flag that this is done so the administrator isn't constantly 
    2513         // bombarded with lots of errors 
    2514         mNotificationsSent[Event] = true; 
     2499        else if(Event != SysadminNotifier::BackupStart && 
     2500                Event != SysadminNotifier::BackupFinish) 
     2501        { 
     2502                mLastNotifiedEvent = Event; 
     2503        } 
    25152504} 
    25162505 

  • box/trunk/bin/bbackupd/BackupDaemon.h

    r2245 r2302  
    101101 
    102102        // Allow other classes to call this too 
    103         enum 
    104         { 
    105                 NotifyEvent_StoreFull = 0, 
    106                 NotifyEvent_ReadError, 
    107                 NotifyEvent_BackupError, 
    108                 NotifyEvent_BackupStart, 
    109                 NotifyEvent_BackupFinish, 
    110                 NotifyEvent__MAX 
    111                 // When adding notifications, remember to add strings to NotifySysadmin() 
    112         }; 
    113         void NotifySysadmin(int Event); 
     103        void NotifySysadmin(SysadminNotifier::EventCode Event); 
    114104 
    115105private: 
    … …  
    120110        void RunSyncNowWithExceptionHandling(); 
    121111        void RunSyncNow(); 
     112        void OnBackupStart(); 
     113        void OnBackupFinish(); 
    122114 
    123115private: 
    … …  
    214206         
    215207        // Stop notifications being repeated. 
    216         bool mNotificationsSent[NotifyEvent__MAX]; 
     208        SysadminNotifier::EventCode mLastNotifiedEvent; 
    217209 
    218210        // Unused entries in the root directory wait a while before being deleted 

  • box/trunk/lib/backupclient/BackupDaemonConfigVerify.cpp

    r2127 r2302  
    9898        // extended log to a file 
    9999        ConfigurationVerifyKey("LogAllFileAccess", ConfigTest_IsBool, false), 
     100        // enable logging reasons why each file is backed up or not 
     101        ConfigurationVerifyKey("LogFile", 0), 
     102        // enable logging to a file 
     103        ConfigurationVerifyKey("LogFileLevel", 0), 
     104        // set the level of verbosity of file logging 
    100105        ConfigurationVerifyKey("CommandSocket", 0), 
    101106        // not compulsory to have this 
    … …  
    107112        // optional script to run when backup needs attention, eg store full 
    108113         
     114        ConfigurationVerifyKey("NotifyAlways", ConfigTest_IsBool, false), 
     115        // option to disable the suppression of duplicate notifications 
     116 
    109117        ConfigurationVerifyKey("CertificateFile", ConfigTest_Exists), 
    110118        ConfigurationVerifyKey("PrivateKeyFile", ConfigTest_Exists), 
Note: See TracChangeset for help on using the changeset viewer.