[RFC] Systrace's custom events formatting

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"""
 

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)

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,24 @@ def trace_hasnt_finished(self):
 
         """
         return lambda x: not x.endswith("</script>\n")
+
+    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(
+                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<event>[A-Z])(\|(?P<pid>\d+)\|(?P<func>.*)(\|(?P<data>\d+))?)?')