Energy Meter Examples

Energy estimations in Gem5

The Gem5EnergyMeter in Lisa uses the devlib Gem5PowerInstrument to extract energy information from the gem5 statistics file referenced in the energy meter field of the target configuration.


In [1]:
from conf import LisaLogging
LisaLogging.setup()


2017-08-16 18:12:20,847 INFO    : root         : Using LISA logging configuration:
2017-08-16 18:12:20,855 INFO    : root         :   /home/vagrant/dev/lisa/logging.conf

In [2]:
# One initial cell for imports
import json
import logging
import os

from env import TestEnv

# Suport for FTrace events parsing and visualization
import trappy
from trappy.ftrace import FTrace
from trace import Trace

# Support for plotting
# Generate plots inline
%matplotlib inline
import numpy
import pandas as pd
import matplotlib.pyplot as plt
from env import TestEnv

# RTApp configurator for generation of PERIODIC tasks
from wlgen import RTA, Ramp

Target configuration

The target configuration is used to describe and configure your test environment. You can find more details in examples/utils/testenv_example.ipynb.


In [3]:
# Root path of the gem5 workspace
base = "/home/vagrant/gem5"

conf = {
    # Only 'linux' is supported by gem5 for now, 'android' is a WIP
    "platform"    : 'linux',
    
    # Preload settings for a specific target
    "board"       : 'gem5',
    
    # Devlib modules to load - "gem5stats" is required to use the power instrument
    "modules" : ["cpufreq", "bl", "gem5stats"],

    # Host that will run the gem5 instance
    "host"        : "workstation-lin",
    
    "gem5" : {
        # System to simulate
        "system" : {
            # Platform description
            "platform" : {
                # Gem5 platform description
                # LISA will also look for an optional gem5<platform> board file
                # located in the same directory as the description file.
                "description" : os.path.join(base, "juno.py"),
                "args" : [
                    "--power-model", # Platform-specific parameter enabling power modelling
                    "--juno-revision 2",
                    # Resume simulation from a previous checkpoint
                    # Checkpoint must be taken before Virtio folders are mounted
                    #"--checkpoint-indir /data/tmp/Results_LISA/gem5",
                    #"--checkpoint-resume 1",
                ]
            },
            # Kernel compiled for gem5 with Virtio flags
            "kernel"   : os.path.join(base, "product/", "vmlinux"),
            # DTB of the system to simulate
            "dtb"      : os.path.join(base, "product/", "armv8_juno_r2.dtb"),
            # Disk of the distrib to run
            "disk"     : os.path.join(base, "aarch64-ubuntu-trusty-headless.img")
        },
        # gem5 settings
        "simulator" : {
            # Path to gem5 binary
            "bin"     : os.path.join(base, "gem5/build/ARM/gem5.fast"),
            # Args to be given to the binary
            "args" : [
                # Zilch
            ],
        }
    },
    
    # Tools required by the experiments
    "tools"   : ['trace-cmd', 'sysbench', 'rt-app'],
    
    # Output directory on host
    "results_dir" : "gem5_res",
    
    # Energy Meters configuration based on Gem5 stats
    "emeter" : {
        "instrument" : "gem5",
        "conf" : {
            # Zilch
        },
        # Each channel here must refer to a specific **power** field in the stats file. 
        'channel_map' : {
            'Core0S' : 'system.cluster0.cores0.power_model.static_power',
            'Core0D' : 'system.cluster0.cores0.power_model.dynamic_power',
            'Core1S' : 'system.cluster0.cores1.power_model.static_power',
            'Core1D' : 'system.cluster0.cores1.power_model.dynamic_power',
            'Core2S' : 'system.cluster0.cores2.power_model.static_power',
            'Core2D' : 'system.cluster0.cores2.power_model.dynamic_power',
            'Core3S' : 'system.cluster0.cores3.power_model.static_power',
            'Core3D' : 'system.cluster0.cores3.power_model.dynamic_power',
            'Core4S' : 'system.cluster1.cores0.power_model.static_power',
            'Core4D' : 'system.cluster1.cores0.power_model.dynamic_power',
            'Core5S' : 'system.cluster1.cores1.power_model.static_power',
            'Core5D' : 'system.cluster1.cores1.power_model.dynamic_power',
        },
    },
}

