Sync: Improve handling of database load failures

Sync: Improve handling of database load failures
   
This failure path has not received a lot of testing until now.  Here are
the issues addressed by this patch:
    
- We usually check the return value of step() calls.  However, we do not
check the return value of prepare() calls, which are more likely to fail.
If they do fail, we will DCHECK() or go on to dereference an invalid
pointer in step().  This patch checks the return value of one particular
prepare statement, the one in CheckIntegrity().
    
- Disable DCHECKs on sqlite errors, DirectoryManager open failure,
and SyncManager initialization failure.  This will allow us to test these
error paths.
    
- Be careful in ShutdownOnSyncThread().  The directory will not be fully
intialized during shutdown if the database load failed.

- Add a ProfileSyncService unit test that simulates a load from an
unreadable database.  The harness had to be modified slightly to make
this possible.

- Remove a setup_for_test_mode_ flag in SyncManager::SyncInternal::Init.
I don't know what the original intent of this flag was.  However, I do
know that it prevents me from properly simulating a database load failure
and removing it seems to have no ill effects.

- Do not delete the database from DirectoryBackingStore.  If this code
were to get executed it would put us into an inconsistent state.  See
issue 103824.  However, it's unlikely this code would get executed.  If
the database were actually corrupt, we would DCHECK or de-reference an
invalid pointer on our way to this code because we don't check the
return value of the attempt to prepare an SQL statement in
DirectoryBackingStore::CheckIntegrity().
    
- Modify the DirectoryBackingStoreTest.Corruption unit test to expect the
new behaviour.

- Disable sync when backend initialize fails.  Such a failure could
be due to bad local state.  We don't know the actual cause because the
information is not available from the ProfileSyncService callback.  The
safe course of action is to clear our local sync state and try again
later.  It's the easiest way to get back to the most well travelled sync
initialization path.

BUG=103307, 103824
TEST=DirectoryBackingStoreTest.Corruption, ProfileSyncServiceTest.CorruptDatabase

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

[rlarocque, 2011-11-08 02:25:00]

