Bug 834138 - Intermittent states/test_doc_busy.html | Test timed out, r=tbsaunde

accessible/tests/mochitest/events.js

@@ -293,11 +293,12 @@ function eventQueue(aEventType)
   {
     // Some scenario was matched, we wait on next invoker processing.
     if (this.mNextInvokerStatus == kInvokerCanceled) {
-      this.mNextInvokerStatus = kInvokerNotScheduled;
+      this.setInvokerStatus(kInvokerNotScheduled,
+                            "scenario was matched, wait for next invoker activation");
       return;
     }
 
-    this.mNextInvokerStatus = kInvokerNotScheduled;
+    this.setInvokerStatus(kInvokerNotScheduled, "the next invoker is processed now");
 
     // Finish processing of the current invoker if any.
     var testFailed = false;
@@ -433,7 +434,7 @@ function eventQueue(aEventType)
   this.processNextInvokerInTimeout =
     function eventQueue_processNextInvokerInTimeout(aUncondProcess)
   {
-    this.mNextInvokerStatus = kInvokerPending;
+    this.setInvokerStatus(kInvokerPending, "Process next invoker in timeout");
 
     // No need to wait extra timeout when a) we know we don't need to do that
     // and b) there's no any single unexpected event.
@@ -541,15 +542,22 @@ function eventQueue(aEventType)
     }
 
     // If we don't have more events to wait then schedule next invoker.
-    if (this.hasMatchedScenario() &&
-        (this.mNextInvokerStatus == kInvokerNotScheduled)) {
-      this.processNextInvokerInTimeout();
+    if (this.hasMatchedScenario()) {
+      if (this.mNextInvokerStatus == kInvokerNotScheduled) {
+        this.processNextInvokerInTimeout();
+
+      } else if (this.mNextInvokerStatus == kInvokerCanceled) {
+        this.setInvokerStatus(kInvokerPending,
+                              "Full match. Void the cancelation of next invoker processing");
+      }
       return;
     }
 
     // If we have scheduled a next invoker then cancel in case of match.
-    if ((this.mNextInvokerStatus == kInvokerPending) && hasMatchedCheckers)
-      this.mNextInvokerStatus = kInvokerCanceled;
+    if ((this.mNextInvokerStatus == kInvokerPending) && hasMatchedCheckers) {
+      this.setInvokerStatus(kInvokerCanceled,
+                            "Cancel the scheduled invoker in case of match");
+    }
   }
 
   // Helpers
@@ -622,6 +630,17 @@ function eventQueue(aEventType)
     return true;
   }
 
+  this.isUnexpectedEventScenario =
+    function eventQueue_isUnexpectedEventsScenario(aScenario)
+  {
+    for (var idx = 0; idx < aScenario.length; idx++) {
+      if (!aScenario[idx].unexpected)
+        break;
+    }
+
+    return idx == aScenario.length;
+  }
+
   this.hasUnexpectedEventsScenario =
     function eventQueue_hasUnexpectedEventsScenario()
   {
@@ -629,23 +648,19 @@ function eventQueue(aEventType)
       return true;
 
     for (var scnIdx = 0; scnIdx < this.mScenarios.length; scnIdx++) {
-      var eventSeq = this.mScenarios[scnIdx];
-      for (var idx = 0; idx < eventSeq.length; idx++) {
-        if (!eventSeq[idx].unexpected)
-          break;
-      }
-      if (idx == eventSeq.length)
+      if (this.isUnexpectedEventScenario(this.mScenarios[scnIdx]))
         return true;
     }
 
     return false;
   }
-  
+
   this.hasMatchedScenario =
     function eventQueue_hasMatchedScenario()
   {
     for (var scnIdx = 0; scnIdx < this.mScenarios.length; scnIdx++) {
-      if (!this.areExpectedEventsLeft(this.mScenarios[scnIdx]))
+      var scn = this.mScenarios[scnIdx];
+      if (!this.isUnexpectedEventScenario(scn) && !this.areExpectedEventsLeft(scn))
         return true;
     }
     return false;
@@ -775,6 +790,14 @@ function eventQueue(aEventType)
     return invoker.getID();
   }
 
