843361 - Dump list of open files if we fail to unlock the DB

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Data Providers, defect)

Description

[Mark Finkle (:mfinkle) (use needinfo?)]

If ensureDatabaseIsNotLocked fails, we should dump out the list of open files to see what process might be holding the DB file open.

Comment 1

[Lukas Blakk [:lsblakk] use ?needinfo]

I believe we're waiting on this to build Firefox 20 beta 1 for Mobile users - so please ping me when it's ready for approval in order to keep the builds moving forward as fast as we can.

Comment 2

[Mark Finkle (:mfinkle) (use needinfo?)]

Attachment: patch

This patch adds a simple dump of open files found by running "lsof" on the device. I call the method twice:

* Once before the code tests for a locked DB (this is debug code and should be removed)
* Once after the test for a locked DB fails to unlock the DB

I don't think this is working right yet. This is the type of out I see:
I/GeckoAppShell(11290): [OPENFILE] com.android.musicfx : /proc/11212/exe
I/GeckoAppShell(11290): [OPENFILE] com.android.musicfx : /proc/11212/root
I/GeckoAppShell(11290): [OPENFILE] com.google.android.gms : /proc/11227/exe
I/GeckoAppShell(11290): [OPENFILE] com.google.android.gms : /proc/11227/root
I/GeckoAppShell(11290): [OPENFILE] com.google.android.partnersetup : /proc/11242/exe
I/GeckoAppShell(11290): [OPENFILE] com.google.android.partnersetup : /proc/11242/root
I/GeckoAppShell(11290): [OPENFILE] com.google.android.gsf.login : /proc/11259/exe
I/GeckoAppShell(11290): [OPENFILE] com.google.android.gsf.login : /proc/11259/root
I/GeckoAppShell(11290): [OPENFILE] com.google.android.apps.maps:FriendService : /proc/11272/exe
I/GeckoAppShell(11290): [OPENFILE] com.google.android.apps.maps:FriendService : /proc/11272/root
I/GeckoAppShell(11290): [OPENFILE] org.mozilla.fennec_mfinkle : /dev/__properties__
I/GeckoAppShell(11290): [OPENFILE] com.google.android.apps.maps:LocationFriendService : /proc/11308/exe
I/GeckoAppShell(11290): [OPENFILE] com.google.android.apps.maps:LocationFriendService : /proc/11308/root

Notice that the files are only "exe" and "root", never anything else. On my rooted phone I see much more detail from lsof than this if I use "adb shell". But the phone only gives me the above output when run from within firefox.

Comment 3

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

Comment on attachment 716292 [details] [diff] [review]
patch

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