This change fixes some issues I ran into while working on code to verify the
data we load from the sync database (http://codereview.chromium.org/8475017/). 
The issues dealt with in this patch are a potential problem in other code as
well.  

I don't really like this patch, but it's probably the least dramatic set of
changes we could make to address these issues.  It doesn't perform any great
refactoring of error handling logic.  Instead it fixes the issues while
retaining maintaining the same approach as the original.  

This approach does have a few drawbacks.  Since we don't know what caused the
error, we could delete the sync database for any sort of database open failure. 
However, it does seem like the only way to end up in PSS::OnBackendInitialized
with success == false is a database load failure (all other kinds of failure are
handled through other mechanisms), so maybe it's not so bad.  

It's also not ideal in that an error leaves the user in an OFFLINE_UNUSABLE
state until they restart their browser.  Though that may be acceptable
considering that this scenario is expected to be extremely rare.

[Nicolas Zea, 2011-11-08 22:12:18]

Since you've removed these DCHECKS, could you now add some tests? I think
profile_sync_service_unittest has an example of a pre-existing database which
you could work off.

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/glue/sync_b...
File chrome/browser/sync/glue/sync_backend_host.cc (left):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/glue/sync_b...
chrome/browser/sync/glue/sync_backend_host.cc:611: DCHECK(success) << "Syncapi
initialization failed!";
LOG_IF(ERROR, !success) would still be useful I think

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/internal_ap...
File chrome/browser/sync/internal_api/sync_manager.cc (right):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/internal_ap...
chrome/browser/sync/internal_api/sync_manager.cc:1294:
dir_manager()->FinalSaveChangesForAll();
Perhaps just condition these two statements? We should still probably remove the
observers above, although perhaps we'd be unable to acquire that
transaction...but in that case there's no contention so it should be safe to
remove them anyways I think

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/profile_syn...
File chrome/browser/sync/profile_sync_service.h (right):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/profile_syn...
chrome/browser/sync/profile_sync_service.h:509: // sync database.
Elaborate a bit about why you would ever want to set delete_stale_data to true.

[rlarocque, 2011-11-11 22:24:56]

I've addressed most of Nicolas' comments in the second patch set.  I've also
made this patch a lot bigger.  

I will update the review accordingly.

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/glue/sync_b...
File chrome/browser/sync/glue/sync_backend_host.cc (left):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/glue/sync_b...
chrome/browser/sync/glue/sync_backend_host.cc:611: DCHECK(success) << "Syncapi
initialization failed!";
On 2011/11/08 22:12:18, nzea wrote:
> LOG_IF(ERROR, !success) would still be useful I think

Done.

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/internal_ap...
File chrome/browser/sync/internal_api/sync_manager.cc (right):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/internal_ap...
chrome/browser/sync/internal_api/sync_manager.cc:1294:
dir_manager()->FinalSaveChangesForAll();
On 2011/11/08 22:12:18, nzea wrote:
> Perhaps just condition these two statements? We should still probably remove
the
> observers above, although perhaps we'd be unable to acquire that
> transaction...but in that case there's no contention so it should be safe to
> remove them anyways I think

The transaction won't work.  The Directory ends up leaving kernel_ uninitialized
when the load fails, so there's no directory kernel, and therefore no lock to
acquire.  I suspect it would end up accessing invalid memory in release mode.   

Besides, we don't need to remove the observers because we never added them in
the first place.  The js_mutation_event_observer_ would have been added to the
observer list in OpenDirectory(), but not if the attempt to open the directory
failed.  The cryptographer observer would be setup in
SyncManager::SyncInternal::Init, but not if the "signed_in" local boolean value
is false, which it would be if we failed to open the directory.  

I admit that this logic is very brittle because it is mostly a coincidence that
!initialized_ implies a directory load failure.  I'm not sure how to fix this
without larger refactoring.

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/profile_syn...
File chrome/browser/sync/profile_sync_service.h (right):

http://codereview.chromium.org/8496002/diff/1/chrome/browser/sync/profile_syn...
chrome/browser/sync/profile_sync_service.h:509: // sync database.
On 2011/11/08 22:12:18, nzea wrote:
> Elaborate a bit about why you would ever want to set delete_stale_data to
true.

I've decided not to do this rename.  Instead I will call DisableForUser() from
the backend initialization failure.

[rlarocque, 2011-11-11 22:39:17]

Nicolas was right to suggest I unit test my change.  I
discovered a few additional DCHECKs while implementing that
suggestion.  

The new patch set attempts to solve issue 103824 and
issue 103307 in one CL.  It also fixes the (unreported)
 issue that we're not checking the return value of SQL statement prepare(),
which can and does fail, which could cause memory errors in release mode.

This patch cleans up the database corruption handling error
paths so I can add a check for database integrity during
startup.  I will upload a new CL for doing this to
http://codereview.chromium.org/8475017/ that is compatible
with the CL posted here.  Hopefully we can get both of
these merged into M16 to resolve 100374.

[tim (not reviewing), 2011-11-14 19:13:13]

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
chrome/browser/sync/profile_sync_service.cc:561: DisableForUser();
Lets add a UMA counter here so we track the # of users we send away.

[Nicolas Zea, 2011-11-14 19:29:21]

LGTM with nits (and with the new histograms Tim mentions)

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
File chrome/browser/sync/profile_sync_service_unittest.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
chrome/browser/sync/profile_sync_service_unittest.cc:310: const char * nonesense
= "not a database";
"const char* nonsense"

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
File chrome/browser/sync/syncable/directory_backing_store.cc (left):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
chrome/browser/sync/syncable/directory_backing_store.cc:308:
UMA_HISTOGRAM_COUNTS_100("Sync.DirectoryOpenFailedWin", bucket);
Since I suppose these histograms don't make sense when we're not attempting to
re-open the directory, we should remove them from the internal histogram file as
well.

[lipalani1, 2011-11-14 21:34:24]

lgtm couple of comments.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/internal...
File chrome/browser/sync/internal_api/sync_manager.cc (left):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/internal...
chrome/browser/sync/internal_api/sync_manager.cc:805: if (signed_in ||
setup_for_test_mode_) {
Did it have to be removed? Are the test cases passing?

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
File chrome/browser/sync/syncable/directory_backing_store.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
chrome/browser/sync/syncable/directory_backing_store.cc:240:
statement.prepare(handle, "PRAGMA integrity_check(1)")) {
We can add a UMA metric here.

[rlarocque, 2011-11-14 22:56:26]

New patch uploaded.

Let me know what you think about the new UMA names.  I struggled to find a way
to describe first-time and non-first-time backend initialization.  I settled
with "Sync.FirstBackendInitializeSuccess" and
"Sync.RestoreBackendInitializeSuccess".  

If those are acceptable, I will upload the separate CL for updating
histograms.xml and start notifying the appropriate people.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/internal...
File chrome/browser/sync/internal_api/sync_manager.cc (left):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/internal...
chrome/browser/sync/internal_api/sync_manager.cc:805: if (signed_in ||
setup_for_test_mode_) {
On 2011/11/14 21:34:24, lipalani1 wrote:
> Did it have to be removed? Are the test cases passing?

Yes and yes.  

This setup_for_test_mode bool would force the SyncManager into thinking SignIn
succeeded when it actually failed due to directory initialization failure. 
That's a problem when I'm trying to test the directory intialization failure
handling code path.  

I tried making this change and sending it at the trybots because I was curious
as to which tests it would break.  I was pleasantly surprised to see that this
change did not appear to break anything.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
File chrome/browser/sync/profile_sync_service.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
chrome/browser/sync/profile_sync_service.cc:561: DisableForUser();
On 2011/11/14 19:13:13, timsteele wrote:
> Lets add a UMA counter here so we track the # of users we send away.

Done.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
File chrome/browser/sync/profile_sync_service_unittest.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/profile_...
chrome/browser/sync/profile_sync_service_unittest.cc:310: const char * nonesense
= "not a database";
On 2011/11/14 19:29:21, nzea wrote:
> "const char* nonsense"

Done.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
File chrome/browser/sync/syncable/directory_backing_store.cc (left):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
chrome/browser/sync/syncable/directory_backing_store.cc:308:
UMA_HISTOGRAM_COUNTS_100("Sync.DirectoryOpenFailedWin", bucket);
On 2011/11/14 19:29:21, nzea wrote:
> Since I suppose these histograms don't make sense when we're not attempting to
> re-open the directory, we should remove them from the internal histogram file
as
> well.

Done in a separate CL that also adds replacement histograms.

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
File chrome/browser/sync/syncable/directory_backing_store.cc (right):

http://codereview.chromium.org/8496002/diff/4001/chrome/browser/sync/syncable...
chrome/browser/sync/syncable/directory_backing_store.cc:240:
statement.prepare(handle, "PRAGMA integrity_check(1)")) {
On 2011/11/14 21:34:24, lipalani1 wrote:
> We can add a UMA metric here.

We could, but we'd probably end up taking it out in a few weeks.  

This change is a band-aid solution.  This entire file's use of the sqlite API
assumes that prepare() can't fail, which is wrong.  Furthermore, every other
component of Chromium has migrated to a newer API that does a better job of
handling these errors.  See crbug.com/77634.

I think we should come back to this when we've converted to the new API.  We
should have more options for tracking those errors at that point.  

Until then, we can rely on the histogram I'm adding to ProfileSyncService to
tell us if we're disabling sync too much.

[Nicolas Zea, 2011-11-15 20:21:08]

UMA names lgtm

[commit-bot: I haz the power, 2011-11-15 20:29:11]

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

[commit-bot: I haz the power, 2011-11-15 21:28:33]

Change committed as 110177

[rlarocque, 2011-11-15 22:58:24]

On 2011/11/15 21:28:33, I haz the power (commit-bot) wrote:
> Change committed as 110177

I had to revert this because of memory issues.  Patch set 4 shows the changes
I've made to attempt to fix it, but I don't think I'll be able to commit off of
this review anymore.  I will start a new review for the next attempt at this
change.