In [5]:
# This can take a lot of time ...
te = TestEnv(conf, wipe=True)
target = te.target


2017-08-16 18:12:21,692 INFO    : TestEnv      : Using base path: /data/work/dev/lisa
2017-08-16 18:12:21,693 INFO    : TestEnv      : Loading custom (inline) target configuration
2017-08-16 18:12:21,694 WARNING : TestEnv      : Wipe previous contents of the results folder:
2017-08-16 18:12:21,694 WARNING : TestEnv      :    /data/work/dev/lisa/results/gem5_res
2017-08-16 18:12:22,796 INFO    : TestEnv      : Loading board:
2017-08-16 18:12:22,796 INFO    : TestEnv      :    /data/work/dev/lisa/libs/utils/platforms/gem5juno.json
2017-08-16 18:12:22,798 INFO    : gem5         : Creating temporary directory for interaction  with gem5 via virtIO: /tmp/wa_0
2017-08-16 18:12:22,798 INFO    : gem5         : Starting the gem5 simulator
2017-08-16 18:12:25,815 INFO    : TestEnv      : Devlib modules to load: ['bl', 'cpufreq', 'gem5stats']
2017-08-16 18:12:25,816 INFO    : TestEnv      : Connecting linux target:
2017-08-16 18:12:25,817 INFO    : TestEnv      :   username : root
2017-08-16 18:12:25,817 INFO    : TestEnv      :       host : workstation-lin
2017-08-16 18:12:25,818 INFO    : TestEnv      :   password : 
2017-08-16 18:12:25,818 INFO    : TestEnv      : Connection settings:
2017-08-16 18:12:25,819 INFO    : TestEnv      :    {'username': 'root', 'host': 'workstation-lin', 'password': ''}
2017-08-16 18:12:25,824 INFO    : gem5-connection : Connecting to the gem5 simulation on port 3456
2017-08-16 18:12:36,544 INFO    : gem5-connection : Connected! Waiting for prompt...
2017-08-16 18:12:36,545 INFO    : gem5-connection : Created lock file /tmp/workstation-lin_3456.LOCK to prevent reconnecting to same simulation
2017-08-16 18:12:36,545 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:13:46,607 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:14:56,729 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:16:06,837 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:17:16,958 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:18:27,038 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:19:37,130 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:20:47,220 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:21:57,335 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:23:07,452 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:24:17,515 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:25:27,579 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:26:37,700 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:27:47,820 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:28:57,883 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:30:07,981 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:31:18,056 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:32:28,135 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:33:38,254 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:34:48,343 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:35:58,405 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:37:08,510 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:38:18,620 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:39:28,688 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:40:38,798 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:41:48,866 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:42:58,945 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:44:09,066 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:45:19,185 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:46:29,291 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:47:39,385 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:48:49,502 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:49:59,623 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:51:09,743 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:52:19,813 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:53:29,912 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:54:39,984 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:55:50,055 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:57:00,145 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:58:10,264 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 18:59:20,327 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:00:30,448 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:01:40,513 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:02:50,620 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:04:00,738 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:05:10,801 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:06:20,867 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:07:30,932 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:08:41,001 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:09:51,115 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:11:01,231 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:12:11,306 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:13:21,421 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:14:31,495 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:15:41,597 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:16:51,710 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:18:01,813 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:19:11,902 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:20:22,010 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:21:32,111 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:22:42,231 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:23:52,332 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:25:02,442 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:26:12,506 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:27:22,568 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:28:32,634 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:29:42,741 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:30:52,802 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:32:02,891 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:33:13,009 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:34:23,099 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:35:33,219 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:36:43,340 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:37:53,408 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:39:03,477 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:40:13,597 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:41:23,709 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:42:33,825 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:43:43,886 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:44:53,967 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:46:04,029 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:47:14,118 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:48:24,228 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:49:34,323 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:50:44,419 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:51:54,523 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:53:04,635 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:54:14,739 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:55:24,835 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 19:56:34,901 INFO    : gem5-connection : Trying to log in to gem5 device
2017-08-16 20:01:16,122 INFO    : gem5-connection : Successfully logged in
2017-08-16 20:01:16,122 INFO    : gem5-connection : Setting unique prompt...
2017-08-16 20:01:20,239 INFO    : gem5-connection : Prompt found and replaced with a unique string
2017-08-16 20:01:22,692 INFO    : gem5-connection : Mounting VirtIO device in simulated system
2017-08-16 20:12:36,313 INFO    : TestEnv      : Initializing target workdir:
2017-08-16 20:12:36,314 INFO    : TestEnv      :    /home/root/devlib-target
2017-08-16 20:33:47,467 INFO    : TestEnv      : Attempting to read energy model from target
2017-08-16 20:33:47,468 ERROR   : TestEnv      : Couldn't read target energy model: Requires cpuidle devlib module. Please ensure "cpuidle" is listed in your target/test modules
2017-08-16 20:33:47,469 INFO    : TestEnv      : Topology:
2017-08-16 20:33:47,469 INFO    : TestEnv      :    [[0, 1, 2, 3], [4, 5]]
2017-08-16 20:34:37,405 INFO    : TestEnv      : Loading default EM:
2017-08-16 20:34:37,406 INFO    : TestEnv      :    /data/work/dev/lisa/libs/utils/platforms/gem5juno.json
2017-08-16 20:34:48,890 INFO    : TestEnv      : Calibrating RTApp...
2017-08-16 20:38:25,372 INFO    : RTApp        : CPU0 calibration...
2017-08-16 20:38:30,263 INFO    : Workload     : Setup new workload rta_calib
2017-08-16 20:38:43,655 INFO    : Workload     : Workload duration defined by longest task
2017-08-16 20:38:43,656 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-16 20:38:43,656 INFO    : Workload     : ------------------------
2017-08-16 20:38:43,657 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-16 20:38:43,658 INFO    : Workload     :  | loops count: 1
2017-08-16 20:38:43,658 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-16 20:38:43,659 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-16 20:38:43,659 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-16 20:40:13,501 INFO    : Workload     : Workload execution START:
2017-08-16 20:40:13,502 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x1 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-16 21:26:43,528 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-16 21:28:01,712 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-16 21:28:01,713 INFO    : RTApp        : CPU1 calibration...
2017-08-16 21:28:06,649 INFO    : Workload     : Setup new workload rta_calib
2017-08-16 21:28:19,938 INFO    : Workload     : Workload duration defined by longest task
2017-08-16 21:28:19,939 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-16 21:28:19,940 INFO    : Workload     : ------------------------
2017-08-16 21:28:19,940 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-16 21:28:19,941 INFO    : Workload     :  | loops count: 1
2017-08-16 21:28:19,941 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-16 21:28:19,942 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-16 21:28:19,942 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-16 21:30:10,731 INFO    : Workload     : Workload execution START:
2017-08-16 21:30:10,732 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x2 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-16 22:16:19,363 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-16 22:17:32,906 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-16 22:17:32,907 INFO    : RTApp        : CPU2 calibration...
2017-08-16 22:17:37,319 INFO    : Workload     : Setup new workload rta_calib
2017-08-16 22:17:49,418 INFO    : Workload     : Workload duration defined by longest task
2017-08-16 22:17:49,419 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-16 22:17:49,420 INFO    : Workload     : ------------------------
2017-08-16 22:17:49,420 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-16 22:17:49,421 INFO    : Workload     :  | loops count: 1
2017-08-16 22:17:49,422 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-16 22:17:49,422 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-16 22:17:49,422 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-16 22:19:33,201 INFO    : Workload     : Workload execution START:
2017-08-16 22:19:33,202 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x4 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-16 23:04:42,602 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-16 23:05:58,918 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-16 23:05:58,919 INFO    : RTApp        : CPU3 calibration...
2017-08-16 23:06:03,183 INFO    : Workload     : Setup new workload rta_calib
2017-08-16 23:06:15,906 INFO    : Workload     : Workload duration defined by longest task
2017-08-16 23:06:15,906 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-16 23:06:15,907 INFO    : Workload     : ------------------------
2017-08-16 23:06:15,907 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-16 23:06:15,908 INFO    : Workload     :  | loops count: 1
2017-08-16 23:06:15,908 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-16 23:06:15,909 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-16 23:06:15,909 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-16 23:07:45,356 INFO    : Workload     : Workload execution START:
2017-08-16 23:07:45,357 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x8 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-16 23:53:15,385 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-16 23:54:29,224 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-16 23:54:29,225 INFO    : RTApp        : CPU4 calibration...
2017-08-16 23:54:33,293 INFO    : Workload     : Setup new workload rta_calib
2017-08-16 23:54:45,843 INFO    : Workload     : Workload duration defined by longest task
2017-08-16 23:54:45,843 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-16 23:54:45,844 INFO    : Workload     : ------------------------
2017-08-16 23:54:45,845 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-16 23:54:45,845 INFO    : Workload     :  | loops count: 1
2017-08-16 23:54:45,846 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-16 23:54:45,847 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-16 23:54:45,848 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-16 23:56:16,442 INFO    : Workload     : Workload execution START:
2017-08-16 23:56:16,443 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x10 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-17 01:14:31,053 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-17 01:15:43,793 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-17 01:15:43,793 INFO    : RTApp        : CPU5 calibration...
2017-08-17 01:15:48,155 INFO    : Workload     : Setup new workload rta_calib
2017-08-17 01:16:01,836 INFO    : Workload     : Workload duration defined by longest task
2017-08-17 01:16:01,837 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-17 01:16:01,838 INFO    : Workload     : ------------------------
2017-08-17 01:16:01,838 INFO    : Workload     : task [task1], sched: {'policy': 'FIFO', 'prio': 0}
2017-08-17 01:16:01,839 INFO    : Workload     :  | loops count: 1
2017-08-17 01:16:01,839 INFO    : Workload     : + phase_000001: duration 1.000000 [s] (10 loops)
2017-08-17 01:16:01,840 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-17 01:16:01,840 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-17 01:17:29,376 INFO    : Workload     : Workload execution START:
2017-08-17 01:17:29,377 INFO    : Workload     :    /home/root/devlib-target/bin/taskset 0x20 /home/root/devlib-target/bin/rt-app /home/root/devlib-target/rta_calib_00.json 2>&1
2017-08-17 02:32:13,228 WARNING : ssh          : Destination file rt-app-task1-0.log already exists!
2017-08-17 02:33:25,637 WARNING : ssh          : Destination file rta_calib_00.json already exists!
2017-08-17 02:37:28,907 INFO    : RTApp        : Target RT-App calibration:
2017-08-17 02:37:28,908 INFO    : RTApp        : {"0": 894, "1": 894, "2": 894, "3": 893, "4": 235, "5": 234}
2017-08-17 02:37:54,764 INFO    : RTApp        : big cores are ~280% more capable than LITTLE cores
2017-08-17 02:37:54,765 INFO    : TestEnv      : Using RT-App calibration values:
2017-08-17 02:37:54,766 INFO    : TestEnv      :    {"0": 894, "1": 894, "2": 894, "3": 893, "4": 235, "5": 234}
2017-08-17 02:38:05,952 INFO    : TestEnv      : Set results folder to:
2017-08-17 02:38:05,953 INFO    : TestEnv      :    /data/work/dev/lisa/results/gem5_res
2017-08-17 02:38:05,954 INFO    : TestEnv      : Experiment results available also in:
2017-08-17 02:38:05,954 INFO    : TestEnv      :    /data/work/dev/lisa/results_latest

