Back to index

moin  1.9.0~rc2
profile.py
Go to the documentation of this file.
00001 """ profile - moin profiling utilities
00002 
00003 This module provides profilers used to profile the memory usage of a
00004 long running process.
00005 
00006 Typical usage:
00007 
00008  1. Create a profiler:
00009 
00010     from MoinMoin.util.profile import Profiler
00011     profiler = Profiler('my log')
00012 
00013  2. In the request handler, add each request to the profiler:
00014 
00015     profiler.addRequest()
00016 
00017  3. If you like, you can add extra samples:
00018 
00019     profiler.sample()
00020 
00021 You can customize the profiler when you create it:
00022 
00023  * requestsPerSample (default 100):
00024 
00025    How many requests to run between samples. Set higher for live wiki or
00026    lower for more accurate results.
00027 
00028  * collect (default 0):
00029 
00030    Use gc.collect to force a memory cleanup each sample. Keeps the
00031    memory usage much lower, but your profile data will not reflect the
00032    real world memory usage of the application.
00033 
00034 Based on code by Oliver Graf
00035 
00036 @copyright: 2004 Nir Soffer
00037 @license: GNU GPL, see COPYING for details.
00038 """
00039 
00040 import os, time, gc
00041 
00042 
00043 class Profiler:
00044     """ Profile memory usage
00045 
00046     Profiler count requests and sample memory usage.
00047 
00048     FIXME: We might want to save the profiler log in the profiled wiki
00049     data dir, but the data dir is available only later in request. This
00050     should be fixed by loading the config earlier.
00051     """
00052     def __init__(self, name, requestsPerSample=100, collect=0):
00053         """ Initialize a profiler
00054 
00055         @param name: profiler name, used in the log file name
00056         @param requestsPerSample: how many request to run between samples
00057         @param collect: should call gc.collect() in each sample
00058         """
00059         logname = '%s--%s.log' % (name, time.strftime('%Y-%m-%d--%H-%M'))
00060         self.logfile = file(logname, 'a')
00061         self.requestsPerSample = requestsPerSample
00062         self.collect = collect
00063         self.pid = os.getpid()
00064         self.count = 0 # count between somples
00065         self.requests = 0 # requests added
00066         self.data = {'collect': 'NA'} # Sample data
00067 
00068     def addRequest(self):
00069         """ Add a request to the profile
00070 
00071         Call this for each page request.
00072 
00073         WARNING: This is the most important call. if you don't call this
00074         for each request - you will not have any profile data.
00075 
00076         Invoke sample when self.count reach self.requestsPerSample.
00077         """
00078         self.requests += 1
00079         self.count += 1
00080         if self.count == self.requestsPerSample:
00081             # Time for a sample
00082             self.count = 0
00083             self.sample()
00084 
00085     def sample(self):
00086         """ Make a sample of memory usage and log it
00087 
00088         You can call this to make samples between the samples done each
00089         requestsPerSample, for example, at startup.
00090 
00091         Invoke common methods for all profilers. Some profilers like
00092         TwistedProfiler override this method.
00093         """
00094         self._setData()
00095         self._setMemory()
00096         self._log()
00097 
00098     # Private methods ------------------------------------------------------
00099 
00100     def _setData(self):
00101         """ Collect sample data into self.data
00102 
00103         Private method used by profilers.
00104         """
00105         d = self.data
00106         d['date'] = time.strftime('%Y-%m-%d %H:%M:%S')
00107         d['requests'] = self.requests
00108         if self.collect:
00109             d['collect'] = str(gc.collect())
00110         d['objects'] = len(gc.get_objects())
00111         d['garbage'] = len(gc.garbage)
00112 
00113     def _setMemory(self):
00114         """ Get process memory usage
00115 
00116         Private method used by profilers.
00117 
00118         Uses ps call, maybe we should use procfs on Linux or maybe
00119         getrusage system call (using the ctypes module).
00120         """
00121         lines = os.popen('/bin/ps -p %s -o rss' % self.pid).readlines()
00122         self.data['memory'] = lines[1].strip()
00123 
00124     def _log(self):
00125         """ Format sample and write to log
00126 
00127         Private method used by profilers.
00128         """
00129         line = ('%(date)s req:%(requests)d mem:%(memory)sKB collect:%(collect)s '
00130                 'objects:%(objects)d garbage:%(garbage)d\n' % self.data)
00131         self.logfile.write(line)
00132         self.logfile.flush()
00133 
00134 
00135 class TwistedProfiler(Profiler):
00136     """ Twisted specific memory profiler
00137 
00138     Customize the way we call ps, to overcome blocking problems on
00139     twisted.
00140     """
00141 
00142     def __init__(self, name, requestsPerSample=100, collect=0):
00143         """ Initialized twisted profiler
00144 
00145         Invoke Profiler.__init__ and import getProcessOuput from
00146         twisted.
00147         """
00148         Profiler.__init__(self, name, requestsPerSample, collect)
00149         from twisted.internet.utils import getProcessOutput
00150         self._getProcessOutput = getProcessOutput
00151 
00152     def sample(self):
00153         """ Make a sample of memory usage and log it
00154 
00155         On twisted we can't just call ps - we have to use deferred,
00156         which will call us using a callback when its finished, and then
00157         we log.
00158 
00159         Since twisted continue to serve while the deferred fetch the
00160         memory, the reading may be late in few requests.
00161         """
00162         self._setData()
00163         # Memory will be available little later
00164         deferred = self._getProcessOutput('/bin/ps',
00165                                           ('-p', str(self.pid), '-o', 'rss'))
00166         deferred.addCallback(self._callback)
00167 
00168     # Private methods ------------------------------------------------------
00169 
00170     def _callback(self, data):
00171         """ Called from deferred when ps output is available
00172 
00173         Private method, don't call this.
00174         """
00175         self.data['memory'] = data.split('\n')[1].strip()
00176         self._log()
00177 
00178 
00179 if __name__ == '__main__':
00180     # In case someone try to run as a script
00181     print __doc__
00182