From e71a3bf0d71113df5bdd192dcfb5aea762ce96dd Mon Sep 17 00:00:00 2001 From: Dave Townsend Date: Thu, 11 Nov 2010 10:48:06 -0800 Subject: [PATCH] Bug 610810: Add file and line number information to ERROR and WARN messages in the console. r=robstrong, a=dtownsend --- toolkit/mozapps/extensions/AddonLogging.jsm | 70 +++++++++++--- toolkit/mozapps/extensions/AddonManager.jsm | 17 ++-- .../mozapps/extensions/AddonRepository.jsm | 4 +- toolkit/mozapps/extensions/XPIProvider.jsm | 91 ++++++++++--------- .../mozapps/extensions/test/xpinstall/head.js | 2 +- 5 files changed, 114 insertions(+), 70 deletions(-) diff --git a/toolkit/mozapps/extensions/AddonLogging.jsm b/toolkit/mozapps/extensions/AddonLogging.jsm index 2005e274b3ad..88bd71a6cf2d 100644 --- a/toolkit/mozapps/extensions/AddonLogging.jsm +++ b/toolkit/mozapps/extensions/AddonLogging.jsm @@ -54,8 +54,43 @@ var EXPORTED_SYMBOLS = [ "LogManager" ]; var gDebugLogEnabled = false; -function formatLogMessage(aType, aName, aStr) { - return aType.toUpperCase() + " " + aName + ": " + aStr; +function formatLogMessage(aType, aName, aStr, aException) { + let message = aType.toUpperCase() + " " + aName + ": " + aStr; + if (aException) + return message + ": " + aException; + return message; +} + +function getStackDetails(aException) { + // Defensively wrap all this to ensure that failing to get the message source + // doesn't stop the message from being logged + try { + if (aException) { + if (aException instanceof Ci.nsIException) { + return { + sourceName: aException.filename, + lineNumber: aException.lineNumber + }; + } + + return { + sourceName: aException.fileName, + lineNumber: aException.lineNumber + }; + } + + let stackFrame = Components.stack.caller.caller.caller; + return { + sourceName: stackFrame.filename, + lineNumber: stackFrame.lineNumber + }; + } + catch (e) { + return { + sourceName: null, + lineNumber: 0 + }; + } } function AddonLogger(aName) { @@ -65,13 +100,15 @@ function AddonLogger(aName) { AddonLogger.prototype = { name: null, - error: function(aStr) { - let message = formatLogMessage("error", this.name, aStr); + error: function(aStr, aException) { + let message = formatLogMessage("error", this.name, aStr, aException); + + let stack = getStackDetails(aException); let consoleMessage = Cc["@mozilla.org/scripterror;1"]. createInstance(Ci.nsIScriptError); - consoleMessage.init(message, null, null, 0, 0, Ci.nsIScriptError.errorFlag, - "component javascript"); + consoleMessage.init(message, stack.sourceName, null, stack.lineNumber, 0, + Ci.nsIScriptError.errorFlag, "component javascript"); Services.console.logMessage(consoleMessage); if (gDebugLogEnabled) @@ -87,28 +124,31 @@ AddonLogger.prototype = { createInstance(Ci.nsIConverterOutputStream); writer.init(stream, "UTF-8", 0, 0x0000); writer.writeString(tstamp.toLocaleFormat("%Y-%m-%d %H:%M:%S ") + - message + "\n"); + message + " at " + stack.sourceName + ":" + + stack.lineNumber + "\n"); writer.close(); } catch (e) { } }, - warn: function(aStr) { - let message = formatLogMessage("warn", this.name, aStr); + warn: function(aStr, aException) { + let message = formatLogMessage("warn", this.name, aStr, aException); + + let stack = getStackDetails(aException); let consoleMessage = Cc["@mozilla.org/scripterror;1"]. createInstance(Ci.nsIScriptError); - consoleMessage.init(message, null, null, 0, 0, Ci.nsIScriptError.warningFlag, - "component javascript"); + consoleMessage.init(message, stack.sourceName, null, stack.lineNumber, 0, + Ci.nsIScriptError.warningFlag, "component javascript"); Services.console.logMessage(consoleMessage); if (gDebugLogEnabled) dump("*** " + message + "\n"); }, - log: function(aStr) { + log: function(aStr, aException) { if (gDebugLogEnabled) { - let message = formatLogMessage("log", this.name, aStr); + let message = formatLogMessage("log", this.name, aStr, aException); dump("*** " + message + "\n"); Services.console.logStringMessage(message); } @@ -123,8 +163,8 @@ var LogManager = { ["error", "warn", "log"].forEach(function(name) { let fname = name.toUpperCase(); delete aTarget[fname]; - aTarget[fname] = function(aStr) { - logger[name](aStr); + aTarget[fname] = function(aStr, aException) { + logger[name](aStr, aException); }; }); } diff --git a/toolkit/mozapps/extensions/AddonManager.jsm b/toolkit/mozapps/extensions/AddonManager.jsm index 360dbe98dca9..8a039ec330fc 100644 --- a/toolkit/mozapps/extensions/AddonManager.jsm +++ b/toolkit/mozapps/extensions/AddonManager.jsm @@ -81,7 +81,7 @@ function safeCall(aCallback) { aCallback.apply(null, args); } catch (e) { - WARN("Exception calling callback: " + e); + WARN("Exception calling callback", e); } } @@ -107,8 +107,9 @@ function callProvider(aProvider, aMethod, aDefault) { try { return aProvider[aMethod].apply(aProvider, args); - } catch (e) { - ERROR("Exception calling provider." + aMethod + ": " + e); + } + catch (e) { + ERROR("Exception calling provider" + aMethod, e); return aDefault; } } @@ -250,7 +251,7 @@ var AddonManagerInternal = { Components.utils.import(url, {}); } catch (e) { - ERROR("Exception loading default provider \"" + url + "\": " + e); + ERROR("Exception loading default provider \"" + url + "\"", e); } }); @@ -267,7 +268,7 @@ var AddonManagerInternal = { } catch (e) { ERROR("Exception loading provider " + entry + " from category \"" + - url + "\": " + e); + url + "\"", e); } } @@ -412,7 +413,7 @@ var AddonManagerInternal = { } } catch (e) { - WARN("InstallListener threw exception when calling " + aMethod + ": " + e); + WARN("InstallListener threw exception when calling " + aMethod, e); } }); return result; @@ -433,7 +434,7 @@ var AddonManagerInternal = { listener[aMethod].apply(listener, args); } catch (e) { - WARN("AddonListener threw exception when calling " + aMethod + ": " + e); + WARN("AddonListener threw exception when calling " + aMethod, e); } }); }, @@ -664,7 +665,7 @@ var AddonManagerInternal = { // In the event that the weblistener throws during instatiation or when // calling onWebInstallBlocked or onWebInstallRequested all of the // installs should get cancelled. - WARN("Failure calling web installer: " + e); + WARN("Failure calling web installer", e); aInstalls.forEach(function(aInstall) { aInstall.cancel(); }); diff --git a/toolkit/mozapps/extensions/AddonRepository.jsm b/toolkit/mozapps/extensions/AddonRepository.jsm index cfcb918b0900..7cd10efce39d 100644 --- a/toolkit/mozapps/extensions/AddonRepository.jsm +++ b/toolkit/mozapps/extensions/AddonRepository.jsm @@ -1190,7 +1190,7 @@ var AddonDatabase = { this.connection = Services.storage.openUnsharedDatabase(dbfile); } catch (e) { this.initialized = false; - ERROR("Failed to open database: " + e); + ERROR("Failed to open database", e); if (aSecondAttempt || dbMissing) { this.databaseOk = false; throw e; @@ -1741,7 +1741,7 @@ var AddonDatabase = { this.connection.schemaVersion = DB_SCHEMA; this.connection.commitTransaction(); } catch (e) { - ERROR("Failed to create database schema"); + ERROR("Failed to create database schema", e); this.logSQLError(this.connection.lastError, this.connection.lastErrorString); this.connection.rollbackTransaction(); throw e; diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm index 57bdd18d3457..4ebf8f6758d5 100644 --- a/toolkit/mozapps/extensions/XPIProvider.jsm +++ b/toolkit/mozapps/extensions/XPIProvider.jsm @@ -186,8 +186,9 @@ SafeMoveOperation.prototype = { newFile.moveTo(aTargetDirectory, null); } catch (e) { - throw new Error("Failed to move file " + aFile.path + " to " + - aTargetDirectory.path + ": " + e); + ERROR("Failed to move file " + aFile.path + " to " + + aTargetDirectory.path, e); + throw e; } this._movedFiles.push({ oldFile: oldFile, newFile: newFile }); }, @@ -199,7 +200,8 @@ SafeMoveOperation.prototype = { newDir.create(Ci.nsILocalFile.DIRECTORY_TYPE, FileUtils.PERMS_DIRECTORY); } catch (e) { - throw new Error("Failed to create directory " + newDir.path + ": " + e); + ERROR("Failed to create directory " + newDir.path, e); + throw e; } this._createdDirs.push(newDir); @@ -221,7 +223,8 @@ SafeMoveOperation.prototype = { aDirectory.remove(false); } catch (e) { - throw new Error("Failed to remove directory " + aDirectory.path + ": " + e); + ERROR("Failed to remove directory " + aDirectory.path, e); + throw e; } // Note we put the directory move in after all the file moves so the @@ -251,7 +254,7 @@ SafeMoveOperation.prototype = { this._moveDirEntry(aFile, aTargetDirectory); } catch (e) { - ERROR("Failure moving " + aFile.path + " to " + aTargetDirectory.path + ": " + e); + ERROR("Failure moving " + aFile.path + " to " + aTargetDirectory.path); this.rollback(); throw e; } @@ -822,7 +825,7 @@ function extractFiles(aZipFile, aDir) { } catch (e) { ERROR("extractFiles: failed to create target directory for " + - "extraction file = " + target.path + ", exception = " + e); + "extraction file = " + target.path, e); } } } @@ -1259,7 +1262,7 @@ var XPIProvider = { var location = new DirectoryInstallLocation(aName, dir, aScope, aLocked); } catch (e) { - WARN("Failed to add directory install location " + aName + " " + e); + WARN("Failed to add directory install location " + aName, e); return; } @@ -1272,7 +1275,7 @@ var XPIProvider = { var location = new WinRegInstallLocation(aName, aRootkey, aScope); } catch (e) { - WARN("Failed to add registry install location " + aName + " " + e); + WARN("Failed to add registry install location " + aName, e); return; } @@ -1461,7 +1464,7 @@ var XPIProvider = { this.currentSkin = this.selectedSkin; } catch (e) { - ERROR(e); + ERROR("Error applying theme change", e); } Services.prefs.clearUserPref(PREF_DSS_SWITCHPENDING); }, @@ -1619,7 +1622,7 @@ var XPIProvider = { } catch (e) { ERROR("Unable to read add-on manifest for " + stagedXPI.leafName + - " in XPI stage of " + aLocation.name + ": " + e); + " in XPI stage of " + aLocation.name, e); continue; } @@ -1632,7 +1635,7 @@ var XPIProvider = { targetDir.create(Ci.nsIFile.DIRECTORY_TYPE, FileUtils.PERMS_DIRECTORY); } catch (e) { - ERROR("Failed to create staging directory for add-on " + id + ": " + e); + ERROR("Failed to create staging directory for add-on " + id, e); continue; } @@ -1641,7 +1644,7 @@ var XPIProvider = { } catch (e) { ERROR("Failed to extract staged XPI for add-on " + id + " in " + - aLocation.name + ": " + e); + aLocation.name, e); } } else { @@ -1650,7 +1653,7 @@ var XPIProvider = { } catch (e) { ERROR("Failed to move staged XPI for add-on " + id + " in " + - aLocation.name + ": " + e); + aLocation.name, e); } } } @@ -1709,7 +1712,7 @@ var XPIProvider = { aLocation.uninstallAddon(id); } catch (e) { - ERROR("Failed to uninstall add-on " + id + " in " + aLocation.name); + ERROR("Failed to uninstall add-on " + id + " in " + aLocation.name, e); } // The file check later will spot the removal and cleanup the database continue; @@ -1721,8 +1724,8 @@ var XPIProvider = { var addonInstallLocation = aLocation.installAddon(id, stageDirEntry); } catch (e) { - ERROR("Failed to install staged add-on " + id + " in " + aLocation.name + - ": " + e); + ERROR("Failed to install staged add-on " + id + " in " + aLocation.name, + e); continue; } @@ -1747,7 +1750,7 @@ var XPIProvider = { } catch (e) { ERROR("Unable to read add-on manifest for " + id + " in " + - aLocation.name + ": " + e); + aLocation.name, e); } finally { fis.close(); @@ -1836,7 +1839,7 @@ var XPIProvider = { throw new Error("Incorrect id in install manifest"); } catch (e) { - WARN("Add-on is invalid: " + e); + WARN("Add-on is invalid", e); XPIDatabase.removeAddonMetadata(aOldAddon); if (!aInstallLocation.locked) aInstallLocation.uninstallAddon(aOldAddon.id); @@ -2061,7 +2064,7 @@ var XPIProvider = { throw new Error("Incorrect id in install manifest"); } catch (e) { - WARN("Add-on is invalid: " + e); + WARN("Add-on is invalid", e); // Remove the invalid add-on from the install location if the install // location isn't locked, no restart will be necessary @@ -2123,7 +2126,7 @@ var XPIProvider = { // add-on will just be unavailable until we try again in a subsequent // startup ERROR("Failed to add add-on " + aId + " in " + aInstallLocation.name + - " to database: " + e); + " to database", e); return false; } @@ -2355,7 +2358,7 @@ var XPIProvider = { migrateData, null); } catch (e) { - ERROR("Error processing file changes: " + e); + ERROR("Error processing file changes", e); } } @@ -2385,7 +2388,7 @@ var XPIProvider = { } catch (e) { ERROR("Error during startup file checks, rolling back any database " + - "changes: " + e); + "changes", e); XPIDatabase.rollbackTransaction(); } @@ -2879,7 +2882,7 @@ var XPIProvider = { loader.loadSubScript(spec, this.bootstrapScopes[aId]); } catch (e) { - WARN("Error loading bootstrap.js for " + aId + ": " + e); + WARN("Error loading bootstrap.js for " + aId, e); } // Copy the reason values from the global object into the bootstrap scope. @@ -2946,7 +2949,7 @@ var XPIProvider = { } catch (e) { WARN("Exception running bootstrap method " + aMethod + " on " + - aId + ": " + e); + aId, e); } }, @@ -3463,18 +3466,18 @@ var XPIDatabase = { connection = Services.storage.openUnsharedDatabase(aDBFile); } catch (e) { - ERROR("Failed to open database (1st attempt): " + e); + ERROR("Failed to open database (1st attempt)", e); try { aDBFile.remove(true); } catch (e) { - ERROR("Failed to remove database that could not be opened: " + e); + ERROR("Failed to remove database that could not be opened", e); } try { connection = Services.storage.openUnsharedDatabase(aDBFile); } catch (e) { - ERROR("Failed to open database (2nd attempt): " + e); + ERROR("Failed to open database (2nd attempt)", e); // If we have got here there seems to be no way to open the real // database, instead open a temporary memory database so things will @@ -3527,7 +3530,7 @@ var XPIDatabase = { this.connection = this.openDatabaseFile(dbfile); } catch (e) { - ERROR("Failed to remove old database: " + e); + ERROR("Failed to remove old database", e); // If the file couldn't be deleted then fall back to an in-memory // database this.connection = Services.storage.openSpecialDatabase("memory"); @@ -3554,7 +3557,7 @@ var XPIDatabase = { this.commitTransaction(); } catch (e) { - ERROR("Error processing file changes: " + e); + ERROR("Error processing file changes", e); dump(e.stack); this.rollbackTransaction(); } @@ -3734,7 +3737,7 @@ var XPIDatabase = { } catch (e) { // An error here means the schema is too different to read - ERROR("Error migrating data: " + e); + ERROR("Error migrating data", e); } finally { if (taStmt) @@ -3869,7 +3872,7 @@ var XPIDatabase = { this.commitTransaction(); } catch (e) { - ERROR("Failed to create database schema"); + ERROR("Failed to create database schema", e); logSQLError(this.connection.lastError, this.connection.lastErrorString); this.rollbackTransaction(); this.connection.close(); @@ -4816,7 +4819,7 @@ function AddonInstall(aCallback, aInstallLocation, aUrl, aHash, aName, aType, }); } catch (e) { - WARN("Invalid XPI: " + e); + WARN("Invalid XPI", e); this.state = AddonManager.STATE_DOWNLOAD_FAILED; this.error = AddonManager.ERROR_CORRUPT_FILE; aCallback(this); @@ -4929,7 +4932,7 @@ AddonInstall.prototype = { this.file.remove(true); } catch (e) { - WARN("Failed to remove temporary file " + this.file.path + ": " + e); + WARN("Failed to remove temporary file " + this.file.path, e); } } break; @@ -4993,7 +4996,7 @@ AddonInstall.prototype = { this.ownsTempFile = false; } catch (e) { - WARN("Failed to remove temporary file " + this.file.path + ": " + e); + WARN("Failed to remove temporary file " + this.file.path, e); } }, @@ -5034,7 +5037,7 @@ AddonInstall.prototype = { } catch (e) { WARN("Failed to extract " + entryName + " from multi-package " + - "XPI: " + e); + "XPI", e); target.remove(false); } } @@ -5060,7 +5063,7 @@ AddonInstall.prototype = { } catch (e) { WARN(this.file.leafName + " cannot be installed from multi-package " + - "XPI: " + e); + "XPI", e); } } @@ -5242,7 +5245,7 @@ AddonInstall.prototype = { FileUtils.MODE_TRUNCATE, FileUtils.PERMS_FILE, 0); } catch (e) { - WARN("Failed to start download: " + e); + WARN("Failed to start download", e); this.state = AddonManager.STATE_DOWNLOAD_FAILED; this.error = AddonManager.ERROR_FILE_ACCESS; XPIProvider.removeActiveInstall(this); @@ -5268,7 +5271,7 @@ AddonInstall.prototype = { Services.obs.addObserver(this, "network:offline-about-to-go-offline", false); } catch (e) { - WARN("Failed to start download: " + e); + WARN("Failed to start download", e); this.state = AddonManager.STATE_DOWNLOAD_FAILED; this.error = AddonManager.ERROR_NETWORK_FAILURE; XPIProvider.removeActiveInstall(this); @@ -5445,7 +5448,7 @@ AddonInstall.prototype = { * The error code to pass to the listeners */ downloadFailed: function(aReason, aError) { - WARN("Download failed: " + aError); + WARN("Download failed", aError); this.state = AddonManager.STATE_DOWNLOAD_FAILED; this.error = aReason; XPIProvider.removeActiveInstall(this); @@ -5664,7 +5667,7 @@ AddonInstall.prototype = { } } catch (e) { - WARN("Failed to install: " + e); + WARN("Failed to install", e); if (stagedAddon.exists()) recursiveRemove(stagedAddon); this.state = AddonManager.STATE_INSTALL_FAILED; @@ -5710,7 +5713,7 @@ AddonInstall.createInstall = function(aCallback, aFile) { new AddonInstall(aCallback, location, url); } catch(e) { - ERROR(e); + ERROR("Error creating install", e); aCallback(null); } }; @@ -6185,7 +6188,7 @@ DBAddonInternal.prototype = { catch (e) { // A failure just means that we discard the compatibility update ERROR("Failed to update target application info in the database for " + - "add-on " + this.id); + "add-on " + this.id, e); return; } XPIProvider.updateAddonDisabledState(this); @@ -6805,7 +6808,7 @@ DirectoryInstallLocation.prototype = { recursiveRemove(trashDir); } catch (e) { - WARN("Failed to remove trash directory when installing " + aId); + WARN("Failed to remove trash directory when installing " + aId, e); } } @@ -6864,7 +6867,7 @@ DirectoryInstallLocation.prototype = { recursiveRemove(trashDir); } catch (e) { - WARN("Failed to remove trash directory when uninstalling " + aId); + WARN("Failed to remove trash directory when uninstalling " + aId, e); } } diff --git a/toolkit/mozapps/extensions/test/xpinstall/head.js b/toolkit/mozapps/extensions/test/xpinstall/head.js index c4b4a47bdd23..c1b586c077b3 100644 --- a/toolkit/mozapps/extensions/test/xpinstall/head.js +++ b/toolkit/mozapps/extensions/test/xpinstall/head.js @@ -104,7 +104,7 @@ var Harness = { AddonManager.getAllInstalls(function(aInstalls) { is(aInstalls.length, 0, "Should be no active installs at the end of the test"); - installs.forEach(function(aInstall) { + aInstalls.forEach(function(aInstall) { info("Install for " + aInstall.sourceURI + " is in state " + aInstall.state); aInstall.cancel(); });