Bug 1400414 - Defer formatting work in sync logging until we are sure we actually will write the log. r?markh
MozReview-Commit-ID: Bx2KTzVRUzF
--- a/services/common/logmanager.js
+++ b/services/common/logmanager.js
@@ -46,36 +46,65 @@ var allBranches = new Set();
// 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)
function FlushableStorageAppender(formatter) {
Log.StorageStreamAppender.call(this, formatter);
this.sawError = false;
+ this.pendingMessages = [];
+ this._lazy = false;
}
FlushableStorageAppender.prototype = {
__proto__: Log.StorageStreamAppender.prototype,
+ get lazy() {
+ return this._lazy;
+ },
+
+ set lazy(v) {
+ if (this._lazy && !v) {
+ this._flushPending();
+ }
+ this._lazy = v;
+ },
+
append(message) {
if (message.level >= Log.Level.Error) {
this.sawError = true;
}
- Log.StorageStreamAppender.prototype.append.call(this, message);
+
+ if (this.lazy) {
+ this.pendingMessages.push(message);
+ } else {
+ Log.StorageStreamAppender.prototype.append.call(this, message);
+ }
},
reset() {
Log.StorageStreamAppender.prototype.reset.call(this);
+ this.pendingMessages.length = 0;
this.sawError = false;
},
+ _flushPending() {
+ for (let i = 0; i < this.pendingMessages.length; ++i) {
+ Log.StorageStreamAppender.prototype.append.call(this, this.pendingMessages[i]);
+ }
+ this.pendingMessages.length = 0;
+ },
+
// 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) {
+ if (this._lazy) {
+ this._flushPending();
+ }
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());
@@ -182,16 +211,20 @@ LogManager.prototype = {
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);
+ // There's no point to deferring the formatting and writing if we're always
+ // going to do it anyway (which is effectively the case if logOnSuccess is set).
+ fapp.lazy = !this._prefs.get("log.appender.file.logOnSuccess", false);
+
// 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]) {
--- a/services/common/tests/unit/test_logmanager.js
+++ b/services/common/tests/unit/test_logmanager.js
@@ -128,53 +128,53 @@ add_task(async function test_logFileErro
// One error log file exists.
checkLogFile("error");
lm.finalize();
});
// Test that we correctly write success logs.
add_task(async function test_logFileSuccess() {
- Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnError", false);
- Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnSuccess", false);
-
- let lm = new LogManager("log-manager.test.", ["TestLog2"], "test");
+ for (let laziness of [true, false]) {
+ Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnError", false);
+ Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnSuccess", false);
+ let lm = new LogManager("log-manager.test.", ["TestLog2"], "test");
+ lm._fileAppender.lazy = laziness;
+ let log = Log.repository.getLogger("TestLog2");
+ log.info("an info message");
+ await lm.resetFileLog();
+ // Zero log files exist.
+ checkLogFile(null);
- let log = Log.repository.getLogger("TestLog2");
- log.info("an info message");
- await lm.resetFileLog();
- // Zero log files exist.
- checkLogFile(null);
+ // Reset logOnSuccess and do it again - log should appear.
+ Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnSuccess", true);
+ log.info("an info message");
+ await lm.resetFileLog();
- // Reset logOnSuccess and do it again - log should appear.
- Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnSuccess", true);
- log.info("an info message");
- await lm.resetFileLog();
-
- checkLogFile("success");
+ checkLogFile("success");
- // Now test with no "reason" specified and no "error" record.
- log.info("an info message");
- await lm.resetFileLog();
- // should get a "success" entry.
- checkLogFile("success");
+ // Now test with no "reason" specified and no "error" record.
+ log.info("an info message");
+ await lm.resetFileLog();
+ // should get a "success" entry.
+ checkLogFile("success");
- // With no "reason" and an error record - should get no success log.
- log.error("an error message");
- await lm.resetFileLog();
- // should get no entry
- checkLogFile(null);
+ // With no "reason" and an error record - should get no success log.
+ log.error("an error message");
+ await lm.resetFileLog();
+ // should get no entry
+ checkLogFile(null);
- // And finally now with no error, to ensure that the fact we had an error
- // previously doesn't persist after the .resetFileLog call.
- log.info("an info message");
- await lm.resetFileLog();
- checkLogFile("success");
-
- lm.finalize();
+ // And finally now with no error, to ensure that the fact we had an error
+ // previously doesn't persist after the .resetFileLog call.
+ log.info("an info message");
+ await lm.resetFileLog();
+ checkLogFile("success");
+ lm.finalize();
+ }
});
// Test that we correctly write error logs.
add_task(async function test_logFileError() {
Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnError", false);
Services.prefs.setBoolPref("log-manager.test.log.appender.file.logOnSuccess", false);
let lm = new LogManager("log-manager.test.", ["TestLog2"], "test");