Bug 633498 - Provide structured context information about mozmill failures.
authorAndrew Sutherland <asutherland@asutherland.org>
Thu, 10 Mar 2011 11:53:36 -0800
changeset 7317 dd7768eaabf2e4a0e3e2ce13b33fcda09fd9c71b
parent 7316 141c656b38ea3cca9da1caef32153c9eb9dc266a
child 7318 6609dcc741a7c1b64ddb375a1155db718723ac75
push idunknown
push userunknown
push dateunknown
bugs633498
Bug 633498 - Provide structured context information about mozmill failures. For the time being, browse to http://arbpl.visophyte.org/ to see the fruits of the structured data. The code that powers that site can be found at: https://github.com/asutherland/arbitrarypushlog
mail/base/content/msgHdrViewOverlay.js
mail/base/test/unit/resources/viewWrapperTestUtils.js
mail/test/mozmill/content-tabs/test-content-tab.js
mail/test/mozmill/folder-display/test-columns.js
mail/test/mozmill/folder-display/test-display-message-with-folder-modes.js
mail/test/mozmill/folder-display/test-message-commands.js
mail/test/mozmill/folder-display/test-right-click-middle-click-folders.js
mail/test/mozmill/folder-display/test-right-click-middle-click-messages.js
mail/test/mozmill/folder-display/test-savedsearch-reload-after-compact.js
mail/test/mozmill/folder-tree-modes/test-custom-folder-tree-mode.js
mail/test/mozmill/message-header/test-message-header.js
mail/test/mozmill/quick-filter-bar/test-display-issues.js
mail/test/mozmill/runtest.py
mail/test/mozmill/search-window/test-search-window.js
mail/test/mozmill/shared-modules/test-account-manager-helpers.js
mail/test/mozmill/shared-modules/test-folder-display-helpers.js
mail/test/mozmill/shared-modules/test-migration-helpers.js
mail/test/mozmill/shared-modules/test-search-window-helpers.js
mail/test/mozmill/shared-modules/test-window-helpers.js
mailnews/db/gloda/modules/log4moz.js
mailnews/test/resources/logHelper.js
mailnews/test/resources/messageInjection.js
--- a/mail/base/content/msgHdrViewOverlay.js
+++ b/mail/base/content/msgHdrViewOverlay.js
@@ -576,17 +576,17 @@ var messageHeaderSink = {
         try {
           size = fileHandler.getFileFromURLSpec(url).fileSize;
         }
         catch(e) {
           dump("Couldn't open external attachment!");
         }
       }
 
