Add support for two new event source types:

- Callwheels traced via KTR_CALLOUT.  Each CPU is assigned a callwheel
  source.  The events on this source are the execution of individual callout
  routines.  Each routine shows up as a green rectangle while it is executed
  and the event details include the function pointer and argument.
- Locks traced via KTR_LOCK.  Currently, each lock name is assigned an event
  source (since the existing KTR_LOCK traces only include lock names and
  not pointers).  This does mean that if multiple locks of the same name are
  manipulated, the source line for that name may be confusing.  However, for
  many cases this can be useful.  Locks are blue when they are held and
  purple when contested.  The contention support is a bit weak due to
  limitations in the rw_rlock() and mtx_lock_spin() logging messages
  currently.  I also have not added support for contention on lockmgr,
  sx, or rmlocks yet.  What is there now can be profitably used to examine
  activity on Giant however.
- Expand the width of the event source names column a bit to allow for some
  of the longer names of these new source types.

1 files changed, 224 insertions, 2 deletions

diff --git a/tools/sched/schedgraph.py b/tools/sched/schedgraph.py
index 87a1c89..d217941 100644
--- a/tools/sched/schedgraph.py
+++ b/tools/sched/schedgraph.py
@@ -672,6 +672,86 @@ class Sched_exit(StateEvent):
 
 configtypes.append(Sched_exit)
 
+# Events for running callout routines
+
+class CalloutIdle(StateEvent):
+	name = "callwheel idle"
+	color = "grey"
+	enabled = 0
+	def __init__(self, wheel, cpu, timestamp):
+		StateEvent.__init__(self, wheel, cpu, timestamp)
+
+configtypes.append(CalloutIdle)
+
+class CalloutRunning(StateEvent):
+	name = "callout running"
+	color = "green"
+	enabled = 1
+	def __init__(self, wheel, cpu, timestamp, func, arg):
+		StateEvent.__init__(self, wheel, cpu, timestamp)
+		self.textadd(("function:", func, 0))
+		self.textadd(("argument:", arg, 0))
+		self.arg = arg
+		self.func = func
+
+	def stattxt(self):
+		statstr = StateEvent.stattxt(self)
+		statstr += " executing %s(%s)" % (self.func, self.arg)
+		return (statstr)
+
+configtypes.append(CalloutRunning)
+
+# Events on locks
+#
+# XXX: No support for upgrade/downgrade currently or differentiating
+# between read/write in general.
+#
+# XXX: Point events for recursion perhaps?
+
+class LockAcquire(StateEvent):
+	name = "lock acquire"
+	color = "blue"
+	enabled = 1
+	def __init__(self, lock, cpu, timestamp, file, line):
+		StateEvent.__init__(self, lock, cpu, timestamp)
+		self.textadd(("file:", file, 0))
+		self.textadd(("line:", line, 0))
+
+configtypes.append(LockAcquire)
+
+class LockContest(StateEvent):
+	name = "lock contest"
+	color = "purple"
+	enabled = 1
+	def __init__(self, lock, cpu, timestamp, file, line):
+		StateEvent.__init__(self, lock, cpu, timestamp)
+		self.textadd(("file:", file, 0))
+		self.textadd(("line:", line, 0))
+
+configtypes.append(LockContest)
+
+class LockFailedTry(PointEvent):
+	name = "failed lock try"
+	color = "red"
+	enabled = 1
+	def __init__(self, lock, cpu, timestamp, file, line):
+		PointEvent.__init__(self, lock, cpu, timestamp)
+		self.textadd(("file:", file, 0))
+		self.textadd(("line:", line, 0))
+
+configtypes.append(LockFailedTry)
+
+class LockRelease(StateEvent):
+	name = "lock release"
+	color = "grey"
+	enabled = 0
+	def __init__(self, lock, cpu, timestamp, file, line):
+		StateEvent.__init__(self, lock, cpu, timestamp)
+		self.textadd(("file:", file, 0))
+		self.textadd(("line:", line, 0))
+
+configtypes.append(LockRelease)
+
 class Padevent(StateEvent):
 	def __init__(self, thread, cpu, timestamp, last=0):
 		StateEvent.__init__(self, thread, cpu, timestamp, last)
@@ -739,7 +819,7 @@ class Wokeup(PointEvent):
 
 configtypes.append(Wokeup)
 
-(DEFAULT, LOAD, COUNT, THREAD) = range(4)
+(DEFAULT, LOAD, COUNT, CALLWHEEL, LOCK, THREAD) = range(6)
 
 class EventSource:
 	def __init__(self, name, group=DEFAULT, order=0):
@@ -852,6 +932,29 @@ class Thread(EventSource):
 	def ysize(self):
 		return (10)
 
+class Callwheel(EventSource):
+	count = 0
+	def __init__(self, cpu):
+		EventSource.__init__(self, "Callwheel", CALLWHEEL, cpu)
+		self.wheel = cpu
+		Callwheel.count += 1
+
+	def fixup(self):
+		EventSource.fixup(self)
+		if (Callwheel.count == 1):
+			return
+		self.name += " (CPU %d)" % (self.wheel)
+
+	def ysize(self):
+		return (10)
+
+class Lock(EventSource):
+	def __init__(self, lock):
+		EventSource.__init__(self, lock, LOCK)
+
+	def ysize(self):
+		return (10)
+
 class Counter(EventSource):
 	max = 0
 	def __init__(self, name):
@@ -888,6 +991,8 @@ class KTRFile:
 		self.timestamp_l = None
 		self.threads = []
 		self.sources = []
+		self.locks = {}
+		self.callwheels = {}
 		self.ticks = {}
 		self.load = {}
 		self.crit = {}
