Bug 1400467 - Ensure services/common/logmanager.js awaits it's cleanup function r?markh draft
authorThom Chiovoloni <tchiovoloni@mozilla.com>
Fri, 22 Sep 2017 11:57:13 -0400
changeset 671353 ca226323d1a0fa9e7d4639d689e99f58e335ba82
parent 671352 41a2c1b3120c720a0ed811a2b74c9a0f11affe09
child 733502 cdef5ee33909812cbffae83d5b8e39c295c6729f
push id81922
push userbmo:tchiovoloni@mozilla.com
push dateWed, 27 Sep 2017 20:58:37 +0000
reviewersmarkh
bugs1400467
milestone58.0a1
Bug 1400467 - Ensure services/common/logmanager.js awaits it's cleanup function r?markh MozReview-Commit-ID: thQph1UUA0
services/common/logmanager.js
services/sync/tests/unit/test_errorhandler_filelog.js
--- a/services/common/logmanager.js
+++ b/services/common/logmanager.js
@@ -261,29 +261,28 @@ LogManager.prototype = {
         this._fileAppender.reset();
         return null;
       }
 
       // We have reasonPrefix at the start of the filename so all "error"
       // logs are grouped in about:sync-log.
       let filename = reasonPrefix + "-" + this.logFilePrefix + "-" + Date.now() + ".txt";
       await this._fileAppender.flushToFile(this._logFileSubDirectoryEntries, filename, this._log);
-
       // It's not completely clear to markh why we only do log cleanups
       // for errors, but for now the Sync semantics have been copied...
       // (one theory is that only cleaning up on error makes it less
       // likely old error logs would be removed, but that's not true if
       // there are occasional errors - let's address this later!)
       if (reason == this.ERROR_LOG_WRITTEN && !this._cleaningUpFileLogs) {
-        this._log.trace("Scheduling cleanup.");
-        // Note we don't return/await or otherwise wait on this promise - it
-        // continues in the background
-        this.cleanupLogs().catch(err => {
+        this._log.trace("Running cleanup.");
+        try {
+          await this.cleanupLogs();
+        } catch (err) {
           this._log.error("Failed to cleanup logs", err);
-        });
+        }
       }
       return reason;
     } catch (ex) {
       this._log.error("Failed to resetFileLog", ex);
       return null;
     }
   },
 
@@ -316,15 +315,21 @@ LogManager.prototype = {
                         " (" + info.lastModificationDate.getTime() + ")");
         await OS.File.remove(entry.path);
         this._log.trace("Deleted " + entry.name);
       } catch (ex) {
         this._log.debug("Encountered error trying to clean up old log file "
                         + entry.name, ex);
       }
     });
-    iterator.close();
+    // Wait for this to close if we need to (but it might fail if OS.File has
+    // shut down)
+    try {
+      await iterator.close();
+    } catch (e) {
+      this._log.warn("Failed to close directory iterator", e);
+    }
     this._cleaningUpFileLogs = false;
     this._log.debug("Done deleting files.");
     // This notification is used only for tests.
     Services.obs.notifyObservers(null, "services-tests:common:log-manager:cleanup-logs");
   },
 }
--- a/services/sync/tests/unit/test_errorhandler_filelog.js
+++ b/services/sync/tests/unit/test_errorhandler_filelog.js
@@ -157,23 +157,16 @@ add_test(function test_sync_error_logOnE
 
 add_test(function test_sync_error_logOnError_true() {
   Svc.Prefs.set("log.appender.file.logOnError", true);
 
   let log = Log.repository.getLogger("Sync.Test.FileLog");
   const MESSAGE = "this WILL show up";
   log.info(MESSAGE);
 
-  // We need to wait until the log cleanup started by this test is complete
-  // or the next test will fail as it is ongoing.
-  Svc.Obs.add("services-tests:common:log-manager:cleanup-logs", function onCleanupLogs() {
-    Svc.Obs.remove("services-tests:common:log-manager:cleanup-logs", onCleanupLogs);
-    run_next_test();
-  });
-
   Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
     Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
 
     // Exactly one log file was written.
     let entries = logsdir.directoryEntries;
     do_check_true(entries.hasMoreElements());
     let logfile = entries.getNext().QueryInterface(Ci.nsIFile);
     do_check_eq(logfile.leafName.slice(-4), ".txt");
@@ -189,16 +182,17 @@ add_test(function test_sync_error_logOnE
       try {
         logfile.remove(false);
       } catch (ex) {
         dump("Couldn't delete file: " + ex.message + "\n");
         // Stupid Windows box.
       }
 
       Svc.Prefs.resetBranch("");
+      run_next_test();
     });
   });
 
   // Fake an unsuccessful sync due to prolonged failure.
   setLastSync(PROLONGED_ERROR_DURATION);
   Svc.Obs.notify("weave:service:sync:error");
 });
 
