From d8bbc7858622b6d9c278469aab701ca0b609cddf Mon Sep 17 00:00:00 2001 From: Daniel Baumann Date: Wed, 15 May 2024 05:35:49 +0200 Subject: Merging upstream version 126.0. Signed-off-by: Daniel Baumann --- .../terminator/TerminatorTelemetry.sys.mjs | 119 ----------- toolkit/components/terminator/components.conf | 15 -- toolkit/components/terminator/moz.build | 8 +- .../components/terminator/nsITerminatorTest.idl | 17 ++ toolkit/components/terminator/nsTerminator.cpp | 236 ++------------------- toolkit/components/terminator/nsTerminator.h | 4 +- .../xpcshell/test_terminator_advance_phases.js | 157 ++++++++++++++ .../tests/xpcshell/test_terminator_record.js | 171 --------------- .../tests/xpcshell/test_terminator_reload.js | 88 -------- .../terminator/tests/xpcshell/xpcshell.toml | 7 +- 10 files changed, 198 insertions(+), 624 deletions(-) delete mode 100644 toolkit/components/terminator/TerminatorTelemetry.sys.mjs delete mode 100644 toolkit/components/terminator/components.conf create mode 100644 toolkit/components/terminator/nsITerminatorTest.idl create mode 100644 toolkit/components/terminator/tests/xpcshell/test_terminator_advance_phases.js delete mode 100644 toolkit/components/terminator/tests/xpcshell/test_terminator_record.js delete mode 100644 toolkit/components/terminator/tests/xpcshell/test_terminator_reload.js (limited to 'toolkit/components/terminator') diff --git a/toolkit/components/terminator/TerminatorTelemetry.sys.mjs b/toolkit/components/terminator/TerminatorTelemetry.sys.mjs deleted file mode 100644 index 9903027436..0000000000 --- a/toolkit/components/terminator/TerminatorTelemetry.sys.mjs +++ /dev/null @@ -1,119 +0,0 @@ -/* -*- indent-tabs-mode: nil; js-indent-level: 2 -*- */ -/* vim: set ts=2 et sw=2 tw=80 filetype=javascript: */ -/* 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/. */ - -/** - * Read the data saved by nsTerminator during shutdown and feed it to the - * relevant telemetry histograms. - */ - -const lazy = {}; - -ChromeUtils.defineESModuleGetters(lazy, { - setTimeout: "resource://gre/modules/Timer.sys.mjs", -}); - -export function nsTerminatorTelemetry() { - this._wasNotified = false; - this._deferred = Promise.withResolvers(); - - IOUtils.sendTelemetry.addBlocker( - "TerminatoryTelemetry: Waiting to submit telemetry", - this._deferred.promise, - () => ({ - wasNotified: this._wasNotified, - }) - ); -} - -var HISTOGRAMS = { - "quit-application": "SHUTDOWN_PHASE_DURATION_TICKS_QUIT_APPLICATION", - "profile-change-net-teardown": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_CHANGE_NET_TEARDOWN", - "profile-change-teardown": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_CHANGE_TEARDOWN", - "profile-before-change": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_BEFORE_CHANGE", - "profile-before-change-qm": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_BEFORE_CHANGE_QM", - "xpcom-will-shutdown": "SHUTDOWN_PHASE_DURATION_TICKS_XPCOM_WILL_SHUTDOWN", - "xpcom-shutdown": "SHUTDOWN_PHASE_DURATION_TICKS_XPCOM_SHUTDOWN", - - // The following keys appear in the JSON, but do not have associated - // histograms. - "xpcom-shutdown-threads": null, - XPCOMShutdownFinal: null, - CCPostLastCycleCollection: null, -}; - -nsTerminatorTelemetry.prototype = { - classID: Components.ID("{3f78ada1-cba2-442a-82dd-d5fb300ddea7}"), - - // nsISupports - - QueryInterface: ChromeUtils.generateQI(["nsIObserver"]), - - // nsIObserver - - observe: function DS_observe(aSubject, aTopic, aData) { - this._wasNotified = true; - - (async () => { - try { - // - // This data is hardly critical, reading it can wait for a few seconds. - // - await new Promise(resolve => lazy.setTimeout(resolve, 3000)); - - let PATH = PathUtils.join( - Services.dirsvc.get("ProfLD", Ci.nsIFile).path, - "ShutdownDuration.json" - ); - let data; - try { - data = await IOUtils.readJSON(PATH); - } catch (ex) { - if (DOMException.isInstance(ex) && ex.name == "NotFoundError") { - return; - } - // Let other errors be reported by Promise's error-reporting. - throw ex; - } - - // Clean up - await IOUtils.remove(PATH); - await IOUtils.remove(PATH + ".tmp"); - - for (let k of Object.keys(data)) { - let id = HISTOGRAMS[k]; - if (id === null) { - // No histogram associated with this entry. - continue; - } - - try { - let histogram = Services.telemetry.getHistogramById(id); - histogram.add(Number.parseInt(data[k])); - } catch (ex) { - // Make sure that the error is reported and causes test failures, - // but otherwise, ignore it. - Promise.reject(ex); - continue; - } - } - - // Inform observers that we are done. - Services.obs.notifyObservers( - null, - "shutdown-terminator-telemetry-updated" - ); - } finally { - this._deferred.resolve(); - } - })(); - }, -}; - -// Module diff --git a/toolkit/components/terminator/components.conf b/toolkit/components/terminator/components.conf deleted file mode 100644 index 14c4c2c562..0000000000 --- a/toolkit/components/terminator/components.conf +++ /dev/null @@ -1,15 +0,0 @@ -# -*- Mode: python; indent-tabs-mode: nil; tab-width: 40 -*- -# vim: set filetype=python: -# 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/. - -Classes = [ - { - 'cid': '{3f78ada1-cba2-442a-82dd-d5fb300ddea7}', - 'contract_ids': ['@mozilla.org/toolkit/shutdown-terminator-telemetry;1'], - 'esModule': 'resource://gre/modules/TerminatorTelemetry.sys.mjs', - 'constructor': 'nsTerminatorTelemetry', - 'categories': {'profile-after-change': 'nsTerminatorTelemetry'}, - }, -] diff --git a/toolkit/components/terminator/moz.build b/toolkit/components/terminator/moz.build index f869b86d95..a13789c2da 100644 --- a/toolkit/components/terminator/moz.build +++ b/toolkit/components/terminator/moz.build @@ -21,12 +21,10 @@ EXTRA_COMPONENTS += [ "terminator.manifest", ] -EXTRA_JS_MODULES += [ - "TerminatorTelemetry.sys.mjs", +XPIDL_SOURCES += [ + "nsITerminatorTest.idl", ] -XPCOM_MANIFESTS += [ - "components.conf", -] +XPIDL_MODULE = "toolkit_terminator" FINAL_LIBRARY = "xul" diff --git a/toolkit/components/terminator/nsITerminatorTest.idl b/toolkit/components/terminator/nsITerminatorTest.idl new file mode 100644 index 0000000000..22f06a11dc --- /dev/null +++ b/toolkit/components/terminator/nsITerminatorTest.idl @@ -0,0 +1,17 @@ +/* -*- Mode: C++; c-basic-offset: 2; indent-tabs-mode: nil; tab-width: 8 -*- */ +/* 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/. */ + +#include "nsISupports.idl" + +[scriptable, uuid(a76599ef-78a4-441f-b258-4908dedef42d)] +interface nsITerminatorTest : nsISupports +{ + + /** + * This method is used to test the shutdown phases of nsTerminator. It is + * not meant to be used outside of tests. + */ + [implicit_jscontext] jsval getTicksForShutdownPhases(); +}; diff --git a/toolkit/components/terminator/nsTerminator.cpp b/toolkit/components/terminator/nsTerminator.cpp index 5a1f9693b8..6339962022 100644 --- a/toolkit/components/terminator/nsTerminator.cpp +++ b/toolkit/components/terminator/nsTerminator.cpp @@ -245,131 +245,9 @@ void RunWatchdog(void* arg) { } } -//////////////////////////////////////////// -// -// Writer thread -// -// This nspr thread is in charge of writing to disk statistics produced by the -// watchdog thread and collected by the main thread. Note that we use a nspr -// thread rather than usual XPCOM I/O simply because we outlive XPCOM and its -// threads. -// - -// -// Communication between the main thread and the writer thread. -// -// Main thread: -// -// * Whenever a shutdown step has been completed, the main thread -// obtains the number of ticks from the watchdog threads, builds -// a string representing all the data gathered so far, places -// this string in `gWriteData`, and wakes up the writer thread -// using `gWriteReady`. If `gWriteData` already contained a non-null -// pointer, this means that the writer thread is lagging behind the -// main thread, and the main thread cleans up the memory. -// -// Writer thread: -// -// * When awake, the writer thread swaps `gWriteData` to nullptr. If -// `gWriteData` contained data to write, the . If so, the writer -// thread writes the data to a file named "ShutdownDuration.json.tmp", -// then moves that file to "ShutdownDuration.json" and cleans up the -// data. If `gWriteData` contains a nullptr, the writer goes to sleep -// until it is awkened using `gWriteReady`. -// -// -// The data written by the writer thread will be read by another -// module upon the next restart and fed to Telemetry. -// -Atomic gWriteData(nullptr); -PRMonitor* gWriteReady = nullptr; - -void RunWriter(void* arg) { - AUTO_PROFILER_REGISTER_THREAD("Shutdown Statistics Writer"); - NS_SetCurrentThreadName("Shutdown Statistics Writer"); - - MOZ_LSAN_INTENTIONALLY_LEAK_OBJECT(arg); - // Shutdown will generally complete before we have a chance to - // deallocate. This is not a leak. - - // Setup destinationPath and tmpFilePath - - nsCString destinationPath; - destinationPath.Adopt(static_cast(arg)); - nsAutoCString tmpFilePath; - tmpFilePath.Append(destinationPath); - tmpFilePath.AppendLiteral(".tmp"); - - // Cleanup any file leftover from a previous run - Unused << PR_Delete(tmpFilePath.get()); - Unused << PR_Delete(destinationPath.get()); - - while (true) { - // - // Check whether we have received data from the main thread. - // - // We perform the check before waiting on `gWriteReady` as we may - // have received data while we were busy writing. - // - // Also note that gWriteData may have been modified several times - // since we last checked. That's ok, we are not losing any important - // data (since we keep adding data), and we are not leaking memory - // (since the main thread deallocates any data that hasn't been - // consumed by the writer thread). - // - UniquePtr data(gWriteData.exchange(nullptr)); - if (!data) { - // Data is not available yet. - // Wait until the main thread provides it. - PR_EnterMonitor(gWriteReady); - PR_Wait(gWriteReady, PR_INTERVAL_NO_TIMEOUT); - PR_ExitMonitor(gWriteReady); - continue; - } - - MOZ_LSAN_INTENTIONALLY_LEAK_OBJECT(data.get()); - // Shutdown may complete before we have a chance to deallocate. - // This is not a leak. - - // - // Write to a temporary file - // - // In case of any error, we simply give up. Since the data is - // hardly critical, we don't want to spend too much effort - // salvaging it. - // - UniquePtr tmpFileDesc(PR_Open( - tmpFilePath.get(), PR_WRONLY | PR_TRUNCATE | PR_CREATE_FILE, 00600)); - - // Shutdown may complete before we have a chance to close the file. - // This is not a leak. - MOZ_LSAN_INTENTIONALLY_LEAK_OBJECT(tmpFileDesc.get()); - - if (tmpFileDesc == nullptr) { - break; - } - if (PR_Write(tmpFileDesc.get(), data->get(), data->Length()) == -1) { - break; - } - tmpFileDesc.reset(); - - // - // Rename on top of destination file. - // - // This is not sufficient to guarantee that the destination file - // will be written correctly, but, again, we don't care enough - // about the data to make more efforts. - // - Unused << PR_Delete(destinationPath.get()); - if (PR_Rename(tmpFilePath.get(), destinationPath.get()) != PR_SUCCESS) { - break; - } - } -} - } // namespace -NS_IMPL_ISUPPORTS(nsTerminator, nsIObserver) +NS_IMPL_ISUPPORTS(nsTerminator, nsIObserver, nsITerminatorTest) nsTerminator::nsTerminator() : mInitialized(false), mCurrentStep(-1) {} @@ -379,12 +257,6 @@ void nsTerminator::Start() { MOZ_ASSERT(!mInitialized); StartWatchdog(); -#if !defined(NS_FREE_PERMANENT_DATA) - // Only allow nsTerminator to write on non-leak-checked builds so we don't - // get leak warnings on shutdown for intentional leaks (see bug 1242084). - // This will be enabled again by bug 1255484 when 1255478 lands. - StartWriter(); -#endif // !defined(NS_FREE_PERMANENT_DATA) mInitialized = true; } @@ -470,41 +342,6 @@ void nsTerminator::StartWatchdog() { MOZ_ASSERT(watchdogThread); } -// Prepare, allocate and start the writer thread. By design, it will never -// finish, nor be deallocated. In case of error, we degrade -// gracefully to not writing Telemetry data. -void nsTerminator::StartWriter() { - if (!Telemetry::CanRecordExtended()) { - return; - } - nsCOMPtr profLD; - nsresult rv = NS_GetSpecialDirectory(NS_APP_USER_PROFILE_LOCAL_50_DIR, - getter_AddRefs(profLD)); - if (NS_FAILED(rv)) { - return; - } - - rv = profLD->Append(u"ShutdownDuration.json"_ns); - if (NS_FAILED(rv)) { - return; - } - - nsAutoString path; - rv = profLD->GetPath(path); - if (NS_FAILED(rv)) { - return; - } - - gWriteReady = PR_NewMonitor(); - MOZ_LSAN_INTENTIONALLY_LEAK_OBJECT( - gWriteReady); // We will never deallocate this object - PRThread* writerThread = CreateSystemThread(RunWriter, ToNewUTF8String(path)); - - if (!writerThread) { - return; - } -} - // This helper is here to preserve the existing crash reporting behavior // based on observer topic names, using the shutdown phase name only for // phases without associated topic. @@ -531,12 +368,6 @@ void nsTerminator::AdvancePhase(mozilla::ShutdownPhase aPhase) { } UpdateHeartbeat(step); -#if !defined(NS_FREE_PERMANENT_DATA) - // Only allow nsTerminator to write on non-leak checked builds so we don't get - // leak warnings on shutdown for intentional leaks (see bug 1242084). This - // will be enabled again by bug 1255484 when 1255478 lands. - UpdateTelemetry(); -#endif // !defined(NS_FREE_PERMANENT_DATA) UpdateCrashReport(GetReadableNameForPhase(aPhase)); } @@ -555,58 +386,25 @@ void nsTerminator::UpdateHeartbeat(int32_t aStep) { } } -void nsTerminator::UpdateTelemetry() { - if (!Telemetry::CanRecordExtended() || !gWriteReady) { - return; - } - - // - // We need Telemetry data on the effective duration of each step, - // to be able to tune the time-to-crash of each of both the - // Terminator and AsyncShutdown. However, at this stage, it is too - // late to record such data into Telemetry, so we write it to disk - // and read it upon the next startup. - // - - // Build JSON. - UniquePtr telemetryData(new nsCString()); - telemetryData->AppendLiteral("{"); - size_t fields = 0; - for (auto& shutdownStep : sShutdownSteps) { - if (shutdownStep.mTicks < 0) { - // Ignore this field. - continue; - } - if (fields++ > 0) { - telemetryData->AppendLiteral(", "); - } - telemetryData->AppendLiteral(R"(")"); - telemetryData->Append(GetReadableNameForPhase(shutdownStep.mPhase)); - telemetryData->AppendLiteral(R"(": )"); - telemetryData->AppendInt(shutdownStep.mTicks); - } - telemetryData->AppendLiteral("}"); - - if (fields == 0) { - // Nothing to write - return; - } - - // - // Send data to the worker thread. - // - delete gWriteData.exchange( - telemetryData.release()); // Clear any data that hasn't been written yet - - // In case the worker thread was sleeping, wake it up. - PR_EnterMonitor(gWriteReady); - PR_Notify(gWriteReady); - PR_ExitMonitor(gWriteReady); -} - void nsTerminator::UpdateCrashReport(const char* aTopic) { // In case of crash, we wish to know where in shutdown we are CrashReporter::RecordAnnotationCString( CrashReporter::Annotation::ShutdownProgress, aTopic); } + +NS_IMETHODIMP +nsTerminator::GetTicksForShutdownPhases(JSContext* aCx, + JS::MutableHandle aRetval) { + JS::Rooted obj(aCx, JS_NewPlainObject(aCx)); + aRetval.setObject(*obj); + + for (auto& shutdownStep : sShutdownSteps) { + if (shutdownStep.mTicks >= 0) { + JS_DefineProperty(aCx, obj, GetReadableNameForPhase(shutdownStep.mPhase), + shutdownStep.mTicks, JSPROP_ENUMERATE); + } + } + + return NS_OK; +} // namespace mozilla } // namespace mozilla diff --git a/toolkit/components/terminator/nsTerminator.h b/toolkit/components/terminator/nsTerminator.h index 46c3e17b92..0de6ebe778 100644 --- a/toolkit/components/terminator/nsTerminator.h +++ b/toolkit/components/terminator/nsTerminator.h @@ -9,13 +9,15 @@ #include "nsISupports.h" #include "nsIObserver.h" +#include "nsITerminatorTest.h" namespace mozilla { -class nsTerminator final : public nsIObserver { +class nsTerminator final : public nsIObserver, public nsITerminatorTest { public: NS_DECL_ISUPPORTS NS_DECL_NSIOBSERVER + NS_DECL_NSITERMINATORTEST nsTerminator(); void AdvancePhase(mozilla::ShutdownPhase aPhase); diff --git a/toolkit/components/terminator/tests/xpcshell/test_terminator_advance_phases.js b/toolkit/components/terminator/tests/xpcshell/test_terminator_advance_phases.js new file mode 100644 index 0000000000..42f0e3686f --- /dev/null +++ b/toolkit/components/terminator/tests/xpcshell/test_terminator_advance_phases.js @@ -0,0 +1,157 @@ +/* Any copyright is dedicated to the Public Domain. + * http://creativecommons.org/publicdomain/zero/1.0/ */ +/* eslint-disable mozilla/no-arbitrary-setTimeout */ + +"use strict"; + +// Test that the Shutdown Terminator advances through the shutdown phases +// correctly. + +const { setTimeout } = ChromeUtils.importESModule( + "resource://gre/modules/Timer.sys.mjs" +); + +var terminator; + +var HEARTBEAT_MS = 100; + +let KEYS = [ + "quit-application", + "profile-change-net-teardown", + "profile-change-teardown", + "profile-before-change", + "profile-before-change-qm", + "xpcom-will-shutdown", + "xpcom-shutdown", + "xpcom-shutdown-threads", + "XPCOMShutdownFinal", + "CCPostLastCycleCollection", +]; + +let DATA = []; +let MeasuredDurations = []; + +add_task(async function init() { + do_get_profile(); + + // Initialize the terminator + // (normally, this is done through the manifest file, but xpcshell + // doesn't take them into account). + info("Initializing the Terminator"); + terminator = Cc["@mozilla.org/toolkit/shutdown-terminator;1"].createInstance( + Ci.nsIObserver + ); + + Assert.ok( + terminator instanceof Ci.nsITerminatorTest, + "Terminator should implement nsITerminatorTest" + ); +}); + +var currentPhase = 0; + +var advancePhase = async function () { + let key = "terminator-test-" + KEYS[currentPhase]; + let msDuration = 200 + HEARTBEAT_MS * currentPhase; + + info("Advancing shutdown phase to " + KEYS[currentPhase]); + terminator.observe(null, key, null); + await new Promise(resolve => setTimeout(resolve, msDuration)); + + let data = terminator.getTicksForShutdownPhases(); + + Assert.ok( + KEYS[currentPhase] in data, + "The KEYS object contains the expected key" + ); + Assert.equal( + Object.keys(data).length, + currentPhase + 1, + "KEYS object does not contain more durations than expected" + ); + + DATA[currentPhase] = data; + currentPhase++; + if (currentPhase < KEYS.length) { + return true; + } + return false; +}; + +// This is a timing affected test, as we want to check if the time measurements +// from the terminator are reasonable. Bug 1768795 assumes that they tend to +// be lower than wall-clock, in particular on MacOS, confirmed by the logs on +// intermittent bug 1760094. This is not a big deal for the terminator's +// general functionality (timeouts might just come a little later than +// expected nominally), but it makes testing harder and the transferred +// telemetry data slightly less reliable (shutdowns might appear shorter than +// they really were). So this test is just happy if there is any data that +// is not too long wrt what we expect. If we ever want to fix bug 1768795, +// we can check for a more reasonable lower boundary, too. +add_task(async function test_record() { + info("Collecting duration data for all known phases"); + + let morePhases = true; + while (morePhases) { + let beforeWait = Date.now(); + + morePhases = await advancePhase(); + + // We measure the effective time that passed as wall-clock and include all + // file IO overhead as the terminator will do so in its measurement, too. + MeasuredDurations[currentPhase - 1] = Math.floor( + (Date.now() - beforeWait) / HEARTBEAT_MS + ); + } + + Assert.equal(DATA.length, KEYS.length, "We have data for each phase"); + + for (let i = 0; i < KEYS.length; i++) { + let lastDuration = DATA[KEYS.length - 1][KEYS[i]]; + Assert.equal( + typeof lastDuration, + "number", + "Duration of phase " + i + ":" + KEYS[i] + " is a number" + ); + + // The durations are only meaningful after we advanced to the next phase. + if (i < KEYS.length - 1) { + // So we read it from the data written for the following phase. + let ticksDuration = DATA[i + 1][KEYS[i]]; + let measuredDuration = MeasuredDurations[i]; + info( + "measuredDuration:" + measuredDuration + " - " + typeof measuredDuration + ); + Assert.lessOrEqual( + ticksDuration, + measuredDuration + 2, + "Duration of phase " + i + ":" + KEYS[i] + " is not too long" + ); + Assert.greaterOrEqual( + ticksDuration, + 0, // TODO: Raise the lower boundary after bug 1768795. + "Duration of phase " + i + ":" + KEYS[i] + " is not too short" + ); + } + // This check is done only for phases <= xpcom-shutdown-threads + // where we have two data points. + if (i < KEYS.length - 2) { + let ticksDuration = DATA[i + 1][KEYS[i]]; + Assert.equal( + ticksDuration, + DATA[KEYS.length - 1][KEYS[i]], + "Duration of phase " + i + ":" + KEYS[i] + " hasn't changed" + ); + } + } + + // Note that after this check the KEYS array remains sorted, so this + // must be the last check to not get confused. + Assert.equal( + Object.keys(DATA[KEYS.length - 1]) + .sort() + .join(", "), + KEYS.sort().join(", "), + "The KEYS object contains all expected keys" + ); +}); diff --git a/toolkit/components/terminator/tests/xpcshell/test_terminator_record.js b/toolkit/components/terminator/tests/xpcshell/test_terminator_record.js deleted file mode 100644 index 62cee636f3..0000000000 --- a/toolkit/components/terminator/tests/xpcshell/test_terminator_record.js +++ /dev/null @@ -1,171 +0,0 @@ -/* Any copyright is dedicated to the Public Domain. - * http://creativecommons.org/publicdomain/zero/1.0/ */ -/* eslint-disable mozilla/no-arbitrary-setTimeout */ - -"use strict"; - -// Test that the Shutdown Terminator records durations correctly - -const { setTimeout } = ChromeUtils.importESModule( - "resource://gre/modules/Timer.sys.mjs" -); - -var PATH; -var PATH_TMP; -var terminator; - -var HEARTBEAT_MS = 100; - -let KEYS = [ - "quit-application", - "profile-change-net-teardown", - "profile-change-teardown", - "profile-before-change", - "profile-before-change-qm", - "xpcom-will-shutdown", - "xpcom-shutdown", - "xpcom-shutdown-threads", - "XPCOMShutdownFinal", - "CCPostLastCycleCollection", -]; - -let DATA = []; -let MeasuredDurations = []; - -add_task(async function init() { - do_get_profile(); - PATH = PathUtils.join(PathUtils.localProfileDir, "ShutdownDuration.json"); - PATH_TMP = PATH + ".tmp"; - - // Initialize the terminator - // (normally, this is done through the manifest file, but xpcshell - // doesn't take them into account). - info("Initializing the Terminator"); - terminator = Cc["@mozilla.org/toolkit/shutdown-terminator;1"].createInstance( - Ci.nsIObserver - ); -}); - -var promiseShutdownDurationData = async function () { - // Wait until PATH exists. - // Timeout if it is never created. - while (true) { - if (await IOUtils.exists(PATH)) { - break; - } - - // Wait just a very short period to not increase measured values. - // Usually the file should appear almost immediately. - await new Promise(resolve => setTimeout(resolve, 50)); - } - - return IOUtils.readJSON(PATH); -}; - -var currentPhase = 0; - -var advancePhase = async function () { - let key = "terminator-test-" + KEYS[currentPhase]; - let msDuration = 200 + HEARTBEAT_MS * currentPhase; - - info("Advancing shutdown phase to " + KEYS[currentPhase]); - terminator.observe(null, key, null); - await new Promise(resolve => setTimeout(resolve, msDuration)); - - let data = await promiseShutdownDurationData(); - - Assert.ok(KEYS[currentPhase] in data, "The file contains the expected key"); - Assert.equal( - Object.keys(data).length, - currentPhase + 1, - "File does not contain more durations than expected" - ); - - DATA[currentPhase] = data; - currentPhase++; - if (currentPhase < KEYS.length) { - return true; - } - return false; -}; - -// This is a timing affected test, as we want to check if the time measurements -// from the terminator are reasonable. Bug 1768795 assumes that they tend to -// be lower than wall-clock, in particular on MacOS, confirmed by the logs on -// intermittent bug 1760094. This is not a big deal for the terminator's -// general functionality (timeouts might just come a little later than -// expected nominally), but it makes testing harder and the transferred -// telemetry data slightly less reliable (shutdowns might appear shorter than -// they really were). So this test is just happy if there is any data that -// is not too long wrt what we expect. If we ever want to fix bug 1768795, -// we can check for a more reasonable lower boundary, too. -add_task(async function test_record() { - info("Collecting duration data for all known phases"); - - let morePhases = true; - while (morePhases) { - let beforeWait = Date.now(); - - morePhases = await advancePhase(); - - await IOUtils.remove(PATH); - await IOUtils.remove(PATH_TMP); - - // We measure the effective time that passed as wall-clock and include all - // file IO overhead as the terminator will do so in its measurement, too. - MeasuredDurations[currentPhase - 1] = Math.floor( - (Date.now() - beforeWait) / HEARTBEAT_MS - ); - } - - Assert.equal(DATA.length, KEYS.length, "We have data for each phase"); - - for (let i = 0; i < KEYS.length; i++) { - let lastDuration = DATA[KEYS.length - 1][KEYS[i]]; - Assert.equal( - typeof lastDuration, - "number", - "Duration of phase " + i + ":" + KEYS[i] + " is a number" - ); - - // The durations are only meaningful after we advanced to the next phase. - if (i < KEYS.length - 1) { - // So we read it from the data written for the following phase. - let ticksDuration = DATA[i + 1][KEYS[i]]; - let measuredDuration = MeasuredDurations[i]; - info( - "measuredDuration:" + measuredDuration + " - " + typeof measuredDuration - ); - Assert.lessOrEqual( - ticksDuration, - measuredDuration + 2, - "Duration of phase " + i + ":" + KEYS[i] + " is not too long" - ); - Assert.greaterOrEqual( - ticksDuration, - 0, // TODO: Raise the lower boundary after bug 1768795. - "Duration of phase " + i + ":" + KEYS[i] + " is not too short" - ); - } - // This check is done only for phases <= xpcom-shutdown-threads - // where we have two data points. - if (i < KEYS.length - 2) { - let ticksDuration = DATA[i + 1][KEYS[i]]; - Assert.equal( - ticksDuration, - DATA[KEYS.length - 1][KEYS[i]], - "Duration of phase " + i + ":" + KEYS[i] + " hasn't changed" - ); - } - } - - // Note that after this check the KEYS array remains sorted, so this - // must be the last check to not get confused. - Assert.equal( - Object.keys(DATA[KEYS.length - 1]) - .sort() - .join(", "), - KEYS.sort().join(", "), - "The last file contains all expected keys" - ); -}); diff --git a/toolkit/components/terminator/tests/xpcshell/test_terminator_reload.js b/toolkit/components/terminator/tests/xpcshell/test_terminator_reload.js deleted file mode 100644 index 79aecd818b..0000000000 --- a/toolkit/components/terminator/tests/xpcshell/test_terminator_reload.js +++ /dev/null @@ -1,88 +0,0 @@ -/* Any copyright is dedicated to the Public Domain. - * http://creativecommons.org/publicdomain/zero/1.0/ */ - -"use strict"; - -// Test that the Shutdown Terminator reloads durations correctly - -const HISTOGRAMS = { - "quit-application": "SHUTDOWN_PHASE_DURATION_TICKS_QUIT_APPLICATION", - "profile-change-net-teardown": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_CHANGE_NET_TEARDOWN", - "profile-change-teardown": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_CHANGE_TEARDOWN", - "profile-before-change": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_BEFORE_CHANGE", - "profile-before-change-qm": - "SHUTDOWN_PHASE_DURATION_TICKS_PROFILE_BEFORE_CHANGE_QM", - "xpcom-will-shutdown": "SHUTDOWN_PHASE_DURATION_TICKS_XPCOM_WILL_SHUTDOWN", - "xpcom-shutdown": "SHUTDOWN_PHASE_DURATION_TICKS_XPCOM_SHUTDOWN", -}; - -let PATH; - -add_setup(async function init() { - do_get_profile(); - PATH = PathUtils.join(PathUtils.localProfileDir, "ShutdownDuration.json"); -}); - -add_task(async function test_reload() { - info("Forging data"); - let data = {}; - let telemetrySnapshots = Services.telemetry.getSnapshotForHistograms( - "main", - false /* clear */ - ).parent; - let i = 0; - for (let k of Object.keys(HISTOGRAMS)) { - let id = HISTOGRAMS[k]; - data[k] = i++; - Assert.equal( - telemetrySnapshots[id] || undefined, - undefined, - "Histogram " + id + " is empty" - ); - } - - // Extra fields that nsTerminator reports that we do not have histograms for. - data["xpcom-shutdown-threads"] = 123; - data.XPCOMShutdownFinal = 456; - data.CCPostLastCycleCollection = 789; - - await IOUtils.writeJSON(PATH, data); - - const TOPIC = "shutdown-terminator-telemetry-updated"; - - let wait = new Promise(resolve => - Services.obs.addObserver(function observer() { - info("Telemetry has been updated"); - Services.obs.removeObserver(observer, TOPIC); - resolve(); - }, TOPIC) - ); - - info("Starting nsTerminatorTelemetry"); - let tt = Cc[ - "@mozilla.org/toolkit/shutdown-terminator-telemetry;1" - ].createInstance(Ci.nsIObserver); - tt.observe(null, "profile-after-change", ""); - - info("Waiting until telemetry is updated"); - // Now wait until Telemetry is updated - await wait; - - telemetrySnapshots = Services.telemetry.getSnapshotForHistograms( - "main", - false /* clear */ - ).parent; - for (let k of Object.keys(HISTOGRAMS)) { - let id = HISTOGRAMS[k]; - info("Testing histogram " + id); - let snapshot = telemetrySnapshots[id]; - let count = 0; - for (let x of Object.values(snapshot.values)) { - count += x; - } - Assert.equal(count, 1, "We have added one item"); - } -}); diff --git a/toolkit/components/terminator/tests/xpcshell/xpcshell.toml b/toolkit/components/terminator/tests/xpcshell/xpcshell.toml index cb328ca2c8..67cc36f265 100644 --- a/toolkit/components/terminator/tests/xpcshell/xpcshell.toml +++ b/toolkit/components/terminator/tests/xpcshell/xpcshell.toml @@ -1,15 +1,10 @@ [DEFAULT] head = "" -["test_terminator_record.js"] +["test_terminator_advance_phases.js"] skip-if = [ "debug", "asan", # Disabled by bug 1242084, bug 1255484 will enable it again "ccov", # Bug 1607583 tracks the ccov failure "tsan", # Bug 1683730 made this timeout for tsan. ] -run-sequentially = "very high failure rate in parallel" - -["test_terminator_reload.js"] -skip-if = ["os == 'android'"] -run-sequentially = "very high failure rate in parallel" -- cgit v1.2.3