From 47d9aba92dc42be93f5e2da1a3dc0ce0cdb1e8d8 Mon Sep 17 00:00:00 2001 From: Eric Rahm Date: Thu, 14 May 2015 10:13:23 -0700 Subject: [PATCH] Bug 1163201 - Part 2: Wrap expensive calls in PR_LOG_TEST. r=froydnj --- dom/base/nsContentPolicy.cpp | 4 +- dom/base/nsDocument.cpp | 19 ++--- dom/base/nsFocusManager.cpp | 8 +-- dom/events/IMEStateManager.cpp | 16 +++-- dom/media/directshow/SampleSink.cpp | 24 ++++--- dom/media/eme/EMEUtils.h | 1 + dom/media/eme/MediaKeySession.cpp | 70 +++++++++++-------- dom/media/systemservices/OpenSLESProvider.cpp | 2 +- dom/media/webm/WebMReader.cpp | 4 ++ .../webrtc/MediaEngineCameraVideoSource.cpp | 18 ++--- dom/media/webrtc/MediaEngineWebRTCAudio.cpp | 2 +- dom/media/webrtc/MediaEngineWebRTCVideo.cpp | 2 +- 12 files changed, 97 insertions(+), 73 deletions(-) diff --git a/dom/base/nsContentPolicy.cpp b/dom/base/nsContentPolicy.cpp index b6e79a2eb682..db30193b386a 100644 --- a/dom/base/nsContentPolicy.cpp +++ b/dom/base/nsContentPolicy.cpp @@ -187,8 +187,8 @@ nsContentPolicy::CheckPolicy(CPMethod policyMethod, //logType must be a literal string constant #define LOG_CHECK(logType) \ PR_BEGIN_MACRO \ - /* skip all this nonsense if the call failed */ \ - if (NS_SUCCEEDED(rv)) { \ + /* skip all this nonsense if the call failed or logging is disabled */ \ + if (NS_SUCCEEDED(rv) && PR_LOG_TEST(gConPolLog, PR_LOG_DEBUG)) { \ const char *resultName; \ if (decision) { \ resultName = NS_CP_ResponseName(*decision); \ diff --git a/dom/base/nsDocument.cpp b/dom/base/nsDocument.cpp index 4220a10899f2..8d92ad9fc14d 100644 --- a/dom/base/nsDocument.cpp +++ b/dom/base/nsDocument.cpp @@ -2864,14 +2864,17 @@ nsDocument::InitCSP(nsIChannel* aChannel) !applyLoopCSP && cspHeaderValue.IsEmpty() && cspROHeaderValue.IsEmpty()) { - nsCOMPtr chanURI; - aChannel->GetURI(getter_AddRefs(chanURI)); - nsAutoCString aspec; - chanURI->GetAsciiSpec(aspec); - PR_LOG(gCspPRLog, PR_LOG_DEBUG, - ("no CSP for document, %s, %s", - aspec.get(), - applyAppDefaultCSP ? "is app" : "not an app")); + if (PR_LOG_TEST(gCspPRLog, PR_LOG_DEBUG)) { + nsCOMPtr chanURI; + aChannel->GetURI(getter_AddRefs(chanURI)); + nsAutoCString aspec; + chanURI->GetAsciiSpec(aspec); + PR_LOG(gCspPRLog, PR_LOG_DEBUG, + ("no CSP for document, %s, %s", + aspec.get(), + applyAppDefaultCSP ? "is app" : "not an app")); + } + return NS_OK; } diff --git a/dom/base/nsFocusManager.cpp b/dom/base/nsFocusManager.cpp index e770debb9d47..302468b9a4d8 100644 --- a/dom/base/nsFocusManager.cpp +++ b/dom/base/nsFocusManager.cpp @@ -77,16 +77,16 @@ using namespace mozilla::widget; PRLogModuleInfo* gFocusLog; PRLogModuleInfo* gFocusNavigationLog; -#define LOGFOCUS(args) PR_LOG(gFocusLog, 4, args) -#define LOGFOCUSNAVIGATION(args) PR_LOG(gFocusNavigationLog, 4, args) +#define LOGFOCUS(args) PR_LOG(gFocusLog, PR_LOG_DEBUG, args) +#define LOGFOCUSNAVIGATION(args) PR_LOG(gFocusNavigationLog, PR_LOG_DEBUG, args) #define LOGTAG(log, format, content) \ - { \ + if (PR_LOG_TEST(log, PR_LOG_DEBUG)) { \ nsAutoCString tag(NS_LITERAL_CSTRING("(none)")); \ if (content) { \ content->NodeInfo()->NameAtom()->ToUTF8String(tag); \ } \ - PR_LOG(log, 4, (format, tag.get())); \ + PR_LOG(log, PR_LOG_DEBUG, (format, tag.get())); \ } #define LOGCONTENT(format, content) LOGTAG(gFocusLog, format, content) diff --git a/dom/events/IMEStateManager.cpp b/dom/events/IMEStateManager.cpp index 19a232841313..101871acf098 100644 --- a/dom/events/IMEStateManager.cpp +++ b/dom/events/IMEStateManager.cpp @@ -507,13 +507,15 @@ IMEStateManager::OnMouseButtonEventInEditor(nsPresContext* aPresContext, bool consumed = sActiveIMEContentObserver->OnMouseButtonEvent(aPresContext, internalEvent); - nsAutoString eventType; - aMouseEvent->GetType(eventType); - PR_LOG(sISMLog, PR_LOG_ALWAYS, - ("ISM: IMEStateManager::OnMouseButtonEventInEditor(), " - "mouse event (type=%s, button=%d) is %s", - NS_ConvertUTF16toUTF8(eventType).get(), internalEvent->button, - consumed ? "consumed" : "not consumed")); + if (PR_LOG_TEST(sISMLog, PR_LOG_ALWAYS)) { + nsAutoString eventType; + aMouseEvent->GetType(eventType); + PR_LOG(sISMLog, PR_LOG_ALWAYS, + ("ISM: IMEStateManager::OnMouseButtonEventInEditor(), " + "mouse event (type=%s, button=%d) is %s", + NS_ConvertUTF16toUTF8(eventType).get(), internalEvent->button, + consumed ? "consumed" : "not consumed")); + } return consumed; } diff --git a/dom/media/directshow/SampleSink.cpp b/dom/media/directshow/SampleSink.cpp index 584fda2c5045..30a36f6de798 100644 --- a/dom/media/directshow/SampleSink.cpp +++ b/dom/media/directshow/SampleSink.cpp @@ -65,11 +65,13 @@ SampleSink::Receive(IMediaSample* aSample) mon.Wait(); } - REFERENCE_TIME start = 0, end = 0; - HRESULT hr = aSample->GetMediaTime(&start, &end); - LOG("SampleSink::Receive() [%4.2lf-%4.2lf]", - (double)RefTimeToUsecs(start) / USECS_PER_S, - (double)RefTimeToUsecs(end) / USECS_PER_S); + if (PR_LOG_TEST(GetDirectShowLog(), PR_LOG_DEBUG)) { + REFERENCE_TIME start = 0, end = 0; + HRESULT hr = aSample->GetMediaTime(&start, &end); + LOG("SampleSink::Receive() [%4.2lf-%4.2lf]", + (double)RefTimeToUsecs(start) / USECS_PER_S, + (double)RefTimeToUsecs(end) / USECS_PER_S); + } mSample = aSample; // Notify the signal, to awaken the consumer thread in WaitForSample() @@ -100,11 +102,13 @@ SampleSink::Extract(RefPtr& aOutSample) } aOutSample = mSample; - int64_t start = 0, end = 0; - mSample->GetMediaTime(&start, &end); - LOG("SampleSink::Extract() [%4.2lf-%4.2lf]", - (double)RefTimeToUsecs(start) / USECS_PER_S, - (double)RefTimeToUsecs(end) / USECS_PER_S); + if (PR_LOG_TEST(GetDirectShowLog(), PR_LOG_DEBUG)) { + int64_t start = 0, end = 0; + mSample->GetMediaTime(&start, &end); + LOG("SampleSink::Extract() [%4.2lf-%4.2lf]", + (double)RefTimeToUsecs(start) / USECS_PER_S, + (double)RefTimeToUsecs(end) / USECS_PER_S); + } mSample = nullptr; // Notify the signal, to awaken the producer thread in Receive() diff --git a/dom/media/eme/EMEUtils.h b/dom/media/eme/EMEUtils.h index 0bff78d3d6a7..43983c8bcc10 100644 --- a/dom/media/eme/EMEUtils.h +++ b/dom/media/eme/EMEUtils.h @@ -15,6 +15,7 @@ namespace mozilla { #ifndef EME_LOG PRLogModuleInfo* GetEMELog(); #define EME_LOG(...) PR_LOG(GetEMELog(), PR_LOG_DEBUG, (__VA_ARGS__)) + #define EME_LOG_ENABLED() PR_LOG_TEST(GetEMELog(), PR_LOG_DEBUG) #endif #ifndef EME_VERBOSE_LOG diff --git a/dom/media/eme/MediaKeySession.cpp b/dom/media/eme/MediaKeySession.cpp index bff0a80d5a7b..140005b77ca2 100644 --- a/dom/media/eme/MediaKeySession.cpp +++ b/dom/media/eme/MediaKeySession.cpp @@ -138,22 +138,24 @@ MediaKeySession::UpdateKeyStatusMap() mKeyStatusMap->Update(keyStatuses); - nsAutoCString message( - nsPrintfCString("MediaKeySession[%p,'%s'] key statuses change {", - this, NS_ConvertUTF16toUTF8(mSessionId).get())); - for (const CDMCaps::KeyStatus& status : keyStatuses) { - nsAutoCString base64KeyId; - nsDependentCSubstring rawKeyId(reinterpret_cast(status.mId.Elements()), - status.mId.Length()); - nsresult rv = Base64Encode(rawKeyId, base64KeyId); - if (NS_WARN_IF(NS_FAILED(rv))) { - continue; + if (EME_LOG_ENABLED()) { + nsAutoCString message( + nsPrintfCString("MediaKeySession[%p,'%s'] key statuses change {", + this, NS_ConvertUTF16toUTF8(mSessionId).get())); + for (const CDMCaps::KeyStatus& status : keyStatuses) { + nsAutoCString base64KeyId; + nsDependentCSubstring rawKeyId(reinterpret_cast(status.mId.Elements()), + status.mId.Length()); + nsresult rv = Base64Encode(rawKeyId, base64KeyId); + if (NS_WARN_IF(NS_FAILED(rv))) { + continue; + } + message.Append(nsPrintfCString(" (%s,%s)", base64KeyId.get(), + MediaKeyStatusValues::strings[status.mStatus].value)); } - message.Append(nsPrintfCString(" (%s,%s)", base64KeyId.get(), - MediaKeyStatusValues::strings[status.mStatus].value)); + message.Append(" }"); + EME_LOG(message.get()); } - message.Append(" }"); - EME_LOG(message.get()); } MediaKeyStatusMap* @@ -195,10 +197,12 @@ MediaKeySession::GenerateRequest(const nsAString& aInitDataType, // Note: UpdateSession() Move()s the data out of the array, so we have // to copy it here. nsAutoCString base64InitData; - nsDependentCSubstring rawInitData(reinterpret_cast(data.Elements()), - data.Length()); - if (NS_FAILED(Base64Encode(rawInitData, base64InitData))) { - NS_WARNING("Failed to base64 encode initData for logging"); + if (EME_LOG_ENABLED()) { + nsDependentCSubstring rawInitData(reinterpret_cast(data.Elements()), + data.Length()); + if (NS_FAILED(Base64Encode(rawInitData, base64InitData))) { + NS_WARNING("Failed to base64 encode initData for logging"); + } } PromiseId pid = mKeys->StorePromise(promise); @@ -280,10 +284,12 @@ MediaKeySession::Update(const ArrayBufferViewOrArrayBuffer& aResponse, ErrorResu // Note: UpdateSession() Move()s the data out of the array, so we have // to copy it here. nsAutoCString base64Response; - nsDependentCSubstring rawResponse(reinterpret_cast(data.Elements()), - data.Length()); - if (NS_FAILED(Base64Encode(rawResponse, base64Response))) { - NS_WARNING("Failed to base64 encode response for logging"); + if (EME_LOG_ENABLED()) { + nsDependentCSubstring rawResponse(reinterpret_cast(data.Elements()), + data.Length()); + if (NS_FAILED(Base64Encode(rawResponse, base64Response))) { + NS_WARNING("Failed to base64 encode response for logging"); + } } PromiseId pid = mKeys->StorePromise(promise); @@ -376,16 +382,18 @@ void MediaKeySession::DispatchKeyMessage(MediaKeyMessageType aMessageType, const nsTArray& aMessage) { - nsAutoCString base64MsgData; - nsDependentCSubstring rawMsgData(reinterpret_cast(aMessage.Elements()), - aMessage.Length()); - if (NS_FAILED(Base64Encode(rawMsgData, base64MsgData))) { - NS_WARNING("Failed to base64 encode message for logging"); + if (EME_LOG_ENABLED()) { + nsAutoCString base64MsgData; + nsDependentCSubstring rawMsgData(reinterpret_cast(aMessage.Elements()), + aMessage.Length()); + if (NS_FAILED(Base64Encode(rawMsgData, base64MsgData))) { + NS_WARNING("Failed to base64 encode message for logging"); + } + EME_LOG("MediaKeySession[%p,'%s'] DispatchKeyMessage() type=%s message(base64)='%s'", + this, NS_ConvertUTF16toUTF8(mSessionId).get(), + MediaKeyMessageTypeValues::strings[uint32_t(aMessageType)].value, + base64MsgData.get()); } - EME_LOG("MediaKeySession[%p,'%s'] DispatchKeyMessage() type=%s message(base64)='%s'", - this, NS_ConvertUTF16toUTF8(mSessionId).get(), - MediaKeyMessageTypeValues::strings[uint32_t(aMessageType)].value, - base64MsgData.get()); nsRefPtr event( MediaKeyMessageEvent::Constructor(this, aMessageType, aMessage)); diff --git a/dom/media/systemservices/OpenSLESProvider.cpp b/dom/media/systemservices/OpenSLESProvider.cpp index 7fad2d49f57e..8f6ad459a3fb 100644 --- a/dom/media/systemservices/OpenSLESProvider.cpp +++ b/dom/media/systemservices/OpenSLESProvider.cpp @@ -16,7 +16,7 @@ #undef LOG_ENABLED PRLogModuleInfo *gOpenSLESProviderLog; #define LOG(args) PR_LOG(gOpenSLESProviderLog, PR_LOG_DEBUG, args) -#define LOG_ENABLED() PR_LOG_TEST(gLoadManagerLog, 5) +#define LOG_ENABLED() PR_LOG_TEST(gOpenSLESProviderLog, PR_LOG_DEBUG) namespace mozilla { diff --git a/dom/media/webm/WebMReader.cpp b/dom/media/webm/WebMReader.cpp index 4f5f3e7fd26b..7eef952d5127 100644 --- a/dom/media/webm/WebMReader.cpp +++ b/dom/media/webm/WebMReader.cpp @@ -105,6 +105,10 @@ static void webm_log(nestegg * context, unsigned int severity, char const * format, ...) { + if (!PR_LOG_TEST(gNesteggLog, PR_LOG_DEBUG)) { + return; + } + va_list args; char msg[256]; const char * sevStr; diff --git a/dom/media/webrtc/MediaEngineCameraVideoSource.cpp b/dom/media/webrtc/MediaEngineCameraVideoSource.cpp index 2420b222250c..d8b86dc1c803 100644 --- a/dom/media/webrtc/MediaEngineCameraVideoSource.cpp +++ b/dom/media/webrtc/MediaEngineCameraVideoSource.cpp @@ -218,14 +218,16 @@ MediaEngineCameraVideoSource::ChooseCapability( const dom::MediaTrackConstraints &aConstraints, const MediaEnginePrefs &aPrefs) { - LOG(("ChooseCapability: prefs: %dx%d @%d-%dfps", - aPrefs.GetWidth(), aPrefs.GetHeight(), - aPrefs.mFPS, aPrefs.mMinFPS)); - LogConstraints(aConstraints, false); - if (aConstraints.mAdvanced.WasPassed()) { - LOG(("Advanced array[%u]:", aConstraints.mAdvanced.Value().Length())); - for (auto& advanced : aConstraints.mAdvanced.Value()) { - LogConstraints(advanced, true); + if (PR_LOG_TEST(GetMediaManagerLog(), PR_LOG_DEBUG)) { + LOG(("ChooseCapability: prefs: %dx%d @%d-%dfps", + aPrefs.GetWidth(), aPrefs.GetHeight(), + aPrefs.mFPS, aPrefs.mMinFPS)); + LogConstraints(aConstraints, false); + if (aConstraints.mAdvanced.WasPassed()) { + LOG(("Advanced array[%u]:", aConstraints.mAdvanced.Value().Length())); + for (auto& advanced : aConstraints.mAdvanced.Value()) { + LogConstraints(advanced, true); + } } } diff --git a/dom/media/webrtc/MediaEngineWebRTCAudio.cpp b/dom/media/webrtc/MediaEngineWebRTCAudio.cpp index f16394ecc6e3..9da8f97f31f7 100644 --- a/dom/media/webrtc/MediaEngineWebRTCAudio.cpp +++ b/dom/media/webrtc/MediaEngineWebRTCAudio.cpp @@ -275,7 +275,7 @@ MediaEngineWebRTCAudioSource::Allocate(const dom::MediaTrackConstraints &aConstr LOG(("Audio device is not initalized")); return NS_ERROR_FAILURE; } - } else { + } else if (PR_LOG_TEST(GetMediaManagerLog(), PR_LOG_DEBUG)) { MonitorAutoLock lock(mMonitor); if (mSources.IsEmpty()) { LOG(("Audio device %d reallocated", mCapIndex)); diff --git a/dom/media/webrtc/MediaEngineWebRTCVideo.cpp b/dom/media/webrtc/MediaEngineWebRTCVideo.cpp index ceb12db22211..72dd343f91ff 100644 --- a/dom/media/webrtc/MediaEngineWebRTCVideo.cpp +++ b/dom/media/webrtc/MediaEngineWebRTCVideo.cpp @@ -227,7 +227,7 @@ MediaEngineWebRTCVideoSource::Allocate(const dom::MediaTrackConstraints &aConstr } mState = kAllocated; LOG(("Video device %d allocated", mCaptureIndex)); - } else { + } else if (PR_LOG_TEST(GetMediaManagerLog(), PR_LOG_DEBUG)) { MonitorAutoLock lock(mMonitor); if (mSources.IsEmpty()) { LOG(("Video device %d reallocated", mCaptureIndex));