Move a debug string util to syncer proto util. Add better getupdates logging in debug builds.

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

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

6 files changed, 59 insertions, 27 deletions

diff --git a/chrome/browser/sync/engine/download_updates_command.cc b/chrome/browser/sync/engine/download_updates_command.cc
index 0dd198d..c7ad790e 100644
--- a/chrome/browser/sync/engine/download_updates_command.cc
+++ b/chrome/browser/sync/engine/download_updates_command.cc
@@ -61,6 +61,9 @@ void DownloadUpdatesCommand::ExecuteImpl(SyncSession* session) {
       &update_response,
       session);
 
+  DLOG(INFO) << SyncerProtoUtil::ClientToServerResponseDebugString(
+      update_response);
+
   StatusController* status = session->status_controller();
   if (!ok) {
     status->increment_num_consecutive_errors();
diff --git a/chrome/browser/sync/engine/syncer.cc b/chrome/browser/sync/engine/syncer.cc
index 59dbae4..d6656b5 100755
--- a/chrome/browser/sync/engine/syncer.cc
+++ b/chrome/browser/sync/engine/syncer.cc
@@ -4,7 +4,6 @@
 
 #include "chrome/browser/sync/engine/syncer.h"
 
-#include "base/format_macros.h"
 #include "base/message_loop.h"
 #include "base/time.h"
 #include "chrome/browser/chrome_thread.h"
@@ -310,20 +309,4 @@ void ClearServerData(syncable::MutableEntry* entry) {
   entry->Put(SERVER_POSITION_IN_PARENT, 0);
 }
 
-std::string SyncEntityDebugString(const sync_pb::SyncEntity& entry) {
-  return StringPrintf("id: %s, parent_id: %s, "
-                      "version: %"PRId64"d, "
-                      "mtime: %" PRId64"d (client: %" PRId64"d), "
-                      "ctime: %" PRId64"d (client: %" PRId64"d), "
-                      "name: %s, sync_timestamp: %" PRId64"d, "
-                      "%s ",
-                      entry.id_string().c_str(),
-                      entry.parent_id_string().c_str(),
-                      entry.version(),
-                      entry.mtime(), ServerTimeToClientTime(entry.mtime()),
-                      entry.ctime(), ServerTimeToClientTime(entry.ctime()),
-                      entry.name().c_str(), entry.sync_timestamp(),
-                      entry.deleted() ? "deleted, ":"");
-}
-
 }  // namespace browser_sync
diff --git a/chrome/browser/sync/engine/syncer.h b/chrome/browser/sync/engine/syncer.h
index 9830170..7daed36 100755
--- a/chrome/browser/sync/engine/syncer.h
+++ b/chrome/browser/sync/engine/syncer.h
@@ -201,10 +201,6 @@ bool SortedCollectionsIntersect(Iterator1 begin1, Iterator1 end1,
 void CopyServerFields(syncable::Entry* src, syncable::MutableEntry* dest);
 void ClearServerData(syncable::MutableEntry* entry);
 
-// Get update contents as a string. Intended for logging, and intended
-// to have a smaller footprint than the protobuf's built-in pretty printer.
-std::string SyncEntityDebugString(const sync_pb::SyncEntity& entry);
-
 }  // namespace browser_sync
 
 #endif  // CHROME_BROWSER_SYNC_ENGINE_SYNCER_H_
diff --git a/chrome/browser/sync/engine/syncer_proto_util.cc b/chrome/browser/sync/engine/syncer_proto_util.cc
index 513b471..4a63da6 100755
--- a/chrome/browser/sync/engine/syncer_proto_util.cc
+++ b/chrome/browser/sync/engine/syncer_proto_util.cc
@@ -4,6 +4,8 @@
 
 #include "chrome/browser/sync/engine/syncer_proto_util.h"
 
+#include "base/format_macros.h"
+#include "base/string_util.h"
 #include "chrome/browser/sync/engine/auth_watcher.h"
 #include "chrome/browser/sync/engine/net/server_connection_manager.h"
 #include "chrome/browser/sync/engine/syncer.h"
@@ -304,5 +306,45 @@ const std::string& SyncerProtoUtil::NameFromCommitEntryResponse(
 
   return entry.name();
 }
+

+std::string SyncerProtoUtil::SyncEntityDebugString(

+    const sync_pb::SyncEntity& entry) {

+  return StringPrintf("id: %s, parent_id: %s, "

+                      "version: %"PRId64"d, "

+                      "mtime: %" PRId64"d (client: %" PRId64"d), "

+                      "ctime: %" PRId64"d (client: %" PRId64"d), "

+                      "name: %s, sync_timestamp: %" PRId64"d, "

+                      "%s ",

+                      entry.id_string().c_str(),

+                      entry.parent_id_string().c_str(),

+                      entry.version(),

+                      entry.mtime(), ServerTimeToClientTime(entry.mtime()),

+                      entry.ctime(), ServerTimeToClientTime(entry.ctime()),

+                      entry.name().c_str(), entry.sync_timestamp(),

+                      entry.deleted() ? "deleted, ":"");

+}
+
+namespace {
+std::string GetUpdatesResponseString(
+    const sync_pb::GetUpdatesResponse& response) {
+  std::string output;
+  output.append("GetUpdatesResponse:\n");
+  for (int i = 0; i < response.entries_size(); i++) {
+    output.append(SyncerProtoUtil::SyncEntityDebugString(response.entries(i)));
+    output.append("\n");
+  }
+  return output;
+}
+}  // namespace
+
+std::string SyncerProtoUtil::ClientToServerResponseDebugString(
+    const sync_pb::ClientToServerResponse& response) {
+  // Add more handlers as needed.
+  std::string output;
+  if (response.has_get_updates()) {
+    output.append(GetUpdatesResponseString(response.get_updates()));
+  }
+  return output;
+}
 
 }  // namespace browser_sync
