toolkit/modules/Log.sys.mjs

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