sync: Count and report reflected updates

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=


Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=128659

[rlarocque, 2012-03-16 22:48:09]

Raz mentioned this would be nice to have.  It turns out it's not too hard to
implement, so I'm going to try to get this in for M19.  

Raz: Can you verify the info I added to the protos are what you're looking for? 
I included counts of number of non-echo updates and the source of the update
request, since I figured that would provide useful context.  Let me know if you
think additional context would be useful.  

Tim: Please review the rest of this.  

By the way, I'm not 100% sure the mechanism I'm using to detect echo updates is
correct.  It looks correct and it seems to work in testing, but I might have
missed a few edge cases.

[tim (not reviewing), 2012-03-20 20:43:53]

http://codereview.chromium.org/9702083/diff/2001/chrome/browser/sync/internal...
File chrome/browser/sync/internal_api/all_status.cc (right):

http://codereview.chromium.org/9702083/diff/2001/chrome/browser/sync/internal...
chrome/browser/sync/internal_api/all_status.cc:76:
snapshot->syncer_status.num_echo_updates_downloaded_total;
nit - Even though I like 'echo', we've historically (and currently, server side)
referred to these as reflected updates (e.g. reflection-blocking for
notifications), so it'd be nice to follow suit.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
File sync/engine/verify_updates_command.cc (right):

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:27: // Returns true if the update's
version is greather than the version of the
nit - greater

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:32: syncable::Entry existing_entry(trans,
GET_BY_ID, update.id());
When we create an item (version 0), we expect to see that item come back down
with updated progress markers and the like at some point.  Does this count those
as reflections?

SyncerUtil::FindLocalIdToUpdate has some interesting cases, particularly
surrounding lost commit responses. For instance, super rarely we could get an
update for a logically equivalent item but with a different id (actually two
cases, one is we lost a commit response and we still have the client id locally,
and the other case is a race).  Depending on the answer to the question above
about expected-echos, I think what you have actually does what you want... but
double checking. I'm still wrapping my head around the explicit goal... may
warrant a comment.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:33: if (existing_entry.good()) {
nit - no braces around single line ifs in this file.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:37: return existing_version <
update.version();
Does this catch redeliveries in general, or only of changes from this client? 
Would it make sense to check originator_cache_guid?

[rlarocque, 2012-03-21 17:42:34]

Sorry for the delayed update.  I wanted to clarify some things first.  It seems
that the server does work as I assumed it did, so the initial design is sound.  

We'll need to wait for Raz's comments on the requirements questions you brought
up.

http://codereview.chromium.org/9702083/diff/2001/chrome/browser/sync/internal...
File chrome/browser/sync/internal_api/all_status.cc (right):

http://codereview.chromium.org/9702083/diff/2001/chrome/browser/sync/internal...
chrome/browser/sync/internal_api/all_status.cc:76:
snapshot->syncer_status.num_echo_updates_downloaded_total;
On 2012/03/20 20:43:53, timsteele wrote:
> nit - Even though I like 'echo', we've historically (and currently, server
side)
> referred to these as reflected updates (e.g. reflection-blocking for
> notifications), so it'd be nice to follow suit.

Done.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
File sync/engine/verify_updates_command.cc (right):

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:27: // Returns true if the update's
version is greather than the version of the
On 2012/03/20 20:43:53, timsteele wrote:
> nit - greater

Done.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:32: syncable::Entry existing_entry(trans,
GET_BY_ID, update.id());
On 2012/03/20 20:43:53, timsteele wrote:
> When we create an item (version 0), we expect to see that item come back down
> with updated progress markers and the like at some point.  Does this count
those
> as reflections?
> 
> SyncerUtil::FindLocalIdToUpdate has some interesting cases, particularly
> surrounding lost commit responses. For instance, super rarely we could get an
> update for a logically equivalent item but with a different id (actually two
> cases, one is we lost a commit response and we still have the client id
locally,
> and the other case is a race).  Depending on the answer to the question above
> about expected-echos, I think what you have actually does what you want... but
> double checking. I'm still wrapping my head around the explicit goal... may
> warrant a comment.
> 

Interesting.  I hadn't fully considered the new ID case.  

I believe the goal is to count updates that do not improve the user's
experience.  Receiving bookmarks created on other clients makes users happy. 
Receiving redundant copies of their own bookmarks does not.  

By that logic, we should count these server-provided-ID updates as reflections
if they don't include data that came form other clients.  I'm not sure how we
could implement it, though.  Even if we did associate the new server-provided ID
with the existing local ID, we wouldn't be allowed to compare versions between
the two.  

What could we use to differentiate between an update with a new ID and a
reflection of our own data, and one that includes a new ID with data that has
been modified by other clients?  I'm not sure there is such a thing.  

The number of these updates should be very small compared to the number of
"normal" updates.  It wouldn't bother me too much to leave this inaccuracy as
is.  It would deserve some commenting, though.

Another alternative would be to have a separate counter for this ambiguous case.
 That would be more precise, but I worry that it would be too confusing. 
