LSSTApplications  17.0+11,17.0+35,17.0+60,17.0+61,17.0+63,17.0+7,17.0-1-g377950a+35,17.0.1-1-g114240f+2,17.0.1-1-g4d4fbc4+30,17.0.1-1-g55520dc+55,17.0.1-1-g5f4ed7e+60,17.0.1-1-g6dd7d69+22,17.0.1-1-g8de6c91+11,17.0.1-1-gb9095d2+7,17.0.1-1-ge9fec5e+5,17.0.1-1-gf4e0155+64,17.0.1-1-gfc65f5f+57,17.0.1-1-gfc6fb1f+20,17.0.1-10-g87f9f3f+10,17.0.1-12-g112a4bc+4,17.0.1-17-gdae4c4a+17,17.0.1-18-gc46c6bd8,17.0.1-19-g3a24bb2+2,17.0.1-2-g26618f5+36,17.0.1-2-g54f2ebc+9,17.0.1-2-gf403422+1,17.0.1-22-gfd3334c,17.0.1-26-gd98a1d13+1,17.0.1-3-g7e86b59+46,17.0.1-3-gb5ca14a,17.0.1-3-gd08d533+47,17.0.1-31-gb0791f330,17.0.1-4-g59d126d+10,17.0.1-5-g3877d06+2,17.0.1-7-g35889ee+7,17.0.1-7-gc7c8782+20,17.0.1-7-gcb7da53+6,17.0.1-9-gc4bbfb2+11,w.2019.24
LSSTDataManagementBasePackage
timer.py
Go to the documentation of this file.
1 #
2 # LSST Data Management System
3 # Copyright 2008, 2009, 2010, 2011 LSST Corporation.
4 #
5 # This product includes software developed by the
6 # LSST Project (http://www.lsst.org/).
7 #
8 # This program is free software: you can redistribute it and/or modify
9 # it under the terms of the GNU General Public License as published by
10 # the Free Software Foundation, either version 3 of the License, or
11 # (at your option) any later version.
12 #
13 # This program is distributed in the hope that it will be useful,
14 # but WITHOUT ANY WARRANTY; without even the implied warranty of
15 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
16 # GNU General Public License for more details.
17 #
18 # You should have received a copy of the LSST License Statement and
19 # the GNU General Public License along with this program. If not,
20 # see <http://www.lsstcorp.org/LegalNotices/>.
21 #
22 """Utilities for measuring execution time.
23 """
24 __all__ = ["logInfo", "timeMethod"]
25 
26 import functools
27 import resource
28 import time
29 import datetime
30 
31 from lsst.log import Log, log
32 
33 
34 def logPairs(obj, pairs, logLevel=Log.DEBUG):
35  """Log ``(name, value)`` pairs to ``obj.metadata`` and ``obj.log``
36 
37  Parameters
38  ----------
39  obj : `lsst.pipe.base.Task`-type
40  A `~lsst.pipe.base.Task` or any other object with these two attributes:
41 
42  - ``metadata`` an instance of `lsst.daf.base.PropertyList`` (or other object with
43  ``add(name, value)`` method).
44  - ``log`` an instance of `lsst.log.Log`.
45 
46  pairs : sequence
47  A sequence of ``(name, value)`` pairs, with value typically numeric.
48  logLevel : optional
49  Log level (an `lsst.log` level constant, such as `lsst.log.Log.DEBUG`).
50  """
51  strList = []
52  for name, value in pairs:
53  try:
54  # Use LongLong explicitly here in case an early value in the sequence is int-sized
55  obj.metadata.addLongLong(name, value)
56  except TypeError:
57  obj.metadata.add(name, value)
58  strList.append("%s=%s" % (name, value))
59  log(obj.log.getName(), logLevel, "; ".join(strList))
60 
61 
62 def logInfo(obj, prefix, logLevel=Log.DEBUG):
63  """Log timer information to ``obj.metadata`` and ``obj.log``.
64 
65  Parameters
66  ----------
67  obj : `lsst.pipe.base.Task`-type
68  A `~lsst.pipe.base.Task` or any other object with these two attributes:
69 
70  - ``metadata`` an instance of `lsst.daf.base.PropertyList`` (or other object with
71  ``add(name, value)`` method).
72  - ``log`` an instance of `lsst.log.Log`.
73 
74  prefix
75  Name prefix, the resulting entries are ``CpuTime``, etc.. For example timeMethod uses
76  ``prefix = Start`` when the method begins and ``prefix = End`` when the method ends.
77  logLevel : optional
78  Log level (an `lsst.log` level constant, such as `lsst.log.Log.DEBUG`).
79 
80  Notes
81  -----
82  Logged items include:
83 
84  - ``Utc``: UTC date in ISO format (only in metadata since log entries have timestamps).
85  - ``CpuTime``: System + User CPU time (seconds). This should only be used
86  in differential measurements; the time reference point is undefined.
87  - ``MaxRss``: maximum resident set size.
88 
89  All logged resource information is only for the current process; child processes are excluded.
90  """
91  cpuTime = time.process_time()
92  utcStr = datetime.datetime.utcnow().isoformat()
93  res = resource.getrusage(resource.RUSAGE_SELF)
94  obj.metadata.add(name=prefix + "Utc", value=utcStr) # log messages already have timestamps
95  logPairs(obj=obj,
96  pairs=[
97  (prefix + "CpuTime", cpuTime),
98  (prefix + "UserTime", res.ru_utime),
99  (prefix + "SystemTime", res.ru_stime),
100  (prefix + "MaxResidentSetSize", int(res.ru_maxrss)),
101  (prefix + "MinorPageFaults", int(res.ru_minflt)),
102  (prefix + "MajorPageFaults", int(res.ru_majflt)),
103  (prefix + "BlockInputs", int(res.ru_inblock)),
104  (prefix + "BlockOutputs", int(res.ru_oublock)),
105  (prefix + "VoluntaryContextSwitches", int(res.ru_nvcsw)),
106  (prefix + "InvoluntaryContextSwitches", int(res.ru_nivcsw)),
107  ],
108  logLevel=logLevel,
109  )
110 
111 
112 def timeMethod(func):
113  """Decorator to measure duration of a task method.
114 
115  Parameters
116  ----------
117  func
118  The method to wrap.
119 
120  Notes
121  -----
122  Writes various measures of time and possibly memory usage to the task's metadata; all items are prefixed
123  with the function name.
124 
125  .. warning::
126 
127  This decorator only works with instance methods of Task, or any class with these attributes:
128 
129  - ``metadata``: an instance of `lsst.daf.base.PropertyList` (or other object with
130  ``add(name, value)`` method).
131  - ``log``: an instance of `lsst.log.Log`.
132 
133  Examples
134  --------
135  To use::
136 
137  import lsst.pipe.base as pipeBase
138  class FooTask(pipeBase.Task):
139  pass
140 
141  @pipeBase.timeMethod
142  def run(self, ...): # or any other instance method you want to time
143  pass
144  """
145 
146  @functools.wraps(func)
147  def wrapper(self, *args, **keyArgs):
148  logInfo(obj=self, prefix=func.__name__ + "Start")
149  try:
150  res = func(self, *args, **keyArgs)
151  finally:
152  logInfo(obj=self, prefix=func.__name__ + "End")
153  return res
154  return wrapper
def logInfo(obj, prefix, logLevel=Log.DEBUG)
Definition: timer.py:62
Definition: Log.h:691
def logPairs(obj, pairs, logLevel=Log.DEBUG)
Definition: timer.py:34
def timeMethod(func)
Definition: timer.py:112