In [1]:
import logging
reload(logging)
logging.basicConfig(
    format='%(asctime)-9s %(levelname)-8s: %(message)s',
    datefmt='%I:%M:%S')

# Enable logging at INFO level
logging.getLogger().setLevel(logging.INFO)
# Comment the follwing line to disable devlib debugging statements
# logging.getLogger('ssh').setLevel(logging.DEBUG)

In [2]:
# Generate plots inline
%pylab inline

import json
import os


Populating the interactive namespace from numpy and matplotlib

Test environment setup


In [3]:
# Setup a target configuration
my_target_conf = {
    
    # Define the kind of target platform to use for the experiments
    "platform"    : 'linux',  # Linux system, valid other options are:
                              # android - access via ADB
                              # linux   - access via SSH
                              # host    - direct access
    
    # Preload settings for a specific target
    "board"       : 'juno',   # load JUNO specific settings, e.g.
                              # - HWMON based energy sampling
                              # - Juno energy model
                              # valid options are:
                              # - juno  - JUNO Development Board
                              # - tc2   - TC2 Development Board
                              # - oak   - Mediatek MT63xx based target

    # Define devlib module to load
    #"modules"     : [
    #    'bl',           # enable big.LITTLE support
    #    'cpufreq'       # enable CPUFreq support
    #],

    # Account to access the remote target
    "host"        : '192.168.0.1',
    "username"    : 'root',
    "password"    : '',

    # Comment the following line to force rt-app calibration on your target
    "rtapp-calib" : {
        '0': 361, '1': 138, '2': 138, '3': 352, '4': 360, '5': 353
    }

}

# Setup the required Test Environment supports
my_tests_conf = {
    
    # Binary tools required to run this experiment
    # These tools must be present in the tools/ folder for the architecture
    #"tools"   : ['rt-app', 'taskset', 'trace-cmd'],
    
    # FTrace events end buffer configuration
    "ftrace"  : {
         "events" : [
             "sched_switch",
             "cpu_frequency"
         ],
         "buffsize" : 10240
    },

}

In [4]:
# Support to access the remote target
import devlib
from env import TestEnv

# Initialize a test environment using:
# the provided target configuration (my_target_conf)
# the provided test configuration   (my_test_conf)
te = TestEnv(target_conf=my_target_conf, test_conf=my_tests_conf)
target = te.target


06:28:57  INFO    :         Target - Using base path: /home/derkling/Code/lisa
06:28:57  INFO    :         Target - Loading custom (inline) target configuration
06:28:57  INFO    :         Target - Loading custom (inline) test configuration
06:28:57  INFO    :         Target - Devlib modules to load: ['bl', 'hwmon', 'cpufreq']
06:28:57  INFO    :         Target - Connecting linux target:
06:28:57  INFO    :         Target -   username : root
06:28:57  INFO    :         Target -       host : 192.168.0.1
06:28:57  INFO    :         Target -   password : 
06:29:34  INFO    :         Target - Initializing target workdir:
06:29:34  INFO    :         Target -    /root/devlib-target
06:29:37  INFO    :         Target - Topology:
06:29:37  INFO    :         Target -    [[0, 3, 4, 5], [1, 2]]
06:29:39  INFO    :       Platform - Loading default EM:
06:29:39  INFO    :       Platform -    /home/derkling/Code/lisa/libs/utils/platforms/juno.json
06:29:40  INFO    :         FTrace - Enabled tracepoints:
06:29:40  INFO    :         FTrace -   sched_switch
06:29:40  INFO    :         FTrace -   cpu_frequency
06:29:40  INFO    :    EnergyMeter - Scanning for HWMON channels, may take some time...
06:29:40  INFO    :    EnergyMeter - Channels selected for energy sampling:
06:29:40  INFO    :    EnergyMeter -    a57_energy
06:29:40  INFO    :    EnergyMeter -    a53_energy
06:29:40  INFO    :        TestEnv - Set results folder to:
06:29:40  INFO    :        TestEnv -    /home/derkling/Code/lisa/results/20160225_182940
06:29:40  INFO    :        TestEnv - Experiment results available also in:
06:29:40  INFO    :        TestEnv -    /home/derkling/Code/lisa/results_latest

Workload configuration


In [5]:
# Support to configure and run RTApp based workloads
from wlgen import RTA, Periodic, Ramp

# Create a new RTApp workload generator using the calibration values
# reported by the TestEnv module
rtapp = RTA(target, 'simple', calibration=te.calibration())

# Configure this RTApp instance to:
rtapp.conf(
    # 1. generate a "profile based" set of tasks
    kind='profile',
    
    # 2. define the "profile" of each task
    params={
        
        # 3. PERIODIC task with
        'task_p20': Periodic(
            period_ms=100,         # period
            duty_cycle_pct=20,     # duty cycle
            duration_s=5,          # duration    
            cpus='0'               # pinned on CPU0
        ).get(),
        
        # 4. RAMP task (i.e. increasing load) with
        'task_r20_5-60': Ramp(
            start_pct=5,           # intial load
            end_pct=65,            # end load
            delta_pct=20,          # load % increase...
            time_s=1,              # ... every 1[s]
            # pinned on last CPU of the target
            cpus=str(len(target.core_names)-1)
        ).get(),
    },
    
    # 4. use this folder for task logfiles
    run_dir=target.working_directory
    
);


