725150 - Need logic to prevent sync and profile migration happening at the same time

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: General, defect, P1)

Description

[Kevin Brosnan [Ex-Mozilla]]

For our existing users it is possible to get into a state where profile migration and sync is taking place at the same time.

steps
Create an extensive XUL history/bookmarks/etc.
upgrade to Native
Connect to Sync
Launch Native to start profile migration
Watch Sync and profile migration fight for cpu time

Comment 1

[Richard Newman [:rnewman]]

Also ugly from a data collision standpoint.

It might be enough to have an exclusive lock on the content providers; the profile migrator would take that.

See also Bug 715550. I don't recall the bug for improving the profile migrator.

Comment 2

[Lucas Rocha (:lucasr)]

Maybe add a ContentProvider URI for updating and querying a lock for the database of a certain profile?

Comment 3

[Richard Newman [:rnewman]]

(In reply to Lucas Rocha (:lucasr) from comment #2)
> Maybe add a ContentProvider URI for updating and querying a lock for the
> database of a certain profile?

Yeah, but the CP would need to have some way to automatically release the lock in case of a process termination, mm?

I'd be happy with some way to find out if a profile migration is happening, but that doesn't work here :/

Perhaps we should flip this around: can Sync ask -- blocking -- if a profile migration has happened or needs to happen, and have that do the work before it starts to sync?

Comment 4

[Gian-Carlo Pascutto [:gcp]]

Does Sync have access to the Firefox profile?

Comment 5

[Richard Newman [:rnewman]]

(In reply to Gian-Carlo Pascutto (:gcp) from comment #4)
> Does Sync have access to the Firefox profile?

Bug 709407 tracks giving Sync enough information to know which profile it's working with. For now the whole caboodle just assumes "default", and the content providers handle that implicitly.

Comment 6

[Richard Newman [:rnewman]]

By which I meant Bug 707123. *sigh*

Comment 7

[Gian-Carlo Pascutto [:gcp]]

Okay. Profile Migration is triggered by the presence of places.sqlite in the Firefox profile, and will delete that file when it's finished. So you could add logic to not run Sync as long as that file is present.

Comment 8

[Richard Newman [:rnewman]]

(In reply to Gian-Carlo Pascutto (:gcp) from comment #7)
> Okay. Profile Migration is triggered by the presence of places.sqlite in the
> Firefox profile, and will delete that file when it's finished. So you could
> add logic to not run Sync as long as that file is present.

Oh, you meant "file access". No; Sync's only access to your profile is indirectly, through content providers.

One could add a CP to answer the question "has profile migration run yet?", which would query for the presence of that file, and Sync could ask it.

Comment 9

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 1. Expose a control Uri for BrowserProvider

I had some doubts about what kind of API this should expose. We don't really want this to be an SQLite DB, because some of the values are dynamic. But the way the ContentProvider API is structured makes it look like it really expects an SQL-like thing to back them, with selectionArgs, projection, sortOrder,...

You can also ignore the shape of the API and pass simple strings in selection (and ignore everything else), and return a trivial Cursor, for example.

I chose a middle road here of exposing an API similar to the other (SQL-based) ContentProviders, and handling the typical queries this would be expected to get. 

This also exposes this: https://bugzilla.mozilla.org/show_bug.cgi?id=721898#c14

Comment 10

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 2. Make Profile Migration mark when its busy.

Make Profile Migration mark when it starts and finishes.

Comment 11

[Gian-Carlo Pascutto [:gcp]]

Lucasr, if you agree with this approach, I'd move the SCHEMA queries to be part of the CONTROL URI handling.

Comment 12

[Richard Newman [:rnewman]]

Did you already fully explore:

* Having profile migration run during BrowserProvider.onCreate?
* Using ordinary concurrency controls (e.g., a RW lock) that both the profile migrator and BrowserProvider take?

I think we should consciously separate the goals here into (at least) two:

* Avoiding simultaneous writes, at least for some classes of writers;
* Ensuring that profile migration has taken place before a first sync.

If you're just trying to achieve mutual exclusion, then use a proper abstraction for that. There will only be a single instance of BrowserProvider, so make *it* (and the migrator, if it doesn't call through BP) take a lock. Sync (and Fennec!) will naturally obey the lock until migration is complete.

Relying on calling code to specify mutual exclusion constraints through the CP interface to achieve mutual exclusion is heavyweight and fallible.


My suggestion for adding an API was to allow the second goal to be achieved -- having Sync back off before migration has occurred. One could also achieve that by doing all profile migrations in onCreate, or through a persistent thread-safe checklist that BrowserProvider consults before allowing access to a profile.

I am strongly in favor of putting as much of this logic into BrowserProvider as possible, because it will ensure the safety of every new chunk of code that calls into BrowserProvider.

And now I'll review the code anyway :)

Comment 13

[Richard Newman [:rnewman]]

Comment on attachment 602278 [details] [diff] [review]
Patch 1. Expose a control Uri for BrowserProvider

Review of attachment 602278 [details] [diff] [review]:
-----------------------------------------------------------------

r- for selection string manipulation alone, but there's a lot of potential simplification here. Oh, and thread-safety in query.

::: mobile/android/base/db/BrowserContract.java.in
@@ +252,5 @@
> +        // of items (profile migration, sync, ...)
> +        public static final String UPDATE_IN_PROGRESS = "update_in_progress";
> +
> +        // Maximum number of items that will be stored in the History table
> +        public static final String MAX_HISTORY_COUNT = "max_history_count";

Separate bug if you want to do this. I'd be inclined to make this a property of BrowserProvider.

::: mobile/android/base/db/BrowserProvider.java.in
@@ +65,5 @@
>      // Number of records marked as deleted to be removed
>      static final long DELETED_RECORDS_PURGE_LIMIT = 5;
>  
> +    // Maximum number of history entries to keep
> +    static final long MAX_HISTORY_COUNT = 250;

Sounds like you intend this to eventually be called DEFAULT_MAX_HISTORY_COUNT, mm?

@@ +751,5 @@
>          synchronized (this) {
>              mContext = getContext();
>              mDatabasePerProfile = new HashMap<String, DatabaseHelper>();
> +            mUpdateInProgress = false;
> +            mUpdateInProgressLastUpdate = new Date().getTime();

System.currentTimeMillis();

@@ +1035,5 @@
> +
> +        // Put the parameters in the selection string.
> +        if (selectionArgs != null) {
> +            for (String arg: selectionArgs) {
> +                selection = selection.replaceFirst("\\?", arg);

Firstly, you aren't checking if selection is null.

Secondly, I think I can figure out what you're doing in this method, and it doesn't seem like a good idea. (And if I can't immediately tell what you're doing, you really ought to have a brief block comment to explain.)

If I deduce correctly, you're substituting into a SQL string, compiling a regex to try to pick up "field = word" pairs, throwing away the SQL string and replacing it with just the field, and then using that as a switch in an if..else command interpreter to do updates.

Don't do that.

Just let ContentValues behave as a field->value map, and walk the keys.

@@ +1054,5 @@
> +
> +        if (selection.compareTo(Control.MAX_HISTORY_COUNT) == 0) {
> +            throw new UnsupportedOperationException("Maximum history entries is not configurable");
> +        } else if (selection.compareTo(Control.UPDATE_IN_PROGRESS) == 0) {
> +            long now = new Date().getTime();

System.currentTimeMillis();

@@ +1161,5 @@
> +                                String[] selectionArgs, String sortOrder) {
> +
> +        // null projection must return all fields.
> +        if (projection == null) {
> +            projection = new String[] { Control.FIELD, Control.DATA };

Extract constant.

@@ +1164,5 @@
> +        if (projection == null) {
> +            projection = new String[] { Control.FIELD, Control.DATA };
> +        }
> +
> +        List projList = Arrays.asList(projection);

You shouldn't need that.

@@ +1167,5 @@
> +
> +        List projList = Arrays.asList(projection);
> +
> +        if (sortOrder != null) {
> +            throw new UnsupportedOperationException("No sorting in CONTROL queries");

You're only returning one row. Why complain? Just ignore.

@@ +1175,5 @@
> +        if (selectionArgs != null) {
> +            for (String arg: selectionArgs) {
> +                selection = selection.replaceFirst("\\?", arg);
> +            }
> +        }

Y'know a much easier solution to this?

/**
 * Queries over the control virtual table do not currently support selection.
 */

@@ +1195,5 @@
> +        }
> +
> +        MatrixCursor cursor = new MatrixCursor(projection);
> +
> +        for (String field: selected) {

Here's a simpler way that also happens to be thread-safe:

  MatrixCursor cursor = new MatrixCursor(projection);
  MatrixCursor.RowBuilder row = cursor.newRow();
  synchronized (this) {
    for (String key : projection) {
      if (key.equals(Control.UPDATE_IN_PROGRESS)) {
        // Expire.
        row.add(mUpdateInProgress ? 1 : 0);
      } else if (key.equals(Control.MAX_HISTORY_COUNT)) {
        row.add(MAX_HISTORY_COUNT);
      }
    }
  }
  return cursor;

@@ +1204,5 @@
> +            if (field.compareTo(Control.UPDATE_IN_PROGRESS) == 0) {
> +                if (projList.contains(Control.DATA)) {
> +                    // Check whether we have been marked as being in an update
> +                    // for an excessively long time. If so, expire the marker.
> +                    long now = new Date().getTime();

System.currentTimeMillis();

And break this out into a method:

  protected synchronized boolean checkAndGetUpdateInProgress() {
    long now = System.currentTimeMillis();
    if (now > mUpdateInProgressLastUpdate + MAX_UPDATE_PROGRESS_TIME) {
      debug("Expiring update in progress");
      mUpdateInProgress = false;
    }
    trace("UpdateInProgress = " + mUpdateInProgress);
    return mUpdateInProgress;
  }

Also, it looks like you're using tabs… spaces, please.

Comment 14

[Richard Newman [:rnewman]]

      if (key.equals(Control.UPDATE_IN_PROGRESS)) {
        // Expire.
        row.add(mUpdateInProgress ? 1 : 0);
      } else if (key.equals(Control.MAX_HISTORY_COUNT)) {
        row.add(MAX_HISTORY_COUNT);
      }

Oh, and you should of course throw or insert NULL if there's an unknown column in the projection.

Comment 15

[Richard Newman [:rnewman]]

Comment on attachment 602279 [details] [diff] [review]
Patch 2. Make Profile Migration mark when its busy.

Review of attachment 602279 [details] [diff] [review]:
-----------------------------------------------------------------

Cursor safety.

::: mobile/android/base/ProfileMigrator.java
@@ +411,5 @@
>                      /*
>                         History entries to return. No point
>                         in retrieving more than we can store.
>                       */
> +                    Integer.toString(getMaxHistoryCount())

While I'm looking at this code: you probably also want ORDER BY frecency DESC, so you only take the most useful results.

@@ +648,5 @@
> +            Cursor cursor = mCr.query(Control.CONTENT_URI,
> +                                      null,
> +                                      Control.FIELD + " = ?",
> +                                      new String[] { Control.MAX_HISTORY_COUNT },
> +                                      null);

Null check for cursor. And I think this should be a property of BrowserProvider, not Control.

@@ +650,5 @@
> +                                      Control.FIELD + " = ?",
> +                                      new String[] { Control.MAX_HISTORY_COUNT },
> +                                      null);
> +            cursor.moveToFirst();
> +            if (!cursor.isAfterLast()) {

If you're only returning one row, just check the return value of `moveToFirst`.

@@ +651,5 @@
> +                                      new String[] { Control.MAX_HISTORY_COUNT },
> +                                      null);
> +            cursor.moveToFirst();
> +            if (!cursor.isAfterLast()) {
> +                int val = cursor.getInt(cursor.getColumnIndexOrThrow(Control.DATA));

s/DATA/MAX_HISTORY_COUNT?

@@ +652,5 @@
> +                                      null);
> +            cursor.moveToFirst();
> +            if (!cursor.isAfterLast()) {
> +                int val = cursor.getInt(cursor.getColumnIndexOrThrow(Control.DATA));
> +                cursor.close();

cursor.close() should be in a `finally` block.

@@ +656,5 @@
> +                cursor.close();
> +                return val;
> +            } else {
> +                cursor.close();
> +                throw new IllegalStateException("Content provider doesn't have max history count");

Is that the most useful behavior? Why not default to processing everything, or 5,000 entries, or something?

Comment 16

[Richard Newman [:rnewman]]

(In reply to Richard Newman [:rnewman] from comment #13)

> > +    // Maximum number of history entries to keep
> > +    static final long MAX_HISTORY_COUNT = 250;

Per mfinkle in Bug 721898:

"Just a nnote. We do not want to truncate to a tiny number. It will kill the usefullness of the awesomebar. We need to try to save as much data as possible. Bug 725914 fixed a slow query that affected the speed of awesomebar and top-sites. Let's re-evaluate based on the current speed to get a higher number. 300 is way too few IMO."

You might want to set that to, say, 5000, and see where we go from there.

Comment 17

[Lucas Rocha (:lucasr)]

Comment on attachment 602278 [details] [diff] [review]
Patch 1. Expose a control Uri for BrowserProvider

rnewman has given a pretty good initial feedback on the patch. I don't feel I have much to add for now.

Comment 18

[Lucas Rocha (:lucasr)]

Comment on attachment 602279 [details] [diff] [review]
Patch 2. Make Profile Migration mark when its busy.

rnewman has given a pretty good initial feedback on the patch. I don't feel I have much to add for now.

Comment 19

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 1. Expose a control Uri for BrowserProvider

Comment 20

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 2. Make Profile Migration mark when its busy.

Comment 21

[Gian-Carlo Pascutto [:gcp]]

After some discussion, the following changes:

- Removed all MAX_HISTORY stuff - we'll deal with that, if needed, in the appropriate bugs.
- Profile Migration must show UI, which precludes it from going into BrowserProvider/onCreate. It's also blocking in the startup of the application, so it cannot use a real lock. It must write, so a R/W lock won't help.
- Sync's main interest is knowing if migration has happened or not. This can be dealt with with a flag that is set once, removing all the lock/timeout handling.
- rnewman's comments here make it clear he prefers an as simple as possible API, and we don't need to pretend to support SQL select syntax. 

So this patch is very much simplified now, and only exposes one thing: has profile migration happened or not.

Comment 22

[Gian-Carlo Pascutto [:gcp]]

After more discussion with rnewman, the storage and management of the preference should move to the ProfileMigrator, and it will be up to the ContentProvider to request the current status.

Comment 23

[Gian-Carlo Pascutto [:gcp]]

...and it's quite useful for Sync to know when either of bookmarks or history has completed (in reality, bookmarks could finish long before history does), so they should be exposed separately.

Comment 24

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 1. Expose Control Uri for Sync use

Comment 25

[Lucas Rocha (:lucasr)]

Comment on attachment 611743 [details] [diff] [review]
Patch 1. Expose Control Uri for Sync use

Review of attachment 611743 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good with nits fixed.

::: mobile/android/base/ProfileMigrator.java
@@ +221,5 @@
>      }
>  
> +    public boolean isBookmarksMigrated() {
> +        return getPreferences().getBoolean(MIGRATE_BOOKMARKS_DONE, false);
> +    }

Moved it to keeping public method together?

::: mobile/android/base/db/BrowserProvider.java.in
@@ +1360,5 @@
> +        if (selection != null) {
> +            throw new UnsupportedOperationException("No selection in virtual CONTROL queries");
> +        }
> +
> +        File profDir = GeckoProfile.get(mContext).getDir();

profileDir for clarity.

@@ +1374,5 @@
> +        MatrixCursor.RowBuilder row = cursor.newRow();
> +        synchronized (this) {
> +            for (String key : projection) {
> +                if (key.equals(Control.ENSURE_BOOKMARKS_MIGRATED)) {
> +                    ProfileMigrator profMigr =

profMigr -> migrator or profileMigrator for clarity. Maybe you could declare this outside the 'if' and use same instance in in both the if and else blocks?

@@ +1382,5 @@
> +                        row.add(1);
> +                    } else {
> +                        // Start migration.
> +                        profMigr.launch();
> +                        boolean bookmarksDone = profMigr.isBookmarksMigrated();

nit: add empty line here.

@@ +1387,5 @@
> +                        // We expect bookmarks to finish in one pass. Warn if
> +                        // this is not the case.
> +                        if (!bookmarksDone) {
> +                            Log.w(LOGTAG, "Bookmarks migration did not finish.");
> +                        }

nit: add empty line here.

@@ +1388,5 @@
> +                        // this is not the case.
> +                        if (!bookmarksDone) {
> +                            Log.w(LOGTAG, "Bookmarks migration did not finish.");
> +                        }
> +                        row.add(bookmarksDone ? 1 : 0);

Just wondering: is a bookmarksDone = 0 return a bug or an expected situation? Are we at least logging the exception/error that caused the 0 return somewhere?

Comment 26

[Gian-Carlo Pascutto [:gcp]]

>Moved it to keeping public method together?

Yup

>Just wondering: is a bookmarksDone = 0 return a bug or an expected situation? Are 
>we at least logging the exception/error that caused the 0 return somewhere?

It's a bug. There should be another logged error before this one if it triggers.

https://hg.mozilla.org/integration/mozilla-inbound/rev/02b15cf9157f

Comment 27

[Richard Newman [:rnewman]]

Can't be a P3 and block beta.

Comment 28

[Richard Newman [:rnewman]]

Comment on attachment 611743 [details] [diff] [review]
Patch 1. Expose Control Uri for Sync use

Review of attachment 611743 [details] [diff] [review]:
-----------------------------------------------------------------

r+ after addressing double-launching and renaming hasMigrationFinished.

::: mobile/android/base/db/BrowserProvider.java.in
@@ +1349,5 @@
> +
> +        final String[] allFields = {
> +            Control.ENSURE_BOOKMARKS_MIGRATED,
> +            Control.ENSURE_HISTORY_MIGRATED
> +        };

Neater if this is a static final in the enclosing scope, but no big deal.

@@ +1394,5 @@
> +                } else if (key.equals(Control.ENSURE_HISTORY_MIGRATED)) {
> +                    ProfileMigrator profMigr =
> +                        new ProfileMigrator(mContext.getContentResolver(), profDir);
> +                    // Are we done?
> +                    if (profMigr.hasMigrationFinished()) {

So for bookmarks you do

  isBookmarksMigrated()
  launch()
  isBookmarksMigrated()

and for history you do

  hasMigrationFinished()
  launch()
  hasMigrationFinished()

? Seems like you want s/hasMigrationFinished/isHistoryMigrated, right?

And do you really intend for both to be migrated when you check one? (That is, for launch() to affect both?)

And, for that matter, if I pass null for the projection, or manually project to both, you're going to call launch() twice, and allocate two profile migrators. That doesn't seem right.

I suspect you want to do something like

  boolean wantBookmarks = false;
  boolean wantHistory   = false;
  boolean needBookmarks = false;
  boolean needHistory   = false;

  // Walk projection, setting to true if appropriate.
  for (...) {
    ...
  }

  needBookmarks = wantBookmarks &&!profMigr.hasMigratedBookmarks();
  needHistory = wantHistory && !profMigr.hasMigratedHistory();

  if (needBookmarks || needHistory) {
    profMigr.launch();
    needBookmarks = wantBookmarks &&!profMigr.hasMigratedBookmarks();
    needHistory = wantHistory && !profMigr.hasMigratedHistory();
  }

  // Now set the results.
  if (wantBookmarks)
    row.add(needBookmarks ? 0 : 1)
  if (wantHistory)
    row.add(wantHistory   ? 0 : 1)

  return cursor;

Comment 29

[(no longer active)]

https://hg.mozilla.org/mozilla-central/rev/02b15cf9157f

Comment 30

[Richard Newman [:rnewman]]

Looks like this landed before my review comments were addressed. Filed a follow-up: Bug 743054.

Comment 31

[Gian-Carlo Pascutto [:gcp]]

>Looks like this landed before my review comments were addressed.

It already landed before you made them (comment 26), because I understood from IRC that the API was OK with you (which is why I feedback?-ed you to begin with). Anyway, good catch on that bug. Another pair of eyes at the code never hurts.