746035 - Profile migration does not adapt to Places database schema version

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: General, defect)

Description

[Kevin Brosnan [Ex-Mozilla]]

* Installed the 11-30-2011 trunk XUL build
* moved Firefox to the SDcard
* sync'ed my profile over to it
* installed today's nightly
* started Firefox up 
* couple seconds of import screen
* checked for bookmarks/history import, nothing was imported

So far every time I start Firefox I see the import screen and the following message.

04-16 15:48:38.700: E/GeckoLinker(3747): /mnt/asec/org.mozilla.fennec-2/pkg.apk!/libnspr4.so: Warning: relocation to NULL @0x00020de0
04-16 15:48:38.700: E/GeckoLinker(3747): /mnt/asec/org.mozilla.fennec-2/pkg.apk!/libnspr4.so: Warning: relocation to NULL @0x00020b98 for symbol "__cxa_begin_cleanup"
04-16 15:48:38.700: E/GeckoLinker(3747): /mnt/asec/org.mozilla.fennec-2/pkg.apk!/libnspr4.so: Warning: relocation to NULL @0x00020cb0 for symbol "__cxa_type_match"
04-16 15:48:38.700: E/GeckoLibLoad(3747): setup nss 1
04-16 15:48:38.710: E/GeckoLibLoad(3747): Load nss done
04-16 15:48:38.880: I/ActivityManager(1320): Displayed org.mozilla.fennec/.App: +1s514ms
04-16 15:48:39.221: I/dalvikvm(3747): Could not find method android.database.sqlite.SQLiteDatabase.enableWriteAheadLogging, referenced from method org.mozilla.fennec.db.BrowserProvider$DatabaseHelper.onOpen
04-16 15:48:39.221: W/dalvikvm(3747): VFY: unable to resolve virtual method 276: Landroid/database/sqlite/SQLiteDatabase;.enableWriteAheadLogging ()Z
04-16 15:48:39.221: D/dalvikvm(3747): VFY: replacing opcode 0x6e at 0x0033
04-16 15:48:39.871: D/dalvikvm(3747): GC_CONCURRENT freed 92K, 46% free 3071K/5639K, external 1224K/1516K, paused 3ms+6ms
04-16 15:48:40.142: D/GeckoBrowserProvider(3747): Can't create favicon bookmarkdefaults_title_abouthome
04-16 15:48:40.322: V/ProfileMigrator(3747): Name: places, pid=1, nid=0
04-16 15:48:40.332: V/ProfileMigrator(3747): Name: menu, pid=2, nid=3
04-16 15:48:40.352: V/ProfileMigrator(3747): Name: toolbar, pid=3, nid=2
04-16 15:48:40.362: V/ProfileMigrator(3747): Name: tags, pid=4, nid=4
04-16 15:48:40.362: V/ProfileMigrator(3747): Name: unfiled, pid=5, nid=5
04-16 15:48:40.362: I/ProfileMigrator(3747): Fetching bookmarks from places
04-16 15:48:40.392: E/GeckoLibLoad(3747): Throw
04-16 15:48:40.432: E/ProfileMigrator(3747): Failed to get bookmarks: 
04-16 15:48:40.432: E/ProfileMigrator(3747): org.mozilla.gecko.sqlite.SQLiteBridgeException: Can't prepare statement: no such column: favicon.guid
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.sqliteCall(Native Method)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.internalQuery(SQLiteBridge.java:243)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.rawQuery(SQLiteBridge.java:134)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.migrateBookmarks(ProfileMigrator.java:666)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.migratePlaces(ProfileMigrator.java:847)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.run(ProfileMigrator.java:897)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator.launch(ProfileMigrator.java:222)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator.launch(ProfileMigrator.java:216)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp.checkMigrateProfile(GeckoApp.java:2295)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp.access$500(GeckoApp.java:95)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp$37.run(GeckoApp.java:1786)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at android.os.Handler.handleCallback(Handler.java:587)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at android.os.Handler.dispatchMessage(Handler.java:92)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at android.os.Looper.loop(Looper.java:130)
04-16 15:48:40.432: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31)
04-16 15:48:40.522: I/ProfileMigrator(3747): Processed 0 history entries
04-16 15:48:40.522: I/ProfileMigrator(3747): Fetching 2000 more history entries
04-16 15:48:40.622: V/Telemetry(3747): Sending telemetry: {"value":6858,"name":"BROWSERPROVIDER_XUL_IMPORT_HISTORY"}
04-16 15:48:40.652: E/GeckoLibLoad(3747): Throw
04-16 15:48:40.682: E/ProfileMigrator(3747): Failed to get history: 
04-16 15:48:40.682: E/ProfileMigrator(3747): org.mozilla.gecko.sqlite.SQLiteBridgeException: Can't prepare statement: no such column: favicon.guid
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.sqliteCall(Native Method)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.internalQuery(SQLiteBridge.java:243)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.sqlite.SQLiteBridge.rawQuery(SQLiteBridge.java:134)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.doMigrateHistoryBatch(ProfileMigrator.java:513)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.migrateHistory(ProfileMigrator.java:582)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.migratePlaces(ProfileMigrator.java:854)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator$PlacesRunnable.run(ProfileMigrator.java:897)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator.launch(ProfileMigrator.java:222)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.ProfileMigrator.launch(ProfileMigrator.java:216)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp.checkMigrateProfile(GeckoApp.java:2295)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp.access$500(GeckoApp.java:95)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoApp$37.run(GeckoApp.java:1786)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at android.os.Handler.handleCallback(Handler.java:587)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at android.os.Handler.dispatchMessage(Handler.java:92)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at android.os.Looper.loop(Looper.java:130)
04-16 15:48:40.682: E/ProfileMigrator(3747): 	at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31)
04-16 15:48:40.682: I/ProfileMigrator(3747): Profile Migration run finished
04-16 15:48:40.692: V/Telemetry(3747): Sending telemetry: {"value":2155,"name":"BROWSERPROVIDER_XUL_IMPORT_TIME"}
04-16 15:48:40.692: I/GeckoApp(3747): Profile migration took 2273 ms
04-16 15:48:40.752: I/GeckoApp(3747): Startup mode: NEW_PROFILE
04-16 15:48:40.822: I/GeckoAboutHome(3747): filestream is null

