From 0482a607bcd156e327e0bad22a1cb008e5e74878 Mon Sep 17 00:00:00 2001 From: Jeff Roberson Date: Wed, 24 Jan 2007 21:19:56 +0000 Subject: [PATCH] - Add a horrible bit of code to detect tsc differences between processors. This only works if there is no significant drift and all processors are running at the same frequency. Fortunately, schedgraph traces on MP machines tend to cover less than a second so drift shouldn't be an issue. - KTRFile::synchstamp() iterates once over the whole list to determine the lowest tsc value and syncs adjusts all other values to match. We assume that the first tick recorded on all cpus happened at the same instant to start with. - KTRFile::monostamp() iterates again over the whole file and checks for a cpu agnostic monotonically increasing clock. If the time ever goes backwards the cpu responsible is adjusted further to fit. This will make the possible incorrect delta between cpus as small as the shortest time between two events. This time can be fairly large due to sched_lock essentially protecting all events. - KTRFile::checkstamp() now returns an adjusted timestamp. - StateEvent::draw() detects states that occur out of order in time and draws them as 0 pixels after printing a warning. --- tools/sched/schedgraph.py | 140 ++++++++++++++++++++++++++++++-------- 1 file changed, 112 insertions(+), 28 deletions(-) diff --git a/tools/sched/schedgraph.py b/tools/sched/schedgraph.py index 1bd031b7db81..3c26f941fb46 100644 --- a/tools/sched/schedgraph.py +++ b/tools/sched/schedgraph.py @@ -64,7 +64,8 @@ class Scaler(Frame): def __init__(self, master, target): Frame.__init__(self, master) self.scale = Scale(self, command=self.scaleset, - from_=1000, to_=1000000, orient=HORIZONTAL, resolution=1000) + from_=1000, to_=10000000, orient=HORIZONTAL, + resolution=1000) self.label = Label(self, text="Ticks per pixel") self.label.pack(side=LEFT) self.scale.pack(fill="both", expand=1) @@ -410,6 +411,11 @@ class StateEvent(Event): next = skipped self.skipnext -= 1 self.duration = next.timestamp - self.timestamp + if (self.duration < 0): + self.duration = 0 + print "Unsynchronized timestamp" + print self.cpu, self.timestamp + print next.cpu, next.timestamp delta = self.duration / canvas.ratio l = canvas.create_rectangle(xpos, ypos, xpos + delta, ypos - 10, fill=self.color, width=0, @@ -813,22 +819,27 @@ class Counter(EventSource): class KTRFile: def __init__(self, file): - self.timestamp_first = None - self.timestamp_last = None + self.timestamp_first = {} + self.timestamp_last = {} + self.timestamp_adjust = {} + self.timestamp_f = None + self.timestamp_l = None self.lineno = -1 self.threads = [] self.sources = [] self.ticks = {} self.load = {} self.crit = {} + self.stathz = 0 self.parse(file) self.fixup() global ticksps - ticksps = self.ticksps() - print "Ticks per second", ticksps, "timespan", self.timespan() + print "first", self.timestamp_f, "last", self.timestamp_l + print "time span", self.timespan() print "stathz", self.stathz - print "first", self.timestamp_first, "last", self.timestamp_last + ticksps = self.ticksps() + print "Ticks per second", ticksps def parse(self, file): try: @@ -895,7 +906,9 @@ class KTRFile: [critsec_re, self.critsec], [idled_re, self.idled]] - for line in ifp.readlines(): + lines = ifp.readlines() + self.synchstamp(lines) + for line in lines: self.lineno += 1 if ((self.lineno % 1024) == 0): status.startup("Parsing line " + @@ -908,18 +921,77 @@ class KTRFile: # if (m == None): # print line, - def checkstamp(self, timestamp): + def synchstamp(self, lines): + status.startup("Rationalizing Timestamps") + tstamp_re = re.compile("\s+\d+\s+(\d+)\s+(\d+)\s+.*") + for line in lines: + m = tstamp_re.match(line) + if (m != None): + self.addstamp(*m.groups()) + self.pickstamp() + self.monostamp(lines) + + + def monostamp(self, lines): + laststamp = None + tstamp_re = re.compile("\s+\d+\s+(\d+)\s+(\d+)\s+.*") + for line in lines: + m = tstamp_re.match(line) + if (m == None): + continue + (cpu, timestamp) = m.groups() + timestamp = int(timestamp) + cpu = int(cpu) + timestamp -= self.timestamp_adjust[cpu] + if (laststamp != None and timestamp > laststamp): + self.timestamp_adjust[cpu] += timestamp - laststamp + laststamp = timestamp + + def addstamp(self, cpu, timestamp): timestamp = int(timestamp) - if (self.timestamp_first == None): - self.timestamp_first = timestamp - if (timestamp > self.timestamp_first): + cpu = int(cpu) + try: + if (timestamp > self.timestamp_first[cpu]): + return + except: + self.timestamp_first[cpu] = timestamp + self.timestamp_last[cpu] = timestamp + + def pickstamp(self): + base = self.timestamp_last[0] + for i in range(0, len(self.timestamp_last)): + if (self.timestamp_last[i] < base): + base = self.timestamp_last[i] + + print "Adjusting to base stamp", base + for i in range(0, len(self.timestamp_last)): + self.timestamp_adjust[i] = self.timestamp_last[i] - base; + print "CPU ", i, "adjust by ", self.timestamp_adjust[i] + + self.timestamp_f = 0 + for i in range(0, len(self.timestamp_first)): + first = self.timestamp_first[i] - self.timestamp_adjust[i] + if (first > self.timestamp_f): + self.timestamp_f = first + + self.timestamp_l = 0 + for i in range(0, len(self.timestamp_last)): + last = self.timestamp_last[i] - self.timestamp_adjust[i] + if (last > self.timestamp_l): + self.timestamp_l = last + + + def checkstamp(self, cpu, timestamp): + cpu = int(cpu) + timestamp = int(timestamp) + if (timestamp > self.timestamp_first[cpu]): print "Bad timestamp on line ", self.lineno return (0) - self.timestamp_last = timestamp - return (1) + timestamp -= self.timestamp_adjust[cpu] + return (timestamp) def timespan(self): - return (self.timestamp_first - self.timestamp_last); + return (self.timestamp_f - self.timestamp_l); def ticksps(self): return (self.timespan() / self.ticks[0]) * int(self.stathz) @@ -931,7 +1003,8 @@ class KTRFile: TDI_LOCK = 0x0008 TDI_IWAIT = 0x0010 - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return inhibit = int(inhibit) thread = self.findtd(td, pcomm) @@ -952,26 +1025,30 @@ class KTRFile: sys.exit(1) def idled(self, cpu, timestamp, td, pcomm, prio): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) Idle(thread, cpu, timestamp, prio) def preempted(self, cpu, timestamp, td, pcomm, prio, bytd, bypcomm): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) Preempted(thread, cpu, timestamp, prio, self.findtd(bytd, bypcomm)) def switchin(self, cpu, timestamp, td, pcomm, prio): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) Running(thread, cpu, timestamp, prio) def sched_add(self, cpu, timestamp, td, pcomm, prio, bytd, bypcomm): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) bythread = self.findtd(bytd, bypcomm) @@ -979,20 +1056,23 @@ class KTRFile: Wokeup(bythread, cpu, timestamp, thread) def sched_rem(self, cpu, timestamp, td, pcomm, prio, bytd, bypcomm): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) KsegrpRunq(thread, cpu, timestamp, prio, self.findtd(bytd, bypcomm)) def sched_exit(self, cpu, timestamp, td, pcomm, prio): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) Sched_exit(thread, cpu, timestamp, prio) def sched_clock(self, cpu, timestamp, td, pcomm, prio, stathz): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return self.stathz = stathz cpu = int(cpu) @@ -1007,7 +1087,8 @@ class KTRFile: def sched_prio(self, cpu, timestamp, td, pcomm, prio, newprio, bytd, bypcomm): if (prio == newprio): return - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return thread = self.findtd(td, pcomm) bythread = self.findtd(bytd, bypcomm) @@ -1015,7 +1096,8 @@ class KTRFile: Lend(bythread, cpu, timestamp, newprio, thread) def cpuload(self, cpu, timestamp, count): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return cpu = int(cpu) try: @@ -1027,7 +1109,8 @@ class KTRFile: Count(load, cpu, timestamp, count) def loadglobal(self, cpu, timestamp, count): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return cpu = 0 try: @@ -1039,7 +1122,8 @@ class KTRFile: Count(load, cpu, timestamp, count) def critsec(self, cpu, timestamp, td, pcomm, to): - if (self.checkstamp(timestamp) == 0): + timestamp = self.checkstamp(cpu, timestamp) + if (timestamp == 0): return cpu = int(cpu) try: @@ -1061,8 +1145,8 @@ class KTRFile: def fixup(self): for source in self.sources: - Padevent(source, -1, self.timestamp_last) - Padevent(source, -1, self.timestamp_first, last=1) + Padevent(source, -1, self.timestamp_l) + Padevent(source, -1, self.timestamp_f, last=1) source.fixup() class SchedDisplay(Canvas):