Bug 1208289 - Log outstanding frames in GMP DrainComplete() and detect dropped ResetComplete. r=jwwang

* * *
Bug 1208289 - Yet another bustage fix. r=bustage

dom/media/VideoUtils.cpp

@@ -18,6 +18,9 @@
 #include "mozilla/SharedThreadPool.h"
 #include "nsIRandomGenerator.h"
 #include "nsIServiceManager.h"
+#include "nsServiceManagerUtils.h"
+#include "nsIConsoleService.h"
+#include "nsThreadUtils.h"
 
 #include <stdint.h>
 
@@ -443,4 +446,24 @@ SimpleTimer::Create(nsIRunnable* aTask, uint32_t aTimeoutMs, nsIThread* aTarget)
   return t.forget();
 }
 
+void
+LogToBrowserConsole(const nsAString& aMsg)
+{
+  if (!NS_IsMainThread()) {
+    nsAutoString msg(aMsg);
+    nsCOMPtr<nsIRunnable> task =
+      NS_NewRunnableFunction([msg]() { LogToBrowserConsole(msg); });
+    NS_DispatchToMainThread(task.forget(), NS_DISPATCH_NORMAL);
+    return;
+  }
+  nsCOMPtr<nsIConsoleService> console(
+    do_GetService("@mozilla.org/consoleservice;1"));
+  if (!console) {
+    NS_WARNING("Failed to log message to console.");
+    return;
+  }
+  nsAutoString msg(aMsg);
+  console->LogStringMessage(msg.get());
+}
+
 } // end namespace mozilla

dom/media/VideoUtils.h

@@ -326,6 +326,9 @@ private:
   nsCOMPtr<nsITimer> mTimer;
 };
 
+void
+LogToBrowserConsole(const nsAString& aMsg);
+
 } // end namespace mozilla
 
 #endif

dom/media/eme/EMEUtils.cpp

@@ -5,8 +5,6 @@
  * You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/EMEUtils.h"
