This would allow the developers to view the client/server sync traffic. In retail builds this code would be compiled out. To view the traffic you have to run chrome with the flag:

--vmodule=traffic_logger=1.


BUG=117615
TEST=git-cl try --email=foo


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

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

11 files changed, 423 insertions, 2 deletions

diff --git a/sync/engine/syncer_proto_util.cc b/sync/engine/syncer_proto_util.cc
index c5041d2..b1ed209 100644
--- a/sync/engine/syncer_proto_util.cc
+++ b/sync/engine/syncer_proto_util.cc
@@ -9,6 +9,7 @@
 #include "sync/engine/net/server_connection_manager.h"
 #include "sync/engine/syncer.h"
 #include "sync/engine/syncer_types.h"
+#include "sync/engine/traffic_logger.h"
 #include "sync/protocol/service_constants.h"
 #include "sync/protocol/sync.pb.h"
 #include "sync/protocol/sync_enums.pb.h"
@@ -337,6 +338,7 @@ SyncerError SyncerProtoUtil::PostClientToServerMessage(
 
   syncable::Directory* dir = session->context()->directory();
 
+  LogClientToServerMessage(msg);
   if (!PostAndProcessHeaders(session->context()->connection_manager(), session,
                              msg, response)) {
     // There was an error establishing communication with the server.
@@ -350,6 +352,8 @@ SyncerError SyncerProtoUtil::PostClientToServerMessage(
     return ServerConnectionErrorAsSyncerError(server_status);
   }
 
+  LogClientToServerResponse(*response);
+
   browser_sync::SyncProtocolError sync_protocol_error;
 
   // Birthday mismatch overrides any error that is sent by the server.
diff --git a/sync/engine/syncer_unittest.cc b/sync/engine/syncer_unittest.cc
index 72ec057..9a66d98 100644
--- a/sync/engine/syncer_unittest.cc
+++ b/sync/engine/syncer_unittest.cc
@@ -1027,8 +1027,8 @@ TEST_F(SyncerTest, NigoriConflicts) {
     sync_pb::NigoriSpecifics* nigori = specifics.mutable_nigori();
     cryptographer(&wtrans)->GetKeys(nigori->mutable_encrypted());
     cryptographer(&wtrans)->UpdateNigoriFromEncryptedTypes(nigori);
-    // Normally this would be written as part of SetDecryptionPassphrase, but we
-    // do it manually for the test.
+    // Normally this would be written as part of SetPassphrase, but we do it
+    // manually for the test.
     nigori_entry.Put(SPECIFICS, specifics);
     nigori_entry.Put(IS_UNSYNCED, true);
   }
diff --git a/sync/engine/traffic_logger.cc b/sync/engine/traffic_logger.cc
new file mode 100644
index 0000000..d849e9b
--- /dev/null
+++ b/sync/engine/traffic_logger.cc
@@ -0,0 +1,50 @@
+// Copyright (c) 2012 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "sync/engine/traffic_logger.h"
+
+#include <string>
+
+#include "base/json/json_writer.h"
+#include "base/logging.h"
+#include "base/memory/scoped_ptr.h"
+#include "base/values.h"
+#include "sync/protocol/proto_value_conversions.h"
+#include "sync/protocol/sync.pb.h"
+
+namespace browser_sync {
+
+namespace {
+template <class T>
+void LogData(const T& data,
+             DictionaryValue* (*to_dictionary_value)(const T&, bool),
+             const std::string& description) {
+  if (::logging::DEBUG_MODE && VLOG_IS_ON(1)) {
+    scoped_ptr<DictionaryValue> value(
+        (*to_dictionary_value)(data, true /* include_specifics */));
+    std::string message;
+    base::JSONWriter::WriteWithOptions(value.get(),
+        base::JSONWriter::OPTIONS_PRETTY_PRINT,
+        &message);
+    DVLOG(1) << "\n" << description << "\n" << message << "\n";
+  }
+}
+}  // namespace
+
+void LogClientToServerMessage(const sync_pb::ClientToServerMessage& msg) {
+  LogData(msg, &ClientToServerMessageToValue,
+          "******Client To Server Message******");
+  // TODO(lipalani) : Store the data (minus specifics)
+  // in a circular buffer in memory.
+}
+
+void LogClientToServerResponse(
+    const sync_pb::ClientToServerResponse& response) {
+  LogData(response, &ClientToServerResponseToValue,
+          "******Server Response******");
+  // TODO(lipalani) : Store the data (minus specifics)
+  // in a circular buffer in memory.
+}
+
+}  // namespace browser_sync
diff --git a/sync/engine/traffic_logger.h b/sync/engine/traffic_logger.h
new file mode 100644
index 0000000..5cb8ffa
--- /dev/null
+++ b/sync/engine/traffic_logger.h
@@ -0,0 +1,26 @@
+// Copyright (c) 2012 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+// This file has the functions to log all the sync related HTTP communication.
+// To get the log run a debug build of chrome with the flag
+// --vmodule=traffic_logger=1.
+
+#ifndef CHROME_BROWSER_SYNC_ENGINE_TRAFFIC_LOGGER_H_
+#define CHROME_BROWSER_SYNC_ENGINE_TRAFFIC_LOGGER_H_
+#pragma once
+
+namespace sync_pb {
+class ClientToServerResponse;
+class ClientToServerMessage;
+}  // namespace sync_pb
+
+namespace browser_sync {
+
+void LogClientToServerMessage(const sync_pb::ClientToServerMessage& msg);
+void LogClientToServerResponse(
+    const sync_pb::ClientToServerResponse& response);
+
+}  // namespace browser_sync
+
+#endif  // CHROME_BROWSER_SYNC_ENGINE_TRAFFIC_LOGGER_H_
diff --git a/sync/protocol/proto_enum_conversions.cc b/sync/protocol/proto_enum_conversions.cc
index 47a0016..04bb9ab 100644
--- a/sync/protocol/proto_enum_conversions.cc
+++ b/sync/protocol/proto_enum_conversions.cc
@@ -90,6 +90,59 @@ const char* GetUpdatesSourceString(
   return "";
 }
 
+const char* GetResponseTypeString(
+    sync_pb::CommitResponse::ResponseType response_type) {
+  ASSERT_ENUM_BOUNDS(sync_pb::CommitResponse, ResponseType, SUCCESS,
+                     TRANSIENT_ERROR);
+  switch (response_type) {
+    ENUM_CASE(sync_pb::CommitResponse, SUCCESS);
+    ENUM_CASE(sync_pb::CommitResponse, CONFLICT);
+    ENUM_CASE(sync_pb::CommitResponse, RETRY);
+    ENUM_CASE(sync_pb::CommitResponse, INVALID_MESSAGE);
+    ENUM_CASE(sync_pb::CommitResponse, OVER_QUOTA);
+    ENUM_CASE(sync_pb::CommitResponse, TRANSIENT_ERROR);
+  }
+  NOTREACHED();
+  return "";
+}
+
+const char* GetErrorTypeString(sync_pb::SyncEnums::ErrorType error_type) {
+  ASSERT_ENUM_BOUNDS(sync_pb::SyncEnums, ErrorType, SUCCESS, UNKNOWN);
+  switch (error_type) {
+    ENUM_CASE(sync_pb::SyncEnums, SUCCESS);
+    ENUM_CASE(sync_pb::SyncEnums, ACCESS_DENIED);
+    ENUM_CASE(sync_pb::SyncEnums, NOT_MY_BIRTHDAY);
+    ENUM_CASE(sync_pb::SyncEnums, THROTTLED);
+    ENUM_CASE(sync_pb::SyncEnums, AUTH_EXPIRED);
+    ENUM_CASE(sync_pb::SyncEnums, USER_NOT_ACTIVATED);
+    ENUM_CASE(sync_pb::SyncEnums, AUTH_INVALID);
+    ENUM_CASE(sync_pb::SyncEnums, CLEAR_PENDING);
+    ENUM_CASE(sync_pb::SyncEnums, TRANSIENT_ERROR);
+    ENUM_CASE(sync_pb::SyncEnums, MIGRATION_DONE);
+    ENUM_CASE(sync_pb::SyncEnums, UNKNOWN);
+  }
+  NOTREACHED();
+  return "";
+}
+
+const char* GetActionString(
+   sync_pb::ClientToServerResponse::Error::Action action) {
+  ASSERT_ENUM_BOUNDS(sync_pb::ClientToServerResponse::Error, Action,
+                     UPGRADE_CLIENT, UNKNOWN_ACTION);
+  switch (action) {
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error, UPGRADE_CLIENT);
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error,
+              CLEAR_USER_DATA_AND_RESYNC);
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error, ENABLE_SYNC_ON_ACCOUNT);
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error, STOP_AND_RESTART_SYNC);
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error, DISABLE_SYNC_ON_CLIENT);
+    ENUM_CASE(sync_pb::ClientToServerResponse::Error, UNKNOWN_ACTION);
+  }
+  NOTREACHED();
+  return "";
+
+}
+
 const char* GetDeviceTypeString(
     sync_pb::SessionHeader::DeviceType device_type) {
   ASSERT_ENUM_BOUNDS(sync_pb::SessionHeader, DeviceType, TYPE_WIN, TYPE_TABLET);
diff --git a/sync/protocol/proto_enum_conversions.h b/sync/protocol/proto_enum_conversions.h
index fb8d44b..9f397a4 100644
--- a/sync/protocol/proto_enum_conversions.h
+++ b/sync/protocol/proto_enum_conversions.h
@@ -32,6 +32,14 @@ const char* GetPageTransitionQualifierString(
 const char* GetUpdatesSourceString(
     sync_pb::GetUpdatesCallerInfo::GetUpdatesSource updates_source);
 
+const char* GetResponseTypeString(
+    sync_pb::CommitResponse::ResponseType response_type);
+
+const char* GetErrorTypeString(sync_pb::SyncEnums::ErrorType error_type);
+
+const char* GetActionString(
+   sync_pb::ClientToServerResponse::Error::Action action);
+
 const char* GetDeviceTypeString(
     sync_pb::SessionHeader::DeviceType device_type);
 
diff --git a/sync/protocol/proto_enum_conversions_unittest.cc b/sync/protocol/proto_enum_conversions_unittest.cc
index 2445a30..91498e7 100644
--- a/sync/protocol/proto_enum_conversions_unittest.cc
+++ b/sync/protocol/proto_enum_conversions_unittest.cc
@@ -58,5 +58,32 @@ TEST_F(ProtoEnumConversionsTest, GetUpdatesSourceString) {
       sync_pb::GetUpdatesCallerInfo::GetUpdatesSource_MAX);
 }
 
+TEST_F(ProtoEnumConversionsTest, GetResponseTypeString) {
+  TestEnumStringFunction(
+      GetResponseTypeString,
+      sync_pb::CommitResponse::ResponseType_MIN,
+      sync_pb::CommitResponse::ResponseType_MAX);
+}
+
+TEST_F(ProtoEnumConversionsTest, GetErrorTypeString) {
+  // We have a gap, so we need to do two ranges.
+  TestEnumStringFunction(
+      GetErrorTypeString,
+      sync_pb::SyncEnums::ErrorType_MIN,
+      sync_pb::SyncEnums::MIGRATION_DONE);
+  TestEnumStringFunction(
+      GetErrorTypeString,
+      sync_pb::SyncEnums::UNKNOWN,
+      sync_pb::SyncEnums::ErrorType_MAX);
+
+}
+
+TEST_F(ProtoEnumConversionsTest, GetActionString) {
+  TestEnumStringFunction(
+      GetActionString,
+      sync_pb::ClientToServerResponse::Error::Action_MIN,
+      sync_pb::ClientToServerResponse::Error::Action_MAX);
+}
+
 }  // namespace
 }  // namespace browser_sync
