VulpesOS/gaia/tests/jsmarionette/plugins/marionette-js-logger/lib/log_grabber.js
OverSu b38dea0597 Publish Vulpes Preview 15 sources for desktop, Android and Tundra
Share Gaia assets and adapters, keep private profiles and development documents local, and update both public READMEs.
2026-09-30 23:13:03 +02:00

671 lines
21 KiB
JavaScript
Executable file

'use strict';
var EventEmitter = require('events').EventEmitter;
var debug = require('debug')('marionette-js-logger');
var util = require('util');
// REMEMBER THIS RUNS ON THE DEVICE/CLIENT!
function remoteInstallHandler(logLimit) {
var Cc = Components.classes;
var Ci = Components.interfaces;
var Cu = Components.utils;
Cu.import('resource://gre/modules/Services.jsm');
// Copyright Joyent, Inc. and other Node contributors.
//
// Permission is hereby granted, free of charge, to any person obtaining a
// copy of this software and associated documentation files (the
// "Software"), to deal in the Software without restriction, including
// without limitation the rights to use, copy, modify, merge, publish,
// distribute, sublicense, and/or sell copies of the Software, and to permit
// persons to whom the Software is furnished to do so, subject to the
// following conditions:
//
// The above copyright notice and this permission notice shall be included
// in all copies or substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN
// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
// USE OR OTHER DEALINGS IN THE SOFTWARE.
var util = (function() {
var exports = {};
var formatRegExp = /%[sdj%]/g;
exports.format = function(f) {
if (typeof f !== 'string') {
var objects = [];
for (var i = 0; i < arguments.length; i++) {
objects.push(inspect(arguments[i]));
}
return objects.join(' ');
}
var i = 1;
var args = arguments;
var len = args.length;
var str = String(f).replace(formatRegExp, function(x) {
if (x === '%%') return '%';
if (i >= len) return x;
switch (x) {
case '%s': return String(args[i++]);
case '%d': return Number(args[i++]);
case '%j': return JSON.stringify(args[i++]);
default:
return x;
}
});
for (var x = args[i]; i < len; x = args[++i]) {
if (x === null || typeof x !== 'object') {
str += ' ' + x;
} else {
str += ' ' + inspect(x);
}
}
return str;
};
/**
* Echos the value of a value. Trys to print the value out
* in the best way possible given the different types.
*
* @param {Object} obj The object to print out.
* @param {Boolean} showHidden Flag that shows hidden (not enumerable)
* properties of objects.
* @param {Number} depth Depth in which to descend in object. Default is 2.
* @param {Boolean} colors Flag to turn on ANSI escape codes to color the
* output. Default is false (no coloring).
*/
function inspect(obj, showHidden, depth, colors) {
var ctx = {
showHidden: showHidden,
seen: [],
stylize: colors ? stylizeWithColor : stylizeNoColor
};
return formatValue(ctx, obj, (typeof depth === 'undefined' ? 2 : depth));
}
exports.inspect = inspect;
// http://en.wikipedia.org/wiki/ANSI_escape_code#graphics
var colors = {
'bold' : [1, 22],
'italic' : [3, 23],
'underline' : [4, 24],
'inverse' : [7, 27],
'white' : [37, 39],
'grey' : [90, 39],
'black' : [30, 39],
'blue' : [34, 39],
'cyan' : [36, 39],
'green' : [32, 39],
'magenta' : [35, 39],
'red' : [31, 39],
'yellow' : [33, 39]
};
// Don't use 'blue' not visible on cmd.exe
var styles = {
'special': 'cyan',
'number': 'yellow',
'boolean': 'yellow',
'undefined': 'grey',
'null': 'bold',
'string': 'green',
'date': 'magenta',
// "name": intentionally not styling
'regexp': 'red'
};
function stylizeWithColor(str, styleType) {
var style = styles[styleType];
return str;
}
function stylizeNoColor(str, styleType) {
return str;
}
function formatValue(ctx, value, recurseTimes) {
// Provide a hook for user-specified inspect functions.
// Check that value is an object with an inspect function on it
if (value && typeof value.inspect === 'function' &&
// Filter out the util module, it's inspect function is special
value.inspect !== exports.inspect &&
// Also filter out any prototype objects using the circular check.
!(value.constructor && value.constructor.prototype === value)) {
return value.inspect(recurseTimes);
}
// Primitive types cannot have properties
var primitive = formatPrimitive(ctx, value);
if (primitive) {
return primitive;
}
// Look up the keys of the object.
var visibleKeys = Object.keys(value);
var keys = ctx.showHidden ? Object.getOwnPropertyNames(value) : visibleKeys;
// Some type of object without properties can be shortcutted.
if (keys.length === 0) {
if (typeof value === 'function') {
var name = value.name ? ': ' + value.name : '';
return ctx.stylize('[Function' + name + ']', 'special');
}
if (isRegExp(value)) {
return ctx.stylize(RegExp.prototype.toString.call(value), 'regexp');
}
if (isDate(value)) {
return ctx.stylize(Date.prototype.toString.call(value), 'date');
}
if (isError(value)) {
return formatError(value);
}
}
var base = '', array = false, braces = ['{', '}'];
// Make Array say that they are Array
if (isArray(value)) {
array = true;
braces = ['[', ']'];
}
// Make functions say that they are functions
if (typeof value === 'function') {
var n = value.name ? ': ' + value.name : '';
base = ' [Function' + n + ']';
}
// Make RegExps say that they are RegExps
if (isRegExp(value)) {
base = ' ' + RegExp.prototype.toString.call(value);
}
// Make dates with properties first say the date
if (isDate(value)) {
base = ' ' + Date.prototype.toUTCString.call(value);
}
// Make error with message first say the error
if (isError(value)) {
base = ' ' + formatError(value);
}
if (keys.length === 0 && (!array || value.length == 0)) {
return braces[0] + base + braces[1];
}
if (recurseTimes < 0) {
if (isRegExp(value)) {
return ctx.stylize(RegExp.prototype.toString.call(value), 'regexp');
} else {
return ctx.stylize('[Object]', 'special');
}
}
ctx.seen.push(value);
var output;
if (array) {
output = formatArray(ctx, value, recurseTimes, visibleKeys, keys);
} else {
output = keys.map(function(key) {
return formatProperty(
ctx, value, recurseTimes, visibleKeys, key, array
);
});
}
ctx.seen.pop();
return reduceToSingleString(output, base, braces);
}
function formatPrimitive(ctx, value) {
switch (typeof value) {
case 'undefined':
return ctx.stylize('undefined', 'undefined');
case 'string':
var simple = '\'' + JSON.stringify(value).replace(/^"|"$/g, '')
.replace(/'/g, "\\'")
.replace(/\\"/g, '"') + '\'';
return ctx.stylize(simple, 'string');
case 'number':
return ctx.stylize('' + value, 'number');
case 'boolean':
return ctx.stylize('' + value, 'boolean');
}
// For some reason typeof null is "object", so special case here.
if (value === null) {
return ctx.stylize('null', 'null');
}
return null;
}
function formatError(value) {
return '[' + Error.prototype.toString.call(value) + ']';
}
function formatArray(ctx, value, recurseTimes, visibleKeys, keys) {
var output = [];
for (var i = 0, l = value.length; i < l; ++i) {
if (Object.prototype.hasOwnProperty.call(value, String(i))) {
output.push(formatProperty(ctx, value, recurseTimes, visibleKeys,
String(i), true));
} else {
output.push('');
}
}
keys.forEach(function(key) {
if (!key.match(/^\d+$/)) {
output.push(formatProperty(ctx, value, recurseTimes, visibleKeys,
key, true));
}
});
return output;
}
function formatProperty(ctx, value, recurseTimes, visibleKeys, key, array) {
var name, str, desc;
desc = Object.getOwnPropertyDescriptor(value, key) || { value: value[key] };
if (desc.get) {
if (desc.set) {
str = ctx.stylize('[Getter/Setter]', 'special');
} else {
str = ctx.stylize('[Getter]', 'special');
}
} else {
if (desc.set) {
str = ctx.stylize('[Setter]', 'special');
}
}
if (visibleKeys.indexOf(key) < 0) {
name = '[' + key + ']';
}
if (!str) {
if (ctx.seen.indexOf(desc.value) < 0) {
if (recurseTimes === null) {
str = formatValue(ctx, desc.value, null);
} else {
str = formatValue(ctx, desc.value, recurseTimes - 1);
}
if (str.indexOf('\n') > -1) {
if (array) {
str = str.split('\n').map(function(line) {
return ' ' + line;
}).join('\n').substr(2);
} else {
str = '\n' + str.split('\n').map(function(line) {
return ' ' + line;
}).join('\n');
}
}
} else {
str = ctx.stylize('[Circular]', 'special');
}
}
if (typeof name === 'undefined') {
if (array && key.match(/^\d+$/)) {
return str;
}
name = JSON.stringify('' + key);
if (name.match(/^"([a-zA-Z_][a-zA-Z_0-9]*)"$/)) {
name = name.substr(1, name.length - 2);
name = ctx.stylize(name, 'name');
} else {
name = name.replace(/'/g, "\\'")
.replace(/\\"/g, '"')
.replace(/(^"|"$)/g, "'");
name = ctx.stylize(name, 'string');
}
}
return name + ': ' + str;
}
function reduceToSingleString(output, base, braces) {
var numLinesEst = 0;
var length = output.reduce(function(prev, cur) {
numLinesEst++;
if (cur.indexOf('\n') >= 0) numLinesEst++;
return prev + cur.length + 1;
}, 0);
if (length > 60) {
return braces[0] +
(base === '' ? '' : base + '\n ') +
' ' +
output.join(',\n ') +
' ' +
braces[1];
}
return braces[0] + base + ' ' + output.join(', ') + ' ' + braces[1];
}
// NOTE: These type checking functions intentionally don't use `instanceof`
// because it is fragile and can be easily faked with `Object.create()`.
function isArray(ar) {
return Array.isArray(ar) ||
(typeof ar === 'object' && objectToString(ar) === '[object Array]');
}
function isRegExp(re) {
return typeof re === 'object' && objectToString(re) === '[object RegExp]';
}
function isDate(d) {
return typeof d === 'object' && objectToString(d) === '[object Date]';
}
function isError(e) {
return typeof e === 'object' && objectToString(e) === '[object Error]';
}
function objectToString(o) {
return Object.prototype.toString.call(o);
}
return exports;
}());
var logs = [];
var grabberGlobal = window.MARIONETTE_LOG_GRABBER = {
_waitingCallback: null,
grabAndClearLogs: function() {
var retLogs = logs;
logs = [];
return retLogs;
},
_queueCallback: function() {
var callback = this._waitingCallback;
this._waitingCallback = null;
window.setTimeout(function() {
callback(this.grabAndClearLogs());
}.bind(this), 0);
},
grabAtLeastOneLog: function(callback) {
this._waitingCallback = callback;
if (logs.length) {
this._queueCallback();
}
},
shutdown: function() {
Services.obs.removeObserver(observer, 'console-api-log-event', false);
}
};
var idCache = {};
function observer(subject, topic, state) {
var msg = subject.wrappedJSObject;
// Gecko primer! We have outer windows and inner windows. Outer windows
// correspond to a browser tab, inner windows correspond to the currently
// loaded document. Every time you navigate the contents of the tab, a new
// inner window is created and the old one crammed in the back-button cache
// and eventually destroyed.
//
// Accordingly we key off the inner ID since that is what corresponds to the
// thing doing the logging. But to get at the inner window, we need to do
// it via the outer window since that's what's easiest to get to.
var origin = idCache[msg.innerID];
if (!origin) {
var idNum = parseInt(msg.ID, 10);
if (!isNaN(idNum)) {
var domWin = Services.wm.getOuterWindowWithId(idNum);
if (domWin) {
if (domWin.document && domWin.document.documentURI) {
origin = domWin.document.documentURI;
}
}
}
idCache[msg.innerID] = origin;
}
queueLogMessage({
window: origin,
level: msg.level,
message: util.format.apply(util, msg.arguments),
filename: msg.filename,
lineNumber: msg.lineNumber,
functionName: msg.functionName,
timeStamp: msg.timeStamp
});
}
function onConsoleServiceMessage(aMessage) {
if (!(aMessage instanceof Ci.nsIScriptError)) {
// Not an error!
return;
}
queueLogMessage({
level: 'error',
stack: [],
message: aMessage.errorMessage,
filename: aMessage.sourceName,
lineNumber: aMessage.lineNumber,
timeStamp: aMessage.timestamp
});
}
function queueLogMessage(aMessage) {
// Immediately stringify so we don't keep any
// complicated object graphs alive
logs.push(JSON.stringify(aMessage));
if (grabberGlobal._waitingCallback) {
grabberGlobal._queueCallback();
}
if (logs.length > logLimit) {
logs.shift();
}
}
var consoleService = Cc["@mozilla.org/consoleservice;1"]
.getService(Ci.nsIConsoleService);
consoleService.registerListener({ observe: onConsoleServiceMessage });
Services.obs.addObserver(observer, 'console-api-log-event', false);
}
function LogGrabber(client, logLimit) {
this._logLimit = logLimit;
this._desiredTimeoutMS = this.DEFAULT_TIMEOUT_MS;
// We may need to muck with the timeout for our executeAsyncScript calls, this
// tracks what we last set it to in case we need to override it.
this._activeTimeoutMS = this._usingTimeout;
// set scope to chrome so we can use privileged apis
this._client = client.scope({
context: 'chrome',
searchTimeout: this._desiredTimeoutMS
});
this.grabLogMessages = this.grabLogMessages.bind(this);
this._pollInterval = null;
}
util.inherits(LogGrabber, EventEmitter);
LogGrabber.prototype.DEFAULT_TIMEOUT_MS = 10 * 1000;
LogGrabber.prototype.setTimeout = function(timeoutMS) {
this._desiredTimeoutMS = timeoutMS;
};
LogGrabber.prototype._connect = function(callback) {
this._client.executeScript(remoteInstallHandler, [this._logLimit], callback);
};
LogGrabber.prototype._processMessages = function(messages, specificHandler) {
if (!specificHandler && this.listeners('message').length === 0) {
return false;
}
var message, checkSpecific = !!specificHandler, foundIt = false;
for (var i = 0; i < messages.length; i++) {
try {
message = JSON.parse(messages[i]);
} catch (e) {
debug('malformed JSON message payload');
}
// emit does not catch errors in handlers, so we should catch and report
try {
this.emit('message', message);
} catch (e) {
debug('emit(message) error:', e);
}
if (checkSpecific) {
try {
if (specificHandler(message)) {
checkSpecific = false;
foundIt = true;
}
}
catch (e) {
debug('specificHandler threw on a message:', e);
}
}
}
return foundIt;
};
/**
* Explicitly fetch all available logs from the server, emitting 'message'
* events. This is a synchronous operation that does not wait around for
* anything.
*
* It is critically important to note that Firefox's console.log batches things
* with a 15ms initial delay so just because you know code must have already run
* does not mean it has actually been logged yet. If you are waiting for
* something, please do *not* assume it will be in the logs. Use
* `waitForLogMessage()` in that case!
*/
LogGrabber.prototype.grabLogMessages = function(processFunc) {
try {
var messages = this._client.executeScript(function() {
return window.MARIONETTE_LOG_GRABBER.grabAndClearLogs();
});
return this._processMessages(messages, processFunc);
} catch (error) {
console.error(error);
}
};
/**
* Fetch all available logs from the server, but if there aren't any there yet,
* wait for at least one new message to be logged. This will wait for at least
* one turn of the event loop before returning for efficiency reasons and to
* avoid mistaken understandings of the state of the device. Do not depend on
* this to leave certain messages on the device.
*
* @param {Function} [procFunc]
* Optional processing function to invoke for each retrieved message which is
* only invoked until it returns true. You really don't / shouldn't use this
* function, it exists for the benefit of `waitForLogMessage`.
* @param {Number} [timeoutMS]
* Timeout to use for this aggregate wait. If not specified, the last timeout
* set using `setTimeout` is used or the default if nothing was ever
* specified.
*/
LogGrabber.prototype.grabAtLeastOneNewMessage = function(procFunc, timeoutMS) {
if (!timeoutMS) {
timeoutMS = this._desiredTimeoutMS;
}
if (timeoutMS !== this._activeTimeoutMS) {
this._client.setScriptTimeout(timeoutMS);
this._activeTimeoutMS = timeoutMS;
}
var messages = this._client.executeAsyncScript(function() {
window.MARIONETTE_LOG_GRABBER.grabAtLeastOneLog(marionetteScriptFinished);
});
return this._processMessages(messages, procFunc);
};
/**
* Keep fetching logs from the server and calling the provided method until it
* returns true indicating it found the log message it wanted. 'message' events
* will still be emitted for all logs retrieved as a result of these calls.
* While the function will only be called on messages until it returns true and
* will not be called for any messages retrieved after the first call that
* returns true, 'message' events will be emitted for ALL retrieved logs. Also,
* subsequent calls to waitForLogMessage will only call the function for newly
* retrieved logs.
*
* If your check function throws an error, it's treated as if it returned false.
* The rationale is that your function may see a lot of logs that it is not
* prepared to deal with, but that it will be able to properly process the log
* it is looking for.
*
* Your check function is called after the emit('message') is sent, so if you
* have a listener subscribed to the event that does thorough processing that
* is always triggered, it's okay for it to set a flag that this function just
* returns.
*
* @param {Function} checkFunc
* @param {Number} [timeoutMS]
* Timeout to use for this aggregate wait. If not specified, the last timeout
* set using `setTimeout` is used or the default if nothing was ever
* specified.
*/
LogGrabber.prototype.waitForLogMessage = function(checkFunc, timeoutMS) {
var explodeAt = Date.now() + (timeoutMS || this._desiredTimeoutMS);
// For our timeouts, rely on executeAsyncScript to do the exploding for us
while (!this.grabAtLeastOneNewMessage(checkFunc,
explodeAt - Date.now())) {
}
};
/**
* Note that logs are only fetched continuously from the message queue
* asynchronously. Messages will not be fetched while synchronous operations
* are performed during a given tick of the event loop.
*/
LogGrabber.prototype.pollMessages = function(freq) {
freq = freq || 50;
this._pollInterval = setInterval(this.grabLogMessages, freq);
};
/**
* @deprecated legacy function used by marionette-js-runner.
*
* This method does not need to do anything because marionette-js-runner's
* childrunner.js calls us after triggering a stopHost() call which means the
* host is dying. This originally mattered in order to allow a web-sockets
* http server to be shutdown.
*/
LogGrabber.prototype.close = function() {
clearInterval(this._pollInterval);
};
exports.LogGrabber = LogGrabber;