Workload execution

For this example, we will investigate the energy consumption of the target while running a random workload. Our observations will be made using the RT-App decreasing ramp workload defined below. With such a workload, the system load goes from high to low over time. We expect to see a similar pattern in power consumption.


In [6]:
# Create and RTApp RAMP tasks
rtapp = RTA(target, 'ramp', calibration=te.calibration())
rtapp.conf(kind='profile',
           params={
                'ramp1' : Ramp(
                    start_pct =  95,
                    end_pct   =  5,
                    delta_pct =   10,
                    time_s    =   0.1).get(),
                'ramp2' : Ramp(
                    start_pct =  90,
                    end_pct   =  30,
                    delta_pct =   20,
                    time_s    =   0.2).get(),
          })


2017-08-17 02:38:05,960 INFO    : Workload     : Setup new workload ramp
2017-08-17 02:38:19,705 INFO    : Workload     : Workload duration defined by longest task
2017-08-17 02:38:19,706 INFO    : Workload     : Default policy: SCHED_OTHER
2017-08-17 02:38:19,707 INFO    : Workload     : ------------------------
2017-08-17 02:38:19,708 INFO    : Workload     : task [ramp1], sched: using default policy
2017-08-17 02:38:19,708 INFO    : Workload     :  | loops count: 1
2017-08-17 02:38:19,709 INFO    : Workload     : + phase_000001: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,709 INFO    : Workload     : |  period   100000 [us], duty_cycle  95 %
2017-08-17 02:38:19,710 INFO    : Workload     : |  run_time  95000 [us], sleep_time   5000 [us]
2017-08-17 02:38:19,710 INFO    : Workload     : + phase_000002: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,710 INFO    : Workload     : |  period   100000 [us], duty_cycle  85 %
2017-08-17 02:38:19,711 INFO    : Workload     : |  run_time  85000 [us], sleep_time  15000 [us]
2017-08-17 02:38:19,711 INFO    : Workload     : + phase_000003: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,712 INFO    : Workload     : |  period   100000 [us], duty_cycle  75 %
2017-08-17 02:38:19,712 INFO    : Workload     : |  run_time  75000 [us], sleep_time  25000 [us]
2017-08-17 02:38:19,713 INFO    : Workload     : + phase_000004: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,713 INFO    : Workload     : |  period   100000 [us], duty_cycle  65 %
2017-08-17 02:38:19,714 INFO    : Workload     : |  run_time  65000 [us], sleep_time  35000 [us]
2017-08-17 02:38:19,714 INFO    : Workload     : + phase_000005: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,714 INFO    : Workload     : |  period   100000 [us], duty_cycle  55 %
2017-08-17 02:38:19,715 INFO    : Workload     : |  run_time  55000 [us], sleep_time  45000 [us]
2017-08-17 02:38:19,715 INFO    : Workload     : + phase_000006: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,716 INFO    : Workload     : |  period   100000 [us], duty_cycle  45 %
2017-08-17 02:38:19,716 INFO    : Workload     : |  run_time  45000 [us], sleep_time  55000 [us]
2017-08-17 02:38:19,717 INFO    : Workload     : + phase_000007: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,717 INFO    : Workload     : |  period   100000 [us], duty_cycle  35 %
2017-08-17 02:38:19,718 INFO    : Workload     : |  run_time  35000 [us], sleep_time  65000 [us]
2017-08-17 02:38:19,719 INFO    : Workload     : + phase_000008: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,719 INFO    : Workload     : |  period   100000 [us], duty_cycle  25 %
2017-08-17 02:38:19,720 INFO    : Workload     : |  run_time  25000 [us], sleep_time  75000 [us]
2017-08-17 02:38:19,721 INFO    : Workload     : + phase_000009: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,721 INFO    : Workload     : |  period   100000 [us], duty_cycle  15 %
2017-08-17 02:38:19,722 INFO    : Workload     : |  run_time  15000 [us], sleep_time  85000 [us]
2017-08-17 02:38:19,722 INFO    : Workload     : + phase_000010: duration 0.100000 [s] (1 loops)
2017-08-17 02:38:19,723 INFO    : Workload     : |  period   100000 [us], duty_cycle   5 %
2017-08-17 02:38:19,724 INFO    : Workload     : |  run_time   5000 [us], sleep_time  95000 [us]
2017-08-17 02:38:19,724 INFO    : Workload     : ------------------------
2017-08-17 02:38:19,725 INFO    : Workload     : task [ramp2], sched: using default policy
2017-08-17 02:38:19,725 INFO    : Workload     :  | loops count: 1
2017-08-17 02:38:19,726 INFO    : Workload     : + phase_000001: duration 0.200000 [s] (2 loops)
2017-08-17 02:38:19,727 INFO    : Workload     : |  period   100000 [us], duty_cycle  90 %
2017-08-17 02:38:19,727 INFO    : Workload     : |  run_time  90000 [us], sleep_time  10000 [us]
2017-08-17 02:38:19,728 INFO    : Workload     : + phase_000002: duration 0.200000 [s] (2 loops)
2017-08-17 02:38:19,729 INFO    : Workload     : |  period   100000 [us], duty_cycle  70 %
2017-08-17 02:38:19,730 INFO    : Workload     : |  run_time  70000 [us], sleep_time  30000 [us]
2017-08-17 02:38:19,730 INFO    : Workload     : + phase_000003: duration 0.200000 [s] (2 loops)
2017-08-17 02:38:19,731 INFO    : Workload     : |  period   100000 [us], duty_cycle  50 %
2017-08-17 02:38:19,732 INFO    : Workload     : |  run_time  50000 [us], sleep_time  50000 [us]
2017-08-17 02:38:19,732 INFO    : Workload     : + phase_000004: duration 0.200000 [s] (2 loops)
2017-08-17 02:38:19,732 INFO    : Workload     : |  period   100000 [us], duty_cycle  30 %
2017-08-17 02:38:19,733 INFO    : Workload     : |  run_time  30000 [us], sleep_time  70000 [us]
Out[6]:
'ramp_00'

