749727 - java.lang.UnsatisfiedLinkError: openDatabase when installing Aurora for the first time

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: General, defect)

Description

[Brad Lassey [:blassey] (use needinfo?)]

I saw this yesterday when installing on the Droid Pro, running 2.2. Wes and I tried to bisect and it seems that once a build runs, it no longer crashes even with previously crashing builds.

Today I installed on a Galaxy S running 2.3 and have the same behavior

Relevant logcat:
E/GeckoLibLoad( 2115): Load nss start
E/GeckoLinker( 2115): /data/app/org.mozilla.fennec_aurora-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020de0
E/GeckoLinker( 2115): /data/app/org.mozilla.fennec_aurora-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020b98 for symbol "__cxa_begin_cleanup"
E/GeckoLinker( 2115): /data/app/org.mozilla.fennec_aurora-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020cb0 for symbol "__cxa_type_match"
E/GeckoLibLoad( 2115): setup nss 1
E/GeckoLibLoad( 2115): Load nss done
W/dalvikvm( 2115): No implementation found for native Lorg/mozilla/gecko/sqlite/SQLiteBridge;.openDatabase (Ljava/lang/String;)J
E/JavaBinder( 2115): *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
E/JavaBinder( 2115): java.lang.UnsatisfiedLinkError: openDatabase
E/JavaBinder( 2115): 	at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(Native Method)
E/JavaBinder( 2115): 	at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(SQLiteBridge.java:255)
E/JavaBinder( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDB(GeckoProvider.java:120)
E/JavaBinder( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDatabaseForProfile(GeckoProvider.java:166)
E/JavaBinder( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDatabase(GeckoProvider.java:210)
E/JavaBinder( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.query(GeckoProvider.java:343)
E/JavaBinder( 2115): 	at android.content.ContentProvider$Transport.bulkQuery(ContentProvider.java:174)
E/JavaBinder( 2115): 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:111)
E/JavaBinder( 2115): 	at android.os.Binder.execTransact(Binder.java:320)
E/JavaBinder( 2115): 	at dalvik.system.NativeStart.run(Native Method)
W/dalvikvm( 2115): threadid=7: thread exiting with uncaught exception (group=0x40015560)
E/AndroidRuntime( 2115): FATAL EXCEPTION: Binder Thread #1
E/AndroidRuntime( 2115): java.lang.UnsatisfiedLinkError: openDatabase
E/AndroidRuntime( 2115): 	at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(Native Method)
E/AndroidRuntime( 2115): 	at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(SQLiteBridge.java:255)
E/AndroidRuntime( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDB(GeckoProvider.java:120)
E/AndroidRuntime( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDatabaseForProfile(GeckoProvider.java:166)
E/AndroidRuntime( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.getDatabase(GeckoProvider.java:210)
E/AndroidRuntime( 2115): 	at org.mozilla.fennec_aurora.db.GeckoProvider.query(GeckoProvider.java:343)
E/AndroidRuntime( 2115): 	at android.content.ContentProvider$Transport.bulkQuery(ContentProvider.java:174)
E/AndroidRuntime( 2115): 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:111)
E/AndroidRuntime( 2115): 	at android.os.Binder.execTransact(Binder.java:320)
E/AndroidRuntime( 2115): 	at dalvik.system.NativeStart.run(Native Method)
D/VoiceDialerReceiver( 1930): onReceive Intent { act=android.intent.action.PACKAGE_CHANGED dat=package:com.android.vending flg=0x10000000 cmp=com.android.voicedialer/.VoiceDialerReceiver (has extras) }
D/szipinf (  203): Initializing inflate state
D/szipinf (  203): Initializing inflate state
D/szipinf (  203): Initializing inflate state

Comment 1

[Richard Newman [:rnewman]]

I would be surprised if this were not the root cause of Bug 745837.

Comment 2

[JP Rosevear [:jpr]]

So far only seems to be seen with Aurora builds.

Comment 3

[Erin Lancaster [:elan]]

Do we know if this is seen going from Aurora 14 to Aurora 14 or has this been reproduced by installing Aurora 14 over Aurora 13?

Comment 4

[Richard Newman [:rnewman]]

Brad, do you have earlier log than you posted in Comment 0?

loadMozGlue is called before loadNSSLibs ("Load nss start...")... and it's libmozglue.so which provides openDatabase.

This looks like a failure to load libmozglue.so, so I'm hopeful that an earlier log snippet will provide a clue.

(Can't resist debugging...)

Comment 5

[Brad Lassey [:blassey] (use needinfo?)]

Attachment: a longer log

Comment 6

[Richard Newman [:rnewman]]

I/ActivityThread( 1482): Pub org.mozilla.fennec.db.passwords: org.mozilla.fennec.db.PasswordsProvider
D/dalvikvm( 1482): Added shared lib /data/data/org.mozilla.fennec/lib/libmozglue.so 0x40534ed8
...
I/ActivityThread( 1482): Pub org.mozilla.fennec_aurora.db.passwords: org.mozilla.fennec_aurora.db.PasswordsProvider
D/dalvikvm( 1482): Added shared lib /data/data/org.mozilla.fennec_aurora/lib/libmozglue.so 0x405151b8

Android is preparing the PasswordsProvider for both Fennec and Aurora.

In the same thread.

And the *other* one is dying:

I/ActivityManager(  203): Process org.mozilla.gecko.PasswordsProvider (pid 1482) has died.
I/ActivityManager(  203): Kill org.mozilla.fennec_aurora (pid 1459): provider org.mozilla.fennec_aurora.db.PasswordsProvider in dying process org.mozilla.gecko.PasswordsProvider

Presumably it's dying because *both* load libmozglue (which is fine), but the Fennec provider does not load the SQLite lib, because that's loaded by GeckoApp (which is Aurora in this case).

And then it dies before Aurora's gets to run, and takes the whole process out with it.

Comment 7

[Richard Newman [:rnewman]]

If I had to take a stab at a single-line fix for this, it would be:

-                   android:process="org.mozilla.gecko.PasswordsProvider"/>
+                   android:process="@ANDROID_PACKAGE_NAME@.PasswordsProvider"/>

Android is starting a named thread that we're sharing between two applications (Nightly and Aurora).

It's publishing the content providers from *both* applications:

https://github.com/android/platform_frameworks_base/blob/master/core/java/android/app/ActivityThread.java#L3978

Changing the process identifier to be app-specific should avoid this, and thus avoid Android loading our libraries twice in the same process.

Comment 8

[Richard Newman [:rnewman]]

Attachment: Proposed patch for Aurora. v1

Testing that hypothesis, let's get an Aurora build that uses a different process name and see if it crashes in the same situation.

Brad, are you able to make an Aurora build and try this out?

Comment 9

[Richard Newman [:rnewman]]

Of note: there might be a requirement here that both builds are built/signed by the same developer key/ID/whatever in order to get a failure.

Please test that you get a failure with a local/try Aurora build before seeing if you *don't* get a failure with the patch!

Comment 10

[Brad Lassey [:blassey] (use needinfo?)]

(In reply to Richard Newman [:rnewman] from comment #9)
> Of note: there might be a requirement here that both builds are built/signed
> by the same developer key/ID/whatever in order to get a failure.
I suspect the same
> 
> Please test that you get a failure with a local/try Aurora build before
> seeing if you *don't* get a failure with the patch!
unfortunately, I can't reproduce with a private build, only the "official" aurora builds.

Comment 11

[David Bolter [:davidb] (NeedInfo me for attention)]

FWIW I tried installing Aurora and everything seemed to go fine (didn't do/check logcat).
Galaxy Nexus (Google Samsung)
Nightly was already installed.
Android 4.0.2

Comment 12

[Richard Newman [:rnewman]]

(In reply to Brad Lassey [:blassey] from comment #10)

> unfortunately, I can't reproduce with a private build, only the "official"
> aurora builds.

This should be a very safe patch on any branch. If you're unable to test with a local build, it should be fine to land this and try for real, if you're OK making that risk tradeoff. If I'm not mistaken, at worst it'll be wasted effort.

(Most likely this patch should land anyway; I don't see any reason why we'd want multiple Firefox versions to share a process with different shared library versions.)

Comment 13

[u279076]

Could not reproduce this using lastest-mozilla-aurora-android from 2012-04-30 on the following devices:

 * Google Nexus S running ICS 4.0.4
 * Asus TF201 running ICS 4.0.2
 * Motorola XOOM running Honeycomb 3.2.0

Comment 14

[Brad Lassey [:blassey] (use needinfo?)]

Comment on attachment 619463 [details] [diff] [review]
Proposed patch for Aurora. v1

[Triage Comment]

Comment 15

[Richard Newman [:rnewman]]

Aurora:

https://hg.mozilla.org/releases/mozilla-aurora/rev/a3a4c8efa239

Comment 16

[Richard Newman [:rnewman]]

https://hg.mozilla.org/mozilla-central/rev/23b86b775f6f

*crosses fingers*

Comment 17

[Richard Newman [:rnewman]]

This needs to reland, because it triggered Bug 700722.

Backed out:

http://hg.mozilla.org/mozilla-central/rev/6e34995a746e

Comment 18

[Richard Newman [:rnewman]]

Attachment: Revised patch for inbound. v1

Hacky and awful: preprocess our package name to avoid triggering Bug 750548.

Building this locally now, see if it works, then I'll push it somewhere.

Comment 19

[Richard Newman [:rnewman]]

This *should* fix Aurora.

https://hg.mozilla.org/releases/mozilla-aurora/rev/47ea3be13859

Comment 20

[Richard Newman [:rnewman]]

The bug that will not die. Talos is *still* detecting browser not closed after munging android:process to org.m0zill4.fennec_aurora.

Trying a try build with org.mozilla.f3nnec_aurora. I feel so sad.

Comment 21

[Richard Newman [:rnewman]]

And again. Thanks, philor, for figuring out what string talos was using.

*crosses fingers again*

https://hg.mozilla.org/releases/mozilla-aurora/rev/58c351982d75

Comment 22

[Richard Newman [:rnewman]]

Relanded in inbound. Second Aurora fix worked (f3nn3c rather than m0zill4). I h4t3 j00, t4l05.

https://hg.mozilla.org/integration/mozilla-inbound/rev/ac1504ff8740

No rush to uplift this to m-c; with the Aurora change, Nightly and Aurora won't collide.

Comment 23

[Brad Lassey [:blassey] (use needinfo?)]

If rnewman's theory is correct, we won't see this during the beta cycle but we will see it when we go to release for people that already have beta installed.

Comment 24

[Richard Newman [:rnewman]]

(In reply to Brad Lassey [:blassey] from comment #23)
> If rnewman's theory is correct, we won't see this during the beta cycle but
> we will see it when we go to release for people that already have beta
> installed.

If there's a preprocessor directive that indicates beta versus release, then we could address that, too.

Comment 25

[(no longer active)]

https://hg.mozilla.org/mozilla-central/rev/ac1504ff8740

Comment 26

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Not sure how to test for this issue.  Do we just monitor Socorro in beta period to see if this pops up?

Comment 27

[Adrian Tamas (:AdrianT)]

Clearing the qawanted flag since this was fixed