just immortalizing some debugging gunk i recently found useful. hidden completely behind ifdefs normally opaque.

xpcom/threads/nsEventQueue.cpp

@@ -29,6 +29,19 @@
 #include "nsIObserverService.h"
 #include "nsString2.h"
 
+#include "prlog.h"
+
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+/* found these logs useful in conjunction with netlibStreamEvent logging
+   from netwerk. */
+PRLogModuleInfo* gEventQueueLog = 0;
+PRUint32 gEventQueueLogCount = 0;
+PRUint32 gEventQueueLogPPCount = 0;
+static int gEventQueueLogPPLevel = 0;
+static PLEventQueue *gEventQueueLogQueue = 0;
+static PRThread *gEventQueueLogThread = 0;
+#endif
+
 // in a real system, these would be members in a header class...
 static char *gActivatedNotification = "nsIEventQueueActivated";
 static char *gDestroyedNotification = "nsIEventQueueDestroyed";
@@ -60,6 +73,11 @@ nsEventQueueImpl::nsEventQueueImpl()
 
 nsEventQueueImpl::~nsEventQueueImpl()
 {
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: Destroyed [queue=%lx]",(long)mEventQueue));
+  ++gEventQueueLogCount;
+#endif
   Unlink();
   if (mEventQueue != NULL) {
     NotifyObservers(gDestroyedNotification);
@@ -119,6 +137,12 @@ nsEventQueueImpl::StopAcceptingEvents()
   NS_ASSERTION(mElderQueue, "attempted to disable eldest queue in chain");
   mAcceptingEvents = PR_FALSE;
   CheckForDeactivation();
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: StopAccepting [queue=%lx, accept=%d, could=%d]",
+         (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+  ++gEventQueueLogCount;
+#endif
   return NS_OK;
 }
 
@@ -152,6 +176,12 @@ NS_IMETHODIMP_(PRStatus)
 nsEventQueueImpl::PostEvent(PLEvent* aEvent)
 {
   if (!mAcceptingEvents) {
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Punt posted event [queue=%lx, accept=%d, could=%d]",
+         (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+  ++gEventQueueLogCount;
+#endif
     PRStatus rv = PR_FAILURE;
     NS_ASSERTION(mElderQueue, "event dropped because event chain is dead");
     if (mElderQueue) {
@@ -161,6 +191,11 @@ nsEventQueueImpl::PostEvent(PLEvent* aEvent)
     }
     return rv;
   }
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: Posting event [queue=%lx]", (long)mEventQueue));
+  ++gEventQueueLogCount;
+#endif
   return PL_PostEvent(mEventQueue, aEvent);
 }
 
@@ -168,6 +203,12 @@ NS_IMETHODIMP
 nsEventQueueImpl::PostSynchronousEvent(PLEvent* aEvent, void** aResult)
 {
   if (!mAcceptingEvents) {
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Punt posted synchronous event [queue=%lx, accept=%d, could=%d]",
+         (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+  ++gEventQueueLogCount;
+#endif
     nsresult rv = NS_ERROR_NO_INTERFACE;
     NS_ASSERTION(mElderQueue, "event dropped because event chain is dead");
     if (mElderQueue) {
@@ -179,6 +220,11 @@ nsEventQueueImpl::PostSynchronousEvent(PLEvent* aEvent, void** aResult)
     return NS_ERROR_ABORT;
   }
 
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: Posting synchronous event [queue=%lx]", (long)mEventQueue));
+  ++gEventQueueLogCount;
+#endif
   void* result = PL_PostSynchronousEvent(mEventQueue, aEvent);
   if (aResult)
     *aResult = result;
@@ -235,11 +281,31 @@ nsEventQueueImpl::ProcessPendingEvents()
   
   NS_ASSERTION(correctThread, "attemping to process events on the wrong thread");
 
-
   if (!correctThread)
     return NS_ERROR_FAILURE;
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  ++gEventQueueLogPPLevel;
+  if ((gEventQueueLogQueue != mEventQueue || gEventQueueLogThread != PR_GetCurrentThread() ||
+       gEventQueueLogCount != gEventQueueLogPPCount) && gEventQueueLogPPLevel == 1) {
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Process pending [queue=%lx, accept=%d, could=%d]",
+           (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+    gEventQueueLogPPCount = ++gEventQueueLogCount;
+    gEventQueueLogQueue = mEventQueue;
+    gEventQueueLogThread = PR_GetCurrentThread();
+  }
+#endif
   PL_ProcessPendingEvents(mEventQueue);
   CheckForDeactivation();
+
+  if (mElderQueue) {
+    nsCOMPtr<nsIEventQueue> elder(do_QueryInterface(mElderQueue));
+    if (elder)
+      elder->ProcessPendingEvents();
+  }
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  --gEventQueueLogPPLevel;
+#endif
   return NS_OK;
 }
 
@@ -280,6 +346,12 @@ nsEventQueueImpl::HandleEvent(PLEvent* aEvent)
   if (!correctThread)
     return NS_ERROR_FAILURE;
 
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: handle event [queue=%lx, accept=%d, could=%d]",
+         (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+  ++gEventQueueLogCount;
+#endif
   PL_HandleEvent(aEvent);
   return NS_OK;
 }
@@ -292,6 +364,12 @@ nsEventQueueImpl::WaitForEvent(PLEvent** aResult)
     if (!correctThread)
       return NS_ERROR_FAILURE;
 
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+         ("EventQueue: wait for event [queue=%lx, accept=%d, could=%d]",
+         (long)mEventQueue,(int)mAcceptingEvents,(int)mCouldHaveEvents));
+  ++gEventQueueLogCount;
+#endif
     *aResult = PL_WaitForEvent(mEventQueue);
     CheckForDeactivation();
     return NS_OK;

xpcom/threads/nsEventQueueService.cpp

@@ -27,6 +27,13 @@
 #include "nsIThread.h"
 #include "nsPIEventQueueChain.h"
 
+#include "prlog.h"
+
+#if defined(PR_LOGGING)
+extern PRLogModuleInfo* gEventQueueLog;
+extern PRUint32 gEventQueueLogCount;
+#endif
+
 static NS_DEFINE_CID(kEventQueueCID, NS_EVENTQUEUE_CID);
 
 ////////////////////////////////////////////////////////////////////////////////
@@ -128,7 +135,7 @@ nsIEventQueue* EventQueueEntry::GetEventQueue(void)
   if (mQueue) {
     nsCOMPtr<nsPIEventQueueChain> ourChain(do_QueryInterface(mQueue));
     if (ourChain)
-      ourChain->GetYoungestActive(&answer);
+      ourChain->GetYoungest(&answer);
     else {
       NS_ADDREF(mQueue);
       answer = mQueue;
@@ -254,6 +261,10 @@ nsEventQueueServiceImpl::nsEventQueueServiceImpl()
   mEventQTable   = new nsHashtable(16);
   mEventQMonitor = PR_NewMonitor();
   mBaseEntry     = 0;
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+  if (!gEventQueueLog)
+    gEventQueueLog = PR_NewLogModule("nseventqueue");
+#endif
 }
 
 nsEventQueueServiceImpl::~nsEventQueueServiceImpl()
@@ -351,6 +362,14 @@ nsEventQueueServiceImpl::AddEventQueueEntry(EventQueueEntry *aEntry)
     aEntry->Link(last);
   } else
     mBaseEntry = aEntry;
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+    PLEventQueue *equeue;
+    nsCOMPtr<nsIEventQueue> iqueue = aEntry->GetEventQueue();
+    iqueue->GetPLEventQueue(&equeue);
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Service add queue entry [queue=%lx]",(long)equeue));
+    ++gEventQueueLogCount;
+#endif
 }
 
 void
@@ -361,6 +380,14 @@ nsEventQueueServiceImpl::RemoveEventQueueEntry(EventQueueEntry *aEntry)
     mBaseEntry = aEntry->Next();
   mEnumerator.Skip(aEntry);
   aEntry->Unlink();
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+    PLEventQueue *equeue;
+    nsCOMPtr<nsIEventQueue> iqueue = aEntry->GetEventQueue();
+    iqueue->GetPLEventQueue(&equeue);
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Service remove queue entry [queue=%lx]",(long)equeue));
+    ++gEventQueueLogCount;
+#endif
 }
 
 NS_IMETHODIMP
@@ -436,6 +463,13 @@ nsEventQueueServiceImpl::PushThreadEventQueue(nsIEventQueue **aNewQueue)
   if (NS_SUCCEEDED(rv)) {
     *aNewQueue = evQueueEntry->GetEventQueue();
     NS_ADDREF(evQueueEntry);
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+    PLEventQueue *equeue;
+    (*aNewQueue)->GetPLEventQueue(&equeue);
+    PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+           ("EventQueue: Service push queue [queue=%lx]",(long)equeue));
+    ++gEventQueueLogCount;
+#endif
   }
 
 done:
@@ -461,8 +495,16 @@ nsEventQueueServiceImpl::PopThreadEventQueue(nsIEventQueue *aQueue)
 
     NS_RELEASE2(evQueueEntry, refcnt);
     // If this wasn't the last reference, we must be popping.
-    if (refcnt > 0)
+    if (refcnt > 0) {
+#if defined(PR_LOGGING) && defined(DEBUG_danm)
+      PLEventQueue *equeue;
+      aQueue->GetPLEventQueue(&equeue);
+      PR_LOG(gEventQueueLog, PR_LOG_DEBUG,
+             ("EventQueue: Service pop queue [queue=%lx]",(long)equeue));
+    ++gEventQueueLogCount;
+#endif
       evQueueEntry->RemoveQueue(aQueue);
+    }
   } else {
     rv = NS_ERROR_FAILURE;
   }