Energy estimation

The gem5 energy meters feature two methods: reset and report.

  • The reset method will start sampling the channels defined in the target configuration.
  • The report method will stop the sampling and produce a CSV file containing power samples together with a JSON file summarizing the total energy consumption of each channel.

In [7]:
# Start emeters & run workload
te.emeter.reset()
rtapp.run(out_dir=te.res_dir)
nrg_rep = te.emeter.report(te.res_dir)


2017-08-17 02:40:06,494 INFO    : Workload     : Workload execution START:
2017-08-17 02:40:06,494 INFO    : Workload     :    /home/root/devlib-target/bin/rt-app /home/root/devlib-target/ramp_00.json 2>&1

Data analysis


In [8]:
logging.info("Measured channels energy:")
print json.dumps(nrg_rep.channels, indent=4)


2017-08-17 04:43:29,481 INFO    : root         : Measured channels energy:
{
    "system.cluster0.cores2.power_model.dynamic_power": 0.0015930811939999978, 
    "system.cluster0.cores2.power_model.static_power": 5.5844099999999809e-07, 
    "system.cluster0.cores0.power_model.static_power": 1.3219494999999962e-05, 
    "system.cluster0.cores3.power_model.dynamic_power": 0.15863506186750015, 
    "system.cluster0.cores0.power_model.dynamic_power": 0.0027130621879999954, 
    "system.cluster1.cores1.power_model.dynamic_power": 0.013573508823999998, 
    "system.cluster0.cores3.power_model.static_power": 0.0009470161700000008, 
    "system.cluster0.cores1.power_model.static_power": 1.930225999999995e-06, 
    "system.cluster1.cores1.power_model.static_power": 0.00015487269799999999, 
    "system.cluster1.cores0.power_model.dynamic_power": 0.29683561018450011, 
    "system.cluster0.cores1.power_model.dynamic_power": 0.0017484881624999973, 
    "system.cluster1.cores0.power_model.static_power": 0.0029071225505000018
}

