From a71f4b4621ae64c38ef2e98737c86e80a5cd3056 Mon Sep 17 00:00:00 2001 From: Julien Wajsberg Date: Tue, 30 Apr 2024 18:26:07 +0200 Subject: [PATCH] Export a tool to extract gecko logs from a profile --- .../__snapshots__/window-console.test.js.snap | 9 ++- src/test/unit/window-console.test.js | 38 ++++++++++- src/utils/window-console.js | 65 ++++++++++++++++++- 3 files changed, 105 insertions(+), 7 deletions(-) diff --git a/src/test/unit/__snapshots__/window-console.test.js.snap b/src/test/unit/__snapshots__/window-console.test.js.snap index f52d898f52..311415926e 100644 --- a/src/test/unit/__snapshots__/window-console.test.js.snap +++ b/src/test/unit/__snapshots__/window-console.test.js.snap @@ -21,7 +21,7 @@ Array [ "font-family: Menlo, monospace;", ], Array [ - "%cThe following profiler information is available via the console:%c + "%cThe following profiler information and tools are available via the console:%c %cwindow.profile%c - The currently loaded profile %cwindow.filteredThread%c - The current filtered thread @@ -35,8 +35,9 @@ Array [ %cwindow.experimental%c - The object that holds flags of all the experimental features. %cwindow.togglePseudoLocalization%c - Enable pseudo localizations by passing \\"accented\\" or \\"bidi\\" to this function, or disable using no parameters. %cwindow.toggleTimelineType%c - Toggle timeline graph type by passing \\"cpu-category\\", \\"category\\", or \\"stack\\". -%cwindow.retrieveRawProfileDataFromBrowser%c - Retrieve the profile attached to the current tab and returns it. Use \\"await\\" to call it. -%cwindow.saveToDisk%c - Saves to a file the parameter passed to it, with an optional filename parameter. You can use that to save the profile returned by \\"retrieveRawProfileDataFromBrowser\\". +%cwindow.retrieveRawProfileDataFromBrowser%c - Retrieve the profile attached to the current tab and returns it. Use \\"await\\" to call it, and use saveToDisk to save it. +%cwindow.extractGeckoLogs%c - Retrieve recorded logs in the current range, using the MOZ_LOG format. Use with \\"copy\\" or \\"saveToDisk\\". +%cwindow.saveToDisk%c - Saves to a file the parameter passed to it, with an optional filename parameter. You can use that to save the profile returned by \\"retrieveRawProfileDataFromBrowser\\" or the data returned by \\"extractGeckoLogs\\". The profile format is documented here: %chttps://github.com/firefox-devtools/profiler/blob/main/docs-developer/processed-profile-format.md%c @@ -73,6 +74,8 @@ The CallTree class's source code is available here: "", "font-weight: bold;", "", + "font-weight: bold;", + "", "font-style: italic; text-decoration: underline;", "", "font-style: italic; text-decoration: underline;", diff --git a/src/test/unit/window-console.test.js b/src/test/unit/window-console.test.js index 8872763601..a39dbe35a3 100644 --- a/src/test/unit/window-console.test.js +++ b/src/test/unit/window-console.test.js @@ -3,11 +3,14 @@ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ // @flow +import { stripIndent } from 'common-tags'; + import { addDataToWindowObject, logFriendlyPreamble, } from '../../utils/window-console'; -import { storeWithSimpleProfile } from '../fixtures/stores'; +import { storeWithSimpleProfile, storeWithProfile } from '../fixtures/stores'; +import { getProfileWithMarkers } from '../fixtures/profiles/processed-profile'; describe('console-accessible values on the window object', function () { // Coerce the window into a generic object, as these values aren't defined @@ -37,4 +40,37 @@ describe('console-accessible values on the window object', function () { expect(console.log.mock.calls).toMatchSnapshot(); (console: any).log = log; }); + + it('can extract gecko logs', function () { + const profile = getProfileWithMarkers([ + [ + 'LogMessages', + 170, + null, + { + type: 'Log', + module: 'nsHttp', + name: 'ParentChannelListener::ParentChannelListener [this=7fb5e19b98d0, next=7fb5f48f2320]', + }, + ], + [ + 'LogMessages', + 190, + null, + { + type: 'Log', + name: 'nsJARChannel::nsJARChannel [this=0x87f1ec80]\n', + module: 'nsJarProtocol', + }, + ], + ]); + const store = storeWithProfile(profile); + const target = {}; + addDataToWindowObject(store.getState, store.dispatch, target); + const result = target.extractGeckoLogs(); + expect(result).toBe(stripIndent` + 1970-01-01 00:00:00.170000000 UTC - [Unknown Process 0: Empty]: D/nsHttp ParentChannelListener::ParentChannelListener [this=7fb5e19b98d0, next=7fb5f48f2320] + 1970-01-01 00:00:00.190000000 UTC - [Unknown Process 0: Empty]: D/nsJarProtocol nsJARChannel::nsJARChannel [this=0x87f1ec80] + `); + }); }); diff --git a/src/utils/window-console.js b/src/utils/window-console.js index 558fcdb7a1..fe2036ad60 100644 --- a/src/utils/window-console.js +++ b/src/utils/window-console.js @@ -210,6 +210,61 @@ export function addDataToWindowObject( URL.revokeObjectURL(blobUrl); }; + // This function extracts MOZ_LOGs saved as markers in a Firefox profile, + // using the MOZ_LOG canonical format. All logs are saved as a debug log + // because the log level information isn't saved in these markers. + target.extractGeckoLogs = function () { + function pad(p, c) { + return String(p).padStart(c, '0'); + } + + // This transforms a timestamp to a string as output by mozlog usually. + function d2s(ts) { + const d = new Date(ts); + // new Date rounds down the timestamp (in milliseconds) to the lower integer, + // let's get the microseconds and nanoseconds differently. + // This will be imperfect because of float rounding errors but still better + // than not having them. + const ns = Math.trunc((ts - Math.trunc(ts)) * 10 ** 6); + return `${d.getFullYear()}-${pad(d.getUTCMonth() + 1, 2)}-${pad(d.getUTCDate(), 2)} ${pad(d.getUTCHours(), 2)}:${pad(d.getUTCMinutes(), 2)}:${pad(d.getUTCSeconds(), 2)}.${pad(d.getUTCMilliseconds(), 3)}${pad(ns, 6)} UTC`; + } + + const logs = []; + + // This algorithm loops over the raw marker table instead of using the + // selectors so that the full marker list isn't generated for all the + // threads in the profile. + const profile = selectorsForConsole.profile.getProfile(getState()); + const range = + selectorsForConsole.profile.getPreviewSelectionRange(getState()); + + for (const thread of profile.threads) { + const { markers } = thread; + for (let i = 0; i < markers.length; i++) { + const startTime = markers.startTime[i]; + // Note that Log markers are instant markers, so they only have a start time. + if ( + startTime !== null && + markers.data[i] && + markers.data[i].type === 'Log' && + startTime >= range.start && + startTime <= range.end + ) { + const data = markers.data[i]; + const strTimestamp = d2s( + profile.meta.startTime + markers.startTime[i] + ); + const processName = thread.processName ?? 'Unknown Process'; + // TODO: lying about the log level as it's not available yet in the markers + const statement = `${strTimestamp} - [${processName} ${thread.pid}: ${thread.name}]: D/${data.module} ${data.name.trim()}`; + logs.push(statement); + } + } + } + + return logs.sort().join('\n'); + }; + target.shortenUrl = shortenUrl; target.getState = getState; target.selectors = selectorsForConsole; @@ -255,7 +310,7 @@ export function logFriendlyPreamble() { console.log( stripIndent` - %cThe following profiler information is available via the console:%c + %cThe following profiler information and tools are available via the console:%c %cwindow.profile%c - The currently loaded profile %cwindow.filteredThread%c - The current filtered thread @@ -269,8 +324,9 @@ export function logFriendlyPreamble() { %cwindow.experimental%c - The object that holds flags of all the experimental features. %cwindow.togglePseudoLocalization%c - Enable pseudo localizations by passing "accented" or "bidi" to this function, or disable using no parameters. %cwindow.toggleTimelineType%c - Toggle timeline graph type by passing "cpu-category", "category", or "stack". - %cwindow.retrieveRawProfileDataFromBrowser%c - Retrieve the profile attached to the current tab and returns it. Use "await" to call it. - %cwindow.saveToDisk%c - Saves to a file the parameter passed to it, with an optional filename parameter. You can use that to save the profile returned by "retrieveRawProfileDataFromBrowser". + %cwindow.retrieveRawProfileDataFromBrowser%c - Retrieve the profile attached to the current tab and returns it. Use "await" to call it, and use saveToDisk to save it. + %cwindow.extractGeckoLogs%c - Retrieve recorded logs in the current range, using the MOZ_LOG format. Use with "copy" or "saveToDisk". + %cwindow.saveToDisk%c - Saves to a file the parameter passed to it, with an optional filename parameter. You can use that to save the profile returned by "retrieveRawProfileDataFromBrowser" or the data returned by "extractGeckoLogs". The profile format is documented here: %chttps://github.com/firefox-devtools/profiler/blob/main/docs-developer/processed-profile-format.md%c @@ -320,6 +376,9 @@ export function logFriendlyPreamble() { // "window.retrieveRawProfileDataFromBrowser" bold, reset, + // "window.extractGeckoLogs" + bold, + reset, // "window.saveToDisk" bold, reset,