Bug 1208289 - Log outstanding frames in GMP DrainComplete() and detect dropped ResetComplete. r=jwwang, a=sylvestre
authorChris Pearce <cpearce@mozilla.com>
Tue, 29 Sep 2015 13:06:14 +1300
changeset 296204 95baa1b51926b77b839c50f4ef6daeb197c95104
parent 296203 7c2733198a536f64ff4dd698751d47a707f46107
child 296205 f7fb82b98052509b881a6c28de2755fbaba1969f
push id5245
push userraliiev@mozilla.com
push dateThu, 29 Oct 2015 11:30:51 +0000
treeherdermozilla-beta@dac831dc1bd0 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjwwang, sylvestre
bugs1208289
milestone43.0a2
Bug 1208289 - Log outstanding frames in GMP DrainComplete() and detect dropped ResetComplete. r=jwwang, a=sylvestre * * * Bug 1208289 - Yet another bustage fix. r=bustage
dom/media/VideoUtils.cpp
dom/media/VideoUtils.h
dom/media/eme/EMEUtils.cpp
dom/media/eme/EMEUtils.h
dom/media/gmp/GMPVideoDecoderParent.cpp
dom/media/gmp/GMPVideoDecoderParent.h
--- a/dom/media/VideoUtils.cpp
+++ b/dom/media/VideoUtils.cpp
@@ -13,16 +13,19 @@
 #include "TimeUnits.h"
 #include "nsMathUtils.h"
 #include "nsSize.h"
 #include "VorbisUtils.h"
 #include "ImageContainer.h"
 #include "mozilla/SharedThreadPool.h"
 #include "nsIRandomGenerator.h"
 #include "nsIServiceManager.h"
+#include "nsServiceManagerUtils.h"
+#include "nsIConsoleService.h"
+#include "nsThreadUtils.h"
 
 #include <stdint.h>
 
 namespace mozilla {
 
 using layers::PlanarYCbCrImage;
 
 static inline CheckedInt64 SaferMultDiv(int64_t aValue, uint32_t aMul, uint32_t aDiv) {
@@ -421,9 +424,29 @@ SimpleTimer::Create(nsIRunnable* aTask, 
 {
   nsRefPtr<SimpleTimer> t(new SimpleTimer());
   if (NS_FAILED(t->Init(aTask, aTimeoutMs, aTarget))) {
     return nullptr;
   }
   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
--- a/dom/media/VideoUtils.h
+++ b/dom/media/VideoUtils.h
@@ -316,11 +316,14 @@ public:
 private:
   virtual ~SimpleTimer() {}
   nsresult Init(nsIRunnable* aTask, uint32_t aTimeoutMs, nsIThread* aTarget);
 
   nsRefPtr<nsIRunnable> mTask;
   nsCOMPtr<nsITimer> mTimer;
 };
 
+void
+LogToBrowserConsole(const nsAString& aMsg);
+
 } // end namespace mozilla
 
 #endif
--- a/dom/media/eme/EMEUtils.cpp
+++ b/dom/media/eme/EMEUtils.cpp
@@ -1,17 +1,15 @@
 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
 /* 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"
 
 namespace mozilla {
 
 PRLogModuleInfo* GetEMELog() {
   static PRLogModuleInfo* log = nullptr;
   if (!log) {
     log = PR_NewLogModule("EME");
   }
@@ -106,29 +104,16 @@ ParseKeySystem(const nsAString& aInputKe
       aOutCDMVersion = minCDMVersion;
       return true;
     }
   }
   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,
                    nsAString& aOutKeySystem)
 {
   aOutKeySystem.Append(aKeySystem);
   aOutKeySystem.AppendLiteral(".");
   aOutKeySystem.Append(aCDMVersion);
 }
--- a/dom/media/eme/EMEUtils.h
+++ b/dom/media/eme/EMEUtils.h
@@ -47,18 +47,15 @@ namespace mozilla {
 // On success, aOutKeySystem contains the keySystem string stripped of the
 // min version number, and aOutMinCDMVersion contains the min version number
 // if present. If it was not present, aOutMinCDMVersion is NO_CDM_VERSION.
 bool ParseKeySystem(const nsAString& aKeySystem,
                     nsAString& aOutKeySystem,
                     int32_t& aOutMinCDMVersion);
 
 void
-LogToBrowserConsole(const nsAString& aMsg);
-
-void
 ConstructKeySystem(const nsAString& aKeySystem,
                    const nsAString& aCDMVersion,
                    nsAString& aOutKeySystem);
 
 } // namespace mozilla
 
 #endif // EME_LOG_H_
--- a/dom/media/gmp/GMPVideoDecoderParent.cpp
+++ b/dom/media/gmp/GMPVideoDecoderParent.cpp
@@ -45,16 +45,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 +153,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 +177,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 +296,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 +362,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 +387,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 +480,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_