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