1359176 - Add GeckoView example app performance logs

Status: RESOLVED FIXED

(Core Graveyard :: Embedding: APIs, enhancement)

Description

[Eugen Sawin [:esawin]]

Add performance logs analogue to Fennec's S1/S2 logs to the GeckoView example app .

Comment 1

[Eugen Sawin [:esawin]]

Attachment: 0001-Bug-1359176-1.0-Add-performance-logs-to-GeckoView-ex.patch

Add GeckoView example app startup and page load times and rename Fennec throbber times for consistency.

Do we care about Gecko or GeckoView ready states?

Comment 2

[James Willcox (:snorp) ([e-mail]) (he/him)]

Comment on attachment 8861144 [details] [diff] [review]
0001-Bug-1359176-1.0-Add-performance-logs-to-GeckoView-ex.patch

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

We want to log System.uptimeMillis() in the log messages so bc doesn't have to rely on logcat time. Also, they should be easily machine parseable. JSON?

Comment 3

[Bob Clary [:bc] (inactive)]

java.lang.System.currentTimeMillis() ?

Comment 4

[Bob Clary [:bc] (inactive)]

Actually, looking at https://developer.android.com/reference/android/os/SystemClock.html 

android.os.SystemClock.uptimeMillis()
This clock stops when the system enters deep sleep (CPU off, display dark, device waiting for external input), but is not affected by clock scaling, idle, or other power saving mechanisms. 

java.lang.System.currentTimeMillis()
The wall clock can be set by the user or the phone network (see setCurrentTimeMillis(long)), so the time may jump backwards or forwards unpredictably. This clock should only be used when correspondence with real-world dates and times is important, such as in a calendar or alarm clock application. Interval or elapsed time measurements should use a different clock. 

android.os.SystemClock.elapsedRealtime() 
the time since the system was booted, and include deep sleep. This clock is guaranteed to be monotonic, and continues to tick even when the CPU is in power saving modes, so is the recommend basis for general purpose interval timing. 

android.os.SystemClock.uptimeMillis() appears to be sufficient though it may be affected if we waiting for input or if the display is dark.

android.os.SystemClock.elapsedRealtime() actually seems the best choice.

android.os.SystemClock.uptimeMillis() is used in many different places in the code. I wonder if we shouldn't be consistent and just use android.os.SystemClock.elapsedRealtime() everywhere?

Comment 5

[James Willcox (:snorp) ([e-mail]) (he/him)]

Yeah, according to that, elapsedRealtime() does look like the right choice.

Comment 6

[Bob Clary [:bc] (inactive)]

what is bug 1357177 "use the new marker i.e. 'time to first nonblank paint'" and do we care?

Comment 7

[Eugen Sawin [:esawin]]

Attachment: 0001-Bug-1359176-1.1-Add-consistent-performance-logs-acro.patch

Replaced uptimeMillis() with elapsedRealtime() for all zerdatime logs.

Removed "* chrome startup finished" logs because their JS timestamps were not comparable and therefore not very useful.
"page load start" for "about:blank" should be close enough to the chrome startup finish, if we are interested in that event timestamp.

Is there anything else we could include into the logs to help with the measurement?

Comment 8

[Bob Clary [:bc] (inactive)]

Attachment: bug-1359176-v1.patch

Handle the new messages in Autophone. This needs to land prior to the actual change. I've tested it with existing builds and with builds containing the changes.

Comment 9

[Bob Clary [:bc] (inactive)]

Comment on attachment 8861593 [details] [diff] [review]
0001-Bug-1359176-1.1-Add-consistent-performance-logs-acro.patch

lgtm.

Comment 10

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8861861 [details] [diff] [review]
bug-1359176-v1.patch

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

this simplifies a lot of code.

Comment 11

[Bob Clary [:bc] (inactive)]

https://github.com/mozilla/autophone/commit/5fcc843424658b72888cd577228a65d1353df693

will deploy in a few minutes.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f811e55616db
[1.1] Add consistent performance logs across the GeckoView example app and Fennec. r=bc

Comment 13

[Carsten Book [:Tomcat]]

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