viewer/execution_graph.py

   1 #!/usr/bin/env python
   2
   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.
  28
  29 """ Frame Execution Graph
  30
  31 This script parses timestamp output generated from the TIDL API and
  32 displays a graph of frame execution.
  33
  34 The script requires `matplotlib` to be installed.
  35 """
  36
  37 import argparse
  38 import matplotlib.pyplot as mpyplot
  39 import matplotlib.patches as mpatch
  40
  41 USAGE = """
  42     Display frame execution using trace data generated by the TIDL API.
  43 """
  44
  45 # Supported TIDL API classes
  46 COMPONENTS = ('eop', 'eo1', 'eo2')
  47
  48 # APIs with timestamps
  49 # ProcessFrameStartAsync, ProcessFrameWait, RunAsyncNext
  50 KEY_PFSA = 'pfsa'
  51 KEY_PFW = 'pfw'
  52 KEY_RAN = 'ran'
  53
  54 KEY_START = 'start'
  55 KEY_END = 'end'
  56
  57 BARH_COLORS = ('lightgray', 'green', 'blue', 'yellow',
  58                'black', 'orange', 'red', 'cyan')
  59
  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'}
  67
  68 class Range:
  69     """ Defines a range in terms of start and stop timestamps. """
  70
  71     def __init__(self):
  72         self.start = 0
  73         self.end = 0
  74
  75     def set_start(self, start):
  76         """Set the start time."""
  77
  78         self.start = start
  79
  80     def set_end(self, end):
  81         """ Set the end time."""
  82
  83         self.end = end
  84
  85     def subtract(self, val):
  86         """ Subtracl val from each start/end."""
  87
  88         self.start -= val
  89         self.end -= val
  90
  91     def get_range(self):
  92         """Return (start, duration)."""
  93
  94         return (self.start, self.end-self.start)
  95
  96
  97 class FrameInfo:
  98     """ All recorded events for a single frame. """
  99
 100     def __init__(self, index):
 101         """Set up dictionaries to store timestamp data"""
 102
 103         self.index = index
 104         self.eo_type = {}
 105         self.eo_id = {}
 106
 107         self.data = {}
 108         for component in COMPONENTS:
 109             self.data[component] = {}
 110
 111     def update(self, component, api, phase, val):
 112         """Update the [c][api][phase] with timestamp"""
 113
 114         if component not in COMPONENTS:
 115             print('Invalid component: {}'.format(component))
 116             return
 117
 118         if api not in self.data[component]:
 119             self.data[component][api] = Range()
 120
 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))
 127
 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"""
 131
 132         self.eo_type[component] = eo_type
 133         self.eo_id[component] = eo_id
 134
 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         """
 139
 140         device_list = []
 141         for component in ('eo1', 'eo2'):
 142             device = ""
 143             if not self.data[component]:
 144                 continue
 145
 146             # Corresponds to DeviceType enum in inc/executor.h
 147             if self.eo_type[component] == 0:
 148                 device += 'DSP'
 149             else:
 150                 device += 'EVE'
 151
 152             device += str(self.eo_id[component]+1)
 153
 154             device_list.append(device)
 155
 156         return '+'.join(device_list)
 157
 158     def get_range(self, component, api):
 159         """Return the range for the specified component:api combination"""
 160
 161         if api in self.data[component]:
 162             return self.data[component][api].get_range()
 163
 164         return None
 165
 166     def get_max_range(self):
 167         """Return a tuple corresponding to the maximum range"""
 168
 169         return (self.min(), self.max() - self.min())
 170
 171     def get_total(self, component):
 172         """Return the range for the specified component"""
 173
 174         if not self.data[component]:
 175             print("{} not available".format(component))
 176             return None
 177
 178         start = self.data[component][KEY_PFSA].start
 179         end = self.data[component][KEY_PFW].end
 180         return (start, int(end-start))
 181
 182     def min(self):
 183         """ Return the lowest timestamp for a frame"""
 184
 185         vals = []
 186         for component in self.data:
 187             for api in self.data[component]:
 188                 vals.append(self.data[component][api].start)
 189
 190         return min(vals)
 191
 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)
 198
 199         return max(vals)
 200
 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         """
 205
 206         for component in self.data:
 207             for api in self.data[component]:
 208                 self.data[component][api].subtract(val)
 209
 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         """
 214
 215         ranges = []
 216         for component in self.data:
 217             if component not in components:
 218                 continue
 219
 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))
 225
 226         # Reverse sort by duration (improves graph rendering)
 227         ranges.sort(key=lambda kv: kv[1][1], reverse=True)
 228
 229         return ranges
 230
 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         """
 236
 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))
 242
 243         # Sort by start time stamp
 244         ranges.sort(key=lambda kv: kv[1][0])
 245
 246         return ranges
 247
 248     def get_barh_ranges(self, found, verbosity):
 249         """Return a list of range tuples for plotting. Also return
 250            corresponding labels"""
 251
 252         label_range_tuples = []
 253
 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()
 264
 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))
 269
 270         labels = [i[0] for i in label_range_tuples]
 271         ranges = [i[1] for i in label_range_tuples]
 272
 273         return ranges, labels
 274
 275     def __repr__(self):
 276         string = '<FI:'
 277
 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))
 282
 283         for component in components:
 284             if not self.data[component]:
 285                 continue
 286
 287             string += ' {} ['.format(component)
 288
 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 += ']'
 296
 297         string += '>'
 298
 299         return string
 300
 301
 302 class Frames:
 303     """ Per-frame data across a set of frames """
 304
 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
 311
 312     def update(self, index, key, val):
 313         """ Update event data for a frame """
 314
 315         # Canonicalize key to lower case
 316         component, api, phase = key.split(':')
 317
 318         if index not in self.trace_data:
 319             self.trace_data[index] = FrameInfo(index)
 320
 321         self.trace_data[index].update(component, api, phase, val)
 322
 323         self.found[component] = True
 324
 325     def adjust_to_zero(self):
 326         """ Adjust timestamp sequence to start at 0"""
 327
 328         # Get a sorted list of frame indices
 329         indices = self.indices()
 330
 331         # Find the smallest timestamp in the 0th frame
 332         min_val = self.trace_data[indices[0]].min()
 333
 334         # Use this value to adjust all the timestamps
 335         for i in indices:
 336             self.trace_data[i].subtract(min_val)
 337
 338     def len(self):
 339         """Returns the number of frames available."""
 340
 341         return len(self.trace_data)
 342
 343     def indices(self):
 344         """ Returns a sorted list of frame indices."""
 345
 346         indices = list(self.trace_data.keys())
 347         indices.sort()
 348         return indices
 349
 350     def min_max_indices(self):
 351         """ Returns the minimum and maximum frame index."""
 352
 353         indices = list(self.trace_data.keys())
 354         return (min(indices), max(indices))
 355
 356     def microseconds_per_frame(self):
 357         """Returns the average microseconds to execute a frame."""
 358
 359         # Get a sorted list of frame indices
 360         indices = self.indices()
 361
 362         num_frames = len(indices)
 363
 364         # Find the smallest timestamp in the 0th frame
 365         min_val = self.trace_data[indices[0]].min()
 366
 367         # Find the largest timestamp in the last frame
 368         max_val = self.trace_data[indices[-1]].max()
 369
 370         return (max_val - min_val)/num_frames
 371
 372
 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"
 379
 380         return string
 381
 382
 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     """
 390
 391     frames = Frames(args.verbosity)
 392
 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
 398
 399             frame_index = int(info[0])
 400             data_key = info[1].lower()
 401
 402             frames.update(index=frame_index, key=data_key, val=int(info[2]))
 403
 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]))
 409
 410     frames.adjust_to_zero()
 411
 412     print('Found {} frames {} in timestamp data, {} microseconds per frame'.
 413           format(frames.len(), frames.min_max_indices(),
 414                  frames.microseconds_per_frame()))
 415
 416     return frames
 417
 418
 419 def insert_legend(labels, axes):
 420     """ Create and insert a legend."""
 421
 422     bars = []
 423     legend_strings = []
 424
 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]))
 429
 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] + ' '
 434
 435         legend_strings.append(legend_string)
 436
 437     # Insert the legend (mapping of colors to labels)
 438     axes.legend(bars, legend_strings, loc='upper left')
 439
 440
 441 def plot(frames, filename):
 442     """ Use matplotlib to plot the data."""
 443
 444     figure, axes = mpyplot.subplots()
 445
 446     y_labels = []
 447     y_ticks = []
 448     y_index = 0
 449     y_increment = 5
 450     legend_inserted = False
 451
 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)
 459
 460         if not legend_inserted:
 461             insert_legend(labels, axes)
 462             legend_inserted = True
 463
 464         # label string - overall time to execute the frame
 465         bar_label = str(int(frame.max() - frame.min()))
 466
 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')
 475
 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')
 484
 485         y_index += y_increment
 486         y_labels.append(str(frame_index))
 487         y_ticks.append(y_index)
 488
 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)
 495
 496     # Set a default size for the displayed figure
 497     figure.set_size_inches(14, 8)
 498
 499     mpyplot.show()
 500
 501
 502 def main():
 503     """ Parse arguments, read input into Frames and plot the data."""
 504
 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()
 513
 514
 515     frames = read_data(args)
 516     plot(frames, args.input_file)
 517
 518 if __name__ == '__main__':
 519     main()