Source code
Revision control
Copy as Markdown
Other Tools
/* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
let gSchemaRegistered = false;
function ensureSchemaRegistered() {
if (gSchemaRegistered) {
return;
}
gSchemaRegistered = true;
/**
* @backward-compat { version 149 }
*
* Bug 2011308: Remove the following typeof / early return check
*/
if (!ChromeUtils.registerMarkerSchema) {
return;
}
ChromeUtils.registerMarkerSchema({
name: "TestStatus",
tableLabel: "{marker.data.message}",
display: ["marker-chart", "marker-table"],
colorField: "color",
data: [
{
key: "message",
label: "Message",
format: "string",
},
{
key: "test",
label: "Test Name",
format: "string",
},
{
key: "subtest",
label: "Subtest",
format: "string",
},
{
key: "status",
label: "Status",
format: "string",
},
{
key: "expected",
label: "Expected",
format: "string",
},
{
key: "color",
hidden: true,
},
],
});
ChromeUtils.registerMarkerSchema({
name: "Test",
tooltipLabel: "{marker.data.name}",
tableLabel: "{marker.data.status} — {marker.data.test}",
chartLabel: "{marker.data.name}",
display: ["marker-chart", "marker-table"],
colorField: "color",
data: [
{
key: "test",
label: "Test Name",
format: "string",
},
{
key: "name",
label: "Short Name",
format: "string",
hidden: true,
},
{
key: "status",
label: "Status",
format: "string",
},
{
key: "expected",
label: "Expected",
format: "string",
},
{
key: "message",
label: "Message",
format: "string",
},
{
key: "color",
hidden: true,
},
],
});
ChromeUtils.registerMarkerSchema({
name: "Log",
tableLabel: "{marker.data.message}",
display: ["marker-chart", "marker-table"],
colorField: "color",
data: [
{
key: "message",
label: "Message",
format: "string",
},
{
key: "level",
label: "Level",
format: "string",
},
{
key: "test",
label: "Test Name",
format: "string",
},
{
key: "subtest",
label: "Subtest",
format: "string",
},
{
key: "color",
hidden: true,
},
],
});
}
/**
* TestLogger: Logger class generating messages compliant with the
* structured logging protocol for tests exposed by mozlog
*
* @param {string} name
* The name of the logger to instantiate.
* @param {function} [dumpFun]
* An underlying function to be used to log raw messages. This function
* will receive the complete serialized json string to log.
* @param {object} [scope]
* The scope that the dumpFun is loaded in, so that messages are cloned
* into that scope before passing them.
*/
export class StructuredLogger {
name = null;
#dumpFun = null;
#dumpScope = null;
#testStartTimes = new Map();
// Regexes that normalize test paths, matching MessageLogger.TEST_PATH_PREFIXES
static #TEST_PATH_PREFIXES = [
/^\/tests\//,
/^\w+:\/\/[\w.]+(:\d+)?(\/\w+)?\/(tests?|a11y|chrome)\//,
/^\w+:\/\/[\w.]+(:\d+)?(\/\w+)?\/(tests?|browser)\//,
];
constructor(name, dumpFun = dump, scope = null) {
this.name = name;
this.#dumpFun = dumpFun;
this.#dumpScope = scope;
}
/**
* Normalize a test path to match the relative path from the sourcedir.
* Matches the behavior of MessageLogger._fix_test_name in runtests.py.
*/
#normalizeTestPath(testPath) {
for (const pattern of StructuredLogger.#TEST_PATH_PREFIXES) {
const normalized = testPath.replace(pattern, "");
if (normalized !== testPath) {
return normalized;
}
}
return testPath;
}
testStart(test) {
var data = { test: this.#testId(test) };
this.logData("test_start", data);
const testId = this.#testId(test);
this.#testStartTimes.set(testId, ChromeUtils.now());
}
testStatus(
test,
subtest,
status,
expected = "PASS",
message = null,
stack = null,
extra = null
) {
var data = {
test: this.#testId(test),
subtest,
status,
};
if (expected != status && status != "SKIP") {
data.expected = expected;
}
if (message !== null) {
data.message = String(message);
}
if (stack !== null) {
data.stack = stack;
}
if (extra !== null) {
data.extra = extra;
}
this.logData("test_status", data);
ensureSchemaRegistered();
// Determine marker name following mochitest conventions
let markerName;
if (status === expected) {
// Expected result
if (status === "FAIL") {
markerName = "TEST-KNOWN-FAIL";
} else {
markerName = "TEST-" + status;
}
} else {
// Unexpected result
markerName = "TEST-UNEXPECTED-" + status;
}
// Prepare marker data with normalized test path
const markerData = {
type: "TestStatus",
test: this.#normalizeTestPath(data.test),
status,
expected,
};
if (subtest) {
markerData.subtest = subtest;
}
if (message !== null) {
markerData.message = String(message);
}
// Determine color
if (status === "ERROR" && status !== expected) {
markerData.color = "red";
} else if (status === expected) {
markerData.color = "green";
} else {
markerData.color = "orange";
}
const options = { category: "Test" };
// Capture stack for failures and errors
if (status === "FAIL" || status === "ERROR") {
options.captureStack = true;
}
ChromeUtils.addProfilerMarker(markerName, options, markerData);
}
testEnd(
test,
status,
expected = "PASS",
message = null,
stack = null,
extra = null
) {
const testId = this.#testId(test);
var data = { test: testId, status };
if (expected != status && status != "SKIP") {
data.expected = expected;
}
if (message !== null) {
data.message = String(message);
}
if (stack !== null) {
data.stack = stack;
}
if (extra !== null) {
data.extra = extra;
}
this.logData("test_end", data);
const startTime = this.#testStartTimes.get(testId);
if (!startTime) {
return;
}
this.#testStartTimes.delete(testId);
ensureSchemaRegistered();
// Normalize test path
const testPath = this.#normalizeTestPath(testId);
const markerData = {
type: "Test",
test: testPath,
name: testPath.split("/").pop(),
status,
};
if (data.expected) {
markerData.expected = data.expected;
}
if (data.message) {
markerData.message = data.message;
}
if (status) {
// Determine color based on status and expectations
if (status === "SKIP" || status === "TIMEOUT") {
markerData.color = "yellow";
} else if (status === "CRASH" || status === "ERROR") {
markerData.color = "red";
} else if (expected === status) {
markerData.color = "green";
} else {
markerData.color = "orange";
}
}
ChromeUtils.addProfilerMarker(
"test",
{
category: "Test",
startTime,
},
markerData
);
}
assertionCount(test, count, minExpected = 0, maxExpected = 0) {
var data = {
test: this.#testId(test),
min_expected: minExpected,
max_expected: maxExpected,
count,
};
this.logData("assertion_count", data);
}
suiteStart(
ids,
name = null,
runinfo = null,
versioninfo = null,
deviceinfo = null,
extra = null
) {
Object.keys(ids).map(function (manifest) {
ids[manifest] = ids[manifest].map(x => this.#testId(x));
}, this);
var data = { tests: ids };
if (name !== null) {
data.name = name;
}
if (runinfo !== null) {
data.runinfo = runinfo;
}
if (versioninfo !== null) {
data.versioninfo = versioninfo;
}
if (deviceinfo !== null) {
data.deviceinfo = deviceinfo;
}
if (extra !== null) {
data.extra = extra;
}
this.logData("suite_start", data);
}
suiteEnd(extra = null) {
var data = {};
if (extra !== null) {
data.extra = extra;
}
this.logData("suite_end", data);
}
/**
* Unstructured logging functions. The "extra" parameter can always by used to
* log suite specific data. If a "stack" field is provided it is logged at the
* top level of the data object for the benefit of mozlog's formatters.
*/
log(level, message, extra = null) {
var data = {
level,
message: String(message),
};
if (extra !== null) {
data.extra = extra;
if ("stack" in extra) {
data.stack = extra.stack;
}
}
this.logData("log", data);
ensureSchemaRegistered();
// Add marker type
data.type = "Log";
// Copy test/subtest from extra if present, normalizing test path
if (extra) {
if (extra.test) {
data.test = this.#normalizeTestPath(extra.test);
}
if (extra.subtest) {
data.subtest = extra.subtest;
}
}
// Determine color based on log level
if (level === "CRITICAL" || level === "ERROR") {
data.color = "red";
} else if (level === "WARNING") {
data.color = "orange";
} else if (level === "DEBUG") {
data.color = "grey";
}
// Remove fields we don't want in the marker
delete data.extra;
const options = { category: "Test" };
// Capture stack for errors and critical
if (level === "CRITICAL" || level === "ERROR") {
options.captureStack = true;
}
ChromeUtils.addProfilerMarker(level, options, data);
}
debug(message, extra = null) {
this.log("DEBUG", message, extra);
}
info(message, extra = null) {
this.log("INFO", message, extra);
}
warning(message, extra = null) {
this.log("WARNING", message, extra);
}
error(message, extra = null) {
this.log("ERROR", message, extra);
}
critical(message, extra = null) {
this.log("CRITICAL", message, extra);
}
processOutput(thread, message) {
this.logData("process_output", {
message,
thread,
});
}
logData(action, data = {}) {
var allData = {
action,
time: Date.now(),
thread: null,
pid: null,
source: this.name,
};
for (var field in data) {
allData[field] = data[field];
}
if (this.#dumpScope) {
try {
allData = Cu.cloneInto(allData, this.#dumpScope);
} catch (e) {
try {
this.error(`Failed to cloneInto: ${e}`);
this.warning(`Tried to clone: ${uneval(allData)}`);
} catch (e2) {
console.error("Failed to handle clone error", e, e2);
}
}
}
this.#dumpFun(allData);
}
#testId(test) {
if (Array.isArray(test)) {
return test.join(" ");
}
return test;
}
}
/**
* StructuredFormatter: Formatter class turning structured messages
* into human-readable messages.
*/
export class StructuredFormatter {
// The time at which the whole suite of tests started.
#suiteStartTime = null;
#testStartTimes = new Map();
log(message) {
return message.message;
}
suite_start(message) {
this.#suiteStartTime = message.time;
return "SUITE-START | Running " + message.tests.length + " tests";
}
test_start(message) {
this.#testStartTimes.set(message.test, new Date().getTime());
return "TEST-START | " + message.test;
}
test_status(message) {
var statusInfo =
message.test +
" | " +
message.subtest +
(message.message ? " | " + message.message : "");
if (message.expected) {
return (
"TEST-UNEXPECTED-" +
message.status +
" | " +
statusInfo +
" - expected: " +
message.expected
);
}
return "TEST-" + message.status + " | " + statusInfo;
}
test_end(message) {
var startTime = this.#testStartTimes.get(message.test);
this.#testStartTimes.delete(message.test);
var statusInfo =
message.test + (message.message ? " | " + String(message.message) : "");
var result;
if (message.expected) {
result =
"TEST-UNEXPECTED-" +
message.status +
" | " +
statusInfo +
" - expected: " +
message.expected;
} else {
return "TEST-" + message.status + " | " + statusInfo;
}
result = result + " | took " + message.time - startTime + "ms";
return result;
}
suite_end(message) {
return "SUITE-END | took " + message.time - this.#suiteStartTime + "ms";
}
}