Bug 1409656 - Append log of ContentCacheInParent::RequestIMEToCommitComposition() in the latest 2 sets of composition events to app notes of crash report when ContentCacheInParent::OnEventNeedingAckHandled() meets unexpected state and crash itself r=m_kato

This is a follow up patch of bug 1408086.  The previous patch starts to append
log of 2 sets of composition events to app notes of crash report when
ContentCacheInParent::OnEventNeedingAckHandled() meets unexpected state and
crash itself.  However, now, we know the unexpected state occurs when TabParent
receives eCompositionCommitRequestHandled message from its remote process.
The event comes when ContentCacheInParent::RequestIMEToCommitComposition()
returns true.  So, we need to know what occurs in the method before the crash.

This patch defines each case of RequestIMEToCommitComposition() with an enum
class, RequestIMEToCommitCompositionResult and make
RequestIMEToCommitComposition() append one of its value to the array.
Then, ContentCacheInParent discards unnecessary log of this when it discards
log of old composition events.  Finally, appends the log to the app notes of
crash report.

MozReview-Commit-ID: 9sJyl4SvUXu

--HG--
extra : rebase_source : f7e90a157d3819523d3d8932d9f8af5d94e2db1f

widget/ContentCache.cpp

@@ -1227,7 +1227,7 @@ ContentCacheInParent::OnEventNeedingAckHandled(nsIWidget* aWidget,
 
     if (NS_WARN_IF(!mPendingCompositionCount)) {
 #ifdef MOZ_CRASHREPORTER
-      nsPrintfCString info("There is no pending composition but received %s "
+      nsPrintfCString info("\nThere is no pending composition but received %s "
                            "message from the remote child\n\n",
                            ToChar(aMessage));
       AppendEventMessageLog(info);
@@ -1253,7 +1253,7 @@ ContentCacheInParent::OnEventNeedingAckHandled(nsIWidget* aWidget,
 
   if (NS_WARN_IF(!mPendingEventsNeedingAck)) {
 #ifdef MOZ_CRASHREPORTER
-    nsPrintfCString info("There is no pending events but received %s "
+    nsPrintfCString info("\nThere is no pending events but received %s "
                          "message from the remote child\n\n",
                          ToChar(aMessage));
     AppendEventMessageLog(info);
@@ -1290,6 +1290,11 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
   // composition events for cleaning up TextComposition and handle the
   // request as it's handled asynchronously.
   if (mPendingCompositionCount > 1) {
+#ifdef MOZ_CRASHREPORTER
+    mRequestIMEToCommitCompositionResults.
+      AppendElement(RequestIMEToCommitCompositionResult::
+                      eToOldCompositionReceived);
+#endif // #ifdef MOZ_CRASHREPORTER
     return false;
   }
 
@@ -1299,6 +1304,11 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
   // TextComposition.  So, this shouldn't do nothing and TextComposition
   // should handle the request as it's handled asynchronously.
   if (mIsPendingLastCommitEvent) {
+#ifdef MOZ_CRASHREPORTER
+    mRequestIMEToCommitCompositionResults.
+      AppendElement(RequestIMEToCommitCompositionResult::
+                      eToCommittedCompositionReceived);
+#endif // #ifdef MOZ_CRASHREPORTER
     return false;
   }
 
@@ -1307,6 +1317,11 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
   if (!IMEStateManager::DoesTabParentHaveIMEFocus(&mTabParent)) {
     // Use the latest composition string which may not be handled in the
     // remote process for avoiding data loss.
+#ifdef MOZ_CRASHREPORTER
+    mRequestIMEToCommitCompositionResults.
+      AppendElement(RequestIMEToCommitCompositionResult::
+                      eReceivedAfterTabParentBlur);
+#endif // #ifdef MOZ_CRASHREPORTER
     aCommittedString = mCompositionString;
     return true;
   }
@@ -1317,6 +1332,11 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
     MOZ_LOG(sContentCacheLog, LogLevel::Warning,
       ("  0x%p RequestToCommitComposition(), "
        "does nothing due to no composition", this));
+#ifdef MOZ_CRASHREPORTER
+    mRequestIMEToCommitCompositionResults.
+      AppendElement(RequestIMEToCommitCompositionResult::
+                      eReceivedButNoTextComposition);
+#endif // #ifdef MOZ_CRASHREPORTER
     return false;
   }
 
@@ -1343,6 +1363,11 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
     // normally. On the other hand, TextComposition instance in the remote
     // process won't dispatch following composition events and will be
     // destroyed by IMEStateManager::DispatchCompositionEvent().
+#ifdef MOZ_CRASHREPORTER
+    mRequestIMEToCommitCompositionResults.
+      AppendElement(RequestIMEToCommitCompositionResult::
+                      eHandledAsynchronously);
+#endif // #ifdef MOZ_CRASHREPORTER
     return false;
   }
 
@@ -1354,6 +1379,10 @@ ContentCacheInParent::RequestIMEToCommitComposition(nsIWidget* aWidget,
   // IMEStateManager::DispatchCompositionEvent() at receiving the
   // eCompositionCommit event (Note that TextComposition instance in this
   // process was already destroyed).
+#ifdef MOZ_CRASHREPORTER
+  mRequestIMEToCommitCompositionResults.
+    AppendElement(RequestIMEToCommitCompositionResult::eHandledSynchronously);
+#endif // #ifdef MOZ_CRASHREPORTER
   return true;
 }
 
@@ -1469,8 +1498,12 @@ ContentCacheInParent::RemoveUnnecessaryEventMessageLog()
     mDispatchedEventMessages.RemoveElementsAt(0, i - 1);
     break;
   }
+  uint32_t numberOfCompositionCommitRequestHandled = 0;
   foundLastCompositionStart = false;
   for (size_t i = mReceivedEventMessages.Length(); i > 1; i--) {
+    if (mReceivedEventMessages[i - 1] == eCompositionCommitRequestHandled) {
+      numberOfCompositionCommitRequestHandled++;
+    }
     if (mReceivedEventMessages[i - 1] != eCompositionStart) {
       continue;
     }
@@ -1483,6 +1516,31 @@ ContentCacheInParent::RemoveUnnecessaryEventMessageLog()
     mReceivedEventMessages.RemoveElementsAt(0, i - 1);
     break;
   }
+
+  if (!numberOfCompositionCommitRequestHandled) {
+    // If there is no eCompositionCommitRequestHandled in
+    // mReceivedEventMessages, we don't need to store log of
+    // RequestIMEToCommmitComposition().
+    mRequestIMEToCommitCompositionResults.Clear();
+  } else {
+    // We need to keep all reason of eCompositionCommitRequestHandled, which
+    // is sent when mRequestIMEToCommitComposition() returns true.
+    // So, we can discard older log than the first
+    // eCompositionCommitRequestHandled in mReceivedEventMessages.
+    for (size_t i = mRequestIMEToCommitCompositionResults.Length();
+         i > 1; i--) {
+      if (mRequestIMEToCommitCompositionResults[i - 1] ==
+            RequestIMEToCommitCompositionResult::eReceivedAfterTabParentBlur ||
+          mRequestIMEToCommitCompositionResults[i - 1] ==
+            RequestIMEToCommitCompositionResult::eHandledSynchronously) {
+        --numberOfCompositionCommitRequestHandled;
+        if (!numberOfCompositionCommitRequestHandled) {
+          mRequestIMEToCommitCompositionResults.RemoveElementsAt(0, i - 1);
+          break;
+        }
+      }
+    }
+  }
 }
 
 void
@@ -1500,6 +1558,13 @@ ContentCacheInParent::AppendEventMessageLog(nsACString& aLog) const
     aLog.Append(ToChar(message));
     aLog.AppendLiteral("\n");
   }
+  aLog.AppendLiteral("\nResult of RequestIMEToCommitComposition():\n");
+  for (RequestIMEToCommitCompositionResult result :
+         mRequestIMEToCommitCompositionResults) {
+    aLog.AppendLiteral("  ");
+    aLog.Append(ToReadableText(result));
+    aLog.AppendLiteral("\n");
+  }
   aLog.AppendLiteral("\n");
 }
 

