Added graph viewer for TIDL API timestamp data
[tidl/tidl-api.git] / viewer / execution_graph.py
1 #!/usr/bin/env python
3 # Copyright (c) 2018 Texas Instruments Incorporated - http://www.ti.com/
4 # All rights reserved.
5 #
6 # Redistribution and use in source and binary forms, with or without
7 # modification, are permitted provided that the following conditions are met:
8 # * Redistributions of source code must retain the above copyright
9 # notice, this list of conditions and the following disclaimer.
10 # * Redistributions in binary form must reproduce the above copyright
11 # notice, this list of conditions and the following disclaimer in the
12 # documentation and/or other materials provided with the distribution.
13 # * Neither the name of Texas Instruments Incorporated nor the
14 # names of its contributors may be used to endorse or promote products
15 # derived from this software without specific prior written permission.
16 #
17 # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
18 # AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
19 # IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
20 # ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
21 # LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
22 # CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
23 # SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
24 # INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
25 # CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
26 # ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
27 # THE POSSIBILITY OF SUCH DAMAGE.
29 """ Frame Execution Graph
31 This script parses timestamp output generated from the TIDL API and
32 displays a graph of frame execution.
34 The script requires `matplotlib` to be installed.
35 """
37 import argparse
38 import matplotlib.pyplot as mpyplot
39 import matplotlib.patches as mpatch
41 USAGE = """
42     Display frame execution using trace data generated by the TIDL API.
43 """
45 # Supported TIDL API classes
46 COMPONENTS = ('eop', 'eo1', 'eo2')
48 # APIs with timestamps
49 # ProcessFrameStartAsync, ProcessFrameWait, RunAsyncNext
50 KEY_PFSA = 'pfsa'
51 KEY_PFW = 'pfw'
52 KEY_RAN = 'ran'
54 KEY_START = 'start'
55 KEY_END = 'end'
57 BARH_COLORS = ('lightgray', 'green', 'blue', 'yellow',
58                'black', 'orange', 'red', 'cyan')
60 BARH_LEGEND_STR = {'eop' : 'ExecutionObjectPipeline',
61                    'eo1' : 'ExecutionObject 0',
62                    'eo2' : 'ExecutionObject 1',
63                    'pfw' : 'Process Frame Wait',
64                    'pfsa': 'Process Frame Start Async',
65                    'ran' : 'Run Async Next',
66                    'total': 'Total frame time'}
68 class Range:
69     """ Defines a range in terms of start and stop timestamps. """
71     def __init__(self):
72         self.start = 0
73         self.end = 0
75     def set_start(self, start):
76         """Set the start time."""
78         self.start = start
80     def set_end(self, end):
81         """ Set the end time."""
83         self.end = end
85     def subtract(self, val):
86         """ Subtracl val from each start/end."""
88         self.start -= val
89         self.end -= val
91     def get_range(self):
92         """Return (start, duration)."""
94         return (self.start, self.end-self.start)
97 class FrameInfo:
98     """ All recorded events for a single frame. """
100     def __init__(self, index):
101         """Set up dictionaries to store timestamp data"""
103         self.index = index
104         self.eo_type = {}
105         self.eo_id = {}
107         self.data = {}
108         for component in COMPONENTS:
109             self.data[component] = {}
111     def update(self, component, api, phase, val):
112         """Update the [c][api][phase] with timestamp"""
114         if component not in COMPONENTS:
115             print('Invalid component: {}'.format(component))
116             return
118         if api not in self.data[component]:
119             self.data[component][api] = Range()
121         if phase == KEY_START:
122             self.data[component][api].set_start(val)
123         elif phase == KEY_END:
124             self.data[component][api].set_end(val)
125         else:
126             raise Exception('Invalid key: {}'.format(phase))
128     def update_eo_info(self, component, eo_type, eo_id):
129         """Set the Execution Object type and index. Used to generate
130            the EVEx or DSPx labels"""
132         self.eo_type[component] = eo_type
133         self.eo_id[component] = eo_id
135     def eo_info(self):
136         """Return a string corresponding to the EO info. Device numbering in
137            TRM starts at 1. E.g. EVE1, EVE2, DSP1, DSP2 etc.
138         """
140         device_list = []
141         for component in ('eo1', 'eo2'):
142             device = ""
143             if not self.data[component]:
144                 continue
146             # Corresponds to DeviceType enum in inc/executor.h
147             if self.eo_type[component] == 0:
148                 device += 'DSP'
149             else:
150                 device += 'EVE'
152             device += str(self.eo_id[component]+1)
154             device_list.append(device)
156         return '+'.join(device_list)
158     def get_range(self, component, api):
159         """Return the range for the specified component:api combination"""
161         if api in self.data[component]:
162             return self.data[component][api].get_range()
164         return None
166     def get_max_range(self):
167         """Return a tuple corresponding to the maximum range"""
169         return (self.min(), self.max() - self.min())
171     def get_total(self, component):
172         """Return the range for the specified component"""
174         if not self.data[component]:
175             print("{} not available".format(component))
176             return None
178         start = self.data[component][KEY_PFSA].start
179         end = self.data[component][KEY_PFW].end
180         return (start, int(end-start))
182     def min(self):
183         """ Return the lowest timestamp for a frame"""
185         vals = []
186         for component in self.data:
187             for api in self.data[component]:
188                 vals.append(self.data[component][api].start)
190         return min(vals)
192     def max(self):
193         """ Return the highest timestamp for a frame"""
194         vals = []
195         for component in self.data:
196             for api in self.data[component]:
197                 vals.append(self.data[component][api].end)
199         return max(vals)
201     def subtract(self, val):
202         """Subtract val from every timestamp in this frame. Use to
203            adjust start of frame 0 to 0.
204         """
206         for component in self.data:
207             for api in self.data[component]:
208                 self.data[component][api].subtract(val)
210     def get_plot_ranges(self, components):
211         """ Return a list of (component, range) tuples for all api data
212             available for the specified components.
213         """
215         ranges = []
216         for component in self.data:
217             if component not in components:
218                 continue
220             for api in self.data[component]:
221                 range_tuple = self.get_range(component, api)
222                 if range_tuple is not None:
223                     label = component + ':' + api
224                     ranges.append((label, range_tuple))
226         # Reverse sort by duration (improves graph rendering)
227         ranges.sort(key=lambda kv: kv[1][1], reverse=True)
229         return ranges
231     def get_plot_totals(self):
232         """ Return (component, range) tuples for all available components.
233             The range corresponds to the execution time for the entire
234             component.
235         """
237         ranges = []
238         for component in self.data:
239             range_tuple = self.get_total(component)
240             if range_tuple is not None:
241                 ranges.append((component, range_tuple))
243         # Sort by start time stamp
244         ranges.sort(key=lambda kv: kv[1][0])
246         return ranges
248     def get_barh_ranges(self, found, verbosity):
249         """Return a list of range tuples for plotting. Also return
250            corresponding labels"""
252         label_range_tuples = []
254         if verbosity == 0:
255             if not found['eo2']:
256                 if found['eop']:
257                     component = 'eop'
258                 else:
259                     component = 'eo1'
260                 label_range_tuples.append(('total', self.get_max_range()))
261                 label_range_tuples.extend(self.get_plot_ranges((component)))
262             else:
263                 label_range_tuples = self.get_plot_totals()
265         elif verbosity == 1:
266             label_range_tuples.append(('total', self.get_max_range()))
267             for component in COMPONENTS:
268                 label_range_tuples.extend(self.get_plot_ranges(component))
270         labels = [i[0] for i in label_range_tuples]
271         ranges = [i[1] for i in label_range_tuples]
273         return ranges, labels
275     def __repr__(self):
276         string = '<FI:'
278         # Sort components based in order in COMPONENTS
279         components = list(self.data.keys())
280         components.sort(key=COMPONENTS.index)
281         #components.sort(key=lambda kv: COMPONENTS.index(kv))
283         for component in components:
284             if not self.data[component]:
285                 continue
287             string += ' {} ['.format(component)
289             # Sort Ranges by start values
290             items = sorted(self.data[component].items(),
291                            key=lambda kv: kv[1].start)
292             for api in items:
293                 string += '{}: {} '.format(api[0],
294                                            self.get_range(component, api[0]))
295             string += ']'
297         string += '>'
299         return string
302 class Frames:
303     """ Per-frame data across a set of frames """
305     def __init__(self, v):
306         self.trace_data = {}
307         self.found = {}
308         for component in COMPONENTS:
309             self.found[component] = False
310         self.verbosity = v
312     def update(self, index, key, val):
313         """ Update event data for a frame """
315         # Canonicalize key to lower case
316         component, api, phase = key.split(':')
318         if index not in self.trace_data:
319             self.trace_data[index] = FrameInfo(index)
321         self.trace_data[index].update(component, api, phase, val)
323         self.found[component] = True
325     def adjust_to_zero(self):
326         """ Adjust timestamp sequence to start at 0"""
328         # Get a sorted list of frame indices
329         indices = self.indices()
331         # Find the smallest timestamp in the 0th frame
332         min_val = self.trace_data[indices[0]].min()
334         # Use this value to adjust all the timestamps
335         for i in indices:
336             self.trace_data[i].subtract(min_val)
338     def len(self):
339         """Returns the number of frames available."""
341         return len(self.trace_data)
343     def indices(self):
344         """ Returns a sorted list of frame indices."""
346         indices = list(self.trace_data.keys())
347         indices.sort()
348         return indices
350     def min_max_indices(self):
351         """ Returns the minimum and maximum frame index."""
353         indices = list(self.trace_data.keys())
354         return (min(indices), max(indices))
356     def microseconds_per_frame(self):
357         """Returns the average microseconds to execute a frame."""
359         # Get a sorted list of frame indices
360         indices = self.indices()
362         num_frames = len(indices)
364         # Find the smallest timestamp in the 0th frame
365         min_val = self.trace_data[indices[0]].min()
367         # Find the largest timestamp in the last frame
368         max_val = self.trace_data[indices[-1]].max()
370         return (max_val - min_val)/num_frames
373     def __repr__(self):
374         string = 'Frames:\n'
375         indices = self.indices()
376         for i in indices:
377             string += str(self.trace_data[i])
378             string += "\n"
380         return string
383 def read_data(args):
384     """ Read a sequence of trace data and create a Frames object
385         Each row has the following syntax: frame_index, key, value
386         There is a row for each event that is recorded for a frame
387         E.g.
388         48,EOP:PFSA:Start,1540246078613202
389     """
391     frames = Frames(args.verbosity)
393     with open(args.input_file) as lines:
394         for line in lines:
395             info = line.rstrip().split(',')
396             if (len(info) != 3 and len(info) != 5):
397                 continue
399             frame_index = int(info[0])
400             data_key = info[1].lower()
402             frames.update(index=frame_index, key=data_key, val=int(info[2]))
404             if len(info) == 5:
405                 component = data_key.split(':')[0]
406                 frames.trace_data[frame_index].update_eo_info(component,
407                                                               int(info[3]),
408                                                               int(info[4]))
410     frames.adjust_to_zero()
412     print('Found {} frames {} in timestamp data, {} microseconds per frame'.
413           format(frames.len(), frames.min_max_indices(),
414                  frames.microseconds_per_frame()))
416     return frames
419 def insert_legend(labels, axes):
420     """ Create and insert a legend."""
422     bars = []
423     legend_strings = []
425     for label in labels:
426         index = labels.index(label)
427         # Create rectangles of the appropriate color for each label
428         bars.append(mpatch.Rectangle((0, 0), 1, 1, fc=BARH_COLORS[index]))
430         # Build a legend string from a ':' separated label string
431         legend_string = ""
432         for tags in label.split(':'):
433             legend_string += BARH_LEGEND_STR[tags] + ' '
435         legend_strings.append(legend_string)
437     # Insert the legend (mapping of colors to labels)
438     axes.legend(bars, legend_strings, loc='upper left')
441 def plot(frames, filename):
442     """ Use matplotlib to plot the data."""
444     figure, axes = mpyplot.subplots()
446     y_labels = []
447     y_ticks = []
448     y_index = 0
449     y_increment = 5
450     legend_inserted = False
452     for frame_index in sorted(frames.trace_data):
453         frame = frames.trace_data[frame_index]
454         ranges, labels = frame.get_barh_ranges(frames.found, frames.verbosity)
455         axes.broken_barh(ranges,
456                          (y_index, 5),
457                          facecolors=BARH_COLORS,
458                          alpha=0.8)
460         if not legend_inserted:
461             insert_legend(labels, axes)
462             legend_inserted = True
464         # label string - overall time to execute the frame
465         bar_label = str(int(frame.max() - frame.min()))
467         # Add total time label
468         axes.annotate(bar_label,
469                       (frame.max(), y_index + 2),
470                       xytext=(5, 0),
471                       textcoords="offset points",
472                       fontsize=8,
473                       va='center',
474                       ha='left')
476         # Add EO info label
477         axes.annotate(frame.eo_info(),
478                       (frame.min(), y_index + 2),
479                       xytext=(-5, 0),
480                       textcoords="offset points",
481                       fontsize=6,
482                       va='center',
483                       ha='right')
485         y_index += y_increment
486         y_labels.append(str(frame_index))
487         y_ticks.append(y_index)
489     axes.set_xlabel('Microseconds')
490     axes.set_ylabel('Frames')
491     axes.set_yticks(y_ticks)
492     axes.set_yticklabels(y_labels, verticalalignment='center')
493     axes.grid(True)
494     axes.set_title(filename)
496     # Set a default size for the displayed figure
497     figure.set_size_inches(14, 8)
499     mpyplot.show()
502 def main():
503     """ Parse arguments, read input into Frames and plot the data."""
505     parser = argparse.ArgumentParser(description=USAGE)
506     parser.add_argument("-v", "--verbosity", type=int, choices=[0, 1],
507                         default=0,
508                         help="Level of graph detail. 0->Summary, 1->Details")
509     parser.add_argument("input_file",
510                         default='trace.log',
511                         help='Path to trace log file')
512     args = parser.parse_args()
515     frames = read_data(args)
516     plot(frames, args.input_file)
518 if __name__ == '__main__':
519     main()