Skip to content

Commit 56bd5d9

Browse files
Add Android Startup Perfetto trace support (#4776)
* Added perfetto support for the android startup scenario runs. * Add perfetto to android-startup-scenarios doc. * Update per PR feedback. Includes updating the trace name to make the time human readable, and switching from catching the trace by taking the max startup and adding 3 seconds to instead just killing perfetto once startup testing is complete. --------- Co-authored-by: Matous Kozak <[email protected]>
1 parent c3b4ec9 commit 56bd5d9

File tree

2 files changed

+92
-3
lines changed

2 files changed

+92
-3
lines changed

docs/android-startup-scenarios.md

+2-1
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@
2828
4. Run the test:
2929

3030
```sh
31-
python test.py devicestartup --device-type android --package-path <path-to-apk> --package-name <apk-package-name> [--disable-animations] [--use-fully-drawn-time --fully-drawn-extra-delay <delay-in-sec>]
31+
python test.py devicestartup --device-type android --package-path <path-to-apk> --package-name <apk-package-name> [--disable-animations] [--use-fully-drawn-time --fully-drawn-extra-delay <delay-in-sec>] [--trace-perfetto]
3232
```
3333

3434
* Refer to the [Notes](./android-startup-scenarios.md#notes) below about specifying --use-fully-drawn-time --fully-drawn-extra-delay parameters.
@@ -62,3 +62,4 @@
6262
- Specific example command such as when using the runtime android example app: `python test.py devicestartup --device-type android --package-path HelloAndroid.apk --package-name net.dot.HelloAndroid`.
6363
- Other example commands and additional logic can be found in the `maui_scenarios_android.proj` and `runner.py` files in the `performance` repository.
6464
- If using `[--use-fully-drawn-time --fully-drawn-extra-delay <delay in sec>]` arguments, the Android app must have reportFullyDrawn() called on a ComponentActivity. Reference: https://developer.android.com/topic/performance/vitals/launch-time#retrieve-TTFD.
65+
- `[--trace-perfetto]` will take a perfetto trace after the execution of the normal startup testing to ensure it does not impact results. The resulting trace will then be saved off of the android device and into `tracedir` in the same directory as test.py. If running in a pipeline, this file should also be uploaded as a result.

src/scenarios/shared/runner.py

+90-2
Original file line numberDiff line numberDiff line change
@@ -76,6 +76,7 @@ def parseargs(self):
7676
devicestartupparser.add_argument('--fully-drawn-extra-delay', help='Set an additional delay time for an Android app to reportFullyDrawn (seconds), not on iOS. This should be greater than the greatest amount of extra time expected between first frame draw and reportFullyDrawn being called. Default = 3 seconds', type=int, default=3, dest='fullyDrawnDelaySecMax')
7777
devicestartupparser.add_argument('--fully-drawn-magic-string', help='Set the magic string that is logged by the app to indicate when the app is fully drawn. Required when using --use-fully-drawn-time on iOS.', type=str, dest='fullyDrawnMagicString')
7878
devicestartupparser.add_argument('--time-from-kill-to-start', help='Set an additional delay time for ensuring an app is cleared after closing the app on Android, not on iOS. This should be greater than the greatest amount of expected time needed between closing an app and starting it again for a cold start. Default = 3 seconds', type=int, default=3, dest='closeToStartDelay')
79+
devicestartupparser.add_argument('--trace-perfetto', help='Android Only. Trace the startup with Perfetto and save to the "traces" directory.', action='store_true', dest='traceperfetto')
7980
self.add_common_arguments(devicestartupparser)
8081

8182
devicememoryconsumptionparser = subparsers.add_parser(const.DEVICEMEMORYCONSUMPTION,
@@ -197,6 +198,7 @@ def parseargs(self):
197198
self.fullyDrawnDelaySecMax = args.fullyDrawnDelaySecMax
198199
self.fullyDrawnMagicString = args.fullyDrawnMagicString
199200
self.closeToStartDelay = args.closeToStartDelay
201+
self.traceperfetto = args.traceperfetto
200202

201203
if self.testtype == const.DEVICEMEMORYCONSUMPTION:
202204
self.packagepath = args.packagepath
@@ -573,11 +575,97 @@ def run(self):
573575
elif len(captureList) == 2: # Have s and ms, but maybe not padded ms, pad and combine (zfill left pads with 0)
574576
formattedTime = f"TotalTime: {captureList[0]}{captureList[1].zfill(3)}\n"
575577
else:
576-
getLogger().error("Time capture failed, found {len(captureList)}")
578+
getLogger().error(f"Time capture failed, found {len(captureList)}")
577579
raise Exception("Android Time Capture Failed! Incorrect number of captures found.")
578580
allResults.append(formattedTime) # append TotalTime: (TIME)
579581
time.sleep(self.closeToStartDelay) # Delay in seconds for ensuring a cold start
580-
582+
583+
if self.traceperfetto:
584+
perfetto_device_save_file = f'/data/misc/perfetto-traces/perfetto_trace_{time.time()}'
585+
original_traced_enable = None
586+
perfetto_terminated = False
587+
588+
stop_perfetto_cmd = xharness_adb() + [ # Stop perfetto now that the app. Sending a Terminate signal should be enough per the longer trace capturing guidance here: https://perfetto.dev/docs/concepts/config#android.
589+
'shell',
590+
'pkill -TERM perfetto'
591+
]
592+
593+
try:
594+
getLogger().info("Clearing potential previous running perfetto traces")
595+
RunCommand(stop_perfetto_cmd, verbose=True).run()
596+
597+
# Get the current value of persist.traced.enable
598+
getLogger().info("Getting current persist.traced.enable value")
599+
get_traced_cmd = xharness_adb() + [
600+
'shell',
601+
'getprop persist.traced.enable'
602+
]
603+
get_traced_result = RunCommand(get_traced_cmd, verbose=True)
604+
get_traced_result.run()
605+
original_traced_enable = get_traced_result.stdout.strip()
606+
607+
# Setup the phone props to allow perfetto to run properly
608+
getLogger().info("Setting up the device for Perfetto")
609+
setup_perfetto_cmd = xharness_adb() + [
610+
'shell',
611+
'setprop persist.traced.enable 1'
612+
]
613+
RunCommand(setup_perfetto_cmd, verbose=True).run()
614+
615+
getLogger().info("Tracing with Perfetto")
616+
# Get the max TotalTime from the allResults list in seconds
617+
max_startup_time_sec = int(max(int(re.search(r"TotalTime: (\d+)", str(result)).group(1)) for result in allResults) / 1000)
618+
perfetto_max_trace_time_sec = max_startup_time_sec * 2 # Set the max trace time to be double the max startup time
619+
if max_startup_time_sec > 60:
620+
getLogger().error(f"Max startup time is greater than 60 seconds (Max startup time: {max_startup_time_sec}), this means something probably went wrong.")
621+
raise Exception("Max startup time is greater than 60 seconds, this means something probably went wrong.")
622+
623+
perfetto_cmd = xharness_adb() + [
624+
'shell',
625+
f'perfetto --background --txt -o {perfetto_device_save_file} --time {perfetto_max_trace_time_sec}s -b 64mb sched freq idle am wm gfx view binder_driver hal dalvik camera input res memory'
626+
]
627+
RunCommand(perfetto_cmd, verbose=True).run()
628+
629+
# Run the startup test with the trace running (only once)
630+
getLogger().info("Running startup test with Perfetto trace running")
631+
traced_start = RunCommand(androidHelper.startappcommand, verbose=True)
632+
traced_start.run()
633+
634+
getLogger().info("Stopping perfetto trace capture")
635+
RunCommand(stop_perfetto_cmd, verbose=True).run()
636+
perfetto_terminated = True
637+
638+
# Pull the trace from the device and store in the traceperfetto directory
639+
pull_trace_cmd = xharness_adb() + [
640+
'pull',
641+
perfetto_device_save_file,
642+
os.path.join(os.getcwd(), const.TRACEDIR, f'perfetto_startup_trace_{self.packagename}_{datetime.now().strftime("%Y-%m-%d_%H-%M-%S")}.trace')
643+
]
644+
RunCommand(pull_trace_cmd, verbose=True).run()
645+
646+
# Delete the trace file on the android device
647+
getLogger().info("Deleting the trace file on the device.")
648+
delete_trace_cmd = xharness_adb() + [
649+
'shell',
650+
f'rm -rf {perfetto_device_save_file}'
651+
]
652+
RunCommand(delete_trace_cmd, verbose=True).run()
653+
654+
finally:
655+
if not perfetto_terminated:
656+
# If we didn't terminate perfetto, we need to stop it now, although it will time out as well if this manages to fail.
657+
getLogger().info("Perfetto not terminated, stopping it now")
658+
RunCommand(stop_perfetto_cmd, verbose=True).run()
659+
660+
# Restore original persist.traced.enable value if we saved one
661+
if original_traced_enable is not None and original_traced_enable != "1":
662+
getLogger().info(f"Restoring persist.traced.enable to original value: {original_traced_enable}")
663+
restore_traced_cmd = xharness_adb() + [
664+
'shell',
665+
f'setprop persist.traced.enable {original_traced_enable}'
666+
]
667+
RunCommand(restore_traced_cmd, verbose=True).run()
668+
581669
finally:
582670
androidHelper.close_device()
583671

0 commit comments

Comments
 (0)