Cleaned up sync logging.

Pay attention to log levels passed from cache-invalidation library
(converting INFO logs to vlogs).

Converted syncable.cc logs to vlogs.

(Finally) put the "Registration failed with code" errors behind a vlog
check.

BUG=54366
TEST=None

Review URL: http://codereview.chromium.org/3525011

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@61678 0039d316-1c4b-4281-b951-d872f2087c98

3 files changed, 36 insertions, 14 deletions

diff --git a/chrome/browser/sync/notifier/chrome_system_resources.cc b/chrome/browser/sync/notifier/chrome_system_resources.cc
index 21c148c..cc3c8d2 100644
--- a/chrome/browser/sync/notifier/chrome_system_resources.cc
+++ b/chrome/browser/sync/notifier/chrome_system_resources.cc
@@ -5,6 +5,7 @@
 #include "chrome/browser/sync/notifier/chrome_system_resources.h"
 
 #include <cstdlib>
+#include <cstring>
 #include <string>
 
 #include "base/logging.h"
@@ -67,12 +68,29 @@ void ChromeSystemResources::Log(
     LogLevel level, const char* file, int line,
     const char* format, ...) {
   DCHECK(non_thread_safe_.CalledOnValidThread());
-  va_list ap;
-  va_start(ap, format);
-  std::string result;
-  StringAppendV(&result, format, ap);
-  logging::LogMessage(file, line).stream() << result;
-  va_end(ap);
+  logging::LogSeverity log_severity = logging::LOG_INFO;
+  switch (level) {
+    case INFO_LEVEL:
+      log_severity = logging::LOG_INFO;
+      break;
+    case WARNING_LEVEL:
+      log_severity = logging::LOG_WARNING;
+      break;
+    case ERROR_LEVEL:
+      log_severity = logging::LOG_ERROR;
+      break;
+  }
+  // We treat LOG(INFO) as VLOG(1).
+  if ((log_severity >= logging::GetMinLogLevel()) &&
+      ((log_severity != logging::LOG_INFO) ||
+       (1 <= logging::GetVlogLevelHelper(file, ::strlen(file))))) {
+    va_list ap;
+    va_start(ap, format);
+    std::string result;
+    StringAppendV(&result, format, ap);
+    logging::LogMessage(file, line, log_severity).stream() << result;
+    va_end(ap);
+  }
 }
 
 Task* ChromeSystemResources::MakeTaskToPost(
diff --git a/chrome/browser/sync/notifier/registration_manager.cc b/chrome/browser/sync/notifier/registration_manager.cc
index ccadac4..5b98902 100644
--- a/chrome/browser/sync/notifier/registration_manager.cc
+++ b/chrome/browser/sync/notifier/registration_manager.cc
@@ -123,7 +123,9 @@ void RegistrationManager::OnRegister(
       // TODO(akalin): Add retry logic.  For now, just fall through.
     default:
       // Treat everything else as a permanent failure.
-      LOG(ERROR) << "Registration failed with code: " << code;
+      if (VLOG_IS_ON(1)) {
+        LOG(ERROR) << "Registration failed with code: " << code;
+      }
       break;
   }
 }
diff --git a/chrome/browser/sync/syncable/syncable.cc b/chrome/browser/sync/syncable/syncable.cc
index 2d51526..8803859 100644
--- a/chrome/browser/sync/syncable/syncable.cc
+++ b/chrome/browser/sync/syncable/syncable.cc
@@ -19,6 +19,7 @@
 #endif
 
 #include <algorithm>
+#include <cstring>
 #include <functional>
 #include <iomanip>
 #include <iterator>
@@ -955,11 +956,6 @@ ScopedKernelLock::ScopedKernelLock(const Directory* dir)
 
 ///////////////////////////////////////////////////////////////////////////
 // Transactions
-#if defined LOG_ALL || !defined NDEBUG
-static const bool kLoggingInfo = true;
-#else
-static const bool kLoggingInfo = false;
-#endif
 
 void BaseTransaction::Lock() {
   base::TimeTicks start_time = base::TimeTicks::Now();
@@ -968,7 +964,10 @@ void BaseTransaction::Lock() {
 
   time_acquired_ = base::TimeTicks::Now();
   const base::TimeDelta elapsed = time_acquired_ - start_time;
-  if (kLoggingInfo && elapsed.InMilliseconds() > 200) {
+  if (LOG_IS_ON(INFO) &&
+      (1 <= logging::GetVlogLevelHelper(
+          source_file_, ::strlen(source_file_))) &&
+      (elapsed.InMilliseconds() > 200)) {
     logging::LogMessage(source_file_, line_, logging::LOG_INFO).stream()
       << name_ << " transaction waited "
       << elapsed.InSecondsF() << " seconds.";
@@ -1002,7 +1001,10 @@ bool BaseTransaction::NotifyTransactionChangingAndEnding(
 
   scoped_ptr<OriginalEntries> originals(originals_arg);
   const base::TimeDelta elapsed = base::TimeTicks::Now() - time_acquired_;
-  if (kLoggingInfo && elapsed.InMilliseconds() > 50) {
+  if (LOG_IS_ON(INFO) &&
+      (1 <= logging::GetVlogLevelHelper(
+          source_file_, ::strlen(source_file_))) &&
+      (elapsed.InMilliseconds() > 50)) {
     logging::LogMessage(source_file_, line_, logging::LOG_INFO).stream()
         << name_ << " transaction completed in " << elapsed.InSecondsF()
         << " seconds.";