toolkit/modules/Log.jsm

   1 /* This Source Code Form is subject to the terms of the Mozilla Public
   2  * License, v. 2.0. If a copy of the MPL was not distributed with this
   3  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
   4
   5 "use strict";
   6
   7 var EXPORTED_SYMBOLS = ["Log"];
   8
   9 const { XPCOMUtils } = ChromeUtils.import(
  10   "resource://gre/modules/XPCOMUtils.jsm"
  11 );
  12 ChromeUtils.defineModuleGetter(
  13   this,
  14   "Services",
  15   "resource://gre/modules/Services.jsm"
  16 );
  17 const INTERNAL_FIELDS = new Set(["_level", "_message", "_time", "_namespace"]);
  18
  19 /*
  20  * Dump a message everywhere we can if we have a failure.
  21  */
  22 function dumpError(text) {
  23   dump(text + "\n");
  24   Cu.reportError(text);
  25 }
  26
  27 var Log = {
  28   Level: {
  29     Fatal: 70,
  30     Error: 60,
  31     Warn: 50,
  32     Info: 40,
  33     Config: 30,
  34     Debug: 20,
  35     Trace: 10,
  36     All: -1, // We don't want All to be falsy.
  37     Desc: {
  38       70: "FATAL",
  39       60: "ERROR",
  40       50: "WARN",
  41       40: "INFO",
  42       30: "CONFIG",
  43       20: "DEBUG",
  44       10: "TRACE",
  45       "-1": "ALL",
  46     },
  47     Numbers: {
  48       FATAL: 70,
  49       ERROR: 60,
  50       WARN: 50,
  51       INFO: 40,
  52       CONFIG: 30,
  53       DEBUG: 20,
  54       TRACE: 10,
  55       ALL: -1,
  56     },
  57   },
  58
  59   get repository() {
  60     delete Log.repository;
  61     Log.repository = new LoggerRepository();
  62     return Log.repository;
  63   },
  64   set repository(value) {
  65     delete Log.repository;
  66     Log.repository = value;
  67   },
  68
  69   _formatError(e) {
  70     let result = String(e);
  71     if (e.fileName) {
  72       let loc = [e.fileName];
  73       if (e.lineNumber) {
  74         loc.push(e.lineNumber);
  75       }
  76       if (e.columnNumber) {
  77         loc.push(e.columnNumber);
  78       }
  79       result += `(${loc.join(":")})`;
  80     }
  81     return `${result} ${Log.stackTrace(e)}`;
  82   },
  83
  84   // This is for back compatibility with services/common/utils.js; we duplicate
  85   // some of the logic in ParameterFormatter
  86   exceptionStr(e) {
  87     if (!e) {
  88       return String(e);
  89     }
  90     if (e instanceof Ci.nsIException) {
  91       return `${e} ${Log.stackTrace(e)}`;
  92     } else if (isError(e)) {
  93       return Log._formatError(e);
  94     }
  95     // else
  96     let message = e.message || e;
  97     return `${message} ${Log.stackTrace(e)}`;
  98   },
  99
 100   stackTrace(e) {
 101     // Wrapped nsIException
 102     if (e.location) {
 103       let frame = e.location;
 104       let output = [];
 105       while (frame) {
 106         // Works on frames or exceptions, munges file:// URIs to shorten the paths
 107         // FIXME: filename munging is sort of hackish, might be confusing if
 108         // there are multiple extensions with similar filenames
 109         let str = "<file:unknown>";
 110
 111         let file = frame.filename || frame.fileName;
 112         if (file) {
 113           str = file.replace(/^(?:chrome|file):.*?([^\/\.]+\.\w+)$/, "$1");
 114         }
 115
 116         if (frame.lineNumber) {
 117           str += ":" + frame.lineNumber;
 118         }
 119
 120         if (frame.name) {
 121           str = frame.name + "()@" + str;
 122         }
 123
 124         if (str) {
 125           output.push(str);
 126         }
 127         frame = frame.caller;
 128       }
 129       return `Stack trace: ${output.join("\n")}`;
 130     }
 131     // Standard JS exception
 132     if (e.stack) {
 133       let stack = e.stack;
 134       return (
 135         "JS Stack trace: " +
 136         stack.trim().replace(/@[^@]*?([^\/\.]+\.\w+:)/g, "@$1")
 137       );
 138     }
 139
 140     return "No traceback available";
 141   },
 142 };
 143
 144 /*
 145  * LogMessage
 146  * Encapsulates a single log event's data
 147  */
 148 class LogMessage {
 149   constructor(loggerName, level, message, params) {
 150     this.loggerName = loggerName;
 151     this.level = level;
 152     /*
 153      * Special case to handle "log./level/(object)", for example logging a caught exception
 154      * without providing text or params like: catch(e) { logger.warn(e) }
 155      * Treating this as an empty text with the object in the 'params' field causes the
 156      * object to be formatted properly by BasicFormatter.
 157      */
 158     if (
 159       !params &&
 160       message &&
 161       typeof message == "object" &&
 162       typeof message.valueOf() != "string"
 163     ) {
 164       this.message = null;
 165       this.params = message;
 166     } else {
 167       // If the message text is empty, or a string, or a String object, normal handling
 168       this.message = message;
 169       this.params = params;
 170     }
 171
 172     // The _structured field will correspond to whether this message is to
 173     // be interpreted as a structured message.
 174     this._structured = this.params && this.params.action;
 175     this.time = Date.now();
 176   }
 177
 178   get levelDesc() {
 179     if (this.level in Log.Level.Desc) {
 180       return Log.Level.Desc[this.level];
 181     }
 182     return "UNKNOWN";
 183   }
 184
 185   toString() {
 186     let msg = `${this.time} ${this.level} ${this.message}`;
 187     if (this.params) {
 188       msg += ` ${JSON.stringify(this.params)}`;
 189     }
 190     return `LogMessage [${msg}]`;
 191   }
 192 }
 193
 194 /*
 195  * Logger
 196  * Hierarchical version.  Logs to all appenders, assigned or inherited
 197  */
 198
 199 class Logger {
 200   constructor(name, repository) {
 201     if (!repository) {
 202       repository = Log.repository;
 203     }
 204     this._name = name;
 205     this.children = [];
 206     this.ownAppenders = [];
 207     this.appenders = [];
 208     this._repository = repository;
 209
 210     this._levelPrefName = null;
 211     this._levelPrefValue = null;
 212     this._level = null;
 213     this._parent = null;
 214   }
 215
 216   get name() {
 217     return this._name;
 218   }
 219
 220   get level() {
 221     if (this._levelPrefName) {
 222       // We've been asked to use a preference to configure the logs. If the
 223       // pref has a value we use it, otherwise we continue to use the parent.
 224       const lpv = this._levelPrefValue;
 225       if (lpv) {
 226         const levelValue = Log.Level[lpv];
 227         if (levelValue) {
 228           // stash it in _level just in case a future value of the pref is
 229           // invalid, in which case we end up continuing to use this value.
 230           this._level = levelValue;
 231           return levelValue;
 232         }
 233       } else {
 234         // in case the pref has transitioned from a value to no value, we reset
 235         // this._level and fall through to using the parent.
 236         this._level = null;
 237       }
 238     }
 239     if (this._level != null) {
 240       return this._level;
 241     }
 242     if (this.parent) {
 243       return this.parent.level;
 244     }
 245     dumpError("Log warning: root logger configuration error: no level defined");
 246     return Log.Level.All;
 247   }
 248   set level(level) {
 249     if (this._levelPrefName) {
 250       // I guess we could honor this by nuking this._levelPrefValue, but it
 251       // almost certainly implies confusion, so we'll warn and ignore.
 252       dumpError(
 253         `Log warning: The log '${this.name}' is configured to use ` +
 254           `the preference '${this._levelPrefName}' - you must adjust ` +
 255           `the level by setting this preference, not by using the ` +
 256           `level setter`
 257       );
 258       return;
 259     }
 260     this._level = level;
 261   }
 262
 263   get parent() {
 264     return this._parent;
 265   }
 266   set parent(parent) {
 267     if (this._parent == parent) {
 268       return;
 269     }
 270     // Remove ourselves from parent's children
 271     if (this._parent) {
 272       let index = this._parent.children.indexOf(this);
 273       if (index != -1) {
 274         this._parent.children.splice(index, 1);
 275       }
 276     }
 277     this._parent = parent;
 278     parent.children.push(this);
 279     this.updateAppenders();
 280   }
 281
 282   manageLevelFromPref(prefName) {
 283     if (prefName == this._levelPrefName) {
 284       // We've already configured this log with an observer for that pref.
 285       return;
 286     }
 287     if (this._levelPrefName) {
 288       dumpError(
 289         `The log '${this.name}' is already configured with the ` +
 290           `preference '${this._levelPrefName}' - ignoring request to ` +
 291           `also use the preference '${prefName}'`
 292       );
 293       return;
 294     }
 295     this._levelPrefName = prefName;
 296     XPCOMUtils.defineLazyPreferenceGetter(this, "_levelPrefValue", prefName);
 297   }
 298
 299   updateAppenders() {
 300     if (this._parent) {
 301       let notOwnAppenders = this._parent.appenders.filter(function(appender) {
 302         return !this.ownAppenders.includes(appender);
 303       }, this);
 304       this.appenders = notOwnAppenders.concat(this.ownAppenders);
 305     } else {
 306       this.appenders = this.ownAppenders.slice();
 307     }
 308
 309     // Update children's appenders.
 310     for (let i = 0; i < this.children.length; i++) {
 311       this.children[i].updateAppenders();
 312     }
 313   }
 314
 315   addAppender(appender) {
 316     if (this.ownAppenders.includes(appender)) {
 317       return;
 318     }
 319     this.ownAppenders.push(appender);
 320     this.updateAppenders();
 321   }
 322
 323   removeAppender(appender) {
 324     let index = this.ownAppenders.indexOf(appender);
 325     if (index == -1) {
 326       return;
 327     }
 328     this.ownAppenders.splice(index, 1);
 329     this.updateAppenders();
 330   }
 331
 332   _unpackTemplateLiteral(string, params) {
 333     if (!Array.isArray(params)) {
 334       // Regular log() call.
 335       return [string, params];
 336     }
 337
 338     if (!Array.isArray(string)) {
 339       // Not using template literal. However params was packed into an array by
 340       // the this.[level] call, so we need to unpack it here.
 341       return [string, params[0]];
 342     }
 343
 344     // We're using template literal format (logger.warn `foo ${bar}`). Turn the
 345     // template strings into one string containing "${0}"..."${n}" tokens, and
 346     // feed it to the basic formatter. The formatter will treat the numbers as
 347     // indices into the params array, and convert the tokens to the params.
 348
 349     if (!params.length) {
 350       // No params; we need to set params to undefined, so the formatter
 351       // doesn't try to output the params array.
 352       return [string[0], undefined];
 353     }
 354
 355     let concat = string[0];
 356     for (let i = 0; i < params.length; i++) {
 357       concat += `\${${i}}${string[i + 1]}`;
 358     }
 359     return [concat, params];
 360   }
 361
 362   log(level, string, params) {
 363     if (this.level > level) {
 364       return;
 365     }
 366
 367     // Hold off on creating the message object until we actually have
 368     // an appender that's responsible.
 369     let message;
 370     let appenders = this.appenders;
 371     for (let appender of appenders) {
 372       if (appender.level > level) {
 373         continue;
 374       }
 375       if (!message) {
 376         [string, params] = this._unpackTemplateLiteral(string, params);
 377         message = new LogMessage(this._name, level, string, params);
 378       }
 379       appender.append(message);
 380     }
 381   }
 382
 383   fatal(string, ...params) {
 384     this.log(Log.Level.Fatal, string, params);
 385   }
 386   error(string, ...params) {
 387     this.log(Log.Level.Error, string, params);
 388   }
 389   warn(string, ...params) {
 390     this.log(Log.Level.Warn, string, params);
 391   }
 392   info(string, ...params) {
 393     this.log(Log.Level.Info, string, params);
 394   }
 395   config(string, ...params) {
 396     this.log(Log.Level.Config, string, params);
 397   }
 398   debug(string, ...params) {
 399     this.log(Log.Level.Debug, string, params);
 400   }
 401   trace(string, ...params) {
 402     this.log(Log.Level.Trace, string, params);
 403   }
 404 }
 405
 406 /*
 407  * LoggerRepository
 408  * Implements a hierarchy of Loggers
 409  */
 410
 411 class LoggerRepository {
 412   constructor() {
 413     this._loggers = {};
 414     this._rootLogger = null;
 415   }
 416
 417   get rootLogger() {
 418     if (!this._rootLogger) {
 419       this._rootLogger = new Logger("root", this);
 420       this._rootLogger.level = Log.Level.All;
 421     }
 422     return this._rootLogger;
 423   }
 424   set rootLogger(logger) {
 425     throw new Error("Cannot change the root logger");
 426   }
 427
 428   _updateParents(name) {
 429     let pieces = name.split(".");
 430     let cur, parent;
 431
 432     // find the closest parent
 433     // don't test for the logger name itself, as there's a chance it's already
 434     // there in this._loggers
 435     for (let i = 0; i < pieces.length - 1; i++) {
 436       if (cur) {
 437         cur += "." + pieces[i];
 438       } else {
 439         cur = pieces[i];
 440       }
 441       if (cur in this._loggers) {
 442         parent = cur;
 443       }
 444     }
 445
 446     // if we didn't assign a parent above, there is no parent
 447     if (!parent) {
 448       this._loggers[name].parent = this.rootLogger;
 449     } else {
 450       this._loggers[name].parent = this._loggers[parent];
 451     }
 452
 453     // trigger updates for any possible descendants of this logger
 454     for (let logger in this._loggers) {
 455       if (logger != name && logger.indexOf(name) == 0) {
 456         this._updateParents(logger);
 457       }
 458     }
 459   }
 460
 461   /**
 462    * Obtain a named Logger.
 463    *
 464    * The returned Logger instance for a particular name is shared among
 465    * all callers. In other words, if two consumers call getLogger("foo"),
 466    * they will both have a reference to the same object.
 467    *
 468    * @return Logger
 469    */
 470   getLogger(name) {
 471     if (name in this._loggers) {
 472       return this._loggers[name];
 473     }
 474     this._loggers[name] = new Logger(name, this);
 475     this._updateParents(name);
 476     return this._loggers[name];
 477   }
 478
 479   /**
 480    * Obtain a Logger that logs all string messages with a prefix.
 481    *
 482    * A common pattern is to have separate Logger instances for each instance
 483    * of an object. But, you still want to distinguish between each instance.
 484    * Since Log.repository.getLogger() returns shared Logger objects,
 485    * monkeypatching one Logger modifies them all.
 486    *
 487    * This function returns a new object with a prototype chain that chains
 488    * up to the original Logger instance. The new prototype has log functions
 489    * that prefix content to each message.
 490    *
 491    * @param name
 492    *        (string) The Logger to retrieve.
 493    * @param prefix
 494    *        (string) The string to prefix each logged message with.
 495    */
 496   getLoggerWithMessagePrefix(name, prefix) {
 497     let log = this.getLogger(name);
 498
 499     let proxy = Object.create(log);
 500     proxy.log = (level, string, params) => {
 501       if (Array.isArray(string) && Array.isArray(params)) {
 502         // Template literal.
 503         // We cannot change the original array, so create a new one.
 504         string = [prefix + string[0]].concat(string.slice(1));
 505       } else {
 506         string = prefix + string; // Regular string.
 507       }
 508       return log.log(level, string, params);
 509     };
 510     return proxy;
 511   }
 512 }
 513
 514 /*
 515  * Formatters
 516  * These massage a LogMessage into whatever output is desired.
 517  */
 518
 519 // Basic formatter that doesn't do anything fancy.
 520 class BasicFormatter {
 521   constructor(dateFormat) {
 522     if (dateFormat) {
 523       this.dateFormat = dateFormat;
 524     }
 525     this.parameterFormatter = new ParameterFormatter();
 526   }
 527
 528   /**
 529    * Format the text of a message with optional parameters.
 530    * If the text contains ${identifier}, replace that with
 531    * the value of params[identifier]; if ${}, replace that with
 532    * the entire params object. If no params have been substituted
 533    * into the text, format the entire object and append that
 534    * to the message.
 535    */
 536   formatText(message) {
 537     let params = message.params;
 538     if (typeof params == "undefined") {
 539       return message.message || "";
 540     }
 541     // Defensive handling of non-object params
 542     // We could add a special case for NSRESULT values here...
 543     let pIsObject = typeof params == "object" || typeof params == "function";
 544
 545     // if we have params, try and find substitutions.
 546     if (this.parameterFormatter) {
 547       // have we successfully substituted any parameters into the message?
 548       // in the log message
 549       let subDone = false;
 550       let regex = /\$\{(\S*?)\}/g;
 551       let textParts = [];
 552       if (message.message) {
 553         textParts.push(
 554           message.message.replace(regex, (_, sub) => {
 555             // ${foo} means use the params['foo']
 556             if (sub) {
 557               if (pIsObject && sub in message.params) {
 558                 subDone = true;
 559                 return this.parameterFormatter.format(message.params[sub]);
 560               }
 561               return "${" + sub + "}";
 562             }
 563             // ${} means use the entire params object.
 564             subDone = true;
 565             return this.parameterFormatter.format(message.params);
 566           })
 567         );
 568       }
 569       if (!subDone) {
 570         // There were no substitutions in the text, so format the entire params object
 571         let rest = this.parameterFormatter.format(message.params);
 572         if (rest !== null && rest != "{}") {
 573           textParts.push(rest);
 574         }
 575       }
 576       return textParts.join(": ");
 577     }
 578     return undefined;
 579   }
 580
 581   format(message) {
 582     return (
 583       message.time +
 584       "\t" +
 585       message.loggerName +
 586       "\t" +
 587       message.levelDesc +
 588       "\t" +
 589       this.formatText(message)
 590     );
 591   }
 592 }
 593
 594 /**
 595  * Test an object to see if it is a Mozilla JS Error.
 596  */
 597 function isError(aObj) {
 598   return (
 599     aObj &&
 600     typeof aObj == "object" &&
 601     "name" in aObj &&
 602     "message" in aObj &&
 603     "fileName" in aObj &&
 604     "lineNumber" in aObj &&
 605     "stack" in aObj
 606   );
 607 }
 608
 609 /*
 610  * Parameter Formatters
 611  * These massage an object used as a parameter for a LogMessage into
 612  * a string representation of the object.
 613  */
 614
 615 class ParameterFormatter {
 616   constructor() {
 617     this._name = "ParameterFormatter";
 618   }
 619
 620   format(ob) {
 621     try {
 622       if (ob === undefined) {
 623         return "undefined";
 624       }
 625       if (ob === null) {
 626         return "null";
 627       }
 628       // Pass through primitive types and objects that unbox to primitive types.
 629       if (
 630         (typeof ob != "object" || typeof ob.valueOf() != "object") &&
 631         typeof ob != "function"
 632       ) {
 633         return ob;
 634       }
 635       if (ob instanceof Ci.nsIException) {
 636         return `${ob} ${Log.stackTrace(ob)}`;
 637       } else if (isError(ob)) {
 638         return Log._formatError(ob);
 639       }
 640       // Just JSONify it. Filter out our internal fields and those the caller has
 641       // already handled.
 642       return JSON.stringify(ob, (key, val) => {
 643         if (INTERNAL_FIELDS.has(key)) {
 644           return undefined;
 645         }
 646         return val;
 647       });
 648     } catch (e) {
 649       dumpError(
 650         `Exception trying to format object for log message: ${Log.exceptionStr(
 651           e
 652         )}`
 653       );
 654     }
 655     // Fancy formatting failed. Just toSource() it - but even this may fail!
 656     try {
 657       return ob.toSource();
 658     } catch (_) {}
 659     try {
 660       return String(ob);
 661     } catch (_) {
 662       return "[object]";
 663     }
 664   }
 665 }
 666
 667 /*
 668  * Appenders
 669  * These can be attached to Loggers to log to different places
 670  * Simply subclass and override doAppend to implement a new one
 671  */
 672
 673 class Appender {
 674   constructor(formatter) {
 675     this.level = Log.Level.All;
 676     this._name = "Appender";
 677     this._formatter = formatter || new BasicFormatter();
 678   }
 679
 680   append(message) {
 681     if (message) {
 682       this.doAppend(this._formatter.format(message));
 683     }
 684   }
 685
 686   toString() {
 687     return `${this._name} [level=${this.level}, formatter=${this._formatter}]`;
 688   }
 689 }
 690
 691 /*
 692  * DumpAppender
 693  * Logs to standard out
 694  */
 695
 696 class DumpAppender extends Appender {
 697   constructor(formatter) {
 698     super(formatter);
 699     this._name = "DumpAppender";
 700   }
 701
 702   doAppend(formatted) {
 703     dump(formatted + "\n");
 704   }
 705 }
 706
 707 /*
 708  * ConsoleAppender
 709  * Logs to the javascript console
 710  */
 711
 712 class ConsoleAppender extends Appender {
 713   constructor(formatter) {
 714     super(formatter);
 715     this._name = "ConsoleAppender";
 716   }
 717
 718   // XXX this should be replaced with calls to the Browser Console
 719   append(message) {
 720     if (message) {
 721       let m = this._formatter.format(message);
 722       if (message.level > Log.Level.Warn) {
 723         Cu.reportError(m);
 724         return;
 725       }
 726       this.doAppend(m);
 727     }
 728   }
 729
 730   doAppend(formatted) {
 731     Services.console.logStringMessage(formatted);
 732   }
 733 }
 734
 735 Object.assign(Log, {
 736   LogMessage,
 737   Logger,
 738   LoggerRepository,
 739
 740   BasicFormatter,
 741
 742   Appender,
 743   DumpAppender,
 744   ConsoleAppender,
 745
 746   ParameterFormatter,
 747 });