Bug 1414740 - Insert info log before async helper functions in form autofill mochitests. r=lchang

MozReview-Commit-ID: JJN7R2WC2D4

--HG--
extra : rebase_source : 7524ffef0f93f74c76630baf221198c33fdf3318

browser/extensions/formautofill/test/browser/browser_autocomplete_footer.js

@@ -28,8 +28,13 @@ add_task(async function test_click_on_footer() {
     // Click on the footer
     const optionButton = itemsBox.querySelector(".autocomplete-richlistitem:last-child")._optionButton;
     const prefTabPromise = BrowserTestUtils.waitForNewTab(gBrowser, PRIVACY_PREF_URL);
+    // Wait for dropdown animation finished to continue mouse synthesizing.
+    await sleep(1000);
     await EventUtils.synthesizeMouseAtCenter(optionButton, {});
-    await BrowserTestUtils.removeTab(await prefTabPromise);
+    info(`expecting tab: about:preferences#privacy opened`);
+    const prefTab = await prefTabPromise;
+    info(`expecting tab: about:preferences#privacy removed`);
+    await BrowserTestUtils.removeTab(prefTab);
     ok(true, "Tab: preferences#privacy was successfully opened by clicking on the footer");
 
     await closePopup(browser);
@@ -48,7 +53,10 @@ add_task(async function test_press_enter_on_footer() {
       await BrowserTestUtils.synthesizeKey("VK_DOWN", {}, browser);
     }
     await BrowserTestUtils.synthesizeKey("VK_RETURN", {}, browser);
-    await BrowserTestUtils.removeTab(await prefTabPromise);
+    info(`expecting tab: about:preferences#privacy opened`);
+    const prefTab = await prefTabPromise;
+    info(`expecting tab: about:preferences#privacy removed`);
+    await BrowserTestUtils.removeTab(prefTab);
     ok(true, "Tab: preferences#privacy was successfully opened by pressing enter on the footer");
 
     await closePopup(browser);

browser/extensions/formautofill/test/browser/browser_autocomplete_marked_back_forward.js

@@ -31,6 +31,7 @@ add_task(async function test_back_forward() {
     // Now navigate forward and make sure autofill autocomplete results are still attached
     let loadPromise = BrowserTestUtils.browserLoaded(browser);
     await BrowserTestUtils.loadURI(browser, `${URL}?load=2`);
+    info("expecting browser loaded");
     await loadPromise;
 
     // Check the second page
@@ -40,6 +41,7 @@ add_task(async function test_back_forward() {
     // Check after hitting back to the first page
     let stoppedPromise = BrowserTestUtils.browserStopped(browser);
     browser.goBack();
+    info("expecting browser stopped");
     await stoppedPromise;
     await openPopupOn(browser, "#street-address");
     checkPopup(autoCompletePopup);
@@ -47,6 +49,7 @@ add_task(async function test_back_forward() {
     // Check after hitting forward to the second page
     stoppedPromise = BrowserTestUtils.browserStopped(browser);
     browser.goForward();
+    info("expecting browser stopped");
     await stoppedPromise;
     await openPopupOn(browser, "#street-address");
     checkPopup(autoCompletePopup);

browser/extensions/formautofill/test/browser/browser_autocomplete_marked_detached_tab.js

@@ -30,6 +30,7 @@ add_task(async function test_detach_tab_marked() {
     await closePopup(browser);
 
     // Detach the tab to a new window
+    info("expecting tab replaced with new window");
     let newWin = gBrowser.replaceTabWithWindow(gBrowser.getTabForBrowser(browser));
     await TestUtils.topicObserved("browser-delayed-startup-finished", subject => {
       return subject == newWin;

browser/extensions/formautofill/test/browser/browser_insecure_form.js

@@ -53,10 +53,9 @@ add_task(async function test_insecure_form() {
     expectedResultLength: 1,
   }];
 
-  await runTest(testSets[0]);
-  await runTest(testSets[1]);
-  await runTest(testSets[2]);
-  await runTest(testSets[3]);
+  for (const test of testSets) {
+    await runTest(test);
+  }
 });
 
 add_task(async function test_click_on_insecure_warning() {

browser/extensions/formautofill/test/browser/head.js

@@ -102,6 +102,7 @@ async function sleep(ms = 500) {
 }
 
 async function focusAndWaitForFieldsIdentified(browser, selector) {
+  info("expecting the target input being focused and indentified");
   /* eslint no-shadow: ["error", { "allow": ["selector", "previouslyFocused", "previouslyIdentified"] }] */
   const {previouslyFocused, previouslyIdentified} = await ContentTask.spawn(browser, {selector}, async function({selector}) {
     Components.utils.import("resource://gre/modules/FormLikeFactory.jsm");
@@ -176,6 +177,7 @@ async function closePopup(browser) {
 }
 
 function getRecords(data) {
+  info(`expecting record retrievals: ${data.collectionName}`);
   return new Promise(resolve => {
     Services.cpmm.addMessageListener("FormAutofill:Records", function getResult(result) {
       Services.cpmm.removeMessageListener("FormAutofill:Records", getResult);
@@ -194,11 +196,13 @@ function getCreditCards() {
 }
 
 function saveAddress(address) {
+  info("expecting address saved");
   Services.cpmm.sendAsyncMessage("FormAutofill:SaveAddress", {address});
   return TestUtils.topicObserved("formautofill-storage-changed");
 }
 
 function saveCreditCard(creditcard) {
+  info("expecting credit card saved");
   let creditcardClone = Object.assign({}, creditcard);
   Services.cpmm.sendAsyncMessage("FormAutofill:SaveCreditCard", {
     creditcard: creditcardClone,
@@ -207,11 +211,13 @@ function saveCreditCard(creditcard) {
 }
 
 function removeAddresses(guids) {
+  info("expecting address removed");
   Services.cpmm.sendAsyncMessage("FormAutofill:RemoveAddresses", {guids});
   return TestUtils.topicObserved("formautofill-storage-changed");
 }
 
 function removeCreditCards(guids) {
+  info("expecting credit card removed");
   Services.cpmm.sendAsyncMessage("FormAutofill:RemoveCreditCards", {guids});
   return TestUtils.topicObserved("formautofill-storage-changed");
 }
@@ -236,6 +242,7 @@ async function clickDoorhangerButton(button, index) {
     EventUtils.synthesizeMouseAtCenter(getNotification()[button], {});
   } else if (button == MENU_BUTTON) {
     // Click the dropmarker arrow and wait for the menu to show up.
+    info("expecting notification menu button present");
     await BrowserTestUtils.waitForCondition(() => getNotification().menubutton);
     await sleep(2000); // menubutton needs extra time for binding
     let notification = getNotification();
@@ -243,11 +250,13 @@ async function clickDoorhangerButton(button, index) {
     let dropdownPromise =
       BrowserTestUtils.waitForEvent(notification.menupopup, "popupshown");
     await EventUtils.synthesizeMouseAtCenter(notification.menubutton, {});
+    info("expecting notification popup show up");
     await dropdownPromise;
 
     let actionMenuItem = notification.querySelectorAll("menuitem")[index];
     await EventUtils.synthesizeMouseAtCenter(actionMenuItem, {});
   }
+  info("expecting notification popup hidden");
   await popuphidden;
 }
 
@@ -264,6 +273,7 @@ function getDoorhangerButton(button) {
 // Wait for the master password dialog to popup and enter the password to log in
 // if "login" is "true" or dismiss it directly if otherwise.
 function waitForMasterPasswordDialog(login = false) {
+  info("expecting master password dialog loaded");
   let dialogShown = TestUtils.topicObserved("common-dialog-loaded");
   return dialogShown.then(([subject]) => {
     let dialog = subject.Dialog;

browser/extensions/formautofill/test/mochitest/formautofill_common.js

@@ -15,6 +15,7 @@ async function sleep(ms = 500, reason = "Intentionally wait for UI ready") {
 }
 
 async function focusAndWaitForFieldsIdentified(input, mustBeIdentified = false) {
+  info("expecting the target input being focused and indentified");
   if (typeof input === "string") {
     input = document.querySelector(input);
   }
@@ -66,6 +67,7 @@ function clickOnElement(selector) {
 }
 
 async function onStorageChanged(type) {
+  info(`expecting the storage changed: ${type}`);
   return new Promise(resolve => {
     formFillChromeScript.addMessageListener("formautofill-storage-changed", function onChanged(data) {
       formFillChromeScript.removeMessageListener("formautofill-storage-changed", onChanged);
@@ -87,6 +89,7 @@ function checkMenuEntries(expectedValues, isFormAutofillResult = true) {
 }
 
 function invokeAsyncChromeTask(message, response, payload = {}) {
+  info(`expecting the chrome task finished: ${message}`);
   return new Promise(resolve => {
     formFillChromeScript.sendAsyncMessage(message, payload);
     formFillChromeScript.addMessageListener(response, function onReceived(data) {
@@ -192,6 +195,7 @@ function formAutoFillCommonSetup() {
 
   SimpleTest.registerCleanupFunction(async () => {
     formFillChromeScript.sendAsyncMessage("cleanup");
+    info(`expecting the storage cleanup`);
     await formFillChromeScript.promiseOneMessage("cleanup-finished");
 
     formFillChromeScript.destroy();

browser/extensions/formautofill/test/mochitest/test_basic_autocomplete_form.html

@@ -61,6 +61,7 @@ function checkAutoCompleteInputFilled(element, expectedvalue) {
 }
 
 function checkFormFilled(address) {
+  info("expecting form filled");
   let promises = [];
   for (let prop in address) {
     let element = document.getElementById(prop);

browser/extensions/formautofill/test/mochitest/test_basic_creditcard_autocomplete_form.html

@@ -62,6 +62,7 @@ function checkElementFilled(element, expectedvalue) {
 }
 
 function checkFormFilled(creditCard) {
+  info("expecting form filled");
   let promises = [];
   for (let prop in creditCard) {
     let element = document.getElementById(prop);

browser/extensions/formautofill/test/mochitest/test_form_changes.html

@@ -47,6 +47,7 @@ function addInputField(form, className) {
 }
 
 async function checkFormChangeHappened(formId) {
+  info("expecting form changed");
   await focusAndWaitForFieldsIdentified(`#${formId} input[name=tel]`);
   doKey("down");
   await expectPopup();

browser/extensions/formautofill/test/mochitest/test_formautofill_preview_highlight.html

@@ -73,6 +73,7 @@ function checkFormFilledFields(address) {
 }
 
 function confirmAllFieldsFilled(address) {
+  info("expecting form filled");
   const pendingPromises = [];
 
   for (const prop in address) {