@@ -224,23 +218,16 @@ add_test(function test_login_error_logOn
 
 add_test(function test_login_error_logOnError_true() {
   Svc.Prefs.set("log.appender.file.logOnError", true);
 
   let log = Log.repository.getLogger("Sync.Test.FileLog");
   const MESSAGE = "this WILL show up";
   log.info(MESSAGE);
 
-  // We need to wait until the log cleanup started by this test is complete
-  // or the next test will fail as it is ongoing.
-  Svc.Obs.add("services-tests:common:log-manager:cleanup-logs", function onCleanupLogs() {
-    Svc.Obs.remove("services-tests:common:log-manager:cleanup-logs", onCleanupLogs);
-    run_next_test();
-  });
-
   Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
     Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
 
     // Exactly one log file was written.
     let entries = logsdir.directoryEntries;
     do_check_true(entries.hasMoreElements());
     let logfile = entries.getNext().QueryInterface(Ci.nsIFile);
     do_check_eq(logfile.leafName.slice(-4), ".txt");
@@ -256,16 +243,17 @@ add_test(function test_login_error_logOn
       try {
         logfile.remove(false);
       } catch (ex) {
         dump("Couldn't delete file: " + ex.message + "\n");
         // Stupid Windows box.
       }
 
       Svc.Prefs.resetBranch("");
+      run_next_test();
     });
   });
 
   // Fake an unsuccessful login due to prolonged failure.
   setLastSync(PROLONGED_ERROR_DURATION);
   Svc.Obs.notify("weave:service:login:error");
 });
 
@@ -296,23 +284,16 @@ add_test(function test_noNewFailed_noErr
 add_test(function test_newFailed_errorLog() {
   Svc.Prefs.set("log.appender.file.logOnError", true);
   Svc.Prefs.set("log.appender.file.logOnSuccess", false);
 
   let log = Log.repository.getLogger("Sync.Test.FileLog");
   const MESSAGE = "this WILL show up 2";
   log.info(MESSAGE);
 
-  // We need to wait until the log cleanup started by this test is complete
-  // or the next test will fail as it is ongoing.
-  Svc.Obs.add("services-tests:common:log-manager:cleanup-logs", function onCleanupLogs() {
-    Svc.Obs.remove("services-tests:common:log-manager:cleanup-logs", onCleanupLogs);
-    run_next_test();
-  });
-
   Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
     Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
 
     // Exactly one log file was written.
     let entries = logsdir.directoryEntries;
     do_check_true(entries.hasMoreElements());
     let logfile = entries.getNext().QueryInterface(Ci.nsIFile);
     do_check_eq(logfile.leafName.slice(-4), ".txt");
@@ -328,17 +309,17 @@ add_test(function test_newFailed_errorLo
       try {
         logfile.remove(false);
       } catch (ex) {
         dump("Couldn't delete file: " + ex.message + "\n");
         // Stupid Windows box.
       }
 
       Svc.Prefs.resetBranch("");
-
+      run_next_test();
     });
   });
   // newFailed is nonzero -- should write a log.
   let count = {
     applied: 8,
     succeeded: 4,
     failed: 5,
     newFailed: 4,
@@ -347,23 +328,16 @@ add_test(function test_newFailed_errorLo
 
   Svc.Obs.notify("weave:engine:sync:applied", count, "foobar-engine");
   Svc.Obs.notify("weave:service:sync:finish");
 });
 
 add_test(function test_errorLog_dumpAddons() {
   Svc.Prefs.set("log.appender.file.logOnError", true);
 
-  // We need to wait until the log cleanup started by this test is complete
-  // or the next test will fail as it is ongoing.
-  Svc.Obs.add("services-tests:common:log-manager:cleanup-logs", function onCleanupLogs() {
-    Svc.Obs.remove("services-tests:common:log-manager:cleanup-logs", onCleanupLogs);
-    run_next_test();
-  });
-
   Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
     Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
 
     let entries = logsdir.directoryEntries;
     do_check_true(entries.hasMoreElements());
     let logfile = entries.getNext().QueryInterface(Ci.nsIFile);
     do_check_eq(logfile.leafName.slice(-4), ".txt");
     do_check_true(logfile.leafName.startsWith("error-sync-"), logfile.leafName);
@@ -378,16 +352,17 @@ add_test(function test_errorLog_dumpAddo
       try {
         logfile.remove(false);
       } catch (ex) {
         dump("Couldn't delete file: " + ex.message + "\n");
         // Stupid Windows box.
       }
 
       Svc.Prefs.resetBranch("");
+      run_next_test();
     });
   });
 
   // Fake an unsuccessful sync due to prolonged failure.
   setLastSync(PROLONGED_ERROR_DURATION);
   Svc.Obs.notify("weave:service:sync:error");
 });