support task profiling in new task manager

direct/src/showbase/ShowBase.py

@@ -367,12 +367,11 @@ class ShowBase(DirectObject.DirectObject):
         if self.windowType != 'none':
             self.__doStartDirect()
 
-
+        if config.GetBool('want-garbage-collect-task', 1):
-        self._wantGcTask = config.GetBool('want-garbage-collect-task', 1)
-        self._gcTask = None
-        if self._wantGcTask:
             # manual garbage-collect task
-            self._gcTask = taskMgr.add(self._garbageCollect, self.GarbageCollectTaskName, 200)
+            taskMgr.add(self._garbageCollect, self.GarbageCollectTaskName, 200)
+            
+        taskMgr.finalInit()
 
         # Start IGLOOP
         self.restart()
@@ -417,10 +416,6 @@ class ShowBase(DirectObject.DirectObject):
 
         This function is designed to be safe to call multiple times."""
 
-        if self._gcTask:
-            self._gcTask.remove()
-            self._gcTask = None
-
         taskMgr.destroy()
 
         if getattr(self, 'musicManager', None):

direct/src/task/TaskNew.py

@@ -8,9 +8,13 @@ __all__ = ['Task', 'TaskManager',
 
 from direct.directnotify.DirectNotifyGlobal import *
 from direct.showbase import ExceptionVarDump
+from direct.showbase.PythonUtil import *
+from direct.showbase.ProfileSession import ProfileSession
 import signal
 import types
 import time
+import random
+import string
 
 from pandac.PandaModules import *
 
@@ -107,6 +111,24 @@ class TaskManager:
         self.fKeyboardInterrupt = False
         self.interruptCount = 0
 
+        self._profileFrames = False
+
+        # this will be set when it's safe to import StateVar
+        self._profileTasks = None
+        self._taskProfiler = None
+        self._profileInfo = ScratchPad(
+            taskId = None,
+            profiled = False,
+            session = None,
+            )
+
+    def finalInit(self):
+        # This function should be called once during startup, after
+        # most things are imported.
+        from direct.fsm.StatePush import StateVar
+        self._profileTasks = StateVar(False)
+        self.setProfileTasks(ConfigVariableBool('profile-task-spikes', 0).getValue())
+
     def destroy(self):
         self.mgr.cleanup()
 
@@ -419,6 +441,10 @@ class TaskManager:
             self.running = True
             while self.running:
                 try:
+                    if self._profileFrames:
+                        self._profileFrames = False
+                        self._doProfiledFrames()
+                    else:
                         self.step()
                 except KeyboardInterrupt:
                     self.stop()
@@ -496,6 +522,125 @@ class TaskManager:
         from direct.tkpanels import TaskManagerPanel
         return TaskManagerPanel.TaskManagerPanel(self)
 
+    def profileFrames(self, num=None):
+        self._profileFrames = True
+        if num is None:
+            num = 1
+        self._profileFrameCount = num
+
+    @profiled()
+    def _doProfiledFrames(self, *args, **kArgs):
+        print '** profiling %s frames' % self._profileFrameCount
+        for i in xrange(self._profileFrameCount):
+            result = self.step(*args, **kArgs)
+        return result
+
+    def getProfileTasks(self):
+        return self._profileTasks.get()
+
+    def getProfileTasksSV(self):
+        return self._profileTasks
+
+    def setProfileTasks(self, profileTasks):
+        self._profileTasks.set(profileTasks)
+        if (not self._taskProfiler) and profileTasks:
+            # import here due to import dependencies
+            from direct.task.TaskProfiler import TaskProfiler
+            self._taskProfiler = TaskProfiler()
+
+    def logTaskProfiles(self, name=None):
+        if self._taskProfiler:
+            self._taskProfiler.logProfiles(name)
+
+    def flushTaskProfiles(self, name=None):
+        if self._taskProfiler:
+            self._taskProfiler.flush(name)
+
+    def _setProfileTask(self, task):
+        if self._profileInfo.session:
+            self._profileInfo.session.release()
+            self._profileInfo.session = None
+        self._profileInfo = ScratchPad(
+            taskFunc = task.getFunction(),
+            taskArgs = task.getArgs(),
+            task = task,
+            profiled = False,
+            session = None,
+            )
+
+        # Temporarily replace the task's own function with our
+        # _profileTask method.
+        task.setFunction(self._profileTask)
+        task.setArgs([self._profileInfo], True)
+
+    def _profileTask(self, profileInfo, task):
+        # This is called instead of the task function when we have
+        # decided to profile a task.
+
+        assert profileInfo.task == task
+        # don't profile the same task twice in a row
+        assert not profileInfo.profiled
+
+        # Restore the task's proper function for next time.
+        appendTask = False
+        taskArgs = profileInfo.taskArgs
+        if taskArgs and taskArgs[-1] == task:
+            appendTask = True
+            taskArgs = taskArgs[:-1]
+        task.setArgs(taskArgs, appendTask)
+        task.setFunction(profileInfo.taskFunc)
+
+        profileSession = ProfileSession(Functor(profileInfo.taskFunc, *profileInfo.taskArgs),
+                                        'profiled-task-%s' % task.getName())
+        ret = profileSession.run()
+
+        # set these values *after* profiling in case we're profiling the TaskProfiler
+        profileInfo.session = profileSession
+        profileInfo.profiled = True
+
+        return ret
+
+    def _hasProfiledDesignatedTask(self):
+        # have we run a profile of the designated task yet?
+        return self._profileInfo.profiled
+
+    def _getLastProfileSession(self):
+        return self._profileInfo.session
+
+    def _getRandomTask(self):
+        tasks = self.mgr.getActiveTasks()
+        numTasks = tasks.getNumTasks()
+        doLaters = self.mgr.getSleepingTasks()
+        numDoLaters = doLaters.getNumTasks()
+        if random.random() < (numDoLaters / float(numTasks + numDoLaters)):
+            # grab a doLater that will most likely trigger in the next frame
+            tNow = globalClock.getFrameTime()
+            avgFrameRate = globalClock.getAverageFrameRate()
+            if avgFrameRate < .00001:
+                avgFrameDur = 0.
+            else:
+                avgFrameDur = (1. / globalClock.getAverageFrameRate())
+            tNext = tNow + avgFrameDur
+            # binary search to find doLaters that are likely to trigger on the next frame
+            curIndex = int(numDoLaters / 2)
+            rangeStart = 0
+            rangeEnd = numDoLaters
+            while True:
+                if tNext < doLaters[curIndex].wakeTime:
+                    rangeEnd = curIndex
+                else:
+                    rangeStart = curIndex
+                prevIndex = curIndex
+                curIndex = int((rangeStart + rangeEnd) / 2)
+                if curIndex == prevIndex:
+                    break
+            index = curIndex
+            task = doLaters[random.randrange(index+1)]
+        else:
+            # grab a task
+            task = tasks[random.randint(0, numTasks - 1)]
+        return task
+
     def __repr__(self):
         return str(self.mgr)
 

direct/src/task/TaskOrig.py

@@ -190,6 +190,25 @@ class Task:
             taskName = self.name
         return ''.join([c for c in taskName if c not in digits])
 
+    def getNamePrefix(self):
+        # get a version of the task name, omitting a hyphen or
+        # underscore followed by a string of digits at the end of the
+        # name.
+        name = self.name
+        trimmed = len(name)
+        p = trimmed
+        while True:
+            while p > 0 and name[p - 1] in string.digits:
+                p -= 1
+            if p > 0 and name[p - 1] in '-_':
+                p -= 1
+                trimmed = p
+            else:
+                p = trimmed
+                break
+
+        return name[:trimmed]
+
     def setupPStats(self):
         if __debug__ and TaskManager.taskTimerVerbose and not self.pstats:
             # Get the PStats name for the task.  By convention,
@@ -440,6 +459,11 @@ class TaskManager:
         # A default task.
         self._doLaterTask = self.add(self.__doLaterProcessor, "doLaterProcessor", -10)
 
+    def finalInit(self):
+        # This function should be called once during startup, after
+        # most things are imported.
+        pass
+
     def destroy(self):
         if self._doLaterTask:
             self._doLaterTask.remove()

direct/src/task/TaskProfiler.py

@@ -5,14 +5,14 @@ from direct.showbase.PythonUtil import Averager
 class TaskTracker:
     # call it TaskProfiler to avoid confusion for the user
     notify = directNotify.newCategory("TaskProfiler")
-    def __init__(self, namePattern):
+    def __init__(self, namePrefix):
-        self._namePattern = namePattern
+        self._namePrefix = namePrefix
-        self._durationAverager = Averager('%s-durationAverager' % namePattern)
+        self._durationAverager = Averager('%s-durationAverager' % namePrefix)
         self._avgSession = None
         self._maxNonSpikeSession = None
     def destroy(self):
         self.flush()
-        del self._namePattern
+        del self._namePrefix
         del self._durationAverager
     def flush(self):
         self._durationAverager.reset()
@@ -22,8 +22,8 @@ class TaskTracker:
             self._maxNonSpikeSession.release()
         self._avgSession = None
         self._maxNonSpikeSession = None
-    def getNamePattern(self, namePattern):
+    def getNamePrefix(self, namePrefix):
-        return self._namePattern
+        return self._namePrefix
     def addProfileSession(self, session, isSpike):
         duration = session.getWallClockDuration()
         self._durationAverager.addValue(duration)
@@ -66,14 +66,14 @@ class TaskTracker:
             self.notify.info('task CPU profile (%s):\n'
                              '== AVERAGE (%s wall-clock seconds)\n%s\n'
                              '== LONGEST NON-SPIKE (%s wall-clock seconds)\n%s' % (
-                self._namePattern,
+                self._namePrefix,
                 self._avgSession.getWallClockDuration(),
                 self._avgSession.getResults(),
                 self._maxNonSpikeSession.getWallClockDuration(),
                 self._maxNonSpikeSession.getResults(),
                 ))
         else:
-            self.notify.info('task CPU profile (%s): no data collected' % self._namePattern)
+            self.notify.info('task CPU profile (%s): no data collected' % self._namePrefix)
 
 class TaskProfiler:
     # this does intermittent profiling of tasks running on the system
@@ -83,7 +83,7 @@ class TaskProfiler:
     def __init__(self):
         self._enableFC = FunctionCall(self._setEnabled, taskMgr.getProfileTasksSV())
         # table of task name pattern to TaskTracker
-        self._namePattern2tracker = {}
+        self._namePrefix2tracker = {}
         self._task = None
         # number of samples required before spikes start getting identified
         self._minSamples = config.GetInt('profile-task-spike-min-samples', 30)
@@ -94,16 +94,16 @@ class TaskProfiler:
         if taskMgr.getProfileTasks():
             self._setEnabled(False)
         self._enableFC.destroy()
-        for tracker in self._namePattern2tracker.itervalues():
+        for tracker in self._namePrefix2tracker.itervalues():
             tracker.destroy()
-        del self._namePattern2tracker
+        del self._namePrefix2tracker
         del self._task
 
     def logProfiles(self, name=None):
         if name:
             name = name.lower()
-        for namePattern, tracker in self._namePattern2tracker.iteritems():
+        for namePrefix, tracker in self._namePrefix2tracker.iteritems():
-            if (name and (name not in namePattern.lower())):
+            if (name and (name not in namePrefix.lower())):
                 continue
             tracker.log()
 
@@ -111,8 +111,8 @@ class TaskProfiler:
         if name:
             name = name.lower()
         # flush stored task profiles
-        for namePattern, tracker in self._namePattern2tracker.iteritems():
+        for namePrefix, tracker in self._namePrefix2tracker.iteritems():
-            if (name and (name not in namePattern.lower())):
+            if (name and (name not in namePrefix.lower())):
                 continue
             tracker.flush()
 
@@ -132,10 +132,10 @@ class TaskProfiler:
             # if we couldn't profile, throw this result out
             if session.profileSucceeded():
                 sessionDur = session.getWallClockDuration()
-                namePattern = self._task.getNamePattern()
+                namePrefix = self._task.getNamePrefix()
-                if namePattern not in self._namePattern2tracker:
+                if namePrefix not in self._namePrefix2tracker:
-                    self._namePattern2tracker[namePattern] = TaskTracker(namePattern)
+                    self._namePrefix2tracker[namePrefix] = TaskTracker(namePrefix)
-                tracker = self._namePattern2tracker[namePattern]
+                tracker = self._namePrefix2tracker[namePrefix]
                 isSpike = False
                 # do we have enough samples?
                 if tracker.getNumDurationSamples() > self._minSamples:
@@ -150,7 +150,7 @@ class TaskProfiler:
                                          '== AVERAGE (%s wall-clock seconds)\n%s\n'
                                          '== LONGEST NON-SPIKE (%s wall-clock seconds)\n%s\n'
                                          '== SPIKE (%s wall-clock seconds)\n%s' % (
-                            namePattern,
+                            namePrefix,
                             avgSession.getWallClockDuration(), avgSession.getResults(),
                             maxNSSession.getWallClockDuration(), maxNSSession.getResults(),
                             sessionDur, session.getResults()))