diff --git a/sync/protocol/proto_value_conversions.cc b/sync/protocol/proto_value_conversions.cc
index 009c030..265939e 100644
--- a/sync/protocol/proto_value_conversions.cc
+++ b/sync/protocol/proto_value_conversions.cc
@@ -397,6 +397,184 @@ DictionaryValue* EntitySpecificsToValue(
   return value;
 }
 
+namespace {
+
+DictionaryValue* SyncEntityToValue(const sync_pb::SyncEntity& proto,
+                                   bool include_specifics) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_STR(id_string);
+  SET_STR(parent_id_string);
+  SET_STR(old_parent_id);
+  SET_INT64(version);
+  SET_INT64(mtime);
+  SET_INT64(ctime);
+  SET_STR(name);
+  SET_STR(non_unique_name);
+  SET_INT64(sync_timestamp);
+  SET_STR(server_defined_unique_tag);
+  SET_INT64(position_in_parent);
+  SET_STR(insert_after_item_id);
+  SET_BOOL(deleted);
+  SET_STR(originator_cache_guid);
+  SET_STR(originator_client_item_id);
+  if (include_specifics)
+    SET(specifics, EntitySpecificsToValue);
+  SET_BOOL(folder);
+  SET_STR(client_defined_unique_tag);
+  return value;
+}
+
+ListValue* SyncEntitiesToValue(
+    const ::google::protobuf::RepeatedPtrField<sync_pb::SyncEntity>& entities,
+    bool include_specifics) {
+  ListValue* list = new ListValue();
+  ::google::protobuf::RepeatedPtrField<sync_pb::SyncEntity>::const_iterator it;
+  for (it = entities.begin(); it != entities.end(); ++it) {
+    list->Append(SyncEntityToValue(*it, include_specifics));
+  }
+
+  return list;
+}
+
+DictionaryValue* ChromiumExtensionActivityToValue(
+    const sync_pb::ChromiumExtensionsActivity& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_STR(extension_id);
+  SET_INT32(bookmark_writes_since_last_commit);
+  return value;
+}
+
+DictionaryValue* CommitMessageToValue(
+    const sync_pb::CommitMessage& proto,
+    bool include_specifics) {
+  DictionaryValue* value = new DictionaryValue();
+  value->Set("entries",
+             SyncEntitiesToValue(proto.entries(), include_specifics));
+  SET_STR(cache_guid);
+  SET_REP(extensions_activity, ChromiumExtensionActivityToValue);
+  return value;
+}
+
+DictionaryValue* DataTypeProgressMarkerToValue(
+    const sync_pb::DataTypeProgressMarker& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_INT32(data_type_id);
+  SET_BYTES(token);
+  SET_INT64(timestamp_token_for_migration);
+  SET_STR(notification_hint);
+  return value;
+}
+
+DictionaryValue* GetUpdatesCallerInfoToValue(
+    const sync_pb::GetUpdatesCallerInfo& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_ENUM(source, GetUpdatesSourceString);
+  SET_BOOL(notifications_enabled);
+  return value;
+}
+
+DictionaryValue* GetUpdatesMessageToValue(
+    const sync_pb::GetUpdatesMessage& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET(caller_info, GetUpdatesCallerInfoToValue);
+  SET_BOOL(fetch_folders);
+  SET_INT32(batch_size);
+  SET_REP(from_progress_marker, DataTypeProgressMarkerToValue);
+  SET_BOOL(streaming);
+  SET_BOOL(create_mobile_bookmarks_folder);
+  return value;
+}
+
+DictionaryValue* EntryResponseToValue(
+    const sync_pb::CommitResponse::EntryResponse& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_ENUM(response_type, GetResponseTypeString);
+  SET_STR(id_string);
+  SET_STR(parent_id_string);
+  SET_INT64(position_in_parent);
+  SET_INT64(version);
+  SET_STR(name);
+  SET_STR(error_message);
+  SET_INT64(mtime);
+  return value;
+}
+
+DictionaryValue* CommitResponseToValue(const sync_pb::CommitResponse& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_REP(entryresponse, EntryResponseToValue);
+  return value;
+}
+
+DictionaryValue* GetUpdatesResponseToValue(
+    const sync_pb::GetUpdatesResponse& proto,
+    bool include_specifics) {
+  DictionaryValue* value = new DictionaryValue();
+  value->Set("entries",
+             SyncEntitiesToValue(proto.entries(), include_specifics));
+  SET_INT64(changes_remaining);
+  SET_REP(new_progress_marker, DataTypeProgressMarkerToValue);
+  return value;
+}
+
+DictionaryValue* ClientCommandToValue(const sync_pb::ClientCommand& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_INT32(set_sync_poll_interval);
+  SET_INT32(set_sync_long_poll_interval);
+  SET_INT32(max_commit_batch_size);
+  SET_INT32(sessions_commit_delay_seconds);
+  SET_INT32(throttle_delay_seconds);
+  return value;
+}
+
+DictionaryValue* ErrorToValue(
+    const sync_pb::ClientToServerResponse::Error& proto) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_ENUM(error_type, GetErrorTypeString);
+  SET_STR(error_description);
+  SET_STR(url);
+  SET_ENUM(action, GetActionString);
+  return value;
+}
+
+}  // namespace
+
+DictionaryValue* ClientToServerResponseToValue(
+    const sync_pb::ClientToServerResponse& proto,
+    bool include_specifics) {
+  DictionaryValue* value = new DictionaryValue();
+  SET(commit, CommitResponseToValue);
+  if (proto.has_get_updates()) {
+    value->Set("get_updates", GetUpdatesResponseToValue(proto.get_updates(),
+                                                        include_specifics));
+  }
+
+  SET(error, ErrorToValue);
+  SET_ENUM(error_code, GetErrorTypeString);
+  SET_STR(error_message);
+  SET_STR(store_birthday);
+  SET(client_command, ClientCommandToValue);
+  SET_INT32_REP(migrated_data_type_id);
+  return value;
+}
+
+DictionaryValue* ClientToServerMessageToValue(
+    const sync_pb::ClientToServerMessage& proto,
+    bool include_specifics) {
+  DictionaryValue* value = new DictionaryValue();
+  SET_STR(share);
+  SET_INT32(protocol_version);
+  if (proto.has_commit()) {
+    value->Set("commit",
+               CommitMessageToValue(proto.commit(), include_specifics));
+  }
+
+  SET(get_updates, GetUpdatesMessageToValue);
+  SET_STR(store_birthday);
+  SET_BOOL(sync_problem_detected);
+  return value;
+}
+
+
 #undef SET
 #undef SET_REP
 
