diff options
author | Igor Murashkin <iam@google.com> | 2019-04-17 12:28:19 -0700 |
---|---|---|
committer | Igor Murashkin <iam@google.com> | 2019-04-24 15:24:25 -0700 |
commit | 7ab5c4d6e65e6b041d686767d377765ad788a695 (patch) | |
tree | f66a1874fe4b03ec904b061ea48f992381dcfcaf /startop/scripts | |
parent | 8298ae003997f53cdef1f39b4d5bfafc0cf06db3 (diff) |
startop: Update app_startup_runner to work with iorapd
Script measures app startup times with/without iorapd-based
prefetching against a cold (or warm) baseline.
mlock/fadvise readahead options now use iorapd to exercise
real code to do prefetching.
Bug: 72170747
Change-Id: I28affac3470271e46febb0e22a6dc9543258b4a4
Diffstat (limited to 'startop/scripts')
-rwxr-xr-x | startop/scripts/app_startup/app_startup_runner.py | 103 | ||||
-rwxr-xr-x | startop/scripts/app_startup/launch_application | 18 | ||||
-rwxr-xr-x | startop/scripts/app_startup/lib/common | 111 | ||||
-rwxr-xr-x | startop/scripts/app_startup/run_app_with_prefetch | 45 | ||||
-rwxr-xr-x | startop/scripts/iorap/collector | 389 | ||||
-rwxr-xr-x | startop/scripts/iorap/common | 207 | ||||
-rwxr-xr-x | startop/scripts/iorap/pull_textcache | 24 |
7 files changed, 868 insertions, 29 deletions
diff --git a/startop/scripts/app_startup/app_startup_runner.py b/startop/scripts/app_startup/app_startup_runner.py index 780bb4eaeeef..adf2ad808ea8 100755 --- a/startop/scripts/app_startup/app_startup_runner.py +++ b/startop/scripts/app_startup/app_startup_runner.py @@ -27,12 +27,13 @@ # import argparse +import asyncio import csv import itertools import os -import subprocess import sys import tempfile +import time from typing import Any, Callable, Dict, Generic, Iterable, List, NamedTuple, TextIO, Tuple, TypeVar, Optional, Union # The following command line options participate in the combinatorial generation. @@ -44,7 +45,7 @@ _RUN_SCRIPT=os.path.join(os.path.dirname(os.path.realpath(__file__)), 'run_app_w RunCommandArgs = NamedTuple('RunCommandArgs', [('package', str), ('readahead', str), ('compiler_filter', Optional[str])]) CollectorPackageInfo = NamedTuple('CollectorPackageInfo', [('package', str), ('compiler_filter', str)]) -_COLLECTOR_SCRIPT=os.path.join(os.path.dirname(os.path.realpath(__file__)), 'collector') +_COLLECTOR_SCRIPT=os.path.join(os.path.dirname(os.path.realpath(__file__)), '../iorap/collector') _COLLECTOR_TIMEOUT_MULTIPLIER = 2 # take the regular --timeout and multiply by 2; systrace starts up slowly. _UNLOCK_SCREEN_SCRIPT=os.path.join(os.path.dirname(os.path.realpath(__file__)), 'unlock_screen') @@ -217,25 +218,95 @@ def make_script_command_with_temp_output(script: str, args: List[str], **kwargs) cmd = cmd + ["--output", tmp_output_file.name] return cmd, tmp_output_file -def execute_arbitrary_command(cmd: List[str], simulate: bool, timeout: int) -> Tuple[bool, str]: +async def _run_command(*args : List[str], timeout: Optional[int] = None) -> Tuple[int, bytes]: + # start child process + # NOTE: universal_newlines parameter is not supported + process = await asyncio.create_subprocess_exec(*args, + stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.STDOUT) + + script_output = b"" + + _debug_print("[PID]", process.pid) + +#hack +# stdout, stderr = await process.communicate() +# return (process.returncode, stdout) + + timeout_remaining = timeout + time_started = time.time() + + # read line (sequence of bytes ending with b'\n') asynchronously + while True: + try: + line = await asyncio.wait_for(process.stdout.readline(), timeout_remaining) + _debug_print("[STDOUT]", line) + script_output += line + + if timeout_remaining: + time_elapsed = time.time() - time_started + timeout_remaining = timeout - time_elapsed + except asyncio.TimeoutError: + _debug_print("[TIMEDOUT] Process ", process.pid) + +# if process.returncode is not None: +# #_debug_print("[WTF] can-write-eof?", process.stdout.can_write_eof()) +# +# _debug_print("[TIMEDOUT] Process already terminated") +# (remaining_stdout, remaining_stderr) = await process.communicate() +# script_output += remaining_stdout +# +# code = await process.wait() +# return (code, script_output) + + _debug_print("[TIMEDOUT] Sending SIGTERM.") + process.terminate() + + # 1 second timeout for process to handle SIGTERM nicely. + try: + (remaining_stdout, remaining_stderr) = await asyncio.wait_for(process.communicate(), 5) + script_output += remaining_stdout + except asyncio.TimeoutError: + _debug_print("[TIMEDOUT] Sending SIGKILL.") + process.kill() + + # 1 second timeout to finish with SIGKILL. + try: + (remaining_stdout, remaining_stderr) = await asyncio.wait_for(process.communicate(), 5) + script_output += remaining_stdout + except asyncio.TimeoutError: + # give up, this will leave a zombie process. + _debug_print("[TIMEDOUT] SIGKILL failed for process ", process.pid) + time.sleep(100) + #await process.wait() + + return (-1, script_output) + else: + if not line: # EOF + break + + #if process.returncode is not None: + # _debug_print("[WTF] can-write-eof?", process.stdout.can_write_eof()) + # process.stdout.write_eof() + + #if process.stdout.at_eof(): + # break + + code = await process.wait() # wait for child process to exit + return (code, script_output) + +def execute_arbitrary_command(cmd: List[str], simulate: bool, timeout: Optional[int]) -> Tuple[bool, str]: if simulate: print(" ".join(cmd)) return (True, "") else: _debug_print("[EXECUTE]", cmd) - proc = subprocess.Popen(cmd, - stderr=subprocess.STDOUT, - stdout=subprocess.PIPE, - universal_newlines=True) - try: - script_output = proc.communicate(timeout=timeout)[0] - except subprocess.TimeoutExpired: - print("[TIMEDOUT]") - proc.kill() - script_output = proc.communicate()[0] - - _debug_print("[STDOUT]", script_output) - return_code = proc.wait() + + # block until either command finishes or the timeout occurs. + loop = asyncio.get_event_loop() + (return_code, script_output) = loop.run_until_complete(_run_command(*cmd, timeout=timeout)) + + script_output = script_output.decode() # convert bytes to str + passed = (return_code == 0) _debug_print("[$?]", return_code) if not passed: diff --git a/startop/scripts/app_startup/launch_application b/startop/scripts/app_startup/launch_application index 8a68e5016190..bc7ca802ed85 100755 --- a/startop/scripts/app_startup/launch_application +++ b/startop/scripts/app_startup/launch_application @@ -17,6 +17,19 @@ DIR="$( cd "$( dirname "${BASH_SOURCE[0]}" )" && pwd )" source "$DIR/lib/common" +launch_application_usage() { + cat <<EOF +Usage: $(basename $0) <package> <activity> + + Positional Arguments: + <package> package of the app to test + <activity> activity to use + + Named Arguments: + -h, --help usage information (this) +EOF +} + launch_application() { local package="$1" local activity="$2" @@ -44,4 +57,9 @@ launch_application() { echo "$total_time" } +if [[ $# -lt 2 ]]; then + launch_application_usage + exit 1 +fi + launch_application "$@" diff --git a/startop/scripts/app_startup/lib/common b/startop/scripts/app_startup/lib/common index 043d8550b64b..41f8cda126d4 100755 --- a/startop/scripts/app_startup/lib/common +++ b/startop/scripts/app_startup/lib/common @@ -1,4 +1,17 @@ #!/bin/bash +# Copyright 2018, The Android Open Source Project +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. if [[ -z $ANDROID_BUILD_TOP ]]; then echo "Please run source build/envsetup.sh first" >&2 @@ -49,5 +62,103 @@ get_activity_name() { local activity_line="$(adb shell cmd package query-activities --brief -a android.intent.action.MAIN -c android.intent.category.LAUNCHER | grep "$package/")" IFS="/" read -a array <<< "$activity_line" local activity_name="${array[1]}" + + # Activities starting with '.' are shorthand for having their package name prefixed. + if [[ $activity_name == .* ]]; then + activity_name="${package}${activity_name}" + fi echo "$activity_name" } + +# Use with logcat_from_timestamp to skip all past log-lines. +logcat_save_timestamp() { + adb shell 'date -u +"%Y-%m-%d %H:%M:%S.%N"' +} + +# Roll forward logcat to only show events +# since the specified timestamp. +# +# i.e. don't look at historical logcat, +# only look at FUTURE logcat. +# +# First use 'logcat_save_timestamp' +# Then do whatever action you want. +# Then us 'logcat_from_timestamp $timestamp' +logcat_from_timestamp() { + local timestamp="$1" + shift # drop timestamp from args. + echo "DONT CALL THIS FUNCTION" >&2 + exit 1 + + verbose_print adb logcat -T \"$timestamp\" \"$@\" + adb logcat -T "$timestamp" "$@" +} + +logcat_from_timestamp_bg() { + local timestamp="$1" + shift # drop timestamp from args. + verbose_print adb logcat -T \"$timestamp\" \"$@\" + adb logcat -v UTC -T "$timestamp" "$@" & + logcat_from_timestamp_pid=$! +} + +# Starting at timestamp $2, wait until we seen pattern $3 +# or until a timeout happens in $1 seconds. +# +# Set VERBOSE_LOGCAT=1 to debug every line of logcat it tries to parse. +logcat_wait_for_pattern() { + local timeout="$1" + local timestamp="$2" + local pattern="$3" + + local logcat_fd + + coproc logcat_fd { + kill_children_quietly() { + kill "$logcat_pidd" + wait "$logcat_pidd" 2>/dev/null + } + + trap 'kill_children_quietly' EXIT # kill logcat when this coproc is killed. + + # run logcat in the background so it can be killed. + logcat_from_timestamp_bg "$timestamp" + logcat_pidd=$logcat_from_timestamp_pid + wait "$logcat_pidd" + } + local logcat_pid="$!" + verbose_print "[LOGCAT] Spawn pid $logcat_pid" + + local timeout_ts="$(date -d "now + ${timeout} seconds" '+%s')" + local now_ts="0" + + local return_code=1 + + verbose_print "logcat_wait_for_pattern begin" + + while read -t "$timeout" -r -u "${logcat_fd[0]}" logcat_output; do + if (( $VERBOSE_LOGCAT )); then + verbose_print "LOGCAT: $logcat_output" + fi + if [[ "$logcat_output:" == *"$pattern"* ]]; then + verbose_print "LOGCAT: " "$logcat_output" + verbose_print "WE DID SEE PATTERN" '<<' "$pattern" '>>.' + return_code=0 + break + fi + now_ts="$(date -d "now" '+%s')" + if (( now_ts >= timeout_ts )); then + verbose_print "DID TIMEOUT BEFORE SEEING ANYTHING (timeout=$timeout seconds) " '<<' "$pattern" '>>.' + break + fi + done + + # Don't leave logcat lying around since it will keep going. + kill "$logcat_pid" + # Suppress annoying 'Terminated...' message. + wait "$logcat_pid" 2>/dev/null + + verbose_print "[LOGCAT] $logcat_pid should be killed" + + return $return_code +} diff --git a/startop/scripts/app_startup/run_app_with_prefetch b/startop/scripts/app_startup/run_app_with_prefetch index 56bffa85eb90..18aaf32abb7a 100755 --- a/startop/scripts/app_startup/run_app_with_prefetch +++ b/startop/scripts/app_startup/run_app_with_prefetch @@ -24,7 +24,7 @@ Usage: run_app_with_prefetch --package <name> [OPTIONS]... -v, --verbose enable extra verbose printing -i, --input <file> trace file protobuf (default 'TraceFile.pb') -r, --readahead <mode> cold, warm, fadvise, mlock (default 'warm') - -w, --when <when> aot or jit (default 'aot') + -w, --when <when> aot or jit (default 'jit') -c, --count <count> how many times to run (default 1) -s, --sleep <sec> how long to sleep after readahead -t, --timeout <sec> how many seconds to timeout in between each app run (default 10) @@ -33,7 +33,7 @@ EOF } DIR="$( cd "$( dirname "${BASH_SOURCE[0]}" )" && pwd )" -source "$DIR/lib/common" +source "$DIR/../iorap/common" needs_trace_file="n" input_file="" @@ -43,7 +43,7 @@ count=2 sleep_time=2 timeout=10 output="" # stdout by default -when="aot" +when="jit" parse_arguments() { while [[ $# -gt 0 ]]; do case "$1" in @@ -176,16 +176,19 @@ if [[ $? -ne 0 ]]; then fi verbose_print "Package was in path '$package_path'" -keep_application_trace_file=n application_trace_file_path="$package_path/TraceFile.pb" trace_file_directory="$package_path" if [[ $needs_trace_file == y ]]; then # system server always passes down the package path in a hardcoded spot. if [[ $when == "jit" ]]; then - verbose_print adb push "$input_file" "$application_trace_file_path" - adb push "$input_file" "$application_trace_file_path" + if ! iorapd_compiler_install_trace_file "$package" "$activity" "$input_file"; then + echo "Error: Failed to install compiled TraceFile.pb for '$package/$activity'" >&2 + exit 1 + fi keep_application_trace_file="y" else + echo "TODO: --readahead=aot is non-functional and needs to be fixed." >&2 + exit 1 # otherwise use a temporary directory to get normal non-jit behavior. trace_file_directory="/data/local/tmp/prefetch/$package" adb shell mkdir -p "$trace_file_directory" @@ -198,7 +201,7 @@ fi # otherwise system server activity hints will kick in # and the new just-in-time app pre-warmup will happen. if [[ $keep_application_trace_file == "n" ]]; then - adb shell "[[ -f '$application_trace_file_path' ]] && rm '$application_trace_file_path'" + iorapd_compiler_purge_trace_file "$package" "$activity" fi # Perform AOT readahead/pinning/etc when an application is about to be launched. @@ -242,12 +245,20 @@ perform_aot() { fi } -perform_aot_cleanup() { +# Perform cleanup at the end of each loop iteration. +perform_post_launch_cleanup() { local the_when="$1" # user: aot, jit local the_mode="$2" # warm, cold, fadvise, mlock, etc. + local logcat_timestamp="$3" # timestamp from before am start. if [[ $the_when != "aot" ]]; then - # TODO: just in time implementation.. should probably use system server. + if [[ $the_mode != 'warm' && $the_mode != 'cold' ]]; then + # Validate that readahead completes. + # If this fails for some reason, then this will also discard the timing of the run. + iorapd_readahead_wait_until_finished "$package" "$activity" "$logcat_timestamp" "$timeout" + return $? + fi + # Don't need to do anything for warm or cold. return 0 fi @@ -321,6 +332,8 @@ for ((i=0;i<count;++i)) do verbose_print "Running with timeout $timeout" + pre_launch_timestamp="$(logcat_save_timestamp)" + # TODO: multiple metrics output. total_time="$(timeout $timeout $DIR/launch_application "$package" "$activity")" @@ -330,7 +343,13 @@ for ((i=0;i<count;++i)) do continue fi - perform_aot_cleanup "$when" "$mode" + perform_post_launch_cleanup "$when" "$mode" "$pre_launch_timestamp" + + if [[ $? -ne 0 ]]; then + echo "WARNING: Skip bad cleanup, try iteration again." >&2 + ((i=i-1)) + continue + fi echo "Iteration $i. Total time was: $total_time" @@ -354,9 +373,9 @@ if [[ x$output != x ]]; then echo " Saved results to '$output'" fi -# Temporary hack around multiple activities being launched with different package paths (for same app): -# Clean up all left-over TraceFile.pb -adb shell 'for i in $(find /data/app -name TraceFile.pb); do rm \$i; done' +if [[ $needs_trace_file == y ]] ; then + iorapd_compiler_purge_trace_file "$package" "$activity" +fi # Kill the process to ensure AM isn't keeping it around. remote_pkill "$package" diff --git a/startop/scripts/iorap/collector b/startop/scripts/iorap/collector new file mode 100755 index 000000000000..8d105adeaa51 --- /dev/null +++ b/startop/scripts/iorap/collector @@ -0,0 +1,389 @@ +#!/bin/bash +# +# Copyright 2017, The Android Open Source Project +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +DIR="$( cd "$( dirname "${BASH_SOURCE[0]}" )" && pwd )" +APP_STARTUP_DIR="$DIR/../app_startup/" +source "$DIR/common" + +usage() { + cat <<EOF +Usage: collector [OPTIONS]... + +Runs an application, causes an iorap trace to be collected for it, and then invokes the iorap +compiler to generate a TraceFile.pb. + + -p, --package package of the app to test + -a, --activity activity of the app to test + -h, --help usage information (this) + -v, --verbose enable extra verbose printing + -i, --inodes path to inodes file (system/extras/pagecache/pagecache.py -d inodes) + -b, --trace_buffer_size how big to make trace buffer size (default 32768) + -w, --wait_time how long to run systrace for (default 10) in seconds + -c, --compiler-filter override the compilation filter if set (default none) + -o, --output output trace file protobuf (default 'TraceFile.pb') +EOF +} + + +DIR="$( cd "$( dirname "${BASH_SOURCE[0]}" )" && pwd )" + +trace_buffer_size=32768 +wait_time=10 +comp_filter="" +output_dest="TraceFile.pb" + +parse_arguments() { + while [[ $# -gt 0 ]]; do + case "$1" in + -a|--activity) + activity="$2" + shift + ;; + -h|--help) + usage + exit 0 + ;; + -p|--package) + package="$2" + shift + ;; + -i|--inodes) + inodes="$2" + shift + ;; + -b|--trace_buffer_size) + trace_buffer_size="$2" + shift + ;; + -w|--wait_time) + wait_time="$2" + shift + ;; + -c|--compiler-filter) + comp_filter="$2" + shift + ;; + -o|--output) + output_dest="$2" + shift + ;; + -v|--verbose) + verbose="y" + ;; + esac + shift + done +} + +remote_pidof() { + local procname="$1" + adb shell ps | grep "$procname" | awk '{print $2;}' +} + +remote_pkill() { + local procname="$1" + shift + + local the_pids=$(remote_pidof "$procname") + local pid + + for pid in $the_pids; do + verbose_print adb shell kill "$@" "$pid" + adb shell kill "$@" "$pid" + done +} + +force_package_compilation() { + local arg_comp_filter="$1" + local arg_package="$2" + + if [[ $arg_comp_filter == speed-profile ]]; then + # Force the running app to dump its profiles to disk. + remote_pkill "$arg_package" -SIGUSR1 + sleep 1 # give some time for above to complete. + fi + + adb shell cmd package compile -m "$arg_comp_filter" -f "$arg_package" +} + +parse_package_dumpsys_line() { + local what_left="$1" + local what_right="$2" + local line="$3" + + if [[ $line == *${what_left}*${what_right}* ]]; then + found="${line#*$what_left}" + found="${found%$what_right*}" + echo "$found" + return 0 + fi + + return 1 +} + +parse_package_dumpsys_section() { + local what_left="$1" + local what_right="$2" + shift + local lines="$@" + + lines="${lines//$'\n'/}" + + local new_lines=() + + local current_line="" + local newline=n + local line + for line in "${lines[@]}"; do + if [[ $line == *: ]]; then + newline=y + current_line="" + new_lines+=("$current_line") + + parse_package_dumpsys_line "$what_left" "$what_right" "$current_line" && return 0 + else + # strip all spaces from the start + line="${line//$' '/}" + current_line+="$line" + #prepend to current line + fi + done + [[ "$current_line" != "" ]] && new_lines+=("$current_line") + + parse_package_dumpsys_line "$what_left" "$what_right" "$current_line" && return 0 + + return 1 +} + +parse_package_compilation() { + local pkg="$1" +# [com.google.android.apps.maps] + + local compilation_filter + local is_prebuilt + local isa + local etc + + local ret_code + + read compilation_filter is_prebuilt isa etc <<< "$("$APP_STARTUP_DIR"/query_compiler_filter.py --package "$pkg")" + ret_code=$? + + if [[ $ret_code -eq 0 && x$compilation_filter != x ]]; then + verbose_print "Package compilation info for $pkg was '$compilation_filter'" + echo "$compilation_filter" + return 0 + else + verbose_print "query failed ret code $ret_code filter=$compilation_filter" + fi + + return $ret_code +} + +# Main entry point +if [[ $# -eq 0 ]]; then + usage + exit 1 +else + parse_arguments "$@" + + # if we do not have have package exit early with an error + [[ "$package" == "" ]] && echo "--package not specified" 1>&2 && exit 1 + + if [[ -z "$inodes" ]] || ! [[ -f $inodes ]]; then + echo "--inodes not specified" 1>&2 + exit 1 + fi + + if [[ "$activity" == "" ]]; then + activity="$(get_activity_name "$package")" + if [[ "$activity" == "" ]]; then + echo "Activity name could not be found, invalid package name?" 1>&2 + exit 1 + else + verbose_print "Activity name inferred: " "$activity" + fi + fi +fi + +adb root > /dev/null + +if [[ "$(adb shell getenforce)" != "Permissive" ]]; then + adb shell setenforce 0 + adb shell stop + adb shell start + adb wait-for-device +fi + +compilation_was="$(parse_package_compilation "$package")" +if [[ $? -ne 0 ]]; then + echo "Could not determine package compilation filter; was this package installed?" >&2 + exit 1 +fi +verbose_print "Package compilation: $compilation_was" + +# Cannot downgrade (e.g. from speed-profile to quicken) without forceful recompilation. +# Forceful recompilation will recompile even if compilation filter was unchanged. +# Therefore avoid recompiling unless the filter is actually different than what we asked for. +if [[ "x$comp_filter" != "x" ]] && [[ "$compilation_was" != "$comp_filter" ]]; then + echo "Current compilation filter is '$compilation_was'; force recompile to '$comp_filter'" >&2 + #TODO: this matching seems hopelessly broken, it will always recompile. + + force_package_compilation "$comp_filter" "$package" +fi + +# Drop all caches prior to beginning a systrace, otherwise we won't record anything already in pagecache. +adb shell "echo 3 > /proc/sys/vm/drop_caches" + +trace_tmp_file="$(mktemp -t trace.XXXXXXXXX.html)" + +function finish { + [[ -f "$trace_tmp_file" ]] && rm "$trace_tmp_file" +} +trap finish EXIT + +launch_application_and_wait_for_trace() { + local package="$1" + local activity="$2" + local timeout=30 # seconds + + # Ensure application isn't running already. + remote_pkill "$package" + + local time_now="$(logcat_save_timestamp)" + local retcode=0 + + verbose_print "now launching application" + # Launch an application + "$APP_STARTUP_DIR"/launch_application "$package" "$activity" + retcode=$? + if [[ $retcode -ne 0 ]]; then + echo "FATAL: Application launch failed." >&2 + return $retcode + fi + + # This blocks until 'am start' returns at which point the application is + # already to be considered "started" as the first frame has been drawn. + + # TODO: check for cold start w.r.t to activitymanager? + + # Wait for application to start from the point of view of ActivityTaskManager. + local pattern="ActivityTaskManager: Displayed $package" + logcat_wait_for_pattern "$timeout" "$time_now" "$pattern" + retcode=$? + if [[ $retcode -ne 0 ]]; then + echo "FATAL: Could not find '$pattern' in logcat." >&2 + return $retcode + fi + + # Wait for iorapd to finish writing out the perfetto traces for this app. + iorapd_perfetto_wait_for_app_trace "$package" "$activity" "$timeout" "$time_now" + retcode=$? + if [[ $retcode -ne 0 ]]; then + echo "FATAL: Could not save perfetto app trace file." >&2 + return $retcode + fi + + verbose_print "iorapd has finished collecting app trace file for $package/$activity" +} + +collector_main() { + # don't even bother trying to run anything until the screen is unlocked. + "$APP_STARTUP_DIR"/unlock_screen + + # Don't mutate state while iorapd is running. + iorapd_stop || return $? + + # Remove all existing metadata for a package/activity in iorapd. + iorapd_perfetto_purge_app_trace "$package" "$activity" || return $? + iorapd_compiler_purge_trace_file "$package" "$activity" || return $? + + iorapd_perfetto_enable || return $? + iorapd_start || return $? + + # Wait for perfetto trace to finished writing itself out. + launch_application_and_wait_for_trace "$package" "$activity" || return $? + + # Compile the trace so that the next app run can use prefetching. + iorapd_compiler_for_app_trace "$package" "$activity" "$inodes" || return $? + + # Save TraceFile.pb to local file. + iorapd_compiler_pull_trace_file "$package" "$activity" "$output_dest" || return $? + # Remove the TraceFile.pb from the device. + iorapd_compiler_purge_trace_file "$package" "$activity" || return $? + + # TODO: better transactional support for restoring iorapd global properties + iorapd_perfetto_disable || return $? +} + +collector_main "$@" + +verbose_print "Collector finished. Children: " +if [[ $verbose == y ]]; then + jobs -p + ps f -g$$ +fi + +exit $? + + +verbose_print "About to begin systrace" +coproc systrace_fd { + # Disable stdout buffering since we need to know the output of systrace RIGHT AWAY. + stdbuf -oL "$ANDROID_BUILD_TOP"/external/chromium-trace/systrace.py --target=android -b "$trace_buffer_size" -t "$wait_time" am pagecache dalvik -o "$trace_tmp_file" +} + +verbose_print "Systrace began" + +systrace_pid="$!" + +while read -r -u "${systrace_fd[0]}" systrace_output; do + verbose_print "$systrace_output" + if [[ "$systrace_output" == *"Starting tracing"* ]]; then + verbose_print "WE DID SEE STARTING TRACING." + break + fi +done +# Systrace has begun recording the tracing. +# Run the application and collect the results. + +am_output="$(adb shell am start -S -W "$package"/"$activity")" +if [[ $? -ne 0 ]]; then + echo "am start failed" >&2 + + exit 1 +fi + +verbose_print "$am_output" +total_time="$(echo "$am_output" | grep 'TotalTime:' | sed 's/TotalTime: //g')" +verbose_print "total time: $total_time" + +# Now wait for systrace to finish. + +wait "$systrace_pid" || { echo "Systrace finished before am start was finished, try a longer --wait_time"; exit 1; } +verbose_print "Systrace has now finished" +verbose_print "$(ls -la "$trace_tmp_file")" + + +iorapd_perfetto_disable + +# Now that systrace has finished, convert the trace file html file to a protobuf. + +"$ANDROID_BUILD_TOP"/system/iorap/src/py/collector/trace_parser.py -i "$inodes" -t "$trace_tmp_file" -o "$output_dest" || exit 1 + +echo "Trace file collection complete, trace file saved to \"$output_dest\"!" >&2 + +finish diff --git a/startop/scripts/iorap/common b/startop/scripts/iorap/common new file mode 100755 index 000000000000..6dde3d51a5ba --- /dev/null +++ b/startop/scripts/iorap/common @@ -0,0 +1,207 @@ +#!/bin/bash +# +# Copyright 2019, The Android Open Source Project +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +DIR_IORAP_COMMON="$( cd "$( dirname "${BASH_SOURCE[0]}" )" && pwd )" +APP_STARTUP_DIR="$DIR/../app_startup/" +source "$APP_STARTUP_DIR/lib/common" + +IORAPD_DATA_PATH="/data/misc/iorapd" + +iorapd_start() { + verbose_print 'iorapd_start' + adb shell start iorapd + sleep 1 + # TODO: block until logcat prints successfully connecting +} + +iorapd_stop() { + verbose_print 'iorapd_stop' + adb shell stop iorapd +} + +iorapd_reset() { + iorapd_stop + iorapd_start +} + +# Enable perfetto tracing. +# Subsequent launches of an application will record a perfetto trace protobuf. +iorapd_perfetto_enable() { + verbose_print 'enable perfetto' + adb shell setprop iorapd.perfetto.enable true + iorapd_reset # iorapd only reads this flag when initializing +} + +# Enable perfetto tracing. +# Subsequent launches of applications will no longer record perfetto trace protobufs. +iorapd_perfetto_disable() { + verbose_print 'disable perfetto' + adb shell setprop iorapd.perfetto.enable false + iorapd_reset # iorapd only reads this flag when initializing +} + +_iorapd_path_to_data_file() { + local package="$1" + local activity="$2" + local suffix="$3" + + # Match logic of 'AppComponentName' in iorap::compiler C++ code. + echo "${IORAPD_DATA_PATH}/${package}%2F${activity}.${suffix}" +} + +iorapd_perfetto_wait_for_app_trace() { + local package="$1" + local activity="$2" + local timeout="$3" + local timestamp="$4" + + local remote_path="$(_iorapd_path_to_data_file "$package" "$activity" "perfetto_trace.pb")" + + verbose_print "iorapd_perfetto_wait_for_app_trace on file '$remote_path'" + + # see event_manager.cc + local pattern="Perfetto TraceBuffer saved to file: $remote_path" + logcat_wait_for_pattern "$timeout" "$timestamp" "$pattern" +} + +# Purge all perfetto traces for a given application. +iorapd_perfetto_purge_app_trace() { + local package="$1" + local activity="$2" + + local remote_path="$(_iorapd_path_to_data_file "$package" "$activity" "perfetto_trace.pb")" + + verbose_print 'iorapd-perfetto: purge app trace in ' "$remote_path" + adb shell "[[ -f '$remote_path' ]] && rm -f '$remote_path' || exit 0" +} + +# Compile a perfetto trace for a given application. +# This requires the app has run at least once with perfetto tracing enabled. +iorapd_compiler_for_app_trace() { + local package="$1" + local activity="$2" + local inodes="$3" # local path + + # remote path calculations + local input_path="$(_iorapd_path_to_data_file "$package" "$activity" "perfetto_trace.pb")" + local compiled_path="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.tmp.pb")" + local compiled_path_final="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.pb")" + + if ! adb shell "[[ -f '$input_path' ]]"; then + echo "Error: Missing perfetto traces; nothing to compile. Expected: '$input_path'" >&2 + return 1 + fi + + if ! [[ -f $inodes ]]; then + # We could compile using 'diskscan' but it's non-deterministic, so refuse instead. + echo "Error: Missing inodes textcache at '$inodes'; refusing to compile." >&2 + return 1 + fi + + # inodes file needs to be on the device for iorap.cmd.compiler to access it + local remote_inodes=/data/local/tmp/prefetch/inodes.txt + adb shell "mkdir -p \"$(dirname "$remote_inodes")\"" || return 1 + adb push "$inodes" "$remote_inodes" + + verbose_print 'iorapd-compiler: compile app trace in ' "$input_path" + verbose_print adb shell "iorap.cmd.compiler '$input_path' --inode-textcache '$remote_inodes' --output-proto '$compiled_path'" + adb shell "iorap.cmd.compiler '$input_path' --inode-textcache '$remote_inodes' --output-proto '$compiled_path'" + retcode=$? + + # Don't overwrite the true 'compiled_trace.pb' unless the compiler completed without error. + # TODO: The native compiler code should be handling its own transaction-safety. + if [[ $retcode -eq 0 ]]; then + adb shell "mv '$compiled_path' '$compiled_path_final'" + else + adb shell "[[ -f '$compiled_path' ]] && rm -f '$compiled_path'" + fi + + # Clean up inodes file we just pushed. + adb shell "[[ -f '$remote_inodes' ]] && rm -f '$remote_inodes'" + + return $retcode +} + +# Pull the remote compiled trace file into a local file. +iorapd_compiler_pull_trace_file() { + local package="$1" + local activity="$2" + local output_file="$3" # local path + + local compiled_path="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.pb")" + + if ! adb shell "[[ -f '$compiled_path' ]]"; then + echo "Error: Remote path '$compiled_path' invalid" >&2 + return 1 + fi + if ! mkdir -p "$(dirname "$output_file")"; then + echo "Error: Fail to make output directory for '$output_file'" >&2 + return 1 + fi + verbose_print adb pull "$compiled_path" "$output_file" + adb pull "$compiled_path" "$output_file" +} + +# Install a compiled trace file. +iorapd_compiler_install_trace_file() { + local package="$1" + local activity="$2" + local input_file="$3" # local path + + # remote path calculations + local compiled_path="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.pb")" + + if ! [[ -f $input_file ]]; then + echo "Error: File '$input_file' does not exist." >&2 + return 1 + fi + + adb shell "mkdir -p \"$(dirname "$compiled_path")\"" || return 1 + + verbose_print adb push "$input_file" "$compiled_path" + adb push "$input_file" "$compiled_path" +} + +iorapd_compiler_purge_trace_file() { + local package="$1" + local activity="$2" + local input_file="$3" # local path + + local remote_path="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.pb")" + + adb shell "[[ -f '$remote_path' ]] && rm -f '$remote_path' || exit 0" +} + +# Blocks until the readahead for the requested package/activity has finished. +# This assumes that the trace file was already installed, and also that +# the application launched but not completed yet. +iorapd_readahead_wait_until_finished() { + local package="$1" + local activity="$2" + local timestamp="$3" + local timeout="$4" + + if [[ $# -lt 4 ]]; then + echo "FATAL: Expected 4 arguments (actual $# $@)" >&2 + exit 1 + fi + + local remote_path="$(_iorapd_path_to_data_file "$package" "$activity" "compiled_trace.pb")" + + # See 'read_ahead.cc' LOG(INFO). + local pattern="ReadAhead completed ($remote_path)" + logcat_wait_for_pattern "$timeout" "$timestamp" "$pattern" +} diff --git a/startop/scripts/iorap/pull_textcache b/startop/scripts/iorap/pull_textcache new file mode 100755 index 000000000000..05544263957d --- /dev/null +++ b/startop/scripts/iorap/pull_textcache @@ -0,0 +1,24 @@ +#!/bin/bash +# +# Copyright 2019, The Android Open Source Project +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +if [[ $# -lt 1 ]]; then + echo "Usage: $0 <output-filename>" >&2 + exit 1 +fi + +# see compiler/main.cc for list of roots +adb shell iorap.inode2filename --output-format=textcache --output=/data/local/tmp/dumpcache --all --root=/system --root=/apex --root=/vendor --root=/data --root=/product --root=/metadata +adb pull /data/local/tmp/dumpcache "$1" |