#!/usr/bin/python # # Copyright (c) 2016 Intel Corporation. # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 # # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. # # 2 possible algos: at each new timestamp, update run/queue/sleep time for all threads vs update # only the right process. 2nd algo is still easy # because we have duration of this state. # this presents run, queued, sleep time of processes sorted by run time. REL time starts when # process was created while ABS time if from beginning. Therefore elapsed time between start and # process creation is added as sleep time import os, sys, re from collections import defaultdict from operator import itemgetter from optparse import OptionParser class FilterTrace: def __init__(self): self.compiled_regexp = [] self.pid_names = {} self.run_time = defaultdict(int) # total run-time per tid self.queued_time = defaultdict(int) self.sleep_time = defaultdict(int) self.ctxswitch_run_times0 = defaultdict(int) self.ctxswitch_run_times1 = defaultdict(int) self.timestamp_current = 0 self.convert = 1.0 / 1000 self.timestamp_start = 0 # must be >= self.timestamp_end = 0 # must be <=, but if > to last context switch, will go until # Last timestamp only self.runqueue_threads_only = False # see options help REGEXP_GLOSSARY = [ # backup rule ['^.*psel.*$', None], ['^(?P\d+)\s+(?P\d+)\s+(?P[\w \.#-_/]+):(?P-?\d+)' \ '\s+(?P\w+)\s+(?P\d+).*$', self.callback_context_switch], ['^Last timestamp:\s*(?P\d+).*$', self.callback_end], ['^.*$', self.callback_no_rule] ] # Compile all regexp for regexp_string, regexp_rules in REGEXP_GLOSSARY: self.compiled_regexp.append([re.compile(regexp_string), regexp_rules]) def filter_line(self, line): # Parse all regexps for regexp, regexp_rules in self.compiled_regexp: # Test if regexp matches res = regexp.search(line) # if regexp match if res: # Execute regexp_rules if regexp_rules: regexp_rules(res, line) # Only one regexp per line break def callback_context_switch(self, res, line): timestamp_current = int(res.group('timestamp')) # end boundary if (timestamp_current >= self.timestamp_end): return duration = int(res.group('duration')) # wait to reach timestamp_start before processing if (timestamp_current < self.timestamp_start): # thread will keep this state until start boundary so count this time if ((timestamp_current + duration) > self.timestamp_start): # remove time before start boundary duration = timestamp_current + duration - self.timestamp_start timestamp_current = self.timestamp_start else: return # if process goes beyond end, remove time after end if (duration > (self.timestamp_end - timestamp_current)): duration = self.timestamp_end - timestamp_current tid = int(res.group('tid')) if (res.group('state') == 'R'): self.run_time[tid] += duration if (int(res.group('cpu_id')) == 0): self.ctxswitch_run_times0[tid] += 1 else: self.ctxswitch_run_times1[tid] += 1 elif (res.group('state') == 'Q'): self.queued_time[tid] += duration elif ((res.group('state') == 'S') or (res.group('state') == 'X')): self.sleep_time[tid] += duration self.pid_names[tid] = res.group('task_name').rstrip(' ') def callback_no_rule(self, res, line): return def callback_end(self, res, line): max_sum = 0 # we capture the process that started the first in order to get the sum for the % and set # START time at 0 for tid in self.pid_names: sum = self.run_time[tid] + self.sleep_time[tid] + self.queued_time[tid] if sum > max_sum: max_sum = sum print("%-16s:%-10s %-10s %-10s %-10s %-10s %-10s %-7s" \ " %-7s %-7s %-7s %-7s %-7s %7s %7s %8s") % ( "PID_NAME", "TID", "RUNNING", "SLEEPING", "QUEUED", "SUM", "START", "%R_ABS", "%S_ABS", "%Q_ABS", "%R_REL", "%S_REL", "%Q_REL", "N_RUN_0", "N_RUN_1", "N_RUN") items = self.run_time.items() items.sort(key = itemgetter(1), reverse=True) # inverse key and value to sort by value for tid, v in items: if ((not self.runqueue_threads_only) or ((self.run_time[tid] != 0) or (self.queued_time[tid] != 0))): rel_sum = self.run_time[tid] + self.sleep_time[tid] + self.queued_time[tid] print("%-16s:%-10d %-10d %-10d %-10d %-10d %-10d %7.3f %7.3f %7.3f %7.3f" \ " %7.3f %7.3f %7d %7d %8d") % ( \ self.pid_names[tid], tid, self.run_time[tid], self.sleep_time[tid], self.queued_time[tid], rel_sum, # script execution time - start time of process max_sum - rel_sum, # start time of process self.run_time[tid] * 100.0 / max_sum, # ABS R time # ABS sleep time, start time is counted as sleep time (self.sleep_time[tid] + max_sum - rel_sum) * 100.0 / max_sum, self.queued_time[tid] * 100.0 / max_sum, # ABS Q time self.run_time[tid] * 100.0 / rel_sum, # REL R time self.sleep_time[tid] * 100.0 / rel_sum, # REL S time self.queued_time[tid] * 100.0 / rel_sum, # REL Q time self.ctxswitch_run_times0[tid], self.ctxswitch_run_times1[tid], self.ctxswitch_run_times0[tid] + self.ctxswitch_run_times1[tid] ) global filterMaster filterMaster = FilterTrace() def Main(argv): usage = "Usage: %prog FILENAME [options]" parser = OptionParser(usage = usage) parser.add_option("-s", "--start", action="store", type="int", dest="start", default=0, help="Start time of analysis in relative ms") parser.add_option("-e", "--end", action="store", type="int", dest="end", default=1000000000, help="End time of analysis in relative ms") parser.add_option("-r", "--runqueue_threads_only", action="store_true", dest="runqueue_threads_only", default=False, help="Display only threads with some running time") (options, args) = parser.parse_args() filterMaster.timestamp_start = int(options.start / filterMaster.convert) filterMaster.timestamp_end = int(options.end / filterMaster.convert) filterMaster.runqueue_threads_only = options.runqueue_threads_only if len(args) != 1: print "Usage: type python .py -h" return file = open(args[0], 'r') string = file.readline() # search for regexp while (string ): filterMaster.filter_line(string) string = file.readline() if __name__=="__main__": Main(sys.argv[1:])