diff --git a/chrome/browser/sync/engine/syncer_proto_util.h b/chrome/browser/sync/engine/syncer_proto_util.h
index 9a5e363..1422b83 100755
--- a/chrome/browser/sync/engine/syncer_proto_util.h
+++ b/chrome/browser/sync/engine/syncer_proto_util.h
@@ -79,6 +79,14 @@ class SyncerProtoUtil {
   static void AddToEntitySpecificDatatypesFilter(syncable::ModelType datatype,
       sync_pb::EntitySpecifics* filter);
 
+  // Get a debug string representation of the client to server response.
+  static std::string ClientToServerResponseDebugString(
+      const sync_pb::ClientToServerResponse& response);
+
+  // Get update contents as a string. Intended for logging, and intended
+  // to have a smaller footprint than the protobuf's built-in pretty printer.
+  static std::string SyncEntityDebugString(const sync_pb::SyncEntity& entry);
+
  private:
   SyncerProtoUtil() {}
 
diff --git a/chrome/browser/sync/engine/syncer_util.cc b/chrome/browser/sync/engine/syncer_util.cc
index 6ade37b..66fc52f 100755
--- a/chrome/browser/sync/engine/syncer_util.cc
+++ b/chrome/browser/sync/engine/syncer_util.cc
@@ -705,7 +705,7 @@ VerifyResult SyncerUtil::VerifyUpdateConsistency(
       } else {
         LOG(ERROR) << "Server update doesn't agree with previous updates. ";
         LOG(ERROR) << " Entry: " << *same_id;
-        LOG(ERROR) << " Update: " << SyncEntityDebugString(entry);
+        LOG(ERROR) << " Update: " << SyncerProtoUtil::SyncEntityDebugString(entry);
         return VERIFY_FAIL;
       }
     }
@@ -731,7 +731,7 @@ VerifyResult SyncerUtil::VerifyUpdateConsistency(
         model_type != same_id->GetModelType()) {
       LOG(ERROR) << "Server update doesn't agree with committed item. ";
       LOG(ERROR) << " Entry: " << *same_id;
-      LOG(ERROR) << " Update: " << SyncEntityDebugString(entry);
+      LOG(ERROR) << " Update: " << SyncerProtoUtil::SyncEntityDebugString(entry);
       return VERIFY_FAIL;
     }
     if (same_id->Get(BASE_VERSION) == entry.version() &&
@@ -741,13 +741,13 @@ VerifyResult SyncerUtil::VerifyUpdateConsistency(
       // fail the verification and deal with it when we ApplyUpdates.
       LOG(ERROR) << "Server update doesn't match local data with same "
           "version. A bug should be filed. Entry: " << *same_id <<
-          "Update: " << SyncEntityDebugString(entry);
+          "Update: " << SyncerProtoUtil::SyncEntityDebugString(entry);
       return VERIFY_FAIL;
     }
     if (same_id->Get(SERVER_VERSION) > entry.version()) {
       LOG(WARNING) << "We've already seen a more recent update from the server";
       LOG(WARNING) << " Entry: " << *same_id;
-      LOG(WARNING) << " Update: " << SyncEntityDebugString(entry);
+      LOG(WARNING) << " Update: " << SyncerProtoUtil::SyncEntityDebugString(entry);
       return VERIFY_SKIP;
     }
   }
@@ -762,7 +762,7 @@ VerifyResult SyncerUtil::VerifyUndelete(syncable::WriteTransaction* trans,
                                         syncable::MutableEntry* same_id) {
   CHECK(same_id->good());
   LOG(INFO) << "Server update is attempting undelete. " << *same_id
-            << "Update:" << SyncEntityDebugString(entry);
+            << "Update:" << SyncerProtoUtil::SyncEntityDebugString(entry);
   // Move the old one aside and start over.  It's too tricky to get the old one
   // back into a state that would pass CheckTreeInvariants().
   if (same_id->Get(IS_DEL)) {
@@ -774,7 +774,7 @@ VerifyResult SyncerUtil::VerifyUndelete(syncable::WriteTransaction* trans,
   }
   if (entry.version() < same_id->Get(SERVER_VERSION)) {
     LOG(WARNING) << "Update older than current server version for" <<
-        *same_id << "Update:" << SyncEntityDebugString(entry);
+        *same_id << "Update:" << SyncerProtoUtil::SyncEntityDebugString(entry);
     return VERIFY_SUCCESS;  // Expected in new sync protocol.
   }
   return VERIFY_UNDECIDED;