diff --git a/sync/protocol/proto_value_conversions.h b/sync/protocol/proto_value_conversions.h
index 79bf1b1..4fa8ca5 100644
--- a/sync/protocol/proto_value_conversions.h
+++ b/sync/protocol/proto_value_conversions.h
@@ -20,6 +20,8 @@ class AppSpecifics;
 class AutofillProfileSpecifics;
 class AutofillSpecifics;
 class BookmarkSpecifics;
+class ClientToServerMessage;
+class ClientToServerResponse;
 class DeviceInformation;
 class EncryptedData;
 class EntitySpecifics;
@@ -137,6 +139,15 @@ base::DictionaryValue* TypedUrlSpecificsToValue(
 base::DictionaryValue* EntitySpecificsToValue(
     const sync_pb::EntitySpecifics& specifics);
 
+base::DictionaryValue* ClientToServerMessageToValue(
+    const sync_pb::ClientToServerMessage& proto,
+    bool include_specifics);
+
+base::DictionaryValue* ClientToServerResponseToValue(
+    const sync_pb::ClientToServerResponse& proto,
+    bool include_specifics);
+
+
 }  // namespace browser_sync
 
 #endif  // SYNC_PROTOCOL_PROTO_VALUE_CONVERSIONS_H_
diff --git a/sync/protocol/proto_value_conversions_unittest.cc b/sync/protocol/proto_value_conversions_unittest.cc
index 3d96378..59eb3a8 100644
--- a/sync/protocol/proto_value_conversions_unittest.cc
+++ b/sync/protocol/proto_value_conversions_unittest.cc
@@ -187,5 +187,67 @@ TEST_F(ProtoValueConversionsTest, EntitySpecificsToValue) {
             static_cast<int>(value->size()));
 }
 
