Bug 1208289 - Log outstanding frames in GMP DrainComplete() and detect dropped ResetComplete. r=jwwang
☠☠ backed out by 8bf3fa9171a0 ☠ ☠
authorChris Pearce <cpearce@mozilla.com>
Mon, 28 Sep 2015 17:57:10 +1300
changeset 264616 efcfe0c08c24ae9148838278c5cc9e41470a2272
parent 264615 967c555a595c9dee70b058fee7e4412eb068d23f
child 264617 ee27fc2f6a1d4415e2a56b416260b77799149871
push id65695
push usercpearce@mozilla.com
push dateMon, 28 Sep 2015 04:57:21 +0000
treeherdermozilla-inbound@efcfe0c08c24 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjwwang
bugs1208289
milestone44.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 1208289 - Log outstanding frames in GMP DrainComplete() and detect dropped ResetComplete. r=jwwang * * * Bug 1208289 - Yet another bustage fix. r=bustage
dom/media/eme/EMEUtils.cpp
dom/media/gmp/GMPVideoDecoderParent.cpp
dom/media/gmp/GMPVideoDecoderParent.h
--- a/dom/media/eme/EMEUtils.cpp
+++ b/dom/media/eme/EMEUtils.cpp
@@ -2,16 +2,17 @@
 /* vim: set ts=8 sts=2 et sw=2 tw=80: */
 /* This Source Code Form is subject to the terms of the Mozilla Public
  * License, v. 2.0. If a copy of the MPL was not distributed with this file,
  * You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/EMEUtils.h"
 #include "nsServiceManagerUtils.h"
 #include "nsIConsoleService.h"
+#include "nsThreadUtils.h"
 
 namespace mozilla {
 
 PRLogModuleInfo* GetEMELog() {
   static PRLogModuleInfo* log = nullptr;
   if (!log) {
     log = PR_NewLogModule("EME");
   }
@@ -108,16 +109,23 @@ ParseKeySystem(const nsAString& aInputKe
     }
   }
   return false;
 }
 
 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());
--- a/dom/media/gmp/GMPVideoDecoderParent.cpp
+++ b/dom/media/gmp/GMPVideoDecoderParent.cpp
@@ -9,16 +9,17 @@
 #include "nsAutoRef.h"
 #include "nsThreadUtils.h"
 #include "GMPUtils.h"
 #include "GMPVideoEncodedFrameImpl.h"
 #include "GMPVideoi420FrameImpl.h"
 #include "GMPContentParent.h"
 #include "GMPMessageUtils.h"
 #include "mozilla/gmp/GMPTypes.h"
+#include "mozilla/EMEUtils.h"
 
 namespace mozilla {
 
 #ifdef LOG
 #undef LOG
 #endif
 
 extern PRLogModuleInfo* GetGMPLog();
@@ -45,16 +46,17 @@ GMPVideoDecoderParent::GMPVideoDecoderPa
   , mShuttingDown(false)
   , mActorDestroyed(false)
   , mIsAwaitingResetComplete(false)
   , mIsAwaitingDrainComplete(false)
   , mPlugin(aPlugin)
   , mCallback(nullptr)
   , mVideoHost(this)
   , mPluginId(aPlugin->GetPluginId())
+  , mFrameCount(0)
 {
   MOZ_ASSERT(mPlugin);
 }
 
 GMPVideoDecoderParent::~GMPVideoDecoderParent()
 {
 }
 
@@ -152,16 +154,17 @@ GMPVideoDecoderParent::Decode(GMPUniqueP
   inputFrameImpl->RelinquishFrameData(frameData);
 
   if (!SendDecode(frameData,
                   aMissingFrames,
                   aCodecSpecificInfo,
                   aRenderTimeMs)) {
     return NS_ERROR_FAILURE;
   }
+  mFrameCount++;
 
   // Async IPC, we don't have access to a return value.
   return NS_OK;
 }
 
 nsresult
 GMPVideoDecoderParent::Reset()
 {
@@ -175,24 +178,43 @@ GMPVideoDecoderParent::Reset()
   MOZ_ASSERT(mPlugin->GMPThread() == NS_GetCurrentThread());
 
   if (!SendReset()) {
     return NS_ERROR_FAILURE;
   }
 
   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");
     return NS_ERROR_FAILURE;
   }
 
   MOZ_ASSERT(mPlugin->GMPThread() == NS_GetCurrentThread());
 
@@ -275,18 +297,19 @@ GMPVideoDecoderParent::ActorDestroy(Acto
     mPlugin = nullptr;
   }
   mVideoHost.ActorDestroyed();
 }
 
 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;
   }
 
   if (!GMPVideoi420FrameImpl::CheckFrameData(aDecodedFrame)) {
     LOG(LogLevel::Error,
       ("GMPVideoDecoderParent[%p]::RecvDecoded() "
@@ -340,18 +363,21 @@ GMPVideoDecoderParent::RecvInputDataExha
   mCallback->InputDataExhausted();
 
   return true;
 }
 
 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;
   }
 
   if (!mIsAwaitingDrainComplete) {
     return true;
   }
   mIsAwaitingDrainComplete = false;
@@ -362,24 +388,27 @@ GMPVideoDecoderParent::RecvDrainComplete
   return true;
 }
 
 bool
 GMPVideoDecoderParent::RecvResetComplete()
 {
   LOGD(("GMPVideoDecoderParent[%p]::RecvResetComplete()", this));
 
+  CancelResetCompleteTimeout();
+
   if (!mCallback) {
     return false;
   }
 
   if (!mIsAwaitingResetComplete) {
     return true;
   }
   mIsAwaitingResetComplete = false;
+  mFrameCount = 0;
 
   // Ignore any return code. It is OK for this to fail without killing the process.
   mCallback->ResetComplete();
 
   return true;
 }
 
 bool
@@ -452,27 +481,30 @@ GMPVideoDecoderParent::Recv__delete__()
   }
 
   return true;
 }
 
 void
 GMPVideoDecoderParent::UnblockResetAndDrain()
 {
-  LOGD(("GMPVideoDecoderParent[%p]::UnblockResetAndDrain()", this));
+  LOGD(("GMPVideoDecoderParent[%p]::UnblockResetAndDrain() "
+        "awaitingResetComplete=%d awaitingDrainComplete=%d",
+       this, mIsAwaitingResetComplete, mIsAwaitingDrainComplete));
 
   if (!mCallback) {
     MOZ_ASSERT(!mIsAwaitingResetComplete);
     MOZ_ASSERT(!mIsAwaitingDrainComplete);
     return;
   }
   if (mIsAwaitingResetComplete) {
     mIsAwaitingResetComplete = false;
     mCallback->ResetComplete();
   }
   if (mIsAwaitingDrainComplete) {
     mIsAwaitingDrainComplete = false;
     mCallback->DrainComplete();
   }
+  CancelResetCompleteTimeout();
 }
 
 } // namespace gmp
 } // namespace mozilla
--- a/dom/media/gmp/GMPVideoDecoderParent.h
+++ b/dom/media/gmp/GMPVideoDecoderParent.h
@@ -9,16 +9,17 @@
 #include "mozilla/RefPtr.h"
 #include "gmp-video-decode.h"
 #include "mozilla/gmp/PGMPVideoDecoderParent.h"
 #include "GMPMessageUtils.h"
 #include "GMPSharedMemManager.h"
 #include "GMPUtils.h"
 #include "GMPVideoHost.h"
 #include "GMPVideoDecoderProxy.h"
+#include "VideoUtils.h"
 
 namespace mozilla {
 namespace gmp {
 
 class GMPContentParent;
 
 class GMPVideoDecoderParent final : public PGMPVideoDecoderParent
                                   , public GMPVideoDecoderProxy
@@ -75,24 +76,27 @@ private:
   virtual bool RecvError(const GMPErr& aError) override;
   virtual bool RecvShutdown() override;
   virtual bool RecvParentShmemForPool(Shmem&& aEncodedBuffer) override;
   virtual bool AnswerNeedShmem(const uint32_t& aFrameBufferSize,
                                Shmem* aMem) override;
   virtual bool Recv__delete__() override;
 
   void UnblockResetAndDrain();
+  void CancelResetCompleteTimeout();
 
   bool mIsOpen;
   bool mShuttingDown;
   bool mActorDestroyed;
   bool mIsAwaitingResetComplete;
   bool mIsAwaitingDrainComplete;
   nsRefPtr<GMPContentParent> mPlugin;
   GMPVideoDecoderCallbackProxy* mCallback;
   GMPVideoHostImpl mVideoHost;
   const uint32_t mPluginId;
+  int32_t mFrameCount;
+  nsRefPtr<SimpleTimer> mResetCompleteTimeout;
 };
 
 } // namespace gmp
 } // namespace mozilla
 
 #endif // GMPVideoDecoderParent_h_