How to count the time used to start an Activity

 

How does one count the time used to start an Activity?

You can analyze the Log (this is the Log of DDMS ).

When we click the touch button, the following Log A is displayed:

03-06 03:36:47. 865: VERBOSE/InputDevice (2486): ID [0] = 0 (0) Dn (0 => 1)

03-06 03:36:47. 865: INFO/PowerManagerService (2486): Ulight 3-> 7 | 0

03-06 03:36:47. 933: INFO/(2486): PRODUCT_SHIP = false

03-06 03:36:47. 933: VERBOSE/InputDevice (2486): ID [0] = 0 (0) Up (1 => 0)

When the system receives an Intent that starts the Activity, there will be Log B similar to the following:

03-06 03:36:47. 954: INFO/ActivityManager (2486): Starting activity: Intent {act = android. intent. action. MAIN cat = [android. intent. category. LAUNCHER] flg = 0x10200000 cmp = com. teleca /. contextMenuActivity}

When the system completes the Activity process to start, there will be a Log C similar to the following:

03-06 03:36:48. 068: INFO/ActivityManager (2486): Start proc com. teleca for activity com. teleca/. ContextMenuActivity: pid = 2933 uid = 10089 gids = {}

When the system completes displaying an Activity, there will be a Log D similar to the following:

03-06 03:36:48. 302: INFO/ActivityManager (2486): Displayed activity com. teleca/. ContextMenuActivity: 240 MS (total 41289 MS)

The time used to start the Activity is equal to the Log D time minus the Log A time.

That is: 03: 36: 48.302 minus 03:36:47. 933, simplified to: 48.302 minus 47.933 = 369 ms.

NOTE 1: The time from Log A to Log B is used by the system. :

NOTE 2: From Log B to Log D, it mainly refers to the time (on create (), onresume (), onDraw () used for activity creation ). 48.302 minus 47.954 = 348ms. Sometimes it also includes the time used by the system to create the application (APK) process of the activity.

NOTE 3: the meaning of "240 MS" and "(total 41289 MS)" for Log D is unclear. It's just that "240ms" is very close to the time from Log C to Log D.

Appendix 1:

A Log that starts the activity:

03-06 03:36:47. 865: VERBOSE/InputDevice (2486): ID [0] = 0 (0) Dn (0 => 1)

03-06 03:36:47. 865: INFO/PowerManagerService (2486): Ulight 3-> 7 | 0

03-06 03:36:47. 933: INFO/(2486): PRODUCT_SHIP = false

03-06 03:36:47. 933: VERBOSE/InputDevice (2486): ID [0] = 0 (0) Up (1 => 0)

03-06 03:36:47. 935: VERBOSE/WindowManager (2486): Dsptch 1x82.0 y592.0> Window {485bd6c0 com. sec. android. app. twlauncher/com. sec. android. app. twlauncher. launcher paused = false}

03-06 03:36:47. 954: INFO/ActivityManager (2486): Starting activity: Intent {act = android. intent. action. MAIN cat = [android. intent. category. LAUNCHER] flg = 0x10200000 cmp = com. teleca /. contextMenuActivity}

03-06 03:36:48. 029: INFO/Launcher (2570): onPause ()

03-06 03:36:48. 044: DEBUG/AudioHardwareALSA (2377): alsa open mode 0, device 2

03-06 03:36:48. 044: INFO/AudioHardwareALSA (2377): Try to open alsa playback device AndroidPlayback_Speaker_normal

03-06 03:36:48. 048: WARN/Launcher (2570): WallpaperManager setVisibility visible true

03-06 03:36:48. 068: INFO/ActivityManager (2486): Start proc com. teleca for activity com. teleca/. ContextMenuActivity: pid = 2933 uid = 10089 gids = {}

03-06 03:36:48. 099: INFO/AudioHardwareALSA (2377): Initialized alsa playback device AndroidPlayback_Speaker_normal

03-06 03:36:48. 099: DEBUG/AudioHardwareALSA (2377): Set playback pcm format to S16_LE (Signed 16 bit Little Endian)

03-06 03:36:48. 099: DEBUG/AudioHardwareALSA (2377): Using 2 channels for PLAYBACK.

03-06 03:36:48. 099: DEBUG/AudioHardwareALSA (2377): Set PLAYBACK sample rate to 44100 HZ

03-06 03:36:48. 099: DEBUG/AudioHardwareALSA (2377): Buffer size: 2048

03-06 03:36:48. 099: DEBUG/AudioHardwareALSA (2377): Latency: 46439

03-06 03:36:48. 134: INFO/WindowManager (2486): Setting rotation to 1, animFlags = 1

03-06 03:36:48. 154: INFO/ActivityManager (2486): Config changed: {scale = 1.0 imsi = 0/0 loc = en_CA touch = 3 keys = 1/1/2 nav = 1/1 orien = 2 layout = 34 uiMode = 17 seq = 3 FlipFont = 0}

03-06 03:36:48. 189: INFO/Launcher (2570): onWindowFocusChanged (false)

03-06 03:36:48. 302: INFO/ActivityManager (2486): Displayed activity com. teleca/. ContextMenuActivity: 240 MS (total 41289 MS)

 

From the column of robin