Bug 777339, Use prlogging for focus instead of enabling a define, allowing for easier enabling of focus logging, r=smaug
authorNeil Deakin <neil@mozilla.com>
Mon, 30 Jul 2012 20:43:28 -0400
changeset 100928 de293780ba8aab62cfa995b1254b4e5601e85461
parent 100927 1ca7e8b00fbbea1b33ff8e5a515833faeb28044e
child 100929 b8a0228a10faac7d965155e15bd66ff8bf3ddb82
push id1
push userroot
push dateMon, 20 Oct 2014 17:29:22 +0000
reviewerssmaug
bugs777339
milestone17.0a1
Bug 777339, Use prlogging for focus instead of enabling a define, allowing for easier enabling of focus logging, r=smaug
dom/base/nsFocusManager.cpp
--- a/dom/base/nsFocusManager.cpp
+++ b/dom/base/nsFocusManager.cpp
@@ -64,26 +64,48 @@
 #ifdef ACCESSIBILITY
 #include "nsAccessibilityService.h"
 #endif
 
 using namespace mozilla;
 using namespace mozilla::dom;
 using namespace mozilla::widget;
 
-//#define DEBUG_FOCUS 1
-//#define DEBUG_FOCUS_NAVIGATION 1
-#define PRINTTAGF(format, content)                     \
-  {                                                    \
-    nsAutoString tag(NS_LITERAL_STRING("(none)"));     \
-    if (content)                                       \
-      content->Tag()->ToString(tag);                   \
-    printf(format, NS_ConvertUTF16toUTF8(tag).get());  \
+#ifdef PR_LOGGING
+
+// Two types of focus pr logging are available:
+//   'Focus' for normal focus manager calls
+//   'FocusNavigation' for tab and document navigation
+PRLogModuleInfo* gFocusLog;
+PRLogModuleInfo* gFocusNavigationLog;
+
+#define LOGFOCUS(args) PR_LOG(gFocusLog, 4, args)
+#define LOGFOCUSNAVIGATION(args) PR_LOG(gFocusNavigationLog, 4, args)
+
+#define LOGTAG(log, format, content)                            \
+  {                                                             \
+    nsCAutoString tag(NS_LITERAL_CSTRING("(none)"));            \
+    if (content) {                                              \
+      content->Tag()->ToUTF8String(tag);                        \
+    }                                                           \
+    PR_LOG(log, 4, (format, tag.get()));                        \
   }
 
+#define LOGCONTENT(format, content) LOGTAG(gFocusLog, format, content)
+#define LOGCONTENTNAVIGATION(format, content) LOGTAG(gFocusNavigationLog, format, content)
+
+#else
+
+#define LOGFOCUS(args)
+#define LOGFOCUSNAVIGATION(args)
+#define LOGCONTENT(format, content)
+#define LOGCONTENTNAVIGATION(format, content)
+
+#endif
+
 struct nsDelayedBlurOrFocusEvent
 {
   nsDelayedBlurOrFocusEvent(PRUint32 aType,
                             nsIPresShell* aPresShell,
                             nsIDocument* aDocument,
                             nsIDOMEventTarget* aTarget)
    : mType(aType),
      mPresShell(aPresShell),
@@ -159,16 +181,21 @@ nsFocusManager::~nsFocusManager()
 nsresult
 nsFocusManager::Init()
 {
   nsFocusManager* fm = new nsFocusManager();
   NS_ENSURE_TRUE(fm, NS_ERROR_OUT_OF_MEMORY);
   NS_ADDREF(fm);
   sInstance = fm;
 
+#ifdef PR_LOGGING
+  gFocusLog = PR_NewLogModule("Focus");
+  gFocusNavigationLog = PR_NewLogModule("FocusNavigation");
+#endif
+
   nsIContent::sTabFocusModelAppliesToXUL =
     Preferences::GetBool("accessibility.tabfocus_applies_to_xul",
                          nsIContent::sTabFocusModelAppliesToXUL);
 
   sMouseFocusesFormControl =
     Preferences::GetBool("accessibility.mouse_focuses_formcontrol", false);
 
   sTestMode = Preferences::GetBool("focusmanager.testmode", false);
@@ -353,19 +380,17 @@ NS_IMETHODIMP
 nsFocusManager::GetFocusedWindow(nsIDOMWindow** aFocusedWindow)
 {
   NS_IF_ADDREF(*aFocusedWindow = mFocusedWindow);
   return NS_OK;
 }
 
 NS_IMETHODIMP nsFocusManager::SetFocusedWindow(nsIDOMWindow* aWindowToFocus)
 {
-#ifdef DEBUG_FOCUS
-  printf("<<SetFocusedWindow begin>>\n");
-#endif
+  LOGFOCUS(("<<SetFocusedWindow begin>>"));
 
   nsCOMPtr<nsPIDOMWindow> windowToFocus(do_QueryInterface(aWindowToFocus));
   NS_ENSURE_TRUE(windowToFocus, NS_ERROR_FAILURE);
 
   windowToFocus = windowToFocus->GetOuterWindow();
 
   nsCOMPtr<nsIContent> frameContent =
     do_QueryInterface(windowToFocus->GetFrameElementInternal());
@@ -386,19 +411,17 @@ NS_IMETHODIMP nsFocusManager::SetFocused
         ClearFocus(windowToFocus);
     }
   }
 
   nsCOMPtr<nsPIDOMWindow> rootWindow = windowToFocus->GetPrivateRoot();
   if (rootWindow)
     RaiseWindow(rootWindow);
 
-#ifdef DEBUG_FOCUS
-  printf("<<SetFocusedWindow end>>\n");
-#endif
+  LOGFOCUS(("<<SetFocusedWindow end>>"));
 
   return NS_OK;
 }
 
 NS_IMETHODIMP
 nsFocusManager::GetFocusedElement(nsIDOMElement** aFocusedElement)
 {
   if (mFocusedContent)
@@ -423,25 +446,25 @@ nsFocusManager::GetLastFocusMethod(nsIDO
   NS_ASSERTION((*aLastFocusMethod & FOCUSMETHOD_MASK) == *aLastFocusMethod,
                "invalid focus method");
   return NS_OK;
 }
 
 NS_IMETHODIMP
 nsFocusManager::SetFocus(nsIDOMElement* aElement, PRUint32 aFlags)
 {
-#ifdef DEBUG_FOCUS
-  printf("<<SetFocus>>\n");
-#endif
+  LOGFOCUS(("<<SetFocus begin>>"));
 
   nsCOMPtr<nsIContent> newFocus = do_QueryInterface(aElement);
   NS_ENSURE_ARG(newFocus);
 
   SetFocusInner(newFocus, aFlags, true, true);
 
+  LOGFOCUS(("<<SetFocus end>>"));
+
   return NS_OK;
 }
 
 NS_IMETHODIMP
 nsFocusManager::ElementIsFocusable(nsIDOMElement* aElement, PRUint32 aFlags,
                                    bool* aIsFocusable)
 {
   NS_ENSURE_TRUE(aElement, NS_ERROR_INVALID_ARG);
@@ -454,29 +477,29 @@ nsFocusManager::ElementIsFocusable(nsIDO
 }
 
 NS_IMETHODIMP
 nsFocusManager::MoveFocus(nsIDOMWindow* aWindow, nsIDOMElement* aStartElement,
                           PRUint32 aType, PRUint32 aFlags, nsIDOMElement** aElement)
 {
   *aElement = nullptr;
 
-#ifdef DEBUG_FOCUS
-  printf("<<MoveFocus Type: %d Flags: %x>>\n<<", aType, aFlags);
-
-  nsCOMPtr<nsPIDOMWindow> focusedWindow = mFocusedWindow;
-  if (focusedWindow) {
-    nsCOMPtr<nsIDocument> doc = do_QueryInterface(focusedWindow->GetExtantDocument());
-    if (doc) {
+#ifdef PR_LOGGING
+  LOGFOCUS(("<<MoveFocus begin Type: %d Flags: %x>>", aType, aFlags));
+
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG) && mFocusedWindow) {
+    nsIDocument* doc = mFocusedWindow->GetExtantDoc();
+    if (doc && doc->GetDocumentURI()) {
       nsCAutoString spec;
       doc->GetDocumentURI()->GetSpec(spec);
-      printf(" [%p] Focused Window: %s", mFocusedWindow.get(), spec.get());
+      LOGFOCUS((" Focused Window: %p %s", mFocusedWindow.get(), spec.get()));
     }
   }
-  PRINTTAGF(">> $[[%s]]\n", mFocusedContent);
+
+  LOGCONTENT("  Current Focus: %s", mFocusedContent.get());
 #endif
 
   // use FLAG_BYMOVEFOCUS when switching focus with MoveFocus unless one of
   // the other focus methods is already set, or we're just moving to the root
   // or caret position.
   if (aType != MOVEFOCUS_ROOT && aType != MOVEFOCUS_CARET &&
       (aFlags & FOCUSMETHOD_MASK) == 0) {
     aFlags |= FLAG_BYMOVEFOCUS;
@@ -499,46 +522,40 @@ nsFocusManager::MoveFocus(nsIDOMWindow* 
   NS_ENSURE_TRUE(window, NS_ERROR_FAILURE);
 
   bool noParentTraversal = aFlags & FLAG_NOPARENTFRAME;
   nsCOMPtr<nsIContent> newFocus;
   nsresult rv = DetermineElementToMoveFocus(window, startContent, aType, noParentTraversal,
                                             getter_AddRefs(newFocus));
   NS_ENSURE_SUCCESS(rv, rv);
 
-#ifdef DEBUG_FOCUS_NAVIGATION
-  PRINTTAGF("-> Element to be focused: %s\n", newFocus);
-#endif
+  LOGCONTENTNAVIGATION("Element to be focused: %s", newFocus.get());
 
   if (newFocus) {
     // for caret movement, pass false for the aFocusChanged argument,
     // otherwise the caret will end up moving to the focus position. This
     // would be a problem because the caret would move to the beginning of the
     // focused link making it impossible to navigate the caret over a link.
     SetFocusInner(newFocus, aFlags, aType != MOVEFOCUS_CARET, true);
     CallQueryInterface(newFocus, aElement);
   }
   else if (aType == MOVEFOCUS_ROOT || aType == MOVEFOCUS_CARET) {
     // no content was found, so clear the focus for these two types.
     ClearFocus(window);
   }
 
-#ifdef DEBUG_FOCUS
-  printf("<<MoveFocus end>>\n");
-#endif
+  LOGFOCUS(("<<MoveFocus end>>"));
 
   return NS_OK;
 }
 
 NS_IMETHODIMP
 nsFocusManager::ClearFocus(nsIDOMWindow* aWindow)
 {
-#ifdef DEBUG_FOCUS
-  printf("<<ClearFocus begin>>\n");
-#endif
+  LOGFOCUS(("<<ClearFocus begin>>"));
 
   // if the window to clear is the focused window or an ancestor of the
   // focused window, then blur the existing focused content. Otherwise, the
   // focus is somewhere else so just update the current node.
   nsCOMPtr<nsPIDOMWindow> window(do_QueryInterface(aWindow));
   NS_ENSURE_TRUE(window, NS_ERROR_INVALID_ARG);
 
   window = window->GetOuterWindow();
@@ -552,19 +569,17 @@ nsFocusManager::ClearFocus(nsIDOMWindow*
       if (isAncestor)
         Focus(window, nullptr, 0, true, false, false, true);
     }
   }
   else {
     window->SetFocusedNode(nullptr);
   }
 
-#ifdef DEBUG_FOCUS
-  printf("<<ClearFocus end>>\n");
-#endif
+  LOGFOCUS(("<<ClearFocus end>>"));
 
   return NS_OK;
 }
 
 NS_IMETHODIMP
 nsFocusManager::GetFocusedElementForWindow(nsIDOMWindow* aWindow,
                                            bool aDeep,
                                            nsIDOMWindow** aFocusedWindow,
@@ -629,32 +644,33 @@ nsFocusManager::MoveCaretToFocus(nsIDOMW
 }
 
 NS_IMETHODIMP
 nsFocusManager::WindowRaised(nsIDOMWindow* aWindow)
 {
   nsCOMPtr<nsPIDOMWindow> window = do_QueryInterface(aWindow);
   NS_ENSURE_TRUE(window && window->IsOuterWindow(), NS_ERROR_INVALID_ARG);
 
-#ifdef DEBUG_FOCUS
-  printf("Window %p Raised [Currently: %p %p] <<", aWindow, mActiveWindow.get(), mFocusedWindow.get());
-  nsCAutoString spec;
-  nsCOMPtr<nsIDocument> doc = do_QueryInterface(window->GetExtantDocument());
-  if (doc) {
-    doc->GetDocumentURI()->GetSpec(spec);
-    printf("[%p] Raised Window: %s", aWindow, spec.get());
-  }
-  if (mActiveWindow) {
-    doc = do_QueryInterface(mActiveWindow->GetExtantDocument());
-    if (doc) {
+#ifdef PR_LOGGING
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG)) {
+    LOGFOCUS(("Window %p Raised [Currently: %p %p]", aWindow, mActiveWindow.get(), mFocusedWindow.get()));
+    nsCAutoString spec;
+    nsIDocument* doc = window->GetExtantDoc();
+    if (doc && doc->GetDocumentURI()) {
       doc->GetDocumentURI()->GetSpec(spec);
-      printf(" [%p] Active Window: %s", mActiveWindow.get(), spec.get());
+      LOGFOCUS(("  Raised Window: %p %s", aWindow, spec.get()));
+    }
+    if (mActiveWindow) {
+      doc = mActiveWindow->GetExtantDoc();
+      if (doc && doc->GetDocumentURI()) {
+        doc->GetDocumentURI()->GetSpec(spec);
+        LOGFOCUS(("  Active Window: %p %s", mActiveWindow.get(), spec.get()));
+      }
     }
   }
-  printf(">>\n");
 #endif
 
   if (mActiveWindow == window) {
     // The window is already active, so there is no need to focus anything,
     // but make sure that the right widget is focused. This is a special case
     // for Windows because when restoring a minimized window, a second
     // activation will occur and the top-level widget could be focused instead
     // of the child we want. We solve this by calling SetFocus to ensure that
@@ -690,18 +706,17 @@ nsFocusManager::WindowRaised(nsIDOMWindo
     baseWindow->SetVisibility(true);
   }
 
   // inform the DOM window that it has activated, so that the active attribute
   // is updated on the window
   window->ActivateOrDeactivate(true);
 
   // send activate event
-  nsCOMPtr<nsIDocument> document = do_QueryInterface(window->GetExtantDocument());
-  nsContentUtils::DispatchTrustedEvent(document,
+  nsContentUtils::DispatchTrustedEvent(window->GetExtantDoc(),
                                        window,
                                        NS_LITERAL_STRING("activate"),
                                        true, true, nullptr);
 
   // retrieve the last focused element within the window that was raised
   nsCOMPtr<nsPIDOMWindow> currentWindow;
   nsCOMPtr<nsIContent> currentFocus =
     GetFocusedDescendant(window, true, getter_AddRefs(currentWindow));
@@ -727,47 +742,47 @@ nsFocusManager::WindowRaised(nsIDOMWindo
 }
 
 NS_IMETHODIMP
 nsFocusManager::WindowLowered(nsIDOMWindow* aWindow)
 {
   nsCOMPtr<nsPIDOMWindow> window = do_QueryInterface(aWindow);
   NS_ENSURE_TRUE(window && window->IsOuterWindow(), NS_ERROR_INVALID_ARG);
 
-#ifdef DEBUG_FOCUS
-  printf("Window %p Lowered [Currently: %p %p] <<", aWindow, mActiveWindow.get(), mFocusedWindow.get());
-  nsCAutoString spec;
-  nsCOMPtr<nsIDocument> doc = do_QueryInterface(window->GetExtantDocument());
-  if (doc) {
-    doc->GetDocumentURI()->GetSpec(spec);
-    printf("[%p] Lowered Window: %s", aWindow, spec.get());
-  }
-  if (mActiveWindow) {
-    doc = do_QueryInterface(mActiveWindow->GetExtantDocument());
-    if (doc) {
+#ifdef PR_LOGGING
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG)) {
+    LOGFOCUS(("Window %p Lowered [Currently: %p %p]", aWindow, mActiveWindow.get(), mFocusedWindow.get()));
+    nsCAutoString spec;
+    nsIDocument* doc = window->GetExtantDoc();
+    if (doc && doc->GetDocumentURI()) {
       doc->GetDocumentURI()->GetSpec(spec);
-      printf(" [%p] Active Window: %s", mActiveWindow.get(), spec.get());
+      LOGFOCUS(("  Lowered Window: %s", spec.get()));
+    }
+    if (mActiveWindow) {
+      doc = mActiveWindow->GetExtantDoc();
+      if (doc && doc->GetDocumentURI()) {
+        doc->GetDocumentURI()->GetSpec(spec);
+        LOGFOCUS(("  Active Window: %s", spec.get()));
+      }
     }
   }
-  printf(">>\n");
 #endif
 
   if (mActiveWindow != window)
     return NS_OK;
 
   // clear the mouse capture as the active window has changed
   nsIPresShell::SetCapturingContent(nullptr, 0);
 
   // inform the DOM window that it has deactivated, so that the active
   // attribute is updated on the window
   window->ActivateOrDeactivate(false);
 
   // send deactivate event
-  nsCOMPtr<nsIDocument> document = do_QueryInterface(window->GetExtantDocument());
-  nsContentUtils::DispatchTrustedEvent(document,
+  nsContentUtils::DispatchTrustedEvent(window->GetExtantDoc(),
                                        window,
                                        NS_LITERAL_STRING("deactivate"),
                                        true, true, nullptr);
 
   // keep track of the window being lowered, so that attempts to raise the
   // window can be prevented until we return. Otherwise, focus can get into
   // an unusual state.
   mWindowBeingLowered = mActiveWindow;
@@ -835,33 +850,34 @@ nsFocusManager::ContentRemoved(nsIDocume
 NS_IMETHODIMP
 nsFocusManager::WindowShown(nsIDOMWindow* aWindow, bool aNeedsFocus)
 {
   nsCOMPtr<nsPIDOMWindow> window = do_QueryInterface(aWindow);
   NS_ENSURE_TRUE(window, NS_ERROR_INVALID_ARG);
 
   window = window->GetOuterWindow();
 
-#ifdef DEBUG_FOCUS
-  printf("Window %p Shown [Currently: %p %p] <<", window.get(), mActiveWindow.get(), mFocusedWindow.get());
-  nsCAutoString spec;
-  nsCOMPtr<nsIDocument> doc = do_QueryInterface(window->GetExtantDocument());
-  if (doc) {
-    doc->GetDocumentURI()->GetSpec(spec);
-    printf("Shown Window: %s", spec.get());
-  }
-
-  if (mFocusedWindow) {
-    doc = do_QueryInterface(mFocusedWindow->GetExtantDocument());
-    if (doc) {
+#ifdef PR_LOGGING
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG)) {
+    LOGFOCUS(("Window %p Shown [Currently: %p %p]", window.get(), mActiveWindow.get(), mFocusedWindow.get()));
+    nsCAutoString spec;
+    nsIDocument* doc = window->GetExtantDoc();
+    if (doc && doc->GetDocumentURI()) {
       doc->GetDocumentURI()->GetSpec(spec);
-      printf(" Focused Window: %s", spec.get());
+      LOGFOCUS(("Shown Window: %s", spec.get()));
+    }
+
+    if (mFocusedWindow) {
+      doc = mFocusedWindow->GetExtantDoc();
+      if (doc && doc->GetDocumentURI()) {
+        doc->GetDocumentURI()->GetSpec(spec);
+        LOGFOCUS((" Focused Window: %s", spec.get()));
+      }
     }
   }
-  printf(">>\n");
 #endif
 
   if (mFocusedWindow != window)
     return NS_OK;
 
   if (aNeedsFocus) {
     nsCOMPtr<nsPIDOMWindow> currentWindow;
     nsCOMPtr<nsIContent> currentFocus =
@@ -886,41 +902,42 @@ nsFocusManager::WindowHidden(nsIDOMWindo
   // currently focused window, just return, as the current focus will not
   // be affected.
 
   nsCOMPtr<nsPIDOMWindow> window = do_QueryInterface(aWindow);
   NS_ENSURE_TRUE(window, NS_ERROR_INVALID_ARG);
 
   window = window->GetOuterWindow();
 
-#ifdef DEBUG_FOCUS
-  printf("Window %p Hidden [Currently: %p %p] <<", window.get(), mActiveWindow.get(), mFocusedWindow.get());
-  nsCAutoString spec;
-  nsCOMPtr<nsIDocument> doc = do_QueryInterface(window->GetExtantDocument());
-  if (doc) {
-    doc->GetDocumentURI()->GetSpec(spec);
-    printf("Hide Window: %s", spec.get());
-  }
-
-  if (mFocusedWindow) {
-    doc = do_QueryInterface(mFocusedWindow->GetExtantDocument());
-    if (doc) {
+#ifdef PR_LOGGING
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG)) {
+    LOGFOCUS(("Window %p Hidden [Currently: %p %p]", window.get(), mActiveWindow.get(), mFocusedWindow.get()));
+    nsCAutoString spec;
+    nsIDocument* doc = window->GetExtantDoc();
+    if (doc && doc->GetDocumentURI()) {
       doc->GetDocumentURI()->GetSpec(spec);
-      printf(" Focused Window: %s", spec.get());
+      LOGFOCUS(("  Hide Window: %s", spec.get()));
+    }
+
+    if (mFocusedWindow) {
+      doc = mFocusedWindow->GetExtantDoc();
+      if (doc && doc->GetDocumentURI()) {
+        doc->GetDocumentURI()->GetSpec(spec);
+        LOGFOCUS(("  Focused Window: %s", spec.get()));
+      }
+    }
+
+    if (mActiveWindow) {
+      doc = mActiveWindow->GetExtantDoc();
+      if (doc && doc->GetDocumentURI()) {
+        doc->GetDocumentURI()->GetSpec(spec);
+        LOGFOCUS(("  Active Window: %s", spec.get()));
+      }
     }
   }
-
-  if (mActiveWindow) {
-    doc = do_QueryInterface(mActiveWindow->GetExtantDocument());
-    if (doc) {
-      doc->GetDocumentURI()->GetSpec(spec);
-      printf(" Active Window: %s", spec.get());
-    }
-  }
-  printf(">>\n");
 #endif
 
   if (!IsSameOrAncestor(window, mFocusedWindow))
     return NS_OK;
 
   // at this point, we know that the window being hidden is either the focused
   // window, or an ancestor of the focused window. Either way, the focus is no
   // longer valid, so it needs to be updated.
@@ -1156,24 +1173,16 @@ nsFocusManager::SetFocusInner(nsIContent
   if (dsti) {
     nsCOMPtr<nsIDocShellTreeItem> root;
     dsti->GetRootTreeItem(getter_AddRefs(root));
     newRootWindow = do_GetInterface(root);
 
     isElementInActiveWindow = (mActiveWindow && newRootWindow == mActiveWindow);
   }
 
-#ifdef DEBUG_FOCUS
-  PRINTTAGF("Shift Focus: %s", contentToFocus);
-  printf(" Flags: %x Current Window: %p New Window: %p Current Element: %p",
-         aFlags, mFocusedWindow.get(), newWindow.get(), mFocusedContent.get());
-  printf(" In Active Window: %d In Focused Window: %d\n",
-         isElementInActiveWindow, isElementInFocusedWindow);
-#endif
-
   // Exit full-screen if we're focusing a windowed plugin on a non-MacOSX
   // system. We don't control event dispatch to windowed plugins on non-MacOSX,
   // so we can't display the "Press ESC to leave full-screen mode" warning on
   // key input if a windowed plugin is focused, so just exit full-screen
   // to guard against phishing.
 #ifndef XP_MACOSX
   if (contentToFocus &&
       nsContentUtils::GetRootDocument(contentToFocus->OwnerDoc())->IsFullScreenDoc() &&
@@ -1213,16 +1222,22 @@ nsFocusManager::SetFocusInner(nsIContent
     if (!sendFocusEvent && mMouseDownEventHandlingDocument) {
       // However, while mouse down event is handling, the handling document's
       // script should be able to steal focus.
       domNode = do_QueryInterface(mMouseDownEventHandlingDocument);
       sendFocusEvent = nsContentUtils::CanCallerAccess(domNode);
     }
   }
 
+  LOGCONTENT("Shift Focus: %s", contentToFocus.get());
+  LOGFOCUS((" Flags: %x Current Window: %p New Window: %p Current Element: %p",
+           aFlags, mFocusedWindow.get(), newWindow.get(), mFocusedContent.get()));
+  LOGFOCUS((" In Active Window: %d In Focused Window: %d SendFocus: %d",
+           isElementInActiveWindow, isElementInFocusedWindow, sendFocusEvent));
+
   if (sendFocusEvent) {
     // return if blurring fails or the focus changes during the blur
     if (mFocusedWindow) {
       // if the focus is being moved to another element in the same document,
       // or to a descendant, pass the existing window to Blur so that the
       // current node in the existing window is cleared. If moving to a
       // window elsewhere, we want to maintain the current node in the
       // window but still blur it.
@@ -1424,38 +1439,44 @@ nsFocusManager::CheckIfFocusable(nsICont
   // this is a special case for some XUL elements where an anonymous child is
   // actually focusable and not the element itself.
   nsIContent* redirectedFocus = GetRedirectedFocus(aContent);
   if (redirectedFocus)
     return CheckIfFocusable(redirectedFocus, aFlags);
 
   nsCOMPtr<nsIDocument> doc = aContent->GetCurrentDoc();
   // can't focus elements that are not in documents
-  if (!doc)
+  if (!doc) {
+    LOGCONTENT("Cannot focus %s because content not in document", aContent)
     return nullptr;
+  }
 
   // Make sure that our frames are up to date
   doc->FlushPendingNotifications(Flush_Layout);
 
   nsIPresShell *shell = doc->GetShell();
   if (!shell)
     return nullptr;
 
   // the root content can always be focused
   if (aContent == doc->GetRootElement())
     return aContent;
 
   // cannot focus content in print preview mode. Only the root can be focused.
   nsPresContext* presContext = shell->GetPresContext();
-  if (presContext && presContext->Type() == nsPresContext::eContext_PrintPreview)
+  if (presContext && presContext->Type() == nsPresContext::eContext_PrintPreview) {
+    LOGCONTENT("Cannot focus %s while in print preview", aContent)
     return nullptr;
+  }
 
   nsIFrame* frame = aContent->GetPrimaryFrame();
-  if (!frame)
+  if (!frame) {
+    LOGCONTENT("Cannot focus %s as it has no frame", aContent)
     return nullptr;
+  }
 
   if (aContent->Tag() == nsGkAtoms::area && aContent->IsHTML()) {
     // HTML areas do not have their own frame, and the img frame we get from
     // GetPrimaryFrame() is not relevant as to whether it is focusable or
     // not, so we have to do all the relevant checks manually for them.
     return frame->IsVisibleConsideringAncestors() &&
            aContent->IsFocusable() ? aContent : nullptr;
   }
@@ -1476,16 +1497,18 @@ nsFocusManager::CheckIfFocusable(nsICont
 }
 
 bool
 nsFocusManager::Blur(nsPIDOMWindow* aWindowToClear,
                      nsPIDOMWindow* aAncestorWindowToFocus,
                      bool aIsLeavingDocument,
                      bool aAdjustWidgets)
 {
+  LOGFOCUS(("<<Blur begin>>"));
+
   // hold a reference to the focused content, which may be null
   nsCOMPtr<nsIContent> content = mFocusedContent;
   if (content) {
     if (!content->IsInDoc()) {
       mFocusedContent = nullptr;
       return true;
     }
     if (content == mFirstBlurEvent)
@@ -1531,19 +1554,17 @@ nsFocusManager::Blur(nsPIDOMWindow* aWin
 
   // now adjust the actual focus, by clearing the fields in the focus manager
   // and in the window.
   mFocusedContent = nullptr;
   bool shouldShowFocusRing = window->ShouldShowFocusRing();
   if (aWindowToClear)
     aWindowToClear->SetFocusedNode(nullptr);
 
-#ifdef DEBUG_FOCUS
-  PRINTTAGF("**Element %s has been blurred\n", content);
-#endif
+  LOGCONTENT("Element %s has been blurred", content.get());
 
   // Don't fire blur event on the root content which isn't editable.
   bool sendBlurEvent =
     content && content->IsInDoc() && !IsNonFocusableRoot(content);
   if (content) {
     if (sendBlurEvent) {
       NotifyFocusStateChange(content, shouldShowFocusRing, false);
     }
@@ -1565,19 +1586,17 @@ nsFocusManager::Blur(nsPIDOMWindow* aWin
           if (widget)
             widget->SetFocus(false);
         }
       }
 
       // if the object being blurred is a remote browser, deactivate remote content
       if (TabParent* remote = TabParent::GetFrom(content)) {
         remote->Deactivate();
-  #ifdef DEBUG_FOCUS
-      printf("*Remote browser deactivated\n");
-  #endif
+        LOGFOCUS(("Remote browser deactivated"));
       }
     }
   }
 
   bool result = true;
   if (sendBlurEvent) {
     // if there is an active window, update commands. If there isn't an active
     // window, then this was a blur caused by the active window being lowered,
@@ -1614,17 +1633,17 @@ nsFocusManager::Blur(nsPIDOMWindow* aWin
       aAncestorWindowToFocus->SetFocusedNode(nullptr, 0, true);
 
     mFocusedWindow = nullptr;
     mFocusedContent = nullptr;
 
     // pass 1 for the focus method when calling SendFocusOrBlurEvent just so
     // that the check is made for suppressed documents. Check to ensure that
     // the document isn't null in case someone closed it during the blur above
-    nsCOMPtr<nsIDocument> doc = do_QueryInterface(window->GetExtantDocument());
+    nsIDocument* doc = window->GetExtantDoc();
     if (doc)
       SendFocusOrBlurEvent(NS_BLUR_CONTENT, presShell, doc, doc, 1, false);
     if (mFocusedWindow == nullptr)
       SendFocusOrBlurEvent(NS_BLUR_CONTENT, presShell, doc, window, 1, false);
 
     // check if a different window was focused
     result = (mFocusedWindow == nullptr && mActiveWindow);
   }
@@ -1647,16 +1666,18 @@ void
 nsFocusManager::Focus(nsPIDOMWindow* aWindow,
                       nsIContent* aContent,
                       PRUint32 aFlags,
                       bool aIsNewDocument,
                       bool aFocusChanged,
                       bool aWindowRaised,
                       bool aAdjustWidgets)
 {
+  LOGFOCUS(("<<Focus begin>>"));
+
   if (!aWindow)
     return;
 
   if (aContent && (aContent == mFirstFocusEvent || aContent == mFirstBlurEvent))
     return;
 
   // Keep a reference to the presShell since dispatching the DOM event may
   // cause the document to be destroyed.
@@ -1687,23 +1708,27 @@ nsFocusManager::Focus(nsPIDOMWindow* aWi
   }
 
   bool clearFirstFocusEvent = false;
   if (!mFirstFocusEvent) {
     mFirstFocusEvent = aContent;
     clearFirstFocusEvent = true;
   }
 
-#ifdef DEBUG_FOCUS
-  PRINTTAGF("**Element %s has been focused", aContent);
-  nsCOMPtr<nsIDocument> docm = do_QueryInterface(aWindow->GetExtantDocument());
-  if (docm)
-    PRINTTAGF(" from %s", docm->GetRootElement());
-  printf(" [Newdoc: %d FocusChanged: %d Raised: %d Flags: %x]\n",
-         aIsNewDocument, aFocusChanged, aWindowRaised, aFlags);
+#ifdef PR_LOGGING
+  LOGCONTENT("Element %s has been focused", aContent);
+
+  if (PR_LOG_TEST(gFocusLog, PR_LOG_DEBUG)) {
+    nsIDocument* docm = aWindow->GetExtantDoc();
+    if (docm) {
+      LOGCONTENT(" from %s", docm->GetRootElement());
+    }
+    LOGFOCUS((" [Newdoc: %d FocusChanged: %d Raised: %d Flags: %x]",
+             aIsNewDocument, aFocusChanged, aWindowRaised, aFlags));
+  }
 #endif
 
   if (aIsNewDocument) {
     // if this is a new document, update the parent chain of frames so that
     // focus can be traversed from the top level down to the newly focused
     // window.
     AdjustWindowFocus(aWindow, false);
 
@@ -1736,17 +1761,17 @@ nsFocusManager::Focus(nsPIDOMWindow* aWi
       if (widget)
         widget->SetFocus(false);
     }
   }
 
   // if switching to a new document, first fire the focus event on the
   // document and then the window.
   if (aIsNewDocument) {
-    nsCOMPtr<nsIDocument> doc = do_QueryInterface(aWindow->GetExtantDocument());
+    nsIDocument* doc = aWindow->GetExtantDoc();
     if (doc)
       SendFocusOrBlurEvent(NS_FOCUS_CONTENT, presShell, doc,
                            doc, aFlags & FOCUSMETHOD_MASK, aWindowRaised);
     if (mFocusedWindow == aWindow && mFocusedContent == nullptr)
       SendFocusOrBlurEvent(NS_FOCUS_CONTENT, presShell, doc,
                            aWindow, aFlags & FOCUSMETHOD_MASK, aWindowRaised);
   }
 
@@ -1776,19 +1801,17 @@ nsFocusManager::Focus(nsPIDOMWindow* aWi
       // aIsNewDocument.
       if (presShell->GetDocument() == aContent->GetDocument()) {
         if (aAdjustWidgets && objectFrameWidget && !sTestMode)
           objectFrameWidget->SetFocus(false);
 
         // if the object being focused is a remote browser, activate remote content
         if (TabParent* remote = TabParent::GetFrom(aContent)) {
           remote->Activate();
-#ifdef DEBUG_FOCUS
-          printf("*Remote browser activated\n");
-#endif
+          LOGFOCUS(("Remote browser activated"));
         }
       }
 
       nsIMEStateManager::OnChangeFocus(presContext, aContent,
                                        GetFocusMoveActionCause(aFlags));
 
       // as long as this focus wasn't because a window was raised, update the
       // commands
@@ -2001,19 +2024,17 @@ nsFocusManager::RaiseWindow(nsPIDOMWindo
 #endif
 }
 
 void
 nsFocusManager::UpdateCaret(bool aMoveCaretToFocus,
                             bool aUpdateVisibility,
                             nsIContent* aContent)
 {
-#ifdef DEBUG_FOCUS
-  printf("Update Caret: %d %d\n", aMoveCaretToFocus, aUpdateVisibility);
-#endif
+  LOGFOCUS(("Update Caret: %d %d", aMoveCaretToFocus, aUpdateVisibility));
 
   if (!mFocusedWindow)
     return;
 
   // this is called when a document is focused or when the caretbrowsing
   // preference is changed
   nsCOMPtr<nsIDocShell> focusedDocShell = mFocusedWindow->GetDocShell();
   nsCOMPtr<nsIDocShellTreeItem> dsti = do_QueryInterface(focusedDocShell);
@@ -2333,17 +2354,17 @@ nsFocusManager::DetermineElementToMoveFo
       startContent = aWindow->GetFocusedNode();
     }
   }
 
   nsCOMPtr<nsIDocument> doc;
   if (startContent)
     doc = startContent->GetCurrentDoc();
   else
-    doc = do_QueryInterface(aWindow->GetExtantDocument());
+    doc = aWindow->GetExtantDoc();
   if (!doc)
     return NS_OK;
 
   LookAndFeel::GetInt(LookAndFeel::eIntID_TabFocusModel,
                       &nsIContent::sTabFocusModel);
 
   if (aType == MOVEFOCUS_ROOT) {
     NS_IF_ADDREF(*aNextContent = GetRootForFocus(aWindow, doc, false, false));
@@ -2504,36 +2525,33 @@ nsFocusManager::DetermineElementToMoveFo
   // be the same as the start content -- when nothing is focused and tabbing
   // forward. Without skipOriginalContentCheck set to true, we'd end up
   // returning right away and focusing nothing. Luckily, GetNextTabbableContent
   // will never wrap around on its own, and can only return the original
   // content when it is called a second time or later.
   bool skipOriginalContentCheck = true;
   nsIContent* originalStartContent = startContent;
 
-#ifdef DEBUG_FOCUS_NAVIGATION
-  PRINTTAGF("Focus Navigation Start Content %s\n", startContent);
-  printf("[Tabindex: %d Ignore: %d]", tabIndex, ignoreTabIndex);
-#endif
+  LOGCONTENTNAVIGATION("Focus Navigation Start Content %s", startContent.get());
+  LOGFOCUSNAVIGATION(("  Tabindex: %d Ignore: %d", tabIndex, ignoreTabIndex));
 
   while (doc) {
     if (doNavigation) {
       nsCOMPtr<nsIContent> nextFocus;
       nsresult rv = GetNextTabbableContent(presShell, rootContent,
                                            skipOriginalContentCheck ? nullptr : originalStartContent,
                                            startContent, forward,
                                            tabIndex, ignoreTabIndex,
                                            getter_AddRefs(nextFocus));
       NS_ENSURE_SUCCESS(rv, rv);
 
       // found a content node to focus.
       if (nextFocus) {
-#ifdef DEBUG_FOCUS_NAVIGATION
-        PRINTTAGF("Next Content: %s\n", nextFocus);
-#endif
+        LOGCONTENTNAVIGATION("Next Content: %s", nextFocus.get());
+
         // as long as the found node was not the same as the starting node,
         // set it as the return value.
         if (nextFocus != originalStartContent)
           NS_ADDREF(*aNextContent = nextFocus);
         return NS_OK;
       }
 
       if (popupFrame) {
@@ -2573,17 +2591,17 @@ nsFocusManager::DetermineElementToMoveFo
       NS_ENSURE_TRUE(piWindow, NS_ERROR_FAILURE);
 
       // Next, retrieve the parent docshell, document and presshell.
       docShell = do_QueryInterface(docShellParent);
       NS_ENSURE_TRUE(docShell, NS_ERROR_FAILURE);
 
       nsCOMPtr<nsPIDOMWindow> piParentWindow = do_GetInterface(docShellParent);
       NS_ENSURE_TRUE(piParentWindow, NS_ERROR_FAILURE);
-      doc = do_QueryInterface(piParentWindow->GetExtantDocument());
+      doc = piParentWindow->GetExtantDoc();
       NS_ENSURE_TRUE(doc, NS_ERROR_FAILURE);
 
       presShell = doc->GetShell();
 
       rootContent = doc->GetRootElement();
       startContent = do_QueryInterface(piWindow->GetFrameElementInternal());
       if (startContent) {
         nsIFrame* frame = startContent->GetPrimaryFrame();
@@ -2653,20 +2671,18 @@ nsFocusManager::GetNextTabbableContent(n
                                        nsIContent** aResultContent)
 {
   *aResultContent = nullptr;
 
   nsCOMPtr<nsIContent> startContent = aStartContent;
   if (!startContent)
     return NS_OK;
 
-#ifdef DEBUG_FOCUS_NAVIGATION
-  PRINTTAGF("GetNextTabbable: %s", aStartContent);
-  printf(" tabindex: %d\n", aCurrentTabIndex);
-#endif
+  LOGCONTENTNAVIGATION("GetNextTabbable: %s", aStartContent);
+  LOGFOCUSNAVIGATION(("  tabindex: %d", aCurrentTabIndex));
 
   nsPresContext* presContext = aPresShell->GetPresContext();
 
   bool getNextFrame = true;
   nsCOMPtr<nsIContent> iterStartContent = aStartContent;
   while (1) {
     nsIFrame* startFrame = iterStartContent->GetPrimaryFrame();
     // if there is no frame, look for another content node that has a frame
@@ -2725,22 +2741,18 @@ nsFocusManager::GetNextTabbableContent(n
       // The returned computed tabindex from IsFocusable() is as follows:
       //          < 0 not tabbable at all
       //          == 0 in normal tab order (last after positive tabindexed items)
       //          > 0 can be tabbed to in the order specified by this value
 
       PRInt32 tabIndex;
       frame->IsFocusable(&tabIndex, 0);
 
-#ifdef DEBUG_FOCUS_NAVIGATION
-      if (frame->GetContent()) {
-        PRINTTAGF("Next Tabbable %s:", frame->GetContent());
-        printf(" with tabindex: %d expected: %d\n", tabIndex, aCurrentTabIndex);
-      }
-#endif
+      LOGCONTENTNAVIGATION("Next Tabbable %s:", frame->GetContent());
+      LOGFOCUSNAVIGATION(("  with tabindex: %d expected: %d", tabIndex, aCurrentTabIndex));
 
       nsIContent* currentContent = frame->GetContent();
       if (tabIndex >= 0) {
         NS_ASSERTION(currentContent, "IsFocusable set a tabindex for a frame with no content");
         if (currentContent->Tag() == nsGkAtoms::img &&
             currentContent->HasAttr(kNameSpaceID_None, nsGkAtoms::usemap)) {
           // This is an image with a map. Image map areas are not traversed by
           // nsIFrameTraversal so look for the next or previous area element.
@@ -3174,24 +3186,24 @@ nsFocusManager::GetNextTabbableDocument(
         currentPopup = content->GetPrimaryFrame();
         break;
       }
       content = content->GetParent();
     }
   }
   else if (mFocusedWindow) {
     startItem = do_QueryInterface(mFocusedWindow->GetDocShell());
-    doc = do_QueryInterface(mFocusedWindow->GetExtantDocument());
+    doc = mFocusedWindow->GetExtantDoc();
   }
   else {
     nsCOMPtr<nsIWebNavigation> webnav = do_GetInterface(mActiveWindow);
     startItem = do_QueryInterface(webnav);
 
     if (mActiveWindow) {
-      doc = do_QueryInterface(mActiveWindow->GetExtantDocument());
+      doc = mActiveWindow->GetExtantDoc();
     }
   }
 
   if (!startItem)
     return nullptr;
 
   // perform a depth first search (preorder) of the docshell tree
   // looking for an HTML Frame or a chrome document
@@ -3254,17 +3266,17 @@ nsFocusManager::GetNextTabbableDocument(
       return nullptr;
 
     // Clear currentPopup for the next iteration
     currentPopup = nullptr;
 
     // If event handling is suppressed, move on to the next document. Set
     // content to null so that the popup check will be skipped on the next
     // loop iteration.
-    doc = do_QueryInterface(nextFrame->GetExtantDocument());
+    doc = nextFrame->GetExtantDoc();
     if (!doc || doc->EventHandlingSuppressed()) {
       content = nullptr;
       continue;
     }
 
     if (checkPopups) {
       // When iterating backwards, check the panels of the previous document
       // first. If a panel exists that has focusable content, focus that.