+  this.setInvokerStatus = function eventQueue_setInvokerStatus(aStatus, aLogMsg)
+  {
+    this.mNextInvokerStatus = aStatus;
+
+    // Uncomment it to debug invoker processing logic.
+    //gLogger.log(eventQueue.invokerStatusToMsg(aStatus, aLogMsg));
+  }
+
   this.mDefEventType = aEventType;
 
   this.mInvokers = new Array();
@@ -872,24 +895,10 @@ eventQueue.isSameEvent = function eventQueue_isSameEvent(aChecker, aEvent)
     !(aEvent instanceof nsIAccessibleStateChangeEvent);
 }
 
-eventQueue.logEvent = function eventQueue_logEvent(aOrigEvent, aMatchedChecker,
-                                                   aScenarioIdx, aEventIdx,
-                                                   aAreExpectedEventsLeft,
-                                                   aInvokerStatus)
+eventQueue.invokerStatusToMsg =
+  function eventQueue_invokerStatusToMsg(aInvokerStatus, aMsg)
 {
-  if (!gLogger.isEnabled()) // debug stuff
-    return;
-
-  // Dump DOM event information. Skip a11y event since it is dumped by
-  // gA11yEventObserver.
-  if (aOrigEvent instanceof nsIDOMEvent) {
-    var info = "Event type: " + eventQueue.getEventTypeAsString(aOrigEvent);
-    info += ". Target: " + eventQueue.getEventTargetDescr(aOrigEvent);
-    gLogger.logToDOM(info);
-  }
-
-  var msg = "unhandled expected events: " + aAreExpectedEventsLeft +
-    ", invoker status: ";
+  var msg = "invoker status: ";
   switch (aInvokerStatus) {
     case kInvokerNotScheduled:
       msg += "not scheduled";
@@ -902,23 +911,37 @@ eventQueue.logEvent = function eventQueue_logEvent(aOrigEvent, aMatchedChecker,
       break;
   }
 
-  gLogger.logToConsole(msg);
-  gLogger.logToDOM(msg);
+  if (aMsg)
+    msg += " (" + aMsg + ")";
 
-  if (!aMatchedChecker)
-    return;
+  return msg;
+}
 
-  var msg = "EQ: ";
-  var emphText = "matched ";
+eventQueue.logEvent = function eventQueue_logEvent(aOrigEvent, aMatchedChecker,
+                                                   aScenarioIdx, aEventIdx,
+                                                   aAreExpectedEventsLeft,
+                                                   aInvokerStatus)
+{
+  // Dump DOM event information. Skip a11y event since it is dumped by
+  // gA11yEventObserver.
+  if (aOrigEvent instanceof nsIDOMEvent) {
+    var info = "Event type: " + eventQueue.getEventTypeAsString(aOrigEvent);
+    info += ". Target: " + eventQueue.getEventTargetDescr(aOrigEvent);
+    gLogger.logToDOM(info);
+  }
+
+  var infoMsg = "unhandled expected events: " + aAreExpectedEventsLeft +
+    ", "  + eventQueue.invokerStatusToMsg(aInvokerStatus);
 
   var currType = eventQueue.getEventTypeAsString(aMatchedChecker);
   var currTargetDescr = eventQueue.getEventTargetDescr(aMatchedChecker);
   var consoleMsg = "*****\nScenario " + aScenarioIdx + 
-    ", event " + aEventIdx + " matched: " + currType + "\n*****";
+    ", event " + aEventIdx + " matched: " + currType + "\n" + infoMsg + "\n*****";
   gLogger.logToConsole(consoleMsg);
 
-  msg += " event, type: " + currType + ", target: " + currTargetDescr;
-
+  var emphText = "matched ";
+  var msg = "EQ event, type: " + currType + ", target: " + currTargetDescr +
+    ", " + infoMsg;
   gLogger.logToDOM(msg, true, emphText);
 }
 

accessible/tests/mochitest/states/test_doc_busy.html

@@ -20,7 +20,7 @@
           src="../events.js"></script>
 
   <script type="application/javascript">
-    gA11yEventDumpToConsole = true; // debugging stuff
+    //gA11yEventDumpToConsole = true; // debugging stuff
 
     function loadFile()
     {