Fix the false-positive detection of commit errors

Fix the false-positive detection of commit errors

When exiting from a sync cycle, the SyncScheduler will look at the results of
the previous cycle and use them to determine when the next sync job should
run.  Part of this is detecting whether or not the job failed.

Right now, we assume that num_unsynced_handles > 0 implies that we failed to
commit everything we should have.  That's wrong, because that information was
calculated at the beginning of the job and doesn't get updated following the
commit.  So num_unsynced_handles > 0 actually implies that we probably tried to
commit something, but it doesn't necessarily mean the commit failed.

Because of that faulty logic, we assume that every sync cycle that commits
something has in fact failed.  We schedule another job soon after to clean up
the failure.

This commit attempts to fix that issue.  It moves the logic for detecting the
failure into SyncSession::ExperiencedTransientError() which will act as an
interpreter for the session's state.  This should make it more difficult to
misinterprent the session's state information in the future.  The function's
definition uses a different, hopefully better, set of tests to determine
whether or not the sync cycle failed to make progress.

This commit also changes the way the MIGRATION_DONE "error" code is handled.
We don't want MIGRATION_DONE to trigger a backoff, which is what it would do
given how we defined ExperiencedTransientError().  The fix is to change the way
we deal with this value, so it does not increment the consecutive error
counter.

BUG=94670
TEST=

[rlarocque, 2011-09-09 00:58:28]

I have no intention of committing this code as is.  I'm just posting it here
because this site is a good place to share and discuss a patch.  

I've provided an initial version of "SyncSession::WasUnableToMakeProgress()",
but I'm sure there's lots of room for improvement.  The problem is that I'm not
sure what this function should look like.  Trying to duplicate the old behaviour
is clearly not an option, because it was wrong.  I don't know of any easy way to
detect errors by querying a StatusController.  Even if such a mechanism existed,
I'm not sure it would it be right to trigger ScheduleNextSync's error correction
logic for all types of errors.  

I tried to use sync_protocol_errors to detect commit errors, which I figured
would be an appropriate replacement for the num_unsynced_handles check.  That
didn't work because I couldn't figure out how to determine whether or not the
field had been initialized.  There are code paths where the field would be
uninitialized and I don't know a way to disambiguate between an UNKOWN_ERROR
from the server and an UNKONWN_ERROR that came from the field's default
constructor.

[rlarocque, 2011-09-19 23:24:41]

+ncarter

Also: ping.