Comment 1

[Gian-Carlo Pascutto [:gcp]]

Can you take a look into the places.sqlite database in your profile and check which tables are present?

The cause is this: "Can't prepare statement: no such column: favicon.guid"

I think the problem here is:

1) Favicons are not Synced.
2) You never browsed with the old profile, so it never stored any Favicons.

We don't handle the case where this required table is missing. I'm not sure if its important to do - I doubt this happens for real users because of the aforementioned 2 conditions.

>So far every time I start Firefox I see the import screen

This *is* an issue. We should probably mark migration as having run very early so even if it fails we do not try again.

Comment 2

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 1. Set Migration as finished if we encounter errors.

Comment 3

[Kevin Brosnan [Ex-Mozilla]]

I browsed a few pages that were bookmarks and made sure favicons were set.

Comment 4

[Richard Newman [:rnewman]]

> We don't handle the case where this required table is missing. I'm not sure
> if its important to do - I doubt this happens for real users because of the
> aforementioned 2 conditions.

Places initializes all of its tables at once. If the database exists, the tables exist.

The problem here is that you're migrating a v13 or earlier Places database, which doesn't have moz_favicons.guid -- that was added in v14. (Coincidentally, I wrote that code.)

See toolkit/components/places/Database.cpp:1600.

You probably want to run all of the Places migrations before migrating, perhaps by translating the Places Migrate*Up functions into Java.

Comment 5

[Richard Newman [:rnewman]]

It's reasonable to assume that we'll have a lot of users who gave up on XUL Fennec, and will have Places databases older than v20 (the current).

Comment 6

[Gian-Carlo Pascutto [:gcp]]

I'm not sure if we want to run migration code from one schema to another so we can then migrate to yet another schema again :)

Looking through that, I see ff10 has Places version 12 (which the documentation claims should cover as early as ff8). This is the earliest one with Bookmarks/History GUIDS. Places version 14 seems to have added the Favicon GUIDs. The changes after that up to Places 20 don't seem so relevant for us.

So there's only 2 cases here. I'll detect them and change the query as appropriate.

Comment 7

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 2. Don't migrate favicons GUIDs if not present

Comment 8

[Richard Newman [:rnewman]]

Comment on attachment 615908 [details] [diff] [review]
Patch 2. Don't migrate favicons GUIDs if not present

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

Looks like it'll work to me.

The only general thing I'd suggest is to break out additional constant strings for the shared clauses in these queries. They're 80% the same, so it'll save bugs later if you have

  private static final String BOOKMARK_QUERY_NO_GUID =
    SELECT_BOOKMARK_FIELDS +
    FAVICON_FIELDS_NO_GUID +
    FROM_BOOKMARKS_PLACES_FAVICONS_JOIN +
    ...;

That would have caught this error, for example: in one query you have

  "WHERE (places.hidden IS NULL " +
  " OR places.hidden <> 1) " +