@@ -959,6 +1064,46 @@ class KTRFile:
 		ktrstr = "critical_\S+ by thread " + crittdname + " to (\d+)"
 		critsec_re = re.compile(ktrhdr + ktrstr)
 
+		ktrstr = "callout 0x[a-f\d]+ "
+		ktrstr += "func (0x[a-f\d]+) arg (0x[a-f\d]+)"
+		callout_start_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "callout mpsafe 0x[a-f\d]+ "
+		ktrstr += "func (0x[a-f\d]+) arg (0x[a-f\d]+)"
+		callout_mpsafe_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "callout mtx 0x[a-f\d]+ "
+		ktrstr += "func (0x[a-f\d]+) arg (0x[a-f\d]+)"
+		callout_mtx_re = re.compile(ktrhdr + ktrstr)
+		
+		ktrstr = "callout 0x[a-f\d]+ finished"
+		callout_stop_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "TRY_([RSWX]?LOCK) \(.*\) (.*) r = ([0-9]+)"
+		ktrstr += " at (?:\.\./)*(.*):([0-9]+)"
+		lock_try_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "([RSWX]?UNLOCK) \(.*\) (.*) r = ([0-9]+)"
+		ktrstr += " at (?:\.\./)*(.*):([0-9]+)"
+		lock_release_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "([RSWX]?LOCK) \(.*\) (.*) r = ([0-9]+)"
+		ktrstr += " at (?:\.\./)*(.*):([0-9]+)"
+		lock_acquire_re = re.compile(ktrhdr + ktrstr)
+
+		ktrstr = "_mtx_lock_sleep: (.*) contested \(lock=0x?[0-9a-f]*\)"
+		ktrstr += " at (?:\.\./)*(.*):([0-9]+)"
+		mtx_contested_re = re.compile(ktrhdr + ktrstr)
+
+		# XXX: Spin lock traces don't have lock name or file/line
+
+		ktrstr = "_rw_wlock_hard: (.*) contested \(lock=0x?[0-9a-f]*\)"
+		ktrstr += " at (?:\.\./)*(.*):([0-9]+)"
+		rw_contested_re = re.compile(ktrhdr + ktrstr)
+
+		# XXX: Read lock traces for rwlocks contesting don't have
+		# lock name or file/line		
+		
 		parsers = [[cpuload_re, self.cpuload],
 			   [cpuload2_re, self.cpuload2],
 			   [loadglobal_re, self.loadglobal],
@@ -973,6 +1118,15 @@ class KTRFile:
 			   [sched_exit_re, self.sched_exit],
 			   [sched_clock_re, self.sched_clock],
 			   [critsec_re, self.critsec],
+			   [callout_start_re, self.callout_start],
+			   [callout_mpsafe_re, self.callout_start],
+			   [callout_mtx_re, self.callout_start],
+			   [callout_stop_re, self.callout_stop],
+			   [lock_try_re, self.lock_try],
+			   [lock_release_re, self.lock_release],
+			   [lock_acquire_re, self.lock_acquire],
+			   [mtx_contested_re, self.lock_contest],
+			   [rw_contested_re, self.lock_contest],
 			   [idled_re, self.idled]]
 
 		global lineno
@@ -1162,6 +1316,74 @@ class KTRFile:
 			self.sources.append(crit)
 		Count(crit, cpu, timestamp, to)
 
+	def callout_start(self, cpu, timestamp, func, arg):
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		wheel = self.findwheel(cpu)
+		CalloutRunning(wheel, cpu, timestamp, func, arg)
+
+	def callout_stop(self, cpu, timestamp):
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		wheel = self.findwheel(cpu)
+		CalloutIdle(wheel, cpu, timestamp)
+
+	def lock_try(self, cpu, timestamp, op, name, result, file, line):
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		lock = self.findlock(name)
+		if (int(result) == 0):
+			LockFailedTry(lock, cpu, timestamp, file, line)
+		else:
+			LockAcquire(lock, cpu, timestamp, file, line)
+
+	def lock_acquire(self, cpu, timestamp, op, name, recurse, file, line):
+		if (int(recurse) != 0):
+			return
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		lock = self.findlock(name)
+		LockAcquire(lock, cpu, timestamp, file, line)
+		
+	def lock_release(self, cpu, timestamp, op, name, recurse, file, line):
+		if (int(recurse) != 0):
+			return
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		lock = self.findlock(name)
+		LockRelease(lock, cpu, timestamp, file, line)
+
+	def lock_contest(self, cpu, timestamp, name, file, line):
+		timestamp = self.checkstamp(cpu, timestamp)
+		if (timestamp == 0):
+			return
+		lock = self.findlock(name)
+		LockContest(lock, cpu, timestamp, file, line)
+
+	def findlock(self, name):
+		try:
+			lock = self.locks[name]
+		except:
+			lock = Lock(name)
+			self.locks[name] = lock
+			self.sources.append(lock)
+		return (lock)
+
+	def findwheel(self, cpu):
+		cpu = int(cpu)
+		try:
+			wheel = self.callwheels[cpu]
+		except:
+			wheel = Callwheel(cpu)
+			self.callwheels[cpu] = wheel
+			self.sources.append(wheel)
+		return (wheel)
+
 	def findtd(self, td, pcomm):
 		for thread in self.threads:
 			if (thread.str == td and thread.name == pcomm):
@@ -1325,7 +1547,7 @@ class SchedGraph(Frame):
 		self.menu = GraphMenu(self)
 		self.display = SchedDisplay(self)
 		self.names = Canvas(self,
-		    width=100, height=self.display["height"],
+		    width=120, height=self.display["height"],
 		    bg='grey', scrollregion=(0, 0, 50, 100))
 		self.scale = Scaler(self, self.display)
 		status = self.status = Status(self)