[tim (not reviewing), 2011-09-20 16:21:57]

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->WasUnableToMakeProgress()) {
With the old "SyncerThread" this would have been broken as we would have dropped
nudges queued up while this session was in progress due to the freshness
condition check (which we still have in ShouldRunJob).  But since we'll now only
compute the scheduled_start time at ScheduleNudgeImpl *and* we always coalesce,
I think we're okay.  The freshness check was only useful if you could have
multiple nudges queued up (and we tried to implement it that way with the
scheduler, but for various reasons it didn't fly.)

The condition may still be used for the POLL path, but I'm thinking it is
useless for nudges now; it has to be useless if we know we do not want to check
for unsynced items here.

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
File chrome/browser/sync/sessions/sync_session.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
chrome/browser/sync/sessions/sync_session.cc:155: // We were unable to download
all updates, for some unknown reason
style nit - end comments with periods

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
chrome/browser/sync/sessions/sync_session.cc:160: if
(status->error().consecutive_errors > 0)
Are all these errors "all or nothing"?  I'm wondering how / if we can enforce
that going forward...

[rlarocque, 2011-09-20 20:10:03]

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->WasUnableToMakeProgress()) {
On 2011/09/20 16:21:57, timsteele wrote:
> With the old "SyncerThread" this would have been broken as we would have
dropped
> nudges queued up while this session was in progress due to the freshness
> condition check (which we still have in ShouldRunJob).  But since we'll now
only
> compute the scheduled_start time at ScheduleNudgeImpl *and* we always
coalesce,
> I think we're okay.  The freshness check was only useful if you could have
> multiple nudges queued up (and we tried to implement it that way with the
> scheduler, but for various reasons it didn't fly.)
> 
> The condition may still be used for the POLL path, but I'm thinking it is
> useless for nudges now; it has to be useless if we know we do not want to
check
> for unsynced items here.

I don't follow.  How does this change affect the way we handle queued nudges?

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
File chrome/browser/sync/sessions/sync_session.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
chrome/browser/sync/sessions/sync_session.cc:146: bool
SyncSession::WasUnableToMakeProgress() const {
This name sucks.  I should call it WasAbleToMakeProgress(), because
!WasAbleToMakeProgress() is more readable than WasUnableToMakeProgress().

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
chrome/browser/sync/sessions/sync_session.cc:160: if
(status->error().consecutive_errors > 0)
On 2011/09/20 16:21:57, timsteele wrote:
> Are all these errors "all or nothing"?  I'm wondering how / if we can enforce
> that going forward...

In the future, I was hoping we could replace this with a GetError() function
that returns an enum value informing us of what kind of error we experienced, or
what the root cause was, or some data structure that contains both.  

Right now I'm not sure how to define an error of any kind.  I also don't know
what the set of error categories would look like.  So I decided to start simple.
 We can base this function on top of GetError() in the future, if we ever figure
out how to implement it.

[tim (not reviewing), 2011-09-20 20:32:12]

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->WasUnableToMakeProgress()) {
On 2011/09/20 20:10:03, rlarocque wrote:
> On 2011/09/20 16:21:57, timsteele wrote:
> > With the old "SyncerThread" this would have been broken as we would have
> dropped
> > nudges queued up while this session was in progress due to the freshness
> > condition check (which we still have in ShouldRunJob).  But since we'll now
> only
> > compute the scheduled_start time at ScheduleNudgeImpl *and* we always
> coalesce,
> > I think we're okay.  The freshness check was only useful if you could have
> > multiple nudges queued up (and we tried to implement it that way with the
> > scheduler, but for various reasons it didn't fly.)
> > 
> > The condition may still be used for the POLL path, but I'm thinking it is
> > useless for nudges now; it has to be useless if we know we do not want to
> check
> > for unsynced items here.
> 
> I don't follow.  How does this change affect the way we handle queued nudges? 


I don't think it does. This was to encourage you to look at the code in
ShouldRunJob and consider how this change might affect the |freshness_condition|
check. Because if a change occurs while this session is in progress, and a nudge
is scheduled but we drop that nudge due to the freshness condition, then your
change would break that flow.

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
File chrome/browser/sync/sessions/sync_session.h (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/sessions/sy...
chrome/browser/sync/sessions/sync_session.h:113: bool WasUnableToMakeProgress()
const;
FailedToMake[Forward]Progress?

[rlarocque, 2011-09-20 20:35:20]

Something to keep in mind when reviewing ScheduleNextSync().

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:855: } else {
FYI: This branch is practically unreachable.  I'm considering deleting it as
part of this patch.  

The else if condition above (... updates_source == SYNC_CYCLE_CONTINUATION) is
almost always true because we set the source to SYNC_CYCLE_CONTINUATION just a
few steps into the state machine.  Unless we kick out of SyncShare() very early,
that condition will evaluate to true.

[lipalani1, 2011-09-20 23:15:56]

Looks good from my side. LGTM. Please wait for Tim's sign off as well.

I have answered one of Tim's question.

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->WasUnableToMakeProgress()) {
When this job is running no new job(nudge) can come in as they all are in the
same thread.(even when they were in different threads the behaviour would be the
same but complicated to explain :))
So this is the right behavior and ShouldRunJob assumes this behavior. But
Richard should look at it just for fun!
On 2011/09/20 20:32:12, timsteele wrote:
> On 2011/09/20 20:10:03, rlarocque wrote:
> > On 2011/09/20 16:21:57, timsteele wrote:
> > > With the old "SyncerThread" this would have been broken as we would have
> > dropped
> > > nudges queued up while this session was in progress due to the freshness
> > > condition check (which we still have in ShouldRunJob).  But since we'll
now
> > only
> > > compute the scheduled_start time at ScheduleNudgeImpl *and* we always
> > coalesce,
> > > I think we're okay.  The freshness check was only useful if you could have
> > > multiple nudges queued up (and we tried to implement it that way with the
> > > scheduler, but for various reasons it didn't fly.)
> > > 
> > > The condition may still be used for the POLL path, but I'm thinking it is
> > > useless for nudges now; it has to be useless if we know we do not want to
> > check
> > > for unsynced items here.
> > 
> > I don't follow.  How does this change affect the way we handle queued
nudges? 
> 
> 
> I don't think it does. This was to encourage you to look at the code in
> ShouldRunJob and consider how this change might affect the
|freshness_condition|
> check. Because if a change occurs while this session is in progress, and a
nudge
> is scheduled but we drop that nudge due to the freshness condition, then your
> change would break that flow.

[lipalani1, 2011-09-20 23:18:09]

Just added more explanation.

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/1/chrome/browser/sync/engine/sync...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->WasUnableToMakeProgress()) {
One more thing, an aside(for Richard): Nudge collapsing is useful when you want
to sync something in x seconds from now and many requests come in that period.
In which case we collapse everything and execute at the xth second.

However when a job has started we dont collapase anything after.
On 2011/09/20 23:15:56, lipalani1 wrote:
> When this job is running no new job(nudge) can come in as they all are in the
> same thread.(even when they were in different threads the behaviour would be
the
> same but complicated to explain :))
> So this is the right behavior and ShouldRunJob assumes this behavior. But
> Richard should look at it just for fun!
> On 2011/09/20 20:32:12, timsteele wrote:
> > On 2011/09/20 20:10:03, rlarocque wrote:
> > > On 2011/09/20 16:21:57, timsteele wrote:
> > > > With the old "SyncerThread" this would have been broken as we would have
> > > dropped
> > > > nudges queued up while this session was in progress due to the freshness
> > > > condition check (which we still have in ShouldRunJob).  But since we'll
> now
> > > only
> > > > compute the scheduled_start time at ScheduleNudgeImpl *and* we always
> > > coalesce,
> > > > I think we're okay.  The freshness check was only useful if you could
have
> > > > multiple nudges queued up (and we tried to implement it that way with
the
> > > > scheduler, but for various reasons it didn't fly.)
> > > > 
> > > > The condition may still be used for the POLL path, but I'm thinking it
is
> > > > useless for nudges now; it has to be useless if we know we do not want
to
> > > check
> > > > for unsynced items here.
> > > 
> > > I don't follow.  How does this change affect the way we handle queued
> nudges? 
> > 
> > 
> > I don't think it does. This was to encourage you to look at the code in
> > ShouldRunJob and consider how this change might affect the
> |freshness_condition|
> > check. Because if a change occurs while this session is in progress, and a
> nudge
> > is scheduled but we drop that nudge due to the freshness condition, then
your
> > change would break that flow.
>

[rlarocque, 2011-09-21 18:44:42]

I've uploaded a new diff.  This one is a bit more ambitious.  

It refactors the structure of the if statements in ScheduleNextSync.  I found
that the old structure made sense when you look at is as a diff, but doesn't
flow very well when you try to read the resulting function top to bottom. 
However, I'm willing to back off this change if anyone objects to it.  The
refactoring also removes the mostly-unreachable else branch.  

I've also renamed the error detection function and added periods to the end of
my comments.

[lipalani1, 2011-09-22 20:22:46]

I agree with this change however prefer if it is another CL.

http://codereview.chromium.org/7861013/diff/8002/chrome/browser/sync/engine/s...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/8002/chrome/browser/sync/engine/s...
chrome/browser/sync/engine/sync_scheduler.cc:840: } else {
Can you add the vlog stmt back here?

[rlarocque, 2011-09-22 23:34:51]

On 2011/09/22 20:22:46, lipalani1 wrote:
> I agree with this change however prefer if it is another CL.
> 
>
http://codereview.chromium.org/7861013/diff/8002/chrome/browser/sync/engine/s...
> File chrome/browser/sync/engine/sync_scheduler.cc (right):
> 
>
http://codereview.chromium.org/7861013/diff/8002/chrome/browser/sync/engine/s...
> chrome/browser/sync/engine/sync_scheduler.cc:840: } else {
> Can you add the vlog stmt back here?

I must have forgot to run the unit tests before submitting patch set number 2. 
I tried running them on what would have been patch set number 3 only to find
that they're strongly against removing that dead code.  

In the interest of keeping this review manageable, I'm going to reduce the scope
of this change back to what it was for the first patch set.  We can open a
separate bug for eliminating the dead code, fixing the unit tests, and
refactoring ScheduleNextSync.

[rlarocque, 2011-09-23 00:02:24]

Uploaded a new patch.  It has all the fix you love, with none of the unnecessary
refactoring.  We can save the dead code removal and refactor for another bug.  

Changes from patch set 1:
* More periods.
* Renamed the error detection function.  Again.  This time it's called
"ExperiencedTransientError()".  I think that's a good name because it implies a
simple test for what errors should and should not set the function's value: "If
we retry without changing anything, is there a chance it will work?"
* Added better comments in some places.

[rlarocque, 2011-09-27 20:02:49]

Updated with MIGRATION_DONE fix.

[tim (not reviewing), 2011-09-27 21:20:04]

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->ExperiencedTransientError()) {
We should add a comment here along the lines of if new changes occurred while
this session was in progress, a new nudge should have been posted to the sync
loop, but not yet handled by the scheduler (so the start_time has not yet been
recorded).  Hence, we just check if there we should try to continue syncing due
to a transient error.

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
File chrome/browser/sync/sessions/sync_session.cc (right):

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
chrome/browser/sync/sessions/sync_session.cc:159: // transient.
Hm.  Don't we increment this for a number of errors that may not be transient
(e.g. not_my_birthday, the default NOTREACHED() case,  if we get any of 
ClientToServerResponse::ACCESS_DENIED,  ClientToServerResponse::AUTH_INVALID,
ClientToServerResponse::USER_NOT_ACTIVATED, SYNC_AUTH_ERROR)?

[lipalani1, 2011-09-27 21:30:39]

Tim & Richard -
I have been discussing this with Richard for a while now. While it is true that
we increment it in number of places the sync_scheduler the way it is coded would
be smart enough to not retry if there is an auth error or a birtday error. That
being said it might or might not be a good idea to rely on that behavior. 

The alternate idea is that from syncer_proto_util we use the delegate and set
the error. (we do it even today). at the end of the sync cycle we simply see if
any of the requests have failed with transient error and if they did then try
exponential retry until all the requests suceed.

Richard - It might be worthwhile to have a short meeting over IM or after Tim
comes back in person to hash this out. (and also a big THANK YOU for hanging in
there still! I know it is frustrating and the code in there is so
complicated(which is NOT a good thing!) that it sometimes could take a couple of
rewrites to get a CR right. I myself have been there just a quarter ago.)
On 2011/09/27 21:20:04, timsteele wrote:
>
http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
> File chrome/browser/sync/engine/sync_scheduler.cc (right):
> 
>
http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
> chrome/browser/sync/engine/sync_scheduler.cc:820: if
> (!old_job.session->ExperiencedTransientError()) {
> We should add a comment here along the lines of if new changes occurred while
> this session was in progress, a new nudge should have been posted to the sync
> loop, but not yet handled by the scheduler (so the start_time has not yet been
> recorded).  Hence, we just check if there we should try to continue syncing
due
> to a transient error.
> 
>
http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
> File chrome/browser/sync/sessions/sync_session.cc (right):
> 
>
http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
> chrome/browser/sync/sessions/sync_session.cc:159: // transient.
> Hm.  Don't we increment this for a number of errors that may not be transient
> (e.g. not_my_birthday, the default NOTREACHED() case,  if we get any of 
> ClientToServerResponse::ACCESS_DENIED,  ClientToServerResponse::AUTH_INVALID,
> ClientToServerResponse::USER_NOT_ACTIVATED, SYNC_AUTH_ERROR)?

[rlarocque, 2011-09-27 23:42:41]

Replied to Tim's comments.  The responses contain more questions than answers.

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
File chrome/browser/sync/engine/sync_scheduler.cc (right):

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/engine/...
chrome/browser/sync/engine/sync_scheduler.cc:820: if
(!old_job.session->ExperiencedTransientError()) {
On 2011/09/27 21:20:07, timsteele wrote:
> We should add a comment here along the lines of if new changes occurred while
> this session was in progress, a new nudge should have been posted to the sync
> loop, but not yet handled by the scheduler (so the start_time has not yet been
> recorded).  Hence, we just check if there we should try to continue syncing
due
> to a transient error.

Is this to prevent readers from assuming that this function has something to do
with scheduling nudges that were requested while the previous sync cycle was in
progress?  I don't see why that would be necessary.  There are plenty of reasons
why this function can not and should not deal with changes that happened during
the previous sync cycle.  I don't see why someone would assume that this method
would deal with anything other than a rescheduling of the recently completed
sync cycle.  

Maybe the name ScheduleNextSync is misleading.  If that's the case, we should
fix this by renaming and simplifying the function, not adding comments.

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
File chrome/browser/sync/sessions/sync_session.cc (right):

http://codereview.chromium.org/7861013/diff/17001/chrome/browser/sync/session...
chrome/browser/sync/sessions/sync_session.cc:159: // transient.
On 2011/09/27 21:20:07, timsteele wrote:
> Hm.  Don't we increment this for a number of errors that may not be transient
> (e.g. not_my_birthday, the default NOTREACHED() case,  if we get any of 
> ClientToServerResponse::ACCESS_DENIED,  ClientToServerResponse::AUTH_INVALID,
> ClientToServerResponse::USER_NOT_ACTIVATED, SYNC_AUTH_ERROR)?

Maybe so.  I haven't tracked down all the cases that could increment this
counter, nor do I fully understand their implications.  (What does
"not_my_birthday" mean, anyway?)  The main reason I started this code review was
to get feedback on whether or not this if statement makes sense.  

If this does a poor job of detecting transient errors, what alternatives could
we use?  

What should we do when we detect errors that are not transient?  Should we
define another SyncSession function to identify them and add a special case for
them in ScheduleNextSync()?  I've tried to keep the two types of errors separate
because I don't see much point in scheduling a retry job unless there's a chance
the error will go away on its own.

[rlarocque, 2011-10-05 23:45:39]

The last round of patches went around in e-mail because I had them nicely
organized in git.  This one isn't nearly as well organized, so I've squashed it
and posted the result here.  

This patch includes several changes:
* Rename and extend the SyncProtocolError struct to support network errors as
well.  Its new name is SyncOperationResult.
* Have PostClientToServerMessage return a SyncOperationResult.
* Store the latest SyncOperationResults for updates and commits in the session
status object.
* Use this information to determine whether or not the SyncScheduler should
retry its current job.

This change is not fully baked.  There's a lot of work involved in changing
SyncProtocolError, and I haven't finished it yet.  

Please let me know if you think I should continue with this approach, go back to
the previous approach (using an enum that duplicates a lot of the
SyncProtocolError states), or try something completely different.