-#include "nsServiceManagerUtils.h"
-#include "nsIConsoleService.h"
 
 namespace mozilla {
 
@@ -110,19 +108,6 @@ ParseKeySystem(const nsAString& aInputKeySystem,
   return false;
 }
 
-void
-LogToBrowserConsole(const nsAString& aMsg)
-{
-  nsCOMPtr<nsIConsoleService> console(
-    do_GetService("@mozilla.org/consoleservice;1"));
-  if (!console) {
-    NS_WARNING("Failed to log message to console.");
-    return;
-  }
-  nsAutoString msg(aMsg);
-  console->LogStringMessage(msg.get());
-}
-
 void
 ConstructKeySystem(const nsAString& aKeySystem,
                    const nsAString& aCDMVersion,

dom/media/eme/EMEUtils.h

@@ -51,9 +51,6 @@ bool ParseKeySystem(const nsAString& aKeySystem,
                     nsAString& aOutKeySystem,
                     int32_t& aOutMinCDMVersion);
 
-void
-LogToBrowserConsole(const nsAString& aMsg);
-
 void
 ConstructKeySystem(const nsAString& aKeySystem,
                    const nsAString& aCDMVersion,

dom/media/gmp/GMPVideoDecoderParent.cpp

@@ -50,6 +50,7 @@ GMPVideoDecoderParent::GMPVideoDecoderParent(GMPContentParent* aPlugin)
   , mCallback(nullptr)
   , mVideoHost(this)
   , mPluginId(aPlugin->GetPluginId())
+  , mFrameCount(0)
 {
   MOZ_ASSERT(mPlugin);
 }
@@ -157,6 +158,7 @@ GMPVideoDecoderParent::Decode(GMPUniquePtr<GMPVideoEncodedFrame> aInputFrame,
                   aRenderTimeMs)) {
     return NS_ERROR_FAILURE;
   }
+  mFrameCount++;
 
   // Async IPC, we don't have access to a return value.
   return NS_OK;
@@ -180,14 +182,33 @@ GMPVideoDecoderParent::Reset()
 
   mIsAwaitingResetComplete = true;
 
+  nsRefPtr<GMPVideoDecoderParent> self(this);
+  nsCOMPtr<nsIRunnable> task = NS_NewRunnableFunction([self]() -> void
+  {
+    LOGD(("GMPVideoDecoderParent[%p]::ResetCompleteTimeout() timed out waiting for ResetComplete", self.get()));
+    self->mResetCompleteTimeout = nullptr;
+    LogToBrowserConsole(NS_LITERAL_STRING("GMPVideoDecoderParent timed out waiting for ResetComplete()"));
+  });
+  CancelResetCompleteTimeout();
+  mResetCompleteTimeout = SimpleTimer::Create(task, 5000, mPlugin->GMPThread());
+
   // Async IPC, we don't have access to a return value.
   return NS_OK;
 }
 
+void
+GMPVideoDecoderParent::CancelResetCompleteTimeout()
+{
+  if (mResetCompleteTimeout) {
+    mResetCompleteTimeout->Cancel();
+    mResetCompleteTimeout = nullptr;
+  }
+}
+
 nsresult
 GMPVideoDecoderParent::Drain()
 {
-  LOGD(("GMPVideoDecoderParent[%p]::Drain()", this));
+  LOGD(("GMPVideoDecoderParent[%p]::Drain() frameCount=%d", this, mFrameCount));
 
   if (!mIsOpen) {
     NS_WARNING("Trying to use an dead GMP video decoder");
@@ -280,8 +301,9 @@ GMPVideoDecoderParent::ActorDestroy(ActorDestroyReason aWhy)
 bool
 GMPVideoDecoderParent::RecvDecoded(const GMPVideoi420FrameData& aDecodedFrame)
 {
-  LOGV(("GMPVideoDecoderParent[%p]::RecvDecoded() timestamp=%lld",
-        this, aDecodedFrame.mTimestamp()));
+  --mFrameCount;
+  LOGV(("GMPVideoDecoderParent[%p]::RecvDecoded() timestamp=%lld frameCount=%d",
+    this, aDecodedFrame.mTimestamp(), mFrameCount));
 
   if (!mCallback) {
     return false;
@@ -345,8 +367,11 @@ GMPVideoDecoderParent::RecvInputDataExhausted()
 bool
 GMPVideoDecoderParent::RecvDrainComplete()
 {
-  LOGD(("GMPVideoDecoderParent[%p]::RecvDrainComplete()", this));
-
+  LOGD(("GMPVideoDecoderParent[%p]::RecvDrainComplete() frameCount=%d", this, mFrameCount));
+  nsAutoString msg;
+  msg.AppendLiteral("GMPVideoDecoderParent::RecvDrainComplete() outstanding frames=");
+  msg.AppendInt(mFrameCount);
+  LogToBrowserConsole(msg);
   if (!mCallback) {
     return false;
   }
@@ -367,6 +392,8 @@ GMPVideoDecoderParent::RecvResetComplete()
 {
   LOGD(("GMPVideoDecoderParent[%p]::RecvResetComplete()", this));
 
+  CancelResetCompleteTimeout();
+
   if (!mCallback) {
     return false;
   }
@@ -375,6 +402,7 @@ GMPVideoDecoderParent::RecvResetComplete()
     return true;
   }
   mIsAwaitingResetComplete = false;
+  mFrameCount = 0;
 
   // Ignore any return code. It is OK for this to fail without killing the process.
   mCallback->ResetComplete();
@@ -457,7 +485,9 @@ GMPVideoDecoderParent::Recv__delete__()
 void
 GMPVideoDecoderParent::UnblockResetAndDrain()
 {
-  LOGD(("GMPVideoDecoderParent[%p]::UnblockResetAndDrain()", this));
+  LOGD(("GMPVideoDecoderParent[%p]::UnblockResetAndDrain() "
+        "awaitingResetComplete=%d awaitingDrainComplete=%d",
+       this, mIsAwaitingResetComplete, mIsAwaitingDrainComplete));
 
   if (!mCallback) {
     MOZ_ASSERT(!mIsAwaitingResetComplete);
@@ -472,6 +502,7 @@ GMPVideoDecoderParent::UnblockResetAndDrain()
     mIsAwaitingDrainComplete = false;
     mCallback->DrainComplete();
   }
+  CancelResetCompleteTimeout();
 }
 
 } // namespace gmp

dom/media/gmp/GMPVideoDecoderParent.h

@@ -14,6 +14,7 @@
 #include "GMPUtils.h"
 #include "GMPVideoHost.h"
 #include "GMPVideoDecoderProxy.h"
+#include "VideoUtils.h"
 
 namespace mozilla {
 namespace gmp {
@@ -80,6 +81,7 @@ private:
   virtual bool Recv__delete__() override;
 
   void UnblockResetAndDrain();
+  void CancelResetCompleteTimeout();
 
   bool mIsOpen;
   bool mShuttingDown;
@@ -90,6 +92,8 @@ private:
   GMPVideoDecoderCallbackProxy* mCallback;
   GMPVideoHostImpl mVideoHost;
   const uint32_t mPluginId;
+  int32_t mFrameCount;
+  nsRefPtr<SimpleTimer> mResetCompleteTimeout;
 };
 
 } // namespace gmp