Thoughts?

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:33: if (existing_entry.good()) {
On 2012/03/20 20:43:53, timsteele wrote:
> nit - no braces around single line ifs in this file.

Done.

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:37: return existing_version <
update.version();
On 2012/03/20 20:43:53, timsteele wrote:
> Does this catch redeliveries in general, or only of changes from this client? 
> Would it make sense to check originator_cache_guid?

I assumed that we're looking for redeliveries in general, so we don't need to
check the originator.  

Raz, which count would you prefer?

[tim (not reviewing), 2012-03-21 18:23:57]

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
File sync/engine/verify_updates_command.cc (right):

http://codereview.chromium.org/9702083/diff/2001/sync/engine/verify_updates_c...
sync/engine/verify_updates_command.cc:32: syncable::Entry existing_entry(trans,
GET_BY_ID, update.id());
On 2012/03/21 17:42:34, rlarocque wrote:
> On 2012/03/20 20:43:53, timsteele wrote:
> > When we create an item (version 0), we expect to see that item come back
down
> > with updated progress markers and the like at some point.  Does this count
> those
> > as reflections?
> > 
> > SyncerUtil::FindLocalIdToUpdate has some interesting cases, particularly
> > surrounding lost commit responses. For instance, super rarely we could get
an
> > update for a logically equivalent item but with a different id (actually two
> > cases, one is we lost a commit response and we still have the client id
> locally,
> > and the other case is a race).  Depending on the answer to the question
above
> > about expected-echos, I think what you have actually does what you want...
but
> > double checking. I'm still wrapping my head around the explicit goal... may
> > warrant a comment.
> > 
> 
> Interesting.  I hadn't fully considered the new ID case.  
> 
> I believe the goal is to count updates that do not improve the user's
> experience.  Receiving bookmarks created on other clients makes users happy. 
> Receiving redundant copies of their own bookmarks does not.  
Makes sense.
> 
> By that logic, we should count these server-provided-ID updates as reflections
> if they don't include data that came form other clients.  I'm not sure how we
> could implement it, though.  Even if we did associate the new server-provided
ID
> with the existing local ID, we wouldn't be allowed to compare versions between
> the two.  
> 
> What could we use to differentiate between an update with a new ID and a
> reflection of our own data, and one that includes a new ID with data that has
> been modified by other clients?  I'm not sure there is such a thing.  
> 

I want to say this sounds like FindLocalIdToUpdate, and you could use the
originator_cache_guid for this.  But I fear I may be missing something.

> The number of these updates should be very small compared to the number of
> "normal" updates.  It wouldn't bother me too much to leave this inaccuracy as
> is.  It would deserve some commenting, though.

Agree, I'm not overly concerned about the precision at that level, but it's good
to be able to explain what we're counting.  For now at least, my gut tells me
not to bother splitting it out into two counters.
> 
> Another alternative would be to have a separate counter for this ambiguous
case.
>  That would be more precise, but I worry that it would be too confusing. 
> Thoughts?

[rlarocque, 2012-03-23 00:24:10]

I talked with Raz about what we're trying to measure.  

Our hypothesis is that it's the notifications, not the LOCAL GetUpdates, that
are the most effective means of ensuring conflicts are resolved on the client,
not the server.  Using LOCAL GetUpdates as a means of preventing conflicts has
been a bit questionable since notifications were introduced.  Recent server-side
changes make it even less likely that the LOCAL GetUpdates are useful.  

PS: "LOCAL GetUpdate" == the GetUpdate request done before a commit.

============

I've made a few changes to the patch.
- I added the GetUpdates source of the recent sync cycle to the set of
information passed up to the server.  This was always the intent, and the patch
did contain some work towards the goal, but it was never fully completed.
- I added some information about whether or not notifications are enabled to the
set of information being reported.
- I added some comments around the code that detects redundant updates to
describe some of the edge cases where we may report incorrectly.

[rlarocque, 2012-03-23 18:16:06]

Those protobuf changes made the python test server very unhappy.  This version
of the patch should fix it.

+Fred for testserver OWNERS review.

[tim (not reviewing), 2012-03-23 20:21:06]

sync changes LGTM.  proto changes look safe from a wire-compatibility point of
view.

akalin's LGTM needed for chromiumsync py approval.

http://codereview.chromium.org/9702083/diff/17003/net/tools/testserver/chromi...
File net/tools/testserver/chromiumsync.py (right):

http://codereview.chromium.org/9702083/diff/17003/net/tools/testserver/chromi...
net/tools/testserver/chromiumsync.py:220: return
get_updates_caller_info_pb2.GetUpdatesCallerInfo \
You can give out/Debug/run_testserver --sync-test a whirl!

[akalin, 2012-03-23 21:06:08]

testserver stuff LGTM

[commit-bot: I haz the power, 2012-03-23 21:19:36]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/rlarocque@chromium.org/9702083/17003

[commit-bot: I haz the power, 2012-03-24 02:17:32]

Change committed as 128659