06:29:40  INFO    :          WlGen - Setup new workload simple
06:29:40  INFO    :          RTApp - Workload duration defined by longest task
06:29:40  INFO    :          RTApp - Default policy: SCHED_OTHER
06:29:40  INFO    :          RTApp - ------------------------
06:29:40  INFO    :          RTApp - task [task_p20], sched: using default policy
06:29:40  INFO    :          RTApp -  | calibration CPU: 1
06:29:40  INFO    :          RTApp -  | loops count: 1
06:29:40  INFO    :          RTApp -  | CPUs affinity: 0
06:29:40  INFO    :          RTApp - + phase_000001: duration 5.000000 [s] (50 loops)
06:29:40  INFO    :          RTApp - |  period   100000 [us], duty_cycle  20 %
06:29:40  INFO    :          RTApp - |  run_time  20000 [us], sleep_time  80000 [us]
06:29:40  INFO    :          RTApp - ------------------------
06:29:40  INFO    :          RTApp - task [task_r20_5-60], sched: using default policy
06:29:40  INFO    :          RTApp -  | calibration CPU: 1
06:29:40  INFO    :          RTApp -  | loops count: 1
06:29:40  INFO    :          RTApp -  | CPUs affinity: 5
06:29:40  INFO    :          RTApp - + phase_000001: duration 1.000000 [s] (10 loops)
06:29:40  INFO    :          RTApp - |  period   100000 [us], duty_cycle   5 %
06:29:40  INFO    :          RTApp - |  run_time   5000 [us], sleep_time  95000 [us]
06:29:40  INFO    :          RTApp - + phase_000002: duration 1.000000 [s] (10 loops)
06:29:40  INFO    :          RTApp - |  period   100000 [us], duty_cycle  25 %
06:29:40  INFO    :          RTApp - |  run_time  25000 [us], sleep_time  75000 [us]
06:29:40  INFO    :          RTApp - + phase_000003: duration 1.000000 [s] (10 loops)
06:29:40  INFO    :          RTApp - |  period   100000 [us], duty_cycle  45 %
06:29:40  INFO    :          RTApp - |  run_time  45000 [us], sleep_time  55000 [us]
06:29:40  INFO    :          RTApp - + phase_000004: duration 1.000000 [s] (10 loops)
06:29:40  INFO    :          RTApp - |  period   100000 [us], duty_cycle  65 %
06:29:40  INFO    :          RTApp - |  run_time  65000 [us], sleep_time  35000 [us]

Workload execution


In [6]:
logging.info('#### Setup FTrace')
te.ftrace.start()

logging.info('#### Start energy sampling')
te.emeter.reset()

logging.info('#### Start RTApp execution')
rtapp.run(out_dir=te.res_dir, cgroup="")

logging.info('#### Read energy consumption: %s/energy.json', te.res_dir)
(nrg, nrg_file) = te.emeter.report(out_dir=te.res_dir)

logging.info('#### Stop FTrace')
te.ftrace.stop()

trace_file = os.path.join(te.res_dir, 'trace.dat')
logging.info('#### Save FTrace: %s', trace_file)
te.ftrace.get_trace(trace_file)

logging.info('#### Save platform description: %s/platform.json', te.res_dir)
(plt, plt_file) = te.platform_dump(te.res_dir)


06:29:40  INFO    : #### Setup FTrace
06:29:43  INFO    : #### Start energy sampling
06:29:44  INFO    : #### Start RTApp execution
06:29:44  INFO    :          WlGen - Workload execution START:
06:29:44  INFO    :          WlGen -    /root/devlib-target/bin/rt-app /root/devlib-target/simple_00.json
06:29:50  INFO    : #### Read energy consumption: /home/derkling/Code/lisa/results/20160225_182940/energy.json
06:29:51  INFO    :   EnergyReport - Energy [             a53]: 9.734375
06:29:51  INFO    :   EnergyReport - Energy [             a57]: 4.190309
06:29:51  INFO    : #### Stop FTrace
06:29:52  INFO    : #### Save FTrace: /home/derkling/Code/lisa/results/20160225_182940/trace.dat
06:29:54  INFO    : #### Save platform description: /home/derkling/Code/lisa/results/20160225_182940/platform.json

Collected results


In [7]:
# All data are produced in the output folder defined by the TestEnv module
logging.info('Content of the output folder %s', te.res_dir)
!ls -la {te.res_dir}