In [9]:
logging.info("DataFrame of collected samples (only first 5)")
nrg_rep.data_frame.head()


2017-08-17 04:43:29,513 INFO    : root         : DataFrame of collected samples (only first 5)
Out[9]:
sim_seconds system.cluster0.cores0.power_model.dynamic_power system.cluster0.cores0.power_model.static_power system.cluster0.cores1.power_model.dynamic_power system.cluster0.cores1.power_model.static_power system.cluster0.cores2.power_model.dynamic_power system.cluster0.cores2.power_model.static_power system.cluster0.cores3.power_model.dynamic_power system.cluster0.cores3.power_model.static_power system.cluster1.cores0.power_model.dynamic_power system.cluster1.cores0.power_model.static_power system.cluster1.cores1.power_model.dynamic_power system.cluster1.cores1.power_model.static_power
time power power power power power power power power power power power power
0.000000 0.000723 0.022943 0.000065 0.017251 0.000001 0.017685 0.000007 0.057793 0.000488 0.022847 0.000234 0.002798 0.000007
0.010000 0.010000 0.024210 0.000085 0.016583 0.000000 0.016586 0.000000 0.063653 0.000479 0.005193 0.000034 0.081359 0.000826
0.017737 0.007737 0.000556 0.000003 0.000479 0.000002 0.000351 0.000000 0.082148 0.000488 0.455068 0.004354 0.113078 0.001088
0.019614 0.001877 0.000255 0.000000 0.000000 0.000000 0.000000 0.000000 0.081870 0.000488 0.189404 0.003608 0.010095 0.000206
0.020000 0.000386 0.000000 0.000000 0.000000 0.000000 0.000000 0.000000 0.082142 0.000488 0.561227 0.005374 0.000000 0.000000

