From bda7a16656809e95cdba13560018ea2cb95d10f9 Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Tue, 26 Jan 2016 14:59:53 +0000 Subject: [PATCH 1/4] ftrace: move file path definitions All ftrace generated files are present under a common base folder. This patch updates the FtraceCollector API to exposes just the common base folder from where all the other paths can be generated. This is a refactoring patch which makes it easier to add further attributes. Signed-off-by: Patrick Bellasi --- devlib/trace/ftrace.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/devlib/trace/ftrace.py b/devlib/trace/ftrace.py index 2973e0b..4851382 100644 --- a/devlib/trace/ftrace.py +++ b/devlib/trace/ftrace.py @@ -47,8 +47,7 @@ class FtraceCollector(TraceCollector): events=None, buffer_size=None, buffer_size_step=1000, - buffer_size_file='/sys/kernel/debug/tracing/buffer_size_kb', - marker_file='/sys/kernel/debug/tracing/trace_marker', + tracing_path='/sys/kernel/debug/tracing', automark=True, autoreport=True, autoview=False, @@ -58,8 +57,7 @@ class FtraceCollector(TraceCollector): self.events = events if events is not None else DEFAULT_EVENTS self.buffer_size = buffer_size self.buffer_size_step = buffer_size_step - self.buffer_size_file = buffer_size_file - self.marker_file = marker_file + self.tracing_path = tracing_path self.automark = automark self.autoreport = autoreport self.autoview = autoview @@ -71,6 +69,10 @@ class FtraceCollector(TraceCollector): self.event_string = _build_trace_events(self.events) self._reset_needed = True + # Setup tracing paths + self.buffer_size_file = self.target.path.join(self.tracing_path, 'buffer_size_kb') + self.marker_file = self.target.path.join(self.tracing_path, 'trace_marker') + self.host_binary = which('trace-cmd') self.kernelshark = which('kernelshark') From c5bc987226b3089ac1ea8c45c64b3b5ff1f76695 Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Tue, 26 Jan 2016 15:05:58 +0000 Subject: [PATCH 2/4] ftrace: add initial support for function profiling FTrace allows to collect profiling stats for kernel functions. This patch adds the initial support which allows to specify a list of kernel function we would like to profile. If a list of functions to profile is specified, for each specified function we check for that function to be actually one of the available instrumented functions which can be monitored by FTrace. If a function is not supported, we throw an expection so that the user is aware about the analysis which is going to do. Signed-off-by: Patrick Bellasi --- devlib/trace/ftrace.py | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/devlib/trace/ftrace.py b/devlib/trace/ftrace.py index 4851382..9cd428c 100644 --- a/devlib/trace/ftrace.py +++ b/devlib/trace/ftrace.py @@ -45,6 +45,7 @@ class FtraceCollector(TraceCollector): def __init__(self, target, events=None, + functions=None, buffer_size=None, buffer_size_step=1000, tracing_path='/sys/kernel/debug/tracing', @@ -55,6 +56,7 @@ class FtraceCollector(TraceCollector): ): super(FtraceCollector, self).__init__(target) self.events = events if events is not None else DEFAULT_EVENTS + self.functions = functions self.buffer_size = buffer_size self.buffer_size_step = buffer_size_step self.tracing_path = tracing_path @@ -67,10 +69,13 @@ class FtraceCollector(TraceCollector): self.start_time = None self.stop_time = None self.event_string = _build_trace_events(self.events) + self.function_string = _build_trace_functions(self.functions) self._reset_needed = True # Setup tracing paths + self.available_functions_file = self.target.path.join(self.tracing_path, 'available_filter_functions') self.buffer_size_file = self.target.path.join(self.tracing_path, 'buffer_size_kb') + self.function_profile_file = self.target.path.join(self.tracing_path, 'function_profile_enabled') self.marker_file = self.target.path.join(self.tracing_path, 'trace_marker') self.host_binary = which('trace-cmd') @@ -90,6 +95,18 @@ class FtraceCollector(TraceCollector): raise TargetError('No trace-cmd found on device and no_install=True is specified.') self.target_binary = 'trace-cmd' + # Check for function tracing support + if self.functions: + if not self.target.file_exists(self.function_profile_file): + raise TargetError('Function profiling not supported. '\ + 'A kernel build with CONFIG_FUNCTION_PROFILER enable is required') + # Validate required functions to be traced + available_functions = self.target.execute( + 'cat {}'.format(self.available_functions_file)).splitlines() + for function in self.functions: + if function not in available_functions: + raise TargetError('Function [{}] not available for filtering'.format(function)) + def reset(self): if self.buffer_size: self._set_buffer_size() @@ -205,3 +222,6 @@ def _build_trace_events(events): event_string = ' '.join(['-e {}'.format(e) for e in events]) return event_string +def _build_trace_functions(functions): + function_string = " ".join(functions) + return function_string From 7f5a150b4f691d8d2972f24c16c911bc4f66727a Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Tue, 26 Jan 2016 15:33:21 +0000 Subject: [PATCH 3/4] ftrace: add support to collect function stats Function stats can be collected while events are accumulated into a trace. This function adds the required support to start and stop functions profiling across a trace collection. Signed-off-by: Patrick Bellasi --- devlib/trace/ftrace.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/devlib/trace/ftrace.py b/devlib/trace/ftrace.py index 9cd428c..c521b00 100644 --- a/devlib/trace/ftrace.py +++ b/devlib/trace/ftrace.py @@ -75,8 +75,10 @@ class FtraceCollector(TraceCollector): # Setup tracing paths self.available_functions_file = self.target.path.join(self.tracing_path, 'available_filter_functions') self.buffer_size_file = self.target.path.join(self.tracing_path, 'buffer_size_kb') + self.current_tracer_file = self.target.path.join(self.tracing_path, 'current_tracer') self.function_profile_file = self.target.path.join(self.tracing_path, 'function_profile_enabled') self.marker_file = self.target.path.join(self.tracing_path, 'trace_marker') + self.ftrace_filter_file = self.target.path.join(self.tracing_path, 'set_ftrace_filter') self.host_binary = which('trace-cmd') self.kernelshark = which('kernelshark') @@ -123,8 +125,17 @@ class FtraceCollector(TraceCollector): if 'cpufreq' in self.target.modules: self.logger.debug('Trace CPUFreq frequencies') self.target.cpufreq.trace_frequencies() + # Enable kernel function profiling + if self.functions: + self.target.execute('echo nop > {}'.format(self.current_tracer_file)) + self.target.execute('echo 0 > {}'.format(self.function_profile_file)) + self.target.execute('echo {} > {}'.format(self.function_string, self.ftrace_filter_file)) + self.target.execute('echo 1 > {}'.format(self.function_profile_file)) def stop(self): + # Disable kernel function profiling + if self.functions: + self.target.execute('echo 1 > {}'.format(self.function_profile_file)) if 'cpufreq' in self.target.modules: self.logger.debug('Trace CPUFreq frequencies') self.target.cpufreq.trace_frequencies() From 082a82c7c51b5cf43b7816fca729f20a5b2f27b2 Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Tue, 26 Jan 2016 15:38:44 +0000 Subject: [PATCH 4/4] ftrace: add support to report function profiling data Functions profiling data are reported in a set of files, one for each CPU. This patch adds the required support to collect these data into a single JSON formatted file. Data are collected using a shutils routing on the target side and formatted in JSON on the host side. Signed-off-by: Patrick Bellasi --- devlib/bin/scripts/shutils.in | 15 ++++++++++++ devlib/trace/ftrace.py | 44 +++++++++++++++++++++++++++++++++++ 2 files changed, 59 insertions(+) diff --git a/devlib/bin/scripts/shutils.in b/devlib/bin/scripts/shutils.in index 0023a5e..9200b70 100755 --- a/devlib/bin/scripts/shutils.in +++ b/devlib/bin/scripts/shutils.in @@ -43,6 +43,18 @@ cpufreq_trace_all_frequencies() { done } +################################################################################ +# FTrace Utility Functions +################################################################################ + +ftrace_get_function_stats() { + for CPU in $(ls /sys/kernel/debug/tracing/trace_stat | sed 's/function//'); do + REPLACE_STRING="s/ Function/\n Function (CPU$CPU)/" + cat /sys/kernel/debug/tracing/trace_stat/function$CPU \ + | sed "$REPLACE_STRING" + done +} + ################################################################################ # Main Function Dispatcher ################################################################################ @@ -63,6 +75,9 @@ cpufreq_get_all_governors) cpufreq_trace_all_frequencies) cpufreq_trace_all_frequencies $* ;; +ftrace_get_function_stats) + ftrace_get_function_stats + ;; *) echo "Command [$CMD] not supported" exit -1 diff --git a/devlib/trace/ftrace.py b/devlib/trace/ftrace.py index c521b00..a177efc 100644 --- a/devlib/trace/ftrace.py +++ b/devlib/trace/ftrace.py @@ -15,7 +15,9 @@ from __future__ import division import os +import json import time +import re import subprocess from devlib.trace import TraceCollector @@ -27,6 +29,7 @@ from devlib.utils.misc import check_output, which TRACE_MARKER_START = 'TRACE_MARKER_START' TRACE_MARKER_STOP = 'TRACE_MARKER_STOP' OUTPUT_TRACE_FILE = 'trace.dat' +OUTPUT_PROFILE_FILE = 'trace_stat.dat' DEFAULT_EVENTS = [ 'cpu_frequency', 'cpu_idle', @@ -40,6 +43,9 @@ DEFAULT_EVENTS = [ ] TIMEOUT = 180 +# Regexps for parsing of function profiling data +CPU_RE = re.compile(r' Function \(CPU([0-9]+)\)') +STATS_RE = re.compile(r'([^ ]*) +([0-9]+) +([0-9.]+) us +([0-9.]+) us +([0-9.]+) us') class FtraceCollector(TraceCollector): @@ -165,6 +171,44 @@ class FtraceCollector(TraceCollector): if self.autoview: self.view(outfile) + def get_stats(self, outfile): + if not self.functions: + return + + if os.path.isdir(outfile): + outfile = os.path.join(outfile, OUTPUT_PROFILE_FILE) + output = self.target._execute_util('ftrace_get_function_stats', + as_root=True) + + function_stats = {} + for line in output.splitlines(): + # Match a new CPU dataset + match = CPU_RE.search(line) + if match: + cpu_id = int(match.group(1)) + function_stats[cpu_id] = {} + self.logger.debug("Processing stats for CPU%d...", cpu_id) + continue + # Match a new function dataset + match = STATS_RE.search(line) + if match: + fname = match.group(1) + function_stats[cpu_id][fname] = { + 'hits' : int(match.group(2)), + 'time' : float(match.group(3)), + 'avg' : float(match.group(4)), + 's_2' : float(match.group(5)), + } + self.logger.debug(" %s: %s", + fname, function_stats[cpu_id][fname]) + + self.logger.debug("FTrace stats output [%s]...", outfile) + with open(outfile, 'w') as fh: + json.dump(function_stats, fh, indent=4) + self.logger.info("FTrace function stats save in [%s]", outfile) + + return function_stats + def report(self, binfile, destfile): # To get the output of trace.dat, trace-cmd must be installed # This is done host-side because the generated file is very large