EAS Testing - Recents Fling on Android

The goal of this experiment is to collect frame statistics while swiping up and down tabs of recently opened applications on a Nexus N5X running Android with an EAS kernel. This process is name Recents Fling. The Analysis phase will consist in comparing EAS with other schedulers, that is comparing sched governor with:

- interactive
- performance
- powersave
- ondemand

For this experiment it is recommended to open many applications so that we can swipe over more recently opened applications.


In [1]:
import logging
reload(logging)
log_fmt = '%(asctime)-9s %(levelname)-8s: %(message)s'
logging.basicConfig(format=log_fmt)

# Change to info once the notebook runs ok
logging.getLogger().setLevel(logging.INFO)

In [2]:
%pylab inline

import os
from time import sleep

# Support to access the remote target
import devlib
from env import TestEnv

from devlib.utils.android import adb_command

# Support for trace events analysis
from trace import Trace

# Suport for FTrace events parsing and visualization
import trappy


Populating the interactive namespace from numpy and matplotlib

Test Environment set up

Devlib requires the ANDROID_HOME environment variable configured to point to your local installation of the Android SDK. If you have not this variable configured in the shell used to start the notebook server, you need to run the next cell to define where your Android SDK is installed.


In [3]:
import os
os.environ['ANDROID_HOME'] = '/ext/android-sdk-linux/'

In case more than one Android device are conencted to the host, you must specify the ID of the device you want to target in my_target_conf. Run adb devices on your host to get the ID.


In [4]:
# Setup a target configuration
my_conf = {
    
    # Target platform and board
    "platform"    : 'android',

    # Device ID
    # "device" : "0123456789abcdef",

    # Folder where all the results will be collected
    "results_dir" : "Android_RecentsFling",
    
    # Define devlib modules to load
    "modules"     : [
        'cpufreq'       # enable CPUFreq support
    ],

    # FTrace events to collect for all the tests configuration which have
    # the "ftrace" flag enabled
    "ftrace"  : {
         "events" : [
            "sched_switch",
            "sched_load_avg_cpu",
            "cpu_frequency",
            "cpu_capacity"
         ],
         "buffsize" : 10 * 1024,
    },

    # Tools required by the experiments
    "tools"   : [ 'trace-cmd' ],
}

In [5]:
# Initialize a test environment using:
te = TestEnv(my_conf)
target = te.target


2016-04-27 10:03:27,438 INFO    :         Target - Using base path: /home/derkling/Code/lisa
2016-04-27 10:03:27,439 INFO    :         Target - Loading custom (inline) target configuration
2016-04-27 10:03:27,440 INFO    :         Target - Devlib modules to load: ['cpufreq']
2016-04-27 10:03:27,441 INFO    :         Target - Connecting Android target [DEFAULT]
2016-04-27 10:03:29,160 INFO    :         Target - Initializing target workdir:
2016-04-27 10:03:29,161 INFO    :         Target -    /data/local/tmp/devlib-target
2016-04-27 10:03:32,592 INFO    :         Target - Topology:
2016-04-27 10:03:32,593 INFO    :         Target -    [[0, 1], [2, 3]]
2016-04-27 10:03:33,947 WARNING : Event [sched_load_avg_cpu] not available for tracing
2016-04-27 10:03:33,949 WARNING : Event [cpu_capacity] not available for tracing
2016-04-27 10:03:33,950 INFO    :         FTrace - Enabled tracepoints:
2016-04-27 10:03:33,950 INFO    :         FTrace -   sched_switch
2016-04-27 10:03:33,951 INFO    :         FTrace -   sched_load_avg_cpu
2016-04-27 10:03:33,951 INFO    :         FTrace -   cpu_frequency
2016-04-27 10:03:33,952 INFO    :         FTrace -   cpu_capacity
2016-04-27 10:03:33,953 WARNING :        TestEnv - Wipe previous contents of the results folder:
2016-04-27 10:03:33,953 WARNING :        TestEnv -    /home/derkling/Code/lisa/results/Android_RecentsFling
2016-04-27 10:03:33,963 INFO    :        TestEnv - Set results folder to:
2016-04-27 10:03:33,963 INFO    :        TestEnv -    /home/derkling/Code/lisa/results/Android_RecentsFling
2016-04-27 10:03:33,964 INFO    :        TestEnv - Experiment results available also in:
2016-04-27 10:03:33,964 INFO    :        TestEnv -    /home/derkling/Code/lisa/results_latest