In [10]:
# Obtain system level energy by ...
df = nrg_rep.data_frame
# ... summing the dynamic power of all cores to obtain total dynamic power, ...
df["total_dynamic"] = df[('system.cluster0.cores0.power_model.dynamic_power', 'power')] + \
                      df[('system.cluster0.cores1.power_model.dynamic_power', 'power')] + \
                      df[('system.cluster0.cores2.power_model.dynamic_power', 'power')] + \
                      df[('system.cluster0.cores3.power_model.dynamic_power', 'power')] + \
                      df[('system.cluster1.cores0.power_model.dynamic_power', 'power')] + \
                      df[('system.cluster1.cores1.power_model.dynamic_power', 'power')]
# ... summing the static power of all cores to obtain total static power and ...
df["total_static"] = df[('system.cluster0.cores0.power_model.static_power', 'power')] + \
                      df[('system.cluster0.cores1.power_model.static_power', 'power')] + \
                      df[('system.cluster0.cores2.power_model.static_power', 'power')] + \
                      df[('system.cluster0.cores3.power_model.static_power', 'power')] + \
                      df[('system.cluster1.cores0.power_model.static_power', 'power')] + \
                      df[('system.cluster1.cores1.power_model.static_power', 'power')]
# ... summing the dynamic and static powers
df["total"] = df["total_dynamic"] + df["total_static"]

