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
authorMasayuki Nakano <masayuki@d-toybox.com>
Thu, 19 Oct 2017 00:13:42 +0900
changeset 387248 45675cb67459f139bbff1a7ce5abb2d26fd8e844
parent 387247 ab89803d6dcef9bc0c8bb538717f0b381a005a0e
child 387249 0ef6de3ab755b3b11962c5c9d51059ca248cedcd
push id32716
push userarchaeopteryx@coole-files.de
push dateFri, 20 Oct 2017 09:38:32 +0000
treeherdermozilla-central@d1e995c8640a [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersm_kato
bugs1409656, 1408086
milestone58.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
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
widget/ContentCache.cpp
widget/ContentCache.h
--- a/widget/ContentCache.cpp
+++ b/widget/ContentCache.cpp
@@ -1222,17 +1222,17 @@ ContentCacheInParent::OnEventNeedingAckH
 #ifdef MOZ_CRASHREPORTER
     if (mPendingCompositionCount == 1) {
       RemoveUnnecessaryEventMessageLog();
     }
 #endif // #ifdef MOZ_CRASHREPORTER
 
     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);
       CrashReporter::AppendAppNotesToCrashReport(info);
 #endif // #ifdef MOZ_CRASHREPORTER
       MOZ_CRASH("No pending composition but received unexpected commit event");
     }
 
@@ -1248,17 +1248,17 @@ ContentCacheInParent::OnEventNeedingAckH
     // process.  Note that this doesn't care too old composition's commit
     // string because in such case, we cannot return proper information
     // to IME synchornously.
     mPendingCommitLength = 0;
   }
 
   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);
     CrashReporter::AppendAppNotesToCrashReport(info);
 #endif // #ifdef MOZ_CRASHREPORTER
     MOZ_CRASH("No pending event message but received unexpected event");
   }
   if (--mPendingEventsNeedingAck) {
@@ -1285,43 +1285,63 @@ ContentCacheInParent::RequestIMEToCommit
   MOZ_ASSERT(!mCommitStringByRequest);
 
   // If there are 2 or more pending compositions, we already sent
   // eCompositionCommit(AsIs) to the remote process.  So, this request is
   // too late for IME.  The remote process should wait following
   // 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;
   }
 
   // If there is no pending composition, we may have already sent
   // eCompositionCommit(AsIs) event for the active composition.  If so, the
   // remote process will receive composition events which causes cleaning up
   // 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;
   }
 
   // If TabParent which has IME focus was already changed to different one, the
   // request shouldn't be sent to IME because it's too late.
   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;
   }
 
   RefPtr<TextComposition> composition =
     IMEStateManager::GetTextCompositionFor(aWidget);
   if (NS_WARN_IF(!composition)) {
     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;
   }
 
   mCommitStringByRequest = &aCommittedString;
 
   aWidget->NotifyIME(IMENotification(aCancel ? REQUEST_TO_CANCEL_COMPOSITION :
                                                REQUEST_TO_COMMIT_COMPOSITION));
 
@@ -1338,27 +1358,36 @@ ContentCacheInParent::RequestIMEToCommit
     // TextComposition instance will synthesize commit events and wait to
     // receive delayed composition events.  When TextComposition instances both
     // in this process and the remote process will be destroyed when delayed
     // composition events received. TextComposition instance in the parent
     // process will dispatch following composition events and be destroyed
     // 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;
   }
 
   // When the composition is committed synchronously, the commit string will be
   // returned to the remote process. Then, PuppetWidget will dispatch
   // eCompositionCommit event with the returned commit string (i.e., the value
   // is aCommittedString of this method).  Finally, TextComposition instance in
   // the remote process will be destroyed by
   // 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;
 }
 
 void
 ContentCacheInParent::MaybeNotifyIME(nsIWidget* aWidget,
                                      const IMENotification& aNotification)
 {
   if (!mPendingEventsNeedingAck) {
@@ -1464,30 +1493,59 @@ ContentCacheInParent::RemoveUnnecessaryE
       // Find previous eCompositionStart of the latest eCompositionStart.
       foundLastCompositionStart = true;
       continue;
     }
     // Remove the messages before the last 2 sets of composition events.
     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;
     }
     if (!foundLastCompositionStart) {
       // Find previous eCompositionStart of the latest eCompositionStart.
       foundLastCompositionStart = true;
       continue;
     }
     // Remove the messages before the last 2 sets of composition events.
     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
 ContentCacheInParent::AppendEventMessageLog(nsACString& aLog) const
 {
   aLog.AppendLiteral("Dispatched Event Message Log:\n");
   for (EventMessage message : mDispatchedEventMessages) {
     aLog.AppendLiteral("  ");
@@ -1495,16 +1553,23 @@ ContentCacheInParent::AppendEventMessage
     aLog.AppendLiteral("\n");
   }
   aLog.AppendLiteral("\nReceived Event Message Log:\n");
   for (EventMessage message : mReceivedEventMessages) {
     aLog.AppendLiteral("  ");
     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");
 }
 
 #endif // #ifdef MOZ_CRASHREPORTER
 
 /*****************************************************************************
  * mozilla::ContentCache::TextRectArray
  *****************************************************************************/
--- a/widget/ContentCache.h
+++ b/widget/ContentCache.h
@@ -409,16 +409,52 @@ private:
   IMENotification mPendingTextChange;
   IMENotification mPendingLayoutChange;
   IMENotification mPendingCompositionUpdate;
 
 #ifdef MOZ_CRASHREPORTER
   // 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.
   dom::TabParent& MOZ_NON_OWNING_REF mTabParent;
   // mCompositionString is composition string which were sent to the remote
   // process but not yet committed in the remote process.
   nsString mCompositionString;
   // This is not nullptr only while the instance is requesting IME to