1152507 - Autophone - improve detection of initial gecko start time.

Status: RESOLVED FIXED

(Testing Graveyard :: Autophone, defect)

Description

[Bob Clary [:bc] (inactive)]

Attachment: Sample logcats illustrating different activitymanager messages.

Currently the performance related autophone tests use the first gecko related message to determine the initial time to use to convert the absolute times for throbber start and stop to times relative to the start of fennec. This was done because I erroneously thought the ActivityManager logcat message showing the intent to start the app wasn't always available.

It isn't always available but it does appear to be available on all of the versions of Android running on my Nexus devices (2.3, 4.2, 4.3, 4.4). The only device where it does not appear is on my Samsung Galaxy S3 with Android 4.0. I don't know if this is specific to the gs3 or Android 4.0.

Autophone should use the ActivityManager message if it is available and only fall back to the first Gecko message if the ActivityManager message is not available.

I've attached the relevant parts of the logcat output for my nexus devices:

for Fennec on Android 2.3, the sequence is:

Starting: Intent { act=android.intent.action.VIEW dat=... flg=0x10000000 cmp=org.mozilla.fennec/.App (has extras) } from pid ...

Start proc org.mozilla.fennec for activity org.mozilla.fennec/.App: pid=... uid=... gids={...}

for Fennec on Android 4.2+
START u0 {act=android.intent.action.VIEW dat=... flg=0x10000000 cmp=org.mozilla.fennec/.App (has extras)} from pid ...

Start proc org.mozilla.fennec for activity org.mozilla.fennec/.App: pid=... uid=... gids={...}

Question: Which is appropriate? The initial Starting|START intent or the subsequent Start proc? There is a potentially significant delay between the two messages. Often there are dalvikvm related messages relating to GC and the heap between the two. The second is more consistent across Android versions and appears to omit dalvikvm related operations which we may not care about.

for Webapp on Android 2.3, the sequence is:

Starting: Intent { act=android.intent.action.MAIN flg=0x10000000 cmp=com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c/org.mozilla.android.synthapk.LauncherActivity (has extras) } from pid ...

Start proc com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c for activity com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c/org.mozilla.android.synthapk.LauncherActivity: pid=... uid=... gids={}

Starting: Intent { act=android.intent.action.VIEW cat=[android.intent.category.DEFAULT] typ=application/webapp cmp=org.mozilla.fennec/org.mozilla.gecko.webapp.Dispatcher (has extras) } from pid ...

Start proc org.mozilla.fennec for activity org.mozilla.fennec/org.mozilla.gecko.webapp.Dispatcher: pid=... uid=... gids={...}

For webapp on Android 4.2+, the sequence is:

START u0 {act=android.intent.action.MAIN flg=0x10000000 cmp=com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c/org.mozilla.android.synthapk.LauncherActivity (has extras)} from pid ...

Start proc com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c for activity com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c/org.mozilla.android.synthapk.LauncherActivity: pid=12462 uid=... gids={...}

START u0 {act=android.intent.action.VIEW cat=[android.intent.category.DEFAULT] typ=application/webapp cmp=org.mozilla.fennec/org.mozilla.gecko.webapp.Dispatcher (has extras)} from pid ...

Start proc org.mozilla.fennec for activity org.mozilla.fennec/org.mozilla.gecko.webapp.Dispatcher: pid=... uid=... gids={...}

START u0 {act=android.intent.action.VIEW cat=[android.intent.category.DEFAULT] typ=application/webapp cmp=org.mozilla.fennec/org.mozilla.gecko.webapp.Webapps$Webapp0 (has extras)} from pid ...

Start proc org.mozilla.fennec:org.mozilla.fennec.Webapp0 for activity org.mozilla.fennec/org.mozilla.gecko.webapp.Webapps$Webapp0: pid= uid=... gids={...}

Question: Again we have the question whether to use the initial Starting|START intent or the subsequent Start proc, but in addition which activity should we use? LauncherActivity, Dispatcher, or Webapps$Webapp0 ?

Comment 1

[Bob Clary [:bc] (inactive)]

NIing mfinkle and blassey in addition to snorp since he is on PTO.

Comment 2

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

I would keep it simple and consistent, while trying to get a better start marker. For me, that means using "Start proc ...", for both, and using the earliest "Start proc ..." for webapps. That should be the one used to launch the wrapper APK, which for you is "com.firefox.cli.apk.webappstartupperformancetestbclary.pc91282b8e6a542101851c47a670b9c8c"

My 2cents

Comment 3

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

I concur, I'd use which ever comes first. Not sure if there was a second part to that question or not.

Comment 4

[Bob Clary [:bc] (inactive)]

Attachment: pr 23

tests well.

Comment 5

[Bob Clary [:bc] (inactive)]

gbrown: ignore that subproject commit to ep1. It is part of a different bug.

Comment 6

[Geoff Brown [:gbrown]]

Comment on attachment 8591030 [details] [review]
pr 23

You probably don't need to check for the logcat prefix now that you are checking for a more specific message, but it's fine just as it is too.

Comment 7

[Bob Clary [:bc] (inactive)]

https://github.com/mozilla/autophone/commit/f232cf4e23a22706d8c573ff58012cf90208787a