With logging draft
authorJan-Erik Rediger <jrediger@mozilla.com>
Sat, 16 Jun 2018 19:18:00 -0700
changeset 808172 c709e9f4a8921ddcedfd3eb276b57293fa547e1f
parent 808171 012060b95ac813e9e3ad09a68f1e75f9b84e00d9
child 808173 982472c5815d55573a3e3da9b8e79380e20bc06d
push id113303
push userbmo:jrediger@mozilla.com
push dateMon, 18 Jun 2018 16:42:17 +0000
milestone62.0a1
With logging MozReview-Commit-ID: AgRcPxmlJyS
toolkit/components/telemetry/tests/unit/test_GeckoView_ScalarSemantics.js
toolkit/components/telemetry/tests/unit/test_GeckoView_content_scalars.js
--- a/toolkit/components/telemetry/tests/unit/test_GeckoView_ScalarSemantics.js
+++ b/toolkit/components/telemetry/tests/unit/test_GeckoView_ScalarSemantics.js
@@ -20,89 +20,107 @@ add_task(async function setup() {
   Services.prefs.setBoolPref("toolkit.telemetry.isGeckoViewMode", true);
 
   // Set the ANDROID_DATA_DIR to the profile dir.
   let env = Cc["@mozilla.org/process/environment;1"].getService(Ci.nsIEnvironment);
   env.set("MOZ_ANDROID_DATA_DIR", profileDir.path);
 });
 
 add_task(async function test_MultiprocessScalarSemantics() {
+  console.log("JER - test_MultiprocessScalarSemantics - start");
   /**
    * To mitigate races during deserialization of persisted data
    * scalar operations will be recorded and applied after the deserialization is finished.
    *
    * This test ensures it works acording to the semantics and follows the documentation example:
    *
    *  * Scalar deserialization is started
    *  * “test” scalar is incremented by “10” by the application -> The operation [test, add, 10] is recorded into the list.
    *  * The state of the “test” scalar is loaded off the persistence file, and the value “14” is set.
    *  * Deserialization is finished and the pending operations are applied.
    *  * The “test” scalar is incremented by “10”, the value is now “24”
    */
 
+  console.log("JER - test_MultiprocessScalarSemantics - clear");
   Telemetry.clearScalars();
 
+  console.log("JER - test_MultiprocessScalarSemantics - initPersistence");
   TelemetryGeckoView.initPersistence();
 
   // Set something in the parent
   Telemetry.scalarSet(ALL_PROCESSES_UINT_SCALAR, 34);
 
   // Set scalars in the child process.
   // The child will then wait for a signal to continue.
+  console.log("JER - test_MultiprocessScalarSemantics - starting child");
   let child = run_in_child("test_GeckoView_content_scalars.js");
 
   // Wait for the data to be collected by the parent process.
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting all_process");
   await waitForScalarSnapshotData(ALL_PROCESSES_UINT_SCALAR, "parent", false /* aKeyed */);
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting content_only");
   await waitForScalarSnapshotData(CONTENT_ONLY_UINT_SCALAR, "content", false /* aKeyed */);
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting content - all-proc");
   await waitForScalarSnapshotData(ALL_PROCESSES_UINT_SCALAR, "content", false /* aKeyed */);
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting content - child-keyed");
   await waitForScalarSnapshotData(CHILD_KEYED_UNSIGNED_INT, "content", true /* aKeyed */);
 
   let snapshot = Telemetry.snapshotScalars(Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTIN, false /* clear */);
   let keyedSnapshot = Telemetry.snapshotKeyedScalars(Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTIN, false /* clear */);
   Assert.equal(snapshot.content[CONTENT_ONLY_UINT_SCALAR], 14,
             `The ${CONTENT_ONLY_UINT_SCALAR} scalar must have the expected value in the content section.`);
   Assert.equal(snapshot.content[ALL_PROCESSES_UINT_SCALAR], 24,
             `The ${ALL_PROCESSES_UINT_SCALAR} scalar must have the expected value in the content section.`);
   Assert.equal(snapshot.parent[ALL_PROCESSES_UINT_SCALAR], 34,
             `The ${ALL_PROCESSES_UINT_SCALAR} scalar must have the expected value in the parent section.`);
   Assert.equal(keyedSnapshot.content[CHILD_KEYED_UNSIGNED_INT].chewbacca, 44,
             `The ${CHILD_KEYED_UNSIGNED_INT} keyed scalar must have the expected value in the content section.`);
 
   // Force persisting the measurements to file.
+  console.log("JER - test_MultiprocessScalarSemantics - force");
   TelemetryGeckoView.forcePersist();
+  console.log("JER - test_MultiprocessScalarSemantics - deinit");
   TelemetryGeckoView.deInitPersistence();
 
   // Clear all data from memory.
+  console.log("JER - test_MultiprocessScalarSemantics - clear");
   Telemetry.clearScalars();
 
   // Mark deserialization as in progress, following operations are recorded and not applied.
+  console.log("JER - test_MultiprocessScalarSemantics - deserialize started");
   TelemetryGeckoView.deserializationStarted();
 
   // Modify a scalar in the parent process.
   Telemetry.scalarAdd(ALL_PROCESSES_UINT_SCALAR, 10);
 
   // Let child know to progress and wait for it to finish.
+  console.log("JER - test_MultiprocessScalarSemantics - sending remote message");
   do_send_remote_message("child-scalar-semantics");
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting child");
   await child;
 
   // Start the persistence system again, to unpersist the data.
   let loadPromise = waitGeckoViewLoadComplete();
+  console.log("JER - test_MultiprocessScalarSemantics - init persistence");
   TelemetryGeckoView.initPersistence();
   // Wait for the load to finish.
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting loadcomplete");
   await loadPromise;
 
   // Wait for the data to be collected by the parent process.
   // We only wait for the new data, as the rest will be in there from the persistence load.
+  console.log("JER - test_MultiprocessScalarSemantics - awaiting default produts");
   await waitForScalarSnapshotData(DEFAULT_PRODUCTS_SCALAR, "content", false /* aKeyed */);
 
   // Validate the snapshot data.
   snapshot =
     Telemetry.snapshotScalars(Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTIN, false /* clear */);
   keyedSnapshot =
     Telemetry.snapshotKeyedScalars(Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTIN, false /* clear */);
+  console.log("JER - test_MultiprocessScalarSemantics - snapshots done");
 
   Assert.ok("parent" in snapshot, "The snapshot object must have a 'content' entry.");
   Assert.ok("content" in snapshot, "The snapshot object must have a 'content' entry.");
   Assert.ok("content" in keyedSnapshot, "The keyed snapshot object must have a 'content' entry.");
 
   Assert.ok(ALL_PROCESSES_UINT_SCALAR in snapshot.parent,
             `The ${ALL_PROCESSES_UINT_SCALAR} scalar must exist in the parent section.`);
   Assert.ok(CONTENT_ONLY_UINT_SCALAR in snapshot.content,
@@ -116,14 +134,15 @@ add_task(async function test_Multiproces
                `The ${ALL_PROCESSES_UINT_SCALAR} must have the expected value in the content section.`);
 
   Assert.equal(snapshot.parent[ALL_PROCESSES_UINT_SCALAR], 44,
                `The ${ALL_PROCESSES_UINT_SCALAR} must have the expected value in the parent section.`);
 
   Assert.equal(keyedSnapshot.content[CHILD_KEYED_UNSIGNED_INT].chewbacca, 54,
             `The ${CHILD_KEYED_UNSIGNED_INT} keyed scalar must have the expected value in the content section.`);
 
+  console.log("JER - test_MultiprocessScalarSemantics - deinit");
   TelemetryGeckoView.deInitPersistence();
 });
 
 add_task(async function cleanup() {
   Services.prefs.clearUserPref("toolkit.telemetry.isGeckoViewMode");
 });
--- a/toolkit/components/telemetry/tests/unit/test_GeckoView_content_scalars.js
+++ b/toolkit/components/telemetry/tests/unit/test_GeckoView_content_scalars.js
@@ -8,23 +8,28 @@ ChromeUtils.import("resource://gre/modul
 const CONTENT_ONLY_UINT_SCALAR = "telemetry.test.content_only_uint";
 const ALL_PROCESSES_UINT_SCALAR = "telemetry.test.all_processes_uint";
 const DEFAULT_PRODUCTS_SCALAR = "telemetry.test.default_products";
 const CHILD_KEYED_UNSIGNED_INT = "telemetry.test.child_keyed_unsigned_int";
 
 // Note: this test file is only supposed to be run by
 // test_GeckoView_ScalarSemantics.js.
 // It assumes to be in the content process.
-add_task(async function run_test() {
+add_task(async function run_child() {
+  console.log("JER - run_child - child running");
   // Set initial values in content process.
   Services.telemetry.scalarSet(CONTENT_ONLY_UINT_SCALAR, 14);
   Services.telemetry.scalarSet(ALL_PROCESSES_UINT_SCALAR, 24);
   Services.telemetry.keyedScalarSet(CHILD_KEYED_UNSIGNED_INT, "chewbacca", 44);
+  console.log("JER - run_child - scalars set");
 
   // Wait for the parent to inform us to continue.
+  console.log("JER - run_child - waiting for signal");
   await do_await_remote_message("child-scalar-semantics");
+  console.log("JER - run_child - received signal");
 
   // Modifications to probes will be recorded and applied later.
   Services.telemetry.scalarAdd(CONTENT_ONLY_UINT_SCALAR, 10);
   Services.telemetry.scalarAdd(ALL_PROCESSES_UINT_SCALAR, 10);
   Services.telemetry.keyedScalarAdd(CHILD_KEYED_UNSIGNED_INT, "chewbacca", 10);
   Services.telemetry.scalarSet(DEFAULT_PRODUCTS_SCALAR, 1);
+  console.log("JER - run_child - all done - end");
 });