widget/ContentCache.h

@@ -414,6 +414,42 @@ private:
   // Log of event messages to be output to crash report.
   nsTArray<EventMessage> mDispatchedEventMessages;
   nsTArray<EventMessage> mReceivedEventMessages;
+  // Log of RequestIMEToCommitComposition() in the last 2 compositions.
+  enum class RequestIMEToCommitCompositionResult : uint8_t
+  {
+    eToOldCompositionReceived,
+    eToCommittedCompositionReceived,
+    eReceivedAfterTabParentBlur,
+    eReceivedButNoTextComposition,
+    eHandledAsynchronously,
+    eHandledSynchronously,
+  };
+  const char* ToReadableText(RequestIMEToCommitCompositionResult aResult) const
+  {
+    switch (aResult) {
+      case RequestIMEToCommitCompositionResult::eToOldCompositionReceived:
+        return "Commit request is not handled because it's for "
+               "older composition";
+      case RequestIMEToCommitCompositionResult::eToCommittedCompositionReceived:
+        return "Commit request is not handled because TabParent has already "
+               "sent commit event for the composition";
+      case RequestIMEToCommitCompositionResult::eReceivedAfterTabParentBlur:
+        return "Commit request is handled with stored composition string "
+               "because TabParent has already lost focus";
+      case RequestIMEToCommitCompositionResult::eReceivedButNoTextComposition:
+        return "Commit request is not handled because there is no "
+               "TextCompsition instance";
+      case RequestIMEToCommitCompositionResult::eHandledAsynchronously:
+        return "Commit request is handled but IME doesn't commit current "
+               "composition synchronously";
+      case RequestIMEToCommitCompositionResult::eHandledSynchronously:
+        return "Commit reqeust is handled synchronously";
+      default:
+        return "Unknown reason";
+    }
+  }
+  nsTArray<RequestIMEToCommitCompositionResult>
+    mRequestIMEToCommitCompositionResults;
 #endif // #ifdef MOZ_CRASHREPORTER
 
   // mTabParent is owner of the instance.