From 9ba5e23690f9c2814d9b164ab2ba12e2d060e86d Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Thu, 20 Apr 2017 11:23:42 -0700 Subject: [PATCH 01/10] android: Add system wakeup and sleep keycodes Signed-off-by: Joel Fernandes --- libs/utils/android/system.py | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/libs/utils/android/system.py b/libs/utils/android/system.py index 42e8c4dec..c26b0dd08 100644 --- a/libs/utils/android/system.py +++ b/libs/utils/android/system.py @@ -254,6 +254,26 @@ class System(object): """ target.execute('input keyevent KEYCODE_BACK') + @staticmethod + def wakeup(target): + """ + Wake up the system if its sleeping + + :param target: instance of devlib Android target + :type target: devlib.target.AndroidTarget + """ + target.execute('input keyevent KEYCODE_WAKEUP') + + @staticmethod + def sleep(target): + """ + Make system sleep if its awake + + :param target: instance of devlib Android target + :type target: devlib.target.AndroidTarget + """ + target.execute('input keyevent KEYCODE_SLEEP') + @staticmethod def gfxinfo_reset(target, apk_name): """ -- GitLab From fb6046b3808fdbbc648076a6db5a9846e070080f Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Sun, 26 Mar 2017 04:05:37 -0700 Subject: [PATCH 02/10] android: Add support for screen on/off and unlock Signed-off-by: Joel Fernandes --- libs/utils/android/screen.py | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/libs/utils/android/screen.py b/libs/utils/android/screen.py index af80a5f07..971760660 100644 --- a/libs/utils/android/screen.py +++ b/libs/utils/android/screen.py @@ -16,6 +16,7 @@ # import logging +from system import System class Screen(object): """ @@ -136,4 +137,20 @@ class Screen(object): """ return target.execute('getprop ro.sf.lcd_density') + @staticmethod + def set_screen(target, on=True): + log = logging.getLogger('Screen') + if not on: + log.info('Setting screen OFF') + System.sleep(target) + return + log.info('Setting screen ON') + System.wakeup(target) + + @staticmethod + def unlock(target): + Screen.set_screen(target, on=True) + System.menu(target) + System.home(target) + # vim :set tabstop=4 shiftwidth=4 expandtab -- GitLab From 70ee583c68a7f91f276d35c12153615edd2b079a Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Mon, 17 Apr 2017 21:43:33 -0700 Subject: [PATCH 03/10] android workloads: Unlock screen properly Also wakes up device if needed while unlocking. For youtube workloads: Since I am removing back button as a part of the unlock patch, I changed to starting youtube video from beginning, to do it with help of force_stop instead of back button which I also find to be more robust. Signed-off-by: Joel Fernandes --- libs/utils/android/workloads/gmaps.py | 4 +--- libs/utils/android/workloads/jankbench.py | 5 ++--- libs/utils/android/workloads/uibench.py | 5 ++--- libs/utils/android/workloads/vellamo.py | 3 +-- libs/utils/android/workloads/youtube.py | 7 ++++--- 5 files changed, 10 insertions(+), 14 deletions(-) diff --git a/libs/utils/android/workloads/gmaps.py b/libs/utils/android/workloads/gmaps.py index 380686d48..838f5cf0e 100644 --- a/libs/utils/android/workloads/gmaps.py +++ b/libs/utils/android/workloads/gmaps.py @@ -70,9 +70,7 @@ class GMaps(Workload): # Set min brightness Screen.set_brightness(self._target, auto=False, percent=0) # Unlock device screen (assume no password required) - System.menu(self._target) - # Press Back button to be sure we run the video from the start - System.back(self._target) + Screen.unlock(self._target) # Use the monkey tool to start GMaps # This allows to subsequently set the screen orientation to LANDSCAPE diff --git a/libs/utils/android/workloads/jankbench.py b/libs/utils/android/workloads/jankbench.py index fcf76e8a0..5d17ded92 100644 --- a/libs/utils/android/workloads/jankbench.py +++ b/libs/utils/android/workloads/jankbench.py @@ -102,9 +102,8 @@ class Jankbench(Workload): except KeyError: raise ValueError('Jankbench test [%s] not supported', test_name) - # Make sure we exit the app if already open - System.menu(self._target) - System.back(self._target) + # Unlock device screen (assume no password required) + Screen.unlock(self._target) # Close and clear application System.force_stop(self._target, self.package, clear=True) diff --git a/libs/utils/android/workloads/uibench.py b/libs/utils/android/workloads/uibench.py index bdba69fa8..3b24030ee 100755 --- a/libs/utils/android/workloads/uibench.py +++ b/libs/utils/android/workloads/uibench.py @@ -85,9 +85,8 @@ class UiBench(Workload): self.out_dir = out_dir self.collect = collect - # Press Back button to be sure we run the video from the start - System.menu(self._target) - System.back(self._target) + # Unlock device screen (assume no password required) + Screen.unlock(self._target) # Close and clear application System.force_stop(self._target, self.package, clear=True) diff --git a/libs/utils/android/workloads/vellamo.py b/libs/utils/android/workloads/vellamo.py index 476266efa..c8863e8d2 100644 --- a/libs/utils/android/workloads/vellamo.py +++ b/libs/utils/android/workloads/vellamo.py @@ -94,8 +94,7 @@ class Vellamo(Workload): sleep_time = 3.5 # Unlock device screen (assume no password required) - System.menu(self._target) - System.back(self._target) + Screen.unlock(self._target) System.force_stop(self._target, self.package, clear=True) diff --git a/libs/utils/android/workloads/youtube.py b/libs/utils/android/workloads/youtube.py index a2461926e..cdfbf2d04 100644 --- a/libs/utils/android/workloads/youtube.py +++ b/libs/utils/android/workloads/youtube.py @@ -66,9 +66,10 @@ class YouTube(Workload): self.collect = collect # Unlock device screen (assume no password required) - System.menu(self._target) - # Press Back button to be sure we run the video from the start - System.back(self._target) + Screen.unlock(self._target) + + # Stop youtube if already running + System.force_stop(self._target, self.package) # Use the monkey tool to start YouTube without playing any video. # This allows to subsequently set the screen orientation to LANDSCAPE -- GitLab From b6e651363cad0848103c9f0767de725ee3ab6213 Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Thu, 16 Mar 2017 20:12:23 -0700 Subject: [PATCH 04/10] Add a monsoon meter for devlib's monsoon instrument The instrument is pushed to devlib separately Signed-off-by: Joel Fernandes --- libs/utils/energy.py | 55 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 55 insertions(+) diff --git a/libs/utils/energy.py b/libs/utils/energy.py index 9e78f45cf..f3753da97 100644 --- a/libs/utils/energy.py +++ b/libs/utils/energy.py @@ -18,9 +18,12 @@ import devlib import json import os +import os.path import psutil import time import logging +from subprocess import Popen, STDOUT +from threading import Timer from collections import namedtuple from subprocess import Popen, PIPE, STDOUT @@ -118,6 +121,58 @@ class EnergyMeter(object): def report(self, out_dir): raise NotImplementedError('Missing implementation') +class Monsoon(EnergyMeter): + def print_log(self, errmsg, exception=0): + print errmsg + self._log.error(errmsg) + if exception == 1: + raise(Exception(errmsg)) + + def __init__(self, target, conf=None): + super(Monsoon, self).__init__(target, '') + + # Read config + # { 'config': { 'device_entry' : '/dev/ttyACM1', 'voltage' : 4.3 } } + try: + device_entry = conf['config']['device_entry'] + self.voltage = conf['config']['voltage'] + except: + device_entry = None + self.voltage = 4.3 + self._log.info("Invalid conf, using defaults. Example format is \ + { 'config': { 'device_entry' : '/dev/ttyACM1', 'voltage' : 4.3 }") + self._monsoon = devlib.MonsoonInstrument(self._target, device_entry) + + def reset_only(self): + m = self._monsoon + self._log.info('Initiailzing Monsoon') + # Waiting for monsoon to get ready + m.get_status() + # Provide power to the target + m.set_voltage(0) + m.set_current(8) + m.set_start_current(8) + m.set_voltage(self.voltage) + self._log.info("Monsoon ready for action") + + # Start a monsoon run asynchronously + def reset(self): + m = self._monsoon + self.reset_only() + m.start() + + # Kill an already running test and report in panda dataframes + def report(self): + return self._monsoon.report() + + # This is synchronous (block until duration) + def get_samples(self, duration): + return self._monsoon.get_samples_sync(duration) + + # Returns csv text output synchronously - function not typically used directly + def run_monsoon(self, args, stream=0, timeout=5): + return self._monsoon.run_monsoon(args, stream, timeout) + class HWMon(EnergyMeter): def __init__(self, target, conf=None, res_dir=None): -- GitLab From 9ac735094b41201637bda3ed2febefe5025b73a7 Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Sat, 22 Apr 2017 12:52:53 -0700 Subject: [PATCH 05/10] Track wakeup latencies Signed-off-by: Joel Fernandes --- get_wlat.py | 144 ++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 144 insertions(+) create mode 100755 get_wlat.py diff --git a/get_wlat.py b/get_wlat.py new file mode 100755 index 000000000..db54dc836 --- /dev/null +++ b/get_wlat.py @@ -0,0 +1,144 @@ +#!/usr/bin/env python + +from collections import namedtuple +import trappy + +EventRow = namedtuple('EventRow', ['time', 'event', 'row']) +LatRow = namedtuple('LatRow', ['pid', 'switch_row', 'wake_row', 'last_wake_row', 'running', 'wake_pend', 'latency']) + +def print_event_rows(rows, start, end): + print "time".ljust(20) + "\t" + "event".ljust(10) + "\tpid" + "\tprevpid" + "\tnextpid" + for r in rows: + if r.time < start or r.time > end: + continue + if r.event == "switch": + nextpid = r.row['next_pid'] + prevpid = r.row['prev_pid'] + pid = -1 + elif r.event == "wake": + pid = r.row['pid'] + nextpid = -1 + prevpid = -1 + else: + raise RuntimeError("unknown event seen") + print str(r.time).ljust(20)[:20] + "\t" + r.event.ljust(10) + "\t" + str(pid) + "\t" + str(prevpid) + "\t" + str(nextpid) + +path_to_html = "/home/joelaf/repo/catapult/systrace/trace_sf-dispsync_rt_pull_fail_1504ms.html" + +systrace_obj = trappy.SysTrace(name="systrace", path=path_to_html, \ + scope="sched", events=["sched_switch", + "sched_wakeup", "sched_waking"]) + +df = systrace_obj.sched_switch.data_frame +# df = df[(df.next_prio < 100) | (df.prev_prio < 100)] +switch_df = df + +df = systrace_obj.sched_wakeup.data_frame +# df = df[df.prio < 100] +wake_df = df + +# Build list of rows +switch_rows = [EventRow(time=i, event="switch", row=row) for i, row in switch_df.iterrows()] +wake_rows = [EventRow(time=i, event="wake", row=row) for i, row in wake_df.iterrows()] +rows = switch_rows + wake_rows +rows = sorted(rows, key=lambda r: r.time) + +# Hash table of pid -> LatRow named tuple +latpids = {} + +for r in rows: + # a df row has a key which is the timestamp and a value which + # is of dtype object which has the trace event fields + row = r.row + event = r.event + time = r.time + + debug = False + dpid = 21047 + + if event == "switch": + prevpid = row['prev_pid'] + nextpid = row['next_pid'] + + debug = debug and (prevpid == dpid or nextpid == dpid) + + if (debug): + print "\nProcessing switch nextpid=" + str(nextpid) + " prevpid=" + str(prevpid) +\ + " time=" + str(time) + + # prev pid processing (switch out) + if latpids.has_key(prevpid): + if latpids[prevpid].running == 1: + latpids[prevpid] = latpids[prevpid]._replace(running=0) + if latpids[prevpid].wake_pend == 1: + print "Impossible: switch out during wake_pend " + str(r) + raise RuntimeError("error") + + if not latpids.has_key(nextpid): + continue + + # nextpid processing (switch in) + pid = nextpid + + if latpids[pid].running == 1: + print "INFO: previous pid switch-out not seen for an event, ignoring\n" + str(r) + continue + + latpids[pid] = latpids[pid]._replace(running=1) + + # Ignore latency calc for next-switch events for which wake never seen + # They are still valid in this scenario because of preemption + if latpids[pid].wake_pend == 0: + if debug: + print "wake_pend = 0, doing nothing" + continue + + # Measure latency + lat = time - latpids[pid].last_wake_row.time + + if lat > latpids[pid].latency: + if debug: + print "recording" + latpids[pid] = LatRow(pid, switch_row = r, + wake_row = latpids[pid].last_wake_row, + last_wake_row=None, latency=lat, running=1, wake_pend=0) + continue + if debug: + print "recording" + latpids[pid] = latpids[pid]._replace(running=1, wake_pend=0) + elif event == "wake": + pid = row["pid"] + debug = debug and (pid == dpid) + if (debug): + print "\nProcessing wake pid=" + str(pid) + " time=" + str(time) + if not latpids.has_key(pid): + latpids[pid] = LatRow(pid, switch_row=None, wake_row=None, + last_wake_row = r, running=0, latency=-1, wake_pend=1) + if debug: + print "new wakeup" + continue + if latpids[pid].running == 1 or latpids[pid].wake_pend == 1: + if debug: + print "already running or wake_pend" + # Task already running or a wakeup->switch pending, ignore + continue + if debug: + print "recording wake" + latpids[pid] = latpids[pid]._replace(last_wake_row = r, wake_pend=1) + else: + errmsg = "Parsing error: Unknown trace event in EventRow (" + str(event) + ")" + raise RuntimeError(errmsg) + +# Print PID, latency, start, end, sort +result = sorted(latpids.items(), key=lambda x: x[1].latency, reverse=True) + +print "PID".ljust(10) + "\t" + "name".ljust(20) + "\t" + "latency (secs)".ljust(20) + \ + "\t" + "start time".ljust(20) + "\t" + "end time".ljust(20) +for r in result: + l = r[1] # LatRow named tuple + if l.pid != r[0]: + raise RuntimeError("BUG: pid inconsitency found") # Sanity check + print str(r[0]).ljust(10) + "\t" + str(l.wake_row.row['comm']).ljust(20) + "\t" + \ + str(l.latency).ljust(20)[:20] + "\t" + str(l.wake_row.time).ljust(20)[:20] + \ + "\t" + str(l.switch_row.time).ljust(20)[:20] + -- GitLab From 4d4c9aff3a18a3aaff2419fe635f6116c5ebe60d Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Sun, 23 Apr 2017 03:20:13 -0700 Subject: [PATCH 06/10] alternate script using cbs Signed-off-by: Joel Fernandes --- get_wlat_cbs.py | 146 ++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 146 insertions(+) create mode 100755 get_wlat_cbs.py diff --git a/get_wlat_cbs.py b/get_wlat_cbs.py new file mode 100755 index 000000000..939501bc6 --- /dev/null +++ b/get_wlat_cbs.py @@ -0,0 +1,146 @@ +#!/usr/bin/env python + +from collections import namedtuple +import trappy + +EventRow = namedtuple('EventRow', ['time', 'event', 'row']) +LatRow = namedtuple('LatRow', ['pid', 'switch_row', 'wake_row', 'last_wake_row', 'running', 'wake_pend', 'latency']) + +def printsw(time, data): + print str(time) + ": " + str(data) + +def print_event_rows(rows, start, end): + print "time".ljust(20) + "\t" + "event".ljust(10) + "\tpid" + "\tprevpid" + "\tnextpid" + for r in rows: + if r.time < start or r.time > end: + continue + if r.event == "switch": + nextpid = r.row['next_pid'] + prevpid = r.row['prev_pid'] + pid = -1 + elif r.event == "wake": + pid = r.row['pid'] + nextpid = -1 + prevpid = -1 + else: + raise RuntimeError("unknown event seen") + print str(r.time).ljust(20)[:20] + "\t" + r.event.ljust(10) + "\t" + str(pid) + "\t" + str(prevpid) + "\t" + str(nextpid) + +path_to_html = "/home/joelaf/repo/catapult/systrace/trace_sf-dispsync_rt_pull_fail_1504ms.html" + +# Hash table of pid -> LatRow named tuple +latpids = {} +dpid = 21047 +debugg = False + +def switch_cb(time, data): + row = data + event = "switch" + + prevpid = row['prev_pid'] + nextpid = row['next_pid'] + + r = EventRow(time=time, event="switch", row=data) + + debug = debugg and (prevpid == dpid or nextpid == dpid) + + if (debug): + print "\nProcessing switch nextpid=" + str(nextpid) + " prevpid=" + str(prevpid) + \ + " time=" + str(time) + + # prev pid processing (switch out) + if latpids.has_key(prevpid): + if latpids[prevpid].running == 1: + latpids[prevpid] = latpids[prevpid]._replace(running=0) + if latpids[prevpid].wake_pend == 1: + print "Impossible: switch out during wake_pend " + str(r) + raise RuntimeError("error") + + if not latpids.has_key(nextpid): + return + + # nextpid processing (switch in) + pid = nextpid + if latpids[pid].running == 1: + print "INFO: previous pid switch-out not seen for an event, ignoring\n" + str(r) + return + latpids[pid] = latpids[pid]._replace(running=1) + + # Ignore latency calc for next-switch events for which wake never seen + # They are still valid in this scenario because of preemption + if latpids[pid].wake_pend == 0: + if debug: + print "wake_pend = 0, doing nothing" + return + + if debug: + print "recording" + # Measure latency + lat = time - latpids[pid].last_wake_row.time + if lat > latpids[pid].latency: + latpids[pid] = LatRow(pid, switch_row = r, + wake_row = latpids[pid].last_wake_row, + last_wake_row=None, latency=lat, running=1, wake_pend=0) + return + latpids[pid] = latpids[pid]._replace(running=1, wake_pend=0) + +def wake_cb(time, data): + row = data + event = "wake" + pid = row["pid"] + debug = debugg and (pid == dpid) + + r = EventRow(time=time, event="wake", row=data) + + if (debug): + print "\nProcessing wake pid=" + str(pid) + " time=" + str(time) + if not latpids.has_key(pid): + latpids[pid] = LatRow(pid, switch_row=None, wake_row=None, + last_wake_row = r, running=0, latency=-1, wake_pend=1) + if debug: + print "new wakeup" + return + + if latpids[pid].running == 1 or latpids[pid].wake_pend == 1: + if debug: + print "already running or wake_pend" + # Task already running or a wakeup->switch pending, ignore + return + + if debug: + print "recording wake" + latpids[pid] = latpids[pid]._replace(last_wake_row = r, wake_pend=1) + +systrace_obj = trappy.SysTrace(name="systrace", path=path_to_html, \ + scope="sched", events=["sched_switch", "sched_wakeup", "sched_waking"], + event_callbacks={ "sched_switch": switch_cb, "sched_wakeup": wake_cb }) + +""" +df = systrace_obj.sched_switch.data_frame +# df = df[(df.next_prio < 100) | (df.prev_prio < 100)] +switch_df = df + +df = systrace_obj.sched_wakeup.data_frame +# df = df[df.prio < 100] +wake_df = df + +# Build list of rows +switch_rows = [EventRow(time=i, event="switch", row=row) for i, row in switch_df.iterrows()] +wake_rows = [EventRow(time=i, event="wake", row=row) for i, row in wake_df.iterrows()] +rows = switch_rows + wake_rows +rows = sorted(rows, key=lambda r: r.time) +""" + +# Print PID, latency, start, end, sort +result = sorted(latpids.items(), key=lambda x: x[1].latency, reverse=True) + +print "PID".ljust(10) + "\t" + "name".ljust(20) + "\t" + "latency (secs)".ljust(20) + \ + "\t" + "start time".ljust(20) + "\t" + "end time".ljust(20) +for r in result: + l = r[1] # LatRow named tuple + if l.pid != r[0]: + raise RuntimeError("BUG: pid inconsitency found") # Sanity check + print str(r[0]).ljust(10) + "\t" + str(l.wake_row.row['comm']).ljust(20) + "\t" + \ + str(l.latency).ljust(20)[:20] + "\t" + str(l.wake_row.time).ljust(20)[:20] + \ + "\t" + str(l.switch_row.time).ljust(20)[:20] + -- GitLab From a2ac636944ec6c7abeb8a347e257be881cd6e4f6 Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Sun, 23 Apr 2017 03:58:25 -0700 Subject: [PATCH 07/10] update wlat cbs script Signed-off-by: Joel Fernandes --- get_wlat_cbs.py | 164 ++++++++++++++++++++++++------------------------ 1 file changed, 83 insertions(+), 81 deletions(-) diff --git a/get_wlat_cbs.py b/get_wlat_cbs.py index 939501bc6..355195abb 100755 --- a/get_wlat_cbs.py +++ b/get_wlat_cbs.py @@ -3,57 +3,49 @@ from collections import namedtuple import trappy -EventRow = namedtuple('EventRow', ['time', 'event', 'row']) -LatRow = namedtuple('LatRow', ['pid', 'switch_row', 'wake_row', 'last_wake_row', 'running', 'wake_pend', 'latency']) +EventData = namedtuple('EventData', ['time', 'event', 'data']) +LatData = namedtuple('LatData', ['pid', 'switch_data', 'wake_data', 'last_wake_data', 'running', 'wake_pend', 'latency']) -def printsw(time, data): - print str(time) + ": " + str(data) +# path_to_html = "/home/joelaf/repo/catapult/systrace/trace_sf-dispsync_rt_pull_fail_1504ms.html" +path_to_html = "/home/joelaf/Downloads/trace_sf_late_wakeup_ipi.html" -def print_event_rows(rows, start, end): - print "time".ljust(20) + "\t" + "event".ljust(10) + "\tpid" + "\tprevpid" + "\tnextpid" - for r in rows: - if r.time < start or r.time > end: - continue - if r.event == "switch": - nextpid = r.row['next_pid'] - prevpid = r.row['prev_pid'] - pid = -1 - elif r.event == "wake": - pid = r.row['pid'] - nextpid = -1 - prevpid = -1 - else: - raise RuntimeError("unknown event seen") - print str(r.time).ljust(20)[:20] + "\t" + r.event.ljust(10) + "\t" + str(pid) + "\t" + str(prevpid) + "\t" + str(nextpid) - -path_to_html = "/home/joelaf/repo/catapult/systrace/trace_sf-dispsync_rt_pull_fail_1504ms.html" - -# Hash table of pid -> LatRow named tuple +# Hash table of pid -> LatData named tuple latpids = {} + +# Debugging aids for debugging within the callbacks dpid = 21047 debugg = False +normalize = True # Normalize with the base timestamp +printrows = False # Debug aid to print all switch and wake events in a time range + +switch_events = [] +wake_events = [] +basetime = None + def switch_cb(time, data): - row = data event = "switch" + prevpid = data['prev_pid'] + nextpid = data['next_pid'] - prevpid = row['prev_pid'] - nextpid = row['next_pid'] + global basetime, switch_events + basetime = time if (normalize and not basetime) else basetime + time = time - basetime if normalize else time - r = EventRow(time=time, event="switch", row=data) + e = EventData(time, event, data) + if printrows: + switch_events.append(e) debug = debugg and (prevpid == dpid or nextpid == dpid) - - if (debug): - print "\nProcessing switch nextpid=" + str(nextpid) + " prevpid=" + str(prevpid) + \ - " time=" + str(time) + if debug: print ("\nProcessing switch nextpid=" + str(nextpid) + " prevpid=" + str(prevpid) + \ + " time=" + str(time)) # prev pid processing (switch out) if latpids.has_key(prevpid): if latpids[prevpid].running == 1: latpids[prevpid] = latpids[prevpid]._replace(running=0) if latpids[prevpid].wake_pend == 1: - print "Impossible: switch out during wake_pend " + str(r) + print "Impossible: switch out during wake_pend " + str(e) raise RuntimeError("error") if not latpids.has_key(nextpid): @@ -62,85 +54,95 @@ def switch_cb(time, data): # nextpid processing (switch in) pid = nextpid if latpids[pid].running == 1: - print "INFO: previous pid switch-out not seen for an event, ignoring\n" + str(r) + print "INFO: previous pid switch-out not seen for an event, ignoring\n" + str(e) return latpids[pid] = latpids[pid]._replace(running=1) # Ignore latency calc for next-switch events for which wake never seen # They are still valid in this scenario because of preemption if latpids[pid].wake_pend == 0: - if debug: - print "wake_pend = 0, doing nothing" + if debug: print "wake_pend = 0, doing nothing" return - if debug: - print "recording" + if debug: print "recording" # Measure latency - lat = time - latpids[pid].last_wake_row.time + lat = time - latpids[pid].last_wake_data.time if lat > latpids[pid].latency: - latpids[pid] = LatRow(pid, switch_row = r, - wake_row = latpids[pid].last_wake_row, - last_wake_row=None, latency=lat, running=1, wake_pend=0) + latpids[pid] = LatData(pid, switch_data = e, + wake_data = latpids[pid].last_wake_data, + last_wake_data=None, latency=lat, running=1, wake_pend=0) return latpids[pid] = latpids[pid]._replace(running=1, wake_pend=0) def wake_cb(time, data): - row = data event = "wake" - pid = row["pid"] + pid = data["pid"] debug = debugg and (pid == dpid) - r = EventRow(time=time, event="wake", row=data) + global basetime, wake_events + basetime = time if (normalize and not basetime) else basetime + time = time - basetime if normalize else time + + e = EventData(time, event, data) + wake_events.append(e) - if (debug): - print "\nProcessing wake pid=" + str(pid) + " time=" + str(time) + if debug: print "\nProcessing wake pid=" + str(pid) + " time=" + str(time) if not latpids.has_key(pid): - latpids[pid] = LatRow(pid, switch_row=None, wake_row=None, - last_wake_row = r, running=0, latency=-1, wake_pend=1) - if debug: - print "new wakeup" + latpids[pid] = LatData(pid, switch_data=None, wake_data=None, + last_wake_data = e, running=0, latency=-1, wake_pend=1) + if debug: print "new wakeup" return if latpids[pid].running == 1 or latpids[pid].wake_pend == 1: - if debug: - print "already running or wake_pend" - # Task already running or a wakeup->switch pending, ignore + if debug: print "already running or wake_pend" + # Task already running or a wakeup->switch pending, ignore return - if debug: - print "recording wake" - latpids[pid] = latpids[pid]._replace(last_wake_row = r, wake_pend=1) + if debug: print "recording wake" + latpids[pid] = latpids[pid]._replace(last_wake_data = e, wake_pend=1) systrace_obj = trappy.SysTrace(name="systrace", path=path_to_html, \ scope="sched", events=["sched_switch", "sched_wakeup", "sched_waking"], - event_callbacks={ "sched_switch": switch_cb, "sched_wakeup": wake_cb }) + event_callbacks={ "sched_switch": switch_cb, "sched_wakeup": wake_cb, + "sched_waking": wake_cb }, + build_df=False) -""" -df = systrace_obj.sched_switch.data_frame -# df = df[(df.next_prio < 100) | (df.prev_prio < 100)] -switch_df = df - -df = systrace_obj.sched_wakeup.data_frame -# df = df[df.prio < 100] -wake_df = df - -# Build list of rows -switch_rows = [EventRow(time=i, event="switch", row=row) for i, row in switch_df.iterrows()] -wake_rows = [EventRow(time=i, event="wake", row=row) for i, row in wake_df.iterrows()] -rows = switch_rows + wake_rows -rows = sorted(rows, key=lambda r: r.time) -""" - -# Print PID, latency, start, end, sort +# Print the results: PID, latency, start, end, sort result = sorted(latpids.items(), key=lambda x: x[1].latency, reverse=True) - print "PID".ljust(10) + "\t" + "name".ljust(20) + "\t" + "latency (secs)".ljust(20) + \ "\t" + "start time".ljust(20) + "\t" + "end time".ljust(20) -for r in result: - l = r[1] # LatRow named tuple +for r in result[:20]: + l = r[1] # LatData named tuple if l.pid != r[0]: raise RuntimeError("BUG: pid inconsitency found") # Sanity check - print str(r[0]).ljust(10) + "\t" + str(l.wake_row.row['comm']).ljust(20) + "\t" + \ - str(l.latency).ljust(20)[:20] + "\t" + str(l.wake_row.time).ljust(20)[:20] + \ - "\t" + str(l.switch_row.time).ljust(20)[:20] + wake_time = l.wake_data.time + switch_time = l.switch_data.time + + print str(r[0]).ljust(10) + "\t" + str(l.wake_data.data['comm']).ljust(20) + "\t" + \ + str(l.latency).ljust(20)[:20] + "\t" + str(wake_time).ljust(20)[:20] + \ + "\t" + str(switch_time).ljust(20)[:20] + +############################################################# +## Debugging aids to print all events in a given time range # +############################################################# +def print_event_rows(events, start, end): + print "time".ljust(20) + "\t" + "event".ljust(10) + "\tpid" + "\tprevpid" + "\tnextpid" + for e in events: + if e.time < start or e.time > end: + continue + if e.event == "switch": + nextpid = e.data['next_pid'] + prevpid = e.data['prev_pid'] + pid = -1 + elif e.event == "wake": + pid = e.data['pid'] + nextpid = -1 + prevpid = -1 + else: + raise RuntimeError("unknown event seen") + print str(e.time).ljust(20)[:20] + "\t" + e.event.ljust(10) + "\t" + str(pid) + "\t" + str(prevpid) + "\t" + str(nextpid) +if printrows: + rows = switch_events + wake_events + rows = sorted(rows, key=lambda r: r.time) + print_event_rows(rows, 1.1, 1.2) -- GitLab From ffda0e124dffbf550f79c5ade0bcb36288220610 Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Tue, 25 Apr 2017 00:48:25 -0700 Subject: [PATCH 08/10] android: Add support for timeout and optional exit code check to monkey Signed-off-by: Joel Fernandes --- libs/utils/android/system.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/libs/utils/android/system.py b/libs/utils/android/system.py index c26b0dd08..2b66cb84f 100644 --- a/libs/utils/android/system.py +++ b/libs/utils/android/system.py @@ -305,7 +305,7 @@ class System(object): GET_FRAMESTATS_CMD.format(apk_name, out_file)) @staticmethod - def monkey(target, apk_name, event_count=1): + def monkey(target, apk_name, event_count=1, check_exit_code=True, timeout=None): """ Wrapper for adb monkey tool. @@ -328,7 +328,11 @@ class System(object): :param event_count: number of events to generate :type event_count: int """ - target.execute('monkey -p {} {}'.format(apk_name, event_count)) + if timeout: + target.execute('timeout {} monkey -p {} {}'.format(timeout, apk_name, event_count), + check_exit_code=check_exit_code) + return + target.execute('monkey -p {} {}'.format(apk_name, event_count), check_exit_code=check_exit_code) @staticmethod def list_packages(target, apk_filter=''): -- GitLab From ced305c0b628d780f3bd184e1fced9581e59af89 Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Tue, 2 May 2017 10:37:36 -0700 Subject: [PATCH 09/10] updates to normalize Signed-off-by: Joel Fernandes --- get_wlat_cbs.py | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/get_wlat_cbs.py b/get_wlat_cbs.py index 355195abb..2ed649027 100755 --- a/get_wlat_cbs.py +++ b/get_wlat_cbs.py @@ -7,7 +7,8 @@ EventData = namedtuple('EventData', ['time', 'event', 'data']) LatData = namedtuple('LatData', ['pid', 'switch_data', 'wake_data', 'last_wake_data', 'running', 'wake_pend', 'latency']) # path_to_html = "/home/joelaf/repo/catapult/systrace/trace_sf-dispsync_rt_pull_fail_1504ms.html" -path_to_html = "/home/joelaf/Downloads/trace_sf_late_wakeup_ipi.html" +# path_to_html = "/home/joelaf/Downloads/trace_sf_late_wakeup_ipi.html" +path_to_html = "/home/joelaf/repo/lisa/results/ChromeMonkey/trace.html" # Hash table of pid -> LatData named tuple latpids = {} @@ -16,7 +17,7 @@ latpids = {} dpid = 21047 debugg = False -normalize = True # Normalize with the base timestamp +normalize = False # Normalize with the base timestamp printrows = False # Debug aid to print all switch and wake events in a time range switch_events = [] @@ -28,6 +29,8 @@ def switch_cb(time, data): prevpid = data['prev_pid'] nextpid = data['next_pid'] + # print str(time) + ": " + str(data) + global basetime, switch_events basetime = time if (normalize and not basetime) else basetime time = time - basetime if normalize else time @@ -86,6 +89,9 @@ def wake_cb(time, data): e = EventData(time, event, data) wake_events.append(e) + if data["prio"] > 99: + return + if debug: print "\nProcessing wake pid=" + str(pid) + " time=" + str(time) if not latpids.has_key(pid): latpids[pid] = LatData(pid, switch_data=None, wake_data=None, @@ -105,7 +111,7 @@ systrace_obj = trappy.SysTrace(name="systrace", path=path_to_html, \ scope="sched", events=["sched_switch", "sched_wakeup", "sched_waking"], event_callbacks={ "sched_switch": switch_cb, "sched_wakeup": wake_cb, "sched_waking": wake_cb }, - build_df=False) + build_df=False, normalize_time=False) # Print the results: PID, latency, start, end, sort result = sorted(latpids.items(), key=lambda x: x[1].latency, reverse=True) -- GitLab From 8e0e6e7e7829fddc3b5f4a0bf66db84102205a4c Mon Sep 17 00:00:00 2001 From: Joel Fernandes Date: Tue, 2 May 2017 10:41:17 -0700 Subject: [PATCH 10/10] hack in monsoon support Signed-off-by: Joel Fernandes --- libs/utils/android/system.py | 5 +- libs/utils/android/workload.py | 9 ++- libs/utils/android/workloads/chromemonkey.py | 67 ++++++++++++++++++++ 3 files changed, 78 insertions(+), 3 deletions(-) create mode 100644 libs/utils/android/workloads/chromemonkey.py diff --git a/libs/utils/android/system.py b/libs/utils/android/system.py index 2b66cb84f..b9f7423d8 100644 --- a/libs/utils/android/system.py +++ b/libs/utils/android/system.py @@ -31,7 +31,7 @@ class System(object): @staticmethod def systrace_start(target, trace_file, time=None, - events=['gfx', 'view', 'sched', 'freq', 'idle']): + events=['irq', 'sched'], bufsize=None): log = logging.getLogger('System') @@ -53,6 +53,9 @@ class System(object): if time is not None: trace_cmd += " -t {}".format(time) + if bufsize is not None: + trace_cmd += " -b {}".format(bufsize) + log.info('SysTrace: %s', trace_cmd) # Actually spawn systrace diff --git a/libs/utils/android/workload.py b/libs/utils/android/workload.py index 626b65d50..36caceae5 100644 --- a/libs/utils/android/workload.py +++ b/libs/utils/android/workload.py @@ -87,7 +87,7 @@ class Workload(object): **kwargs): raise RuntimeError('Not implemeted') - def tracingStart(self): + def tracingStart(self, bufsize=None): if 'ftrace' in self.collect and 'systrace' in self.collect: msg = 'ftrace and systrace cannot be used at the same time' raise ValueError(msg) @@ -104,7 +104,12 @@ class Workload(object): self._trace_time = match.group(1) if match else None self._log.info('Systrace START') self._systrace_output = System.systrace_start( - self._te, self.trace_file, self._trace_time) + self._te, self.trace_file, self._trace_time, bufsize=bufsize) + elif 'monsoon' in self.collect: + self._target.execute('svc power stayon usb') + self._target.execute('echo 0 > /sys/class/power_supply/battery/charging_enabled') + monsout = os.path.join(self.out_dir, 'monsoon.txt') + os.system("~/repo/monsoon/monsoon.par --timestamp --hz 5 --samples 300 > " + monsout) # Initialize energy meter results if 'energy' in self.collect and self._te.emeter: self._te.emeter.reset() diff --git a/libs/utils/android/workloads/chromemonkey.py b/libs/utils/android/workloads/chromemonkey.py new file mode 100644 index 000000000..349b0efec --- /dev/null +++ b/libs/utils/android/workloads/chromemonkey.py @@ -0,0 +1,67 @@ +# SPDX-License-Identifier: Apache-2.0 +# +# Copyright (C) 2015, ARM Limited and contributors. +# +# 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. +# + +import re +import os +import logging + +from android import Screen, System, Workload + +class ChromeMonkey(Workload): + """ + Android Chrome monkey tests workload + """ + + # Package required by this workload + package = 'com.android.chrome' + + def __init__(self, test_env): + super(ChromeMonkey, self).__init__(test_env) + self._log = logging.getLogger('ChromeMonkey') + self._log.debug('Workload created') + + def run(self, out_dir, duration_s, collect='', bufsize=10000): + """ + Run Chrome with random events from monkey. Useful to diagnose/trace + UI related issues. + + :param out_dir: Path to experiment directory where to store results. + :type out_dir: str + + :param collect: Specifies what to collect. Possible values: + - 'sched' + - 'systrace' + - 'ftrace' + - any combination of the above + :type collect: list(str) + """ + + # Keep track of mandatory parameters + self.out_dir = out_dir + self.collect = collect + + # Unlock device screen (assume no password required) + Screen.unlock(self._target) + + self.tracingStart(bufsize) + + # Use the monkey tool + self._log.info('Running monkey for %d [s]', duration_s) + System.monkey(self._target, self.package, event_count=100000, timeout=duration_s, + check_exit_code=False) + + self.tracingStop() -- GitLab