-      currentAttachments.push (new createNewAttachmentInfo(contentType, url, displayName, 
+      currentAttachments.push (new createNewAttachmentInfo(contentType, url, displayName,
                                                            uri, isExternalAttachment, size));
       // If we have an attachment, set the nsMsgMessageFlags.Attachment flag
       // on the hdr to cause the "message with attachment" icon to show up
       // in the thread pane.
       // We only need to do this on the first attachment.
       var numAttachments = currentAttachments.length;
       if (numAttachments == 1) {
         // we also have to enable the File/Attachments menuitem
@@ -618,26 +618,32 @@ var messageHeaderSink = {
         last.size = null;
       }
     },
 
     onEndAllAttachments: function()
     {
       displayAttachmentsForExpandedView();
 
-      gMessageDisplay.onLoadCompleted();
-
       for each (let [, listener] in Iterator(gMessageListeners)) {
         if ("onEndAttachments" in listener)
           listener.onEndAttachments();
       }
     },
 
+    /**
+     * This event is generated by nsMsgStatusFeedback when it gets an
+     * OnStateChange event for STATE_STOP.  This is the same event that
+     * generates the "msgLoaded" property flag change event.  This best
+     * corresponds to the end of the streaming process.
+     */
     onEndMsgDownload: function(url)
     {
+      gMessageDisplay.onLoadCompleted();
+
       // if we don't have any attachments, turn off the attachments flag
       if (!this.mSaveHdr)
       {
         var messageUrl = url.QueryInterface(Components.interfaces.nsIMsgMessageUrl);
         this.mSaveHdr = messenger.msgHdrFromURI(messageUrl.uri);
       }
       if (!currentAttachments.length && this.mSaveHdr)
         this.mSaveHdr.markHasAttachments(false);
@@ -1588,17 +1594,17 @@ function CopyNewsgroupURL(newsgroupNode)
 }
 
 /**
  * Create a new attachment object which goes into the data attachment array.
  * This method checks whether the passed attachment is empty or not.
  *
  * @param contentType The attachment's mimetype
  * @param url The URL for the attachment
- * @param displayName The name to be displayed for this attachment (usually the 
+ * @param displayName The name to be displayed for this attachment (usually the
           filename)
  * @param uri The URI for the message containing the attachment
  * @param isExternalAttachment True if the attachment has been detached
  * @param size The size in bytes of the attachment
  */
 function createNewAttachmentInfo(contentType, url, displayName, uri,
                                  isExternalAttachment, size)
 {
--- a/mail/base/test/unit/resources/viewWrapperTestUtils.js
+++ b/mail/base/test/unit/resources/viewWrapperTestUtils.js
@@ -440,30 +440,32 @@ function verify_messages_in_view(aSynSet
     }
     // the view is showing a message that should not be shown, explode.
     else {
       dump("The view is showing the following message header and should not" +
            " be:\n");
       dump_message_header(msgHdr);
       dump("View State:\n");
       dump_view_state(aViewWrapper);
-      do_throw("view contains header that should not be present!");
+      mark_failure(["view contains header that should not be present!",
+                    msgHdr]);
     }
   }
 
   // - Iterate over our URI set and make sure every message got nulled out.
   for each (let [, msgHdr] in Iterator(synMessageURIs)) {
     if (msgHdr != null) {
       dump("************************\n");
       dump("The view should have included the following message header but" +
            " did not:\n");
       dump_message_header(msgHdr);
       dump("View State:\n");
       dump_view_state(aViewWrapper);
-      do_throw("view does not contain a header that should be present!");
+      mark_failure(["view does not contain a header that should be present!",
+                    msgHdr]);
     }
   }
 }
 
 /**
  * Assert if the view wrapper is displaying any messages.
  */
 function verify_empty_view(aViewWrapper) {
--- a/mail/test/mozmill/content-tabs/test-content-tab.js
+++ b/mail/test/mozmill/content-tabs/test-content-tab.js
@@ -86,44 +86,45 @@ function test_content_tab_open() {
 /**
  * Just make sure that the context menu does what we expect in content tabs wrt.
  * spell checking options.
  */
 function test_spellcheck_in_content_tabs() {
   let tabmail = mc.tabmail;
   let w = tabmail.selectedTab.browser.contentWindow;
   let textarea = w.document.getElementsByTagName("textarea")[0];
+  let eidMailContext = mc.eid("mailContext");
 
   // Test a few random items
   mc.rightClick(new elementslib.Elem(textarea));
   assert_element_visible("mailContext-spell-dictionaries");
   assert_element_visible("mailContext-spell-check-enabled");
   assert_element_not_visible("mailContext-replySender"); // we're in a content tab!
-  close_popup();
+  close_popup(mc, eidMailContext);
 
   // Different test
   mc.rightClick(new elementslib.Elem(w.document.body.firstElementChild));
   assert_element_not_visible("mailContext-spell-dictionaries");
   assert_element_not_visible("mailContext-spell-check-enabled");
-  close_popup();
+  close_popup(mc, eidMailContext);
 
   // Right-click on "zombocom" and add to dictionary
   EventUtils.synthesizeMouse(textarea, 5, 5,
                              {type: "contextmenu", button: 2}, w);
   let suggestions = mc.window.document.getElementsByClassName("spell-suggestion");
   assert_true(suggestions.length > 0, "What, is zombocom a registered word now?");
   mc.click(mc.eid("mailContext-spell-add-to-dictionary"));
-  close_popup();
+  close_popup(mc, eidMailContext);
 
   // Now check we don't have any suggestionss
   EventUtils.synthesizeMouse(textarea, 5, 5,
                              {type: "contextmenu", button: 2}, w);
   let suggestions = mc.window.document.getElementsByClassName("spell-suggestion");
   assert_true(suggestions.length == 0, "But I just taught you this word!");
-  close_popup();
+  close_popup(mc, eidMailContext);
 }
 
 function test_content_tab_open_same() {
   let preCount = mc.tabmail.tabContainer.childNodes.length;
 
   mc.click(new elementslib.Elem(mc.menus.helpMenu.whatsNew));
 
   controller.sleep(0);
--- a/mail/test/mozmill/folder-display/test-columns.js
+++ b/mail/test/mozmill/folder-display/test-columns.js
@@ -363,18 +363,20 @@ function invoke_column_picker_option(aAc
   //  treadCols
   //   |- hbox                item 0
   //   |- treecolpicker   <-- item 1 this is the one we want
   let threadCols = mc.window.document.getElementById("threadCols");
   let colPicker = mc.window.document.getAnonymousNodes(threadCols).item(1);
   let colPickerPopup = mc.window.document.getAnonymousElementByAttribute(
                          colPicker, "anonid", "popup");
 
-  mc.click(new elib.Elem(colPicker), 10, 10);
+  mc.click(new elib.Elem(colPicker));
+  wait_for_popup_to_open(colPickerPopup);
   mc.click_menus_in_sequence(colPickerPopup, aActions);
+  close_popup(mc, new elib.Elem(colPickerPopup));
 }
 
 
 /**
  * The column picker's "reset columns to default" option should set our state
  *  back to inbox state.
  */
 function test_reset_to_inbox() {
--- a/mail/test/mozmill/folder-display/test-display-message-with-folder-modes.js
+++ b/mail/test/mozmill/folder-display/test-display-message-with-folder-modes.js
@@ -66,17 +66,18 @@ function setupModule(module) {
   inboxFolder.createSubfolder("DisplayMessageWithFolderModesA", null);
   folder = inboxFolder.getChildNamed("DisplayMessageWithFolderModesA");
   // This second folder is meant to act as a dummy folder to switch to when we
   // want to not be in folder.
   inboxFolder.createSubfolder("DisplayMessageWithFolderModesB", null);
   dummyFolder = inboxFolder.getChildNamed("DisplayMessageWithFolderModesB");
   make_new_sets_in_folder(folder, [{count: 5}]);
   // The message itself doesn't really matter, as long as there's at least one
-  // in the inbox.
+  // in the inbox.  We will delete this in teardownModule because the inbox
+  // is a shared resource and it's not okay to leave stuff in there.
   make_new_sets_in_folder(inboxFolder, [{count: 1}]);
 }
 
 /**
  * Test that displaying a message causes a switch to the default folder mode if
  * the folder isn't present in the current folder mode.
  */
 function test_display_message_with_folder_not_present_in_current_folder_mode() {
@@ -198,8 +199,14 @@ function test_display_inbox_message_in_s
 }
 
 /**
  * Move back to the all folders mode.
  */
 function test_switch_to_all_folders() {
   mc.folderTreeView.mode = "all";
 }
+
+function teardownModule() {
+  be_in_folder(inboxFolder);
+  select_click_row(0);
+  press_delete();
+}
--- a/mail/test/mozmill/folder-display/test-message-commands.js
+++ b/mail/test/mozmill/folder-display/test-message-commands.js
@@ -86,25 +86,22 @@ function check_read_status(messages, rea
 
 /**
  * Ensures that the mark read/unread menu items are enabled/disabled properly
  * @param canMarkRead true if the mark read item should be enabled
  * @param canMarkUnread true if the mark unread item should be enabled
  */
 function check_read_menuitems(index, canMarkRead, canMarkUnread) {
   right_click_on_row(index);
+  wait_for_popup_to_open(mc.e("mailContext"));
   mc.click_menus_in_sequence(mc.e("mailContext"), [{id: "mailContext-mark"}]);
 
   let readEnabled = !mc.e("mailContext-markRead").disabled;
   let unreadEnabled = !mc.e("mailContext-markUnread").disabled;
 
-  // Close both the mark submenu and the main context menu
-  close_popup();
-  close_popup();
-
   assert_true(readEnabled == canMarkRead,
               "Mark read menu item " + (canMarkRead ? "dis" : "en") +
               "abled when it shouldn't be!");
 
   assert_true(unreadEnabled == canMarkUnread,
               "Mark unread menu item " + (canMarkUnread ? "dis" : "en") +
               "abled when it shouldn't be!");
 }
--- a/mail/test/mozmill/folder-display/test-right-click-middle-click-folders.js
+++ b/mail/test/mozmill/folder-display/test-right-click-middle-click-folders.js
@@ -78,77 +78,77 @@ function test_right_click_folder_with_no
   select_no_folders();
   assert_no_folders_selected();
 
   right_click_on_folder(folderB);
   assert_folder_selected(folderB);
   // The displayed folder shouldn't change
   assert_folder_displayed(folderA);
 
-  close_popup();
+  close_popup(mc, mc.eid("folderPaneContext"));
   assert_no_folders_selected();
 }
 
 /**
  * One-thing selected, right-click on something else.
  */
 function test_right_click_folder_with_one_thing_selected() {
   select_click_folder(folderB);
   assert_folder_selected_and_displayed(folderB);
 
   right_click_on_folder(folderA);
   assert_folder_selected(folderA);
   assert_folder_displayed(folderB);
 
-  close_popup();
+  close_popup(mc, mc.eid("folderPaneContext"));
   assert_folder_selected_and_displayed(folderB);
 }
 
 /**
  * Many things selected, right-click on something that is not in that selection.
  */
 function test_right_click_folder_with_many_things_selected() {
   select_click_folder(folderA);
   select_shift_click_folder(folderB);
   assert_folders_selected_and_displayed(folderA, folderB);
 
   right_click_on_folder(folderC);
   assert_folder_selected(folderC);
   assert_folder_displayed(folderA);
 
-  close_popup();
+  close_popup(mc, mc.eid("folderPaneContext"));
   assert_folders_selected_and_displayed(folderA, folderB);
 }
 
 /**
  * One thing selected, right-click on that.
  */
 function test_right_click_folder_on_existing_single_selection() {
   select_click_folder(folderA);
   assert_folders_selected_and_displayed(folderA);
 
   right_click_on_folder(folderA);
   assert_folders_selected_and_displayed(folderA);
 
-  close_popup();
+  close_popup(mc, mc.eid("folderPaneContext"));
   assert_folders_selected_and_displayed(folderA);
 }
 
 /**
  * Many things selected, right-click somewhere in the selection.
  */
 function test_right_click_folder_on_existing_multi_selection() {
   select_click_folder(folderB);
   select_shift_click_folder(folderC);
   assert_folders_selected_and_displayed(folderB, folderC);
 
   right_click_on_folder(folderC);
   assert_folders_selected_and_displayed(folderB, folderC);
 
-  close_popup();
+  close_popup(mc, mc.eid("folderPaneContext"));
   assert_folders_selected_and_displayed(folderB, folderC);
 }
 
 /**
  * Middle clicking should open a message in a tab, but not affect our selection.
  */
 function _middle_click_folder_with_nothing_selected_helper(aBackground) {
   // This should cause folderA to be displayed
--- a/mail/test/mozmill/folder-display/test-right-click-middle-click-messages.js
+++ b/mail/test/mozmill/folder-display/test-right-click-middle-click-messages.js
@@ -30,16 +30,19 @@
  * use your version of this file under the terms of the MPL, indicate your
  * decision by deleting the provisions above and replace them with the notice
  * and other provisions required by the GPL or the LGPL. If you do not delete
  * the provisions above, a recipient may use your version of this file under
  * the terms of any one of the MPL, the GPL or the LGPL.
  *
  * ***** END LICENSE BLOCK ***** */
 
+var elib = {};
+Cu.import('resource://mozmill/modules/elementslib.js', elib);
+
 /*
  * Test the many horrors involving right-clicks, middle clicks, and selections.
  */
 
 var MODULE_NAME = 'test-right-click-middle-click-messages';
 
 var RELATIVE_ROOT = '../shared-modules';
 var MODULE_REQUIRES = ['folder-display-helpers', 'window-helpers'];
@@ -78,63 +81,66 @@ function setupModule(module) {
  */
 function test_right_click_with_nothing_selected() {
   be_in_folder(folder);
 
   select_none();
   assert_nothing_selected();
 
   right_click_on_row(1);
+  // Check that the popup opens.
+  wait_for_popup_to_open(mc.e("mailContext"));
+
   assert_selected(1);
   assert_displayed();
 
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   assert_nothing_selected();
 }
 
 /**
  * Test that clicking on the column header shows the column picker.
  */
 function test_right_click_column_header_shows_col_picker() {
   be_in_folder(folder);
 
-  // Right click the subject columen header (must use 10 10 offset to make it work!)
-  // This should show the column picker popup.
-  mc.rightClick(mc.eid("subjectCol"), 10, 10);
-
   // The treecolpicker element itself doesn't have an id, so we have to walk
   // down from the parent to find it.
   //  treadCols
   //   |- hbox                item 0
   //   |- treecolpicker   <-- item 1 this is the one we want
   let threadCols = mc.window.document.getElementById("threadCols");
   let treeColPicker = mc.window.document.getAnonymousNodes(threadCols).item(1);
   let popup = mc.window.document.getAnonymousElementByAttribute(
                 treeColPicker, "anonid", "popup");
 
+  // Right click the subject column header
+  // This should show the column picker popup.
+  mc.rightClick(mc.eid("subjectCol"));
+
   // Check that the popup opens.
-  mc.waitForEval("subject.state == 'open'", 1000, 100, popup);
+  wait_for_popup_to_open(popup);
   // Hide it again, we just wanted to know it was gonna be shown.
-  popup.hidePopup();
+  close_popup(mc, new elib.Elem(popup));
 }
 
 /**
  * One-thing selected, right-click on something else.
  */
 function test_right_click_with_one_thing_selected() {
   be_in_folder(folder);
 
   select_click_row(0);
   assert_selected_and_displayed(0);
 
   right_click_on_row(1);
   assert_selected(1);
   assert_displayed(0);
 
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   assert_selected_and_displayed(0);
 }
 
 /**
  * Many things selected, right-click on something that is not in that selection.
  */
 function test_right_click_with_many_things_selected() {
   be_in_folder(folder);
@@ -142,50 +148,50 @@ function test_right_click_with_many_thin
   select_click_row(0);
   select_shift_click_row(5);
   assert_selected_and_displayed([0, 5]);
 
   right_click_on_row(6);
   assert_selected(6);
   assert_displayed([0, 5]);
 
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   assert_selected_and_displayed([0, 5]);
 }
 
 /**
  * One thing selected, right-click on that.
  */
 function test_right_click_on_existing_single_selection() {
   be_in_folder(folder);
 
   select_click_row(3);
   assert_selected_and_displayed(3);
 
   right_click_on_row(3);
   assert_selected_and_displayed(3);
 
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   assert_selected_and_displayed(3);
 }
 
 /**
  * Many things selected, right-click somewhere in the selection.
  */
 function test_right_click_on_existing_multi_selection() {
   be_in_folder(folder);
 
   select_click_row(3);
   select_shift_click_row(6);
   assert_selected_and_displayed([3, 6]);
 
   right_click_on_row(5);
   assert_selected_and_displayed([3, 6]);
 
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   assert_selected_and_displayed([3, 6]);
 }
 
 /**
  * Middle clicking should open a message in a tab, but not affect our selection.
  */
 function _middle_click_with_nothing_selected_helper(aBackground) {
   be_in_folder(folder);
--- a/mail/test/mozmill/folder-display/test-savedsearch-reload-after-compact.js
+++ b/mail/test/mozmill/folder-display/test-savedsearch-reload-after-compact.js
@@ -50,17 +50,17 @@ var folderInbox, folderVirtual;
 function setupModule(module) {
   let fdh = collector.getModule('folder-display-helpers');
   fdh.installInto(module);
   let wh = collector.getModule('window-helpers');
   wh.installInto(module);
 }
 
 /**
- * Add some messages to a folder, delete the first one, and create a saved 
+ * Add some messages to a folder, delete the first one, and create a saved
  * search over the inbox and the folder. Then, compact folders.
  */
 function test_setup_virtual_folder_and_compact() {
   otherFolder = create_folder("otherFolder");
   let [msgSet] = make_new_sets_in_folder(otherFolder, [{count: 2}]);
 
   /**
    * We delete the first message in the local folder, so compaction of the
--- a/mail/test/mozmill/folder-tree-modes/test-custom-folder-tree-mode.js
+++ b/mail/test/mozmill/folder-tree-modes/test-custom-folder-tree-mode.js
@@ -72,17 +72,19 @@ function test_switch_to_test_mode() {
   assert_folder_visible(folder);
 }
 
 /**
  * Open a new 3-pane window while the custom mode is selected, and make sure
  * that the mode displayed in the new window is the custom mode.
  */
 function test_open_new_window_with_custom_mode() {
-  be_in_folder(folder);
+  // Our selection may get lost while changing modes, and be_in_folder is
+  // not sufficient to ensure actual selection.
+  mc.folderTreeView.selectFolder(folder);
 
   plan_for_new_window("mail:3pane");
   mc.window.MsgOpenNewWindowForFolder(null, -1);
   let mc2 = wait_for_new_window("mail:3pane");
 
   assert_folder_mode(kTestModeID, mc2);
   assert_folder_visible(folder, mc2);
 
--- a/mail/test/mozmill/message-header/test-message-header.js
+++ b/mail/test/mozmill/message-header/test-message-header.js
@@ -329,23 +329,23 @@ function test_add_contact_from_context_m
     throw new Error("addToAddressBookItem is hidden for unknown contact");
   var editContactItem = mc.window.document.getElementById("editContactItem");
   if (!editContactItem.getAttribute("hidden"))
     throw new Error("editContactItem is NOT hidden for unknown contact");
 
   // Click the Add to Address Book context menu entry.
   mc.click(mc.eid("addToAddressBookItem"));
   // (for reasons unknown, the pop-up does not close itself)
-  close_popup();
+  close_popup(mc, mc.eid("emailAddressPopup"));
 
   // Now click the contact again, the context menu should now show the
   // Edit Contact menu instead.
   mc.click(mc.aid("expandedfromBox", {tagName: "mail-emailaddress"}));
   // (for reasons unknown, the pop-up does not close itself)
-  close_popup();
+  close_popup(mc, mc.eid("emailAddressPopup"));
 
   addToAddressBookItem = mc.window.document.getElementById("addToAddressBookItem");
   if (!addToAddressBookItem.hidden)
     throw new Error("addToAddressBookItem is NOT hidden for known contact");
   editContactItem = mc.window.document.getElementById("editContactItem");
   if (editContactItem.hidden)
     throw new Error("editContactItem is hidden for known contact");
 }
--- a/mail/test/mozmill/quick-filter-bar/test-display-issues.js
+++ b/mail/test/mozmill/quick-filter-bar/test-display-issues.js
@@ -55,87 +55,106 @@ function setupModule(module) {
   wh.installInto(module);
   let qfb = collector.getModule('quick-filter-bar-helper');
   qfb.installInto(module);
 
   folder = create_folder("QuickFilterBarDisplayIssues");
   be_in_folder(folder);
 }
 
+function resize_to(width, height) {
+  mark_action("test", "resize_to", [width, "x", height]);
+  mc.window.resizeTo(width, height);
+  // Give the event loop a spin in order to let the reality of an asynchronously
+  //  interacting window manager have its impact.  This still may not be
+  //  sufficient.
+  mc.sleep(0);
+  mc.waitForEval("subject.outerWidth == " + width + " && " +
+                 " subject.outerHeight == " + height,
+                 1000, 50, mc.window);
+}
+
+function collapse_folder_pane(shouldBeCollapsed) {
+  mark_action("test", "collapse_folder_pane",
+              [shouldBeCollapsed]);
+  mc.e("folderpane_splitter").setAttribute("state",
+                                           shouldBeCollapsed ? "collapsed"
+                                                             : "open");
+}
+
+
 /**
  * When the window gets too narrow the collapsible button labels need to get
  *  gone.  Then they need to come back when we get large enough again.
  *
  * Because the mozmill window sizing is weird and confusing, we force our size
  *  in both cases but do save/restore around our test.
  */
 function test_buttons_collapse_and_expand() {
   assert_quick_filter_bar_visible(true); // precondition
 
-  try {
-    let qfbCollapsy = mc.e("quick-filter-bar-collapsible-buttons");
-    let qfbExemplarButton = mc.e("qfb-unread"); // (arbitrary labeled button)
-    let qfbExemplarLabel = mc.window
-                             .document.getAnonymousNodes(qfbExemplarButton)[1];
+  let qfbCollapsy = mc.e("quick-filter-bar-collapsible-buttons");
+  let qfbExemplarButton = mc.e("qfb-unread"); // (arbitrary labeled button)
+  let qfbExemplarLabel = mc.window
+                           .document.getAnonymousNodes(qfbExemplarButton)[1];
 
-    function logState(aWhen) {
-      dump("\n\n*********** " + aWhen + "\n");
-      dump("Current window location: " + mc.window.screenX + ", " +
-           mc.window.screenY + "\n");
-      dump("Current window dimensions: " + mc.window.outerWidth + ", " +
-           mc.window.outerHeight + "\n");
-      dump("Collapsy bar width: " + qfbCollapsy.clientWidth + "\n");
-      dump("***********\n\n");
-    }
+  function logState(aWhen) {
+    mark_action("test", "log_window_state",
+                [aWhen,
+                 "location:", mc.window.screenX, mc.window.screenY,
+                 "dims:", mc.window.outerWidth, mc.window.outerHeight,
+                 "Collapsy bar width:", qfbCollapsy.clientWidth,
+                 "shrunk?", qfbCollapsy.getAttribute("shrink")]);
+  }
 
-    function assertCollapsed() {
-      // The bar should be shrunken and the button should be the same size as its
-      // image!
-      if (qfbCollapsy.getAttribute("shrink") != "true")
-        throw new Error("The collapsy bar should be shrunk!");
-      if (qfbExemplarLabel.clientWidth != 0)
-        throw new Error("The exemplar label should be collapsed!");
-    }
-    function assertExpanded() {
-      // The bar should not be shrunken and the button should be smaller than its
-      // label!
-      if (qfbCollapsy.hasAttribute("shrink"))
-        throw new Error("The collapsy bar should not be shrunk!");
-      if (qfbExemplarLabel.clientWidth == 0)
-        throw new Error("The exemplar label should not be collapsed!");
-    }
+  function assertCollapsed() {
+    // The bar should be shrunken and the button should be the same size as its
+    // image!
+    if (qfbCollapsy.getAttribute("shrink") != "true")
+      throw new Error("The collapsy bar should be shrunk!");
+    if (qfbExemplarLabel.clientWidth != 0)
+      throw new Error("The exemplar label should be collapsed!");
+  }
+  function assertExpanded() {
+    // The bar should not be shrunken and the button should be smaller than its
+    // label!
+    if (qfbCollapsy.hasAttribute("shrink"))
+      throw new Error("The collapsy bar should not be shrunk!");
+    if (qfbExemplarLabel.clientWidth == 0)
+      throw new Error("The exemplar label should not be collapsed!");
+  }
 
-    logState("entry");
+  logState("entry");
 
-    // -- GIANT!
-    mc.window.resizeTo(1200, 600);
-    // Right, so resizeTo caps us at the display size limit, so we may end up
-    // smaller than we want.  So let's turn off the folder pane too.
-    mc.e("folderpane_splitter").setAttribute("state", "collapsed");
-    // spin the event loop once
-    mc.sleep(0);
-    logState("giant");
-    assertExpanded();
+  // -- GIANT!
+  resize_to(1200, 600);
+  // Right, so resizeTo caps us at the display size limit, so we may end up
+  // smaller than we want.  So let's turn off the folder pane too.
+  collapse_folder_pane(true);
+  // spin the event loop once
+  mc.sleep(0);
+  logState("giant");
+  assertExpanded();
 
-    // -- tiny.
-    mc.e("folderpane_splitter").setAttribute("state", "open");
-    mc.window.resizeTo(600, 600);
-    // spin the event loop once
-    mc.sleep(0);
-    logState("tiny");
-    assertCollapsed();
+  // -- tiny.
+  collapse_folder_pane(false);
+  resize_to(600, 600);
+  // spin the event loop once
+  mc.sleep(0);
+  logState("tiny");
+  assertCollapsed();
 
-    // -- GIANT again!
-    mc.window.resizeTo(1200, 600);
-    mc.e("folderpane_splitter").setAttribute("state", "collapsed");
-    // spin the event loop once
-    mc.sleep(0);
-    logState("giant again!");
-    assertExpanded();
-  }
-  finally {
-    // restore window to nominal dimensions; saving was not working out
-    //  See also: message-header/test-message-header.js if we change the
-    //            default window size.
-    mc.window.resizeTo(1024, 768);
-    mc.e("folderpane_splitter").setAttribute("state", "open");
-  }
+  // -- GIANT again!
+  resize_to(1200, 600);
+  collapse_folder_pane(true);
+  // spin the event loop once
+  mc.sleep(0);
+  logState("giant again!");
+  assertExpanded();
 }
+
+function teardownModule() {
+  // restore window to nominal dimensions; saving was not working out
+  //  See also: message-header/test-message-header.js if we change the
+  //            default window size.
+  resize_to(1024, 768);
+  collapse_folder_pane(false);
+}
--- a/mail/test/mozmill/runtest.py
+++ b/mail/test/mozmill/runtest.py
@@ -305,17 +305,18 @@ class ThunderTestCLI(mozmill.CLI):
         jsbridge.CLI.__init__(self, *args, **kwargs)
         SYMBOLS_PATH = self.options.symbols
         TEST_NAME = os.path.basename(self.options.test)
 
         self._load_wrapper()
 
         self.mozmill = self.mozmill_class(runner_class=self.runner_class,
                                           profile_class=self.profile_class,
-                                          jsbridge_port=int(self.options.port))
+                                          jsbridge_port=int(self.options.port),
+                                          jsbridge_timeout=300)
 
         self.mozmill.add_global_listener(mozmill.LoggerListener())
 
     def _load_wrapper(self):
         global wrapper
         """
         Load the wrapper module if it is present in the test directory.
         """
@@ -335,31 +336,37 @@ class ThunderTestCLI(mozmill.CLI):
             finally:
                 if fd is not None:
                     fd.close()
 
 TEST_RESULTS = []
 # Versions of MozMill prior to 1.5 did not output test-pass /
 # TEST-UNEXPECTED-FAIL. Since 1.5 happened this gets output, so we only want
 # a summary at the end to make it easy for developers.
-# override mozmill's default logging case, which I hate.
-def logFailure(obj):
-    if isinstance(obj, basestring):
-        obj = json.loads(obj)
-    FAILURE_LIST.append(obj)
 def logEndTest(obj):
     # If we've got a string here, we know we're later than 1.5, and we can just
     # display a summary at the end as 1.5 will do TEST-UNEXPECTED-FAIL for us.
     if isinstance(obj, str):
         obj = json.loads(obj)
         obj['summary'] = True
     TEST_RESULTS.append(obj)
-#mozmill.LoggerListener.cases['mozmill.fail'] = logFailure
 mozmill.LoggerListener.cases['mozmill.endTest'] = logEndTest
 
+# We now send extended meta-data about failures.  We do not want the entire
+# message dumped with this extra data, so clobber the default mozmill.fail
+# with one that wraps it and only tells it the exception message rather than
+# the whole JSON blob.
+ORIGINAL_FAILURE_LOGGER = mozmill.LoggerListener.cases['mozmill.fail']
+def logFailure(obj):
+    if isinstance(obj, basestring):
+        obj = json.loads(obj)
+    ORIGINAL_FAILURE_LOGGER(obj["exception"]["message"])
+mozmill.LoggerListener.cases['mozmill.fail'] = logFailure
+
+
 def prettifyFilename(path):
     lslash = path.rfind('/')
     if lslash != -1:
         return path[lslash+1:]
     else:
         return path
 
 def prettyPrintException(e):
@@ -388,34 +395,43 @@ def prettyPrintException(e):
                 print '      ', funcname, prettifyFilename(path), line
             else:
                 print '           ', prettifyFilename(path), line
 
 
 # Tests that are useless and shouldn't be printed if successful
 TEST_BLACKLIST = ["setupModule", "setupTest", "teardownTest", "teardownModule"]
 
-import pprint
+import pprint, atexit
+@atexit.register
 def prettyPrintResults():
     for result in TEST_RESULTS:
         #pprint.pprint(result)
         testOrSummary = 'TEST'
         if 'summary' in result:
             testOrSummary = 'SUMMARY'
         if len(result['fails']) == 0:
             if result['name'] not in TEST_BLACKLIST:
                 print '%s-PASS | %s' % (testOrSummary, result['name'])
         else:
             print '%s-UNEXPECTED-FAIL | %s | %s' % (testOrSummary, prettifyFilename(result['filename']), result['name'])
         for failure in result['fails']:
             if 'exception' in failure:
                 prettyPrintException(failure['exception'])
 
-import atexit
-atexit.register(prettyPrintResults)
+@atexit.register
+def dumpRichResults():
+    print '##### MOZMILL-RICH-FAILURES-BEGIN #####'
+    for result in TEST_RESULTS:
+        if len(result['fails']) > 0:
+            for failure in result['fails']:
+                failure['fileName'] = prettifyFilename(result['filename'])
+                failure['testName'] = result['name']
+                print json.dumps(failure)
+    print '##### MOZMILL-RICH-FAILURES-END #####'
 
 def checkCrashesAtExit():
     if checkForCrashes(os.path.join(PROFILE_DIR, 'minidumps'), SYMBOLS_PATH,
                        TEST_NAME):
         print >> sys.stderr, 'TinderboxPrint: ' + TEST_NAME + '<br/><em class="testfail">CRASH</em>'
         sys.exit(1)
 
 if __name__ == '__main__':
--- a/mail/test/mozmill/search-window/test-search-window.js
+++ b/mail/test/mozmill/search-window/test-search-window.js
@@ -140,16 +140,17 @@ function test_go_search() {
  */
 function test_open_single_search_result_in_tab() {
   swc.window.focus();
   set_open_message_behavior("NEW_TAB");
   let folderTab = mc.tabmail.currentTabInfo;
   let preCount = mc.tabmail.tabContainer.childNodes.length;
 
   // Select one message
+  swc.e("threadTree").focus();
   let msgHdr = select_click_row(1, swc);
   // Open the selected message
   open_selected_message(swc);
   // This is going to trigger a message display in the main 3pane window
   wait_for_message_display_completion(mc);
   // Check that the tab count has increased by 1
   assert_number_of_tabs_open(preCount + 1);
   // Check that the currently displayed tab is a message tab (i.e. our newly
@@ -168,16 +169,17 @@ function test_open_single_search_result_
  */
 function test_open_multiple_search_results_in_new_tabs() {
   swc.window.focus();
   set_open_message_behavior("NEW_TAB");
   let folderTab = mc.tabmail.currentTabInfo;
   let preCount = mc.tabmail.tabContainer.childNodes.length;
 
   // Select a bunch of messages
+  swc.e("threadTree").focus();
   select_click_row(1, swc);
   let selectedMessages = select_shift_click_row(NUM_MESSAGES_TO_OPEN, swc);
   // Open them
   open_selected_messages(swc);
   // This is going to trigger a message display in the main 3pane window
   wait_for_message_display_completion(mc, true);
   // Check that the tab count has increased by the correct number
   assert_number_of_tabs_open(preCount + NUM_MESSAGES_TO_OPEN);
@@ -204,16 +206,17 @@ function test_open_multiple_search_resul
 /**
  * Test opening a search result in a new window.
  */
 function test_open_search_result_in_new_window() {
   swc.window.focus();
   set_open_message_behavior("NEW_WINDOW");
 
   // Select a message
+  swc.e("threadTree").focus();
   let msgHdr = select_click_row(1, swc);
 
   plan_for_new_window("mail:messageWindow");
   // Open it
   open_selected_message(swc);
   let msgc = wait_for_new_window("mail:messageWindow");
   wait_for_message_display_completion(msgc, true);
 
@@ -226,16 +229,17 @@ function test_open_search_result_in_new_
 /**
  * Test reusing an existing window to open another search result.
  */
 function test_open_search_result_in_existing_window() {
   swc.window.focus();
   set_open_message_behavior("EXISTING_WINDOW");
 
   // Open up a window
+  swc.e("threadTree").focus();
   select_click_row(1, swc);
   plan_for_new_window("mail:messageWindow");
   open_selected_message(swc);
   let msgc = wait_for_new_window("mail:messageWindow");
   wait_for_message_display_completion(msgc, true);
 
   // Select another message and open it
   let msgHdr = select_click_row(2, swc);
--- a/mail/test/mozmill/shared-modules/test-account-manager-helpers.js
+++ b/mail/test/mozmill/shared-modules/test-account-manager-helpers.js
@@ -72,20 +72,17 @@ function installInto(module) {
  *
  * @param callback Callback for the modal dialog that is opened.
  */
 function open_advanced_settings(aCallback, aController) {
   if (aController === undefined)
     aController = mc;
 
   wh.plan_for_modal_dialog("mailnews:accountmanager", aCallback);
-  if (mozmill.isLinux)
-    aController.click(new elib.Elem(mc.menus.menu_Edit.menu_accountmgr));
-  else
-    aController.click(new elib.Elem(mc.menus.tasksMenu.menu_accountmgr));
+  aController.click(mc.eid("menu_accountmgr"));
   return wh.wait_for_modal_dialog("mailnews:accountmanager");
 }
 
 /**
  * Opens the Account Manager from the mail account setup wizard.
  *
  * @param callback Callback for the modal dialog that is opened.
  */
--- a/mail/test/mozmill/shared-modules/test-folder-display-helpers.js
+++ b/mail/test/mozmill/shared-modules/test-folder-display-helpers.js
@@ -46,16 +46,18 @@ var mozmill = {};
 Cu.import('resource://mozmill/modules/mozmill.js', mozmill);
 var controller = {};
 Cu.import('resource://mozmill/modules/controller.js', controller);
 var frame = {};
 Cu.import('resource://mozmill/modules/frame.js', frame);
 var os = {};
 Cu.import('resource://mozmill/stdlib/os.js', os);
 
+Cu.import("resource:///modules/gloda/log4moz.js");
+
 const MODULE_NAME = 'folder-display-helpers';
 
 const RELATIVE_ROOT = '../shared-modules';
 // we need window-helpers for augment_controller
 const MODULE_REQUIRES = ['window-helpers'];
 
 const nsMsgViewIndex_None = 0xffffffff;
 Cu.import('resource:///modules/MailUtils.js');
@@ -140,37 +142,87 @@ function setupModule() {
     do_throw: function(aMsg) {
       throw new Error(aMsg);
     },
     do_check_eq: function() {},
     do_check_neq: function() {},
     gDEPTH: "../../",
   };
 
+  // -- logging
+
   // The xpcshell test resources assume they are loaded into a single global
   //  namespace, so we need to help them out to maintain their delusion.
   load_via_src_path('logHelper.js', testHelperModule);
   mark_action = testHelperModule.mark_action;
   mark_failure = testHelperModule.mark_failure;
 
-  // Hook-up logHelper to the mozmill event system...
+  // Remove the dump appender that got appended; it just adds noise.
+  testHelperModule._testLogger._appenders.splice(
+    testHelperModule._testLogger._appenders.length - 1, 1);
+
+  // Add a bucketing appender to the root.
+  let rootLogger = Log4Moz.repository.rootLogger;
+  let bucketAppender = new Log4Moz.TimeAwareMemoryBucketAppender();
+  bucketAppender.level = Log4Moz.Level.All;
+  rootLogger.addAppender(bucketAppender);
+
+  // Indicate to any fancy helpers (just folderEventLogHelper right now) that
+  //  we want them to log extra stuff.
+  testHelperModule._logHelperInterestedListeners = true;
+
+  // - Hook-up logHelper to the mozmill event system...
   let curTestFile = null;
+  // Listen for setTest so we can change buckets and generate logHelper test
+  //  begin/end notifications.
   frame.events.addListener("setTest", function(obj) {
+      // ignore setupModule and teardownModule
+      if (obj.name == "setupModule" ||
+          obj.name == "teardownModule")
+        return;
       if (obj.filename != curTestFile) {
+        testHelperModule.mark_test_end();  
+        bucketAppender.newBucket();
         testHelperModule.mark_test_start(obj.filename);
         curTestFile = obj.filename;
       }
+      else {
+        testHelperModule.mark_test_end(1);
+        bucketAppender.newBucket();
+      }
       testHelperModule.mark_sub_test_start(obj.name);
     });
+  // Listen for the fail event so that we can annotate the failure object
+  //  with additional metadata.  This works out because we are directly handed
+  //  a reference to the object that will be provided to the jsbridge and we
+  //  can mutate it.  (The jsbridge is a global listener and so is guaranteed
+  //  to be invoked after our specific named listener.)
   frame.events.addListener("fail", function(obj) {
+      // generate the failure notification now so it shows up in the event log
+      //  bucket for presentation purposes.
       testHelperModule._xpcshellLogger.info(
         testHelperModule._testLoggerActiveContext,
         new testHelperModule._Failure(obj.exception.message, obj.exception));
+
+      try {
+        obj.failureContext = {
+          preEvents: bucketAppender.getPreviousBucketEvents(10000),
+          events: bucketAppender.getBucketEvents(),
+          windows: windowHelper.captureWindowStatesForErrorReporting(
+                     testHelperModule._normalize_for_json),
+        };
+      }
+      catch(ex) {
+        dump("!!!!!!!!EX: " + ex);
+        mark_action("fdh", "fail fail marking!", [ex]);
+      }
     });
 
+  // -- the rest of the asyncTestUtils framework (but not actually async)
+
   load_via_src_path('asyncTestUtils.js', testHelperModule);
   load_via_src_path('messageGenerator.js', testHelperModule);
   load_via_src_path('messageModifier.js', testHelperModule);
   load_via_src_path('messageInjection.js', testHelperModule);
   load_via_src_path('viewWrapperTestUtils.js', testHelperModule);
 
   // provide super helpful folder event info (when logHelper cares)
   load_via_src_path('folderEventLogHelper.js', testHelperModule);
@@ -191,16 +243,25 @@ function setupModule() {
   delete_message_set = testHelperModule.async_delete_messages;
 
   // use window-helper's augment_controller method to get our extra good stuff
   //  we need.
   windowHelper = collector.getModule('window-helpers');
   mc = windowHelper.wait_for_existing_window("mail:3pane");
   windowHelper.augment_controller(mc);
 
+  // Tell window-helper about the true mark_action function in order to try
+  // and further complicate this horrid seven-dimensional rats' nest.
+  windowHelper.hereIsMarkAction(mark_action,
+                                testHelperModule._normalize_for_json);
+
+  mark_action("fdh", "startup completed",
+              [(mc.window.msgWindow != null) ? "3pane looks initialized"
+               : "3pane does not appear to have fully loaded yet!"]);
+
   setupAccountStuff();
 }
 
 /**
  * Install this module into the provided module.
  */
 function installInto(module) {
   setupModule();
@@ -284,31 +345,41 @@ function teardownImporter(customTeardown
       if (!mc || mc.window.closed)
         mc = windowHelper.wait_for_existing_window("mail:3pane");
     }
 
     // Run through all open windows, closing any that aren't assigned to mc.
     let enumerator = windowMediator.getEnumerator(null);
     while (enumerator.hasMoreElements()) {
       let win = enumerator.getNext();
-      if (win != mc.window)
+      if (win != mc.window) {
+        mark_action("fdh", "teardown",
+                    ["cleanup closing non-mc window", win.toString(),
+                     "window type",
+                     windowHelper.getWindowTypeForXulWindow(win)]);
         win.close();
+      }
     }
 
     // At this point we should have exactly one window open.
     // - Close all tabs other than the first one.
     mc.tabmail.closeOtherTabs(mc.tabmail.tabInfo[0]);
 
     // - Set the mode to All Folders.
-    if (mc.folderTreeView.mode != "all")
+    if (mc.folderTreeView.mode != "all") {
+      mark_action("fdh", "teardown",
+                  ["resetting folderTreeView mode", mc.folderTreeView.mode]);
       mc.folderTreeView.mode = "all";
+    }
 
     // - Make sure the message pane is visible.
-    if (mc.window.IsMessagePaneCollapsed())
+    if (mc.window.IsMessagePaneCollapsed()) {
+      mark_action("fdh", "teardown", ["toggling message pane on again"]);
       mc.window.MsgToggleMessagePane();
+    }
   };
   // Another internal mozmill thing, again figured out too early for it to have
   // a chance.
   teardownModule.__name__ = "teardownModule";
   return teardownModule;
 }
 
 /*
@@ -443,20 +514,20 @@ function open_folder_in_new_tab(aFolder)
  *
  * Since we don't know where this is going to trigger a message load, you're
  * going to have to wait for message display completion yourself.
  *
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  */
 function open_selected_messages(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   // Focus the thread tree
-  aController.threadTree.focus();
+  focus_thread_tree();
   mark_action("fdh", "open_selected_messages",
               mc.folderDisplay.selectedMessages);
   // Open whatever's selected
   press_enter(aController);
 }
 
 var open_selected_message = open_selected_messages;
 
@@ -723,17 +794,17 @@ function close_message_window(aControlle
   windowHelper.close_window(aController);
 }
 
 /**
  * Clear the selection.  I'm not sure how we're pretending we did that.
  */
 function select_none(aController) {
   mark_action("fdh", "select_none", []);
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   wait_for_message_display_completion();
   aController.dbView.selection.clearSelection();
   // Because the selection event may not be generated immediately, we need to
   //  spin until the message display thinks it is not displaying a message,
   //  which is the sign that the event actually happened.
   function noMessageChecker() {
     return aController.messageDisplay.displayedMessage == null;
@@ -747,17 +818,17 @@ function select_none(aController) {
  * Normalize a view index to be an absolute index, handling slice-style negative
  *  references as well as piercing complex things like message headers and
  *  synthetic message sets.
  *
  * @param aViewIndex An absolute index (integer >= 0), slice-style index (< 0),
  *     or a SyntheticMessageSet (we only care about the first message in it).
  */
 function _normalize_view_index(aViewIndex, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   // SyntheticMessageSet special-case
   if (typeof(aViewIndex) != "number") {
     let msgHdrIter = aViewIndex.msgHdrs;
     let msgHdr = msgHdrIter.next();
     msgHdrIter.close();
     // do not expand
     aViewIndex = aController.dbView.findIndexOfMsgHdr(msgHdr, false);
@@ -776,17 +847,17 @@ function _normalize_view_index(aViewInde
  *     a view index counting from the last row in the tree.  -1 indicates the
  *     last message in the tree, -2 the second to last, etc.
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  *
  * @return The message header selected.
  */
 function select_click_row(aViewIndex, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   let hasMessageDisplay = "messageDisplay" in aController;
   if (hasMessageDisplay)
     wait_for_message_display_completion(aController);
   aViewIndex = _normalize_view_index(aViewIndex, aController);
 
   mark_action("fdh", "select_click_row", [aViewIndex]);
 
@@ -851,17 +922,17 @@ function select_control_click_row(aViewI
  *     a view index counting from the last row in the tree.  -1 indicates the
  *     last message in the tree, -2 the second to last, etc.
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  *
  * @return The message headers for all messages that are now selected.
  */
 function select_shift_click_row(aViewIndex, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   let hasMessageDisplay = "messageDisplay" in aController;
   if (hasMessageDisplay)
     wait_for_message_display_completion(aController);
   aViewIndex = _normalize_view_index(aViewIndex, aController);
 
   // Passing -1 as the start range checks the shift-pivot, which should be -1,
   //  so it should fall over to the current index, which is what we want.  It
@@ -894,22 +965,32 @@ function _row_click_helper(aTree, aViewI
   let rowY = treeBox.rowHeight * (aViewIndex - treeBox.getFirstVisibleRow());
   if (treeBox.getRowAt(x + rowX, y + rowY) != aViewIndex) {
     throw new Error("Thought we would find row " + aViewIndex + " at " +
                     rowX + "," + rowY + " but we found " +
                     treeBox.getRowAt(rowX, rowY));
   }
   let tx = aTree.boxObject.x;
   let ty = aTree.boxObject.y;
+  // Generate a mouse-down for all click types; the transient selection
+  // logic happens on mousedown which our tests assume is happening.  (If you
+  // are using a keybinding to trigger the event, that will not happen, but
+  // we don't test that.)
   EventUtils.synthesizeMouse(aTree, x + rowX - tx, y + rowY - ty,
                              {type: "mousedown", button: aButton}, mc.window);
+
+  // For right-clicks, the platform code generates a "contextmenu" event
+  // when it sees the mouse press/down event. We are not synthesizing a platform
+  // level event (though it is in our power; we just historically have not),
+  // so we need to be the people to create the context menu.
   if (aButton == 2)
     EventUtils.synthesizeMouse(aTree, x + rowX - tx, y + rowY - ty,
                                {type: "contextmenu", button: aButton},
                                mc.window);
+
   EventUtils.synthesizeMouse(aTree, x + rowX - tx, y + rowY - ty,
                              {type: "mouseup", button: aButton}, mc.window);
 }
 
 /**
  * Right-click on the tree-view in question.  With any luck, this will have
  *  the side-effect of opening up a pop-up which it is then on _your_ head
  *  to do something with or close.  However, we have helpful popup function
@@ -956,17 +1037,17 @@ function assert_row_visible(aViewIndex) 
 /**
  * Assert that the given folder mode is the current one.
  *
  * @param aMode The expected folder mode.
  * @param [aController] The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  */
 function assert_folder_mode(aMode, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   let actualMode = aController.folderTreeView.mode;
   if (actualMode != aMode)
     throw new Error("The folder mode should be " + aMode +
                     ", but is actually " + actualMode);
 }
 
 /**
@@ -988,17 +1069,17 @@ function assert_folder_child_in_view(aCh
  * Assert that the given folder is in the current folder mode and is visible.
  *
  * @param aFolder The folder to assert as visible
  * @param [aController] The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  * @returns The index of the folder, if it is visible.
  */
 function assert_folder_visible(aFolder, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   let folderIndex = aController.folderTreeView.getIndexOfFolder(aFolder);
   if (folderIndex == null)
     throw new Error("Folder: " + aFolder.URI + " should be visible, but isn't");
 
   return folderIndex;
 }
 
@@ -1174,113 +1255,140 @@ function get_smart_folder_named(aFolderN
  */
 function delete_via_popup() {
   plan_to_wait_for_folder_events("DeleteOrMoveMsgCompleted",
                                  "DeleteOrMoveMsgFailed");
   mark_action("fdh", "delete_via_popup",
               ["selected messages:", mc.folderDisplay.selectedMessages]);
   mc.click(mc.eid("mailContext-delete"));
   // for reasons unknown, the pop-up does not close itself?
-  close_popup();
+  close_popup(mc, mc.eid("mailContext"));
   wait_for_folder_events();
 }
 
+function wait_for_popup_to_open(popupElem) {
+  mark_action("fdh", "wait_for_popup_to_open", [popupElem]);
+  mc.waitForEval("subject.state == 'open'", 1000, 50, popupElem);
+}
+
 /**
  * Close the open pop-up.
  */
-function close_popup(aController) {
-  if (aController === undefined)
+function close_popup(aController, eid) {
+  if (aController == null)
     aController = mc;
-  mark_action("fdh", "close_popup", []);
-  aController.keypress(aController.eid("mailContext"), "VK_ESCAPE", {});
-  // drain event queue
-  aController.sleep(0);
+  let elem = eid.getNode();
+  // if it was already closing, just leave
+  if (elem.state == "closed") {
+    mark_action("fdh", "close_popup", ["popup suspiciously already closed!",
+                                       elem]);
+    return;
+  }
+  mark_action("fdh", "close_popup", [elem]);
+  // if it's in the process of closing, don't push escape
+  if (elem.state == "hiding")
+    mark_action("fdh", "close_popup",
+                ["popup suspiciously already closing..."]);
+  else // actually push escape because it's not closing/closed
+    aController.keypress(eid, "VK_ESCAPE", {});
+   if (!controller.waitForEval("subject.state == 'closed'", 1000, 50,
+                               elem))
+     throw new Error("Popup did not close!");
 }
 
 /**
  * Pretend we are pressing the delete key, triggering message deletion of the
  *  selected messages.
  *
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  */
 function press_delete(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   // if something is loading, make sure it finishes loading...
   wait_for_message_display_completion(aController);
   plan_to_wait_for_folder_events("DeleteOrMoveMsgCompleted",
                                  "DeleteOrMoveMsgFailed");
   mark_action("fdh", "press_delete",
               ["selected messages:",
-               aController.folderDisplay.selectedMessages]);
+               aController.folderDisplay.selectedMessages,
+               "currently focused element:",
+               aController.focusedElement]);
   aController.keypress(aController == mc ? mc.eThreadTree : null,
                        "VK_DELETE", {});
   wait_for_folder_events();
 }
 
 /**
  * Archive the selected messages, and wait for it to complete.
  *
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  */
 function archive_selected_messages(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   let expectedCount = aController.dbView.rowCount - aController.dbView.numSelected;
   // XXX We seem to sometimes have focus issues on trunk; this works around it.
   focus_thread_tree();
+
+  mark_action("fdh", "archive_selected_messages",
+              ["selected messages:",
+               aController.folderDisplay.selectedMessages,
+               "currently focused element:",
+               aController.focusedElement]);
   aController.keypress(null, "a", {});
 
   // Wait for the view rowCount to decrease by the number of selected messages.
   let messagesDeletedFromView = function() {
     return aController.dbView.rowCount == expectedCount;
   };
   controller.waitForEval('subject()',
                          NORMAL_TIMEOUT,
                          FAST_INTERVAL, messagesDeletedFromView);
   // The above may return immediately, meaning the event queue might not get a
   //  chance.  give it a chance now.
   aController.sleep(0);
-
 }
 
 /**
  * Pretend we are pressing the Enter key, triggering opening selected messages.
  * Note that since we don't know where this is going to trigger a message load,
  * you're going to have to wait for message display completion yourself.
  *
  * @param aController The controller in whose context to do this, defaults to
  *     |mc| if omitted.
  */
 function press_enter(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   // if something is loading, make sure it finishes loading...
   if ("messageDisplay" in aController)
     wait_for_message_display_completion(aController);
   mark_action("fdh", "press_enter",
               ["selected messages:",
-               aController.folderDisplay.selectedMessages]);
+               aController.folderDisplay.selectedMessages,
+               "currently focused element:",
+               aController.focusedElement]);
   aController.keypress(aController == mc ? mc.eThreadTree : null,
                        "VK_RETURN", {});
   // The caller's going to have to wait for message display completion
 }
 
 /**
  * Wait for the |folderDisplay| on aController (defaults to mc if omitted) to
  *  finish loading.  This generally only matters for folders that have an active
  *  search.
  * This method is generally called automatically most of the time, and you
  *  should not need to call it yourself unless you are operating outside the
  *  helper methods in this file.
  */
 function wait_for_all_messages_to_load(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   if (!controller.waitForEval('subject.allMessagesLoaded', NORMAL_TIMEOUT,
                               FAST_INTERVAL, aController.folderDisplay))
     mark_failure(["Messages never finished loading.  Timed Out."]);
   // the above may return immediately, meaning the event queue might not get a
   //  chance.  give it a chance now.
   aController.sleep(0);
 }
@@ -1292,18 +1400,19 @@ function wait_for_all_messages_to_load(a
  *  displayed for the given controller that state is sufficiently cleaned up
  *  so it doesn't trick us into thinking that there is no need to wait.
  *
  * @param [aControllerOrTab] optional controller or tab, defaulting to |mc|. If
  *     the message display is going to be caused by a tab switch, a reference to
  *     the tab to switch to should be passed in.
  */
 function plan_for_message_display(aControllerOrTab) {
-  if (aControllerOrTab === undefined)
+  if (aControllerOrTab == null)
     aControllerOrTab = mc;
+  mark_action("fdh", "plan_for_message_display", []);
   // We're relying on duck typing here -- both controllers and tabs expose their
   // message displays as the property |messageDisplay|.
   aControllerOrTab.messageDisplay.messageLoaded = false;
 }
 
 /**
  * If a message or summary is in the process of loading, let it finish;
  *  optionally, be sure to wait for a load to happen (assuming
@@ -1336,18 +1445,19 @@ function plan_for_message_display(aContr
  * @param [aController] optional controller, defaulting to |mc|.
  * @param [aLoadDemanded=false] Should we require that we wait for a message to
  *     be loaded?  You should use this in conjunction with
  *     |plan_for_message_display| as per the documentation above.  If you do
  *     not pass true and there is no message load in process, this method will
  *     return immediately.
  */
 function wait_for_message_display_completion(aController, aLoadDemanded) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
+  mark_action("fdh", "wait_for_message_display_completion", []);
   let contentPane = aController.contentPane;
   let oldHref = null;
 
   // There are a couple possible states the universe can be in:
   // 1) No message load happened or is going to happen.
   // 2) The only message load that is going to happened has happened.
   // 3) A message load is happening right now.
   // 4) A message load should happen in the near future.
@@ -1380,39 +1490,42 @@ function wait_for_message_display_comple
     return !docShell.busyFlags;
   };
   if (!controller.waitForEval('subject()', NORMAL_TIMEOUT, FAST_INTERVAL,
                               isLoadedChecker))
     mark_failure(["Timed out waiting for message display completion."]);
   // the above may return immediately, meaning the event queue might not get a
   //  chance.  give it a chance now.
   aController.sleep(0);
+  mark_action("fdh", "/wait_for_message_display_completion", []);
 }
 
 /**
  * Wait for the content pane to be blank because no message is to be displayed.
  * You would not want to call this once folder summaries land and if they are
  *  enabled.
  *
  * @param aController optional controller, defaulting to |mc|.
  */
 function wait_for_blank_content_pane(aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
+  mark_action("fdh", "wait_for_blank_content_pane", []);
 
   let isBlankChecker = function() {
     return aController.window.content.location.href == "about:blank";
   };
   if (!controller.waitForEval('subject()', NORMAL_TIMEOUT, FAST_INTERVAL,
                               isBlankChecker))
     mark_failure(["Timeout waiting for blank content pane.  Current location:",
                   aController.window.content.location.href]);
   // the above may return immediately, meaning the event queue might not get a
   //  chance.  give it a chance now.
   aController.sleep(0);
+  mark_action("fdh", "/wait_for_blank_content_pane", []);
 }
 
 
 var FolderListener = {
   _inited: false,
   ensureInited: function() {
     if (this._inited)
       return;
@@ -1478,28 +1591,28 @@ function wait_for_folder_events() {
  * Assert that the given synthetic message sets are present in the folder
  *  display.
  *
  * @param aSynSets Either a single SyntheticMessageSet or a list of them.
  * @param aController Optional controller, which we get the folderDisplay
  *     property from.  If omitted, we use mc.
  */
 function assert_messages_in_view(aSynSets, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   testHelperModule.verify_messages_in_view(aSynSets,
                                            aController.folderDisplay.view);
 }
 
 /**
  * Assert the the given message/messages are not present in the view.
  * @param aMessages Either a single nsIMsgDBHdr or a list of them.
  */
 function assert_messages_not_in_view(aMessages, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   if (aMessages instanceof Ci.nsIMsgDBHdr)
     aMessages = [aMessages];
   for each (let [, msgHdr] in Iterator(aMessages)) {
     if (mc.dbView.findIndexOfMsgHdr(msgHdr, true) != nsMsgViewIndex_None)
       mark_failure(["Message header is present in view but should not be:",
                     msgHdr, "index:",
                     mc.dbView.findIndexOfMsgHdr(msgHdr, true)]);
@@ -2103,17 +2216,17 @@ function assert_message_pane_focused() {
  * Assert that the multimessage pane is focused.
  */
 function assert_multimessage_pane_focused() {
   _assert_thing_focused("multimessage");
 }
 
 
 function _normalize_folder_view_index(aViewIndex, aController) {
-  if (aController === undefined)
+  if (aController == null)
     aController = mc;
   if (aViewIndex < 0)
     return aController.folderTreeView.QueryInterface(Ci.nsITreeView).rowCount +
       aViewIndex;
   return aViewIndex;
 }
 
 /**
--- a/mail/test/mozmill/shared-modules/test-migration-helpers.js
+++ b/mail/test/mozmill/shared-modules/test-migration-helpers.js
@@ -120,11 +120,19 @@ function close_migration_assistant(fc) {
  *
  * @param fc the migration assistant window wrapped in a MozmillController.
  *
  * @return The subpage's window wrapped in a MozmillController with the
  *     contentFrame displaying the appropriate pane.
  */
 function get_subpage(fc) {
   let contentWindow = fc.e("contentFrame").contentWindow;
+  // XXX this is not my fault, but I'm not going to fix it.  just make it less
+  // broken:
+
+  // Lie to mozmill to convince it to not explode because these frames never
+  // get a documentLoaded attribute.
+  contentWindow.documentLoaded = true;
+  // And sleep so the page has a chance to load
+  controller.sleep(1000);
   let aController = new controller.MozMillController(contentWindow);
   return wh.augment_controller(aController);
 }
--- a/mail/test/mozmill/shared-modules/test-search-window-helpers.js
+++ b/mail/test/mozmill/shared-modules/test-search-window-helpers.js
@@ -92,17 +92,17 @@ function open_search_window() {
  */
 function open_search_window_from_context_menu(aFolder) {
   folderDisplayHelper.right_click_on_folder(aFolder);
 
   windowHelper.plan_for_new_window("mailnews:search");
   mc.folderTreeController.searchMessages();
   let swc = windowHelper.wait_for_new_window("mailnews:search");
 
-  folderDisplayHelper.close_popup();
+  folderDisplayHelper.close_popup(mc, mc.eid("folderPaneContext"));
 
   return swc;
 }
 
 /**
  * Close a search window by calling window.close() on the controller.
  */
 function close_search_window(aController) {
--- a/mail/test/mozmill/shared-modules/test-window-helpers.js
+++ b/mail/test/mozmill/shared-modules/test-window-helpers.js
@@ -90,16 +90,29 @@ const WINDOW_FOCUS_TIMEOUT_MS = 10000;
 const focusManager = Cc["@mozilla.org/focus-manager;1"].
                        getService(Ci.nsIFocusManager);
 const threadManager = Cc["@mozilla.org/thread-manager;1"]
                         .getService(Ci.nsIThreadManager);
 const hiddenWindow = Cc["@mozilla.org/appshell/appShellService;1"]
                        .getService(Ci.nsIAppShellService)
                        .hiddenDOMWindow;
 
+// Have a dummy mark_action function in case test-folder-display-helpers does
+// not provide us with one.
+var mark_action = function() {};
+var normalize_for_json = function() {};
+/**
+ * This is used by test-folder-display-helpers to provide us with a reference
+ * to logHelper's mark_action because of ugliness in the module system.
+ */
+function hereIsMarkAction(mark_action_impl, normalize_for_json_impl) {
+  mark_action = mark_action_impl;
+  normalize_for_json = normalize_for_json_impl;
+}
+
 function setupModule() {
   // do nothing
 }
 
 function installInto(module) {
   module.plan_for_new_window = plan_for_new_window;
   module.wait_for_new_window = wait_for_new_window;
   module.plan_for_modal_dialog = plan_for_modal_dialog;
@@ -110,16 +123,55 @@ function installInto(module) {
   module.wait_for_existing_window = wait_for_existing_window;
 
   module.plan_for_observable_event = plan_for_observable_event;
   module.wait_for_observable_event = wait_for_observable_event;
 
   module.augment_controller = augment_controller;
 }
 
+/**
+ * Return the "windowtype" or "id" for the given xul window if it is available.
+ * If not, return null.
+ */
+function getWindowTypeForXulWindow(aXULWindow) {
+  // Sometimes we are given HTML windows, for which the logic below will
+  //  bail.  So we use a fast-path here that should work for HTML and should
+  //  maybe also work with XUL.  I'm not going to go into it...
+  if (aXULWindow.document &&
+      aXULWindow.document.documentElement &&
+      aXULWindow.document.documentElement.hasAttribute("windowtype"))
+    return aXULWindow.document.documentElement.getAttribute("windowtype");
+
+  let docshell = aXULWindow.docShell;
+  // we need the docshell to exist...
+  if (!docshell)
+    return null;
+
+  // we can't know if it's the right document until it's not busy
+  if (docshell.busyFlags)
+    return null;
+
+  // it also needs to have content loaded (it starts out not busy with no
+  //  content viewer.)
+  if (docshell.contentViewer == null)
+    return null;
+
+  // now we're cooking! let's get the document...
+  let outerDoc = docshell.contentViewer.DOMDocument;
+  // and make sure it's not blank.  that's also an intermediate state.
+  if (outerDoc.location.href == "about:blank")
+    return null;
+
+  // finally, we can now have a windowtype!
+  let windowType = outerDoc.documentElement.getAttribute("windowtype") ||
+                   outerDoc.documentElement.getAttribute("id");
+  return windowType;
+}
+
 var WindowWatcher = {
   _inited: false,
   _firstWindowOpened: false,
   ensureInited: function WindowWatcher_ensureInited() {
     if (this._inited)
       return;
 
     // Add ourselves as an nsIWindowMediatorListener so we can here about when
@@ -195,17 +247,21 @@ var WindowWatcher = {
     let xulWindow = this.waitingList[aWindowType];
     let domWindow = xulWindow.docShell.QueryInterface(Ci.nsIInterfaceRequestor)
                                       .getInterface(Ci.nsIDOMWindowInternal);
     delete this.waitingList[aWindowType];
     // spin the event loop to make sure any setTimeout 0 calls have gotten their
     //  time in the sun.
     controller.sleep(0);
     this._firstWindowOpened = true;
-    return new controller.MozMillController(domWindow);
+    // wrap the creation because 
+    mark_action("winhelp", "new MozMillController()", [aWindowType]);
+    let c = new controller.MozMillController(domWindow);
+    mark_action("winhelp", "/new MozMillController()", [aWindowType]);
+    return c;
   },
 
   /**
    * Because the modal dialog spins its own event loop, the mozmill idiom of
    *  spinning your own event-loop as performed by waitForEval is no good.  We
    *  use this timer to generate our events so that we can have a waitForEval
    *  equivalent.
    *
@@ -316,16 +372,19 @@ var WindowWatcher = {
 
   /**
    * This notification gets called when windows tell the widnow mediator when
    *  the window title gets changed.  In theory, we could use this to be
    *  event driven with less polling (effort), but it is not to be.
    */
   onWindowTitleChange: function WindowWatcher_onWindowTitleChange(
       aXULWindow, aNewTitle) {
+    mark_action("winhelp", "onWindowTitleChange",
+                [aXULWindow.toString(), getWindowTypeForXulWindow(aXULWindow),
+                 "changed title to", aNewTitle]);
   },
 
   /**
    * Used by waitForWindowOpen to check all of the windows we are monitoring and
    *  then check if we have any results.
    *
    * @return true if we found what we were |waitingForOpen|, false otherwise.
    */
@@ -363,53 +422,38 @@ var WindowWatcher = {
   },
 
   /**
    * nsIWindowMediatorListener notification that a XUL window was opened.  We
    *  check out the window, and if we were not able to fully consider it, we
    *  add it to our monitoring list.
    */
   onOpenWindow: function WindowWatcher_onOpenWindow(aXULWindow) {
+    // It would be great to be able to indicate if the window is modal or not,
+    //  but nothing is really jumping out at me to enable that...
+    mark_action("winhelp", "onOpenWindow",
+                [aXULWindow.toString(),
+                 "window type", getWindowTypeForXulWindow(aXULWindow)]);
     if (!this.consider(aXULWindow))
       this.monitorWindowLoad(aXULWindow);
   },
 
   /**
    * Consider if the given window is something in our |waitingList|.
    *
    * @return true if we were able to fully consider the object, false if we were
    *     not and need to be called again on the window later.  This has no
    *     relation to whether the window was one in our waitingList or not.
    *     Check the waitingList structure for that.
    */
   consider: function (aXULWindow) {
-    let docshell = aXULWindow.docShell;
-    // we need the docshell to exist...
-    if (!docshell)
-      return false;
-
-    // we can't know if it's the right document until it's not busy
-    if (docshell.busyFlags)
+    let windowType = getWindowTypeForXulWindow(aXULWindow);
+    if (windowType == null)
       return false;
 
-    // it also needs to have content loaded (it starts out not busy with no
-    //  content viewer.)
-    if (docshell.contentViewer == null)
-      return false;
-
-    // now we're cooking! let's get the document...
-    let outerDoc = docshell.contentViewer.DOMDocument;
-    // and make sure it's not blank.  that's also an intermediate state.
-    if (outerDoc.location.href == "about:blank")
-      return false;
-
-    // finally, we can now have a windowtype!
-    let windowType = outerDoc.documentElement.getAttribute("windowtype") ||
-                     outerDoc.documentElement.getAttribute("id");
-
     // stash the window if we were watching for it
     if (windowType in this.waitingList) {
       this.waitingList[windowType] = aXULWindow;
     }
 
     return true;
   },
 
@@ -418,16 +462,18 @@ var WindowWatcher = {
    *  so things like their windowtype are immediately available.
    */
   onCloseWindow: function WindowWatcher_onCloseWindow(aXULWindow) {
     let domWindow = aXULWindow.docShell.QueryInterface(Ci.nsIInterfaceRequestor)
                                        .getInterface(Ci.nsIDOMWindowInternal);
     let windowType =
       domWindow.document.documentElement.getAttribute("windowtype") ||
       domWindow.document.documentElement.getAttribute("id");
+    mark_action("winhelp", "onCloseWindow",
+                [aXULWindow.toString(), "window type", windowType]);
     // XXX because of how we dance with things, equivalence is not gonna
     //  happen for us.  This is most pragmatic.
     if (this.waitingList[windowType] !== null)
       this.waitingList[windowType] = null;
   },
 };
 
 /**
@@ -439,16 +485,17 @@ var WindowWatcher = {
  * @param aWindowType the window type that will be created.  This is literally
  *     the value of the "windowtype" attribute on the window.  The values tend
  *     to look like "app:windowname", for example "mailnews:search".
  *
  * @return The loaded window of the given type wrapped in a MozmillController
  *     that is augmented using augment_controller.
  */
 function wait_for_existing_window(aWindowType) {
+  mark_action("fdh", "wait_for_existing_window", [aWindowType]);
   WindowWatcher.ensureInited();
   WindowWatcher.planForAlreadyOpenWindow(aWindowType);
   return augment_controller(WindowWatcher.waitForWindowOpen(aWindowType),
                             aWindowType);
 }
 
 /**
  * Call this just before you trigger the event that will cause a window to be
@@ -459,32 +506,40 @@ function wait_for_existing_window(aWindo
  *  resilient in the face of multiple windows of the same type as long as you
  *  don't try and open them all at the same time.
  *
  * @param aWindowType the window type that will be created.  This is literally
  *     the value of the "windowtype" attribute on the window.  The values tend
  *     to look like "app:windowname", for example "mailnews:search".
  */
 function plan_for_new_window(aWindowType) {
+  mark_action("fdh", "plan_for_new_window", [aWindowType]);
   WindowWatcher.ensureInited();
   WindowWatcher.planForWindowOpen(aWindowType);
 }
 
 
 /**
  * Wait for the loading of the given window type to complete (that you
  *  previously told us about via |plan_for_new_window|), returning it wrapped
  *  in a MozmillController.
  *
  * @return The loaded window of the given type wrapped in a MozmillController
  *     that is augmented using augment_controller.
  */
 function wait_for_new_window(aWindowType) {
-  return augment_controller(WindowWatcher.waitForWindowOpen(aWindowType),
-                            aWindowType);
+  mark_action("fdh", "wait_for_new_window", [aWindowType]);
+  let c = augment_controller(WindowWatcher.waitForWindowOpen(aWindowType),
+                             aWindowType);
+  // A nested event loop can get spun inside the Controller's constructor
+  //  (which is arguably not a great idea), so it's important that we denote
+  //  when we're actually leaving this function in case something crazy
+  //  happens.
+  mark_action("fdh", "/wait_for_new_window", [aWindowType]);
+  return c;
 }
 
 /**
  * Plan for the imminent display of a modal dialog.  Modal dialogs spin their
  *  own event loop which means that either that control flow will not return
  *  to the caller until the modal dialog finishes running.  This means that
  *  you need to provide a sub-test function to be run inside the modal dialog
  *  (and it should not start with "test" or mozmill will also try and run it.)
@@ -492,47 +547,54 @@ function wait_for_new_window(aWindowType
  * @param aWindowType The window type that you expect the modal dialog to have
  *                    or the id of the window if there is no window type
  *                    available.
  * @param aSubTestFunction The sub-test function that will be run once the modal
  *     dialog appears and is loaded.  This function should take one argument,
  *     a MozmillController against the modal dialog.
  */
 function plan_for_modal_dialog(aWindowType, aSubTestFunction) {
+  mark_action("fdh", "plan_for_modal_dialog", [aWindowType]);
   WindowWatcher.ensureInited();
   WindowWatcher.planForModalDialog(aWindowType, aSubTestFunction);
 }
 /**
  * In case the dialog might be stuck for a long time, you can pass an optional
  *  timeout.
  *
  * @param aTimeout Your custom timeout (default is WINDOW_OPEN_TIMEOUT_MS)
  */
 function wait_for_modal_dialog(aWindowType, aTimeout) {
+  mark_action("fdh", "wait_for_modal_dialog", [aWindowType, aTimeout]);
   WindowWatcher.waitForModalDialog(aWindowType, aTimeout);
+  mark_action("fdh", "/wait_for_modal_dialog", [aWindowType, aTimeout]);
 }
 
 /**
  * Call this just before you trigger the event that will cause the provided
  *  controller's window to disappear.  You then follow this with a call to
  *  |wait_for_window_close| when you want to block on verifying the close.
  *
  * @param aController The MozmillController, potentially returned from a call to
  *     wait_for_new_window, whose window should be disappearing.
  */
 function plan_for_window_close(aController) {
+  mark_action("fdh", "plan_for_window_close",
+              [getWindowTypeForXulWindow(aController.window)]);
   WindowWatcher.ensureInited();
   WindowWatcher.planForWindowClose(aController.window);
 }
 
 /**
  * Wait for the closure of the window you noted you would listen for its close
  *  in plan_for_window_close.
  */
 function wait_for_window_close() {
+  mark_action("fdh", "wait_for_window_close",
+              ["(using window from plan_for_window_close)"]);
   WindowWatcher.waitForWindowClose();
 }
 
 /**
  * Close a window by calling window.close() on the controller.
  *
  * @param aController the controller whose window is to be closed.
  */
@@ -548,32 +610,35 @@ let obsService = Cc["@mozilla.org/observ
 let observationWaitFuncs = {};
 let observationSaw = {};
 /**
  * Plan for a notification to be sent via the observer service.
  *
  * @param aTopic The topic that will be sent via the observer service.
  */
 function plan_for_observable_event(aTopic) {
+  mark_action("fdh", "plan_for_observable_event", [aTopic]);
   observationSaw[aTopic] = false;
   let waiter = observationWaitFuncs[aTopic] = {
     observe: function() {
+      mark_action("winhelp", "observed event", [aTopic]);
       observationSaw[aTopic] = true;
     }
   };
   obsService.addObserver(waiter, aTopic, false);
 }
 
 /**
  * Wait for a notification (previously planned for via
  *  |plan_for_observable_event|) to fire.
  *
  * @param aTopic The topic sent via the observer service.
  */
 function wait_for_observable_event(aTopic) {
+  mark_action("fdh", "wait_for_observable_event", [aTopic]);
   try {
     function areWeThereYet() {
       return observationSaw[aTopic];
     }
     if (!controller.waitForEval(
           'subject()',
           3000, 50,
           areWeThereYet))
@@ -730,21 +795,24 @@ var AugmentEverybodyWith = {
      *     attribute with a single value.  We pick the menu option whose DOM
      *     node has an attribute with that name and value.  We click whatever we
      *     find.  We throw if we don't find what you were asking for.
      */
     click_menus_in_sequence: function _click_menus(aRootPopup, aActions) {
       if (aRootPopup.state == "closed")
         aRootPopup.openPopup(null, "", 0, 0, true, true);
       if (aRootPopup.state != "open") { // handle "showing"
-        if (!controller.waitForEval("subject.state == 'open'", 1000, 100,
+        if (!controller.waitForEval("subject.state == 'open'", 1000, 50,
                                     aRootPopup)) {
           throw new Error("Popup never opened!");
         }
       }
+      // These popups sadly do not close themselves, so we need to keep track
+      //  of them so we can make sure they end up closed.
+      let closeStack = [aRootPopup];
 
       let curPopup = aRootPopup;
       for each (let [iAction, actionObj] in Iterator(aActions)) {
         let matchingNode = null;
 
         let kids = curPopup.children;
         for (let iKid=0; iKid < kids.length; iKid++) {
           let node = kids[iKid];
@@ -765,45 +833,64 @@ var AugmentEverybodyWith = {
 
         if (!matchingNode)
           throw new Error("Did not find matching menu item for action index " +
                           iAction);
 
         this.click(new elib.Elem(matchingNode));
         if ("menupopup" in matchingNode) {
           curPopup = matchingNode.menupopup;
-          if (!controller.waitForEval("subject.state == 'open'", 1000, 100,
+          closeStack.push(curPopup);
+          if (!controller.waitForEval("subject.state == 'open'", 1000, 50,
                                       curPopup)) {
             throw new Error("Popup never opened at action depth: " + iAction);
           }
         }
       }
+
+      while (closeStack.length) {
+        curPopup = closeStack.pop();
+        this.keypress(new elib.Elem(curPopup), "VK_ESCAPE", {});
+        if (!controller.waitForEval("subject.state == 'closed'", 1000, 50,
+                                    curPopup))
+          throw new Error("Popup did not close!");
+      }
     }
-
+  },
+  getters: {
+    focusedElement: function() {
+      let ignoredFocusedWindow = {};
+      return focusManager.getFocusedElementForWindow(this.window, true,
+                                                     ignoredFocusedWindow);
+    },
   },
 };
 
 /**
  * Clicks and other mouse operations used to be recognized just outside a curved
  * border but are no longer so (bug 595652), so we need these wrappers to
  * perform the operations at the center when aLeft or aTop aren't passed in.
  */
 const MOUSE_OPS_TO_WRAP = [
   "click", "doubleClick", "mouseDown", "mouseOut", "mouseOver", "mouseUp",
   "middleClick", "rightClick",
 ];
 
 for (let [, mouseOp] in Iterator(MOUSE_OPS_TO_WRAP)) {
   let thisMouseOp = mouseOp;
   let wrapperFunc = function (aElem, aLeft, aTop) {
-    let rect = aElem.getNode().getBoundingClientRect();
+    let el = aElem.getNode();
+    let rect = el.getBoundingClientRect();
     if (aLeft === undefined)
       aLeft = rect.width / 2;
     if (aTop === undefined)
       aTop = rect.height / 2;
+    // claim to be folder-display-helper since this is an explicit action
+    mark_action("fdh", thisMouseOp,
+                [normalize_for_json(el), "x:", aLeft, "y:", aTop]);
     // |this| refers to the window that gets augmented, which is what we want
     this.__proto__[thisMouseOp](aElem, aLeft, aTop);
   };
   AugmentEverybodyWith.methods[thisMouseOp] = wrapperFunc;
 }
 
 /**
  * Per-windowtype augmentations.  Please use the documentation and general
@@ -864,17 +951,60 @@ var PerWindowTypeAugmentations = {
     onAugment: function(aController) {
       // -- turn off summarization's stabilization logic for now by setting the
       //  timer interval to 0.  We do need to make sure that we drain the event
       //  queue after performing anything that will summarize, but use of
       //  assert_selected_and_displayed in test-folder-display-helpers should
       //  handle that.
       aController.window.MessageDisplayWidget.prototype
                  .SUMMARIZATION_SELECTION_STABILITY_INTERVAL_MS = 0;
-    }
+    },
+    
+    /**
+     * Used to wrap methods on a class prototype in order to generate
+     *  mark_action data about the call.
+     */         
+    debugTrace: [
+      // goDoCommand command gobbling notification
+      {
+        method: "goDoCommand",
+        onGlobal: true,
+        doBefore: function(command) {
+          let controller = this.top.document
+                             .commandDispatcher
+                             .getControllerForCommand(command);
+          if (controller && !controller.isCommandEnabled(command))
+            mark_action("winhelp", "goDoCommand",
+                        ["about to ignore command because it's disabled:",
+                         command]);
+        }
+      },
+      // DefaultController command gobbling notification
+      {
+        method: "doCommand",
+        onObject: "DefaultController",
+        doBefore: function(command) {
+          if (!this.isCommandEnabled(command))
+            mark_action("winhelp", "DC_doCommand",
+                        ["about to ignore command because it's disabled:",
+                         command]);
+        }
+      },
+      // FolderDisplayWidget command invocations
+      {
+        method: "doCommand",
+        onConstructor: "FolderDisplayWidget",
+        reportAs: "FDW_doCommand",
+      },
+      {
+        method: "doCommandWithFolder",
+        onConstructor: "FolderDisplayWidget",
+        reportAs: "FDW_doCommandWithFolder",
+      },
+    ],
   },
 
   /**
    * Standalone message window.
    */
   "mail:messageWindow": {
     elementsToExpose: {
       contentPane: "messagepane",
@@ -945,29 +1075,340 @@ function _augment_helper(aController, aA
     }
   }
   if (aAugmentDef.methods) {
     for each (let [key, value] in Iterator(aAugmentDef.methods)) {
       aController[key] = value;
     }
   }
 
+  if (aAugmentDef.debugTrace) {
+    let win = aController.window;
+    for each (let [, traceDef] in Iterator(aAugmentDef.debugTrace)) {
+      let baseObj, useThis;
+      // - Get the object that actually has the method to wrap
+      if (traceDef.hasOwnProperty("onGlobal")) {
+        baseObj = win;
+        useThis = false;
+      }
+      else if (traceDef.hasOwnProperty("onConstructor")) {
+        baseObj = win[traceDef.onConstructor].prototype;
+        useThis = true;
+      }
+      else if (traceDef.hasOwnProperty("onObject")) {
+        baseObj = win[traceDef.onObject];
+        useThis = false;
+      }
+      else // ignore/bail if unsupported type
+        continue;
+
+      // - compute/set the wrapped attr, bailing if it's already there
+      let wrappedName = "__traceWrapped_" + traceDef.method;
+      // bail if we/someone have already wrapped it.
+      if (baseObj.hasOwnProperty(wrappedName))
+        continue;
+      let origFunc = baseObj[traceDef.method];
+      let reportAs = traceDef.reportAs; // latch
+      baseObj[wrappedName] = origFunc;
+
+      // - create the trace func based on the definition and apply
+      let traceFunc;
+      if (traceDef.hasOwnProperty("doBefore")) {
+        let beforeFunc = traceDef.doBefore;
+        traceFunc = function() {
+          beforeFunc.apply(useThis ? this : baseObj, arguments);
+          return origFunc.apply(this, arguments);
+        }
+      }
+      else {
+        traceFunc = function() {
+          mark_action("winhelp", reportAs,
+                      Array.prototype.slice.call(arguments));
+          return origFunc.apply(this, arguments);
+        }
+      }
+      baseObj[traceDef.method] = traceFunc;
+    }
+  }
+
   if (aAugmentDef.onAugment) {
     aAugmentDef.onAugment(aController);
   }
 }
 
+var INPUT_PEEK_EVENTS = ["click", "keypress"];
+
+function getWindowDescribeyFromEvent(event) {
+  var win = event.target.ownerDocument.defaultView;
+  var owningWin =
+    win.QueryInterface(Ci.nsIInterfaceRequestor)
+       .getInterface(Ci.nsIWebNavigation)
+       .QueryInterface(Ci.nsIDocShellTreeItem)
+       .rootTreeItem
+       .QueryInterface(Ci.nsIInterfaceRequestor)
+       .getInterface(Ci.nsIDOMWindow);
+  var docElem = owningWin.document.documentElement;
+  return docElem.getAttribute("windowtype") ||
+         docElem.getAttribute("id");
+}
+
+function __peek_click_handler(event) {
+  mark_action("winhelp", event.type,
+              ["mouse button", event.button,
+               "target:", normalize_for_json(event.target),
+               "in", getWindowDescribeyFromEvent(event),
+               "original target:", normalize_for_json(event.originalTarget)]);
+  return true;
+}
+
+function __bubbled_click_handler(event) {
+  mark_action("winhelp", "bubbled " + event.type,
+              ["mouse button", event.button,
+               "target:", normalize_for_json(event.target),
+               "in", getWindowDescribeyFromEvent(event),
+               "original target:", normalize_for_json(event.originalTarget)]);
+  return true;
+}
+
+function __peek_keypress_handler(event) {
+  mark_action("winhelp", event.type,
+              ["keycode", event.keyCode, "char", event.charCode,
+               "target:", normalize_for_json(event.target),
+               "in", getWindowDescribeyFromEvent(event)]);
+  return true;
+}
+
+
+function __popup_showing(event) {
+  mark_action("winhelp", "popupShowing",
+              [this,
+               "target:", normalize_for_json(event.target),
+               "current target:", normalize_for_json(event.target)]);
+  return true;
+}
+
+function __popup_shown(event) {
+  mark_action("winhelp", "popupShown",
+              [this,
+               "target:", normalize_for_json(event.target),
+               "current target:", normalize_for_json(event.target)]);
+  return true;
+}
+
+function __popup_hiding(event) {
+  mark_action("winhelp", "popupHiding",
+              [this,
+               "target:", normalize_for_json(event.target),
+               "current target:", normalize_for_json(event.target)]);
+  return true;
+}
+
+function __popup_hidden(event) {
+  mark_action("winhelp", "popupHidden",
+              [this,
+               "target:", normalize_for_json(event.target),
+               "current target:", normalize_for_json(event.target)]);
+  return true;
+}
+
+
 /**
  * controller.js in mozmill actually has its own extension mechanism,
  *  controllerAdditions.  Unfortunately, it does not make its stuff public at
  *  this time.  In the future we can change ourselves to just use that
  *  mechanism.
  */
 function augment_controller(aController, aWindowType) {
   if (aWindowType === undefined)
     aWindowType =
       aController.window.document.documentElement.getAttribute("windowtype");
 
   _augment_helper(aController, AugmentEverybodyWith);
   if (PerWindowTypeAugmentations[aWindowType])
     _augment_helper(aController, PerWindowTypeAugmentations[aWindowType]);
+
+  // for debugging purposes, add our listener that sneaks a peek at clicks and
+  //  key events
+  try {
+    let doc = aController.window.document;
+
+    doc.addEventListener("mousedown", __peek_click_handler, true);
+    doc.addEventListener("click", __peek_click_handler, true);
+    doc.addEventListener("contextmenu", __peek_click_handler, true);
+    doc.addEventListener("mouseup", __peek_click_handler, true);
+
+    doc.addEventListener("mousedown", __bubbled_click_handler, false);
+    doc.addEventListener("click", __bubbled_click_handler, false);
+    doc.addEventListener("contextmenu", __bubbled_click_handler, false);
+    doc.addEventListener("mouseup", __bubbled_click_handler, false);
+
+    doc.addEventListener("keypress", __peek_keypress_handler, true);
+
+    // - also, add pop-up shown/hidden events....
+    // We need to add these directly to the popups themselves in order to
+    //  see anything.
+    let popups = doc.documentElement.getElementsByTagName("menupopup");
+    for (let i = 0; i < popups.length; i++) {
+      let popup = popups[i];
+      popup.addEventListener("popupshowing", __popup_showing, true);
+      popup.addEventListener("popupshown", __popup_shown, true);
+      popup.addEventListener("popuphiding", __popup_hiding, true);
+      popup.addEventListener("popuphidden", __popup_hidden, true);
+    }
+    // Now go find the anonymous popups for tree column pickers that the
+    //  above selector could not find because they live in anonymous
+    //  content pocket universes.
+    let treecolses = doc.documentElement.getElementsByTagName("treecols");
+    for (let i = 0; i < treecolses.length; i++) {
+      let treecols = treecolses[i];
+      // The treecolpicker element itself doesn't have an id, so we have to walk
+      // down from the parent to find it.
+      //  treadCols
+      //   |- hbox                item 0
+      //   |- treecolpicker   <-- item 1 this is the one we want
+      let treeColPicker = doc.getAnonymousNodes(treecols).item(1);
+      let popup = doc.getAnonymousElementByAttribute(treeColPicker,
+                                                     "anonid", "popup");
+      popup.addEventListener("popupshowing", __popup_showing, true);
+      popup.addEventListener("popupshown", __popup_shown, true);
+      popup.addEventListener("popuphiding", __popup_hiding, true);
+      popup.addEventListener("popuphidden", __popup_hidden, true);
+    }
+
+  }
+  catch(ex) {
+    dump("!!!! failure augmenting controller: " + ex + "\n" + ex.stack);
+  }
+
+
   return aController;
 }
+
+/**
+ * Render the contents of a window to a data URL.  Every effort is made to
+ * make the screenshot as real as possible, but currently this is all done using
+ * canvas-based rendering which is not the same thing as a real screenshot.
+ *
+ * @param aWindow The window to render
+ */
+function screenshotToDataURL(aWindow) {
+  // -- render to canvas
+  let win = aWindow;
+  let doc = win.document;
+  let canvas = doc.createElementNS("http://www.w3.org/1999/xhtml", "canvas");
+  let width = win.innerWidth;
+  let height = win.innerHeight;
+
+  canvas.style.width = width + "px";
+  canvas.style.height = height + "px";
+  canvas.width = width;
+  canvas.height = height;
+  let ctx = canvas.getContext("2d");
+  // We use the following flags, which appear to avoid us needing to
+  // recursively render the contained iframes/browsers.  Or the behaviour
+  // changed a while ago and we never noticed.
+  //  DRAWWINDOW_DRAW_VIEW = 0x04
+  //  DRAWWINDOW_USE_WIDGET_LAYERS = 0x08
+  ctx.drawWindow(win, 0, 0, width, height, "rgb(0,0,0)",
+                 0x04 | 0x08);
+
+  // As per the note about flags above, we no longer appear to need to do
+  // the following, so it is commented out.  It is left around rather than
+  // deleted because in the event we do need it again, this has some
+  // improvements on the other variations a search might turn up.
+  //
+  // (We may need to do this for popups...)
+  /*
+  // - find all the sub-windows and render them
+  function isVisible(aElem) {
+    if (aElem.hidden || aElem.collapsed)
+      return false;
+    let parent = aElem.parentNode;
+    if (parent == null)
+      return true;
+    if (("selectedPanel" in parent) &&
+        parent.selectedPanel != aElem)
+      return false;
+    return isVisible(parent);
+  }
+
+  function subrenderCandidates(aElements) {
+    for (let i = 0; i < aElements.length; i++) {
+      let elem = aElements[i];
+      if (isVisible(elem)) {
+        let rect = elem.getBoundingClientRect();
+        ctx.save();
+        ctx.translate(rect.left, rect.top);
+        ctx.drawWindow(elem.contentWindow,
+                       0, 0,
+                       rect.right - rect.left, rect.bottom - rect.top,
+                       "rgb(255,255,255)");
+        ctx.restore();
+      }
+    }
+  }
+  subrenderCandidates(doc.documentElement.getElementsByTagName("iframe"));
+  subrenderCandidates(doc.documentElement.getElementsByTagName("browser"));
+  */
+
+  return canvas.toDataURL("image/png", "");
+}
+
+/**
+ * Render the contents of a window to a base64-encoded string.
+ */
+function screenshotToBase64(aWindow) {
+  let dataUrl = screenshotToDataURL(aWindow);
+  return dataUrl.substring(dataUrl.indexOf("base64,") + 7);
+}
+
+/**
+ * Capture general information on the state of all open windows and provide
+ *  them in a JSON-serializable object blob.
+ *
+ * Specific details for each window:
+ * - Screen coordinates and dimensions of the window.
+ * - Is the window active/focused?
+ * - The focused element in the window; we leave this up to logHelper to
+ *    describe.
+ */
+function captureWindowStatesForErrorReporting(normalizeForJsonFunc) {
+  let info = {};
+  let windows = info.windows = [];
+
+  let windowMediator = Cc["@mozilla.org/appshell/window-mediator;1"]
+                         .getService(Ci.nsIWindowMediator);
+
+  let enumerator = windowMediator.getEnumerator(null);
+  let iWin=0;
+  while (enumerator.hasMoreElements()) {
+    let win = enumerator.getNext().QueryInterface(Ci.nsIDOMWindowInternal);
+
+    let winId = win.document.documentElement.getAttribute("windowtype") ||
+                win.document.documentElement.getAttribute("id") ||
+                ("unnamed:" + iWin);
+
+    let openPopups =
+      Array.prototype.slice.call(
+          win.document.documentElement.getElementsByTagName("menupopup"))
+        .filter(function(x) x.state != "closed")
+        .map(function (x) normalizeForJsonFunc(x));
+
+    let ignoredFocusedWindow = {};
+    let winfo = {
+      id: winId,
+      title: win.document.title,
+      coords: {x: win.screenX, y: win.screenY},
+      dims: {width: win.outerWidth, height: win.outerHeight},
+      pageOffsets: {x: win.pageXOffset, y: win.pageYOffset},
+      screenshotDataUrl: screenshotToDataURL(win),
+      isActive: focusManager.activeWindow == win,
+      focusedElem: normalizeForJsonFunc(
+        focusManager.getFocusedElementForWindow(win, true,
+                                                ignoredFocusedWindow)),
+      openPopups: openPopups,
+    };
+
+    windows.push(winfo);
+  }
+
+  return info;
+}
--- a/mailnews/db/gloda/modules/log4moz.js
+++ b/mailnews/db/gloda/modules/log4moz.js
@@ -187,16 +187,17 @@ let Log4Moz = {
 
   get Formatter() { return Formatter; },
   get BasicFormatter() { return BasicFormatter; },
   get XMLFormatter() { return XMLFormatter; },
   get JSONFormatter() { return JSONFormatter; },
   get Appender() { return Appender; },
   get DumpAppender() { return DumpAppender; },
   get ConsoleAppender() { return ConsoleAppender; },
+  get TimeAwareMemoryBucketAppender() { return TimeAwareMemoryBucketAppender; },
   get FileAppender() { return FileAppender; },
   get SocketAppender() { return SocketAppender; },
   get RotatingFileAppender() { return RotatingFileAppender; },
   get ThrowingAppender() { return ThrowingAppender; },
 
   // Logging helper:
   // let logger = Log4Moz.repository.getLogger("foo");
   // logger.info(Log4Moz.enumerateInterfaces(someObject).join(","));
@@ -233,17 +234,17 @@ let Log4Moz = {
       }
     }
 
     return properties;
   }
 };
 
 function LoggerContext() {
-  this._started = this.lastStateChange = Date.now();
+  this._started = this._lastStateChange = Date.now();
   this._state = "started";
 }
 LoggerContext.prototype = {
   _jsonMe: true,
   _id: "unknown",
   setState: function LoggerContext_state(aState) {
     this._state = aState;
     this._lastStateChange = Date.now();
@@ -525,16 +526,22 @@ XMLFormatter.prototype = {
 };
 
 function JSONFormatter() {
 }
 JSONFormatter.prototype = {
   __proto__: Formatter.prototype,
 
   format: function JF_format(message) {
+    // XXX I did all kinds of questionable things in here; they should be
+    //  resolved...
+    // 1) JSON does not walk the __proto__ chain; there is no need to clobber
+    //   it.
+    // 2) Our net mutation is sorta redundant messageObjects alongside
+    //   msgObjects, although we only serialize one.
     let origMessageObjects = message.messageObjects;
     message.messageObjects = [];
     let reProto = [];
     for each (let [, messageObject] in Iterator(origMessageObjects)) {
       if (messageObject)
         if (messageObject._jsonMe) {
           message.messageObjects.push(messageObject);
           // temporarily strip the prototype to avoid JSONing the impl.
@@ -596,16 +603,75 @@ function DumpAppender(formatter) {
 DumpAppender.prototype = {
   __proto__: Appender.prototype,
 
   doAppend: function DApp_doAppend(message) {
     dump(message);
   }
 };
 
+/**
+ * An in-memory appender that always logs to its in-memory bucket and associates
+ * each message with a timestamp.  Whoever creates us is responsible for causing
+ * us to switch to a new bucket using whatever criteria is appropriate.
+ *
+ * This is intended to be used roughly like an in-memory circular buffer.  The
+ * expectation is that we are being used for unit tests and that each unit test
+ * function will get its own bucket.  In the event that a test fails we would
+ * be asked for the contents of the current bucket and some portion of the
+ * previous bucket using up to some duration.
+ */
+function TimeAwareMemoryBucketAppender() {
+  this._name = "TimeAwareMemoryBucketAppender";
+  this._level = Log4Moz.Level.All;
+
+  this._lastBucket = null;
+  // to minimize object construction, even indices are timestamps, odd indices
+  //  are the message objects.
+  this._curBucket = [];
+  this._curBucketStartedAt = Date.now();
+}
+TimeAwareMemoryBucketAppender.prototype = {
+  get level() { return this._level; },
+  set level(level) { this._level = level; },
+
+  append: function TAMBA_append(message) {
+    if (this._level <= message.level)
+      this._curBucket.push(message);
+  },
+
+  newBucket: function() {
+    this._lastBucket = this._curBucket;
+    this._curBucketStartedAt = Date.now();
+    this._curBucket = [];
+  },
+
+  getPreviousBucketEvents: function(aNumMS) {
+    let lastBucket = this._lastBucket;
+    if (lastBucket == null || !lastBucket.length)
+      return [];
+    let timeBound = this._curBucketStartedAt - aNumMS;
+    // seek backwards through the list...
+    let i;
+    for (i = lastBucket.length - 1; i >= 0; i --) {
+      if (lastBucket[i].time < timeBound)
+        break;
+    }
+    return lastBucket.slice(i+1);
+  },
+
+  getBucketEvents: function() {
+    return this._curBucket.concat();
+  },
+
+  toString: function() {
+    return "[TimeAwareMemoryBucketAppender]";
+  },
+};
+
 /*
  * ConsoleAppender
  * Logs to the javascript console
  */
 
 function ConsoleAppender(formatter) {
   this._name = "ConsoleAppender";
   this._formatter = formatter;
--- a/mailnews/test/resources/logHelper.js
+++ b/mailnews/test/resources/logHelper.js
@@ -295,17 +295,18 @@ function __simple_obj_copy(aObj, aDepthA
     }
     else if (typeof(value) != "object") {
       oot[key] = value;
     }
     // steal control flow if no more depth is allowed
     else if (!aDepthAllowed) {
       oot[key] = "truncated, string rep: " + value.toString();
     }
-    // array?  we don't count that as depth for now.
+    // array?  (not directly counted, but we will terminate because the
+    //  child copying occurs using nextDepth...)
     else if (Array.isArray(value)) {
       oot[key] = [__value_copy(v, nextDepth) for each
                    ([, v] in Iterator(value))];
     }
     // it's another object! woo!
     else {
       oot[key] = _normalize_for_json(value, nextDepth, true);
     }
@@ -340,16 +341,21 @@ function _normalize_for_json(aObj, aDept
     aDepthAllowed = 2;
 
   // if it's a simple type just return it direct
   if (typeof(aObj) != "object")
     return aObj;
   else if (aObj == null)
     return aObj;
 
+  // recursively transform arrays outright
+  if (Array.isArray(aObj))
+      return [__value_copy(v, aDepthAllowed - 1) for each
+              ([, v] in Iterator(aObj))];
+
   // === Mail Specific ===
   // (but common and few enough to not split out)
   if (aObj instanceof Ci.nsIMsgFolder) {
     let flags = aObj.flags;
     return {
       type: "folder",
       name: aObj.prettiestName,
       uri: aObj.URI,
@@ -382,21 +388,30 @@ function _normalize_for_json(aObj, aDept
   }
   // === Generic ===
   // DOM nodes, including elements
   else if (aObj instanceof Ci.nsIDOMNode) {
     let name = aObj.nodeName;
     if (aObj instanceof Ci.nsIDOMElement)
       name += "#" + aObj.getAttribute("id");
 
+    let nodeAttrs = aObj.attributes, objAttrs = {};
+    for (let iAttr = 0; iAttr < nodeAttrs.length; iAttr++) {
+      objAttrs[nodeAttrs[iAttr].name] = nodeAttrs[iAttr].value;
+    }
+
+    let bounds = aObj.getBoundingClientRect();
     return {
       type: "domNode",
       name: name,
       value: aObj.nodeValue,
       namespace: aObj.namespaceURI,
+      boundingClientRect: {left: bounds.left, top: bounds.top,
+                           width: bounds.width, height: bounds.height},
+      attrs: objAttrs,
     };
   }
   // Although straight JS exceptions should serialize pretty well, we can
   //  improve things by making "stack" more friendly.
   else if (aObj instanceof Error) {
     return {
       type: "error",
       message: aObj.message,
@@ -496,17 +511,18 @@ function _MarkAction(aWho, aWhat, aArgs)
  * @param aArgs A list of arguments, which could each be something like an
  *     nsIMsgFolder or nsIMsgDBHdr or something like that.  It uses
  *     |_normalize_for_json| which can handle some native objects, be extended
  *     to handle more, and does a fair job on straight JS objects.
  */
 function mark_action(aWho, aWhat, aArgs) {
   let logger = Log4Moz.repository.getLogger("test." + aWho);
 
-  aArgs = [_normalize_for_json(arg) for each ([, arg] in Iterator(aArgs))];
+  aArgs = [_normalize_for_json(arg, undefined, true) for each
+           ([, arg] in Iterator(aArgs))];
   logger.info(_testLoggerActiveContext, new _MarkAction(aWho, aWhat, aArgs));
 }
 
 /*
  * Wrap the xpcshell test functions that do interesting things.  The idea is
  *  that we clobber these only if we're going to value-add; that decision
  *  gets made up top in the initialization function.
  *
--- a/mailnews/test/resources/messageInjection.js
+++ b/mailnews/test/resources/messageInjection.js
@@ -445,16 +445,21 @@ function get_trash_folder() {
  *     those attribute things.
  * @param aBooleanAnd Should the search terms be and-ed together.
  * @param [aName] Name to use.
  */
 function make_virtual_folder(aFolders, aSearchDef, aBooleanAnd, aName) {
   let mis = _messageInjectionSetup;
   let name = aName ? aName : "virt" + mis._nextUniqueFolderId++;
 
+  mark_action("messageInjection", "make_virtual_folder",
+              ["creating folder named", name,
+               "from folders", aFolders, "anding?", aBooleanAnd,
+               "using search def", aSearchDef]);
+
   let terms = [];
   let termCreator = Components.classes["@mozilla.org/messenger/searchSession;1"]
                               .createInstance(Ci.nsIMsgSearchSession);
   for each (let [key, val] in Iterator(aSearchDef)) {
     let term = termCreator.createTerm();
     let value = term.value;
     value.str = val;
     term.value = value;