From 225789d0670caf4742ba22b3a941df28d046ee4c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Peter=20Bostr=C3=B6m?= Date: Fri, 23 Oct 2015 15:20:56 +0200 Subject: [PATCH] Move logging CriticalSection into implementation. Prevents including platform headers from all files that include logging. Also removes warn_slow_logs_delay_ which adds contention to the logging critical section. BUG= R=tommi@webrtc.org Review URL: https://codereview.webrtc.org/1416373004 . Cr-Commit-Position: refs/heads/master@{#10388} --- webrtc/base/logging.cc | 59 +++++++++++++++++++----------------------- webrtc/base/logging.h | 14 +++------- 2 files changed, 29 insertions(+), 44 deletions(-) diff --git a/webrtc/base/logging.cc b/webrtc/base/logging.cc index b60a244429..b02be27e33 100644 --- a/webrtc/base/logging.cc +++ b/webrtc/base/logging.cc @@ -37,6 +37,7 @@ static const char kLibjingle[] = "libjingle"; #include #include +#include "webrtc/base/criticalsection.h" #include "webrtc/base/logging.h" #include "webrtc/base/platform_thread.h" #include "webrtc/base/scoped_ptr.h" @@ -100,23 +101,27 @@ LoggingSeverity LogMessage::dbg_sev_ = LS_NONE; #endif // !_DEBUG bool LogMessage::log_to_stderr_ = true; +namespace { // Global lock for log subsystem, only needed to serialize access to streams_. -CriticalSection LogMessage::crit_; +CriticalSection g_log_crit; +} // namespace // The list of logging streams currently configured. // Note: we explicitly do not clean this up, because of the uncertain ordering // of destructors at program exit. Let the person who sets the stream trigger // cleanup by setting to NULL, or let it leak (safe at program exit). -LogMessage::StreamList LogMessage::streams_ GUARDED_BY(LogMessage::crit_); +LogMessage::StreamList LogMessage::streams_ GUARDED_BY(g_log_crit); // Boolean options default to false (0) bool LogMessage::thread_, LogMessage::timestamp_; -LogMessage::LogMessage(const char* file, int line, LoggingSeverity sev, - LogErrorContext err_ctx, int err, const char* module) - : severity_(sev), - tag_(kLibjingle), - warn_slow_logs_delay_(WARN_SLOW_LOGS_DELAY) { +LogMessage::LogMessage(const char* file, + int line, + LoggingSeverity sev, + LogErrorContext err_ctx, + int err, + const char* module) + : severity_(sev), tag_(kLibjingle) { if (timestamp_) { uint32_t time = TimeSince(LogStartTime()); // Also ensure WallClockStartTime is initialized, so that it matches @@ -197,24 +202,12 @@ LogMessage::~LogMessage() { OutputToDebug(str, severity_, tag_); } - uint32_t before = Time(); - // Must lock streams_ before accessing - CritScope cs(&crit_); - for (StreamList::iterator it = streams_.begin(); it != streams_.end(); ++it) { - if (severity_ >= it->second) { - it->first->OnLogMessage(str); + CritScope cs(&g_log_crit); + for (auto& kv : streams_) { + if (severity_ >= kv.second) { + kv.first->OnLogMessage(str); } } - uint32_t delay = TimeSince(before); - if (delay >= warn_slow_logs_delay_) { - rtc::LogMessage slow_log_warning(__FILE__, __LINE__, LS_WARNING); - // If our warning is slow, we don't want to warn about it, because - // that would lead to inifinite recursion. So, give a really big - // number for the delay threshold. - slow_log_warning.warn_slow_logs_delay_ = UINT_MAX; - slow_log_warning.stream() << "Slow log: took " << delay << "ms to write " - << str.size() << " bytes."; - } } uint32_t LogMessage::LogStartTime() { @@ -237,7 +230,7 @@ void LogMessage::LogTimestamps(bool on) { void LogMessage::LogToDebug(LoggingSeverity min_sev) { dbg_sev_ = min_sev; - CritScope cs(&crit_); + CritScope cs(&g_log_crit); UpdateMinLogSeverity(); } @@ -246,24 +239,24 @@ void LogMessage::SetLogToStderr(bool log_to_stderr) { } int LogMessage::GetLogToStream(LogSink* stream) { - CritScope cs(&crit_); + CritScope cs(&g_log_crit); LoggingSeverity sev = LS_NONE; - for (StreamList::iterator it = streams_.begin(); it != streams_.end(); ++it) { - if (!stream || stream == it->first) { - sev = std::min(sev, it->second); + for (auto& kv : streams_) { + if (!stream || stream == kv.first) { + sev = std::min(sev, kv.second); } } return sev; } void LogMessage::AddLogToStream(LogSink* stream, LoggingSeverity min_sev) { - CritScope cs(&crit_); + CritScope cs(&g_log_crit); streams_.push_back(std::make_pair(stream, min_sev)); UpdateMinLogSeverity(); } void LogMessage::RemoveLogToStream(LogSink* stream) { - CritScope cs(&crit_); + CritScope cs(&g_log_crit); for (StreamList::iterator it = streams_.begin(); it != streams_.end(); ++it) { if (stream == it->first) { streams_.erase(it); @@ -335,10 +328,10 @@ void LogMessage::ConfigureLogging(const char* params) { LogToDebug(debug_level); } -void LogMessage::UpdateMinLogSeverity() EXCLUSIVE_LOCKS_REQUIRED(crit_) { +void LogMessage::UpdateMinLogSeverity() EXCLUSIVE_LOCKS_REQUIRED(g_log_crit) { LoggingSeverity min_sev = dbg_sev_; - for (StreamList::iterator it = streams_.begin(); it != streams_.end(); ++it) { - min_sev = std::min(dbg_sev_, it->second); + for (auto& kv : streams_) { + min_sev = std::min(dbg_sev_, kv.second); } min_sev_ = min_sev; } diff --git a/webrtc/base/logging.h b/webrtc/base/logging.h index 71c6c53482..1208275a34 100644 --- a/webrtc/base/logging.h +++ b/webrtc/base/logging.h @@ -54,8 +54,9 @@ #include #include #include + #include "webrtc/base/basictypes.h" -#include "webrtc/base/criticalsection.h" +#include "webrtc/base/constructormagic.h" #include "webrtc/base/thread_annotations.h" namespace rtc { @@ -131,8 +132,6 @@ class LogSink { class LogMessage { public: - static const uint32_t WARN_SLOW_LOGS_DELAY = 50; // ms - LogMessage(const char* file, int line, LoggingSeverity sev, LogErrorContext err_ctx = ERRCTX_NONE, int err = 0, const char* module = NULL); @@ -196,7 +195,7 @@ class LogMessage { typedef std::list StreamList; // Updates min_sev_ appropriately when debug sinks change. - static void UpdateMinLogSeverity() EXCLUSIVE_LOCKS_REQUIRED(crit_); + static void UpdateMinLogSeverity(); // These write out the actual log messages. static void OutputToDebug(const std::string& msg, @@ -216,13 +215,6 @@ class LogMessage { // the message before output. std::string extra_; - // If time it takes to write to stream is more than this, log one - // additional warning about it. - uint32_t warn_slow_logs_delay_; - - // Global lock for the logging subsystem - static CriticalSection crit_; - // dbg_sev_ is the thresholds for those output targets // min_sev_ is the minimum (most verbose) of those levels, and is used // as a short-circuit in the logging macros to identify messages that won't