Bug 663181 - Automatic cleanup for Sync error logs. r=philikon

services/sync/modules/policies.js

@@ -21,6 +21,7 @@
  * Contributor(s):
  *  Marina Samuel <msamuel@mozilla.com>
  *  Philipp von Weitershausen <philipp@weitershausen.de>
+ *  Chenxia Liu <liuche@mozilla.com>
  *
  * Alternatively, the contents of this file may be used under the terms of
  * either the GNU General Public License Version 2 or later (the "GPL"), or
@@ -453,6 +454,7 @@ let ErrorHandler = {
   initLogs: function initLogs() {
     this._log = Log4Moz.repository.getLogger("Sync.ErrorHandler");
     this._log.level = Log4Moz.Level[Svc.Prefs.get("log.logger.service.main")];
+    this._cleaningUpFileLogs = false;
 
     let root = Log4Moz.repository.getLogger("Sync");
     root.level = Log4Moz.Level[Svc.Prefs.get("log.rootLogger")];
@@ -552,6 +554,46 @@ let ErrorHandler = {
     Utils.nextTick(Weave.Service.sync, Weave.Service);
   },
 
+  /**
+   * Finds all logs older than maxErrorAge and deletes them without tying up I/O.
+   */
+  cleanupLogs: function cleanupLogs() {
+    let direntries = FileUtils.getDir("ProfD", ["weave", "logs"]).directoryEntries;
+    let oldLogs = [];
+    let index = 0;
+    let threshold = Date.now() - 1000 * Svc.Prefs.get("log.appender.file.maxErrorAge");
+
+    while (direntries.hasMoreElements()) {
+      let logFile = direntries.getNext().QueryInterface(Ci.nsIFile);
+      if (logFile.lastModifiedTime < threshold) {
+        oldLogs.push(logFile);
+      }
+    }
+
+    // Deletes a file from oldLogs each tick until there are none left.
+    function deleteFile() {
+      if (index >= oldLogs.length) {
+        ErrorHandler._cleaningUpFileLogs = false;
+        Svc.Obs.notify("weave:service:cleanup-logs");
+        return;
+      }
+      try {
+        oldLogs[index].remove(false);
+      } catch (ex) {
+        ErrorHandler._log._debug("Encountered error trying to clean up old log file '"
+                                 + oldLogs[index].leafName + "':"
+                                 + Utils.exceptionStr(ex));
+      }
+      index++;
+      Utils.nextTick(deleteFile);
+    }
+
+    if (oldLogs.length > 0) {
+      ErrorHandler._cleaningUpFileLogs = true;
+      Utils.nextTick(deleteFile);
+    }
+  },
+
   /**
    * Generate a log file for the sync that just completed
    * and refresh the input & output streams.
@@ -573,6 +615,10 @@ let ErrorHandler = {
         let outStream = FileUtils.openFileOutputStream(file);
         NetUtil.asyncCopy(inStream, outStream, function () {
           Svc.Obs.notify("weave:service:reset-file-log");
+          if (filenamePrefix == LOG_PREFIX_ERROR
+              && !ErrorHandler._cleaningUpFileLogs) {
+            Utils.nextTick(ErrorHandler.cleanupLogs, ErrorHandler);
+          }
         });
       } catch (ex) {
         Svc.Obs.notify("weave:service:reset-file-log");

services/sync/services-sync.js

@@ -34,6 +34,7 @@ pref("services.sync.log.appender.dump", "Error");
 pref("services.sync.log.appender.file.level", "Trace");
 pref("services.sync.log.appender.file.logOnError", true);
 pref("services.sync.log.appender.file.logOnSuccess", false);
+pref("services.sync.log.appender.file.maxErrorAge", 864000); // 10 days
 pref("services.sync.log.rootLogger", "Debug");
 pref("services.sync.log.logger.service.main", "Debug");
 pref("services.sync.log.logger.authenticator", "Debug");

services/sync/tests/unit/test_errorhandler_filelog.js

@@ -5,9 +5,11 @@ Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 Cu.import("resource://services-sync/log4moz.js");
 
-const logsdir = FileUtils.getDir("ProfD", ["weave", "logs"], true);
+const logsdir            = FileUtils.getDir("ProfD", ["weave", "logs"], true);
 const LOG_PREFIX_SUCCESS = "success-";
 const LOG_PREFIX_ERROR   = "error-";
+const CLEANUP_DELAY      = 1000; // delay to age files for cleanup (ms)
+const DELAY_BUFFER       = 50; // buffer for timers on different OS platforms
 
 const PROLONGED_ERROR_DURATION =
   (Svc.Prefs.get('errorhandler.networkFailureReportTimeout') * 2) * 1000;
@@ -231,3 +233,53 @@ add_test(function test_login_error_logOnError_true() {
   setLastSync(PROLONGED_ERROR_DURATION);
   Svc.Obs.notify("weave:service:login:error");
 });
+
+// Check that error log files are deleted above an age threshold.
+add_test(function test_logErrorCleanup_age() {
+  let maxAge = CLEANUP_DELAY/1000;
+  let firstlog_name;
+  let oldLogs = [];
+  let numLogs = 10;
+  let errString = "some error log\n";
+
+  Svc.Prefs.set("log.appender.file.logOnError", true);
+  Svc.Prefs.set("log.appender.file.maxErrorAge", maxAge);
+
+  // Make some files.
+  for (let i = 0; i < numLogs; i++) {
+    let filename = LOG_PREFIX_ERROR + Date.now() + i + ".txt";
+    let newLog = FileUtils.getFile("ProfD", ["weave", "logs", filename]);
+    let foStream = FileUtils.openFileOutputStream(newLog);
+    foStream.write(errString, errString.length);
+    foStream.close();
+    oldLogs.push(newLog.leafName);
+  }
+
+  Svc.Obs.add("weave:service:cleanup-logs", function onCleanupLogs() {
+    Svc.Obs.remove("weave:service:cleanup-logs", onCleanupLogs);
+
+    // Only the newest created log file remains.
+    let entries = logsdir.directoryEntries;
+    do_check_true(entries.hasMoreElements());
+    let logfile = entries.getNext().QueryInterface(Ci.nsILocalFile);
+    do_check_true(oldLogs.every(function (e) {
+      return e != logfile.leafName;
+    }));
+    do_check_false(entries.hasMoreElements());
+
+    // Clean up.
+    try {
+      logfile.remove(false);
+    } catch(ex) {
+      dump("Couldn't delete file: " + ex + "\n");
+      // Stupid Windows box.
+    }
+
+    Svc.Prefs.resetBranch("");
+    run_next_test();
+  });
+
+  Utils.namedTimer(function () Svc.Obs.notify("weave:service:sync:error"),
+                   CLEANUP_DELAY + DELAY_BUFFER, this, "cleanup-timer");
+
+});