diff --git a/tests/test_systrace.py b/tests/test_systrace.py index 608ed8ec..04424589 100644 --- a/tests/test_systrace.py +++ b/tests/test_systrace.py @@ -21,7 +21,8 @@ class TestSystrace(utils_tests.SetupDirectory): def __init__(self, *args, **kwargs): super(TestSystrace, self).__init__( - [("trace_systrace.html", "trace.html")], + [("trace_systrace.html", "trace.html"), + ("trace_surfaceflinger.html", "trace_sf.html")], *args, **kwargs) @@ -51,6 +52,17 @@ def test_cpu_counting(self): self.assertTrue(hasattr(trace, "_cpus")) self.assertEquals(trace._cpus, 3) + def test_systrace_userspace(self): + """Test parsing of userspace events""" + + trace = trappy.SysTrace("trace_sf.html") + dfr = trace.tracing_mark_write.data_frame + self.assertTrue(dfr['__pid'].iloc[2], 7459) + self.assertTrue(dfr['__comm'].iloc[2], 'RenderThread') + self.assertTrue(dfr['pid'].iloc[2], 7459) + self.assertTrue(dfr['event'].iloc[2], 'B') + self.assertTrue(dfr['func'].iloc[2], 'notifyFramePending') + self.assertTrue(dfr['data'].iloc[-2], 'HW_VSYNC_0') class TestLegacySystrace(utils_tests.SetupDirectory): diff --git a/tests/trace_surfaceflinger.html b/tests/trace_surfaceflinger.html new file mode 100644 index 00000000..aee045e8 --- /dev/null +++ b/tests/trace_surfaceflinger.html @@ -0,0 +1,3111 @@ + + + + + +Android System Trace + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + diff --git a/trappy/bare_trace.py b/trappy/bare_trace.py index f3fbd58c..2d4400b8 100644 --- a/trappy/bare_trace.py +++ b/trappy/bare_trace.py @@ -134,5 +134,9 @@ def add_parsed_event(self, name, dfr, pivot=None): def finalize_objects(self): for trace_class in self.trace_classes: + trace_class.tracer = self trace_class.create_dataframe() trace_class.finalize_object() + + def generate_data_dict(self): + return None diff --git a/trappy/base.py b/trappy/base.py index 6b9be4db..93ce60cd 100644 --- a/trappy/base.py +++ b/trappy/base.py @@ -95,10 +95,16 @@ class Base(object): :param parse_raw: If :code:`True`, raw trace data (-R option) to trace-cmd will be used + :param fallback: If :code:`True`, the parsing class will be used + only if no other candidate class's unique_word matched. subclasses + should override this (for ex. TracingMarkWrite uses it) + This class acts as a base class for all TRAPpy events """ - def __init__(self, parse_raw=False): + def __init__(self, parse_raw=False, fallback=False): + self.fallback = fallback + self.tracer = None self.data_frame = pd.DataFrame() self.data_array = [] self.time_array = [] @@ -171,6 +177,25 @@ def append_data(self, time, comm, pid, cpu, data): self.cpu_array.append(cpu) self.data_array.append(data) + def generate_data_dict(self, data_str): + data_dict = {} + prev_key = None + for field in data_str.split(): + if "=" not in field: + # Concatenation is supported only for "string" values + if type(data_dict[prev_key]) is not str: + continue + data_dict[prev_key] += ' ' + field + continue + (key, value) = field.split('=', 1) + try: + value = int(value) + except ValueError: + pass + data_dict[key] = value + prev_key = key + return data_dict + def generate_parsed_data(self): # Get a rough idea of how much memory we have to play with @@ -183,21 +208,7 @@ def generate_parsed_data(self): for (comm, pid, cpu, data_str) in zip(self.comm_array, self.pid_array, self.cpu_array, self.data_array): data_dict = {"__comm": comm, "__pid": pid, "__cpu": cpu} - prev_key = None - for field in data_str.split(): - if "=" not in field: - # Concatenation is supported only for "string" values - if type(data_dict[prev_key]) is not str: - continue - data_dict[prev_key] += ' ' + field - continue - (key, value) = field.split('=', 1) - try: - value = int(value) - except ValueError: - pass - data_dict[key] = value - prev_key = key + data_dict.update(self.generate_data_dict(data_str)) # When running out of memory, Pandas has been observed to segfault # rather than throwing a proper Python error. diff --git a/trappy/ftrace.py b/trappy/ftrace.py index dd0a2fc3..5bd6872e 100644 --- a/trappy/ftrace.py +++ b/trappy/ftrace.py @@ -168,11 +168,10 @@ def contains_unique_word(line, unique_words=cls_for_unique_word.keys()): return True return False - special_fields_regexp = r"^\s*(?P.*)-(?P\d+)(?:\s+\(.*\))"\ + fields_regexp = r"^\s*(?P.*)-(?P\d+)(?:\s+\(.*\))"\ r"?\s+\[(?P\d+)\](?:\s+....)?\s+"\ - r"(?P[0-9]+\.[0-9]+):" - special_fields_regexp = re.compile(special_fields_regexp) - start_match = re.compile(r"[A-Za-z0-9_]+=") + r"(?P[0-9]+\.[0-9]+): (\w+:\s+)+(?P.+)" + fields_regexp = re.compile(fields_regexp) actual_trace = itertools.dropwhile(self.trace_hasnt_started(), fin) actual_trace = itertools.takewhile(self.trace_hasnt_finished(), @@ -182,19 +181,22 @@ def contains_unique_word(line, unique_words=cls_for_unique_word.keys()): for unique_word, cls in cls_for_unique_word.iteritems(): if unique_word in line: trace_class = cls - break + if not cls.fallback: + break else: - raise FTraceParseError("No unique word in '{}'".format(line)) + if not trace_class: + raise FTraceParseError("No unique word in '{}'".format(line)) line = line[:-1] - special_fields_match = special_fields_regexp.match(line) - if not special_fields_match: + fields_match = fields_regexp.match(line) + if not fields_match: raise FTraceParseError("Couldn't match special fields in '{}'".format(line)) - comm = special_fields_match.group('comm') - pid = int(special_fields_match.group('pid')) - cpu = int(special_fields_match.group('cpu')) - timestamp = float(special_fields_match.group('timestamp')) + comm = fields_match.group('comm') + pid = int(fields_match.group('pid')) + cpu = int(fields_match.group('cpu')) + timestamp = float(fields_match.group('timestamp')) + data_str = fields_match.group('data') if not self.basetime: self.basetime = timestamp @@ -207,13 +209,6 @@ def contains_unique_word(line, unique_words=cls_for_unique_word.keys()): (abs_window[1] and timestamp > abs_window[1]): return - try: - data_start_idx = start_match.search(line).start() - except AttributeError: - continue - - data_str = line[data_start_idx:] - # Remove empty arrays from the trace data_str = re.sub(r"[A-Za-z0-9_]+=\{\} ", r"", data_str) diff --git a/trappy/systrace.py b/trappy/systrace.py index 6e917a65..e18abf85 100644 --- a/trappy/systrace.py +++ b/trappy/systrace.py @@ -14,6 +14,10 @@ # from trappy.ftrace import GenericFTrace +import re + +SYSTRACE_EVENT = re.compile( + r'^(?P[A-Z])(\|(?P\d+)\|(?P.*)(\|(?P\d+))?)?') class drop_before_trace(object): """Object that, when called, returns True if the line is not part of @@ -75,3 +79,16 @@ def trace_hasnt_finished(self): """ return lambda x: not x.endswith("\n") + + def generate_data_dict(self, data_str): + """ Custom parsing for systrace's userspace events """ + data_dict = None + + match = SYSTRACE_EVENT.match(data_str) + if match: + data_dict = { 'event': match.group('event'), + 'pid' : match.group('pid'), + 'func' : match.group('func'), + 'data' : match.group('data') } + + return data_dict diff --git a/trappy/tracing_mark_write.py b/trappy/tracing_mark_write.py new file mode 100644 index 00000000..49a23b07 --- /dev/null +++ b/trappy/tracing_mark_write.py @@ -0,0 +1,43 @@ +# Copyright 2017 ARM Limited, Google 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. +# + +"""This module contains the class for representing a tracing_mark_write +trace_event used for ftrace events injected from userspace. +""" + +from trappy.base import Base +from trappy.dynamic import register_ftrace_parser + +class TracingMarkWrite(Base): + """Parse tracing_mark_write events that couldn't be matched with more specific unique words + This class is always used as a fallback if nothing more specific could match the particular + tracing_mark_write event. + """ + + unique_word = "tracing_mark_write" + + def generate_data_dict(self, data_str): + if self.tracer: + data_dict = self.tracer.generate_data_dict(data_str) + if data_dict: + return data_dict + + data_dict = { 'string': data_str } + return data_dict + + def __init__(self): + super(TracingMarkWrite, self).__init__(fallback=True) + +register_ftrace_parser(TracingMarkWrite)