Browse files

sync: Count and report reflected updates

Many of the updates a sync client receives are echoes of its own
changes.  This patch attempts to count how often these updates are
received by comparing the version of downloaded updates against the
local version.

These counts are exposed locally through AllStatus/about:sync.  We also
upload this information to the server through the ClientDebugInfo
mechanism.

BUG=117565
TEST=


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

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@128659 0039d316-1c4b-4281-b951-d872f2087c98
  • Loading branch information...
1 parent c87efed commit de4963c3f017007f36853564f4ed2ccbf299f454 rlarocque@chromium.org committed Mar 24, 2012
View
2 chrome/browser/sync/internal_api/all_status.cc
@@ -71,6 +71,8 @@ sync_api::SyncManager::Status AllStatus::CalcSyncing(
snapshot->syncer_status.num_updates_downloaded_total;
status.tombstone_updates_received +=
snapshot->syncer_status.num_tombstone_updates_downloaded_total;
+ status.reflected_updates_received +=
+ snapshot->syncer_status.num_reflected_updates_downloaded_total;
status.num_local_overwrites_total +=
snapshot->syncer_status.num_local_overwrites;
status.num_server_overwrites_total +=
View
9 chrome/browser/sync/internal_api/debug_info_event_listener.cc
@@ -32,6 +32,15 @@ void DebugInfoEventListener::OnSyncCycleCompleted(
sync_completed_event_info->set_num_server_conflicts(
snapshot->num_server_conflicts);
+ sync_completed_event_info->set_num_updates_downloaded(
+ snapshot->syncer_status.num_updates_downloaded_total);
+ sync_completed_event_info->set_num_reflected_updates_downloaded(
+ snapshot->syncer_status.num_reflected_updates_downloaded_total);
+ sync_completed_event_info->mutable_caller_info()->set_source(
+ snapshot->source.updates_source);
+ sync_completed_event_info->mutable_caller_info()->set_notifications_enabled(
+ snapshot->notifications_enabled);
+
AddEventToQueue(event_info);
}
View
1 chrome/browser/sync/internal_api/js_sync_manager_observer_unittest.cc
@@ -88,6 +88,7 @@ TEST_F(JsSyncManagerObserverTest, OnSyncCycleCompleted) {
7,
false,
sessions::SyncSourceInfo(),
+ false,
0,
base::Time::Now(),
false);
View
1 chrome/browser/sync/internal_api/sync_manager.cc
@@ -706,6 +706,7 @@ SyncManager::Status::Status()
initial_sync_ended(false),
updates_available(0),
updates_received(0),
+ reflected_updates_received(0),
tombstone_updates_received(0),
num_local_overwrites_total(0),
num_server_overwrites_total(0),
View
2 chrome/browser/sync/internal_api/sync_manager.h
@@ -128,6 +128,8 @@ class SyncManager {
int64 updates_available;
// Total updates received by the syncer since browser start.
int updates_received;
+ // Total updates received that are echoes of our own changes.
+ int reflected_updates_received;
// Of updates_received, how many were tombstones.
int tombstone_updates_received;
View
3 chrome/browser/sync/sync_ui_util.cc
@@ -570,6 +570,9 @@ void ConstructAboutInformation(ProfileSyncService* service,
"Updates Downloaded (Tombstones)",
full_status.tombstone_updates_received);
sync_ui_util::AddIntSyncDetail(details,
+ "Updates Downloaded (Reflections)",
+ full_status.reflected_updates_received);
+ sync_ui_util::AddIntSyncDetail(details,
"Empty GetUpdates",
full_status.empty_get_updates);
sync_ui_util::AddIntSyncDetail(details,
View
4 chrome/browser/sync/test_profile_sync_service.cc
@@ -53,7 +53,7 @@ void SyncBackendHostForProfileSyncTest::
HandleSyncCycleCompletedOnFrontendLoop(new SyncSessionSnapshot(
SyncerStatus(), ErrorCounters(), 0, false,
sync_ended, download_progress_markers, false, false, 0, 0, 0, 0, 0,
- false, SyncSourceInfo(), 0, base::Time::Now(), false));
+ false, SyncSourceInfo(), false, 0, base::Time::Now(), false));
}
namespace {
@@ -96,7 +96,7 @@ void SyncBackendHostForProfileSyncTest::StartConfiguration(
HandleSyncCycleCompletedOnFrontendLoop(new SyncSessionSnapshot(
SyncerStatus(), ErrorCounters(), 0, false,
sync_ended, download_progress_markers, false, false, 0, 0, 0, 0, 0,
- false, SyncSourceInfo(), 0, base::Time::Now(), false));
+ false, SyncSourceInfo(), false, 0, base::Time::Now(), false));
}
}
View
6 net/tools/testserver/chromiumsync.py
@@ -23,6 +23,7 @@
import app_specifics_pb2
import autofill_specifics_pb2
import bookmark_specifics_pb2
+import get_updates_caller_info_pb2
import extension_setting_specifics_pb2
import extension_specifics_pb2
import nigori_specifics_pb2
@@ -216,8 +217,9 @@ def SyncTypeToString(data_type):
def CallerInfoToString(caller_info_source):
"""Formats a GetUpdatesSource enum value to a readable string."""
- return sync_pb2.GetUpdatesCallerInfo.DESCRIPTOR.enum_types_by_name[
- 'GetUpdatesSource'].values_by_number[caller_info_source].name
+ return get_updates_caller_info_pb2.GetUpdatesCallerInfo \
+ .DESCRIPTOR.enum_types_by_name['GetUpdatesSource'] \
+ .values_by_number[caller_info_source].name
def ShortDatatypeListSummary(data_types):
View
66 sync/engine/verify_updates_command.cc
@@ -22,6 +22,54 @@ using syncable::WriteTransaction;
using syncable::GET_BY_ID;
using syncable::SYNCER;
+namespace {
+
+// This function attempts to determine whether or not this update is genuinely
+// new, or if it is a reflection of one of our own commits.
+//
+// There is a known inaccuracy in its implementation. If this update ends up
+// being applied to a local item with a different ID, we will count the change
+// as being a non-reflection update. Fortunately, the server usually updates
+// our IDs correctly in its commit response, so a new ID during GetUpdate should
+// be rare.
+//
+// The only secnarios I can think of where this might happen are:
+// - We commit a new item to the server, but we don't persist the
+// server-returned new ID to the database before we shut down. On the GetUpdate
+// following the next restart, we will receive an update from the server that
+// updates its local ID.
+// - When two attempts to create an item with identical UNIQUE_CLIENT_TAG values
+// collide at the server. I have seen this in testing. When it happens, the
+// test server will send one of the clients a response to upate its local ID so
+// that both clients will refer to the item using the same ID going forward. In
+// this case, we're right to assume that the update is not a reflection.
+//
+// For more information, see SyncerUtil::FindLocalIdToUpdate().
+bool UpdateContainsNewVersion(syncable::BaseTransaction *trans,
+ const SyncEntity &update) {
+ int64 existing_version = -1; // The server always sends positive versions.
+ syncable::Entry existing_entry(trans, GET_BY_ID, update.id());
+ if (existing_entry.good())
+ existing_version = existing_entry.Get(syncable::BASE_VERSION);
+
+ return existing_version < update.version();
+}
+
+// In the event that IDs match, but tags differ AttemptReuniteClient tag
+// will have refused to unify the update.
+// We should not attempt to apply it at all since it violates consistency
+// rules.
+VerifyResult VerifyTagConsistency(const SyncEntity& entry,
+ const syncable::MutableEntry& same_id) {
+ if (entry.has_client_defined_unique_tag() &&
+ entry.client_defined_unique_tag() !=
+ same_id.Get(syncable::UNIQUE_CLIENT_TAG)) {
+ return VERIFY_FAIL;
+ }
+ return VERIFY_UNDECIDED;
+}
+} // namespace
+
VerifyUpdatesCommand::VerifyUpdatesCommand() {}
VerifyUpdatesCommand::~VerifyUpdatesCommand() {}
@@ -62,29 +110,15 @@ SyncerError VerifyUpdatesCommand::ModelChangingExecuteImpl(
session->routing_info());
status->mutable_update_progress()->AddVerifyResult(result.value, update);
status->increment_num_updates_downloaded_by(1);
+ if (!UpdateContainsNewVersion(&trans, update))
+ status->increment_num_reflected_updates_downloaded_by(1);
if (update.deleted())
status->increment_num_tombstone_updates_downloaded_by(1);
}
return SYNCER_OK;
}
-namespace {
-// In the event that IDs match, but tags differ AttemptReuniteClient tag
-// will have refused to unify the update.
-// We should not attempt to apply it at all since it violates consistency
-// rules.
-VerifyResult VerifyTagConsistency(const SyncEntity& entry,
- const syncable::MutableEntry& same_id) {
- if (entry.has_client_defined_unique_tag() &&
- entry.client_defined_unique_tag() !=
- same_id.Get(syncable::UNIQUE_CLIENT_TAG)) {
- return VERIFY_FAIL;
- }
- return VERIFY_UNDECIDED;
-}
-} // namespace
-
VerifyUpdatesCommand::VerifyUpdateResult VerifyUpdatesCommand::VerifyUpdate(
syncable::WriteTransaction* trans, const SyncEntity& entry,
const ModelSafeRoutingInfo& routes) {
View
7 sync/protocol/client_debug_info.proto
@@ -11,6 +11,8 @@ option retain_unknown_fields = true;
package sync_pb;
+import "get_updates_caller_info.proto";
+
// The additional info here is from SyncerStatus. They get sent when the event
// SYNC_CYCLE_COMPLETED is sent.
message SyncCycleCompletedEventInfo {
@@ -31,6 +33,11 @@ message SyncCycleCompletedEventInfo {
optional int32 num_hierarchy_conflicts = 5;
optional int32 num_simple_conflicts = 6;
optional int32 num_server_conflicts = 7;
+
+ // Counts to track the effective usefulness of our GetUpdate requests.
+ optional int32 num_updates_downloaded = 8;
+ optional int32 num_reflected_updates_downloaded = 9;
+ optional GetUpdatesCallerInfo caller_info = 10;
}
message DebugEventInfo {
View
45 sync/protocol/get_updates_caller_info.proto
@@ -0,0 +1,45 @@
+// 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.
+
+syntax = "proto2";
+
+option optimize_for = LITE_RUNTIME;
+option retain_unknown_fields = true;
+
+package sync_pb;
+
+message GetUpdatesCallerInfo {
+ enum GetUpdatesSource {
+ UNKNOWN = 0; // The source was not set by the caller.
+ FIRST_UPDATE = 1; // First request after browser restart. Not to
+ // be confused with "NEW_CLIENT".
+ LOCAL = 2; // The source of the update was a local change.
+ NOTIFICATION = 3; // The source of the update was a p2p notification.
+ PERIODIC = 4; // The source of the update was periodic polling.
+ SYNC_CYCLE_CONTINUATION = 5; // The source of the update was a
+ // continuation of a previous update.
+ CLEAR_PRIVATE_DATA = 6; // Source is a call to remove all private data
+ NEWLY_SUPPORTED_DATATYPE = 7; // The client is in configuration mode
+ // because it's syncing all datatypes, and
+ // support for a new datatype was recently
+ // released via a software auto-update.
+ MIGRATION = 8; // The client is in configuration mode because a
+ // MIGRATION_DONE error previously returned by the
+ // server necessitated resynchronization.
+ NEW_CLIENT = 9; // The client is in configuration mode because the
+ // user enabled sync for the first time. Not to be
+ // confused with FIRST_UPDATE.
+ RECONFIGURATION = 10; // The client is in configuration mode because the
+ // user opted to sync a different set of datatypes.
+ DATATYPE_REFRESH = 11; // A datatype has requested a refresh. This is
+ // typically used when datatype's have custom
+ // sync UI, e.g. sessions.
+ }
+
+ required GetUpdatesSource source = 1;
+
+ // True only if notifications were enabled for this GetUpdateMessage.
+ optional bool notifications_enabled = 2;
+};
+
View
35 sync/protocol/sync.proto
@@ -19,6 +19,7 @@ import "app_setting_specifics.proto";
import "app_specifics.proto";
import "autofill_specifics.proto";
import "bookmark_specifics.proto";
+import "get_updates_caller_info.proto";
import "extension_setting_specifics.proto";
import "extension_specifics.proto";
import "nigori_specifics.proto";
@@ -355,40 +356,6 @@ message CommitMessage {
repeated ChromiumExtensionsActivity extensions_activity = 3;
};
-message GetUpdatesCallerInfo {
- enum GetUpdatesSource {
- UNKNOWN = 0; // The source was not set by the caller.
- FIRST_UPDATE = 1; // First request after browser restart. Not to
- // be confused with "NEW_CLIENT".
- LOCAL = 2; // The source of the update was a local change.
- NOTIFICATION = 3; // The source of the update was a p2p notification.
- PERIODIC = 4; // The source of the update was periodic polling.
- SYNC_CYCLE_CONTINUATION = 5; // The source of the update was a
- // continuation of a previous update.
- CLEAR_PRIVATE_DATA = 6; // Source is a call to remove all private data
- NEWLY_SUPPORTED_DATATYPE = 7; // The client is in configuration mode
- // because it's syncing all datatypes, and
- // support for a new datatype was recently
- // released via a software auto-update.
- MIGRATION = 8; // The client is in configuration mode because a
- // MIGRATION_DONE error previously returned by the
- // server necessitated resynchronization.
- NEW_CLIENT = 9; // The client is in configuration mode because the
- // user enabled sync for the first time. Not to be
- // confused with FIRST_UPDATE.
- RECONFIGURATION = 10; // The client is in configuration mode because the
- // user opted to sync a different set of datatypes.
- DATATYPE_REFRESH = 11; // A datatype has requested a refresh. This is
- // typically used when datatype's have custom
- // sync UI, e.g. sessions.
- }
-
- required GetUpdatesSource source = 1;
-
- // True only if notifications were enabled for this GetUpdateMessage.
- optional bool notifications_enabled = 2;
-};
-
message DataTypeProgressMarker {
// An integer identifying the data type whose progress is tracked by this
// marker. The legitimate values of this field correspond to the protobuf
View
1 sync/protocol/sync_proto.gyp
@@ -18,6 +18,7 @@
'bookmark_specifics.proto',
'client_commands.proto',
'client_debug_info.proto',
+ 'get_updates_caller_info.proto',
'encryption.proto',
'extension_setting_specifics.proto',
'extension_specifics.proto',
View
6 sync/sessions/session_state.cc
@@ -50,6 +50,7 @@ SyncerStatus::SyncerStatus()
num_successful_bookmark_commits(0),
num_updates_downloaded_total(0),
num_tombstone_updates_downloaded_total(0),
+ num_reflected_updates_downloaded_total(0),
num_local_overwrites(0),
num_server_overwrites(0) {
}
@@ -67,6 +68,8 @@ DictionaryValue* SyncerStatus::ToValue() const {
num_updates_downloaded_total);
value->SetInteger("numTombstoneUpdatesDownloadedTotal",
num_tombstone_updates_downloaded_total);
+ value->SetInteger("numReflectedUpdatesDownloadedTotal",
+ num_reflected_updates_downloaded_total);
value->SetInteger("numLocalOverwrites", num_local_overwrites);
value->SetInteger("numServerOverwrites", num_server_overwrites);
return value;
@@ -113,6 +116,7 @@ SyncSessionSnapshot::SyncSessionSnapshot(
int num_server_conflicts,
bool did_commit_items,
const SyncSourceInfo& source,
+ bool notifications_enabled,
size_t num_entries,
base::Time sync_start_time,
bool retry_scheduled)
@@ -131,6 +135,7 @@ SyncSessionSnapshot::SyncSessionSnapshot(
num_server_conflicts(num_server_conflicts),
did_commit_items(did_commit_items),
source(source),
+ notifications_enabled(notifications_enabled),
num_entries(num_entries),
sync_start_time(sync_start_time),
retry_scheduled(retry_scheduled) {
@@ -170,6 +175,7 @@ DictionaryValue* SyncSessionSnapshot::ToValue() const {
value->SetBoolean("didCommitItems", did_commit_items);
value->SetInteger("numEntries", num_entries);
value->Set("source", source.ToValue());
+ value->SetBoolean("notificationsEnabled", notifications_enabled);
return value;
}
View
3 sync/sessions/session_state.h
@@ -72,6 +72,7 @@ struct SyncerStatus {
// Download event counters.
int num_updates_downloaded_total;
int num_tombstone_updates_downloaded_total;
+ int num_reflected_updates_downloaded_total;
// If the syncer encountered a MIGRATION_DONE code, these are the types that
// the client must now "migrate", by purging and re-downloading all updates.
@@ -121,6 +122,7 @@ struct SyncSessionSnapshot {
int num_server_conflicts,
bool did_commit_items,
const SyncSourceInfo& source,
+ bool notifications_enabled,
size_t num_entries,
base::Time sync_start_time,
bool retry_scheduled);
@@ -146,6 +148,7 @@ struct SyncSessionSnapshot {
const int num_server_conflicts;
const bool did_commit_items;
const SyncSourceInfo source;
+ const bool notifications_enabled;
const size_t num_entries;
base::Time sync_start_time;
const bool retry_scheduled;
View
9 sync/sessions/session_state_unittest.cc
@@ -49,11 +49,12 @@ TEST_F(SessionStateTest, SyncerStatusToValue) {
status.num_successful_bookmark_commits = 10;
status.num_updates_downloaded_total = 100;
status.num_tombstone_updates_downloaded_total = 200;
+ status.num_reflected_updates_downloaded_total = 50;
status.num_local_overwrites = 15;
status.num_server_overwrites = 18;
scoped_ptr<DictionaryValue> value(status.ToValue());
- EXPECT_EQ(7u, value->size());
+ EXPECT_EQ(8u, value->size());
ExpectDictBooleanValue(status.invalid_store, *value, "invalidStore");
ExpectDictIntegerValue(status.num_successful_commits,
*value, "numSuccessfulCommits");
@@ -63,6 +64,8 @@ TEST_F(SessionStateTest, SyncerStatusToValue) {
*value, "numUpdatesDownloadedTotal");
ExpectDictIntegerValue(status.num_tombstone_updates_downloaded_total,
*value, "numTombstoneUpdatesDownloadedTotal");
+ ExpectDictIntegerValue(status.num_reflected_updates_downloaded_total,
+ *value, "numReflectedUpdatesDownloadedTotal");
ExpectDictIntegerValue(status.num_local_overwrites,
*value, "numLocalOverwrites");
ExpectDictIntegerValue(status.num_server_overwrites,
@@ -141,11 +144,12 @@ TEST_F(SessionStateTest, SyncSessionSnapshotToValue) {
kNumServerConflicts,
kDidCommitItems,
source,
+ false,
0,
base::Time::Now(),
false);
scoped_ptr<DictionaryValue> value(snapshot.ToValue());
- EXPECT_EQ(15u, value->size());
+ EXPECT_EQ(16u, value->size());
ExpectDictDictionaryValue(*expected_syncer_status_value, *value,
"syncerStatus");
ExpectDictIntegerValue(kNumServerChangesRemaining, *value,
@@ -169,6 +173,7 @@ TEST_F(SessionStateTest, SyncSessionSnapshotToValue) {
ExpectDictBooleanValue(kDidCommitItems, *value,
"didCommitItems");
ExpectDictDictionaryValue(*expected_source_value, *value, "source");
+ ExpectDictBooleanValue(false, *value, "notificationsEnabled");
}
} // namespace
View
6 sync/sessions/status_controller.cc
@@ -116,6 +116,12 @@ void StatusController::increment_num_tombstone_updates_downloaded_by(
value;
}
+void StatusController::increment_num_reflected_updates_downloaded_by(
+ int value) {
+ shared_.syncer_status.mutate()->num_reflected_updates_downloaded_total +=
+ value;
+}
+
void StatusController::set_num_server_changes_remaining(
int64 changes_remaining) {
if (shared_.num_server_changes_remaining.value() != changes_remaining)
View
1 sync/sessions/status_controller.h
@@ -214,6 +214,7 @@ class StatusController {
void increment_num_successful_bookmark_commits();
void increment_num_updates_downloaded_by(int value);
void increment_num_tombstone_updates_downloaded_by(int value);
+ void increment_num_reflected_updates_downloaded_by(int value);
void set_types_needing_local_migration(syncable::ModelTypeSet types);
void set_unsynced_handles(const std::vector<int64>& unsynced_handles);
void increment_num_local_overwrites();
View
1 sync/sessions/sync_session.cc
@@ -165,6 +165,7 @@ SyncSessionSnapshot SyncSession::TakeSnapshot() const {
status_controller_->TotalNumServerConflictingItems(),
status_controller_->did_commit_items(),
source_,
+ context_->notifications_enabled(),
dir->GetEntriesCount(),
status_controller_->sync_start_time(),
!Succeeded());

0 comments on commit de4963c

Please sign in to comment.