From 51ab550327b1b650f4c39bda91c42236dfb7f1f0 Mon Sep 17 00:00:00 2001 From: Jean-Yves Avenard Date: Thu, 12 Feb 2015 18:52:13 +1100 Subject: [PATCH] Bug 1131433: Show codec/container type in MSE logs. r=cajbir Also rationalize MSE debugging logs, so they all follow the same format. --- dom/media/mediasource/ContainerParser.cpp | 64 ++++++----- dom/media/mediasource/ContainerParser.h | 4 +- dom/media/mediasource/MediaSource.cpp | 55 ++++----- dom/media/mediasource/MediaSourceDecoder.cpp | 14 +-- dom/media/mediasource/MediaSourceReader.cpp | 106 +++++++++--------- dom/media/mediasource/MediaSourceResource.h | 6 +- dom/media/mediasource/ResourceQueue.h | 28 +++-- dom/media/mediasource/SourceBuffer.cpp | 55 ++++----- dom/media/mediasource/SourceBuffer.h | 1 + dom/media/mediasource/SourceBufferDecoder.cpp | 37 +++--- dom/media/mediasource/SourceBufferList.cpp | 30 ++--- .../mediasource/SourceBufferResource.cpp | 50 +++++---- dom/media/mediasource/SourceBufferResource.h | 9 -- dom/media/mediasource/TrackBuffer.cpp | 103 ++++++++--------- 14 files changed, 288 insertions(+), 274 deletions(-) diff --git a/dom/media/mediasource/ContainerParser.cpp b/dom/media/mediasource/ContainerParser.cpp index b3f9c2c8bff..49151946556 100644 --- a/dom/media/mediasource/ContainerParser.cpp +++ b/dom/media/mediasource/ContainerParser.cpp @@ -18,29 +18,32 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_DEBUGV(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +/* Polyfill __func__ on MSVC to pass to the log. */ +#ifdef _MSC_VER +#define __func__ __FUNCTION__ +#endif + +#define STRINGIFY(x) #x +#define TOSTRING(x) STRINGIFY(x) +#define MSE_DEBUG(name, arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (TOSTRING(name) "(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) -#define MSE_DEBUGV(...) -#define MSE_API(...) #endif namespace mozilla { -ContainerParser::ContainerParser() +ContainerParser::ContainerParser(const nsACString& aType) : mHasInitData(false) + , mType(aType) { } bool ContainerParser::IsInitSegmentPresent(LargeDataBuffer* aData) { -MSE_DEBUG("ContainerParser(%p)::IsInitSegmentPresent aLength=%u [%x%x%x%x]", - this, aData->Length(), +MSE_DEBUG(ContainerParser, "aLength=%u [%x%x%x%x]", + aData->Length(), aData->Length() > 0 ? (*aData)[0] : 0, aData->Length() > 1 ? (*aData)[1] : 0, aData->Length() > 2 ? (*aData)[2] : 0, @@ -51,8 +54,8 @@ return false; bool ContainerParser::IsMediaSegmentPresent(LargeDataBuffer* aData) { - MSE_DEBUG("ContainerParser(%p)::IsMediaSegmentPresent aLength=%u [%x%x%x%x]", - this, aData->Length(), + MSE_DEBUG(ContainerParser, "aLength=%u [%x%x%x%x]", + aData->Length(), aData->Length() > 0 ? (*aData)[0] : 0, aData->Length() > 1 ? (*aData)[1] : 0, aData->Length() > 2 ? (*aData)[2] : 0, @@ -94,8 +97,10 @@ ContainerParser::InitData() class WebMContainerParser : public ContainerParser { public: - WebMContainerParser() - : mParser(0), mOffset(0) + explicit WebMContainerParser(const nsACString& aType) + : ContainerParser(aType) + , mParser(0) + , mOffset(0) {} static const unsigned NS_PER_USEC = 1000; @@ -180,11 +185,11 @@ public: } char* buffer = reinterpret_cast(mInitData->Elements()); mResource->ReadFromCache(buffer, 0, mParser.mInitEndOffset); - MSE_DEBUG("WebMContainerParser(%p)::ParseStartAndEndTimestamps: Stashed init of %u bytes.", - this, mParser.mInitEndOffset); + MSE_DEBUG(WebMContainerParser, "Stashed init of %u bytes.", + mParser.mInitEndOffset); mResource = nullptr; } else { - MSE_DEBUG("WebMContainerParser(%p)::ParseStartAndEndTimestamps: Incomplete init found."); + MSE_DEBUG(WebMContainerParser, "Incomplete init found."); } mHasInitData = true; } @@ -208,8 +213,8 @@ public: aStart = mapping[0].mTimecode / NS_PER_USEC; aEnd = (mapping[endIdx].mTimecode + frameDuration) / NS_PER_USEC; - MSE_DEBUG("WebMContainerParser(%p)::ParseStartAndEndTimestamps: [%lld, %lld] [fso=%lld, leo=%lld, l=%u endIdx=%u]", - this, aStart, aEnd, mapping[0].mSyncOffset, mapping[endIdx].mEndOffset, mapping.Length(), endIdx); + MSE_DEBUG(WebMContainerParser, "[%lld, %lld] [fso=%lld, leo=%lld, l=%u endIdx=%u]", + aStart, aEnd, mapping[0].mSyncOffset, mapping[endIdx].mEndOffset, mapping.Length(), endIdx); mapping.RemoveElementsAt(0, endIdx + 1); mOverlappedMapping.AppendElements(mapping); @@ -232,7 +237,10 @@ private: #ifdef MOZ_FMP4 class MP4ContainerParser : public ContainerParser { public: - MP4ContainerParser() :mMonitor("MP4ContainerParser Index Monitor") {} + explicit MP4ContainerParser(const nsACString& aType) + : ContainerParser(aType) + , mMonitor("MP4ContainerParser Index Monitor") + {} bool IsInitSegmentPresent(LargeDataBuffer* aData) { @@ -308,10 +316,10 @@ public: } char* buffer = reinterpret_cast(mInitData->Elements()); mResource->ReadFromCache(buffer, range.mStart, length); - MSE_DEBUG("MP4ContainerParser(%p)::ParseStartAndEndTimestamps: Stashed init of %u bytes.", - this, length); + MSE_DEBUG(MP4ContainerParser ,"Stashed init of %u bytes.", + length); } else { - MSE_DEBUG("MP4ContainerParser(%p)::ParseStartAndEndTimestamps: Incomplete init found."); + MSE_DEBUG(MP4ContainerParser, "Incomplete init found."); } mHasInitData = true; } @@ -325,8 +333,8 @@ public: } aStart = compositionRange.start; aEnd = compositionRange.end; - MSE_DEBUG("MP4ContainerParser(%p)::ParseStartAndEndTimestamps: [%lld, %lld]", - this, aStart, aEnd); + MSE_DEBUG(MP4ContainerParser, "[%lld, %lld]", + aStart, aEnd); return true; } @@ -348,15 +356,17 @@ private: ContainerParser::CreateForMIMEType(const nsACString& aType) { if (aType.LowerCaseEqualsLiteral("video/webm") || aType.LowerCaseEqualsLiteral("audio/webm")) { - return new WebMContainerParser(); + return new WebMContainerParser(aType); } #ifdef MOZ_FMP4 if (aType.LowerCaseEqualsLiteral("video/mp4") || aType.LowerCaseEqualsLiteral("audio/mp4")) { - return new MP4ContainerParser(); + return new MP4ContainerParser(aType); } #endif - return new ContainerParser(); + return new ContainerParser(aType); } +#undef MSE_DEBUG + } // namespace mozilla diff --git a/dom/media/mediasource/ContainerParser.h b/dom/media/mediasource/ContainerParser.h index 872431eb6c1..4bb16b171e0 100644 --- a/dom/media/mediasource/ContainerParser.h +++ b/dom/media/mediasource/ContainerParser.h @@ -8,6 +8,7 @@ #define MOZILLA_CONTAINERPARSER_H_ #include "nsRefPtr.h" +#include "nsString.h" namespace mozilla { @@ -16,7 +17,7 @@ class SourceBufferResource; class ContainerParser { public: - ContainerParser(); + explicit ContainerParser(const nsACString& aType); virtual ~ContainerParser() {} // Return true if aData starts with an initialization segment. @@ -57,6 +58,7 @@ protected: nsRefPtr mInitData; nsRefPtr mResource; bool mHasInitData; + const nsCString mType; }; } // namespace mozilla diff --git a/dom/media/mediasource/MediaSource.cpp b/dom/media/mediasource/MediaSource.cpp index 94087555b5c..da6422edcdc 100644 --- a/dom/media/mediasource/MediaSource.cpp +++ b/dom/media/mediasource/MediaSource.cpp @@ -55,8 +55,8 @@ PRLogModuleInfo* GetMediaSourceAPILog() return sLogModule; } -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("MediaSource(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#define MSE_API(arg, ...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, ("MediaSource(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) #define MSE_API(...) @@ -135,7 +135,7 @@ MediaSource::Constructor(const GlobalObject& aGlobal, MediaSource::~MediaSource() { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("MediaSource(%p)::~MediaSource()", this); + MSE_API(""); if (mDecoder) { mDecoder->DetachMediaSource(); } @@ -179,7 +179,7 @@ void MediaSource::SetDuration(double aDuration, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("MediaSource(%p)::SetDuration(aDuration=%f, ErrorResult)", this, aDuration); + MSE_API("SetDuration(aDuration=%f, ErrorResult)", aDuration); if (aDuration < 0 || IsNaN(aDuration)) { aRv.Throw(NS_ERROR_DOM_INVALID_ACCESS_ERR); return; @@ -196,7 +196,7 @@ void MediaSource::SetDuration(double aDuration, MSRangeRemovalAction aAction) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("MediaSource(%p)::SetDuration(aDuration=%f)", this, aDuration); + MSE_API("SetDuration(aDuration=%f)", aDuration); mDecoder->SetMediaSourceDuration(aDuration, aAction); } @@ -205,8 +205,8 @@ MediaSource::AddSourceBuffer(const nsAString& aType, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); nsresult rv = mozilla::IsTypeSupported(aType); - MSE_API("MediaSource(%p)::AddSourceBuffer(aType=%s)%s", - this, NS_ConvertUTF16toUTF8(aType).get(), + MSE_API("AddSourceBuffer(aType=%s)%s", + NS_ConvertUTF16toUTF8(aType).get(), rv == NS_OK ? "" : " [not supported]"); if (NS_FAILED(rv)) { aRv.Throw(rv); @@ -234,7 +234,7 @@ MediaSource::AddSourceBuffer(const nsAString& aType, ErrorResult& aRv) } mSourceBuffers->Append(sourceBuffer); mActiveSourceBuffers->Append(sourceBuffer); - MSE_DEBUG("MediaSource(%p)::AddSourceBuffer() sourceBuffer=%p", this, sourceBuffer.get()); + MSE_DEBUG("sourceBuffer=%p", sourceBuffer.get()); return sourceBuffer.forget(); } @@ -243,7 +243,7 @@ MediaSource::RemoveSourceBuffer(SourceBuffer& aSourceBuffer, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); SourceBuffer* sourceBuffer = &aSourceBuffer; - MSE_API("MediaSource(%p)::RemoveSourceBuffer(aSourceBuffer=%p)", this, sourceBuffer); + MSE_API("RemoveSourceBuffer(aSourceBuffer=%p)", sourceBuffer); if (!mSourceBuffers->Contains(sourceBuffer)) { aRv.Throw(NS_ERROR_DOM_NOT_FOUND_ERR); return; @@ -271,8 +271,8 @@ void MediaSource::EndOfStream(const Optional& aError, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("MediaSource(%p)::EndOfStream(aError=%d)", - this, aError.WasPassed() ? uint32_t(aError.Value()) : 0); + MSE_API("EndOfStream(aError=%d)", + aError.WasPassed() ? uint32_t(aError.Value()) : 0); if (mReadyState != MediaSourceReadyState::Open || mSourceBuffers->AnyUpdating()) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); @@ -313,8 +313,10 @@ MediaSource::IsTypeSupported(const GlobalObject&, const nsAString& aType) { MOZ_ASSERT(NS_IsMainThread()); nsresult rv = mozilla::IsTypeSupported(aType); - MSE_API("MediaSource::IsTypeSupported(aType=%s)%s", - NS_ConvertUTF16toUTF8(aType).get(), rv == NS_OK ? "" : " [not supported]"); +#define this nullptr + MSE_API("IsTypeSupported(aType=%s)%s ", + NS_ConvertUTF16toUTF8(aType).get(), rv == NS_OK ? "OK" : "[not supported]"); +#undef this // don't ever remove this line ! return NS_SUCCEEDED(rv); } @@ -364,7 +366,7 @@ bool MediaSource::Attach(MediaSourceDecoder* aDecoder) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("MediaSource(%p)::Attach(aDecoder=%p) owner=%p", this, aDecoder, aDecoder->GetOwner()); + MSE_DEBUG("Attach(aDecoder=%p) owner=%p", aDecoder, aDecoder->GetOwner()); MOZ_ASSERT(aDecoder); MOZ_ASSERT(aDecoder->GetOwner()); if (mReadyState != MediaSourceReadyState::Closed) { @@ -383,8 +385,8 @@ void MediaSource::Detach() { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("MediaSource(%p)::Detach() mDecoder=%p owner=%p", - this, mDecoder.get(), mDecoder ? mDecoder->GetOwner() : nullptr); + MSE_DEBUG("mDecoder=%p owner=%p", + mDecoder.get(), mDecoder ? mDecoder->GetOwner() : nullptr); if (!mDecoder) { MOZ_ASSERT(mReadyState == MediaSourceReadyState::Closed); MOZ_ASSERT(mActiveSourceBuffers->IsEmpty() && mSourceBuffers->IsEmpty()); @@ -419,8 +421,8 @@ MediaSource::MediaSource(nsPIDOMWindow* aWindow) mPrincipal = sop->GetPrincipal(); } - MSE_API("MediaSource(%p)::MediaSource(aWindow=%p) mSourceBuffers=%p mActiveSourceBuffers=%p", - this, aWindow, mSourceBuffers.get(), mActiveSourceBuffers.get()); + MSE_API("MediaSource(aWindow=%p) mSourceBuffers=%p mActiveSourceBuffers=%p", + aWindow, mSourceBuffers.get(), mActiveSourceBuffers.get()); } void @@ -428,7 +430,7 @@ MediaSource::SetReadyState(MediaSourceReadyState aState) { MOZ_ASSERT(NS_IsMainThread()); MOZ_ASSERT(aState != mReadyState); - MSE_DEBUG("MediaSource(%p)::SetReadyState(aState=%d) mReadyState=%d", this, aState, mReadyState); + MSE_DEBUG("SetReadyState(aState=%d) mReadyState=%d", aState, mReadyState); MediaSourceReadyState oldState = mReadyState; mReadyState = aState; @@ -460,14 +462,14 @@ void MediaSource::DispatchSimpleEvent(const char* aName) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("MediaSource(%p) Dispatch event '%s'", this, aName); + MSE_API("Dispatch event '%s'", aName); DispatchTrustedEvent(NS_ConvertUTF8toUTF16(aName)); } void MediaSource::QueueAsyncSimpleEvent(const char* aName) { - MSE_DEBUG("MediaSource(%p) Queuing event '%s'", this, aName); + MSE_DEBUG("Queuing event '%s'", aName); nsCOMPtr event = new AsyncEventRunner(this, aName); NS_DispatchToMainThread(event); } @@ -476,7 +478,7 @@ void MediaSource::DurationChange(double aOldDuration, double aNewDuration) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("MediaSource(%p)::DurationChange(aOldDuration=%f, aNewDuration=%f)", this, aOldDuration, aNewDuration); + MSE_DEBUG("DurationChange(aOldDuration=%f, aNewDuration=%f)", aOldDuration, aNewDuration); if (aNewDuration < aOldDuration) { // Remove all buffered data from aNewDuration. @@ -489,7 +491,7 @@ void MediaSource::NotifyEvicted(double aStart, double aEnd) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("MediaSource(%p)::NotifyEvicted(aStart=%f, aEnd=%f)", this, aStart, aEnd); + MSE_DEBUG("NotifyEvicted(aStart=%f, aEnd=%f)", aStart, aEnd); // Cycle through all SourceBuffers and tell them to evict data in // the given range. mSourceBuffers->Evict(aStart, aEnd); @@ -503,7 +505,7 @@ MediaSource::QueueInitializationEvent() return; } mFirstSourceBufferInitialized = true; - MSE_DEBUG("MediaSource(%p)::QueueInitializationEvent()", this); + MSE_DEBUG(""); nsRefPtr task = NS_NewRunnableMethod(this, &MediaSource::InitializationEvent); NS_DispatchToMainThread(task); @@ -513,7 +515,7 @@ void MediaSource::InitializationEvent() { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("MediaSource(%p)::InitializationEvent()", this); + MSE_DEBUG(""); if (mDecoder) { mDecoder->PrepareReaderInitialization(); } @@ -562,6 +564,9 @@ NS_INTERFACE_MAP_BEGIN_CYCLE_COLLECTION_INHERITED(MediaSource) NS_INTERFACE_MAP_ENTRY(mozilla::dom::MediaSource) NS_INTERFACE_MAP_END_INHERITING(DOMEventTargetHelper) +#undef MSE_DEBUG +#undef MSE_API + } // namespace dom } // namespace mozilla diff --git a/dom/media/mediasource/MediaSourceDecoder.cpp b/dom/media/mediasource/MediaSourceDecoder.cpp index 86caa730645..959c106638f 100644 --- a/dom/media/mediasource/MediaSourceDecoder.cpp +++ b/dom/media/mediasource/MediaSourceDecoder.cpp @@ -17,15 +17,12 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_DEBUGV(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("MediaSourceDecoder(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#define MSE_DEBUGV(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG + 1, ("MediaSourceDecoder(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) #define MSE_DEBUGV(...) -#define MSE_API(...) #endif namespace mozilla { @@ -88,14 +85,14 @@ MediaSourceDecoder::GetSeekable(dom::TimeRanges* aSeekable) } else { aSeekable->Add(0, duration); } - MSE_DEBUG("MediaSourceDecoder(%p)::GetSeekable ranges=%s", this, DumpTimeRanges(aSeekable).get()); + MSE_DEBUG("ranges=%s", DumpTimeRanges(aSeekable).get()); return NS_OK; } void MediaSourceDecoder::Shutdown() { - MSE_DEBUG("MediaSourceDecoder(%p)::Shutdown", this); + MSE_DEBUG("Shutdown"); // Detach first so that TrackBuffers are unused on the main thread when // shut down on the decode task queue. if (mMediaSource) { @@ -323,4 +320,7 @@ MediaSourceDecoder::GetDuration() return mMediaSourceDuration; } +#undef MSE_DEBUG +#undef MSE_DEBUGV + } // namespace mozilla diff --git a/dom/media/mediasource/MediaSourceReader.cpp b/dom/media/mediasource/MediaSourceReader.cpp index 0bfd74b6806..dec78d527db 100644 --- a/dom/media/mediasource/MediaSourceReader.cpp +++ b/dom/media/mediasource/MediaSourceReader.cpp @@ -22,16 +22,11 @@ #endif #ifdef PR_LOGGING -extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); - -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_DEBUGV(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("MediaSourceReader(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#define MSE_DEBUGV(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG + 1, ("MediaSourceReader(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) #define MSE_DEBUGV(...) -#define MSE_API(...) #endif // When a stream hits EOS it needs to decide what other stream to switch to. Due @@ -69,8 +64,7 @@ void MediaSourceReader::PrepareInitialization() { ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor()); - MSE_DEBUG("MediaSourceReader(%p)::PrepareInitialization trackBuffers=%u", - this, mTrackBuffers.Length()); + MSE_DEBUG("trackBuffers=%u", mTrackBuffers.Length()); mEssentialTrackBuffers.AppendElements(mTrackBuffers); mHasEssentialTrackBuffers = true; mDecoder->NotifyWaitingForResourcesStatusChanged(); @@ -94,7 +88,7 @@ size_t MediaSourceReader::SizeOfVideoQueueInFrames() { if (!GetVideoReader()) { - MSE_DEBUG("MediaSourceReader(%p)::SizeOfVideoQueue called with no video reader", this); + MSE_DEBUG("called with no video reader"); return 0; } return GetVideoReader()->SizeOfVideoQueueInFrames(); @@ -104,7 +98,7 @@ size_t MediaSourceReader::SizeOfAudioQueueInFrames() { if (!GetAudioReader()) { - MSE_DEBUG("MediaSourceReader(%p)::SizeOfAudioQueue called with no audio reader", this); + MSE_DEBUG("called with no audio reader"); return 0; } return GetAudioReader()->SizeOfAudioQueueInFrames(); @@ -114,14 +108,14 @@ nsRefPtr MediaSourceReader::RequestAudioData() { nsRefPtr p = mAudioPromise.Ensure(__func__); - MSE_DEBUGV("MediaSourceReader(%p)::RequestAudioData", this); + MSE_DEBUGV(""); if (!GetAudioReader()) { - MSE_DEBUG("MediaSourceReader(%p)::RequestAudioData called with no audio reader", this); + MSE_DEBUG("called with no audio reader"); mAudioPromise.Reject(DECODE_ERROR, __func__); return p; } if (IsSeeking()) { - MSE_DEBUG("MediaSourceReader(%p)::RequestAudioData called mid-seek. Rejecting.", this); + MSE_DEBUG("called mid-seek. Rejecting."); mAudioPromise.Reject(CANCELED, __func__); return p; } @@ -167,12 +161,12 @@ MediaSourceReader::OnAudioDecoded(AudioData* aSample) mAudioDiscontinuity = true; } - MSE_DEBUGV("MediaSourceReader(%p)::OnAudioDecoded [mTime=%lld mDuration=%lld mDiscontinuity=%d]", - this, ourTime, aSample->mDuration, aSample->mDiscontinuity); + MSE_DEBUGV("[mTime=%lld mDuration=%lld mDiscontinuity=%d]", + ourTime, aSample->mDuration, aSample->mDiscontinuity); if (mDropAudioBeforeThreshold) { if (ourTime < mTimeThreshold) { - MSE_DEBUG("MediaSourceReader(%p)::OnAudioDecoded mTime=%lld < mTimeThreshold=%lld", - this, ourTime, mTimeThreshold); + MSE_DEBUG("mTime=%lld < mTimeThreshold=%lld", + ourTime, mTimeThreshold); mAudioRequest.Begin(GetAudioReader()->RequestAudioData() ->RefableThen(GetTaskQueue(), __func__, this, &MediaSourceReader::OnAudioDecoded, @@ -228,7 +222,7 @@ MediaSourceReader::OnAudioNotDecoded(NotDecodedReason aReason) MOZ_DIAGNOSTIC_ASSERT(!IsSeeking()); mAudioRequest.Complete(); - MSE_DEBUG("MediaSourceReader(%p)::OnAudioNotDecoded aReason=%u IsEnded: %d", this, aReason, IsEnded()); + MSE_DEBUG("aReason=%u IsEnded: %d", aReason, IsEnded()); if (aReason == DECODE_ERROR || aReason == CANCELED) { mAudioPromise.Reject(aReason, __func__); return; @@ -257,10 +251,10 @@ nsRefPtr MediaSourceReader::RequestVideoData(bool aSkipToNextKeyframe, int64_t aTimeThreshold) { nsRefPtr p = mVideoPromise.Ensure(__func__); - MSE_DEBUGV("MediaSourceReader(%p)::RequestVideoData(%d, %lld)", - this, aSkipToNextKeyframe, aTimeThreshold); + MSE_DEBUGV("RequestVideoData(%d, %lld)", + aSkipToNextKeyframe, aTimeThreshold); if (!GetVideoReader()) { - MSE_DEBUG("MediaSourceReader(%p)::RequestVideoData called with no video reader", this); + MSE_DEBUG("called with no video reader"); mVideoPromise.Reject(DECODE_ERROR, __func__); return p; } @@ -270,7 +264,7 @@ MediaSourceReader::RequestVideoData(bool aSkipToNextKeyframe, int64_t aTimeThres mDropVideoBeforeThreshold = true; } if (IsSeeking()) { - MSE_DEBUG("MediaSourceReader(%p)::RequestVideoData called mid-seek. Rejecting.", this); + MSE_DEBUG("called mid-seek. Rejecting."); mVideoPromise.Reject(CANCELED, __func__); return p; } @@ -319,12 +313,12 @@ MediaSourceReader::OnVideoDecoded(VideoData* aSample) mVideoDiscontinuity = true; } - MSE_DEBUGV("MediaSourceReader(%p)::OnVideoDecoded [mTime=%lld mDuration=%lld mDiscontinuity=%d]", - this, ourTime, aSample->mDuration, aSample->mDiscontinuity); + MSE_DEBUGV("[mTime=%lld mDuration=%lld mDiscontinuity=%d]", + ourTime, aSample->mDuration, aSample->mDiscontinuity); if (mDropVideoBeforeThreshold) { if (ourTime < mTimeThreshold) { - MSE_DEBUG("MediaSourceReader(%p)::OnVideoDecoded mTime=%lld < mTimeThreshold=%lld", - this, ourTime, mTimeThreshold); + MSE_DEBUG("mTime=%lld < mTimeThreshold=%lld", + ourTime, mTimeThreshold); DoVideoRequest(); return; } @@ -353,7 +347,7 @@ MediaSourceReader::OnVideoNotDecoded(NotDecodedReason aReason) MOZ_DIAGNOSTIC_ASSERT(!IsSeeking()); mVideoRequest.Complete(); - MSE_DEBUG("MediaSourceReader(%p)::OnVideoNotDecoded aReason=%u IsEnded: %d", this, aReason, IsEnded()); + MSE_DEBUG("aReason=%u IsEnded: %d", aReason, IsEnded()); if (aReason == DECODE_ERROR || aReason == CANCELED) { mVideoPromise.Reject(aReason, __func__); return; @@ -480,8 +474,8 @@ MediaSourceReader::SelectDecoder(int64_t aTarget, newDecoder->GetBuffered(ranges); if (ranges->Find(double(aTarget) / USECS_PER_S, double(aTolerance) / USECS_PER_S) == dom::TimeRanges::NoIndex) { - MSE_DEBUGV("MediaSourceReader(%p)::SelectDecoder(%lld) newDecoder=%p target not in ranges=%s", - this, aTarget, newDecoder.get(), DumpTimeRanges(ranges).get()); + MSE_DEBUGV("SelectDecoder(%lld) newDecoder=%p target not in ranges=%s", + aTarget, newDecoder.get(), DumpTimeRanges(ranges).get()); continue; } @@ -533,8 +527,8 @@ MediaSourceReader::SwitchAudioSource(int64_t* aTarget) *aTarget = startTime; } } - MSE_DEBUGV("MediaSourceReader(%p)::SwitchAudioSource switched decoder to %p (fuzz:%d)", - this, mAudioSourceDecoder.get(), usedFuzz); + MSE_DEBUGV("switched decoder to %p (fuzz:%d)", + mAudioSourceDecoder.get(), usedFuzz); return SOURCE_NEW; } return newDecoder ? SOURCE_EXISTING : SOURCE_ERROR; @@ -573,8 +567,8 @@ MediaSourceReader::SwitchVideoSource(int64_t* aTarget) *aTarget = startTime; } } - MSE_DEBUGV("MediaSourceReader(%p)::SwitchVideoSource switched decoder to %p (fuzz:%d)", - this, mVideoSourceDecoder.get(), usedFuzz); + MSE_DEBUGV("switched decoder to %p (fuzz:%d)", + mVideoSourceDecoder.get(), usedFuzz); return SOURCE_NEW; } return newDecoder ? SOURCE_EXISTING : SOURCE_ERROR; @@ -653,8 +647,8 @@ MediaSourceReader::CreateSubDecoder(const nsACString& aType, int64_t aTimestampO #endif reader->Init(nullptr); - MSE_DEBUG("MediaSourceReader(%p)::CreateSubDecoder subdecoder %p subreader %p", - this, decoder.get(), reader.get()); + MSE_DEBUG("subdecoder %p subreader %p", + decoder.get(), reader.get()); decoder->SetReader(reader); #ifdef MOZ_EME decoder->SetCDMProxy(mCDMProxy); @@ -666,7 +660,7 @@ void MediaSourceReader::AddTrackBuffer(TrackBuffer* aTrackBuffer) { ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor()); - MSE_DEBUG("MediaSourceReader(%p)::AddTrackBuffer %p", this, aTrackBuffer); + MSE_DEBUG("AddTrackBuffer(%p)", aTrackBuffer); mTrackBuffers.AppendElement(aTrackBuffer); } @@ -674,7 +668,7 @@ void MediaSourceReader::RemoveTrackBuffer(TrackBuffer* aTrackBuffer) { ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor()); - MSE_DEBUG("MediaSourceReader(%p)::RemoveTrackBuffer %p", this, aTrackBuffer); + MSE_DEBUG("RemoveTrackBuffer(%p)", aTrackBuffer); mTrackBuffers.RemoveElement(aTrackBuffer); if (mAudioTrack == aTrackBuffer) { mAudioTrack = nullptr; @@ -691,11 +685,11 @@ MediaSourceReader::OnTrackBufferConfigured(TrackBuffer* aTrackBuffer, const Medi MOZ_ASSERT(aTrackBuffer->IsReady()); MOZ_ASSERT(mTrackBuffers.Contains(aTrackBuffer)); if (aInfo.HasAudio() && !mAudioTrack) { - MSE_DEBUG("MediaSourceReader(%p)::OnTrackBufferConfigured %p audio", this, aTrackBuffer); + MSE_DEBUG("%p audio", aTrackBuffer); mAudioTrack = aTrackBuffer; } if (aInfo.HasVideo() && !mVideoTrack) { - MSE_DEBUG("MediaSourceReader(%p)::OnTrackBufferConfigured %p video", this, aTrackBuffer); + MSE_DEBUG("%p video", aTrackBuffer); mVideoTrack = aTrackBuffer; } mDecoder->NotifyWaitingForResourcesStatusChanged(); @@ -729,8 +723,8 @@ MediaSourceReader::NotifyTimeRangesChanged() nsRefPtr MediaSourceReader::Seek(int64_t aTime, int64_t aIgnored /* Used only for ogg which is non-MSE */) { - MSE_DEBUG("MediaSourceReader(%p)::Seek(aTime=%lld, aEnd=%lld, aCurrent=%lld)", - this, aTime); + MSE_DEBUG("Seek(aTime=%lld, aEnd=%lld, aCurrent=%lld)", + aTime); MOZ_ASSERT(mSeekPromise.IsEmpty()); nsRefPtr p = mSeekPromise.Ensure(__func__); @@ -825,7 +819,7 @@ MediaSourceReader::DoAudioSeek() ->RefableThen(GetTaskQueue(), __func__, this, &MediaSourceReader::OnAudioSeekCompleted, &MediaSourceReader::OnAudioSeekFailed)); - MSE_DEBUG("MediaSourceReader(%p)::DoAudioSeek reader=%p", this, GetAudioReader()); + MSE_DEBUG("reader=%p", GetAudioReader()); } void @@ -885,7 +879,7 @@ MediaSourceReader::DoVideoSeek() ->RefableThen(GetTaskQueue(), __func__, this, &MediaSourceReader::OnVideoSeekCompleted, &MediaSourceReader::OnVideoSeekFailed)); - MSE_DEBUG("MediaSourceReader(%p)::DoVideoSeek reader=%p", this, GetVideoReader()); + MSE_DEBUG("reader=%p", GetVideoReader()); } nsresult @@ -924,7 +918,7 @@ MediaSourceReader::GetBuffered(dom::TimeRanges* aBuffered) intersectionRanges->Intersection(sourceRanges); } - MSE_DEBUG("MediaSourceReader(%p)::GetBuffered ranges=%s", this, DumpTimeRanges(intersectionRanges).get()); + MSE_DEBUG("ranges=%s", DumpTimeRanges(intersectionRanges).get()); return NS_OK; } @@ -950,8 +944,8 @@ MediaSourceReader::MaybeNotifyHaveData() haveVideo = true; WaitPromise(MediaData::VIDEO_DATA).ResolveIfExists(MediaData::VIDEO_DATA, __func__); } - MSE_DEBUG("MediaSourceReader(%p)::MaybeNotifyHaveData haveAudio=%d, haveVideo=%d", this, - haveAudio, haveVideo); + MSE_DEBUG("isSeeking=%d haveAudio=%d, haveVideo=%d", + IsSeeking(), haveAudio, haveVideo); } nsresult @@ -959,14 +953,14 @@ MediaSourceReader::ReadMetadata(MediaInfo* aInfo, MetadataTags** aTags) { ReentrantMonitorAutoEnter mon(mDecoder->GetReentrantMonitor()); - MSE_DEBUG("MediaSourceReader(%p)::ReadMetadata tracks=%u/%u audio=%p video=%p", - this, mEssentialTrackBuffers.Length(), mTrackBuffers.Length(), + MSE_DEBUG("tracks=%u/%u audio=%p video=%p", + mEssentialTrackBuffers.Length(), mTrackBuffers.Length(), mAudioTrack.get(), mVideoTrack.get()); mEssentialTrackBuffers.Clear(); if (!mAudioTrack && !mVideoTrack) { - MSE_DEBUG("MediaSourceReader(%p)::ReadMetadata missing track: mAudioTrack=%p mVideoTrack=%p", - this, mAudioTrack.get(), mVideoTrack.get()); + MSE_DEBUG("missing track: mAudioTrack=%p mVideoTrack=%p", + mAudioTrack.get(), mVideoTrack.get()); return NS_ERROR_FAILURE; } @@ -978,8 +972,8 @@ MediaSourceReader::ReadMetadata(MediaInfo* aInfo, MetadataTags** aTags) MOZ_ASSERT(info.HasAudio()); mInfo.mAudio = info.mAudio; mInfo.mIsEncrypted = mInfo.mIsEncrypted || info.mIsEncrypted; - MSE_DEBUG("MediaSourceReader(%p)::ReadMetadata audio reader=%p duration=%lld", - this, mAudioSourceDecoder.get(), + MSE_DEBUG("audio reader=%p duration=%lld", + mAudioSourceDecoder.get(), mAudioSourceDecoder->GetReader()->GetDecoder()->GetMediaDuration()); } @@ -991,8 +985,8 @@ MediaSourceReader::ReadMetadata(MediaInfo* aInfo, MetadataTags** aTags) MOZ_ASSERT(info.HasVideo()); mInfo.mVideo = info.mVideo; mInfo.mIsEncrypted = mInfo.mIsEncrypted || info.mIsEncrypted; - MSE_DEBUG("MediaSourceReader(%p)::ReadMetadata video reader=%p duration=%lld", - this, GetVideoReader(), + MSE_DEBUG("video reader=%p duration=%lld", + GetVideoReader(), GetVideoReader()->GetDecoder()->GetMediaDuration()); } @@ -1136,4 +1130,6 @@ MediaSourceReader::GetReaderVideoTime(int64_t aTime) const return aTime - mVideoSourceDecoder->GetTimestampOffset(); } +#undef MSE_DEBUG +#undef MSE_DEBUGV } // namespace mozilla diff --git a/dom/media/mediasource/MediaSourceResource.h b/dom/media/mediasource/MediaSourceResource.h index 28f9ec0959e..97ddda5a450 100644 --- a/dom/media/mediasource/MediaSourceResource.h +++ b/dom/media/mediasource/MediaSourceResource.h @@ -12,14 +12,13 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("MediaSourceResource(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) #endif -#define UNIMPLEMENTED() MSE_DEBUG("MediaSourceResource(%p): UNIMPLEMENTED FUNCTION at %s:%d", this, __FILE__, __LINE__) +#define UNIMPLEMENTED() MSE_DEBUG("UNIMPLEMENTED FUNCTION at %s:%d", __FILE__, __LINE__) namespace mozilla { @@ -87,6 +86,7 @@ private: } // namespace mozilla +#undef MSE_DEBUG #undef UNIMPLEMENTED #endif /* MOZILLA_MEDIASOURCERESOURCE_H_ */ diff --git a/dom/media/mediasource/ResourceQueue.h b/dom/media/mediasource/ResourceQueue.h index 461eb553fa6..9941830d4cc 100644 --- a/dom/media/mediasource/ResourceQueue.h +++ b/dom/media/mediasource/ResourceQueue.h @@ -15,8 +15,13 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetSourceBufferResourceLog(); -#define SBR_DEBUG(...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define SBR_DEBUGV(...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) +/* Polyfill __func__ on MSVC to pass to the log. */ +#ifdef _MSC_VER +#define __func__ __FUNCTION__ +#endif + +#define SBR_DEBUG(arg, ...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG, ("ResourceQueue(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#define SBR_DEBUGV(arg, ...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG+1, ("ResourceQueue(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) #else #define SBR_DEBUG(...) #define SBR_DEBUGV(...) @@ -106,17 +111,17 @@ public: // Tries to evict at least aSizeToEvict from the queue up until // aOffset. Returns amount evicted. uint32_t Evict(uint64_t aOffset, uint32_t aSizeToEvict) { - SBR_DEBUG("ResourceQueue(%p)::Evict(aOffset=%llu, aSizeToEvict=%u)", - this, aOffset, aSizeToEvict); + SBR_DEBUG("Evict(aOffset=%llu, aSizeToEvict=%u)", + aOffset, aSizeToEvict); return EvictBefore(std::min(aOffset, mOffset + (uint64_t)aSizeToEvict)); } uint32_t EvictBefore(uint64_t aOffset) { - SBR_DEBUG("ResourceQueue(%p)::EvictBefore(%llu)", this, aOffset); + SBR_DEBUG("EvictBefore(%llu)", aOffset); uint32_t evicted = 0; while (ResourceItem* item = ResourceAt(0)) { - SBR_DEBUG("ResourceQueue(%p)::EvictBefore item=%p length=%d offset=%llu", - this, item, item->mData->Length(), mOffset); + SBR_DEBUG("item=%p length=%d offset=%llu", + item, item->mData->Length(), mOffset); if (item->mData->Length() + mOffset >= aOffset) { break; } @@ -128,11 +133,11 @@ public: } uint32_t EvictAll() { - SBR_DEBUG("ResourceQueue(%p)::EvictAll()", this); + SBR_DEBUG("EvictAll()"); uint32_t evicted = 0; while (ResourceItem* item = ResourceAt(0)) { - SBR_DEBUG("ResourceQueue(%p)::EvictAll item=%p length=%d offset=%llu", - this, item, item->mData->Length(), mOffset); + SBR_DEBUG("item=%p length=%d offset=%llu", + item, item->mData->Length(), mOffset); mOffset += item->mData->Length(); evicted += item->mData->Length(); delete PopFront(); @@ -209,5 +214,8 @@ private: uint64_t mOffset; }; +#undef SBR_DEBUG +#undef SBR_DEBUGV + } // namespace mozilla #endif /* MOZILLA_RESOURCEQUEUE_H_ */ diff --git a/dom/media/mediasource/SourceBuffer.cpp b/dom/media/mediasource/SourceBuffer.cpp index 08397b4b69d..c5bbfc95f07 100644 --- a/dom/media/mediasource/SourceBuffer.cpp +++ b/dom/media/mediasource/SourceBuffer.cpp @@ -29,9 +29,9 @@ class JSObject; extern PRLogModuleInfo* GetMediaSourceLog(); extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_DEBUGV(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("SourceBuffer(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) +#define MSE_DEBUGV(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG + 1, ("SourceBuffer(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) +#define MSE_API(arg, ...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, ("SourceBuffer(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) #define MSE_DEBUGV(...) @@ -101,7 +101,7 @@ void SourceBuffer::SetMode(SourceBufferAppendMode aMode, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::SetMode(aMode=%d)", this, aMode); + MSE_API("SetMode(aMode=%d)", aMode); if (!IsAttached() || mUpdating) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -123,7 +123,7 @@ void SourceBuffer::SetTimestampOffset(double aTimestampOffset, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::SetTimestampOffset(aTimestampOffset=%f)", this, aTimestampOffset); + MSE_API("SetTimestampOffset(aTimestampOffset=%f)", aTimestampOffset); if (!IsAttached() || mUpdating) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -154,7 +154,7 @@ SourceBuffer::GetBuffered(ErrorResult& aRv) ranges->Add(ranges->GetEndTime(), highestEndTime); ranges->Normalize(); } - MSE_DEBUGV("SourceBuffer(%p)::GetBuffered ranges=%s", this, DumpTimeRanges(ranges).get()); + MSE_DEBUGV("ranges=%s", DumpTimeRanges(ranges).get()); return ranges.forget(); } @@ -162,7 +162,7 @@ void SourceBuffer::SetAppendWindowStart(double aAppendWindowStart, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::SetAppendWindowStart(aAppendWindowStart=%f)", this, aAppendWindowStart); + MSE_API("SetAppendWindowStart(aAppendWindowStart=%f)", aAppendWindowStart); if (!IsAttached() || mUpdating) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -178,7 +178,7 @@ void SourceBuffer::SetAppendWindowEnd(double aAppendWindowEnd, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::SetAppendWindowEnd(aAppendWindowEnd=%f)", this, aAppendWindowEnd); + MSE_API("SetAppendWindowEnd(aAppendWindowEnd=%f)", aAppendWindowEnd); if (!IsAttached() || mUpdating) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -195,7 +195,7 @@ void SourceBuffer::AppendBuffer(const ArrayBuffer& aData, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::AppendBuffer(ArrayBuffer)", this); + MSE_API("AppendBuffer(ArrayBuffer)"); aData.ComputeLengthAndData(); AppendData(aData.Data(), aData.Length(), aRv); } @@ -204,7 +204,7 @@ void SourceBuffer::AppendBuffer(const ArrayBufferView& aData, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::AppendBuffer(ArrayBufferView)", this); + MSE_API("AppendBuffer(ArrayBufferView)"); aData.ComputeLengthAndData(); AppendData(aData.Data(), aData.Length(), aRv); } @@ -213,7 +213,7 @@ void SourceBuffer::Abort(ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::Abort()", this); + MSE_API("Abort()"); if (!IsAttached()) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -227,7 +227,7 @@ SourceBuffer::Abort(ErrorResult& aRv) mAppendWindowStart = 0; mAppendWindowEnd = PositiveInfinity(); // Discard the current decoder so no new data will be added to it. - MSE_DEBUG("SourceBuffer(%p)::Abort() Discarding decoder", this); + MSE_DEBUG("Discarding decoder"); mTrackBuffer->DiscardCurrentDecoder(); } @@ -247,7 +247,7 @@ void SourceBuffer::Remove(double aStart, double aEnd, ErrorResult& aRv) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p)::Remove(aStart=%f, aEnd=%f)", this, aStart, aEnd); + MSE_API("Remove(aStart=%f, aEnd=%f)", aStart, aEnd); if (!IsAttached()) { aRv.Throw(NS_ERROR_DOM_INVALID_STATE_ERR); return; @@ -284,7 +284,7 @@ SourceBuffer::RangeRemoval(double aStart, double aEnd) void SourceBuffer::DoRangeRemoval(double aStart, double aEnd) { - MSE_DEBUG("SourceBuffer(%p)::DoRangeRemoval", this); + MSE_DEBUG("DoRangeRemoval(%f, %f)", aStart, aEnd); if (mTrackBuffer && !IsInfinite(aStart)) { int64_t start = aStart * USECS_PER_S; int64_t end = IsInfinite(aEnd) ? INT64_MAX : (int64_t)(aEnd * USECS_PER_S); @@ -296,7 +296,7 @@ void SourceBuffer::Detach() { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("SourceBuffer(%p)::Detach", this); + MSE_DEBUG("Detach"); AbortBufferAppend(); if (mTrackBuffer) { mTrackBuffer->Detach(); @@ -310,7 +310,7 @@ SourceBuffer::Ended() { MOZ_ASSERT(NS_IsMainThread()); MOZ_ASSERT(IsAttached()); - MSE_DEBUG("SourceBuffer(%p)::Ended", this); + MSE_DEBUG("Ended"); mTrackBuffer->EndCurrentDecoder(); } @@ -323,21 +323,22 @@ SourceBuffer::SourceBuffer(MediaSource* aMediaSource, const nsACString& aType) , mAppendMode(SourceBufferAppendMode::Segments) , mUpdating(false) , mUpdateID(0) + , mType(aType) { MOZ_ASSERT(NS_IsMainThread()); MOZ_ASSERT(aMediaSource); mEvictionThreshold = Preferences::GetUint("media.mediasource.eviction_threshold", 75 * (1 << 20)); mTrackBuffer = new TrackBuffer(aMediaSource->GetDecoder(), aType); - MSE_DEBUG("SourceBuffer(%p)::SourceBuffer: Create mTrackBuffer=%p", - this, mTrackBuffer.get()); + MSE_DEBUG("Create mTrackBuffer=%p", + mTrackBuffer.get()); } SourceBuffer::~SourceBuffer() { MOZ_ASSERT(NS_IsMainThread()); MOZ_ASSERT(!mMediaSource); - MSE_DEBUG("SourceBuffer(%p)::~SourceBuffer", this); + MSE_DEBUG(""); } MediaSource* @@ -356,14 +357,14 @@ void SourceBuffer::DispatchSimpleEvent(const char* aName) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBuffer(%p) Dispatch event '%s'", this, aName); + MSE_API("Dispatch event '%s'", aName); DispatchTrustedEvent(NS_ConvertUTF8toUTF16(aName)); } void SourceBuffer::QueueAsyncSimpleEvent(const char* aName) { - MSE_DEBUG("SourceBuffer(%p) Queuing event '%s'", this, aName); + MSE_DEBUG("Queuing event '%s'", aName); nsCOMPtr event = new AsyncEventRunner(this, aName); NS_DispatchToMainThread(event, NS_DISPATCH_NORMAL); } @@ -421,7 +422,7 @@ SourceBuffer::CheckEndTime() void SourceBuffer::AppendData(const uint8_t* aData, uint32_t aLength, ErrorResult& aRv) { - MSE_DEBUG("SourceBuffer(%p)::AppendData(aLength=%u)", this, aLength); + MSE_DEBUG("AppendData(aLength=%u)", aLength); nsRefPtr data = PrepareAppend(aData, aLength, aRv); if (!data) { @@ -550,8 +551,8 @@ SourceBuffer::PrepareAppend(const uint8_t* aData, uint32_t aLength, ErrorResult& mTrackBuffer->EvictData(mMediaSource->GetDecoder()->GetCurrentTime(), toEvict, &newBufferStartTime); if (evicted) { - MSE_DEBUG("SourceBuffer(%p)::AppendData Evict; current buffered start=%f", - this, GetBufferedStart()); + MSE_DEBUG("AppendData Evict; current buffered start=%f", + GetBufferedStart()); // We notify that we've evicted from the time range 0 through to // the current start point. @@ -589,7 +590,7 @@ void SourceBuffer::Evict(double aStart, double aEnd) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("SourceBuffer(%p)::Evict(aStart=%f, aEnd=%f)", this, aStart, aEnd); + MSE_DEBUG("Evict(aStart=%f, aEnd=%f)", aStart, aEnd); double currentTime = mMediaSource->GetDecoder()->GetCurrentTime(); double evictTime = aEnd; const double safety_threshold = 5; @@ -631,6 +632,10 @@ NS_IMPL_RELEASE_INHERITED(SourceBuffer, DOMEventTargetHelper) NS_INTERFACE_MAP_BEGIN_CYCLE_COLLECTION_INHERITED(SourceBuffer) NS_INTERFACE_MAP_END_INHERITING(DOMEventTargetHelper) +#undef MSE_DEBUG +#undef MSE_DEBUGV +#undef MSE_API + } // namespace dom } // namespace mozilla diff --git a/dom/media/mediasource/SourceBuffer.h b/dom/media/mediasource/SourceBuffer.h index acf83cc4caf..85a1b60fba6 100644 --- a/dom/media/mediasource/SourceBuffer.h +++ b/dom/media/mediasource/SourceBuffer.h @@ -180,6 +180,7 @@ private: uint32_t mUpdateID; MediaPromiseConsumerHolder mPendingAppend; + const nsCString mType; }; } // namespace dom diff --git a/dom/media/mediasource/SourceBufferDecoder.cpp b/dom/media/mediasource/SourceBufferDecoder.cpp index e17dac9b804..b952c424df8 100644 --- a/dom/media/mediasource/SourceBufferDecoder.cpp +++ b/dom/media/mediasource/SourceBufferDecoder.cpp @@ -4,6 +4,7 @@ * 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 "MediaSourceUtils.h" #include "SourceBufferDecoder.h" #include "prlog.h" #include "AbstractMediaDecoder.h" @@ -12,13 +13,10 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (TOSTRING(name) "SourceBufferDecoder(%p:%s)::%s: " arg, this, mResource->GetContentType().get(), __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) -#define MSE_API(...) #endif namespace mozilla { @@ -57,14 +55,14 @@ bool SourceBufferDecoder::IsShutdown() const { // SourceBufferDecoder cannot be shut down. - MSE_DEBUG("SourceBufferDecoder(%p)::IsShutdown UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); return false; } void SourceBufferDecoder::NotifyBytesConsumed(int64_t aBytes, int64_t aOffset) { - MSE_DEBUG("SourceBufferDecoder(%p)::NotifyBytesConsumed UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } int64_t @@ -76,21 +74,21 @@ SourceBufferDecoder::GetMediaDuration() VideoFrameContainer* SourceBufferDecoder::GetVideoFrameContainer() { - MSE_DEBUG("SourceBufferDecoder(%p)::GetVideoFrameContainer UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); return nullptr; } bool SourceBufferDecoder::IsTransportSeekable() { - MSE_DEBUG("SourceBufferDecoder(%p)::IsTransportSeekable UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); return false; } bool SourceBufferDecoder::IsMediaSeekable() { - MSE_DEBUG("SourceBufferDecoder(%p)::IsMediaSeekable UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); return false; } @@ -99,14 +97,14 @@ SourceBufferDecoder::MetadataLoaded(nsAutoPtr aInfo, nsAutoPtr aTags, bool aRestoredFromDormant) { - MSE_DEBUG("SourceBufferDecoder(%p)::MetadataLoaded UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::FirstFrameLoaded(nsAutoPtr aInfo, bool aRestoredFromDormant) { - MSE_DEBUG("SourceBufferDecoder(%p)::FirstFrameLoaded UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void @@ -114,25 +112,25 @@ SourceBufferDecoder::QueueMetadata(int64_t aTime, nsAutoPtr aInfo, nsAutoPtr aTags) { - MSE_DEBUG("SourceBufferDecoder(%p)::QueueMetadata UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::RemoveMediaTracks() { - MSE_DEBUG("SourceBufferDecoder(%p)::RemoveMediaTracks UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::SetMediaEndTime(int64_t aTime) { - MSE_DEBUG("SourceBufferDecoder(%p)::SetMediaEndTime UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::UpdatePlaybackPosition(int64_t aTime) { - MSE_DEBUG("SourceBufferDecoder(%p)::UpdatePlaybackPosition UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } bool @@ -144,13 +142,13 @@ SourceBufferDecoder::HasInitializationData() void SourceBufferDecoder::OnReadMetadataCompleted() { - MSE_DEBUG("SourceBufferDecoder(%p)::OnReadMetadataCompleted UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::NotifyWaitingForResourcesStatusChanged() { - MSE_DEBUG("SourceBufferDecoder(%p)::NotifyWaitingForResourcesStatusChanged UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } ReentrantMonitor& @@ -208,13 +206,13 @@ SourceBufferDecoder::Trim(int64_t aDuration) void SourceBufferDecoder::UpdateEstimatedMediaDuration(int64_t aDuration) { - MSE_DEBUG("SourceBufferDecoder(%p)::UpdateEstimatedMediaDuration UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } void SourceBufferDecoder::SetMediaSeekable(bool aMediaSeekable) { - MSE_DEBUG("SourceBufferDecoder(%p)::SetMediaSeekable UNIMPLEMENTED", this); + MSE_DEBUG("UNIMPLEMENTED"); } layers::ImageContainer* @@ -285,4 +283,5 @@ SourceBufferDecoder::ConvertToByteOffset(double aTime) return offset; } +#undef MSE_DEBUG } // namespace mozilla diff --git a/dom/media/mediasource/SourceBufferList.cpp b/dom/media/mediasource/SourceBufferList.cpp index 041fbb80ed9..758c1da903b 100644 --- a/dom/media/mediasource/SourceBufferList.cpp +++ b/dom/media/mediasource/SourceBufferList.cpp @@ -16,20 +16,18 @@ #include "nsThreadUtils.h" #include "prlog.h" +#ifdef PR_LOGGING +extern PRLogModuleInfo* GetMediaSourceAPILog(); +#define MSE_API(arg, ...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, ("SourceBufferList(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("SourceBufferList(%p)::%s: " arg, this, __func__, ##__VA_ARGS__)) +#else +#define MSE_API(...) +#define MSE_DEBUG(...) +#endif + struct JSContext; class JSObject; -#ifdef PR_LOGGING -extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); - -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#else -#define MSE_DEBUG(...) -#define MSE_API(...) -#endif - namespace mozilla { namespace dom { @@ -111,7 +109,7 @@ void SourceBufferList::RangeRemoval(double aStart, double aEnd) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("SourceBufferList(%p)::RangeRemoval(aStart=%f, aEnd=%f", this, aStart, aEnd); + MSE_DEBUG("RangeRemoval(aStart=%f, aEnd=%f)", aStart, aEnd); for (uint32_t i = 0; i < mSourceBuffers.Length(); ++i) { mSourceBuffers[i]->RangeRemoval(aStart, aEnd); } @@ -121,7 +119,7 @@ void SourceBufferList::Evict(double aStart, double aEnd) { MOZ_ASSERT(NS_IsMainThread()); - MSE_DEBUG("SourceBufferList(%p)::Evict(aStart=%f, aEnd=%f)", this, aStart, aEnd); + MSE_DEBUG("Evict(aStart=%f, aEnd=%f)", aStart, aEnd); for (uint32_t i = 0; i < mSourceBuffers.Length(); ++i) { mSourceBuffers[i]->Evict(aStart, aEnd); } @@ -151,14 +149,14 @@ void SourceBufferList::DispatchSimpleEvent(const char* aName) { MOZ_ASSERT(NS_IsMainThread()); - MSE_API("SourceBufferList(%p) Dispatch event '%s'", this, aName); + MSE_API("Dispatch event '%s'", aName); DispatchTrustedEvent(NS_ConvertUTF8toUTF16(aName)); } void SourceBufferList::QueueAsyncSimpleEvent(const char* aName) { - MSE_DEBUG("SourceBufferList(%p) Queuing event '%s'", this, aName); + MSE_DEBUG("Queue event '%s'", aName); nsCOMPtr event = new AsyncEventRunner(this, aName); NS_DispatchToMainThread(event); } @@ -201,6 +199,8 @@ NS_IMPL_RELEASE_INHERITED(SourceBufferList, DOMEventTargetHelper) NS_INTERFACE_MAP_BEGIN_CYCLE_COLLECTION_INHERITED(SourceBufferList) NS_INTERFACE_MAP_END_INHERITING(DOMEventTargetHelper) +#undef MSE_API +#undef MSE_DEBUG } // namespace dom } // namespace mozilla diff --git a/dom/media/mediasource/SourceBufferResource.cpp b/dom/media/mediasource/SourceBufferResource.cpp index e1737fc3d86..53da8673198 100644 --- a/dom/media/mediasource/SourceBufferResource.cpp +++ b/dom/media/mediasource/SourceBufferResource.cpp @@ -23,8 +23,8 @@ PRLogModuleInfo* GetSourceBufferResourceLog() return sLogModule; } -#define SBR_DEBUG(...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define SBR_DEBUGV(...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) +#define SBR_DEBUG(arg, ...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG, ("SourceBufferResource(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) +#define SBR_DEBUGV(arg, ...) PR_LOG(GetSourceBufferResourceLog(), PR_LOG_DEBUG+1, ("SourceBufferResource(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) #else #define SBR_DEBUG(...) #define SBR_DEBUGV(...) @@ -36,7 +36,7 @@ nsresult SourceBufferResource::Close() { ReentrantMonitorAutoEnter mon(mMonitor); - SBR_DEBUG("SourceBufferResource(%p)::Close", this); + SBR_DEBUG("Close"); //MOZ_ASSERT(!mClosed); mClosed = true; mon.NotifyAll(); @@ -46,8 +46,8 @@ SourceBufferResource::Close() nsresult SourceBufferResource::Read(char* aBuffer, uint32_t aCount, uint32_t* aBytes) { - SBR_DEBUGV("SourceBufferResource(%p)::Read(aBuffer=%p, aCount=%u, aBytes=%p)", - this, aBytes, aCount, aBytes); + SBR_DEBUGV("Read(aBuffer=%p, aCount=%u, aBytes=%p)", + aBytes, aCount, aBytes); ReentrantMonitorAutoEnter mon(mMonitor); return ReadInternal(aBuffer, aCount, aBytes, /* aMayBlock = */ true); @@ -67,16 +67,16 @@ SourceBufferResource::ReadInternal(char* aBuffer, uint32_t aCount, uint32_t* aBy while (aMayBlock && !mEnded && readOffset + aCount > static_cast(GetLength())) { - SBR_DEBUGV("SourceBufferResource(%p)::ReadInternal waiting for data", this); + SBR_DEBUGV("waiting for data"); mMonitor.Wait(); } uint32_t available = GetLength() - readOffset; uint32_t count = std::min(aCount, available); - SBR_DEBUGV("SourceBufferResource(%p)::ReadInternal() readOffset=%llu GetLength()=%u available=%u count=%u mEnded=%d", + SBR_DEBUGV("readOffset=%llu GetLength()=%u available=%u count=%u mEnded=%d", this, readOffset, GetLength(), available, count, mEnded); if (available == 0) { - SBR_DEBUGV("SourceBufferResource(%p)::ReadInternal() reached EOF", this); + SBR_DEBUGV("reached EOF"); *aBytes = 0; return NS_OK; } @@ -95,8 +95,8 @@ SourceBufferResource::ReadInternal(char* aBuffer, uint32_t aCount, uint32_t* aBy nsresult SourceBufferResource::ReadAt(int64_t aOffset, char* aBuffer, uint32_t aCount, uint32_t* aBytes) { - SBR_DEBUG("SourceBufferResource(%p)::ReadAt(aOffset=%lld, aBuffer=%p, aCount=%u, aBytes=%p)", - this, aOffset, aBytes, aCount, aBytes); + SBR_DEBUG("ReadAt(aOffset=%lld, aBuffer=%p, aCount=%u, aBytes=%p)", + aOffset, aBytes, aCount, aBytes); ReentrantMonitorAutoEnter mon(mMonitor); return ReadAtInternal(aOffset, aBuffer, aCount, aBytes, /* aMayBlock = */ true); } @@ -117,7 +117,8 @@ SourceBufferResource::ReadAtInternal(int64_t aOffset, char* aBuffer, uint32_t aC nsresult SourceBufferResource::Seek(int32_t aWhence, int64_t aOffset) { - SBR_DEBUG("SourceBufferResource(%p)::Seek(aWhence=%d, aOffset=%lld)", this, aWhence, aOffset); + SBR_DEBUG("Seek(aWhence=%d, aOffset=%lld)", + aWhence, aOffset); ReentrantMonitorAutoEnter mon(mMonitor); int64_t newOffset = mOffset; @@ -133,8 +134,8 @@ SourceBufferResource::Seek(int32_t aWhence, int64_t aOffset) break; } - SBR_DEBUGV("SourceBufferResource(%p)::Seek() newOffset=%lld GetOffset()=%llu GetLength()=%llu)", - this, newOffset, mInputBuffer.GetOffset(), GetLength()); + SBR_DEBUGV("newOffset=%lld GetOffset()=%llu GetLength()=%llu)", + newOffset, mInputBuffer.GetOffset(), GetLength()); nsresult rv = SeekInternal(newOffset); mon.NotifyAll(); return rv; @@ -159,8 +160,8 @@ SourceBufferResource::SeekInternal(int64_t aOffset) nsresult SourceBufferResource::ReadFromCache(char* aBuffer, int64_t aOffset, uint32_t aCount) { - SBR_DEBUG("SourceBufferResource(%p)::ReadFromCache(aBuffer=%p, aOffset=%lld, aCount=%u)", - this, aBuffer, aOffset, aCount); + SBR_DEBUG("ReadFromCache(aBuffer=%p, aOffset=%lld, aCount=%u)", + aBuffer, aOffset, aCount); ReentrantMonitorAutoEnter mon(mMonitor); uint32_t bytesRead; int64_t oldOffset = mOffset; @@ -175,8 +176,8 @@ SourceBufferResource::ReadFromCache(char* aBuffer, int64_t aOffset, uint32_t aCo uint32_t SourceBufferResource::EvictData(uint64_t aPlaybackOffset, uint32_t aThreshold) { - SBR_DEBUG("SourceBufferResource(%p)::EvictData(aPlaybackOffset=%llu," - "aThreshold=%u)", this, aPlaybackOffset, aThreshold); + SBR_DEBUG("EvictData(aPlaybackOffset=%llu," + "aThreshold=%u)", aPlaybackOffset, aThreshold); ReentrantMonitorAutoEnter mon(mMonitor); return mInputBuffer.Evict(aPlaybackOffset, aThreshold); } @@ -184,7 +185,7 @@ SourceBufferResource::EvictData(uint64_t aPlaybackOffset, uint32_t aThreshold) void SourceBufferResource::EvictBefore(uint64_t aOffset) { - SBR_DEBUG("SourceBufferResource(%p)::EvictBefore(aOffset=%llu)", this, aOffset); + SBR_DEBUG("EvictBefore(aOffset=%llu)", aOffset); ReentrantMonitorAutoEnter mon(mMonitor); // If aOffset is past the current playback offset we don't evict. if (aOffset < mOffset) { @@ -195,7 +196,7 @@ SourceBufferResource::EvictBefore(uint64_t aOffset) uint32_t SourceBufferResource::EvictAll() { - SBR_DEBUG("SourceBufferResource(%p)::EvictAll()", this); + SBR_DEBUG("EvictAll()"); ReentrantMonitorAutoEnter mon(mMonitor); return mInputBuffer.EvictAll(); } @@ -203,7 +204,7 @@ SourceBufferResource::EvictAll() void SourceBufferResource::AppendData(LargeDataBuffer* aData) { - SBR_DEBUG("SourceBufferResource(%p)::AppendData(aData=%p, aLength=%u)", this, + SBR_DEBUG("AppendData(aData=%p, aLength=%u)", aData->Elements(), aData->Length()); ReentrantMonitorAutoEnter mon(mMonitor); mInputBuffer.AppendItem(aData); @@ -214,7 +215,7 @@ SourceBufferResource::AppendData(LargeDataBuffer* aData) void SourceBufferResource::Ended() { - SBR_DEBUG("SourceBufferResource(%p)::Ended()", this); + SBR_DEBUG(""); ReentrantMonitorAutoEnter mon(mMonitor); mEnded = true; mon.NotifyAll(); @@ -222,7 +223,7 @@ SourceBufferResource::Ended() SourceBufferResource::~SourceBufferResource() { - SBR_DEBUG("SourceBufferResource(%p)::~SourceBufferResource()", this); + SBR_DEBUG(""); MOZ_COUNT_DTOR(SourceBufferResource); } @@ -233,9 +234,10 @@ SourceBufferResource::SourceBufferResource(const nsACString& aType) , mClosed(false) , mEnded(false) { - SBR_DEBUG("SourceBufferResource(%p)::SourceBufferResource(aType=%s)", - this, nsCString(aType).get()); + SBR_DEBUG(""); MOZ_COUNT_CTOR(SourceBufferResource); } +#undef SBR_DEBUG +#undef SBR_DEBUGV } // namespace mozilla diff --git a/dom/media/mediasource/SourceBufferResource.h b/dom/media/mediasource/SourceBufferResource.h index 4888bb7ad00..9953b07833f 100644 --- a/dom/media/mediasource/SourceBufferResource.h +++ b/dom/media/mediasource/SourceBufferResource.h @@ -20,15 +20,6 @@ #include "nscore.h" #include "prlog.h" -#ifdef PR_LOGGING -extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); - -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#else -#define MSE_DEBUG(...) -#endif - #define UNIMPLEMENTED() { /* Logging this is too spammy to do by default */ } class nsIStreamListener; diff --git a/dom/media/mediasource/TrackBuffer.cpp b/dom/media/mediasource/TrackBuffer.cpp index 4c59ce9eaa8..4c831fa9226 100644 --- a/dom/media/mediasource/TrackBuffer.cpp +++ b/dom/media/mediasource/TrackBuffer.cpp @@ -23,15 +23,10 @@ #ifdef PR_LOGGING extern PRLogModuleInfo* GetMediaSourceLog(); -extern PRLogModuleInfo* GetMediaSourceAPILog(); -#define MSE_DEBUG(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, (__VA_ARGS__)) -#define MSE_DEBUGV(...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG+1, (__VA_ARGS__)) -#define MSE_API(...) PR_LOG(GetMediaSourceAPILog(), PR_LOG_DEBUG, (__VA_ARGS__)) +#define MSE_DEBUG(arg, ...) PR_LOG(GetMediaSourceLog(), PR_LOG_DEBUG, ("TrackBuffer(%p:%s)::%s: " arg, this, mType.get(), __func__, ##__VA_ARGS__)) #else #define MSE_DEBUG(...) -#define MSE_DEBUGV(...) -#define MSE_API(...) #endif // Time in seconds to substract from the current time when deciding the @@ -57,7 +52,7 @@ TrackBuffer::TrackBuffer(MediaSourceDecoder* aParentDecoder, const nsACString& a mTaskQueue = new MediaTaskQueue(GetMediaDecodeThreadPool()); aParentDecoder->AddTrackBuffer(this); mDecoderPerSegment = Preferences::GetBool("media.mediasource.decoder-per-segment", false); - MSE_DEBUG("TrackBuffer(%p) created for parent decoder %p", this, aParentDecoder); + MSE_DEBUG("TrackBuffer created for parent decoder %p", aParentDecoder); } TrackBuffer::~TrackBuffer() @@ -158,9 +153,9 @@ TrackBuffer::AppendData(LargeDataBuffer* aData, int64_t aTimestampOffset) // TODO: Run more of the buffer append algorithm asynchronously. if (newInitData) { - MSE_DEBUG("TrackBuffer(%p)::AppendData: New initialization segment.", this); + MSE_DEBUG("New initialization segment."); } else if (!hadInitData) { - MSE_DEBUG("TrackBuffer(%p)::AppendData: Non-init segment appended during initialization.", this); + MSE_DEBUG("Non-init segment appended during initialization."); mInitializationPromise.Reject(NS_ERROR_FAILURE, __func__); return p; } @@ -199,8 +194,8 @@ TrackBuffer::AppendData(LargeDataBuffer* aData, int64_t aTimestampOffset) mLastTimestampOffset != aTimestampOffset || mDecoderPerSegment || (mCurrentDecoder && mCurrentDecoder->WasTrimmed()))) { - MSE_DEBUG("TrackBuffer(%p)::AppendData: Data last=[%lld, %lld] overlaps [%lld, %lld]", - this, mLastStartTimestamp, mLastEndTimestamp.value(), start, end); + MSE_DEBUG("Data last=[%lld, %lld] overlaps [%lld, %lld]", + mLastStartTimestamp, mLastEndTimestamp.value(), start, end); if (!newInitData) { // This data is earlier in the timeline than data we have already @@ -211,13 +206,14 @@ TrackBuffer::AppendData(LargeDataBuffer* aData, int64_t aTimestampOffset) mInitializationPromise.Reject(NS_ERROR_FAILURE, __func__); return p; } - MSE_DEBUG("TrackBuffer(%p)::AppendData: Decoder marked as initialized.", this); + MSE_DEBUG("Decoder marked as initialized."); AppendDataToCurrentResource(oldInit, 0); } mLastStartTimestamp = start; } else { - MSE_DEBUG("TrackBuffer(%p)::AppendData: Segment last=[%lld, %lld] [%lld, %lld]", - this, mLastStartTimestamp, mLastEndTimestamp ? mLastEndTimestamp.value() : 0, start, end); + MSE_DEBUG("Segment last=[%lld, %lld] [%lld, %lld]", + mLastStartTimestamp, + mLastEndTimestamp ? mLastEndTimestamp.value() : 0, start, end); } mLastEndTimestamp.reset(); mLastEndTimestamp.emplace(end); @@ -334,9 +330,9 @@ TrackBuffer::EvictData(double aPlaybackTime, pastCurrentDecoder = false; } - MSE_DEBUG("TrackBuffer(%p)::EvictData decoder=%u/%u threshold=%u " + MSE_DEBUG("decoder=%u/%u threshold=%u " "toEvict=%lld current=%s pastCurrent=%s", - this, i, decoders.Length(), aThreshold, toEvict, + i, decoders.Length(), aThreshold, toEvict, onCurrent ? "true" : "false", pastCurrentDecoder ? "true" : "false"); @@ -344,9 +340,9 @@ TrackBuffer::EvictData(double aPlaybackTime, !mParentDecoder->IsActiveReader(decoders[i]->GetReader())) { // Remove data from older decoders than the current one. // Don't remove data if it is currently active. - MSE_DEBUG("TrackBuffer(%p)::EvictData evicting all before start " + MSE_DEBUG("evicting all before start " "bufferedStart=%f bufferedEnd=%f aPlaybackTime=%f size=%lld", - this, buffered->GetStartTime(), buffered->GetEndTime(), + buffered->GetStartTime(), buffered->GetEndTime(), aPlaybackTime, decoders[i]->GetResource()->GetSize()); toEvict -= decoders[i]->GetResource()->EvictAll(); } else { @@ -356,9 +352,9 @@ TrackBuffer::EvictData(double aPlaybackTime, if (aPlaybackTime > MSE_EVICT_THRESHOLD_TIME) { double time = aPlaybackTime - MSE_EVICT_THRESHOLD_TIME; int64_t playbackOffset = decoders[i]->ConvertToByteOffset(time); - MSE_DEBUG("TrackBuffer(%p)::EvictData evicting some bufferedEnd=%f" + MSE_DEBUG("evicting some bufferedEnd=%f" "aPlaybackTime=%f time=%f, playbackOffset=%lld size=%lld", - this, buffered->GetEndTime(), aPlaybackTime, time, + buffered->GetEndTime(), aPlaybackTime, time, playbackOffset, decoders[i]->GetResource()->GetSize()); if (playbackOffset > 0) { toEvict -= decoders[i]->GetResource()->EvictData(playbackOffset, @@ -372,9 +368,9 @@ TrackBuffer::EvictData(double aPlaybackTime, for (i = 0; i < decoders.Length(); ++i) { nsRefPtr buffered = new dom::TimeRanges(); decoders[i]->GetBuffered(buffered); - MSE_DEBUG("TrackBuffer(%p):EvictData maybe remove empty decoders=%d " + MSE_DEBUG("maybe remove empty decoders=%d " "size=%lld start=%f end=%f", - this, i, decoders[i]->GetResource()->GetSize(), + i, decoders[i]->GetResource()->GetSize(), buffered->GetStartTime(), buffered->GetEndTime()); if (decoders[i] == mCurrentDecoder || mParentDecoder->IsActiveReader(decoders[i]->GetReader())) { @@ -384,7 +380,7 @@ TrackBuffer::EvictData(double aPlaybackTime, if (decoders[i]->GetResource()->GetSize() == 0 || buffered->GetStartTime() < 0.0 || buffered->GetEndTime() < 0.0) { - MSE_DEBUG("TrackBuffer(%p):EvictData remove empty decoders=%d", this, i); + MSE_DEBUG("remove empty decoders=%d", i); RemoveDecoder(decoders[i]); } } @@ -407,7 +403,8 @@ TrackBuffer::EvictBefore(double aTime) for (uint32_t i = 0; i < mInitializedDecoders.Length(); ++i) { int64_t endOffset = mInitializedDecoders[i]->ConvertToByteOffset(aTime); if (endOffset > 0) { - MSE_DEBUG("TrackBuffer(%p)::EvictBefore decoder=%u offset=%lld", this, i, endOffset); + MSE_DEBUG("decoder=%u offset=%lld", + i, endOffset); mInitializedDecoders[i]->GetResource()->EvictBefore(endOffset); } } @@ -470,7 +467,7 @@ TrackBuffer::QueueInitializeDecoder(SourceBufferDecoder* aDecoder) &TrackBuffer::InitializeDecoder, aDecoder); if (NS_FAILED(mTaskQueue->Dispatch(task))) { - MSE_DEBUG("TrackBuffer(%p): Failed to enqueue decoder initialization task", this); + MSE_DEBUG("failed to enqueue decoder initialization task"); RemoveDecoder(aDecoder); mInitializationPromise.RejectIfExists(NS_ERROR_FAILURE, __func__); return false; @@ -482,8 +479,7 @@ void TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) { if (!mParentDecoder) { - MSE_DEBUG("TrackBuffer(%p) was shutdown. Aborting initialization.", - this); + MSE_DEBUG("decoder was shutdown. Aborting initialization."); return; } // ReadMetadata may block the thread waiting on data, so we must be able @@ -494,8 +490,7 @@ TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) ReentrantMonitorAutoEnter mon(mParentDecoder->GetReentrantMonitor()); if (mCurrentDecoder != aDecoder) { - MSE_DEBUG("TrackBuffer(%p) append was cancelled. Aborting initialization.", - this); + MSE_DEBUG("append was cancelled. Aborting initialization."); // If we reached this point, the SourceBuffer would have disconnected // the promise. So no need to reject it. return; @@ -506,15 +501,15 @@ TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) // need to abort immediately, because the reader has forgotten about us, and // important pieces of our state (like mTaskQueue) have also been torn down. if (mShutdown) { - MSE_DEBUG("TrackBuffer(%p) was shut down. Aborting initialization.", this); + MSE_DEBUG("was shut down. Aborting initialization."); RemoveDecoder(aDecoder); return; } MOZ_ASSERT(mTaskQueue->IsCurrentThreadIn()); MediaDecoderReader* reader = aDecoder->GetReader(); - MSE_DEBUG("TrackBuffer(%p): Initializing subdecoder %p reader %p", - this, aDecoder, reader); + MSE_DEBUG("Initializing subdecoder %p reader %p", + aDecoder, reader); MediaInfo mi; nsAutoPtr tags; // TODO: Handle metadata. @@ -544,7 +539,7 @@ TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) reader->SetIdle(); if (mShutdown) { - MSE_DEBUG("TrackBuffer(%p) was shut down while reading metadata. Aborting initialization.", this); + MSE_DEBUG("was shut down while reading metadata. Aborting initialization."); return; } @@ -557,20 +552,20 @@ TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) if (NS_FAILED(rv) || (!mi.HasVideo() && !mi.HasAudio())) { // XXX: Need to signal error back to owning SourceBuffer. - MSE_DEBUG("TrackBuffer(%p): Reader %p failed to initialize rv=%x audio=%d video=%d", - this, reader, rv, mi.HasAudio(), mi.HasVideo()); + MSE_DEBUG("Reader %p failed to initialize rv=%x audio=%d video=%d", + reader, rv, mi.HasAudio(), mi.HasVideo()); RemoveDecoder(aDecoder); mInitializationPromise.RejectIfExists(NS_ERROR_FAILURE, __func__); return; } if (mi.HasVideo()) { - MSE_DEBUG("TrackBuffer(%p): Reader %p video resolution=%dx%d", - this, reader, mi.mVideo.mDisplay.width, mi.mVideo.mDisplay.height); + MSE_DEBUG("Reader %p video resolution=%dx%d", + reader, mi.mVideo.mDisplay.width, mi.mVideo.mDisplay.height); } if (mi.HasAudio()) { - MSE_DEBUG("TrackBuffer(%p): Reader %p audio sampleRate=%d channels=%d", - this, reader, mi.mAudio.mRate, mi.mAudio.mChannels); + MSE_DEBUG("Reader %p audio sampleRate=%d channels=%d", + reader, mi.mAudio.mRate, mi.mAudio.mChannels); } RefPtr task = @@ -578,7 +573,7 @@ TrackBuffer::InitializeDecoder(SourceBufferDecoder* aDecoder) &TrackBuffer::CompleteInitializeDecoder, aDecoder); if (NS_FAILED(NS_DispatchToMainThread(task))) { - MSE_DEBUG("TrackBuffer(%p): Failed to enqueue decoder initialization task", this); + MSE_DEBUG("Failed to enqueue decoder initialization task"); RemoveDecoder(aDecoder); mInitializationPromise.RejectIfExists(NS_ERROR_FAILURE, __func__); return; @@ -589,28 +584,26 @@ void TrackBuffer::CompleteInitializeDecoder(SourceBufferDecoder* aDecoder) { if (!mParentDecoder) { - MSE_DEBUG("TrackBuffer(%p) was shutdown. Aborting initialization.", - this); + MSE_DEBUG("was shutdown. Aborting initialization."); return; } ReentrantMonitorAutoEnter mon(mParentDecoder->GetReentrantMonitor()); if (mCurrentDecoder != aDecoder) { - MSE_DEBUG("TrackBuffer(%p) append was cancelled. Aborting initialization.", - this); + MSE_DEBUG("append was cancelled. Aborting initialization."); // If we reached this point, the SourceBuffer would have disconnected // the promise. So no need to reject it. return; } if (mShutdown) { - MSE_DEBUG("TrackBuffer(%p) was shut down. Aborting initialization.", this); + MSE_DEBUG("was shut down. Aborting initialization."); RemoveDecoder(aDecoder); return; } if (!RegisterDecoder(aDecoder)) { - MSE_DEBUG("TrackBuffer(%p): Reader %p not activated", - this, aDecoder->GetReader()); + MSE_DEBUG("Reader %p not activated", + aDecoder->GetReader()); RemoveDecoder(aDecoder); mInitializationPromise.RejectIfExists(NS_ERROR_FAILURE, __func__); return; @@ -627,8 +620,8 @@ TrackBuffer::CompleteInitializeDecoder(SourceBufferDecoder* aDecoder) // required when data is appended. mParentDecoder->GetReader()->MaybeNotifyHaveData(); - MSE_DEBUG("TrackBuffer(%p): Reader %p activated", - this, aDecoder->GetReader()); + MSE_DEBUG("Reader %p activated", + aDecoder->GetReader()); mInitializationPromise.ResolveIfExists(aDecoder->GetRealMediaDuration() > 0, __func__); } @@ -637,7 +630,7 @@ TrackBuffer::ValidateTrackFormats(const MediaInfo& aInfo) { if (mInfo.HasAudio() != aInfo.HasAudio() || mInfo.HasVideo() != aInfo.HasVideo()) { - MSE_DEBUG("TrackBuffer(%p)::ValidateTrackFormats audio/video track mismatch", this); + MSE_DEBUG("audio/video track mismatch"); return false; } @@ -645,7 +638,7 @@ TrackBuffer::ValidateTrackFormats(const MediaInfo& aInfo) if (mInfo.HasAudio() && (mInfo.mAudio.mRate != aInfo.mAudio.mRate || mInfo.mAudio.mChannels != aInfo.mAudio.mChannels)) { - MSE_DEBUG("TrackBuffer(%p)::ValidateTrackFormats audio format mismatch", this); + MSE_DEBUG("audio format mismatch"); return false; } @@ -663,7 +656,7 @@ TrackBuffer::RegisterDecoder(SourceBufferDecoder* aDecoder) mParentDecoder->OnTrackBufferConfigured(this, mInfo); } if (!ValidateTrackFormats(info)) { - MSE_DEBUG("TrackBuffer(%p)::RegisterDecoder with mismatched audio/video tracks", this); + MSE_DEBUG("mismatched audio/video tracks"); return false; } mInitializedDecoders.AppendElement(aDecoder); @@ -907,7 +900,7 @@ TrackBuffer::RangeRemoval(int64_t aStart, int64_t aEnd) } if (aEnd < bufferedEnd) { // TODO. We only handle trimming. - NS_WARNING("TrackBuffer::RangeRemoval unsupported arguments. " + NS_WARNING("RangeRemoval unsupported arguments. " "Can only handle trimming"); return false; } @@ -926,7 +919,7 @@ TrackBuffer::RangeRemoval(int64_t aStart, int64_t aEnd) mParentDecoder->IsActiveReader(decoders[i]->GetReader())) { continue; } - MSE_DEBUG("TrackBuffer(%p):RangeRemoval remove empty decoders=%d", this, i); + MSE_DEBUG("remove empty decoders=%d", i); RemoveDecoder(decoders[i]); } } @@ -942,4 +935,6 @@ TrackBuffer::AdjustDecodersTimestampOffset(int32_t aOffset) } } +#undef MSE_DEBUG + } // namespace mozilla