Restore severity precondition to logging.h.

I mistakenly ommitted the checks when logging.h was ported from
libjingle to webrtc. This caused a significant CPU cost for logs which
were later filtered out anyway.

Verified with LS_VERBOSE logging in neteq4, running:
$ out/Release/modules_unittests \
--gtest_filter=NetEqDecodingTest.TestBitExactness \
--gtest_repeat=50 > time.txt
$ grep "case ran" time.txt | grep "[0-9]* ms" -o | sort

Results on a MacBook Retina, averaged over 5 runs:
Verbose logs disabled:                          666 ms
Exisiting implementation, verbose logs enabled: 944 ms (1.42x)
New implementation, verbose logs enabled:       673 ms (1.01x)

BUG=2314
R=henrik.lundin@webrtc.org, henrike@webrtc.org, kjellander@webrtc.org, turaj@webrtc.org

Review URL: https://webrtc-codereview.appspot.com/2160005

git-svn-id: http://webrtc.googlecode.com/svn/trunk@4682 4adac7df-926f-26a2-2b94-8c16560cd09d

talk/app/webrtc/java/jni/peerconnection_jni.cc

@@ -1154,8 +1154,7 @@ JOW(void, Logging_nativeEnableTracing)(
   if (nativeLevels != webrtc::kTraceNone) {
     CHECK(!webrtc::Trace::SetTraceFile(path.c_str(), false),
           "SetTraceFile failed");
-    CHECK(!webrtc::Trace::SetLevelFilter(nativeLevels),
-          "SetLevelFilter failed");
+    webrtc::Trace::set_level_filter(nativeLevels);
   }
   talk_base::LogMessage::LogToDebug(nativeSeverity);
 }

tools/valgrind-webrtc/tsan/suppressions.txt

@@ -48,12 +48,19 @@
   fun:__tz*
 }
 {
-  don't care about issues in trace functions
+  Don't care about issues in trace functions
   ThreadSanitizer:Race
   ...
   fun:webrtc::Trace::Add
   ...
 }
