sync: Attempt to recover from directory corruption

sync: Attempt to recover from directory corruption

Sync when sqlite fails to maintain databsae integrity, most likely due
to unexpected shutdowns or flaky storage devices. They can also be
corrupted by logic errors in the sync code, though we hope that's a rare
occurence.

This patch attempts to improve a user's experience in this scenario by
transparently deleting the old directory and re-downloading all their
data. This will be much better than the old behaviours, which included
silently signing a user out of sync, triggering an unrecoverable error,
or crashing.

To help catch sync logic bugs, debug builds are set to crash when they
detect directory corruption.

Also included in this patch is a new test. The
DirectoryBackingStore.MinorCorruption test exercises the code invoked
when the directory is successfully re-created.

BUG=109668, 129825
Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=150465

[rlarocque, 2012-08-01 00:25:10]

Here's the remainder of the directory corruption handling patch.  I've closed
the original review.

This patch adds some UMAs that were not present in the old review.  The existing
UMAs would not be able to tell us when we've encountered and automatically
resolved directory corruption.

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
chrome/browser/sync/profile_sync_service.cc:650: if
(is_first_time_sync_configure_) {
I'm considering removing these UMAs.  They were useful mainly to track directory
corruption.  However, they're completely unaware of the delete and retry that
now resides in on_disk_directory_backing_store.cc.

Are there any objections to removing them?

[tim (not reviewing), 2012-08-01 21:31:59]

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
chrome/browser/sync/profile_sync_service.cc:394: // won't make a difference.
Hmm... I don't follow.  I thought this was called when a sync cycle failed to
download nigori, but the scheduler has set up another pending job.  How or where
will we have tried to delete the directory ?

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
File sync/syncable/on_disk_directory_backing_store.cc (right):

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
sync/syncable/on_disk_directory_backing_store.cc:72: // immediately so a
developer can investigate.
Let's keep an eye on this.  I've seen similar dchecks, particularly around
sqlite, in other parts of chrome code really annoy people, especially when
debugging (or inspecting the db, ...).  sqlite can and will fail.

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
sync/syncable/on_disk_directory_backing_store.cc:79: db_.reset(new
sql::Connection);
A bit nervous to swap this out since we set it in the constructor, but okay.

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
sync/syncable/on_disk_directory_backing_store.cc:94: void
OnDiskDirectoryBackingStore::AllowFailureForTest() {
I think it would be clearer / preferable to have a ReportTryLoadFailure()
virtual that could call NOTREACHED() << "try load failed!" in this case, and
perhaps just log a warning in tests.

[rlarocque, 2012-08-01 21:53:50]

Still working on an updated patch.

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/10821121/diff/1/chrome/browser/sync/profile_sy...
chrome/browser/sync/profile_sync_service.cc:394: // won't make a difference.
On 2012/08/01 21:31:59, timsteele wrote:
> Hmm... I don't follow.  I thought this was called when a sync cycle failed to
> download nigori, but the scheduler has set up another pending job.  How or
where
> will we have tried to delete the directory ?

Woops, that was a dumb mistake.  This comment belongs next to the
UnrecoverableError on line 673.

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
File sync/syncable/on_disk_directory_backing_store.cc (right):

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
sync/syncable/on_disk_directory_backing_store.cc:94: void
OnDiskDirectoryBackingStore::AllowFailureForTest() {
On 2012/08/01 21:31:59, timsteele wrote:
> I think it would be clearer / preferable to have a ReportTryLoadFailure()
> virtual that could call NOTREACHED() << "try load failed!" in this case, and
> perhaps just log a warning in tests.

Yet another implementation of DirectoryBackingStore.  That would bring the total
up to five.

You're right, though.  That is the right thing to do.

[rlarocque, 2012-08-01 22:37:51]

Patch updated.

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
File sync/syncable/on_disk_directory_backing_store.cc (right):

http://codereview.chromium.org/10821121/diff/1/sync/syncable/on_disk_director...
sync/syncable/on_disk_directory_backing_store.cc:72: // immediately so a
developer can investigate.
On 2012/08/01 21:31:59, timsteele wrote:
> Let's keep an eye on this.  I've seen similar dchecks, particularly around
> sqlite, in other parts of chrome code really annoy people, especially when
> debugging (or inspecting the db, ...).  sqlite can and will fail.

I've updated the comment with instructions on how to bypass the DCHECK.  I'm
hoping that will reduce the annoyance somewhat.

[tim (not reviewing), 2012-08-02 00:31:18]

http://codereview.chromium.org/10821121/diff/5001/chrome/browser/sync/profile...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/10821121/diff/5001/chrome/browser/sync/profile...
chrome/browser/sync/profile_sync_service.cc:671: // directory.  Whether or not
we try to delete it again after the error is
Ah, maybe reword these last sentences to be explicit that it's fine to delete it
here, the 'false' bool is conveniently totally ambiguous and I got confused.
"There may not be much point to keeping the directory around, since by the time
we get here, we have already tried and failed to delete the directory."

http://codereview.chromium.org/10821121/diff/5001/sync/syncable/on_disk_direc...
File sync/syncable/on_disk_directory_backing_store.cc (right):

http://codereview.chromium.org/10821121/diff/5001/sync/syncable/on_disk_direc...
sync/syncable/on_disk_directory_backing_store.cc:77:
file_util::Delete(backing_filepath_, false);
How did you test this?  

We have integration tests now that simulate browser start, I believe (I forget
exactly how they work).  It would be SO COOL if we could corrupt the db in such
a way that we'd trigger this code path...  is that just a pipe dream?  

We have some that simulate a browser restart, though... apparently disabled :(
http://code.google.com/p/chromium/source/search?q=RestartSyncService

[rlarocque, 2012-08-02 00:47:20]

Updated the comment.

http://codereview.chromium.org/10821121/diff/5001/sync/syncable/on_disk_direc...
File sync/syncable/on_disk_directory_backing_store.cc (right):

http://codereview.chromium.org/10821121/diff/5001/sync/syncable/on_disk_direc...
sync/syncable/on_disk_directory_backing_store.cc:77:
file_util::Delete(backing_filepath_, false);
On 2012/08/02 00:31:18, timsteele wrote:
> How did you test this?  
> 
> We have integration tests now that simulate browser start, I believe (I forget
> exactly how they work).  It would be SO COOL if we could corrupt the db in
such
> a way that we'd trigger this code path...  is that just a pipe dream?  
> 
> We have some that simulate a browser restart, though... apparently disabled :(
> http://code.google.com/p/chromium/source/search?q=RestartSyncService

We have to instantiate a special version of the directory to avoid the DCHECK. 
I don't think there's any hope of plumbing it all the way down through the
integration tests.

The corruption itself was pretty simple.  One of the checks we perform on load
is to make sure all the IDs referred to actually exist.  All I had to do was run
some SQL to update a node's PARENT_ID to a non-existent ID.

On the plus side, the transparent re-create case is tested by a unit test I'm
adding in this commit.  The failure case (all the way back to the
ProfileSyncService) is tested in the unit test I landed in r149306
(http://codereview.chromium.org/10830100/).  We've got pretty good coverage of
this code without needing to write integration tests.

[tim (not reviewing), 2012-08-02 17:21:35]

LGTM and note, rlarocque is out today and I'll be guiding this through CQ.

[commit-bot: I haz the power, 2012-08-02 17:21:49]

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

[commit-bot: I haz the power, 2012-08-02 18:04:52]

Try job failure for 10821121-4002 (retry) on win for step "compile" (clobber
build).
It's a second try, previously, step "compile" failed.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win&number...

[tim (not reviewing), 2012-08-02 19:40:50]

On 2012/08/02 18:04:52, I haz the power (commit-bot) wrote:
> Try job failure for 10821121-4002 (retry) on win for step "compile" (clobber
> build).
> It's a second try, previously, step "compile" failed.
>
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win&number...

oh darn.  looks like a legit compile failure.  If I have time I'll patch it, but
it may have to wait till Richard gets back.

[commit-bot: I haz the power, 2012-08-07 22:43:13]

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

[commit-bot: I haz the power, 2012-08-08 00:10:18]

Change committed as 150465