LSSTApplications  18.0.0+56,19.0.0+1,19.0.0+18,19.0.0+19,19.0.0+21,19.0.0+26,19.0.0+5,19.0.0-1-g20d9b18+12,19.0.0-1-g425ff20,19.0.0-1-g5549ca4,19.0.0-1-g580fafe+12,19.0.0-1-g6fe20d0+4,19.0.0-1-g8c57eb9+12,19.0.0-1-ga72da6b,19.0.0-1-gbfe0924+3,19.0.0-1-gdc0e4a7+17,19.0.0-1-ge272bc4+12,19.0.0-1-ge3aa853+3,19.0.0-16-g3a790c8c,19.0.0-18-g955d782+1,19.0.0-2-g0d9f9cd+19,19.0.0-2-g260436e+3,19.0.0-2-g9b11441+6,19.0.0-2-gd955cfd+25,19.0.0-3-g6513920+3,19.0.0-3-gc4f6e04+2,19.0.0-4-g41ffa1d+5,19.0.0-4-g725f80e+21,19.0.0-5-g0745e3f+3,19.0.0-6-g5a632bb5+1,19.0.0-6-gb6b8b0a+3,19.0.0-7-g686a884,19.0.0-7-gea0a0fe+8,19.0.0-9-gd2f60f3c3,w.2020.03
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:706
def logPairs(obj, pairs, logLevel=Log.DEBUG)
Definition: timer.py:34
def timeMethod(func)
Definition: timer.py:112