+namespace {
+// Returns whether the given value has specifics under the entries in the given
+// path.
+bool ValueHasSpecifics(const DictionaryValue& value,
+                       const std::string& path) {
+  ListValue* entities_list = NULL;
+  DictionaryValue* entry_dictionary = NULL;
+  DictionaryValue* specifics_dictionary = NULL;
+
+  if (!value.GetList(path, &entities_list))
+    return false;
+
+  if (!entities_list->GetDictionary(0, &entry_dictionary))
+    return false;
+
+  return entry_dictionary->GetDictionary("specifics",
+                                         &specifics_dictionary);
+}
+}  // namespace
+
+// Create a ClientToServerMessage with an EntitySpecifics.  Converting it to
+// a value should respect the |include_specifics| flag.
+TEST_F(ProtoValueConversionsTest, ClientToServerMessageToValue) {
+  sync_pb::ClientToServerMessage message;
+  sync_pb::CommitMessage* commit_message = message.mutable_commit();
+  sync_pb::SyncEntity* entity = commit_message->add_entries();
+  entity->mutable_specifics();
+
+  scoped_ptr<DictionaryValue> value_with_specifics(
+      ClientToServerMessageToValue(message, true /* include_specifics */));
+  EXPECT_FALSE(value_with_specifics->empty());
+  EXPECT_TRUE(ValueHasSpecifics(*(value_with_specifics.get()),
+                                "commit.entries"));
+
+  scoped_ptr<DictionaryValue> value_without_specifics(
+      ClientToServerMessageToValue(message, false /* include_specifics */));
+  EXPECT_FALSE(value_without_specifics->empty());
+  EXPECT_FALSE(ValueHasSpecifics(*(value_without_specifics.get()),
+                                 "commit.entries"));
+}
+
+// Create a ClientToServerResponse with an EntitySpecifics.  Converting it to
+// a value should respect the |include_specifics| flag.
+TEST_F(ProtoValueConversionsTest, ClientToServerResponseToValue) {
+  sync_pb::ClientToServerResponse message;
+  sync_pb::GetUpdatesResponse* response = message.mutable_get_updates();
+  sync_pb::SyncEntity* entity = response->add_entries();
+  entity->mutable_specifics();
+
+  scoped_ptr<DictionaryValue> value_with_specifics(
+      ClientToServerResponseToValue(message, true /* include_specifics */));
+  EXPECT_FALSE(value_with_specifics->empty());
+  EXPECT_TRUE(ValueHasSpecifics(*(value_with_specifics.get()),
+                                "get_updates.entries"));
+
+  scoped_ptr<DictionaryValue> value_without_specifics(
+      ClientToServerResponseToValue(message, false /* include_specifics */));
+  EXPECT_FALSE(value_without_specifics->empty());
+  EXPECT_FALSE(ValueHasSpecifics(*(value_without_specifics.get()),
+                                 "get_updates.entries"));
+}
+
 }  // namespace
 }  // namespace browser_sync
diff --git a/sync/sync.gyp b/sync/sync.gyp
index 55bae93..5bda6b5 100644
--- a/sync/sync.gyp
+++ b/sync/sync.gyp
@@ -89,6 +89,8 @@
         'engine/syncer_util.cc',
         'engine/syncer_util.h',
         'engine/syncproto.h',
+        'engine/traffic_logger.cc',
+        'engine/traffic_logger.h',
         'engine/update_applicator.cc',
         'engine/update_applicator.h',
         'engine/verify_updates_command.cc',