::: mobile/android/base/GeckoAppShell.java
@@ +1580,5 @@
> +            // alright, the rest are process entries.
> +            String output = null;
> +            while ((output = in.readLine()) != null) {
> +                String[] split = output.split("\\s+");
> +                if (split.length <= 9)

you want this to be split.length < 9.

As is you're only getting the lines that end with (readlink: Permission denied) after the file name

Comment 4

[Mark Finkle (:mfinkle) (use needinfo?)]

Attachment: patch 2

This patch dumps the list of open files associated with any "org.mozilla" process. We lookup the full name of the process because the "lsof" name is truncated.

We only dump this list if we are unable to unlock a DB. The output looks like this:
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /dev/pvrsrvkm
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /dev/pvrsrvkm
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /dev/ashmem
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /dev/pvrsrvkm
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /dev/pvrsrvkm
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /data/app/com.adobe.flashplayer-2.apk
I/GeckoAppShell(12415): [OPENFILE] org.mozilla.fennec_mfinkle(12415) : /data/app/com.adobe.flashplayer-2.apk

The (number) is the PID of the process

Comment 5

[Mark Finkle (:mfinkle) (use needinfo?)]

Attachment: refactor patch

Since we have two methods that lookup columns (both even lookup a PID column) in a process output stream, I felt keeping the EnumerateGeckoProcesses columns as static would be a potential maintenance bug. This patch makes the column indexes non-static.

We shouldn't see any performance hit since the "ps" header only has a few columns in it.

This patch is only needed for mozilla-central. No uplift needed.

Comment 6

[Mark Finkle (:mfinkle) (use needinfo?)]

Comment on attachment 716343 [details] [diff] [review]
patch 2

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 
User impact if declined: we want more logging for DB locked crashes
Testing completed (on m-c, etc.): 
Risk to taking this patch (and alternatives if risky): slight risk, but if something goes wrong it won't matter too much. we call this code before we know we're going to crash anyway.
String or UUID changes made by this patch: none

Comment 7

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

Comment on attachment 716343 [details] [diff] [review]
patch 2

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

::: mobile/android/base/GeckoAppShell.java
@@ +1560,5 @@
>      }
>  
> +    public static String getAppNameByPID(Context context, int pid) {
> +        ActivityManager manager = (ActivityManager) context.getSystemService(Context.ACTIVITY_SERVICE);
> +        for (ActivityManager.RunningAppProcessInfo processInfo : manager.getRunningAppProcesses()) {

This can be done more efficiently, at least by loading the processes into a map with the pid's as keys. But let's take it as is for now and follow up with that.

Comment 8

[Mark Finkle (:mfinkle) (use needinfo?)]

Core patch: https://hg.mozilla.org/integration/mozilla-inbound/rev/985efc588a5e

Comment 9

[Mark Finkle (:mfinkle) (use needinfo?)]

Core patch:
https://hg.mozilla.org/releases/mozilla-aurora/rev/3429bb5e8954
https://hg.mozilla.org/releases/mozilla-beta/rev/23f738b12fb7

Comment 10

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

Attachment: patch to get proc names more efficiently

Comment 11

[Mark Finkle (:mfinkle) (use needinfo?)]

Comment on attachment 716574 [details] [diff] [review]
patch to get proc names more efficiently

>-    static File sHomeDir = null;

Intentional?

>     public static void listOfOpenFiles() {
>+        Log.i(LOGTAG, "[OPENFILE] starting to list");

Do we really need this? I vote to remove it

>+            Map<Integer, String> pidNameMap = new TreeMap<Integer, String>();
>             // alright, the rest are open file entries.

nit: Blank line before the comment

>+                if (!TextUtils.isEmpty(name))
>                     Log.i(LOGTAG, "[OPENFILE] " + name + "(" + split[pidColumn] + ") : " + split[nameColumn]);

I still like the idea of doing some filtering here. Filtering filenames from "org.mozilla" folders would be enough I think. We only capture something like 200 lines of logcat in crash reports. This could be enough to blow the limit.

r+, but consider the filtering

Comment 12

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

(In reply to Mark Finkle (:mfinkle) from comment #11)
> Comment on attachment 716574 [details] [diff] [review]
> patch to get proc names more efficiently
> 
> >-    static File sHomeDir = null;
> 
> Intentional?
yes, this is an unused variable. Just figured I'd clean it up while I'm here.

> >     public static void listOfOpenFiles() {
> >+        Log.i(LOGTAG, "[OPENFILE] starting to list");
> 
> Do we really need this? I vote to remove it
nope, meant to remove it
> 
> >+            Map<Integer, String> pidNameMap = new TreeMap<Integer, String>();
> >             // alright, the rest are open file entries.
> 
> nit: Blank line before the comment
> 
> >+                if (!TextUtils.isEmpty(name))
> >                     Log.i(LOGTAG, "[OPENFILE] " + name + "(" + split[pidColumn] + ") : " + split[nameColumn]);
> 
> I still like the idea of doing some filtering here. Filtering filenames from
> "org.mozilla" folders would be enough I think. We only capture something
> like 200 lines of logcat in crash reports. This could be enough to blow the
> limit.
talked about this on irc, mfinkle is putting together yet another patch

Comment 13

[Mark Finkle (:mfinkle) (use needinfo?)]

Attachment: nit fixes and filtering changes

This patch builds on attachment 716574 [details] [diff] [review], adding filtering on the filename and fixing the nits

Comment 14

[Mark Finkle (:mfinkle) (use needinfo?)]

Comment on attachment 716574 [details] [diff] [review]
patch to get proc names more efficiently

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 
User impact if declined:
Testing completed (on m-c, etc.): 
Risk to taking this patch (and alternatives if risky): nothing more than the core patch, which is only called right before we crash anyway
String or UUID changes made by this patch: none

Comment 15

[Mark Finkle (:mfinkle) (use needinfo?)]

Comment on attachment 716629 [details] [diff] [review]
nit fixes and filtering changes

[Approval Request Comment]
See above

Comment 16

[Lukas Blakk [:lsblakk] use ?needinfo]

Comment on attachment 716574 [details] [diff] [review]
patch to get proc names more efficiently

fast-tracking approval here since we're still waiting to go on FF20 b1 for these landings and i trust mfinkle will land to all the affected branches in due course.

Comment 17

[Mark Finkle (:mfinkle) (use needinfo?)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/0c8353e38b3b

Comment 18

[Mark Finkle (:mfinkle) (use needinfo?)]

https://hg.mozilla.org/releases/mozilla-beta/rev/fb4ca44342cc

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/985efc588a5e
https://hg.mozilla.org/mozilla-central/rev/0c8353e38b3b

Comment 20

[Mark Finkle (:mfinkle) (use needinfo?)]

Landed the small refactor patch:
https://hg.mozilla.org/integration/mozilla-inbound/rev/7c9e1c72d931

Comment 21

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/7c9e1c72d931