From 6b8006f03622735034ca269dacff867c616bca55 Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Wed, 26 Apr 2017 09:57:54 +0100 Subject: [PATCH 1/3] ftarce: allow subclasses to reformat data_str before parsing Some run-times (e.g. Android) inject interesting events from user-space which unfortunately are not formatted using the `key=value` pairs required by TRAPpy. The format string they use is expected by other tools, e.g. systrace. Since TRAPpy learnt to parse systrace events, let's prepare the ground for him to improve its skills. This adds a simple call-back based mechanism which allows a parser to reformat a data string into a TRAPpy compliant format before processing it the usual way. Signed-off-by: Patrick Bellasi --- trappy/ftrace.py | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/trappy/ftrace.py b/trappy/ftrace.py index 6a5fce0a..89d485e2 100644 --- a/trappy/ftrace.py +++ b/trappy/ftrace.py @@ -156,6 +156,11 @@ class definitions list. Otherwise, register a class to parse trace_class = DynamicTypeFactory(event_name, (Base,), kwords) self.class_definitions[event_name] = trace_class + def format_data(self, unique_word, data_str): + """Reformat data before parsing + """ + return data_str + def __populate_data(self, fin, cls_for_unique_word, window, abs_window): """Append to trace data from a txt trace""" @@ -202,12 +207,16 @@ def contains_unique_word(line, unique_words=cls_for_unique_word.keys()): (abs_window[1] and timestamp > abs_window[1]): return + # Allow the trace class to reformat data + data_str = line[line.find(unique_word) + len(unique_word):] + data_str = self.format_data(unique_word, data_str) + try: - data_start_idx = start_match.search(line).start() + data_start_idx = start_match.search(data_str).start() except AttributeError: continue - data_str = line[data_start_idx:] + data_str = data_str[data_start_idx:] # Remove empty arrays from the trace data_str = re.sub(r"[A-Za-z0-9_]+=\{\} ", r"", data_str) From eea51f435dd27cb38cfd3cdd3e18c1787c9ffe5a Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Wed, 26 Apr 2017 11:35:32 +0100 Subject: [PATCH 2/3] systrace: teach systrace to parse Android profiling events Android injects function profiling envets from using tracing_mark strings which are not formatted according to the `key=value` pari expected by TRAPpy. Let's use our `formad_data` callback to give the a proper shape. Signed-off-by: Patrick Bellasi --- trappy/systrace.py | 27 +++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/trappy/systrace.py b/trappy/systrace.py index 6e917a65..880107ce 100644 --- a/trappy/systrace.py +++ b/trappy/systrace.py @@ -13,7 +13,10 @@ # limitations under the License. # +import re + from trappy.ftrace import GenericFTrace +from trappy.utils import listify class drop_before_trace(object): """Object that, when called, returns True if the line is not part of @@ -54,6 +57,13 @@ def __init__(self, path=".", name="", normalize_time=True, scope="all", self.trace_path = path + # Android injects useful events from userspace, unfortunately not using + # a specific attention word. Thus, let's capture tracing_mark events + # and reformat them in a local format_data callback. + events = listify(events) + if 'tracing_mark_write' not in events: + events.append('tracing_mark_write') + super(SysTrace, self).__init__(name, normalize_time, scope, events, window, abs_window) @@ -75,3 +85,20 @@ def trace_hasnt_finished(self): """ return lambda x: not x.endswith("\n") + + def format_data(self, unique_word, data_str): + if unique_word != 'tracing_mark_write:': + return data_str + + match = SYSTRACE_EVENT.match(data_str) + if match: + data_str = "event={} pid={} func={} data={}".format( + match.group('event'), match.group('pid'), + match.group('func'), match.group('data')) + return data_str + + raise ValueError('Unexpected systrace marker: {}'.format(data_str)) + return data_str + +SYSTRACE_EVENT = re.compile( + r'^ (?P[A-Z])(\|(?P\d+)\|(?P.*)(\|(?P\d+))?)?') From 7b0d5a6c764ee9ace256cdb6e45a3583eb049274 Mon Sep 17 00:00:00 2001 From: Patrick Bellasi Date: Wed, 26 Apr 2017 11:37:22 +0100 Subject: [PATCH 3/3] systrace: discard not useful clock synchronization events This event is not really useful and, so far, it's the only one properly formatted using `key=value` pairs. Let's ignore it while we find a better way to synchronize TRAPpy and Systrace viewer times. Signed-off-by: Patrick Bellasi --- tests/test_systrace.py | 4 ---- trappy/systrace.py | 4 ++++ 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/tests/test_systrace.py b/tests/test_systrace.py index 608ed8ec..55480813 100644 --- a/tests/test_systrace.py +++ b/tests/test_systrace.py @@ -39,10 +39,6 @@ def test_systrace_html(self): self.assertEquals(len(trace.sched_wakeup.data_frame), 4) self.assertTrue("target_cpu" in trace.sched_wakeup.data_frame.columns) - self.assertTrue(hasattr(trace, "trace_event_clock_sync")) - self.assertEquals(len(trace.trace_event_clock_sync.data_frame), 1) - self.assertTrue("realtime_ts" in trace.trace_event_clock_sync.data_frame.columns) - def test_cpu_counting(self): """SysTrace traces know the number of cpus""" diff --git a/trappy/systrace.py b/trappy/systrace.py index 880107ce..bf0f5499 100644 --- a/trappy/systrace.py +++ b/trappy/systrace.py @@ -90,6 +90,10 @@ def format_data(self, unique_word, data_str): if unique_word != 'tracing_mark_write:': return data_str + # Disacrd not useful clock synchronization events + if 'trace_event_clock_sync' in data_str: + return '' + match = SYSTRACE_EVENT.match(data_str) if match: data_str = "event={} pid={} func={} data={}".format(