Support Functions

This set of support functions will help us running the benchmark using different CPUFreq governors.


In [6]:
def set_performance():
    target.cpufreq.set_all_governors('performance')

def set_powersave():
    target.cpufreq.set_all_governors('powersave')

def set_interactive():
    target.cpufreq.set_all_governors('interactive')

def set_sched():
    target.cpufreq.set_all_governors('sched')

def set_ondemand():
    target.cpufreq.set_all_governors('ondemand')
    
    for cpu in target.list_online_cpus():
        tunables = target.cpufreq.get_governor_tunables(cpu)
        target.cpufreq.set_governor_tunables(
            cpu,
            'ondemand',
            **{'sampling_rate' : tunables['sampling_rate_min']}
        )

In [7]:
# CPUFreq configurations to test
confs = {
    'performance' : {
        'label' : 'prf',
        'set' :  set_performance,
    },
    #'powersave' : {
    #    'label' : 'pws',
    #    'set' :  set_powersave,
    #},
     'interactive' : {
         'label' : 'int',
         'set' :  set_interactive,
     },
    #'sched' : {
    #    'label' : 'sch',
    #    'set' :  set_sched,
    #},
    #'ondemand' : {
    #    'label' : 'odm',
    #    'set' :  set_ondemand,
    #}
}

# The set of results for each comparison test
results = {}

In [8]:
def open_apps(n):
    """
    Open `n` apps on the device
    
    :param n: number of apps to open
    :type n: int
    """
    # Get a list of third-party packages
    android_version = target.getprop('ro.build.version.release')
    if android_version >= 'N':
        packages = target.execute('cmd package list packages | cut -d: -f 2')
        packages = packages.splitlines()
    else:
        packages = target.execute('pm list packages -3 | cut -d: -f 2')
        packages = packages.splitlines()

    # As a safe fallback let's use a list of standard Android AOSP apps which are always available
    if len(packages) < 8:
        packages = [
            'com.android.messaging',
            'com.android.calendar',
            'com.android.settings',
            'com.android.calculator2',
            'com.android.email',
            'com.android.music',
            'com.android.deskclock',
            'com.android.contacts',
        ]
    
    LAUNCH_CMD = 'monkey -p {} -c android.intent.category.LAUNCHER 1 '
    
    if n > len(packages):
        n = len(packages)
        
    logging.info('Trying to open %d apps...', n)
    started = 0
    for app in packages:
        logging.debug('    Launching %s', app)
        try:
            target.execute(LAUNCH_CMD.format(app))
            started = started + 1
            logging.info('  %2d starting %s...', started, app)
        except Exception:
            pass
        if started >= n:
            break
        
    # Close Recents
    target.execute('input keyevent KEYCODE_HOME')

In [9]:
def recentsfling_run(exp_dir):
    # Open Recents on the target device
    target.execute('input keyevent KEYCODE_APP_SWITCH')
    # Allow the activity to start
    sleep(5)
    # Reset framestats collection
    target.execute('dumpsys gfxinfo --reset')
    
    w, h = target.screen_resolution
    x = w/2
    yl = int(0.2*h)
    yh = int(0.9*h)
    
    logging.info('Start Swiping Recents')
    for i in range(5):
        # Simulate two fast UP and DOWN swipes
        target.execute('input swipe {} {} {} {} 50'.format(x, yl, x, yh))
        sleep(0.3)
        target.execute('input swipe {} {} {} {} 50'.format(x, yh, x, yl))
        sleep(0.7)
    logging.info('Swiping Recents Completed')
    
    # Get frame stats
    framestats_file = os.path.join(exp_dir, "framestats.txt")
    adb_command(target.adb_name, 'shell dumpsys gfxinfo com.android.systemui > {}'.format(framestats_file))
    
    # Close Recents
    target.execute('input keyevent KEYCODE_HOME')

    return framestats_file

