mirror of
https://github.com/ARM-software/workload-automation.git
synced 2024-10-06 19:01:15 +01:00
497b5febc3
The default value for buffer_size_file contained a path under "/d/", which is an Android-specific alias for "/sys/kernel/debug". This commit updates the default value to use the system-agnostic path.
323 lines
16 KiB
Python
323 lines
16 KiB
Python
# Copyright 2013-2015 ARM Limited
|
|
#
|
|
# 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.
|
|
#
|
|
|
|
|
|
# pylint: disable=W0613,E1101
|
|
from __future__ import division
|
|
import os
|
|
import time
|
|
import subprocess
|
|
from collections import defaultdict
|
|
|
|
from wlauto import Instrument, Parameter, Executable
|
|
from wlauto.exceptions import InstrumentError, ConfigError
|
|
from wlauto.core import signal
|
|
from wlauto.utils.types import boolean
|
|
|
|
OUTPUT_TRACE_FILE = 'trace.dat'
|
|
OUTPUT_TEXT_FILE = '{}.txt'.format(os.path.splitext(OUTPUT_TRACE_FILE)[0])
|
|
TIMEOUT = 180
|
|
|
|
|
|
class TraceCmdInstrument(Instrument):
|
|
|
|
name = 'trace-cmd'
|
|
description = """
|
|
trace-cmd is an instrument which interacts with Ftrace Linux kernel internal
|
|
tracer
|
|
|
|
From trace-cmd man page:
|
|
|
|
trace-cmd command interacts with the Ftrace tracer that is built inside the
|
|
Linux kernel. It interfaces with the Ftrace specific files found in the
|
|
debugfs file system under the tracing directory.
|
|
|
|
trace-cmd reads a list of events it will trace, which can be specified in
|
|
the config file as follows ::
|
|
|
|
trace_events = ['irq*', 'power*']
|
|
|
|
If no event is specified in the config file, trace-cmd traces the following events:
|
|
|
|
- sched*
|
|
- irq*
|
|
- power*
|
|
- cpufreq_interactive*
|
|
|
|
The list of available events can be obtained by rooting and running the following
|
|
command line on the device ::
|
|
|
|
trace-cmd list
|
|
|
|
You may also specify ``trace_buffer_size`` setting which must be an integer that will
|
|
be used to set the ftrace buffer size. It will be interpreted as KB::
|
|
|
|
trace_cmd_buffer_size = 8000
|
|
|
|
The maximum buffer size varies from device to device, but there is a maximum and trying
|
|
to set buffer size beyound that will fail. If you plan on collecting a lot of trace over
|
|
long periods of time, the buffer size will not be enough and you will only get trace for
|
|
the last portion of your run. To deal with this you can set the ``trace_mode`` setting to
|
|
``'record'`` (the default is ``'start'``)::
|
|
|
|
trace_cmd_mode = 'record'
|
|
|
|
This will cause trace-cmd to trace into file(s) on disk, rather than the buffer, and so the
|
|
limit for the max size of the trace is set by the storage available on device. Bear in mind
|
|
that ``'record'`` mode *is* more instrusive than the default, so if you do not plan on
|
|
generating a lot of trace, it is best to use the default ``'start'`` mode.
|
|
|
|
.. note:: Mode names correspend to the underlying trace-cmd exectuable's command used to
|
|
implement them. You can find out more about what is happening in each case from
|
|
trace-cmd documentation: https://lwn.net/Articles/341902/.
|
|
|
|
This instrument comes with an Android trace-cmd binary that will be copied and used on the
|
|
device, however post-processing will be done on-host and you must have trace-cmd installed and
|
|
in your path. On Ubuntu systems, this may be done with::
|
|
|
|
sudo apt-get install trace-cmd
|
|
|
|
"""
|
|
|
|
parameters = [
|
|
Parameter('events', kind=list, default=['sched*', 'irq*', 'power*', 'cpufreq_interactive*'],
|
|
global_alias='trace_events',
|
|
description="""
|
|
Specifies the list of events to be traced. Each event in the list will be passed to
|
|
trace-cmd with -e parameter and must be in the format accepted by trace-cmd.
|
|
"""),
|
|
Parameter('mode', default='start', allowed_values=['start', 'record'],
|
|
global_alias='trace_mode',
|
|
description="""
|
|
Trace can be collected using either 'start' or 'record' trace-cmd
|
|
commands. In 'start' mode, trace will be collected into the ftrace buffer;
|
|
in 'record' mode, trace will be written into a file on the device's file
|
|
system. 'start' mode is (in theory) less intrusive than 'record' mode, however
|
|
it is limited by the size of the ftrace buffer (which is configurable --
|
|
see ``buffer_size`` -- but only up to a point) and that may overflow
|
|
for long-running workloads, which will result in dropped events.
|
|
"""),
|
|
Parameter('buffer_size', kind=int, default=None,
|
|
global_alias='trace_buffer_size',
|
|
description="""
|
|
Attempt to set ftrace buffer size to the specified value (in KB). Default buffer size
|
|
may need to be increased for long-running workloads, or if a large number
|
|
of events have been enabled. Note: there is a maximum size that the buffer can
|
|
be set, and that varies from device to device. Attempting to set buffer size higher
|
|
than this will fail. In that case, this instrument will set the size to the highest
|
|
possible value by going down from the specified size in ``buffer_size_step`` intervals.
|
|
"""),
|
|
Parameter('buffer_size_step', kind=int, default=1000,
|
|
global_alias='trace_buffer_size_step',
|
|
description="""
|
|
Defines the decremental step used if the specified ``buffer_size`` could not be set.
|
|
This will be subtracted form the buffer size until set succeeds or size is reduced to
|
|
1MB.
|
|
"""),
|
|
Parameter('buffer_size_file', default='/sys/kernel/debug/tracing/buffer_size_kb',
|
|
description="""
|
|
Path to the debugs file that may be used to set ftrace buffer size. This should need
|
|
to be modified for the vast majority devices.
|
|
"""),
|
|
Parameter('report', kind=boolean, default=True,
|
|
description="""
|
|
Specifies whether host-side reporting should be performed once the binary trace has been
|
|
pulled form the device.
|
|
|
|
.. note:: This requires the latest version of trace-cmd to be installed on the host (the
|
|
one in your distribution's repos may be too old).
|
|
|
|
"""),
|
|
Parameter('no_install', kind=boolean, default=False,
|
|
description="""
|
|
Do not install the bundled trace-cmd and use the one on the device instead. If there is
|
|
not already a trace-cmd on the device, an error is raised.
|
|
|
|
"""),
|
|
]
|
|
|
|
def __init__(self, device, **kwargs):
|
|
super(TraceCmdInstrument, self).__init__(device, **kwargs)
|
|
self.trace_cmd = None
|
|
self.event_string = _build_trace_events(self.events)
|
|
self.output_file = os.path.join(self.device.working_directory, OUTPUT_TRACE_FILE)
|
|
self.temp_trace_file = self.device.path.join(self.device.working_directory, OUTPUT_TRACE_FILE)
|
|
|
|
def on_run_init(self, context):
|
|
if not self.device.is_rooted:
|
|
raise InstrumentError('trace-cmd instrument cannot be used on an unrooted device.')
|
|
if not self.no_install:
|
|
host_file = context.resolver.get(Executable(self, self.device.abi, 'trace-cmd'))
|
|
self.trace_cmd = self.device.install_executable(host_file)
|
|
else:
|
|
if not self.device.is_installed('trace-cmd'):
|
|
raise ConfigError('No trace-cmd found on device and no_install=True is specified.')
|
|
self.trace_cmd = 'trace-cmd'
|
|
# Register ourselves as absolute last event before and
|
|
# first after so we can mark the trace at the right time
|
|
signal.connect(self.insert_start_mark, signal.BEFORE_WORKLOAD_EXECUTION, priority=11)
|
|
signal.connect(self.insert_end_mark, signal.AFTER_WORKLOAD_EXECUTION, priority=11)
|
|
|
|
def setup(self, context):
|
|
if self.mode == 'start':
|
|
if self.buffer_size:
|
|
self._set_buffer_size()
|
|
self.device.execute('{} reset'.format(self.trace_cmd), as_root=True, timeout=180)
|
|
elif self.mode == 'record':
|
|
pass
|
|
else:
|
|
raise ValueError('Bad mode: {}'.format(self.mode)) # should never get here
|
|
|
|
def start(self, context):
|
|
self.start_time = time.time() # pylint: disable=attribute-defined-outside-init
|
|
if self.mode == 'start':
|
|
self.device.execute('{} start {}'.format(self.trace_cmd, self.event_string), as_root=True)
|
|
elif self.mode == 'record':
|
|
self.device.kick_off('{} record -o {} {}'.format(self.trace_cmd, self.output_file, self.event_string))
|
|
else:
|
|
raise ValueError('Bad mode: {}'.format(self.mode)) # should never get here
|
|
|
|
def stop(self, context):
|
|
self.stop_time = time.time() # pylint: disable=attribute-defined-outside-init
|
|
if self.mode == 'start':
|
|
self.device.execute('{} stop'.format(self.trace_cmd), timeout=60, as_root=True)
|
|
elif self.mode == 'record':
|
|
# There will be a trace-cmd worker process per CPU core plus a main
|
|
# control trace-cmd process. Interrupting the control process will
|
|
# trigger the generation of the single binary trace file.
|
|
trace_cmds = self.device.ps(name=self.trace_cmd)
|
|
if not trace_cmds:
|
|
raise InstrumentError('Could not find running trace-cmd on device.')
|
|
# The workers will have their PPID set to the PID of control.
|
|
parent_map = defaultdict(list)
|
|
for entry in trace_cmds:
|
|
parent_map[entry.ppid].append(entry.pid)
|
|
controls = [v[0] for _, v in parent_map.iteritems()
|
|
if len(v) == 1 and v[0] in parent_map]
|
|
if len(controls) > 1:
|
|
self.logger.warning('More than one trace-cmd instance found; stopping all of them.')
|
|
for c in controls:
|
|
self.device.kill(c, signal='INT', as_root=True)
|
|
else:
|
|
raise ValueError('Bad mode: {}'.format(self.mode)) # should never get here
|
|
|
|
def update_result(self, context): # NOQA pylint: disable=R0912
|
|
if self.mode == 'start':
|
|
self.device.execute('{} extract -o {}'.format(self.trace_cmd, self.output_file),
|
|
timeout=TIMEOUT, as_root=True)
|
|
elif self.mode == 'record':
|
|
self.logger.debug('Waiting for trace.dat to be generated.')
|
|
while self.device.ps(name=self.trace_cmd):
|
|
time.sleep(2)
|
|
else:
|
|
raise ValueError('Bad mode: {}'.format(self.mode)) # should never get here
|
|
|
|
# The size of trace.dat will depend on how long trace-cmd was running.
|
|
# Therefore timout for the pull command must also be adjusted
|
|
# accordingly.
|
|
pull_timeout = (self.stop_time - self.start_time)
|
|
self.device.pull_file(self.output_file, context.output_directory, timeout=pull_timeout)
|
|
context.add_iteration_artifact('bintrace', OUTPUT_TRACE_FILE, kind='data',
|
|
description='trace-cmd generated ftrace dump.')
|
|
|
|
local_trace_file = os.path.join(context.output_directory, OUTPUT_TRACE_FILE)
|
|
local_txt_trace_file = os.path.join(context.output_directory, OUTPUT_TEXT_FILE)
|
|
|
|
if self.report:
|
|
# To get the output of trace.dat, trace-cmd must be installed
|
|
# This is done host-side because the generated file is very large
|
|
if not os.path.isfile(local_trace_file):
|
|
self.logger.warning('Not generating trace.txt, as trace.bin does not exist.')
|
|
try:
|
|
command = 'trace-cmd report {} > {}'.format(local_trace_file, local_txt_trace_file)
|
|
self.logger.debug(command)
|
|
process = subprocess.Popen(command, stderr=subprocess.PIPE, shell=True)
|
|
_, error = process.communicate()
|
|
if process.returncode:
|
|
raise InstrumentError('trace-cmd returned non-zero exit code {}'.format(process.returncode))
|
|
if error:
|
|
# logged at debug level, as trace-cmd always outputs some
|
|
# errors that seem benign.
|
|
self.logger.debug(error)
|
|
if os.path.isfile(local_txt_trace_file):
|
|
context.add_iteration_artifact('txttrace', OUTPUT_TEXT_FILE, kind='export',
|
|
description='trace-cmd generated ftrace dump.')
|
|
self.logger.debug('Verifying traces.')
|
|
with open(local_txt_trace_file) as fh:
|
|
for line in fh:
|
|
if 'EVENTS DROPPED' in line:
|
|
self.logger.warning('Dropped events detected.')
|
|
break
|
|
else:
|
|
self.logger.debug('Trace verified.')
|
|
else:
|
|
self.logger.warning('Could not generate trace.txt.')
|
|
except OSError:
|
|
raise InstrumentError('Could not find trace-cmd. Please make sure it is installed and is in PATH.')
|
|
|
|
def teardown(self, context):
|
|
self.device.delete_file(os.path.join(self.device.working_directory, OUTPUT_TRACE_FILE))
|
|
|
|
def on_run_end(self, context):
|
|
pass
|
|
|
|
def validate(self):
|
|
if self.report and os.system('which trace-cmd > /dev/null'):
|
|
raise InstrumentError('trace-cmd is not in PATH; is it installed?')
|
|
if self.buffer_size:
|
|
if self.mode == 'record':
|
|
self.logger.debug('trace_buffer_size specified with record mode; it will be ignored.')
|
|
else:
|
|
try:
|
|
int(self.buffer_size)
|
|
except ValueError:
|
|
raise ConfigError('trace_buffer_size must be an int.')
|
|
|
|
def insert_start_mark(self, context):
|
|
# trace marker appears in ftrace as an ftrace/print event with TRACE_MARKER_START in info field
|
|
self.device.set_sysfile_value("/sys/kernel/debug/tracing/trace_marker", "TRACE_MARKER_START", verify=False)
|
|
|
|
def insert_end_mark(self, context):
|
|
# trace marker appears in ftrace as an ftrace/print event with TRACE_MARKER_STOP in info field
|
|
self.device.set_sysfile_value("/sys/kernel/debug/tracing/trace_marker", "TRACE_MARKER_STOP", verify=False)
|
|
|
|
def _set_buffer_size(self):
|
|
target_buffer_size = self.buffer_size
|
|
attempt_buffer_size = target_buffer_size
|
|
buffer_size = 0
|
|
floor = 1000 if target_buffer_size > 1000 else target_buffer_size
|
|
while attempt_buffer_size >= floor:
|
|
self.device.set_sysfile_value(self.buffer_size_file, attempt_buffer_size, verify=False)
|
|
buffer_size = self.device.get_sysfile_value(self.buffer_size_file, kind=int)
|
|
if buffer_size == attempt_buffer_size:
|
|
break
|
|
else:
|
|
attempt_buffer_size -= self.buffer_size_step
|
|
if buffer_size == target_buffer_size:
|
|
return
|
|
while attempt_buffer_size < target_buffer_size:
|
|
attempt_buffer_size += self.buffer_size_step
|
|
self.device.set_sysfile_value(self.buffer_size_file, attempt_buffer_size, verify=False)
|
|
buffer_size = self.device.get_sysfile_value(self.buffer_size_file, kind=int)
|
|
if attempt_buffer_size != buffer_size:
|
|
self.logger.warning('Failed to set trace buffer size to {}, value set was {}'.format(target_buffer_size, buffer_size))
|
|
break
|
|
|
|
|
|
def _build_trace_events(events):
|
|
event_string = ' '.join(['-e {}'.format(e) for e in events])
|
|
return event_string
|
|
|