1e76aff05SHagen Paul Pfeifer# task-analyzer.py - comprehensive perf tasks analysis 2e76aff05SHagen Paul Pfeifer# SPDX-License-Identifier: GPL-2.0 3e76aff05SHagen Paul Pfeifer# Copyright (c) 2022, Hagen Paul Pfeifer <hagen@jauu.net> 4e76aff05SHagen Paul Pfeifer# Licensed under the terms of the GNU GPL License version 2 5e76aff05SHagen Paul Pfeifer# 6e76aff05SHagen Paul Pfeifer# Usage: 7e76aff05SHagen Paul Pfeifer# 8e76aff05SHagen Paul Pfeifer# perf record -e sched:sched_switch -a -- sleep 10 9e76aff05SHagen Paul Pfeifer# perf script report task-analyzer 10e76aff05SHagen Paul Pfeifer# 11e76aff05SHagen Paul Pfeifer 12e76aff05SHagen Paul Pfeiferfrom __future__ import print_function 13e76aff05SHagen Paul Pfeiferimport sys 14e76aff05SHagen Paul Pfeiferimport os 15e76aff05SHagen Paul Pfeiferimport string 16e76aff05SHagen Paul Pfeiferimport argparse 17e76aff05SHagen Paul Pfeiferimport decimal 18e76aff05SHagen Paul Pfeifer 19e76aff05SHagen Paul Pfeifer 20e76aff05SHagen Paul Pfeifersys.path.append( 21e76aff05SHagen Paul Pfeifer os.environ["PERF_EXEC_PATH"] + "/scripts/python/Perf-Trace-Util/lib/Perf/Trace" 22e76aff05SHagen Paul Pfeifer) 23e76aff05SHagen Paul Pfeiferfrom perf_trace_context import * 24e76aff05SHagen Paul Pfeiferfrom Core import * 25e76aff05SHagen Paul Pfeifer 26e76aff05SHagen Paul Pfeifer# Definition of possible ASCII color codes 27e76aff05SHagen Paul Pfeifer_COLORS = { 28e76aff05SHagen Paul Pfeifer "grey": "\033[90m", 29e76aff05SHagen Paul Pfeifer "red": "\033[91m", 30e76aff05SHagen Paul Pfeifer "green": "\033[92m", 31e76aff05SHagen Paul Pfeifer "yellow": "\033[93m", 32e76aff05SHagen Paul Pfeifer "blue": "\033[94m", 33e76aff05SHagen Paul Pfeifer "violet": "\033[95m", 34e76aff05SHagen Paul Pfeifer "reset": "\033[0m", 35e76aff05SHagen Paul Pfeifer} 36e76aff05SHagen Paul Pfeifer 37e76aff05SHagen Paul Pfeifer# Columns will have a static size to align everything properly 38e76aff05SHagen Paul Pfeifer# Support of 116 days of active update with nano precision 39e76aff05SHagen Paul PfeiferLEN_SWITCHED_IN = len("9999999.999999999") # 17 40e76aff05SHagen Paul PfeiferLEN_SWITCHED_OUT = len("9999999.999999999") # 17 41e76aff05SHagen Paul PfeiferLEN_CPU = len("000") 42e76aff05SHagen Paul PfeiferLEN_PID = len("maxvalue") # 8 43e76aff05SHagen Paul PfeiferLEN_TID = len("maxvalue") # 8 44e76aff05SHagen Paul PfeiferLEN_COMM = len("max-comms-length") # 16 45e76aff05SHagen Paul PfeiferLEN_RUNTIME = len("999999.999") # 10 46e76aff05SHagen Paul Pfeifer# Support of 3.45 hours of timespans 47e76aff05SHagen Paul PfeiferLEN_OUT_IN = len("99999999999.999") # 15 48e76aff05SHagen Paul PfeiferLEN_OUT_OUT = len("99999999999.999") # 15 49e76aff05SHagen Paul PfeiferLEN_IN_IN = len("99999999999.999") # 15 50e76aff05SHagen Paul PfeiferLEN_IN_OUT = len("99999999999.999") # 15 51e76aff05SHagen Paul Pfeifer 52e76aff05SHagen Paul Pfeifer 53e76aff05SHagen Paul Pfeifer# py2/py3 compatibility layer, see PEP469 54e76aff05SHagen Paul Pfeifertry: 55e76aff05SHagen Paul Pfeifer dict.iteritems 56e76aff05SHagen Paul Pfeiferexcept AttributeError: 57e76aff05SHagen Paul Pfeifer # py3 58e76aff05SHagen Paul Pfeifer def itervalues(d): 59e76aff05SHagen Paul Pfeifer return iter(d.values()) 60e76aff05SHagen Paul Pfeifer 61e76aff05SHagen Paul Pfeifer def iteritems(d): 62e76aff05SHagen Paul Pfeifer return iter(d.items()) 63e76aff05SHagen Paul Pfeifer 64e76aff05SHagen Paul Pfeiferelse: 65e76aff05SHagen Paul Pfeifer # py2 66e76aff05SHagen Paul Pfeifer def itervalues(d): 67e76aff05SHagen Paul Pfeifer return d.itervalues() 68e76aff05SHagen Paul Pfeifer 69e76aff05SHagen Paul Pfeifer def iteritems(d): 70e76aff05SHagen Paul Pfeifer return d.iteritems() 71e76aff05SHagen Paul Pfeifer 72e76aff05SHagen Paul Pfeifer 73e76aff05SHagen Paul Pfeiferdef _check_color(): 74e76aff05SHagen Paul Pfeifer global _COLORS 75e76aff05SHagen Paul Pfeifer """user enforced no-color or if stdout is no tty we disable colors""" 76e76aff05SHagen Paul Pfeifer if sys.stdout.isatty() and args.stdio_color != "never": 77e76aff05SHagen Paul Pfeifer return 78e76aff05SHagen Paul Pfeifer _COLORS = { 79e76aff05SHagen Paul Pfeifer "grey": "", 80e76aff05SHagen Paul Pfeifer "red": "", 81e76aff05SHagen Paul Pfeifer "green": "", 82e76aff05SHagen Paul Pfeifer "yellow": "", 83e76aff05SHagen Paul Pfeifer "blue": "", 84e76aff05SHagen Paul Pfeifer "violet": "", 85e76aff05SHagen Paul Pfeifer "reset": "", 86e76aff05SHagen Paul Pfeifer } 87e76aff05SHagen Paul Pfeifer 88e76aff05SHagen Paul Pfeifer 89e76aff05SHagen Paul Pfeiferdef _parse_args(): 90e76aff05SHagen Paul Pfeifer global args 91e76aff05SHagen Paul Pfeifer parser = argparse.ArgumentParser(description="Analyze tasks behavior") 92e76aff05SHagen Paul Pfeifer parser.add_argument( 93e76aff05SHagen Paul Pfeifer "--time-limit", 94e76aff05SHagen Paul Pfeifer default=[], 95e76aff05SHagen Paul Pfeifer help= 96e76aff05SHagen Paul Pfeifer "print tasks only in time[s] window e.g" 97e76aff05SHagen Paul Pfeifer " --time-limit 123.111:789.222(print all between 123.111 and 789.222)" 98e76aff05SHagen Paul Pfeifer " --time-limit 123: (print all from 123)" 99e76aff05SHagen Paul Pfeifer " --time-limit :456 (print all until incl. 456)", 100e76aff05SHagen Paul Pfeifer ) 101e76aff05SHagen Paul Pfeifer parser.add_argument( 102e76aff05SHagen Paul Pfeifer "--summary", action="store_true", help="print addtional runtime information" 103e76aff05SHagen Paul Pfeifer ) 104e76aff05SHagen Paul Pfeifer parser.add_argument( 105e76aff05SHagen Paul Pfeifer "--summary-only", action="store_true", help="print only summary without traces" 106e76aff05SHagen Paul Pfeifer ) 107e76aff05SHagen Paul Pfeifer parser.add_argument( 108e76aff05SHagen Paul Pfeifer "--summary-extended", 109e76aff05SHagen Paul Pfeifer action="store_true", 110e76aff05SHagen Paul Pfeifer help="print the summary with additional information of max inter task times" 111e76aff05SHagen Paul Pfeifer " relative to the prev task", 112e76aff05SHagen Paul Pfeifer ) 113e76aff05SHagen Paul Pfeifer parser.add_argument( 114e76aff05SHagen Paul Pfeifer "--ns", action="store_true", help="show timestamps in nanoseconds" 115e76aff05SHagen Paul Pfeifer ) 116e76aff05SHagen Paul Pfeifer parser.add_argument( 117*de047c10SColin Ian King "--ms", action="store_true", help="show timestamps in milliseconds" 118e76aff05SHagen Paul Pfeifer ) 119e76aff05SHagen Paul Pfeifer parser.add_argument( 120e76aff05SHagen Paul Pfeifer "--extended-times", 121e76aff05SHagen Paul Pfeifer action="store_true", 122e76aff05SHagen Paul Pfeifer help="Show the elapsed times between schedule in/schedule out" 123e76aff05SHagen Paul Pfeifer " of this task and the schedule in/schedule out of previous occurrence" 124e76aff05SHagen Paul Pfeifer " of the same task", 125e76aff05SHagen Paul Pfeifer ) 126e76aff05SHagen Paul Pfeifer parser.add_argument( 127e76aff05SHagen Paul Pfeifer "--filter-tasks", 128e76aff05SHagen Paul Pfeifer default=[], 129e76aff05SHagen Paul Pfeifer help="filter out unneeded tasks by tid, pid or processname." 130e76aff05SHagen Paul Pfeifer " E.g --filter-task 1337,/sbin/init ", 131e76aff05SHagen Paul Pfeifer ) 132e76aff05SHagen Paul Pfeifer parser.add_argument( 133e76aff05SHagen Paul Pfeifer "--limit-to-tasks", 134e76aff05SHagen Paul Pfeifer default=[], 135e76aff05SHagen Paul Pfeifer help="limit output to selected task by tid, pid, processname." 136e76aff05SHagen Paul Pfeifer " E.g --limit-to-tasks 1337,/sbin/init", 137e76aff05SHagen Paul Pfeifer ) 138e76aff05SHagen Paul Pfeifer parser.add_argument( 139e76aff05SHagen Paul Pfeifer "--highlight-tasks", 140e76aff05SHagen Paul Pfeifer default="", 141e76aff05SHagen Paul Pfeifer help="colorize special tasks by their pid/tid/comm." 142e76aff05SHagen Paul Pfeifer " E.g. --highlight-tasks 1:red,mutt:yellow" 143e76aff05SHagen Paul Pfeifer " Colors available: red,grey,yellow,blue,violet,green", 144e76aff05SHagen Paul Pfeifer ) 145e76aff05SHagen Paul Pfeifer parser.add_argument( 146e76aff05SHagen Paul Pfeifer "--rename-comms-by-tids", 147e76aff05SHagen Paul Pfeifer default="", 148e76aff05SHagen Paul Pfeifer help="rename task names by using tid (<tid>:<newname>,<tid>:<newname>)" 149e76aff05SHagen Paul Pfeifer " This option is handy for inexpressive processnames like python interpreted" 150e76aff05SHagen Paul Pfeifer " process. E.g --rename 1337:my-python-app", 151e76aff05SHagen Paul Pfeifer ) 152e76aff05SHagen Paul Pfeifer parser.add_argument( 153e76aff05SHagen Paul Pfeifer "--stdio-color", 154e76aff05SHagen Paul Pfeifer default="auto", 155e76aff05SHagen Paul Pfeifer choices=["always", "never", "auto"], 156e76aff05SHagen Paul Pfeifer help="always, never or auto, allowing configuring color output" 157e76aff05SHagen Paul Pfeifer " via the command line", 158e76aff05SHagen Paul Pfeifer ) 159fdd0f81fSPetar Gligoric parser.add_argument( 160fdd0f81fSPetar Gligoric "--csv", 161fdd0f81fSPetar Gligoric default="", 162fdd0f81fSPetar Gligoric help="Write trace to file selected by user. Options, like --ns or --extended" 163fdd0f81fSPetar Gligoric "-times are used.", 164fdd0f81fSPetar Gligoric ) 165fdd0f81fSPetar Gligoric parser.add_argument( 166fdd0f81fSPetar Gligoric "--csv-summary", 167fdd0f81fSPetar Gligoric default="", 168fdd0f81fSPetar Gligoric help="Write summary to file selected by user. Options, like --ns or" 169fdd0f81fSPetar Gligoric " --summary-extended are used.", 170fdd0f81fSPetar Gligoric ) 171e76aff05SHagen Paul Pfeifer args = parser.parse_args() 172e76aff05SHagen Paul Pfeifer args.tid_renames = dict() 173e76aff05SHagen Paul Pfeifer 174e76aff05SHagen Paul Pfeifer _argument_filter_sanity_check() 175e76aff05SHagen Paul Pfeifer _argument_prepare_check() 176e76aff05SHagen Paul Pfeifer 177e76aff05SHagen Paul Pfeifer 178e76aff05SHagen Paul Pfeiferdef time_uniter(unit): 179e76aff05SHagen Paul Pfeifer picker = { 180e76aff05SHagen Paul Pfeifer "s": 1, 181e76aff05SHagen Paul Pfeifer "ms": 1e3, 182e76aff05SHagen Paul Pfeifer "us": 1e6, 183e76aff05SHagen Paul Pfeifer "ns": 1e9, 184e76aff05SHagen Paul Pfeifer } 185e76aff05SHagen Paul Pfeifer return picker[unit] 186e76aff05SHagen Paul Pfeifer 187e76aff05SHagen Paul Pfeifer 188e76aff05SHagen Paul Pfeiferdef _init_db(): 189e76aff05SHagen Paul Pfeifer global db 190e76aff05SHagen Paul Pfeifer db = dict() 191e76aff05SHagen Paul Pfeifer db["running"] = dict() 192e76aff05SHagen Paul Pfeifer db["cpu"] = dict() 193e76aff05SHagen Paul Pfeifer db["tid"] = dict() 194e76aff05SHagen Paul Pfeifer db["global"] = [] 195e76aff05SHagen Paul Pfeifer if args.summary or args.summary_extended or args.summary_only: 196e76aff05SHagen Paul Pfeifer db["task_info"] = dict() 197e76aff05SHagen Paul Pfeifer db["runtime_info"] = dict() 198e76aff05SHagen Paul Pfeifer # min values for summary depending on the header 199e76aff05SHagen Paul Pfeifer db["task_info"]["pid"] = len("PID") 200e76aff05SHagen Paul Pfeifer db["task_info"]["tid"] = len("TID") 201e76aff05SHagen Paul Pfeifer db["task_info"]["comm"] = len("Comm") 202e76aff05SHagen Paul Pfeifer db["runtime_info"]["runs"] = len("Runs") 203e76aff05SHagen Paul Pfeifer db["runtime_info"]["acc"] = len("Accumulated") 204e76aff05SHagen Paul Pfeifer db["runtime_info"]["max"] = len("Max") 205e76aff05SHagen Paul Pfeifer db["runtime_info"]["max_at"] = len("Max At") 206e76aff05SHagen Paul Pfeifer db["runtime_info"]["min"] = len("Min") 207e76aff05SHagen Paul Pfeifer db["runtime_info"]["mean"] = len("Mean") 208e76aff05SHagen Paul Pfeifer db["runtime_info"]["median"] = len("Median") 209e76aff05SHagen Paul Pfeifer if args.summary_extended: 210e76aff05SHagen Paul Pfeifer db["inter_times"] = dict() 211e76aff05SHagen Paul Pfeifer db["inter_times"]["out_in"] = len("Out-In") 212e76aff05SHagen Paul Pfeifer db["inter_times"]["inter_at"] = len("At") 213e76aff05SHagen Paul Pfeifer db["inter_times"]["out_out"] = len("Out-Out") 214e76aff05SHagen Paul Pfeifer db["inter_times"]["in_in"] = len("In-In") 215e76aff05SHagen Paul Pfeifer db["inter_times"]["in_out"] = len("In-Out") 216e76aff05SHagen Paul Pfeifer 217e76aff05SHagen Paul Pfeifer 218e76aff05SHagen Paul Pfeiferdef _median(numbers): 219e76aff05SHagen Paul Pfeifer """phython3 hat statistics module - we have nothing""" 220e76aff05SHagen Paul Pfeifer n = len(numbers) 221e76aff05SHagen Paul Pfeifer index = n // 2 222e76aff05SHagen Paul Pfeifer if n % 2: 223e76aff05SHagen Paul Pfeifer return sorted(numbers)[index] 224e76aff05SHagen Paul Pfeifer return sum(sorted(numbers)[index - 1 : index + 1]) / 2 225e76aff05SHagen Paul Pfeifer 226e76aff05SHagen Paul Pfeifer 227e76aff05SHagen Paul Pfeiferdef _mean(numbers): 228e76aff05SHagen Paul Pfeifer return sum(numbers) / len(numbers) 229e76aff05SHagen Paul Pfeifer 230e76aff05SHagen Paul Pfeifer 231e76aff05SHagen Paul Pfeiferclass Timespans(object): 232e76aff05SHagen Paul Pfeifer """ 233e76aff05SHagen Paul Pfeifer The elapsed time between two occurrences of the same task is being tracked with the 234e76aff05SHagen Paul Pfeifer help of this class. There are 4 of those Timespans Out-Out, In-Out, Out-In and 235e76aff05SHagen Paul Pfeifer In-In. 236e76aff05SHagen Paul Pfeifer The first half of the name signals the first time point of the 237e76aff05SHagen Paul Pfeifer first task. The second half of the name represents the second 238e76aff05SHagen Paul Pfeifer timepoint of the second task. 239e76aff05SHagen Paul Pfeifer """ 240e76aff05SHagen Paul Pfeifer 241e76aff05SHagen Paul Pfeifer def __init__(self): 242e76aff05SHagen Paul Pfeifer self._last_start = None 243e76aff05SHagen Paul Pfeifer self._last_finish = None 244e76aff05SHagen Paul Pfeifer self.out_out = -1 245e76aff05SHagen Paul Pfeifer self.in_out = -1 246e76aff05SHagen Paul Pfeifer self.out_in = -1 247e76aff05SHagen Paul Pfeifer self.in_in = -1 248e76aff05SHagen Paul Pfeifer if args.summary_extended: 249e76aff05SHagen Paul Pfeifer self._time_in = -1 250e76aff05SHagen Paul Pfeifer self.max_out_in = -1 251e76aff05SHagen Paul Pfeifer self.max_at = -1 252e76aff05SHagen Paul Pfeifer self.max_in_out = -1 253e76aff05SHagen Paul Pfeifer self.max_in_in = -1 254e76aff05SHagen Paul Pfeifer self.max_out_out = -1 255e76aff05SHagen Paul Pfeifer 256e76aff05SHagen Paul Pfeifer def feed(self, task): 257e76aff05SHagen Paul Pfeifer """ 258e76aff05SHagen Paul Pfeifer Called for every recorded trace event to find process pair and calculate the 259e76aff05SHagen Paul Pfeifer task timespans. Chronological ordering, feed does not do reordering 260e76aff05SHagen Paul Pfeifer """ 261e76aff05SHagen Paul Pfeifer if not self._last_finish: 262e76aff05SHagen Paul Pfeifer self._last_start = task.time_in(time_unit) 263e76aff05SHagen Paul Pfeifer self._last_finish = task.time_out(time_unit) 264e76aff05SHagen Paul Pfeifer return 265e76aff05SHagen Paul Pfeifer self._time_in = task.time_in() 266e76aff05SHagen Paul Pfeifer time_in = task.time_in(time_unit) 267e76aff05SHagen Paul Pfeifer time_out = task.time_out(time_unit) 268e76aff05SHagen Paul Pfeifer self.in_in = time_in - self._last_start 269e76aff05SHagen Paul Pfeifer self.out_in = time_in - self._last_finish 270e76aff05SHagen Paul Pfeifer self.in_out = time_out - self._last_start 271e76aff05SHagen Paul Pfeifer self.out_out = time_out - self._last_finish 272e76aff05SHagen Paul Pfeifer if args.summary_extended: 273e76aff05SHagen Paul Pfeifer self._update_max_entries() 274e76aff05SHagen Paul Pfeifer self._last_finish = task.time_out(time_unit) 275e76aff05SHagen Paul Pfeifer self._last_start = task.time_in(time_unit) 276e76aff05SHagen Paul Pfeifer 277e76aff05SHagen Paul Pfeifer def _update_max_entries(self): 278e76aff05SHagen Paul Pfeifer if self.in_in > self.max_in_in: 279e76aff05SHagen Paul Pfeifer self.max_in_in = self.in_in 280e76aff05SHagen Paul Pfeifer if self.out_out > self.max_out_out: 281e76aff05SHagen Paul Pfeifer self.max_out_out = self.out_out 282e76aff05SHagen Paul Pfeifer if self.in_out > self.max_in_out: 283e76aff05SHagen Paul Pfeifer self.max_in_out = self.in_out 284e76aff05SHagen Paul Pfeifer if self.out_in > self.max_out_in: 285e76aff05SHagen Paul Pfeifer self.max_out_in = self.out_in 286e76aff05SHagen Paul Pfeifer self.max_at = self._time_in 287e76aff05SHagen Paul Pfeifer 288e76aff05SHagen Paul Pfeifer 289e76aff05SHagen Paul Pfeifer 290e76aff05SHagen Paul Pfeiferclass Summary(object): 291e76aff05SHagen Paul Pfeifer """ 292e76aff05SHagen Paul Pfeifer Primary instance for calculating the summary output. Processes the whole trace to 293e76aff05SHagen Paul Pfeifer find and memorize relevant data such as mean, max et cetera. This instance handles 294e76aff05SHagen Paul Pfeifer dynamic alignment aspects for summary output. 295e76aff05SHagen Paul Pfeifer """ 296e76aff05SHagen Paul Pfeifer 297e76aff05SHagen Paul Pfeifer def __init__(self): 298e76aff05SHagen Paul Pfeifer self._body = [] 299e76aff05SHagen Paul Pfeifer 300e76aff05SHagen Paul Pfeifer class AlignmentHelper: 301e76aff05SHagen Paul Pfeifer """ 302e76aff05SHagen Paul Pfeifer Used to calculated the alignment for the output of the summary. 303e76aff05SHagen Paul Pfeifer """ 304e76aff05SHagen Paul Pfeifer def __init__(self, pid, tid, comm, runs, acc, mean, 305e76aff05SHagen Paul Pfeifer median, min, max, max_at): 306e76aff05SHagen Paul Pfeifer self.pid = pid 307e76aff05SHagen Paul Pfeifer self.tid = tid 308e76aff05SHagen Paul Pfeifer self.comm = comm 309e76aff05SHagen Paul Pfeifer self.runs = runs 310e76aff05SHagen Paul Pfeifer self.acc = acc 311e76aff05SHagen Paul Pfeifer self.mean = mean 312e76aff05SHagen Paul Pfeifer self.median = median 313e76aff05SHagen Paul Pfeifer self.min = min 314e76aff05SHagen Paul Pfeifer self.max = max 315e76aff05SHagen Paul Pfeifer self.max_at = max_at 316e76aff05SHagen Paul Pfeifer if args.summary_extended: 317e76aff05SHagen Paul Pfeifer self.out_in = None 318e76aff05SHagen Paul Pfeifer self.inter_at = None 319e76aff05SHagen Paul Pfeifer self.out_out = None 320e76aff05SHagen Paul Pfeifer self.in_in = None 321e76aff05SHagen Paul Pfeifer self.in_out = None 322e76aff05SHagen Paul Pfeifer 323e76aff05SHagen Paul Pfeifer def _print_header(self): 324e76aff05SHagen Paul Pfeifer ''' 325e76aff05SHagen Paul Pfeifer Output is trimmed in _format_stats thus additional adjustment in the header 326e76aff05SHagen Paul Pfeifer is needed, depending on the choice of timeunit. The adjustment corresponds 327e76aff05SHagen Paul Pfeifer to the amount of column titles being adjusted in _column_titles. 328e76aff05SHagen Paul Pfeifer ''' 329e76aff05SHagen Paul Pfeifer decimal_precision = 6 if not args.ns else 9 330e76aff05SHagen Paul Pfeifer fmt = " {{:^{}}}".format(sum(db["task_info"].values())) 331e76aff05SHagen Paul Pfeifer fmt += " {{:^{}}}".format( 332e76aff05SHagen Paul Pfeifer sum(db["runtime_info"].values()) - 2 * decimal_precision 333e76aff05SHagen Paul Pfeifer ) 334e76aff05SHagen Paul Pfeifer _header = ("Task Information", "Runtime Information") 335e76aff05SHagen Paul Pfeifer 336e76aff05SHagen Paul Pfeifer if args.summary_extended: 337e76aff05SHagen Paul Pfeifer fmt += " {{:^{}}}".format( 338e76aff05SHagen Paul Pfeifer sum(db["inter_times"].values()) - 4 * decimal_precision 339e76aff05SHagen Paul Pfeifer ) 340e76aff05SHagen Paul Pfeifer _header += ("Max Inter Task Times",) 341fdd0f81fSPetar Gligoric fd_sum.write(fmt.format(*_header) + "\n") 342e76aff05SHagen Paul Pfeifer 343e76aff05SHagen Paul Pfeifer def _column_titles(self): 344e76aff05SHagen Paul Pfeifer """ 345e76aff05SHagen Paul Pfeifer Cells are being processed and displayed in different way so an alignment adjust 346e76aff05SHagen Paul Pfeifer is implemented depeding on the choice of the timeunit. The positions of the max 347e76aff05SHagen Paul Pfeifer values are being displayed in grey. Thus in their format two additional {}, 348e76aff05SHagen Paul Pfeifer are placed for color set and reset. 349e76aff05SHagen Paul Pfeifer """ 350fdd0f81fSPetar Gligoric separator, fix_csv_align = _prepare_fmt_sep() 351e76aff05SHagen Paul Pfeifer decimal_precision, time_precision = _prepare_fmt_precision() 352fdd0f81fSPetar Gligoric fmt = "{{:>{}}}".format(db["task_info"]["pid"] * fix_csv_align) 353fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, db["task_info"]["tid"] * fix_csv_align) 354fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, db["task_info"]["comm"] * fix_csv_align) 355fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, db["runtime_info"]["runs"] * fix_csv_align) 356fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, db["runtime_info"]["acc"] * fix_csv_align) 357fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, db["runtime_info"]["mean"] * fix_csv_align) 358fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 359fdd0f81fSPetar Gligoric separator, db["runtime_info"]["median"] * fix_csv_align 360fdd0f81fSPetar Gligoric ) 361fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 362fdd0f81fSPetar Gligoric separator, (db["runtime_info"]["min"] - decimal_precision) * fix_csv_align 363fdd0f81fSPetar Gligoric ) 364fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 365fdd0f81fSPetar Gligoric separator, (db["runtime_info"]["max"] - decimal_precision) * fix_csv_align 366fdd0f81fSPetar Gligoric ) 367fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:>{}}}{{}}".format( 368fdd0f81fSPetar Gligoric separator, (db["runtime_info"]["max_at"] - time_precision) * fix_csv_align 369fdd0f81fSPetar Gligoric ) 370e76aff05SHagen Paul Pfeifer 371e76aff05SHagen Paul Pfeifer column_titles = ("PID", "TID", "Comm") 372e76aff05SHagen Paul Pfeifer column_titles += ("Runs", "Accumulated", "Mean", "Median", "Min", "Max") 373fdd0f81fSPetar Gligoric column_titles += (_COLORS["grey"], "Max At", _COLORS["reset"]) 374e76aff05SHagen Paul Pfeifer 375e76aff05SHagen Paul Pfeifer if args.summary_extended: 376fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 377fdd0f81fSPetar Gligoric separator, 378fdd0f81fSPetar Gligoric (db["inter_times"]["out_in"] - decimal_precision) * fix_csv_align 379e76aff05SHagen Paul Pfeifer ) 380fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:>{}}}{{}}".format( 381fdd0f81fSPetar Gligoric separator, 382fdd0f81fSPetar Gligoric (db["inter_times"]["inter_at"] - time_precision) * fix_csv_align 383fdd0f81fSPetar Gligoric ) 384fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 385fdd0f81fSPetar Gligoric separator, 386fdd0f81fSPetar Gligoric (db["inter_times"]["out_out"] - decimal_precision) * fix_csv_align 387fdd0f81fSPetar Gligoric ) 388fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 389fdd0f81fSPetar Gligoric separator, 390fdd0f81fSPetar Gligoric (db["inter_times"]["in_in"] - decimal_precision) * fix_csv_align 391fdd0f81fSPetar Gligoric ) 392fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format( 393fdd0f81fSPetar Gligoric separator, 394fdd0f81fSPetar Gligoric (db["inter_times"]["in_out"] - decimal_precision) * fix_csv_align 395fdd0f81fSPetar Gligoric ) 396e76aff05SHagen Paul Pfeifer 397e76aff05SHagen Paul Pfeifer column_titles += ("Out-In", _COLORS["grey"], "Max At", _COLORS["reset"], 398e76aff05SHagen Paul Pfeifer "Out-Out", "In-In", "In-Out") 399fdd0f81fSPetar Gligoric 400fdd0f81fSPetar Gligoric fd_sum.write(fmt.format(*column_titles) + "\n") 401fdd0f81fSPetar Gligoric 402e76aff05SHagen Paul Pfeifer 403e76aff05SHagen Paul Pfeifer def _task_stats(self): 404e76aff05SHagen Paul Pfeifer """calculates the stats of every task and constructs the printable summary""" 405e76aff05SHagen Paul Pfeifer for tid in sorted(db["tid"]): 406e76aff05SHagen Paul Pfeifer color_one_sample = _COLORS["grey"] 407e76aff05SHagen Paul Pfeifer color_reset = _COLORS["reset"] 408e76aff05SHagen Paul Pfeifer no_executed = 0 409e76aff05SHagen Paul Pfeifer runtimes = [] 410e76aff05SHagen Paul Pfeifer time_in = [] 411e76aff05SHagen Paul Pfeifer timespans = Timespans() 412e76aff05SHagen Paul Pfeifer for task in db["tid"][tid]: 413e76aff05SHagen Paul Pfeifer pid = task.pid 414e76aff05SHagen Paul Pfeifer comm = task.comm 415e76aff05SHagen Paul Pfeifer no_executed += 1 416e76aff05SHagen Paul Pfeifer runtimes.append(task.runtime(time_unit)) 417e76aff05SHagen Paul Pfeifer time_in.append(task.time_in()) 418e76aff05SHagen Paul Pfeifer timespans.feed(task) 419e76aff05SHagen Paul Pfeifer if len(runtimes) > 1: 420e76aff05SHagen Paul Pfeifer color_one_sample = "" 421e76aff05SHagen Paul Pfeifer color_reset = "" 422e76aff05SHagen Paul Pfeifer time_max = max(runtimes) 423e76aff05SHagen Paul Pfeifer time_min = min(runtimes) 424e76aff05SHagen Paul Pfeifer max_at = time_in[runtimes.index(max(runtimes))] 425e76aff05SHagen Paul Pfeifer 426e76aff05SHagen Paul Pfeifer # The size of the decimal after sum,mean and median varies, thus we cut 427e76aff05SHagen Paul Pfeifer # the decimal number, by rounding it. It has no impact on the output, 428e76aff05SHagen Paul Pfeifer # because we have a precision of the decimal points at the output. 429e76aff05SHagen Paul Pfeifer time_sum = round(sum(runtimes), 3) 430e76aff05SHagen Paul Pfeifer time_mean = round(_mean(runtimes), 3) 431e76aff05SHagen Paul Pfeifer time_median = round(_median(runtimes), 3) 432e76aff05SHagen Paul Pfeifer 433e76aff05SHagen Paul Pfeifer align_helper = self.AlignmentHelper(pid, tid, comm, no_executed, time_sum, 434e76aff05SHagen Paul Pfeifer time_mean, time_median, time_min, time_max, max_at) 435e76aff05SHagen Paul Pfeifer self._body.append([pid, tid, comm, no_executed, time_sum, color_one_sample, 436e76aff05SHagen Paul Pfeifer time_mean, time_median, time_min, time_max, 437e76aff05SHagen Paul Pfeifer _COLORS["grey"], max_at, _COLORS["reset"], color_reset]) 438e76aff05SHagen Paul Pfeifer if args.summary_extended: 439e76aff05SHagen Paul Pfeifer self._body[-1].extend([timespans.max_out_in, 440e76aff05SHagen Paul Pfeifer _COLORS["grey"], timespans.max_at, 441e76aff05SHagen Paul Pfeifer _COLORS["reset"], timespans.max_out_out, 442e76aff05SHagen Paul Pfeifer timespans.max_in_in, 443e76aff05SHagen Paul Pfeifer timespans.max_in_out]) 444e76aff05SHagen Paul Pfeifer align_helper.out_in = timespans.max_out_in 445e76aff05SHagen Paul Pfeifer align_helper.inter_at = timespans.max_at 446e76aff05SHagen Paul Pfeifer align_helper.out_out = timespans.max_out_out 447e76aff05SHagen Paul Pfeifer align_helper.in_in = timespans.max_in_in 448e76aff05SHagen Paul Pfeifer align_helper.in_out = timespans.max_in_out 449e76aff05SHagen Paul Pfeifer self._calc_alignments_summary(align_helper) 450e76aff05SHagen Paul Pfeifer 451e76aff05SHagen Paul Pfeifer def _format_stats(self): 452fdd0f81fSPetar Gligoric separator, fix_csv_align = _prepare_fmt_sep() 453e76aff05SHagen Paul Pfeifer decimal_precision, time_precision = _prepare_fmt_precision() 454fdd0f81fSPetar Gligoric len_pid = db["task_info"]["pid"] * fix_csv_align 455fdd0f81fSPetar Gligoric len_tid = db["task_info"]["tid"] * fix_csv_align 456fdd0f81fSPetar Gligoric len_comm = db["task_info"]["comm"] * fix_csv_align 457fdd0f81fSPetar Gligoric len_runs = db["runtime_info"]["runs"] * fix_csv_align 458fdd0f81fSPetar Gligoric len_acc = db["runtime_info"]["acc"] * fix_csv_align 459fdd0f81fSPetar Gligoric len_mean = db["runtime_info"]["mean"] * fix_csv_align 460fdd0f81fSPetar Gligoric len_median = db["runtime_info"]["median"] * fix_csv_align 461fdd0f81fSPetar Gligoric len_min = (db["runtime_info"]["min"] - decimal_precision) * fix_csv_align 462fdd0f81fSPetar Gligoric len_max = (db["runtime_info"]["max"] - decimal_precision) * fix_csv_align 463fdd0f81fSPetar Gligoric len_max_at = (db["runtime_info"]["max_at"] - time_precision) * fix_csv_align 464fdd0f81fSPetar Gligoric if args.summary_extended: 465fdd0f81fSPetar Gligoric len_out_in = ( 466fdd0f81fSPetar Gligoric db["inter_times"]["out_in"] - decimal_precision 467fdd0f81fSPetar Gligoric ) * fix_csv_align 468fdd0f81fSPetar Gligoric len_inter_at = ( 469fdd0f81fSPetar Gligoric db["inter_times"]["inter_at"] - time_precision 470fdd0f81fSPetar Gligoric ) * fix_csv_align 471fdd0f81fSPetar Gligoric len_out_out = ( 472fdd0f81fSPetar Gligoric db["inter_times"]["out_out"] - decimal_precision 473fdd0f81fSPetar Gligoric ) * fix_csv_align 474fdd0f81fSPetar Gligoric len_in_in = (db["inter_times"]["in_in"] - decimal_precision) * fix_csv_align 475fdd0f81fSPetar Gligoric len_in_out = ( 476fdd0f81fSPetar Gligoric db["inter_times"]["in_out"] - decimal_precision 477fdd0f81fSPetar Gligoric ) * fix_csv_align 478fdd0f81fSPetar Gligoric 479fdd0f81fSPetar Gligoric fmt = "{{:{}d}}".format(len_pid) 480fdd0f81fSPetar Gligoric fmt += "{}{{:{}d}}".format(separator, len_tid) 481fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, len_comm) 482fdd0f81fSPetar Gligoric fmt += "{}{{:{}d}}".format(separator, len_runs) 483fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_acc, time_precision) 484fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:{}.{}f}}".format(separator, len_mean, time_precision) 485fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_median, time_precision) 486fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_min, time_precision) 487fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_max, time_precision) 488fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:{}.{}f}}{{}}{{}}".format( 489fdd0f81fSPetar Gligoric separator, len_max_at, decimal_precision 490e76aff05SHagen Paul Pfeifer ) 491e76aff05SHagen Paul Pfeifer if args.summary_extended: 492fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_out_in, time_precision) 493fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:{}.{}f}}{{}}".format( 494fdd0f81fSPetar Gligoric separator, len_inter_at, decimal_precision 495e76aff05SHagen Paul Pfeifer ) 496fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_out_out, time_precision) 497fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_in_in, time_precision) 498fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, len_in_out, time_precision) 499e76aff05SHagen Paul Pfeifer return fmt 500e76aff05SHagen Paul Pfeifer 501e76aff05SHagen Paul Pfeifer 502e76aff05SHagen Paul Pfeifer def _calc_alignments_summary(self, align_helper): 503e76aff05SHagen Paul Pfeifer # Length is being cut in 3 groups so that further addition is easier to handle. 504e76aff05SHagen Paul Pfeifer # The length of every argument from the alignment helper is being checked if it 505e76aff05SHagen Paul Pfeifer # is longer than the longest until now. In that case the length is being saved. 506e76aff05SHagen Paul Pfeifer for key in db["task_info"]: 507e76aff05SHagen Paul Pfeifer if len(str(getattr(align_helper, key))) > db["task_info"][key]: 508e76aff05SHagen Paul Pfeifer db["task_info"][key] = len(str(getattr(align_helper, key))) 509e76aff05SHagen Paul Pfeifer for key in db["runtime_info"]: 510e76aff05SHagen Paul Pfeifer if len(str(getattr(align_helper, key))) > db["runtime_info"][key]: 511e76aff05SHagen Paul Pfeifer db["runtime_info"][key] = len(str(getattr(align_helper, key))) 512e76aff05SHagen Paul Pfeifer if args.summary_extended: 513e76aff05SHagen Paul Pfeifer for key in db["inter_times"]: 514e76aff05SHagen Paul Pfeifer if len(str(getattr(align_helper, key))) > db["inter_times"][key]: 515e76aff05SHagen Paul Pfeifer db["inter_times"][key] = len(str(getattr(align_helper, key))) 516e76aff05SHagen Paul Pfeifer 517e76aff05SHagen Paul Pfeifer 518e76aff05SHagen Paul Pfeifer def print(self): 519e76aff05SHagen Paul Pfeifer self._task_stats() 520fdd0f81fSPetar Gligoric fmt = self._format_stats() 521fdd0f81fSPetar Gligoric 522fdd0f81fSPetar Gligoric if not args.csv_summary: 523fdd0f81fSPetar Gligoric print("\nSummary") 524e76aff05SHagen Paul Pfeifer self._print_header() 525e76aff05SHagen Paul Pfeifer self._column_titles() 526e76aff05SHagen Paul Pfeifer for i in range(len(self._body)): 527fdd0f81fSPetar Gligoric fd_sum.write(fmt.format(*tuple(self._body[i])) + "\n") 528e76aff05SHagen Paul Pfeifer 529e76aff05SHagen Paul Pfeifer 530e76aff05SHagen Paul Pfeifer 531e76aff05SHagen Paul Pfeiferclass Task(object): 532e76aff05SHagen Paul Pfeifer """ The class is used to handle the information of a given task.""" 533e76aff05SHagen Paul Pfeifer 534e76aff05SHagen Paul Pfeifer def __init__(self, id, tid, cpu, comm): 535e76aff05SHagen Paul Pfeifer self.id = id 536e76aff05SHagen Paul Pfeifer self.tid = tid 537e76aff05SHagen Paul Pfeifer self.cpu = cpu 538e76aff05SHagen Paul Pfeifer self.comm = comm 539e76aff05SHagen Paul Pfeifer self.pid = None 540e76aff05SHagen Paul Pfeifer self._time_in = None 541e76aff05SHagen Paul Pfeifer self._time_out = None 542e76aff05SHagen Paul Pfeifer 543e76aff05SHagen Paul Pfeifer def schedule_in_at(self, time): 544e76aff05SHagen Paul Pfeifer """set the time where the task was scheduled in""" 545e76aff05SHagen Paul Pfeifer self._time_in = time 546e76aff05SHagen Paul Pfeifer 547e76aff05SHagen Paul Pfeifer def schedule_out_at(self, time): 548e76aff05SHagen Paul Pfeifer """set the time where the task was scheduled out""" 549e76aff05SHagen Paul Pfeifer self._time_out = time 550e76aff05SHagen Paul Pfeifer 551e76aff05SHagen Paul Pfeifer def time_out(self, unit="s"): 552e76aff05SHagen Paul Pfeifer """return time where a given task was scheduled out""" 553e76aff05SHagen Paul Pfeifer factor = time_uniter(unit) 554e76aff05SHagen Paul Pfeifer return self._time_out * decimal.Decimal(factor) 555e76aff05SHagen Paul Pfeifer 556e76aff05SHagen Paul Pfeifer def time_in(self, unit="s"): 557e76aff05SHagen Paul Pfeifer """return time where a given task was scheduled in""" 558e76aff05SHagen Paul Pfeifer factor = time_uniter(unit) 559e76aff05SHagen Paul Pfeifer return self._time_in * decimal.Decimal(factor) 560e76aff05SHagen Paul Pfeifer 561e76aff05SHagen Paul Pfeifer def runtime(self, unit="us"): 562e76aff05SHagen Paul Pfeifer factor = time_uniter(unit) 563e76aff05SHagen Paul Pfeifer return (self._time_out - self._time_in) * decimal.Decimal(factor) 564e76aff05SHagen Paul Pfeifer 565e76aff05SHagen Paul Pfeifer def update_pid(self, pid): 566e76aff05SHagen Paul Pfeifer self.pid = pid 567e76aff05SHagen Paul Pfeifer 568e76aff05SHagen Paul Pfeifer 569e76aff05SHagen Paul Pfeiferdef _task_id(pid, cpu): 570e76aff05SHagen Paul Pfeifer """returns a "unique-enough" identifier, please do not change""" 571e76aff05SHagen Paul Pfeifer return "{}-{}".format(pid, cpu) 572e76aff05SHagen Paul Pfeifer 573e76aff05SHagen Paul Pfeifer 574e76aff05SHagen Paul Pfeiferdef _filter_non_printable(unfiltered): 575e76aff05SHagen Paul Pfeifer """comm names may contain loony chars like '\x00000'""" 576e76aff05SHagen Paul Pfeifer filtered = "" 577e76aff05SHagen Paul Pfeifer for char in unfiltered: 578e76aff05SHagen Paul Pfeifer if char not in string.printable: 579e76aff05SHagen Paul Pfeifer continue 580e76aff05SHagen Paul Pfeifer filtered += char 581e76aff05SHagen Paul Pfeifer return filtered 582e76aff05SHagen Paul Pfeifer 583e76aff05SHagen Paul Pfeifer 584e76aff05SHagen Paul Pfeiferdef _fmt_header(): 585fdd0f81fSPetar Gligoric separator, fix_csv_align = _prepare_fmt_sep() 586fdd0f81fSPetar Gligoric fmt = "{{:>{}}}".format(LEN_SWITCHED_IN*fix_csv_align) 587fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_SWITCHED_OUT*fix_csv_align) 588fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_CPU*fix_csv_align) 589fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_PID*fix_csv_align) 590fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_TID*fix_csv_align) 591fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_COMM*fix_csv_align) 592fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_RUNTIME*fix_csv_align) 593fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_OUT_IN*fix_csv_align) 594e76aff05SHagen Paul Pfeifer if args.extended_times: 595fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_OUT_OUT*fix_csv_align) 596fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_IN_IN*fix_csv_align) 597fdd0f81fSPetar Gligoric fmt += "{}{{:>{}}}".format(separator, LEN_IN_OUT*fix_csv_align) 598e76aff05SHagen Paul Pfeifer return fmt 599e76aff05SHagen Paul Pfeifer 600e76aff05SHagen Paul Pfeifer 601e76aff05SHagen Paul Pfeiferdef _fmt_body(): 602fdd0f81fSPetar Gligoric separator, fix_csv_align = _prepare_fmt_sep() 603e76aff05SHagen Paul Pfeifer decimal_precision, time_precision = _prepare_fmt_precision() 604fdd0f81fSPetar Gligoric fmt = "{{}}{{:{}.{}f}}".format(LEN_SWITCHED_IN*fix_csv_align, decimal_precision) 605fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format( 606fdd0f81fSPetar Gligoric separator, LEN_SWITCHED_OUT*fix_csv_align, decimal_precision 607fdd0f81fSPetar Gligoric ) 608fdd0f81fSPetar Gligoric fmt += "{}{{:{}d}}".format(separator, LEN_CPU*fix_csv_align) 609fdd0f81fSPetar Gligoric fmt += "{}{{:{}d}}".format(separator, LEN_PID*fix_csv_align) 610fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:{}d}}{{}}".format(separator, LEN_TID*fix_csv_align) 611fdd0f81fSPetar Gligoric fmt += "{}{{}}{{:>{}}}".format(separator, LEN_COMM*fix_csv_align) 612fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, LEN_RUNTIME*fix_csv_align, time_precision) 613e76aff05SHagen Paul Pfeifer if args.extended_times: 614fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, LEN_OUT_IN*fix_csv_align, time_precision) 615fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, LEN_OUT_OUT*fix_csv_align, time_precision) 616fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}".format(separator, LEN_IN_IN*fix_csv_align, time_precision) 617fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}{{}}".format( 618fdd0f81fSPetar Gligoric separator, LEN_IN_OUT*fix_csv_align, time_precision 619fdd0f81fSPetar Gligoric ) 620e76aff05SHagen Paul Pfeifer else: 621fdd0f81fSPetar Gligoric fmt += "{}{{:{}.{}f}}{{}}".format( 622fdd0f81fSPetar Gligoric separator, LEN_OUT_IN*fix_csv_align, time_precision 623fdd0f81fSPetar Gligoric ) 624e76aff05SHagen Paul Pfeifer return fmt 625e76aff05SHagen Paul Pfeifer 626e76aff05SHagen Paul Pfeifer 627e76aff05SHagen Paul Pfeiferdef _print_header(): 628e76aff05SHagen Paul Pfeifer fmt = _fmt_header() 629e76aff05SHagen Paul Pfeifer header = ("Switched-In", "Switched-Out", "CPU", "PID", "TID", "Comm", "Runtime", 630e76aff05SHagen Paul Pfeifer "Time Out-In") 631e76aff05SHagen Paul Pfeifer if args.extended_times: 632e76aff05SHagen Paul Pfeifer header += ("Time Out-Out", "Time In-In", "Time In-Out") 633fdd0f81fSPetar Gligoric fd_task.write(fmt.format(*header) + "\n") 634fdd0f81fSPetar Gligoric 635e76aff05SHagen Paul Pfeifer 636e76aff05SHagen Paul Pfeifer 637e76aff05SHagen Paul Pfeiferdef _print_task_finish(task): 638e76aff05SHagen Paul Pfeifer """calculating every entry of a row and printing it immediately""" 639e76aff05SHagen Paul Pfeifer c_row_set = "" 640e76aff05SHagen Paul Pfeifer c_row_reset = "" 641e76aff05SHagen Paul Pfeifer out_in = -1 642e76aff05SHagen Paul Pfeifer out_out = -1 643e76aff05SHagen Paul Pfeifer in_in = -1 644e76aff05SHagen Paul Pfeifer in_out = -1 645e76aff05SHagen Paul Pfeifer fmt = _fmt_body() 646e76aff05SHagen Paul Pfeifer # depending on user provided highlight option we change the color 647e76aff05SHagen Paul Pfeifer # for particular tasks 648e76aff05SHagen Paul Pfeifer if str(task.tid) in args.highlight_tasks_map: 649e76aff05SHagen Paul Pfeifer c_row_set = _COLORS[args.highlight_tasks_map[str(task.tid)]] 650e76aff05SHagen Paul Pfeifer c_row_reset = _COLORS["reset"] 651e76aff05SHagen Paul Pfeifer if task.comm in args.highlight_tasks_map: 652e76aff05SHagen Paul Pfeifer c_row_set = _COLORS[args.highlight_tasks_map[task.comm]] 653e76aff05SHagen Paul Pfeifer c_row_reset = _COLORS["reset"] 654e76aff05SHagen Paul Pfeifer # grey-out entries if PID == TID, they 655e76aff05SHagen Paul Pfeifer # are identical, no threaded model so the 656e76aff05SHagen Paul Pfeifer # thread id (tid) do not matter 657e76aff05SHagen Paul Pfeifer c_tid_set = "" 658e76aff05SHagen Paul Pfeifer c_tid_reset = "" 659e76aff05SHagen Paul Pfeifer if task.pid == task.tid: 660e76aff05SHagen Paul Pfeifer c_tid_set = _COLORS["grey"] 661e76aff05SHagen Paul Pfeifer c_tid_reset = _COLORS["reset"] 662e76aff05SHagen Paul Pfeifer if task.tid in db["tid"]: 663e76aff05SHagen Paul Pfeifer # get last task of tid 664e76aff05SHagen Paul Pfeifer last_tid_task = db["tid"][task.tid][-1] 665e76aff05SHagen Paul Pfeifer # feed the timespan calculate, last in tid db 666e76aff05SHagen Paul Pfeifer # and second the current one 667e76aff05SHagen Paul Pfeifer timespan_gap_tid = Timespans() 668e76aff05SHagen Paul Pfeifer timespan_gap_tid.feed(last_tid_task) 669e76aff05SHagen Paul Pfeifer timespan_gap_tid.feed(task) 670e76aff05SHagen Paul Pfeifer out_in = timespan_gap_tid.out_in 671e76aff05SHagen Paul Pfeifer out_out = timespan_gap_tid.out_out 672e76aff05SHagen Paul Pfeifer in_in = timespan_gap_tid.in_in 673e76aff05SHagen Paul Pfeifer in_out = timespan_gap_tid.in_out 674e76aff05SHagen Paul Pfeifer 675e76aff05SHagen Paul Pfeifer 676fdd0f81fSPetar Gligoric if args.extended_times: 677fdd0f81fSPetar Gligoric line_out = fmt.format(c_row_set, task.time_in(), task.time_out(), task.cpu, 678fdd0f81fSPetar Gligoric task.pid, c_tid_set, task.tid, c_tid_reset, c_row_set, task.comm, 679fdd0f81fSPetar Gligoric task.runtime(time_unit), out_in, out_out, in_in, in_out, 680fdd0f81fSPetar Gligoric c_row_reset) + "\n" 681fdd0f81fSPetar Gligoric else: 682fdd0f81fSPetar Gligoric line_out = fmt.format(c_row_set, task.time_in(), task.time_out(), task.cpu, 683fdd0f81fSPetar Gligoric task.pid, c_tid_set, task.tid, c_tid_reset, c_row_set, task.comm, 684fdd0f81fSPetar Gligoric task.runtime(time_unit), out_in, c_row_reset) + "\n" 685fdd0f81fSPetar Gligoric try: 686fdd0f81fSPetar Gligoric fd_task.write(line_out) 687fdd0f81fSPetar Gligoric except(IOError): 688fdd0f81fSPetar Gligoric # don't mangle the output if user SIGINT this script 689fdd0f81fSPetar Gligoric sys.exit() 690fdd0f81fSPetar Gligoric 691e76aff05SHagen Paul Pfeiferdef _record_cleanup(_list): 692e76aff05SHagen Paul Pfeifer """ 693e76aff05SHagen Paul Pfeifer no need to store more then one element if --summarize 694e76aff05SHagen Paul Pfeifer is not enabled 695e76aff05SHagen Paul Pfeifer """ 696e76aff05SHagen Paul Pfeifer if not args.summary and len(_list) > 1: 697e76aff05SHagen Paul Pfeifer _list = _list[len(_list) - 1 :] 698e76aff05SHagen Paul Pfeifer 699e76aff05SHagen Paul Pfeifer 700e76aff05SHagen Paul Pfeiferdef _record_by_tid(task): 701e76aff05SHagen Paul Pfeifer tid = task.tid 702e76aff05SHagen Paul Pfeifer if tid not in db["tid"]: 703e76aff05SHagen Paul Pfeifer db["tid"][tid] = [] 704e76aff05SHagen Paul Pfeifer db["tid"][tid].append(task) 705e76aff05SHagen Paul Pfeifer _record_cleanup(db["tid"][tid]) 706e76aff05SHagen Paul Pfeifer 707e76aff05SHagen Paul Pfeifer 708e76aff05SHagen Paul Pfeiferdef _record_by_cpu(task): 709e76aff05SHagen Paul Pfeifer cpu = task.cpu 710e76aff05SHagen Paul Pfeifer if cpu not in db["cpu"]: 711e76aff05SHagen Paul Pfeifer db["cpu"][cpu] = [] 712e76aff05SHagen Paul Pfeifer db["cpu"][cpu].append(task) 713e76aff05SHagen Paul Pfeifer _record_cleanup(db["cpu"][cpu]) 714e76aff05SHagen Paul Pfeifer 715e76aff05SHagen Paul Pfeifer 716e76aff05SHagen Paul Pfeiferdef _record_global(task): 717e76aff05SHagen Paul Pfeifer """record all executed task, ordered by finish chronological""" 718e76aff05SHagen Paul Pfeifer db["global"].append(task) 719e76aff05SHagen Paul Pfeifer _record_cleanup(db["global"]) 720e76aff05SHagen Paul Pfeifer 721e76aff05SHagen Paul Pfeifer 722e76aff05SHagen Paul Pfeiferdef _handle_task_finish(tid, cpu, time, perf_sample_dict): 723e76aff05SHagen Paul Pfeifer if tid == 0: 724e76aff05SHagen Paul Pfeifer return 725e76aff05SHagen Paul Pfeifer _id = _task_id(tid, cpu) 726e76aff05SHagen Paul Pfeifer if _id not in db["running"]: 727e76aff05SHagen Paul Pfeifer # may happen, if we missed the switch to 728e76aff05SHagen Paul Pfeifer # event. Seen in combination with --exclude-perf 729e76aff05SHagen Paul Pfeifer # where the start is filtered out, but not the 730e76aff05SHagen Paul Pfeifer # switched in. Probably a bug in exclude-perf 731e76aff05SHagen Paul Pfeifer # option. 732e76aff05SHagen Paul Pfeifer return 733e76aff05SHagen Paul Pfeifer task = db["running"][_id] 734e76aff05SHagen Paul Pfeifer task.schedule_out_at(time) 735e76aff05SHagen Paul Pfeifer 736e76aff05SHagen Paul Pfeifer # record tid, during schedule in the tid 737e76aff05SHagen Paul Pfeifer # is not available, update now 738e76aff05SHagen Paul Pfeifer pid = int(perf_sample_dict["sample"]["pid"]) 739e76aff05SHagen Paul Pfeifer 740e76aff05SHagen Paul Pfeifer task.update_pid(pid) 741e76aff05SHagen Paul Pfeifer del db["running"][_id] 742e76aff05SHagen Paul Pfeifer 743e76aff05SHagen Paul Pfeifer # print only tasks which are not being filtered and no print of trace 744e76aff05SHagen Paul Pfeifer # for summary only, but record every task. 745e76aff05SHagen Paul Pfeifer if not _limit_filtered(tid, pid, task.comm) and not args.summary_only: 746e76aff05SHagen Paul Pfeifer _print_task_finish(task) 747e76aff05SHagen Paul Pfeifer _record_by_tid(task) 748e76aff05SHagen Paul Pfeifer _record_by_cpu(task) 749e76aff05SHagen Paul Pfeifer _record_global(task) 750e76aff05SHagen Paul Pfeifer 751e76aff05SHagen Paul Pfeifer 752e76aff05SHagen Paul Pfeiferdef _handle_task_start(tid, cpu, comm, time): 753e76aff05SHagen Paul Pfeifer if tid == 0: 754e76aff05SHagen Paul Pfeifer return 755e76aff05SHagen Paul Pfeifer if tid in args.tid_renames: 756e76aff05SHagen Paul Pfeifer comm = args.tid_renames[tid] 757e76aff05SHagen Paul Pfeifer _id = _task_id(tid, cpu) 758e76aff05SHagen Paul Pfeifer if _id in db["running"]: 759e76aff05SHagen Paul Pfeifer # handle corner cases where already running tasks 760e76aff05SHagen Paul Pfeifer # are switched-to again - saw this via --exclude-perf 761e76aff05SHagen Paul Pfeifer # recorded traces. We simple ignore this "second start" 762e76aff05SHagen Paul Pfeifer # event. 763e76aff05SHagen Paul Pfeifer return 764e76aff05SHagen Paul Pfeifer assert _id not in db["running"] 765e76aff05SHagen Paul Pfeifer task = Task(_id, tid, cpu, comm) 766e76aff05SHagen Paul Pfeifer task.schedule_in_at(time) 767e76aff05SHagen Paul Pfeifer db["running"][_id] = task 768e76aff05SHagen Paul Pfeifer 769e76aff05SHagen Paul Pfeifer 770e76aff05SHagen Paul Pfeiferdef _time_to_internal(time_ns): 771e76aff05SHagen Paul Pfeifer """ 772e76aff05SHagen Paul Pfeifer To prevent float rounding errors we use Decimal internally 773e76aff05SHagen Paul Pfeifer """ 774e76aff05SHagen Paul Pfeifer return decimal.Decimal(time_ns) / decimal.Decimal(1e9) 775e76aff05SHagen Paul Pfeifer 776e76aff05SHagen Paul Pfeifer 777e76aff05SHagen Paul Pfeiferdef _limit_filtered(tid, pid, comm): 778e76aff05SHagen Paul Pfeifer if args.filter_tasks: 779e76aff05SHagen Paul Pfeifer if str(tid) in args.filter_tasks or comm in args.filter_tasks: 780e76aff05SHagen Paul Pfeifer return True 781e76aff05SHagen Paul Pfeifer else: 782e76aff05SHagen Paul Pfeifer return False 783e76aff05SHagen Paul Pfeifer if args.limit_to_tasks: 784e76aff05SHagen Paul Pfeifer if str(tid) in args.limit_to_tasks or comm in args.limit_to_tasks: 785e76aff05SHagen Paul Pfeifer return False 786e76aff05SHagen Paul Pfeifer else: 787e76aff05SHagen Paul Pfeifer return True 788e76aff05SHagen Paul Pfeifer 789e76aff05SHagen Paul Pfeifer 790e76aff05SHagen Paul Pfeiferdef _argument_filter_sanity_check(): 791e76aff05SHagen Paul Pfeifer if args.limit_to_tasks and args.filter_tasks: 792e76aff05SHagen Paul Pfeifer sys.exit("Error: Filter and Limit at the same time active.") 793e76aff05SHagen Paul Pfeifer if args.extended_times and args.summary_only: 794e76aff05SHagen Paul Pfeifer sys.exit("Error: Summary only and extended times active.") 795e76aff05SHagen Paul Pfeifer if args.time_limit and ":" not in args.time_limit: 796e76aff05SHagen Paul Pfeifer sys.exit( 797e76aff05SHagen Paul Pfeifer "Error: No bound set for time limit. Please set bound by ':' e.g :123." 798e76aff05SHagen Paul Pfeifer ) 799e76aff05SHagen Paul Pfeifer if args.time_limit and (args.summary or args.summary_only or args.summary_extended): 800e76aff05SHagen Paul Pfeifer sys.exit("Error: Cannot set time limit and print summary") 801fdd0f81fSPetar Gligoric if args.csv_summary: 802fdd0f81fSPetar Gligoric args.summary = True 803fdd0f81fSPetar Gligoric if args.csv == args.csv_summary: 804fdd0f81fSPetar Gligoric sys.exit("Error: Chosen files for csv and csv summary are the same") 805fdd0f81fSPetar Gligoric if args.csv and (args.summary_extended or args.summary) and not args.csv_summary: 806fdd0f81fSPetar Gligoric sys.exit("Error: No file chosen to write summary to. Choose with --csv-summary " 807fdd0f81fSPetar Gligoric "<file>") 808fdd0f81fSPetar Gligoric if args.csv and args.summary_only: 809fdd0f81fSPetar Gligoric sys.exit("Error: --csv chosen and --summary-only. Standard task would not be" 810fdd0f81fSPetar Gligoric "written to csv file.") 811e76aff05SHagen Paul Pfeifer 812e76aff05SHagen Paul Pfeiferdef _argument_prepare_check(): 813fdd0f81fSPetar Gligoric global time_unit, fd_task, fd_sum 814e76aff05SHagen Paul Pfeifer if args.filter_tasks: 815e76aff05SHagen Paul Pfeifer args.filter_tasks = args.filter_tasks.split(",") 816e76aff05SHagen Paul Pfeifer if args.limit_to_tasks: 817e76aff05SHagen Paul Pfeifer args.limit_to_tasks = args.limit_to_tasks.split(",") 818e76aff05SHagen Paul Pfeifer if args.time_limit: 819e76aff05SHagen Paul Pfeifer args.time_limit = args.time_limit.split(":") 820e76aff05SHagen Paul Pfeifer for rename_tuple in args.rename_comms_by_tids.split(","): 821e76aff05SHagen Paul Pfeifer tid_name = rename_tuple.split(":") 822e76aff05SHagen Paul Pfeifer if len(tid_name) != 2: 823e76aff05SHagen Paul Pfeifer continue 824e76aff05SHagen Paul Pfeifer args.tid_renames[int(tid_name[0])] = tid_name[1] 825e76aff05SHagen Paul Pfeifer args.highlight_tasks_map = dict() 826e76aff05SHagen Paul Pfeifer for highlight_tasks_tuple in args.highlight_tasks.split(","): 827e76aff05SHagen Paul Pfeifer tasks_color_map = highlight_tasks_tuple.split(":") 828e76aff05SHagen Paul Pfeifer # default highlight color to red if no color set by user 829e76aff05SHagen Paul Pfeifer if len(tasks_color_map) == 1: 830e76aff05SHagen Paul Pfeifer tasks_color_map.append("red") 831e76aff05SHagen Paul Pfeifer if args.highlight_tasks and tasks_color_map[1].lower() not in _COLORS: 832e76aff05SHagen Paul Pfeifer sys.exit( 833e76aff05SHagen Paul Pfeifer "Error: Color not defined, please choose from grey,red,green,yellow,blue," 834e76aff05SHagen Paul Pfeifer "violet" 835e76aff05SHagen Paul Pfeifer ) 836e76aff05SHagen Paul Pfeifer if len(tasks_color_map) != 2: 837e76aff05SHagen Paul Pfeifer continue 838e76aff05SHagen Paul Pfeifer args.highlight_tasks_map[tasks_color_map[0]] = tasks_color_map[1] 839e76aff05SHagen Paul Pfeifer time_unit = "us" 840e76aff05SHagen Paul Pfeifer if args.ns: 841e76aff05SHagen Paul Pfeifer time_unit = "ns" 842e76aff05SHagen Paul Pfeifer elif args.ms: 843e76aff05SHagen Paul Pfeifer time_unit = "ms" 844e76aff05SHagen Paul Pfeifer 845e76aff05SHagen Paul Pfeifer 846fdd0f81fSPetar Gligoric fd_task = sys.stdout 847fdd0f81fSPetar Gligoric if args.csv: 848fdd0f81fSPetar Gligoric args.stdio_color = "never" 849fdd0f81fSPetar Gligoric fd_task = open(args.csv, "w") 850fdd0f81fSPetar Gligoric print("generating csv at",args.csv,) 851fdd0f81fSPetar Gligoric 852fdd0f81fSPetar Gligoric fd_sum = sys.stdout 853fdd0f81fSPetar Gligoric if args.csv_summary: 854fdd0f81fSPetar Gligoric args.stdio_color = "never" 855fdd0f81fSPetar Gligoric fd_sum = open(args.csv_summary, "w") 856fdd0f81fSPetar Gligoric print("generating csv summary at",args.csv_summary) 857fdd0f81fSPetar Gligoric if not args.csv: 858fdd0f81fSPetar Gligoric args.summary_only = True 859fdd0f81fSPetar Gligoric 860fdd0f81fSPetar Gligoric 861e76aff05SHagen Paul Pfeiferdef _is_within_timelimit(time): 862e76aff05SHagen Paul Pfeifer """ 863e76aff05SHagen Paul Pfeifer Check if a time limit was given by parameter, if so ignore the rest. If not, 864e76aff05SHagen Paul Pfeifer process the recorded trace in its entirety. 865e76aff05SHagen Paul Pfeifer """ 866e76aff05SHagen Paul Pfeifer if not args.time_limit: 867e76aff05SHagen Paul Pfeifer return True 868e76aff05SHagen Paul Pfeifer lower_time_limit = args.time_limit[0] 869e76aff05SHagen Paul Pfeifer upper_time_limit = args.time_limit[1] 870e76aff05SHagen Paul Pfeifer # check for upper limit 871e76aff05SHagen Paul Pfeifer if upper_time_limit == "": 872e76aff05SHagen Paul Pfeifer if time >= decimal.Decimal(lower_time_limit): 873e76aff05SHagen Paul Pfeifer return True 874e76aff05SHagen Paul Pfeifer # check for lower limit 875e76aff05SHagen Paul Pfeifer if lower_time_limit == "": 876e76aff05SHagen Paul Pfeifer if time <= decimal.Decimal(upper_time_limit): 877e76aff05SHagen Paul Pfeifer return True 878e76aff05SHagen Paul Pfeifer # quit if time exceeds upper limit. Good for big datasets 879e76aff05SHagen Paul Pfeifer else: 880e76aff05SHagen Paul Pfeifer quit() 881e76aff05SHagen Paul Pfeifer if lower_time_limit != "" and upper_time_limit != "": 882e76aff05SHagen Paul Pfeifer if (time >= decimal.Decimal(lower_time_limit) and 883e76aff05SHagen Paul Pfeifer time <= decimal.Decimal(upper_time_limit)): 884e76aff05SHagen Paul Pfeifer return True 885e76aff05SHagen Paul Pfeifer # quit if time exceeds upper limit. Good for big datasets 886e76aff05SHagen Paul Pfeifer elif time > decimal.Decimal(upper_time_limit): 887e76aff05SHagen Paul Pfeifer quit() 888e76aff05SHagen Paul Pfeifer 889e76aff05SHagen Paul Pfeiferdef _prepare_fmt_precision(): 890e76aff05SHagen Paul Pfeifer decimal_precision = 6 891e76aff05SHagen Paul Pfeifer time_precision = 3 892e76aff05SHagen Paul Pfeifer if args.ns: 893e76aff05SHagen Paul Pfeifer decimal_precision = 9 894e76aff05SHagen Paul Pfeifer time_precision = 0 895e76aff05SHagen Paul Pfeifer return decimal_precision, time_precision 896e76aff05SHagen Paul Pfeifer 897fdd0f81fSPetar Gligoricdef _prepare_fmt_sep(): 898fdd0f81fSPetar Gligoric separator = " " 899fdd0f81fSPetar Gligoric fix_csv_align = 1 900fdd0f81fSPetar Gligoric if args.csv or args.csv_summary: 901fdd0f81fSPetar Gligoric separator = ";" 902fdd0f81fSPetar Gligoric fix_csv_align = 0 903fdd0f81fSPetar Gligoric return separator, fix_csv_align 904e76aff05SHagen Paul Pfeifer 905e76aff05SHagen Paul Pfeiferdef trace_unhandled(event_name, context, event_fields_dict, perf_sample_dict): 906e76aff05SHagen Paul Pfeifer pass 907e76aff05SHagen Paul Pfeifer 908e76aff05SHagen Paul Pfeifer 909e76aff05SHagen Paul Pfeiferdef trace_begin(): 910e76aff05SHagen Paul Pfeifer _parse_args() 911e76aff05SHagen Paul Pfeifer _check_color() 912e76aff05SHagen Paul Pfeifer _init_db() 913e76aff05SHagen Paul Pfeifer if not args.summary_only: 914e76aff05SHagen Paul Pfeifer _print_header() 915e76aff05SHagen Paul Pfeifer 916e76aff05SHagen Paul Pfeiferdef trace_end(): 917e76aff05SHagen Paul Pfeifer if args.summary or args.summary_extended or args.summary_only: 918e76aff05SHagen Paul Pfeifer Summary().print() 919e76aff05SHagen Paul Pfeifer 920e76aff05SHagen Paul Pfeiferdef sched__sched_switch(event_name, context, common_cpu, common_secs, common_nsecs, 921e76aff05SHagen Paul Pfeifer common_pid, common_comm, common_callchain, prev_comm, 922e76aff05SHagen Paul Pfeifer prev_pid, prev_prio, prev_state, next_comm, next_pid, 923e76aff05SHagen Paul Pfeifer next_prio, perf_sample_dict): 924e76aff05SHagen Paul Pfeifer # ignore common_secs & common_nsecs cause we need 925e76aff05SHagen Paul Pfeifer # high res timestamp anyway, using the raw value is 926e76aff05SHagen Paul Pfeifer # faster 927e76aff05SHagen Paul Pfeifer time = _time_to_internal(perf_sample_dict["sample"]["time"]) 928e76aff05SHagen Paul Pfeifer if not _is_within_timelimit(time): 929e76aff05SHagen Paul Pfeifer # user specific --time-limit a:b set 930e76aff05SHagen Paul Pfeifer return 931e76aff05SHagen Paul Pfeifer 932e76aff05SHagen Paul Pfeifer next_comm = _filter_non_printable(next_comm) 933e76aff05SHagen Paul Pfeifer _handle_task_finish(prev_pid, common_cpu, time, perf_sample_dict) 934e76aff05SHagen Paul Pfeifer _handle_task_start(next_pid, common_cpu, next_comm, time) 935