In [10]:
def experiment(governor, exp_dir):
    os.system('mkdir -p {}'.format(exp_dir));

    logging.info('------------------------')
    logging.info('Run workload using %s governor', governor)
    confs[governor]['set']()
    
    # Start FTrace
    te.ftrace.start()
      
    ### Run the benchmark ###
    framestats_file = recentsfling_run(exp_dir)
    
    # Stop FTrace
    te.ftrace.stop()    

    # Collect and keep track of the trace
    trace_file = os.path.join(exp_dir, 'trace.dat')
    te.ftrace.get_trace(trace_file)
    
    # Parse trace
    tr = Trace(te.platform, exp_dir,
               events=my_conf['ftrace']['events'])
    
    # return all the experiment data
    return {
        'dir'             : exp_dir,
        'framestats_file' : framestats_file,
        'trace_file'      : trace_file,
        'ftrace'          : tr.ftrace,
        'trace'           : tr
    }

Run Flinger

Prepare Environment


In [11]:
N_APPS = 20

In [12]:
open_apps(N_APPS)

# Give apps enough time to open
sleep(5)


2016-04-27 10:04:15,735 INFO    : Trying to open 20 apps...
2016-04-27 10:04:19,062 INFO    :    1 starting com.android.documentsui...
2016-04-27 10:04:20,636 INFO    :    2 starting com.android.quicksearchbox...
2016-04-27 10:04:22,291 INFO    :    3 starting com.android.messaging...
2016-04-27 10:04:26,125 INFO    :    4 starting com.android.contacts...
2016-04-27 10:04:30,385 INFO    :    5 starting com.android.calendar...
2016-04-27 10:04:33,122 INFO    :    6 starting com.htc.android.ssdtest...
2016-04-27 10:04:37,992 INFO    :    7 starting com.android.dialer...
2016-04-27 10:04:38,592 INFO    :    8 starting com.android.gallery3d...
2016-04-27 10:04:45,168 INFO    :    9 starting com.android.settings...
2016-04-27 10:04:45,718 INFO    :   10 starting com.android.calculator2...
2016-04-27 10:04:46,798 INFO    :   11 starting com.android.email...
2016-04-27 10:04:47,373 INFO    :   12 starting com.android.music...
2016-04-27 10:04:49,977 INFO    :   13 starting com.android.deskclock...
2016-04-27 10:04:52,633 INFO    :   14 starting com.android.development...

Run workload and collect traces


In [13]:
# Unlock device screen (assume no password required)
target.execute('input keyevent 82')

# Run the benchmark in all the configured governors
for governor in confs:
    test_dir = os.path.join(te.res_dir, governor)
    results[governor] = experiment(governor, test_dir)


2016-04-27 10:05:16,261 INFO    : ------------------------
2016-04-27 10:05:16,261 INFO    : Run workload using performance governor
2016-04-27 10:05:23,910 INFO    : Start Swiping Recents
2016-04-27 10:05:34,043 INFO    : Swiping Recents Completed
2016-04-27 10:05:37,908 INFO    : Parsing FTrace format...
2016-04-27 10:05:41,305 INFO    : Collected events spans a 16.850 [s] time interval
2016-04-27 10:05:41,306 INFO    : Set plots time range to (0.000000, 16.849682)[s]
2016-04-27 10:05:41,659 INFO    : ------------------------
2016-04-27 10:05:41,660 INFO    : Run workload using interactive governor
2016-04-27 10:05:49,387 INFO    : Start Swiping Recents
2016-04-27 10:06:00,339 INFO    : Swiping Recents Completed
2016-04-27 10:06:05,640 INFO    : Parsing FTrace format...
2016-04-27 10:06:08,702 INFO    : Collected events spans a 17.899 [s] time interval
2016-04-27 10:06:08,703 INFO    : Set plots time range to (0.000000, 17.898734)[s]

UI Performance Analysis


In [14]:
for governor in confs:
    framestats_file = results[governor]['framestats_file']
    print "Frame Statistics for {} governor".format(governor.upper())
    !sed '/Stats since/,/99th/!d;/99th/q' $framestats_file
    print ""


Frame Statistics for PERFORMANCE governor
Stats since: 31757612331ns
Total frames rendered: 1052
Janky frames: 124 (11.79%)
50th percentile: 9ms
90th percentile: 17ms
95th percentile: 23ms
99th percentile: 34ms

Frame Statistics for INTERACTIVE governor
Stats since: 31757612331ns
Total frames rendered: 1527
Janky frames: 230 (15.06%)
50th percentile: 10ms
90th percentile: 19ms
95th percentile: 23ms
99th percentile: 34ms