from panda3d.core import ConfigVariableBool, ClockObject
from direct.directnotify.DirectNotifyGlobal import directNotify
from direct.fsm.StatePush import FunctionCall
from direct.showbase.PythonUtil import formatTimeExact, normalDistrib, serialNum
from direct.showbase.PythonUtil import Functor
from .Task import Task
from .TaskManagerGlobal import taskMgr
[docs]class FrameProfiler:
notify = directNotify.newCategory('FrameProfiler')
# because of precision requirements, all times related to the profile/log
# schedule are stored as integers
Minute = 60
Hour = 60 * Minute
Day = 24 * Hour
[docs] def __init__(self):
Hour = FrameProfiler.Hour
# how long to wait between frame profiles
frequent_profiles = ConfigVariableBool('frequent-frame-profiles', False)
self._period = 2 * FrameProfiler.Minute
if frequent_profiles:
self._period = 1 * FrameProfiler.Minute
# used to prevent profile from being taken exactly every 'period' seconds
self._jitterMagnitude = self._period * .75
# when to log output
# each entry must be an integer multiple of all previous entries
# as well as an integer multiple of the period
self._logSchedule = [ 1 * FrameProfiler.Hour,
4 * FrameProfiler.Hour,
12 * FrameProfiler.Hour,
1 * FrameProfiler.Day,
] # day schedule proceeds as 1, 2, 4, 8 days, etc.
if frequent_profiles:
self._logSchedule = [ 1 * FrameProfiler.Minute,
4 * FrameProfiler.Minute,
12 * FrameProfiler.Minute,
24 * FrameProfiler.Minute,
]
for t in self._logSchedule:
#assert isInteger(t)
# make sure the period is evenly divisible into each element of the log schedule
assert (t % self._period) == 0
# make sure each element of the schedule is evenly divisible into each subsequent element
for i in range(len(self._logSchedule)):
e = self._logSchedule[i]
for j in range(i, len(self._logSchedule)):
assert (self._logSchedule[j] % e) == 0
#assert isInteger(self._period)
self._enableFC = FunctionCall(self._setEnabled, taskMgr.getProfileFramesSV())
self._enableFC.pushCurrentState()
[docs] def destroy(self):
self._enableFC.set(False)
self._enableFC.destroy()
def _setEnabled(self, enabled):
if enabled:
self.notify.info('frame profiler started')
self._startTime = ClockObject.getGlobalClock().getFrameTime()
self._profileCounter = 0
self._jitter = None
self._period2aggregateProfile = {}
self._id2session = {}
self._id2task = {}
# don't profile process startup
self._task = taskMgr.doMethodLater(self._period, self._scheduleNextProfileDoLater,
'FrameProfilerStart-%s' % serialNum())
else:
self._task.remove()
del self._task
for session in self._period2aggregateProfile.values():
session.release()
del self._period2aggregateProfile
for task in self._id2task.values():
task.remove()
del self._id2task
for session in self._id2session.values():
session.release()
del self._id2session
self.notify.info('frame profiler stopped')
def _scheduleNextProfileDoLater(self, task):
self._scheduleNextProfile()
return Task.done
def _scheduleNextProfile(self):
self._profileCounter += 1
self._timeElapsed = self._profileCounter * self._period
#assert isInteger(self._timeElapsed)
time = self._startTime + self._timeElapsed
# vary the actual delay between profiles by a random amount to prevent interaction
# with periodic events
jitter = self._jitter
if jitter is None:
jitter = normalDistrib(-self._jitterMagnitude, self._jitterMagnitude)
time += jitter
else:
time -= jitter
jitter = None
self._jitter = jitter
sessionId = serialNum()
session = taskMgr.getProfileSession('FrameProfile-%s' % sessionId)
self._id2session[sessionId] = session
taskMgr.profileFrames(num=1, session=session, callback=Functor(
self._analyzeResults, sessionId))
# schedule the next profile
delay = max(time - ClockObject.getGlobalClock().getFrameTime(), 0.)
self._task = taskMgr.doMethodLater(delay, self._scheduleNextProfileDoLater,
'FrameProfiler-%s' % serialNum())
def _analyzeResults(self, sessionId):
# do the analysis in a task 1) to separate the processing from the profiled frame,
# and 2) to get the processing to show up in a named task instead of in the taskMgr
self._id2task[sessionId] = taskMgr.add(
Functor(self._doAnalysis, sessionId), 'FrameProfilerAnalysis-%s' % sessionId)
def _doAnalysis(self, sessionId, task):
if hasattr(task, '_generator'):
gen = task._generator
else:
gen = self._doAnalysisGen(sessionId)
task._generator = gen
result = next(gen)
if result == Task.done:
del task._generator
return result
def _doAnalysisGen(self, sessionId):
# generator to limit max number of profile loggings per frame
p2ap = self._period2aggregateProfile
self._id2task.pop(sessionId)
session = self._id2session.pop(sessionId)
if session.profileSucceeded():
# always add this profile to the first aggregated profile
period = self._logSchedule[0]
if period not in self._period2aggregateProfile:
p2ap[period] = session.getReference()
else:
p2ap[period].aggregate(session)
else:
self.notify.warning('frame profile did not succeed')
session.release()
session = None
counter = 0
# log profiles when it's time, and aggregate them upwards into the
# next-longer profile
for pi in range(len(self._logSchedule)):
period = self._logSchedule[pi]
if (self._timeElapsed % period) == 0:
if period in p2ap:
# delay until the next frame if we've already processed N profiles this frame
if counter >= 3:
counter = 0
yield Task.cont
self.notify.info('aggregate profile of sampled frames over last %s\n%s' %
(formatTimeExact(period), p2ap[period].getResults()))
counter += 1
# aggregate this profile into the next larger profile
nextIndex = pi + 1
if nextIndex >= len(self._logSchedule):
# if we're adding a new period to the end of the log period table,
# set it to double the duration of the current longest period
nextPeriod = period * 2
self._logSchedule.append(nextPeriod)
else:
nextPeriod = self._logSchedule[nextIndex]
if nextPeriod not in p2ap:
p2ap[nextPeriod] = p2ap[period].getReference()
else:
p2ap[nextPeriod].aggregate(p2ap[period])
# this profile is now represented in the next larger profile
# throw it out
p2ap[period].release()
del p2ap[period]
else:
# current time is not divisible evenly into selected period, and all higher
# periods are multiples of this one
break
yield Task.done