06:29:54  INFO    : Content of the output folder /home/derkling/Code/lisa/results/20160225_182940
total 4064
drwxrwxr-x  2 derkling derkling    4096 Feb 25 18:29 .
drwxrwxr-x 99 derkling derkling    4096 Feb 25 18:29 ..
-rw-rw-r--  1 derkling derkling      52 Feb 25 18:29 energy.json
-rw-rw-r--  1 derkling derkling     450 Feb 25 18:29 output.log
-rw-rw-r--  1 derkling derkling    1075 Feb 25 18:29 platform.json
-rw-r--r--  1 derkling derkling    6360 Feb 25 18:29 rt-app-task_p20-0.log
-rw-r--r--  1 derkling derkling    6360 Feb 25 18:29 rt-app-task_p20-3.log
-rw-r--r--  1 derkling derkling    5120 Feb 25 18:29 rt-app-task_r20_5-60-1.log
-rw-r--r--  1 derkling derkling    3880 Feb 25 18:29 rt-app-task_r20_5-60-3.log
-rw-r--r--  1 derkling derkling    3880 Feb 25 18:29 rt-app-task_r20_5-60-6.log
-rw-r--r--  1 derkling derkling    1831 Feb 25 18:29 simple_00.json
-rw-r--r--  1 derkling derkling 4104192 Feb 25 18:29 trace.dat

In [8]:
# Inspect the JSON file used to run the application
with open('{}/simple_00.json'.format(te.res_dir), 'r') as fh:
    rtapp_json = json.load(fh, )
logging.info('Generated RTApp JSON file:')
print json.dumps(rtapp_json, indent=4, sort_keys=True)


06:29:54  INFO    : Generated RTApp JSON file:
{
    "global": {
        "calibration": "CPU1", 
        "default_policy": "SCHED_OTHER", 
        "duration": -1, 
        "logdir": "/root/devlib-target"
    }, 
    "tasks": {
        "task_p20": {
            "cpus": [
                0
            ], 
            "loop": 1, 
            "phases": {
                "p000001": {
                    "loop": 50, 
                    "run": 20000, 
                    "timer": {
                        "period": 100000, 
                        "ref": "task_p20"
                    }
                }
            }, 
            "policy": "SCHED_OTHER"
        }, 
        "task_r20_5-60": {
            "cpus": [
                5
            ], 
            "loop": 1, 
            "phases": {
                "p000001": {
                    "loop": 10, 
                    "run": 5000, 
                    "timer": {
                        "period": 100000, 
                        "ref": "task_r20_5-60"
                    }
                }, 
                "p000002": {
                    "loop": 10, 
                    "run": 25000, 
                    "timer": {
                        "period": 100000, 
                        "ref": "task_r20_5-60"
                    }
                }, 
                "p000003": {
                    "loop": 10, 
                    "run": 45000, 
                    "timer": {
                        "period": 100000, 
                        "ref": "task_r20_5-60"
                    }
                }, 
                "p000004": {
                    "loop": 10, 
                    "run": 65000, 
                    "timer": {
                        "period": 100000, 
                        "ref": "task_r20_5-60"
                    }
                }
            }, 
            "policy": "SCHED_OTHER"
        }
    }
}

In [9]:
# Dump the energy measured for the LITTLE and big clusters
logging.info('Energy: %s', nrg_file)
print json.dumps(nrg, indent=4, sort_keys=True)


06:29:54  INFO    : Energy: /home/derkling/Code/lisa/results/20160225_182940/energy.json
{
    "LITTLE": "9.734375", 
    "big": "4.190309"
}

In [10]:
# Dump the platform descriptor, which could be useful for further analysis
# of the generated results
logging.info('Platform description: %s', plt_file)
print json.dumps(plt, indent=4, sort_keys=True)


06:29:54  INFO    : Platform description: /home/derkling/Code/lisa/results/20160225_182940/platform.json
{
    "clusters": {
        "big": [
            1, 
            2
        ], 
        "little": [
            0, 
            3, 
            4, 
            5
        ]
    }, 
    "cpus_count": 6, 
    "freqs": {
        "big": [
            450000, 
            625000, 
            800000, 
            950000, 
            1100000
        ], 
        "little": [
            450000, 
            575000, 
            700000, 
            775000, 
            850000
        ]
    }, 
    "nrg_model": {
        "big": {
            "cluster": {
                "nrg_max": 64
            }, 
            "cpu": {
                "cap_max": 1024, 
                "nrg_max": 616
            }
        }, 
        "little": {
            "cluster": {
                "nrg_max": 57
            }, 
            "cpu": {
                "cap_max": 447, 
                "nrg_max": 93
            }
        }
    }, 
    "topology": [
        [
            0, 
            3, 
            4, 
            5
        ], 
        [
            1, 
            2
        ]
    ]
}

Trace inspection


In [11]:
# Suport for FTrace events parsing and visualization
import trappy

# NOTE: The interactive trace visualization is available only if you run
#       the workload to generate a new trace-file
trappy.plotter.plot_trace(te.res_dir)


RTApp task performance plots


In [12]:
# Support for performance analysis of RTApp workloads
from perf_analysis import PerfAnalysis

# Parse the RT-App generate log files to compute performance metrics
pa = PerfAnalysis(te.res_dir)

# For each task which has generated a logfile, plot  its performance metrics
for task in pa.tasks():
    pa.plotPerf(task, "Performance plots for task [{}] ".format(task))


06:29:55  INFO    : PerfIndex, Task [task_p20] avg: 0.59, std: 0.00
06:29:55  INFO    : PerfIndex, Task [task_r20_5-60] avg: -0.25, std: 1.33