and in another you only have

  "WHERE places.hidden <> 1 " +

::: mobile/android/base/ProfileMigrator.java
@@ +120,5 @@
>          "SELECT root_name, folder_id FROM moz_bookmarks_roots";
>      private final String kRootName     = "root_name";
>      private final String kRootFolderId = "folder_id";
>  
> +    private final String kBookmarkQueryGuid =

All of these strings should be static, and have JAVA_CONSTANT_NAMES.

Comment 9

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 2. Don't migrate favicons GUIDs if not present

Comment 10

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch 3. Fix up constant naming

Comment 11

[Gian-Carlo Pascutto [:gcp]]

>That would have caught this error

I agree on the principle (and I updated the patch), but this is not a bug - in fact, on the line above there is a comment explaining why it isn't!

>All of these strings should be static, and have JAVA_CONSTANT_NAMES.

The constant renaming is quite spammy so I put that in a separate patch.

Comment 12

[Richard Newman [:rnewman]]

(In reply to Gian-Carlo Pascutto (:gcp) from comment #11)

> I agree on the principle (and I updated the patch), but this is not a bug -
> in fact, on the line above there is a comment explaining why it isn't!

Nono, I didn't mean the bookmark clause was an error -- IMO it should be shared with the other branch in case there's a consistency issue in the source DB.

Comment 13

[Lucas Rocha (:lucasr)]

Comment on attachment 615643 [details] [diff] [review]
Patch 1. Set Migration as finished if we encounter errors.

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

Looks good. I assume this kind of situation will only happen is extreme or weird/unknown cases, right?

Comment 14

[Gian-Carlo Pascutto [:gcp]]

>Looks good. I assume this kind of situation will only happen is extreme or 
>weird/unknown cases, right?

Right, it's our insurance policy. If there's unforeseen problems, we bail out and don't try again, so we don't complicate things further for the user or sync.

Comment 15

[Lucas Rocha (:lucasr)]

Comment on attachment 615959 [details] [diff] [review]
Patch 2. Don't migrate favicons GUIDs if not present

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

::: mobile/android/base/ProfileMigrator.java
@@ +120,3 @@
>          "SELECT root_name, folder_id FROM moz_bookmarks_roots";
> +    private static final String kRootName     = "root_name";
> +    private static final String kRootFolderId = "folder_id";

The changes to make everything static are very verbose. I'd probably do it in a separate patch.

Comment 16

[Gian-Carlo Pascutto [:gcp]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/12a595c5d7a4
https://hg.mozilla.org/integration/mozilla-inbound/rev/a9ee797ccd07
https://hg.mozilla.org/integration/mozilla-inbound/rev/e320015d6348
https://hg.mozilla.org/integration/mozilla-inbound/rev/76c80a198eba

Comment 17

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/12a595c5d7a4
https://hg.mozilla.org/mozilla-central/rev/a9ee797ccd07
https://hg.mozilla.org/mozilla-central/rev/e320015d6348
https://hg.mozilla.org/mozilla-central/rev/76c80a198eba

Comment 18

[Adrian Tamas (:AdrianT)]

Attachment: logs profile migration

I can still reproduce the issue as described in the bug steps on:
Nightly 15.0a1 XUL 2012-05-03 / Nightly 15.0a1 Native 2012-05-04
Device: HTC Desire
OS: Android 2.2

Comment 19

[Gian-Carlo Pascutto [:gcp]]

What issue and what steps? Your log claims you have no history/bookmarks DB, so not seeing any history/bookmarks in Native Fennec would be the expected result.

I think you're seeing some variation of bug 746860?

Comment 20

[Adrian Tamas (:AdrianT)]

Using Nightly 15.0a1 XUL 2012-05-06 / Nightly 15.0a1 Native 2012-05-06 on HTC Desire running Android 2.2 following the steps:
1. Install Nightly XUL.
2. Move app to SD Card.
3. Set up sync.
4. Download and install Nightly Native.
5. Open Nightly.

Actual:
There are no Bookamrks and History. After checking I can actually see that user and passwords are synced so what I have described in Comment 18 may be caused by bug 746860. I will verify the issue once the bug is fixed.

Comment 21

[Gian-Carlo Pascutto [:gcp]]

Can't you verify by skipping the "Move app to SD card" step? It was present in the original report but it's unrelated to this bug.

Comment 22

[Adrian Tamas (:AdrianT)]

Migration is ok without moving the profile to the SD card except for the behavior from Bug 752444 where mobile bookmarks disappear from the bookmark list.