michael@0: /* Any copyright is dedicated to the Public Domain.
michael@0:    http://creativecommons.org/publicdomain/zero/1.0/ */
michael@0: 
michael@0: const {utils: Cu} = Components;
michael@0: 
michael@0: Cu.import("resource://gre/modules/NetUtil.jsm");
michael@0: Cu.import("resource://gre/modules/osfile.jsm");
michael@0: 
michael@0: Cu.import("resource://gre/modules/Log.jsm");
michael@0: 
michael@0: let testFormatter = {
michael@0:   format: function format(message) {
michael@0:     return message.loggerName + "\t" +
michael@0:       message.levelDesc + "\t" +
michael@0:       message.message;
michael@0:   }
michael@0: };
michael@0: 
michael@0: function MockAppender(formatter) {
michael@0:   Log.Appender.call(this, formatter);
michael@0:   this.messages = [];
michael@0: }
michael@0: MockAppender.prototype = {
michael@0:   __proto__: Log.Appender.prototype,
michael@0: 
michael@0:   doAppend: function DApp_doAppend(message) {
michael@0:     this.messages.push(message);
michael@0:   }
michael@0: };
michael@0: 
michael@0: function run_test() {
michael@0:   run_next_test();
michael@0: }
michael@0: 
michael@0: add_task(function test_Logger() {
michael@0:   let log = Log.repository.getLogger("test.logger");
michael@0:   let appender = new MockAppender(new Log.BasicFormatter());
michael@0: 
michael@0:   log.level = Log.Level.Debug;
michael@0:   appender.level = Log.Level.Info;
michael@0:   log.addAppender(appender);
michael@0:   log.info("info test");
michael@0:   log.debug("this should be logged but not appended.");
michael@0: 
michael@0:   do_check_eq(appender.messages.length, 1);
michael@0: 
michael@0:   let msgRe = /\d+\ttest.logger\t\INFO\tinfo test/;
michael@0:   do_check_true(msgRe.test(appender.messages[0]));
michael@0: });
michael@0: 
michael@0: add_task(function test_Logger_parent() {
michael@0:   // Check whether parenting is correct
michael@0:   let grandparentLog = Log.repository.getLogger("grandparent");
michael@0:   let childLog = Log.repository.getLogger("grandparent.parent.child");
michael@0:   do_check_eq(childLog.parent.name, "grandparent");
michael@0: 
michael@0:   let parentLog = Log.repository.getLogger("grandparent.parent");
michael@0:   do_check_eq(childLog.parent.name, "grandparent.parent");
michael@0: 
michael@0:   // Check that appends are exactly in scope
michael@0:   let gpAppender = new MockAppender(new Log.BasicFormatter());
michael@0:   gpAppender.level = Log.Level.Info;
michael@0:   grandparentLog.addAppender(gpAppender);
michael@0:   childLog.info("child info test");
michael@0:   Log.repository.rootLogger.info("this shouldn't show up in gpAppender");
michael@0: 
michael@0:   do_check_eq(gpAppender.messages.length, 1);
michael@0:   do_check_true(gpAppender.messages[0].indexOf("child info test") > 0);
michael@0: });
michael@0: 
michael@0: add_test(function test_LoggerWithMessagePrefix() {
michael@0:   let log = Log.repository.getLogger("test.logger.prefix");
michael@0:   let appender = new MockAppender(new Log.MessageOnlyFormatter());
michael@0:   log.addAppender(appender);
michael@0: 
michael@0:   let prefixed = Log.repository.getLoggerWithMessagePrefix(
michael@0:     "test.logger.prefix", "prefix: ");
michael@0: 
michael@0:   log.warn("no prefix");
michael@0:   prefixed.warn("with prefix");
michael@0: 
michael@0:   Assert.equal(appender.messages.length, 2, "2 messages were logged.");
michael@0:   Assert.deepEqual(appender.messages, [
michael@0:     "no prefix",
michael@0:     "prefix: with prefix",
michael@0:   ], "Prefix logger works.");
michael@0: 
michael@0:   run_next_test();
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * A utility method for checking object equivalence.
michael@0:  * Fields with a reqular expression value in expected will be tested
michael@0:  * against the corresponding value in actual. Otherwise objects
michael@0:  * are expected to have the same keys and equal values.
michael@0:  */
michael@0: function checkObjects(expected, actual) {
michael@0:   do_check_true(expected instanceof Object);
michael@0:   do_check_true(actual instanceof Object);
michael@0:   for (let key in expected) {
michael@0:     do_check_neq(actual[key], undefined);
michael@0:     if (expected[key] instanceof RegExp) {
michael@0:       do_check_true(expected[key].test(actual[key].toString()));
michael@0:     } else {
michael@0:       if (expected[key] instanceof Object) {
michael@0:         checkObjects(expected[key], actual[key]);
michael@0:       } else {
michael@0:         do_check_eq(expected[key], actual[key]);
michael@0:       }
michael@0:     }
michael@0:   }
michael@0: 
michael@0:   for (let key in actual) {
michael@0:     do_check_neq(expected[key], undefined);
michael@0:   }
michael@0: }
michael@0: 
michael@0: add_task(function test_StructuredLogCommands() {
michael@0:   let appender = new MockAppender(new Log.StructuredFormatter());
michael@0:   let logger = Log.repository.getLogger("test.StructuredOutput");
michael@0:   logger.addAppender(appender);
michael@0:   logger.level = Log.Level.Info;
michael@0: 
michael@0:   logger.logStructured("test_message", {_message: "message string one"});
michael@0:   logger.logStructured("test_message", {_message: "message string two",
michael@0:                                         _level: "ERROR",
michael@0:                                         source_file: "test_Log.js"});
michael@0:   logger.logStructured("test_message");
michael@0:   logger.logStructured("test_message", {source_file: "test_Log.js",
michael@0:                                         message_position: 4});
michael@0: 
michael@0:   let messageOne = {"_time": /\d+/,
michael@0:                     "_namespace": "test.StructuredOutput",
michael@0:                     "_level": "INFO",
michael@0:                     "_message": "message string one",
michael@0:                     "action": "test_message"};
michael@0: 
michael@0:   let messageTwo = {"_time": /\d+/,
michael@0:                     "_namespace": "test.StructuredOutput",
michael@0:                     "_level": "ERROR",
michael@0:                     "_message": "message string two",
michael@0:                     "action": "test_message",
michael@0:                     "source_file": "test_Log.js"};
michael@0: 
michael@0:   let messageThree = {"_time": /\d+/,
michael@0:                       "_namespace": "test.StructuredOutput",
michael@0:                       "_level": "INFO",
michael@0:                       "action": "test_message"};
michael@0: 
michael@0:   let messageFour = {"_time": /\d+/,
michael@0:                      "_namespace": "test.StructuredOutput",
michael@0:                      "_level": "INFO",
michael@0:                      "action": "test_message",
michael@0:                      "source_file": "test_Log.js",
michael@0:                      "message_position": 4};
michael@0: 
michael@0:   checkObjects(messageOne, JSON.parse(appender.messages[0]));
michael@0:   checkObjects(messageTwo, JSON.parse(appender.messages[1]));
michael@0:   checkObjects(messageThree, JSON.parse(appender.messages[2]));
michael@0:   checkObjects(messageFour, JSON.parse(appender.messages[3]));
michael@0: 
michael@0:   let errored = false;
michael@0:   try {
michael@0:     logger.logStructured("", {_message: "invalid message"});
michael@0:   } catch (e) {
michael@0:     errored = true;
michael@0:     do_check_eq(e, "An action is required when logging a structured message.");
michael@0:   } finally {
michael@0:     do_check_true(errored);
michael@0:   }
michael@0: 
michael@0:   let errored = false;
michael@0:   try {
michael@0:     logger.logStructured("message_action", "invalid params");
michael@0:   } catch (e) {
michael@0:     errored = true;
michael@0:     do_check_eq(e, "The params argument is required to be an object.");
michael@0:   } finally {
michael@0:     do_check_true(errored);
michael@0:   }
michael@0: 
michael@0:   // Logging with unstructured interface should produce the same messages
michael@0:   // as the structured interface for these cases.
michael@0:   let appender = new MockAppender(new Log.StructuredFormatter());
michael@0:   let logger = Log.repository.getLogger("test.StructuredOutput1");
michael@0:   messageOne._namespace = "test.StructuredOutput1";
michael@0:   messageTwo._namespace = "test.StructuredOutput1";
michael@0:   logger.addAppender(appender);
michael@0:   logger.level = Log.Level.All;
michael@0:   logger.info("message string one", {action: "test_message"});
michael@0:   logger.error("message string two", {action: "test_message",
michael@0:                                       source_file: "test_Log.js"});
michael@0: 
michael@0:   checkObjects(messageOne, JSON.parse(appender.messages[0]));
michael@0:   checkObjects(messageTwo, JSON.parse(appender.messages[1]));
michael@0: });
michael@0: 
michael@0: add_task(function test_StorageStreamAppender() {
michael@0:   let appender = new Log.StorageStreamAppender(testFormatter);
michael@0:   do_check_eq(appender.getInputStream(), null);
michael@0: 
michael@0:   // Log to the storage stream and verify the log was written and can be
michael@0:   // read back.
michael@0:   let logger = Log.repository.getLogger("test.StorageStreamAppender");
michael@0:   logger.addAppender(appender);
michael@0:   logger.info("OHAI");
michael@0:   let inputStream = appender.getInputStream();
michael@0:   let data = NetUtil.readInputStreamToString(inputStream,
michael@0:                                              inputStream.available());
michael@0:   do_check_eq(data, "test.StorageStreamAppender\tINFO\tOHAI\n");
michael@0: 
michael@0:   // We can read it again even.
michael@0:   let sndInputStream = appender.getInputStream();
michael@0:   let sameData = NetUtil.readInputStreamToString(sndInputStream,
michael@0:                                                  sndInputStream.available());
michael@0:   do_check_eq(data, sameData);
michael@0: 
michael@0:   // Reset the appender and log some more.
michael@0:   appender.reset();
michael@0:   do_check_eq(appender.getInputStream(), null);
michael@0:   logger.debug("wut?!?");
michael@0:   inputStream = appender.getInputStream();
michael@0:   data = NetUtil.readInputStreamToString(inputStream,
michael@0:                                          inputStream.available());
michael@0:   do_check_eq(data, "test.StorageStreamAppender\tDEBUG\twut?!?\n");
michael@0: });
michael@0: 
michael@0: function fileContents(path) {
michael@0:   let decoder = new TextDecoder();
michael@0:   return OS.File.read(path).then(array => {
michael@0:     return decoder.decode(array);
michael@0:   });
michael@0: }
michael@0: 
michael@0: add_task(function test_FileAppender() {
michael@0:   // This directory does not exist yet
michael@0:   let dir = OS.Path.join(do_get_profile().path, "test_Log");
michael@0:   do_check_false(yield OS.File.exists(dir));
michael@0:   let path = OS.Path.join(dir, "test_FileAppender");
michael@0:   let appender = new Log.FileAppender(path, testFormatter);
michael@0:   let logger = Log.repository.getLogger("test.FileAppender");
michael@0:   logger.addAppender(appender);
michael@0: 
michael@0:   // Logging to a file that can't be created won't do harm.
michael@0:   do_check_false(yield OS.File.exists(path));
michael@0:   logger.info("OHAI!");
michael@0: 
michael@0:   yield OS.File.makeDir(dir);
michael@0:   logger.info("OHAI");
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.FileAppender\tINFO\tOHAI\n");
michael@0: 
michael@0:   logger.info("OHAI");
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.FileAppender\tINFO\tOHAI\n" +
michael@0:               "test.FileAppender\tINFO\tOHAI\n");
michael@0: 
michael@0:   // Reset the appender and log some more.
michael@0:   yield appender.reset();
michael@0:   do_check_false(yield OS.File.exists(path));
michael@0: 
michael@0:   logger.debug("O RLY?!?");
michael@0:   yield appender._lastWritePromise;
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.FileAppender\tDEBUG\tO RLY?!?\n");
michael@0: 
michael@0:   yield appender.reset();
michael@0:   logger.debug("1");
michael@0:   logger.info("2");
michael@0:   logger.info("3");
michael@0:   logger.info("4");
michael@0:   logger.info("5");
michael@0:   // Waiting on only the last promise should account for all of these.
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   // Messages ought to be logged in order.
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.FileAppender\tDEBUG\t1\n" +
michael@0:               "test.FileAppender\tINFO\t2\n" +
michael@0:               "test.FileAppender\tINFO\t3\n" +
michael@0:               "test.FileAppender\tINFO\t4\n" +
michael@0:               "test.FileAppender\tINFO\t5\n");
michael@0: });
michael@0: 
michael@0: add_task(function test_BoundedFileAppender() {
michael@0:   let dir = OS.Path.join(do_get_profile().path, "test_Log");
michael@0:   let path = OS.Path.join(dir, "test_BoundedFileAppender");
michael@0:   // This appender will hold about two lines at a time.
michael@0:   let appender = new Log.BoundedFileAppender(path, testFormatter, 40);
michael@0:   let logger = Log.repository.getLogger("test.BoundedFileAppender");
michael@0:   logger.addAppender(appender);
michael@0: 
michael@0:   logger.info("ONE");
michael@0:   logger.info("TWO");
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.BoundedFileAppender\tINFO\tONE\n" +
michael@0:               "test.BoundedFileAppender\tINFO\tTWO\n");
michael@0: 
michael@0:   logger.info("THREE");
michael@0:   logger.info("FOUR");
michael@0: 
michael@0:   do_check_neq(appender._removeFilePromise, undefined);
michael@0:   yield appender._removeFilePromise;
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.BoundedFileAppender\tINFO\tTHREE\n" +
michael@0:               "test.BoundedFileAppender\tINFO\tFOUR\n");
michael@0: 
michael@0:   yield appender.reset();
michael@0:   logger.info("ONE");
michael@0:   logger.info("TWO");
michael@0:   logger.info("THREE");
michael@0:   logger.info("FOUR");
michael@0: 
michael@0:   do_check_neq(appender._removeFilePromise, undefined);
michael@0:   yield appender._removeFilePromise;
michael@0:   yield appender._lastWritePromise;
michael@0: 
michael@0:   do_check_eq((yield fileContents(path)),
michael@0:               "test.BoundedFileAppender\tINFO\tTHREE\n" +
michael@0:               "test.BoundedFileAppender\tINFO\tFOUR\n");
michael@0: 
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * Test parameter formatting.
michael@0:  */
michael@0: add_task(function log_message_with_params() {
michael@0:   let formatter = new Log.BasicFormatter();
michael@0: 
michael@0:   function formatMessage(text, params) {
michael@0:     let full = formatter.format(new Log.LogMessage("test.logger", Log.Level.Warn, text, params));
michael@0:     return full.split("\t")[3];
michael@0:   }
michael@0: 
michael@0:   // Strings are substituted directly.
michael@0:   do_check_eq(formatMessage("String is ${foo}", {foo: "bar"}),
michael@0:               "String is bar");
michael@0: 
michael@0:   // Numbers are substituted.
michael@0:   do_check_eq(formatMessage("Number is ${number}", {number: 47}),
michael@0:               "Number is 47")
michael@0: 
michael@0:   // The entire params object is JSON-formatted and substituted.
michael@0:   do_check_eq(formatMessage("Object is ${}", {foo: "bar"}),
michael@0:               'Object is {"foo":"bar"}');
michael@0: 
michael@0:   // An object nested inside params is JSON-formatted and substituted.
michael@0:   do_check_eq(formatMessage("Sub object is ${sub}", {sub: {foo: "bar"}}),
michael@0:                 'Sub object is {"foo":"bar"}');
michael@0: 
michael@0:   // The substitution field is missing from params. Leave the placeholder behind
michael@0:   // to make the mistake obvious.
michael@0:   do_check_eq(formatMessage("Missing object is ${missing}", {}),
michael@0:               'Missing object is ${missing}');
michael@0: 
michael@0:   // Make sure we don't treat the parameter name 'false' as a falsey value.
michael@0:   do_check_eq(formatMessage("False is ${false}", {false: true}),
michael@0:               'False is true');
michael@0: 
michael@0:   // If an object has a .toJSON method, the formatter uses it.
michael@0:   let ob = function() {};
michael@0:   ob.toJSON = function() {return {sneaky: "value"}};
michael@0:   do_check_eq(formatMessage("JSON is ${sub}", {sub: ob}),
michael@0:               'JSON is {"sneaky":"value"}');
michael@0: 
michael@0:   // Fall back to .toSource() if JSON.stringify() fails on an object.
michael@0:   let ob = function() {};
michael@0:   ob.toJSON = function() {throw "oh noes JSON"};
michael@0:   do_check_eq(formatMessage("Fail is ${sub}", {sub: ob}),
michael@0:               'Fail is (function () {})');
michael@0: 
michael@0:   // Fall back to .toString if both .toJSON and .toSource fail.
michael@0:   ob.toSource = function() {throw "oh noes SOURCE"};
michael@0:   do_check_eq(formatMessage("Fail is ${sub}", {sub: ob}),
michael@0:               'Fail is function () {}');
michael@0: 
michael@0:   // Fall back to '[object]' if .toJSON, .toSource and .toString fail.
michael@0:   ob.toString = function() {throw "oh noes STRING"};
michael@0:   do_check_eq(formatMessage("Fail is ${sub}", {sub: ob}),
michael@0:               'Fail is [object]');
michael@0: 
michael@0:   // If params are passed but there are no substitution in the text
michael@0:   // we JSON format and append the entire parameters object.
michael@0:   do_check_eq(formatMessage("Text with no subs", {a: "b", c: "d"}),
michael@0:               'Text with no subs: {"a":"b","c":"d"}');
michael@0: 
michael@0:   // If we substitute one parameter but not the other,
michael@0:   // we ignore any params that aren't substituted.
michael@0:   do_check_eq(formatMessage("Text with partial sub ${a}", {a: "b", c: "d"}),
michael@0:               'Text with partial sub b');
michael@0: 
michael@0:   // We don't format internal fields stored in params.
michael@0:   do_check_eq(formatMessage("Params with _ ${}", {a: "b", _c: "d", _level:20, _message:"froo",
michael@0:                                                   _time:123456, _namespace:"here.there"}),
michael@0:               'Params with _ {"a":"b","_c":"d"}');
michael@0: 
michael@0:   // Don't print an empty params holder if all params are internal.
michael@0:   do_check_eq(formatMessage("All params internal", {_level:20, _message:"froo",
michael@0:                                                     _time:123456, _namespace:"here.there"}),
michael@0:               'All params internal');
michael@0: 
michael@0:   // Format params with null and undefined values.
michael@0:   do_check_eq(formatMessage("Null ${n} undefined ${u}", {n: null, u: undefined}),
michael@0:               'Null null undefined undefined');
michael@0: 
michael@0:   // Format params with number, bool, and Object/String type.
michael@0:   do_check_eq(formatMessage("number ${n} boolean ${b} boxed Boolean ${bx} String ${s}",
michael@0:                             {n: 45, b: false, bx: new Boolean(true), s: new String("whatevs")}),
michael@0:               'number 45 boolean false boxed Boolean true String whatevs');
michael@0: 
michael@0:   /*
michael@0:    * Check that errors get special formatting if they're formatted directly as
michael@0:    * a named param or they're the only param, but not if they're a field in a
michael@0:    * larger structure.
michael@0:    */
michael@0:   let err = Components.Exception("test exception", Components.results.NS_ERROR_FAILURE);
michael@0:   let str = formatMessage("Exception is ${}", err);
michael@0:   do_check_true(str.contains('Exception is [Exception... "test exception"'));
michael@0:   do_check_true(str.contains("(NS_ERROR_FAILURE)"));
michael@0:   let str = formatMessage("Exception is", err);
michael@0:   do_check_true(str.contains('Exception is: [Exception... "test exception"'));
michael@0:   let str = formatMessage("Exception is ${error}", {error: err});
michael@0:   do_check_true(str.contains('Exception is [Exception... "test exception"'));
michael@0:   let str = formatMessage("Exception is", {_error: err});
michael@0:   do_print(str);
michael@0:   // Exceptions buried inside objects are formatted badly.
michael@0:   do_check_true(str.contains('Exception is: {"_error":{}'));
michael@0:   // If the message text is null, the message contains only the formatted params object.
michael@0:   let str = formatMessage(null, err);
michael@0:   do_check_true(str.startsWith('[Exception... "test exception"'));
michael@0:   // If the text is null and 'params' is a String object, the message is exactly that string.
michael@0:   let str = formatMessage(null, new String("String in place of params"));
michael@0:   do_check_eq(str, "String in place of params");
michael@0: 
michael@0:   // We use object.valueOf() internally; make sure a broken valueOf() method
michael@0:   // doesn't cause the logger to fail.
michael@0:   let vOf = {a: 1, valueOf: function() {throw "oh noes valueOf"}};
michael@0:   do_check_eq(formatMessage("Broken valueOf ${}", vOf),
michael@0:               'Broken valueOf ({a:1, valueOf:(function () {throw "oh noes valueOf"})})');
michael@0: 
michael@0:   // Test edge cases of bad data to formatter:
michael@0:   // If 'params' is not an object, format it as a basic type.
michael@0:   do_check_eq(formatMessage("non-object no subst", 1),
michael@0:               'non-object no subst: 1');
michael@0:   do_check_eq(formatMessage("non-object all subst ${}", 2),
michael@0:               'non-object all subst 2');
michael@0:   // If 'params' is not an object, no named substitutions can succeed;
michael@0:   // therefore we leave the placeholder and append the formatted params.
michael@0:   do_check_eq(formatMessage("non-object named subst ${junk} space", 3),
michael@0:               'non-object named subst ${junk} space: 3');
michael@0:   // If there are no params, we leave behind the placeholders in the text.
michael@0:   do_check_eq(formatMessage("no params ${missing}", undefined),
michael@0:               'no params ${missing}');
michael@0:   // If params doesn't contain any of the tags requested in the text,
michael@0:   // we leave them all behind and append the formatted params.
michael@0:   do_check_eq(formatMessage("object missing tag ${missing} space", {mising: "not here"}),
michael@0:               'object missing tag ${missing} space: {"mising":"not here"}');
michael@0:   // If we are given null text and no params, the resulting formatted message is empty.
michael@0:   do_check_eq(formatMessage(null), '');
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * If we call a log function with a non-string object in place of the text
michael@0:  * argument, and no parameters, treat that the same as logging empty text
michael@0:  * with the object argument as parameters. This makes the log useful when the
michael@0:  * caller does "catch(err) {logger.error(err)}"
michael@0:  */
michael@0: add_task(function test_log_err_only() {
michael@0:   let log = Log.repository.getLogger("error.only");
michael@0:   let testFormatter = { format: msg => msg };
michael@0:   let appender = new MockAppender(testFormatter);
michael@0:   log.addAppender(appender);
michael@0: 
michael@0:   /*
michael@0:    * Check that log.error(err) is treated the same as
michael@0:    * log.error(null, err) by the logMessage constructor; the formatMessage()
michael@0:    * tests above ensure that the combination of null text and an error object
michael@0:    * is formatted correctly.
michael@0:    */
michael@0:   try {
michael@0:     eval("javascript syntax error");
michael@0:   }
michael@0:   catch (e) {
michael@0:     log.error(e);
michael@0:     msg = appender.messages.pop();
michael@0:     do_check_eq(msg.message, null);
michael@0:     do_check_eq(msg.params, e);
michael@0:   }
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * Test logStructured() messages through basic formatter.
michael@0:  */
michael@0: add_task(function test_structured_basic() {
michael@0:   let log = Log.repository.getLogger("test.logger");
michael@0:   let appender = new MockAppender(new Log.BasicFormatter());
michael@0: 
michael@0:   log.level = Log.Level.Info;
michael@0:   appender.level = Log.Level.Info;
michael@0:   log.addAppender(appender);
michael@0: 
michael@0:   // A structured entry with no _message is treated the same as log./level/(null, params)
michael@0:   // except the 'action' field is added to the object.
michael@0:   log.logStructured("action", {data: "structure"});
michael@0:   do_check_eq(appender.messages.length, 1);
michael@0:   do_check_true(appender.messages[0].contains('{"data":"structure","action":"action"}'));
michael@0: 
michael@0:   // A structured entry with _message and substitution is treated the same as
michael@0:   // log./level/(null, params).
michael@0:   log.logStructured("action", {_message: "Structured sub ${data}", data: "structure"});
michael@0:   do_check_eq(appender.messages.length, 2);
michael@0:   do_print(appender.messages[1]);
michael@0:   do_check_true(appender.messages[1].contains('Structured sub structure'));
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * Test that all the basic logger methods pass the message and params through to the appender.
michael@0:  */
michael@0: add_task(function log_message_with_params() {
michael@0:   let log = Log.repository.getLogger("error.logger");
michael@0:   let testFormatter = { format: msg => msg };
michael@0:   let appender = new MockAppender(testFormatter);
michael@0:   log.addAppender(appender);
michael@0: 
michael@0:   let testParams = {a:1, b:2};
michael@0:   log.fatal("Test fatal", testParams);
michael@0:   log.error("Test error", testParams);
michael@0:   log.warn("Test warn", testParams);
michael@0:   log.info("Test info", testParams);
michael@0:   log.config("Test config", testParams);
michael@0:   log.debug("Test debug", testParams);
michael@0:   log.trace("Test trace", testParams);
michael@0:   do_check_eq(appender.messages.length, 7);
michael@0:   for (let msg of appender.messages) {
michael@0:     do_check_true(msg.params === testParams);
michael@0:     do_check_true(msg.message.startsWith("Test "));
michael@0:   }
michael@0: });
michael@0: 
michael@0: /*
michael@0:  * Check that we format JS Errors reasonably.
michael@0:  */
michael@0: add_task(function format_errors() {
michael@0:   let pFormat = new Log.ParameterFormatter();
michael@0: 
michael@0:   // Test that subclasses of Error are recognized as errors.
michael@0:   err = new ReferenceError("Ref Error", "ERROR_FILE", 28);
michael@0:   str = pFormat.format(err);
michael@0:   do_check_true(str.contains("ReferenceError"));
michael@0:   do_check_true(str.contains("ERROR_FILE:28"));
michael@0:   do_check_true(str.contains("Ref Error"));
michael@0: 
michael@0:   // Test that JS-generated Errors are recognized and formatted.
michael@0:   try {
michael@0:     eval("javascript syntax error");
michael@0:   }
michael@0:   catch (e) {
michael@0:     str = pFormat.format(e);
michael@0:     do_check_true(str.contains("SyntaxError: missing ;"));
michael@0:     // Make sure we identified it as an Error and formatted the error location as
michael@0:     // lineNumber:columnNumber.
michael@0:     do_check_true(str.contains(":1:11)"));
michael@0:   }
michael@0: });