Bug 1263280 - Dump a list of addons currently installed when writing the sync error log r?markh
MozReview-Commit-ID: KudJLUYWv1N
--- a/services/common/logmanager.js
+++ b/services/common/logmanager.js
@@ -221,16 +221,20 @@ LogManager.prototype = {
get _logFileSubDirectoryEntries() {
// At this point we don't allow a custom directory for the logs, nor allow
// it to be outside the profile directory.
// This returns an array of the the relative directory entries below the
// profile dir, and is the directory about:sync-log uses.
return ["weave", "logs"];
},
+ get sawError() {
+ return this._fileAppender.sawError;
+ },
+
// Result values for resetFileLog.
SUCCESS_LOG_WRITTEN: "success-log-written",
ERROR_LOG_WRITTEN: "error-log-written",
/**
* Possibly generate a log file for all accumulated log messages and refresh
* the input & output streams.
* Whether a "success" or "error" log is written is determined based on
--- a/services/sync/modules/policies.js
+++ b/services/sync/modules/policies.js
@@ -13,16 +13,18 @@ Cu.import("resource://gre/modules/Log.js
Cu.import("resource://services-sync/constants.js");
Cu.import("resource://services-sync/engines.js");
Cu.import("resource://services-sync/util.js");
Cu.import("resource://services-common/logmanager.js");
Cu.import("resource://services-common/async.js");
XPCOMUtils.defineLazyModuleGetter(this, "Status",
"resource://services-sync/status.js");
+XPCOMUtils.defineLazyModuleGetter(this, "AddonManager",
+ "resource://gre/modules/AddonManager.jsm");
this.SyncScheduler = function SyncScheduler(service) {
this.service = service;
this.init();
}
SyncScheduler.prototype = {
_log: Log.repository.getLogger("Sync.SyncScheduler"),
@@ -681,31 +683,62 @@ ErrorHandler.prototype = {
*/
syncAndReportErrors: function syncAndReportErrors() {
this._log.debug("Beginning user-triggered sync.");
this.dontIgnoreErrors = true;
Utils.nextTick(this.service.sync, this.service);
},
+ _dumpAddons: function _dumpAddons() {
+ // Just dump the items that sync may be concerned with. Specifically,
+ // active extensions that are not hidden.
+ let addonPromise = new Promise(resolve => {
+ try {
+ AddonManager.getAddonsByTypes(["extension"], resolve);
+ } catch (e) {
+ this._log.warn("Failed to dump addons", e)
+ resolve([])
+ }
+ });
+
+ return addonPromise.then(addons => {
+ let relevantAddons = addons.filter(x => x.isActive && !x.hidden);
+ this._log.debug("Addons installed", relevantAddons.length);
+ for (let addon of relevantAddons) {
+ this._log.debug(" - ${name}, version ${version}, id ${id}", addon);
+ }
+ });
+ },
+
/**
* Generate a log file for the sync that just completed
* and refresh the input & output streams.
*/
resetFileLog: function resetFileLog() {
let onComplete = logType => {
Svc.Obs.notify("weave:service:reset-file-log");
this._log.trace("Notified: " + Date.now());
if (logType == this._logManager.ERROR_LOG_WRITTEN) {
Cu.reportError("Sync encountered an error - see about:sync-log for the log file.");
}
};
+
+ // If we're writing an error log, dump extensions that may be causing problems.
+ let beforeResetLog;
+ if (this._logManager.sawError) {
+ beforeResetLog = this._dumpAddons();
+ } else {
+ beforeResetLog = Promise.resolve();
+ }
// Note we do not return the promise here - the caller doesn't need to wait
// for this to complete.
- this._logManager.resetFileLog().then(onComplete, onComplete);
+ beforeResetLog
+ .then(() => this._logManager.resetFileLog())
+ .then(onComplete, onComplete);
},
/**
* Translates server error codes to meaningful strings.
*
* @param code
* server error code as an integer
*/
--- a/services/sync/tests/unit/test_errorhandler_filelog.js
+++ b/services/sync/tests/unit/test_errorhandler_filelog.js
@@ -40,30 +40,32 @@ function run_test() {
add_test(function test_noOutput() {
// Ensure that the log appender won't print anything.
errorHandler._logManager._fileAppender.level = Log.Level.Fatal + 1;
// Clear log output from startup.
Svc.Prefs.set("log.appender.file.logOnSuccess", false);
Svc.Obs.notify("weave:service:sync:finish");
+ Svc.Obs.add("weave:service:reset-file-log", function onResetFileLogOuter() {
+ Svc.Obs.remove("weave:service:reset-file-log", onResetFileLogOuter);
+ // Clear again without having issued any output.
+ Svc.Prefs.set("log.appender.file.logOnSuccess", true);
- // Clear again without having issued any output.
- Svc.Prefs.set("log.appender.file.logOnSuccess", true);
-
- Svc.Obs.add("weave:service:reset-file-log", function onResetFileLog() {
- Svc.Obs.remove("weave:service:reset-file-log", onResetFileLog);
+ Svc.Obs.add("weave:service:reset-file-log", function onResetFileLogInner() {
+ Svc.Obs.remove("weave:service:reset-file-log", onResetFileLogInner);
- errorHandler._logManager._fileAppender.level = Log.Level.Trace;
- Svc.Prefs.resetBranch("");
- run_next_test();
+ errorHandler._logManager._fileAppender.level = Log.Level.Trace;
+ Svc.Prefs.resetBranch("");
+ run_next_test();
+ });
+
+ // Fake a successful sync.
+ Svc.Obs.notify("weave:service:sync:finish");
});
-
- // Fake a successful sync.
- Svc.Obs.notify("weave:service:sync:finish");
});
add_test(function test_logOnSuccess_false() {
Svc.Prefs.set("log.appender.file.logOnSuccess", false);
let log = Log.repository.getLogger("Sync.Test.FileLog");
log.info("this won't show up");
@@ -260,16 +262,61 @@ add_test(function test_login_error_logOn
});
});
// Fake an unsuccessful login due to prolonged failure.
setLastSync(PROLONGED_ERROR_DURATION);
Svc.Obs.notify("weave:service:login:error");
});
+
+add_test(function test_errorLog_dumpAddons() {
+ Svc.Prefs.set("log.appender.file.logOnError", true);
+
+ let log = Log.repository.getLogger("Sync.Test.FileLog");
+
+ // 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.nsILocalFile);
+ do_check_eq(logfile.leafName.slice(-4), ".txt");
+ do_check_true(logfile.leafName.startsWith("error-sync-"), logfile.leafName);
+ do_check_false(entries.hasMoreElements());
+
+ // Ensure we logged some addon list (which is probably empty)
+ readFile(logfile, function (error, data) {
+ do_check_true(Components.isSuccessCode(error));
+ do_check_neq(data.indexOf("Addons installed"), -1);
+
+ // Clean up.
+ try {
+ logfile.remove(false);
+ } catch(ex) {
+ dump("Couldn't delete file: " + ex + "\n");
+ // Stupid Windows box.
+ }
+
+ Svc.Prefs.resetBranch("");
+ });
+ });
+
+ // Fake an unsuccessful sync due to prolonged failure.
+ setLastSync(PROLONGED_ERROR_DURATION);
+ Svc.Obs.notify("weave:service:sync:error");
+});
+
// Check that error log files are deleted above an age threshold.
add_test(function test_logErrorCleanup_age() {
_("Beginning test_logErrorCleanup_age.");
let maxAge = CLEANUP_DELAY / 1000;
let oldLogs = [];
let numLogs = 10;
let errString = "some error log\n";