+{
+  More not caring about issues in trace functions
+  ThreadSanitizer:Race
+  ...
+  fun:webrtc::Trace::set_level_filter
+  ...
+}
 {
   Test posix socket HasIncoming
   ThreadSanitizer:Race

webrtc/modules/audio_coding/neteq4/tools/neteq_rtpplay.cc

@@ -145,7 +145,7 @@ int main(int argc, char* argv[]) {
   webrtc::Trace::CreateTrace();
   webrtc::Trace::SetTraceFile((webrtc::test::OutputPath() +
       "neteq_trace.txt").c_str());
-  webrtc::Trace::SetLevelFilter(webrtc::kTraceAll);
+  webrtc::Trace::set_level_filter(webrtc::kTraceAll);
 
   // Initialize NetEq instance.
   int sample_rate_hz = 16000;

webrtc/modules/rtp_rtcp/test/BWEStandAlone/BWEStandAlone.cc

@@ -97,7 +97,7 @@ int main(int argc, char* argv[])
 
     Trace::CreateTrace();
     Trace::SetTraceFile("BWEStandAloneTrace.txt");
-    Trace::SetLevelFilter(webrtc::kTraceAll);
+    Trace::set_level_filter(webrtc::kTraceAll);
 
     sendrec->InitReceiver(port);
 

webrtc/modules/video_coding/main/test/decode_from_storage_test.cc

@@ -33,7 +33,7 @@ int DecodeFromStorageTest(const CmdArgs& args) {
       "decodeFromStorageTestTrace.txt";
   webrtc::Trace::CreateTrace();
   webrtc::Trace::SetTraceFile(trace_file.c_str());
-  webrtc::Trace::SetLevelFilter(webrtc::kTraceAll);
+  webrtc::Trace::set_level_filter(webrtc::kTraceAll);
 
   webrtc::rtpplayer::PayloadTypes payload_types;
   payload_types.push_back(webrtc::rtpplayer::PayloadCodecTuple(

webrtc/modules/video_coding/main/test/generic_codec_test.cc

@@ -34,7 +34,7 @@ int GenericCodecTest::RunTest(CmdArgs& args)
     Trace::CreateTrace();
     Trace::SetTraceFile(
         (test::OutputPath() + "genericCodecTestTrace.txt").c_str());
-    Trace::SetLevelFilter(webrtc::kTraceAll);
+    Trace::set_level_filter(webrtc::kTraceAll);
     get->Perform(args);
     Trace::ReturnTrace();
     delete get;

webrtc/modules/video_coding/main/test/media_opt_test.cc

@@ -31,7 +31,7 @@ int MediaOptTest::RunTest(int testNum, CmdArgs& args)
 {
     Trace::CreateTrace();
     Trace::SetTraceFile((test::OutputPath() + "mediaOptTestTrace.txt").c_str());
-    Trace::SetLevelFilter(webrtc::kTraceAll);
+    Trace::set_level_filter(webrtc::kTraceAll);
     VideoCodingModule* vcm = VideoCodingModule::Create(1);
     Clock* clock = Clock::GetRealTimeClock();
     MediaOptTest* mot = new MediaOptTest(vcm, clock);

webrtc/modules/video_coding/main/test/mt_rx_tx_test.cc

@@ -129,7 +129,7 @@ int MTRxTxTest(CmdArgs& args)
     // Set up trace
     Trace::CreateTrace();
     Trace::SetTraceFile((test::OutputPath() + "MTRxTxTestTrace.txt").c_str());
-    Trace::SetLevelFilter(webrtc::kTraceAll);
+    Trace::set_level_filter(webrtc::kTraceAll);
 
     FILE* sourceFile;
     FILE* decodedFile;

webrtc/modules/video_coding/main/test/normal_test.cc

@@ -36,7 +36,7 @@ int NormalTest::RunTest(const CmdArgs& args)
     Trace::CreateTrace();
     Trace::SetTraceFile(
         (test::OutputPath() + "VCMNormalTestTrace.txt").c_str());
-    Trace::SetLevelFilter(webrtc::kTraceAll);
+    Trace::set_level_filter(webrtc::kTraceAll);
     VideoCodingModule* vcm = VideoCodingModule::Create(1, clock,
                                                        &event_factory);
     NormalTest VCMNTest(vcm, clock);

webrtc/modules/video_coding/main/test/video_rtp_play.cc

@@ -31,7 +31,7 @@ int RtpPlay(const CmdArgs& args) {
   std::string trace_file = webrtc::test::OutputPath() + "receiverTestTrace.txt";
   webrtc::Trace::CreateTrace();
   webrtc::Trace::SetTraceFile(trace_file.c_str());
-  webrtc::Trace::SetLevelFilter(webrtc::kTraceAll);
+  webrtc::Trace::set_level_filter(webrtc::kTraceAll);
 
   webrtc::rtpplayer::PayloadTypes payload_types;
   payload_types.push_back(webrtc::rtpplayer::PayloadCodecTuple(

webrtc/modules/video_coding/main/test/video_rtp_play_mt.cc

@@ -67,7 +67,7 @@ int RtpPlayMT(const CmdArgs& args) {
   std::string trace_file = webrtc::test::OutputPath() + "receiverTestTrace.txt";
   webrtc::Trace::CreateTrace();
   webrtc::Trace::SetTraceFile(trace_file.c_str());
-  webrtc::Trace::SetLevelFilter(webrtc::kTraceAll);
+  webrtc::Trace::set_level_filter(webrtc::kTraceAll);
 
   webrtc::rtpplayer::PayloadTypes payload_types;
   payload_types.push_back(webrtc::rtpplayer::PayloadCodecTuple(

webrtc/system_wrappers/interface/logging.h

@@ -76,6 +76,7 @@ class LogMessage {
   LogMessage(const char* file, int line, LoggingSeverity sev);
   ~LogMessage();
 
+  static bool Loggable(LoggingSeverity sev);
   std::ostream& stream() { return print_stream_; }
 
  private:
@@ -108,12 +109,19 @@ class LogMessageVoidify {
   void operator&(std::ostream&) { }
 };
 
+#define LOG_SEVERITY_PRECONDITION(sev) \
+  !(webrtc::LogMessage::Loggable(sev)) \
+    ? (void) 0 \
+    : webrtc::LogMessageVoidify() &
+
 #define LOG(sev) \
+  LOG_SEVERITY_PRECONDITION(webrtc::sev) \
     webrtc::LogMessage(__FILE__, __LINE__, webrtc::sev).stream()
 
 // The _V version is for when a variable is passed in.  It doesn't do the
 // namespace concatination.
 #define LOG_V(sev) \
+  LOG_SEVERITY_PRECONDITION(sev) \
     webrtc::LogMessage(__FILE__, __LINE__, sev).stream()
 
 // The _F version prefixes the message with the current function name.

webrtc/system_wrappers/interface/trace.h

@@ -48,10 +48,10 @@ class Trace {
   // filter parameter is a bitmask where each message type is enumerated by the
   // TraceLevel enumerator. TODO(hellner): why is the TraceLevel enumerator not
   // defined in this file?
-  static int32_t SetLevelFilter(const uint32_t filter);
+  static void set_level_filter(uint32_t filter) { level_filter_ = filter; }
 
   // Returns what type of messages are written to the trace file.
-  static int32_t LevelFilter(uint32_t& filter);
+  static uint32_t level_filter() { return level_filter_; }
 
   // Sets the file name. If add_file_counter is false the same file will be
   // reused when it fills up. If it's true a new file with incremented name
@@ -81,6 +81,9 @@ class Trace {
                   const TraceModule module,
                   const int32_t id,
                   const char* msg, ...);
+
+ private:
+  static uint32_t level_filter_;
 };
 
 }  // namespace webrtc

webrtc/system_wrappers/source/logging.cc

@@ -22,7 +22,7 @@ namespace {
 
 TraceLevel WebRtcSeverity(LoggingSeverity sev) {
   switch (sev) {
-    // TODO(andrew): SENSITIVE doesn't have a corresponding webrtc level.
+    // TODO(ajm): SENSITIVE doesn't have a corresponding webrtc level.
     case LS_SENSITIVE:  return kTraceInfo;
     case LS_VERBOSE:    return kTraceInfo;
     case LS_INFO:       return kTraceTerseInfo;
@@ -48,6 +48,11 @@ LogMessage::LogMessage(const char* file, int line, LoggingSeverity sev)
   print_stream_ << "(" << DescribeFile(file) << ":" << line << "): ";
 }
 
+bool LogMessage::Loggable(LoggingSeverity sev) {
+  // |level_filter| is a bitmask, unlike libjingle's minimum severity value.
+  return WebRtcSeverity(sev) & Trace::level_filter() ? true : false;
+}
+
 LogMessage::~LogMessage() {
   const std::string& str = print_stream_.str();
   WEBRTC_TRACE(WebRtcSeverity(severity_), kTraceUndefined, 0, str.c_str());

webrtc/system_wrappers/source/logging_unittest.cc

@@ -47,7 +47,7 @@ class LoggingTest : public ::testing::Test, public TraceCallback {
     Trace::CreateTrace();
     Trace::SetTraceCallback(this);
     // Reduce the chance that spurious traces will ruin the test.
-    Trace::SetLevelFilter(kTraceWarning | kTraceError);
+    Trace::set_level_filter(kTraceWarning | kTraceError);
   }
 
   void TearDown() {

webrtc/system_wrappers/source/trace_impl.cc

@@ -34,8 +34,7 @@ namespace webrtc {
 const int Trace::kBoilerplateLength = 71;
 const int Trace::kTimestampPosition = 13;
 const int Trace::kTimestampLength = 12;
-
-static uint32_t level_filter = kTraceDefault;
+uint32_t Trace::level_filter_ = kTraceDefault;
 
 // Construct On First Use idiom. Avoids "static initialization order fiasco".
 TraceImpl* TraceImpl::StaticInstance(CountOperation count_operation,
@@ -44,7 +43,7 @@ TraceImpl* TraceImpl::StaticInstance(CountOperation count_operation,
   // performance reasons). count_operation == kAddRefNoCreate implies that a
   // message will be written to file.
   if ((level != kTraceAll) && (count_operation == kAddRefNoCreate)) {
-    if (!(level & level_filter)) {
+    if (!(level & level_filter())) {
       return NULL;
     }
   }
@@ -624,7 +623,7 @@ void TraceImpl::AddImpl(const TraceLevel level, const TraceModule module,
 }
 
 bool TraceImpl::TraceCheck(const TraceLevel level) const {
-  return (level & level_filter) ? true : false;
+  return (level & level_filter()) ? true : false;
 }
 
 bool TraceImpl::UpdateFileName(
@@ -699,16 +698,6 @@ void Trace::ReturnTrace() {
   TraceImpl::StaticInstance(kRelease);
 }
 
-int32_t Trace::SetLevelFilter(uint32_t filter) {
-  level_filter = filter;
-  return 0;
-}
-
-int32_t Trace::LevelFilter(uint32_t& filter) {
-  filter = level_filter;
-  return 0;
-}
-
 int32_t Trace::TraceFile(char file_name[FileWrapper::kMaxFileNameSize]) {
   TraceImpl* trace = TraceImpl::GetTrace();
   if (trace) {

webrtc/system_wrappers/source/trace_impl_no_op.cc

@@ -15,6 +15,7 @@ namespace webrtc {
 const int Trace::kBoilerplateLength = 71;
 const int Trace::kTimestampPosition = 13;
 const int Trace::kTimestampLength = 12;
+uint32_t Trace::level_filter_ = kTraceNone;
 
 void Trace::CreateTrace() {
 }
@@ -22,14 +23,6 @@ void Trace::CreateTrace() {
 void Trace::ReturnTrace() {
 }
 
-int32_t Trace::SetLevelFilter(uint32_t filter) {
-  return 0;
-}
-
-int32_t Trace::LevelFilter(uint32_t& filter) {
-  return 0;
-}
-
 int32_t Trace::TraceFile(char file_name[1024]) {
   return -1;
 }

webrtc/system_wrappers/source/unittest_utilities.h

@@ -60,7 +60,7 @@ class ScopedTracing {
   void StartTrace() {
     if (logging_) {
       Trace::CreateTrace();
-      Trace::SetLevelFilter(webrtc::kTraceAll);
+      Trace::set_level_filter(webrtc::kTraceAll);
       Trace::SetTraceCallback(&trace_);
     }
   }

webrtc/test/testsupport/trace_to_stderr.cc

@@ -23,17 +23,17 @@ static const int kLevelFilter = kTraceError | kTraceWarning | kTraceTerseInfo;
 TraceToStderr::TraceToStderr()
     : override_time_(false),
       time_seconds_(0) {
+  Trace::set_level_filter(kLevelFilter);
   Trace::CreateTrace();
   Trace::SetTraceCallback(this);
-  Trace::SetLevelFilter(kLevelFilter);
 }
 
 TraceToStderr::TraceToStderr(bool override_time)
     : override_time_(override_time),
       time_seconds_(0) {
+  Trace::set_level_filter(kLevelFilter);
   Trace::CreateTrace();
   Trace::SetTraceCallback(this);
-  Trace::SetLevelFilter(kLevelFilter);
 }
 
 TraceToStderr::~TraceToStderr() {

webrtc/video_engine/vie_impl.cc

@@ -143,8 +143,7 @@ int VideoEngine::SetTraceFile(const char* file_nameUTF8,
 }
 
 int VideoEngine::SetTraceFilter(const unsigned int filter) {
-  uint32_t old_filter = 0;
-  Trace::LevelFilter(old_filter);
+  uint32_t old_filter = Trace::level_filter();
 
   if (filter == kTraceNone && old_filter != kTraceNone) {
     // Do the logging before turning it off.
@@ -152,14 +151,9 @@ int VideoEngine::SetTraceFilter(const unsigned int filter) {
                  "SetTraceFilter(filter = 0x%x)", filter);
   }
 
-  int32_t error = Trace::SetLevelFilter(filter);
+  Trace::set_level_filter(filter);
   WEBRTC_TRACE(kTraceApiCall, kTraceVideo, kModuleId,
                "SetTraceFilter(filter = 0x%x)", filter);
-  if (error != 0) {
-    WEBRTC_TRACE(kTraceError, kTraceVideo, kModuleId,
-                 "SetTraceFilter error: %d", error);
-    return -1;
-  }
   return 0;
 }
 

webrtc/voice_engine/voice_engine_impl.cc

@@ -87,11 +87,8 @@ int VoiceEngine::SetTraceFilter(unsigned int filter)
                  "SetTraceFilter(filter=0x%x)", filter);
 
     // Remember old filter
-    uint32_t oldFilter = 0;
-    Trace::LevelFilter(oldFilter);
-
-    // Set new filter
-    int32_t ret = Trace::SetLevelFilter(filter);
+    uint32_t oldFilter = Trace::level_filter();
+    Trace::set_level_filter(filter);
 
     // If previous log was ignored, log again after changing filter
     if (kTraceNone == oldFilter)
@@ -100,7 +97,7 @@ int VoiceEngine::SetTraceFilter(unsigned int filter)
                      "SetTraceFilter(filter=0x%x)", filter);
     }
 
-    return (ret);
+    return 0;
 }
 
 int VoiceEngine::SetTraceFile(const char* fileNameUTF8,