In [11]:
logging.info("Plot of collected power samples")
axes =df[('total')].plot(figsize=(16,8),
                         drawstyle='steps-post');
axes.set_title('Power samples');
axes.set_xlabel('Time [s]');
axes.set_ylabel('Output power [W]');


2017-08-17 04:43:29,627 INFO    : root         : Plot of collected power samples

We can see on the above plot that the system level power consumption decreases over time (in average). This is coherent with the expected behaviour given the decreasing ramp workload under consideration.


In [12]:
logging.info("Power distribution")
axes = df[('total')].plot(kind='hist', bins=32,
                          figsize=(16,8));
axes.set_title('Power Histogram');
axes.set_xlabel('Output power [W] buckets');
axes.set_ylabel('Samples per bucket');


2017-08-17 04:43:29,810 INFO    : root         : Power distribution

In [13]:
logging.info("Plot of collected power samples")
nrg_rep.data_frame.describe(percentiles=[0.90, 0.95, 0.99]).T


2017-08-17 04:43:30,013 INFO    : root         : Plot of collected power samples
Out[13]:
count mean std min 50% 90% 95% 99% max
sim_seconds time 225.0 8.800516e-03 0.002832 0.000246 0.010000 0.010000 0.010000 0.010000 0.010000
system.cluster0.cores0.power_model.dynamic_power power 225.0 1.860018e-03 0.006584 0.000000 0.000000 0.000170 0.021604 0.028975 0.036593
system.cluster0.cores0.power_model.static_power power 225.0 9.782222e-06 0.000036 0.000000 0.000000 0.000000 0.000099 0.000165 0.000255
system.cluster0.cores1.power_model.dynamic_power power 225.0 1.103284e-03 0.004315 0.000000 0.000000 0.000000 0.013626 0.021795 0.023048
system.cluster0.cores1.power_model.static_power power 225.0 1.160000e-06 0.000008 0.000000 0.000000 0.000000 0.000002 0.000046 0.000076
system.cluster0.cores2.power_model.dynamic_power power 225.0 1.011360e-03 0.004075 0.000000 0.000000 0.000000 0.013540 0.018692 0.025682
system.cluster0.cores2.power_model.static_power power 225.0 4.000000e-07 0.000003 0.000000 0.000000 0.000000 0.000000 0.000009 0.000042
system.cluster0.cores3.power_model.dynamic_power power 225.0 7.881513e-02 0.013059 0.003832 0.082498 0.082545 0.082548 0.082639 0.082641
system.cluster0.cores3.power_model.static_power power 225.0 4.727467e-04 0.000067 0.000003 0.000488 0.000488 0.000488 0.000488 0.000488
system.cluster1.cores0.power_model.dynamic_power power 225.0 1.475154e-01 0.227330 0.000000 0.000000 0.561185 0.561188 0.561307 0.561547
system.cluster1.cores0.power_model.static_power power 225.0 1.512400e-03 0.002240 0.000000 0.000000 0.005374 0.005374 0.005374 0.005374
system.cluster1.cores1.power_model.dynamic_power power 225.0 9.468827e-03 0.037444 0.000000 0.000000 0.006187 0.080026 0.166915 0.295482
system.cluster1.cores1.power_model.static_power power 225.0 1.134667e-04 0.000449 0.000000 0.000000 0.000115 0.001036 0.002300 0.003488
total_dynamic 225.0 2.397740e-01 0.226858 0.029284 0.082545 0.643704 0.643728 0.646666 0.651680
total_static 225.0 2.109956e-03 0.002235 0.000297 0.000488 0.005862 0.005862 0.005893 0.005935
total 225.0 2.418840e-01 0.229050 0.029581 0.083033 0.649566 0.649590 0.652559 0.657615

In [14]:
# Don't forget to stop Gem5
target.disconnect()


2017-08-17 04:43:30,123 INFO    : gem5-connection : Gracefully terminating the gem5 simulation.
2017-08-17 04:43:37,381 INFO    : gem5-connection : Removing the temporary directory