From d565fd2492c299f9d854d37a8e57c8ac63ae58ba Mon Sep 17 00:00:00 2001 From: Chris Pearce Date: Tue, 29 Sep 2015 13:06:14 +1300 Subject: [PATCH] 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 | 23 +++++++++++++ dom/media/VideoUtils.h | 3 ++ dom/media/eme/EMEUtils.cpp | 15 --------- dom/media/eme/EMEUtils.h | 3 -- dom/media/gmp/GMPVideoDecoderParent.cpp | 43 +++++++++++++++++++++---- dom/media/gmp/GMPVideoDecoderParent.h | 4 +++ 6 files changed, 67 insertions(+), 24 deletions(-) diff --git a/dom/media/VideoUtils.cpp b/dom/media/VideoUtils.cpp index 5e124360ccf5..6bada8ebef77 100644 --- a/dom/media/VideoUtils.cpp +++ b/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 @@ -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 task = + NS_NewRunnableFunction([msg]() { LogToBrowserConsole(msg); }); + NS_DispatchToMainThread(task.forget(), NS_DISPATCH_NORMAL); + return; + } + nsCOMPtr 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 diff --git a/dom/media/VideoUtils.h b/dom/media/VideoUtils.h index b94942e19e79..aa1e525887d8 100644 --- a/dom/media/VideoUtils.h +++ b/dom/media/VideoUtils.h @@ -326,6 +326,9 @@ private: nsCOMPtr mTimer; }; +void +LogToBrowserConsole(const nsAString& aMsg); + } // end namespace mozilla #endif diff --git a/dom/media/eme/EMEUtils.cpp b/dom/media/eme/EMEUtils.cpp index b6f5121d0bfe..5d0af6f71791 100644 --- a/dom/media/eme/EMEUtils.cpp +++ b/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 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, diff --git a/dom/media/eme/EMEUtils.h b/dom/media/eme/EMEUtils.h index 6c2fbe2f1ac6..a8fde65f8532 100644 --- a/dom/media/eme/EMEUtils.h +++ b/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, diff --git a/dom/media/gmp/GMPVideoDecoderParent.cpp b/dom/media/gmp/GMPVideoDecoderParent.cpp index 0209ecd4fd5d..eacc05b447eb 100644 --- a/dom/media/gmp/GMPVideoDecoderParent.cpp +++ b/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 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 self(this); + nsCOMPtr 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 diff --git a/dom/media/gmp/GMPVideoDecoderParent.h b/dom/media/gmp/GMPVideoDecoderParent.h index 1f477ed4176a..b6b6ad32561d 100644 --- a/dom/media/gmp/GMPVideoDecoderParent.h +++ b/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 mResetCompleteTimeout; }; } // namespace gmp