summaryrefslogtreecommitdiffstats
path: root/services/common/logmanager.sys.mjs
diff options
context:
space:
mode:
Diffstat (limited to 'services/common/logmanager.sys.mjs')
-rw-r--r--services/common/logmanager.sys.mjs449
1 files changed, 449 insertions, 0 deletions
diff --git a/services/common/logmanager.sys.mjs b/services/common/logmanager.sys.mjs
new file mode 100644
index 0000000000..178228f3e6
--- /dev/null
+++ b/services/common/logmanager.sys.mjs
@@ -0,0 +1,449 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+"use strict;";
+
+import { Log } from "resource://gre/modules/Log.sys.mjs";
+
+const lazy = {};
+
+ChromeUtils.defineESModuleGetters(lazy, {
+ FileUtils: "resource://gre/modules/FileUtils.sys.mjs",
+});
+ChromeUtils.defineModuleGetter(
+ lazy,
+ "NetUtil",
+ "resource://gre/modules/NetUtil.jsm"
+);
+
+import { Preferences } from "resource://gre/modules/Preferences.sys.mjs";
+
+const DEFAULT_MAX_ERROR_AGE = 20 * 24 * 60 * 60; // 20 days
+
+// "shared" logs (ie, where the same log name is used by multiple LogManager
+// instances) are a fact of life here - eg, FirefoxAccounts logs are used by
+// both Sync and Reading List.
+// However, different instances have different pref branches, so we need to
+// handle when one pref branch says "Debug" and the other says "Error"
+// So we (a) keep singleton console and dump appenders and (b) keep track
+// of the minimum (ie, most verbose) level and use that.
+// This avoids (a) the most recent setter winning (as that is indeterminate)
+// and (b) multiple dump/console appenders being added to the same log multiple
+// times, which would cause messages to appear twice.
+
+// Singletons used by each instance.
+var formatter;
+var dumpAppender;
+var consoleAppender;
+
+// A set of all preference roots used by all instances.
+var allBranches = new Set();
+
+const STREAM_SEGMENT_SIZE = 4096;
+const PR_UINT32_MAX = 0xffffffff;
+
+/**
+ * Append to an nsIStorageStream
+ *
+ * This writes logging output to an in-memory stream which can later be read
+ * back as an nsIInputStream. It can be used to avoid expensive I/O operations
+ * during logging. Instead, one can periodically consume the input stream and
+ * e.g. write it to disk asynchronously.
+ */
+class StorageStreamAppender extends Log.Appender {
+ constructor(formatter) {
+ super(formatter);
+ this._name = "StorageStreamAppender";
+
+ this._converterStream = null; // holds the nsIConverterOutputStream
+ this._outputStream = null; // holds the underlying nsIOutputStream
+
+ this._ss = null;
+ }
+
+ get outputStream() {
+ if (!this._outputStream) {
+ // First create a raw stream. We can bail out early if that fails.
+ this._outputStream = this.newOutputStream();
+ if (!this._outputStream) {
+ return null;
+ }
+
+ // Wrap the raw stream in an nsIConverterOutputStream. We can reuse
+ // the instance if we already have one.
+ if (!this._converterStream) {
+ this._converterStream = Cc[
+ "@mozilla.org/intl/converter-output-stream;1"
+ ].createInstance(Ci.nsIConverterOutputStream);
+ }
+ this._converterStream.init(this._outputStream, "UTF-8");
+ }
+ return this._converterStream;
+ }
+
+ newOutputStream() {
+ let ss = (this._ss = Cc["@mozilla.org/storagestream;1"].createInstance(
+ Ci.nsIStorageStream
+ ));
+ ss.init(STREAM_SEGMENT_SIZE, PR_UINT32_MAX, null);
+ return ss.getOutputStream(0);
+ }
+
+ getInputStream() {
+ if (!this._ss) {
+ return null;
+ }
+ return this._ss.newInputStream(0);
+ }
+
+ reset() {
+ if (!this._outputStream) {
+ return;
+ }
+ this.outputStream.close();
+ this._outputStream = null;
+ this._ss = null;
+ }
+
+ doAppend(formatted) {
+ if (!formatted) {
+ return;
+ }
+ try {
+ this.outputStream.writeString(formatted + "\n");
+ } catch (ex) {
+ if (ex.result == Cr.NS_BASE_STREAM_CLOSED) {
+ // The underlying output stream is closed, so let's open a new one
+ // and try again.
+ this._outputStream = null;
+ }
+ try {
+ this.outputStream.writeString(formatted + "\n");
+ } catch (ex) {
+ // Ah well, we tried, but something seems to be hosed permanently.
+ }
+ }
+ }
+}
+
+// A storage appender that is flushable to a file on disk. Policies for
+// when to flush, to what file, log rotation etc are up to the consumer
+// (although it does maintain a .sawError property to help the consumer decide
+// based on its policies)
+class FlushableStorageAppender extends StorageStreamAppender {
+ constructor(formatter) {
+ super(formatter);
+ this.sawError = false;
+ }
+
+ append(message) {
+ if (message.level >= Log.Level.Error) {
+ this.sawError = true;
+ }
+ StorageStreamAppender.prototype.append.call(this, message);
+ }
+
+ reset() {
+ super.reset();
+ this.sawError = false;
+ }
+
+ // Flush the current stream to a file. Somewhat counter-intuitively, you
+ // must pass a log which will be written to with details of the operation.
+ async flushToFile(subdirArray, filename, log) {
+ let inStream = this.getInputStream();
+ this.reset();
+ if (!inStream) {
+ log.debug("Failed to flush log to a file - no input stream");
+ return;
+ }
+ log.debug("Flushing file log");
+ log.trace("Beginning stream copy to " + filename + ": " + Date.now());
+ try {
+ await this._copyStreamToFile(inStream, subdirArray, filename, log);
+ log.trace("onCopyComplete", Date.now());
+ } catch (ex) {
+ log.error("Failed to copy log stream to file", ex);
+ }
+ }
+
+ /**
+ * Copy an input stream to the named file, doing everything off the main
+ * thread.
+ * subDirArray is an array of path components, relative to the profile
+ * directory, where the file will be created.
+ * outputFileName is the filename to create.
+ * Returns a promise that is resolved on completion or rejected with an error.
+ */
+ async _copyStreamToFile(inputStream, subdirArray, outputFileName, log) {
+ let outputDirectory = PathUtils.join(PathUtils.profileDir, ...subdirArray);
+ await IOUtils.makeDirectory(outputDirectory);
+ let fullOutputFileName = PathUtils.join(outputDirectory, outputFileName);
+
+ let outputStream = Cc[
+ "@mozilla.org/network/file-output-stream;1"
+ ].createInstance(Ci.nsIFileOutputStream);
+
+ outputStream.init(
+ new lazy.FileUtils.File(fullOutputFileName),
+ -1,
+ -1,
+ Ci.nsIFileOutputStream.DEFER_OPEN
+ );
+
+ await new Promise(resolve =>
+ lazy.NetUtil.asyncCopy(inputStream, outputStream, () => resolve())
+ );
+
+ outputStream.close();
+ log.trace("finished copy to", fullOutputFileName);
+ }
+}
+
+// The public LogManager object.
+export function LogManager(prefRoot, logNames, logFilePrefix) {
+ this._prefObservers = [];
+ this.init(prefRoot, logNames, logFilePrefix);
+}
+
+LogManager.StorageStreamAppender = StorageStreamAppender;
+
+LogManager.prototype = {
+ _cleaningUpFileLogs: false,
+
+ init(prefRoot, logNames, logFilePrefix) {
+ if (prefRoot instanceof Preferences) {
+ this._prefs = prefRoot;
+ } else {
+ this._prefs = new Preferences(prefRoot);
+ }
+
+ this.logFilePrefix = logFilePrefix;
+ if (!formatter) {
+ // Create a formatter and various appenders to attach to the logs.
+ formatter = new Log.BasicFormatter();
+ consoleAppender = new Log.ConsoleAppender(formatter);
+ dumpAppender = new Log.DumpAppender(formatter);
+ }
+
+ allBranches.add(this._prefs._branchStr);
+ // We create a preference observer for all our prefs so they are magically
+ // reflected if the pref changes after creation.
+ let setupAppender = (
+ appender,
+ prefName,
+ defaultLevel,
+ findSmallest = false
+ ) => {
+ let observer = newVal => {
+ let level = Log.Level[newVal] || defaultLevel;
+ if (findSmallest) {
+ // As some of our appenders have global impact (ie, there is only one
+ // place 'dump' goes to), we need to find the smallest value from all
+ // prefs controlling this appender.
+ // For example, if consumerA has dump=Debug then consumerB sets
+ // dump=Error, we need to keep dump=Debug so consumerA is respected.
+ for (let branch of allBranches) {
+ let lookPrefBranch = new Preferences(branch);
+ let lookVal = Log.Level[lookPrefBranch.get(prefName)];
+ if (lookVal && lookVal < level) {
+ level = lookVal;
+ }
+ }
+ }
+ appender.level = level;
+ };
+ this._prefs.observe(prefName, observer, this);
+ this._prefObservers.push([prefName, observer]);
+ // and call the observer now with the current pref value.
+ observer(this._prefs.get(prefName));
+ return observer;
+ };
+
+ this._observeConsolePref = setupAppender(
+ consoleAppender,
+ "log.appender.console",
+ Log.Level.Fatal,
+ true
+ );
+ this._observeDumpPref = setupAppender(
+ dumpAppender,
+ "log.appender.dump",
+ Log.Level.Error,
+ true
+ );
+
+ // The file appender doesn't get the special singleton behaviour.
+ let fapp = (this._fileAppender = new FlushableStorageAppender(formatter));
+ // the stream gets a default of Debug as the user must go out of their way
+ // to see the stuff spewed to it.
+ this._observeStreamPref = setupAppender(
+ fapp,
+ "log.appender.file.level",
+ Log.Level.Debug
+ );
+
+ // now attach the appenders to all our logs.
+ for (let logName of logNames) {
+ let log = Log.repository.getLogger(logName);
+ for (let appender of [fapp, dumpAppender, consoleAppender]) {
+ log.addAppender(appender);
+ }
+ }
+ // and use the first specified log as a "root" for our log.
+ this._log = Log.repository.getLogger(logNames[0] + ".LogManager");
+ },
+
+ /**
+ * Cleanup this instance
+ */
+ finalize() {
+ for (let [name, pref] of this._prefObservers) {
+ this._prefs.ignore(name, pref, this);
+ }
+ this._prefObservers = [];
+ try {
+ allBranches.delete(this._prefs._branchStr);
+ } catch (e) {}
+ this._prefs = null;
+ },
+
+ 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
+ * whether an "Error" log entry was written to any of the logs.
+ * Returns a promise that resolves on completion with either null (for no
+ * file written or on error), SUCCESS_LOG_WRITTEN if a "success" log was
+ * written, or ERROR_LOG_WRITTEN if an "error" log was written.
+ */
+ async resetFileLog() {
+ try {
+ let flushToFile;
+ let reasonPrefix;
+ let reason;
+ if (this._fileAppender.sawError) {
+ reason = this.ERROR_LOG_WRITTEN;
+ flushToFile = this._prefs.get("log.appender.file.logOnError", true);
+ reasonPrefix = "error";
+ } else {
+ reason = this.SUCCESS_LOG_WRITTEN;
+ flushToFile = this._prefs.get("log.appender.file.logOnSuccess", false);
+ reasonPrefix = "success";
+ }
+
+ // might as well avoid creating an input stream if we aren't going to use it.
+ if (!flushToFile) {
+ 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("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;
+ }
+ },
+
+ /**
+ * Finds all logs older than maxErrorAge and deletes them using async I/O.
+ */
+ cleanupLogs() {
+ let maxAge = this._prefs.get(
+ "log.appender.file.maxErrorAge",
+ DEFAULT_MAX_ERROR_AGE
+ );
+ let threshold = Date.now() - 1000 * maxAge;
+ this._log.debug("Log cleanup threshold time: " + threshold);
+
+ let shouldDelete = fileInfo => {
+ return fileInfo.lastModified < threshold;
+ };
+ return this._deleteLogFiles(shouldDelete);
+ },
+
+ /**
+ * Finds all logs and removes them.
+ */
+ removeAllLogs() {
+ return this._deleteLogFiles(() => true);
+ },
+
+ // Delete some log files. A callback is invoked for each found log file to
+ // determine if that file should be removed.
+ async _deleteLogFiles(cbShouldDelete) {
+ this._cleaningUpFileLogs = true;
+ let logDir = lazy.FileUtils.getDir(
+ "ProfD",
+ this._logFileSubDirectoryEntries
+ );
+ for (const path of await IOUtils.getChildren(logDir.path)) {
+ const name = PathUtils.filename(path);
+
+ if (!name.startsWith("error-") && !name.startsWith("success-")) {
+ continue;
+ }
+
+ try {
+ const info = await IOUtils.stat(path);
+ if (!cbShouldDelete(info)) {
+ continue;
+ }
+
+ this._log.trace(` > Cleanup removing ${name} (${info.lastModified})`);
+ await IOUtils.remove(path);
+ this._log.trace(`Deleted ${name}`);
+ } catch (ex) {
+ this._log.debug(
+ `Encountered error trying to clean up old log file ${name}`,
+ ex
+ );
+ }
+ }
+ 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"
+ );
+ },
+};
generated by cgit v1.2.3 (git 2.39.1) at 2024-11-02 10:48:48 +0000