##// END OF EJS Templates
mercurial: switch to util.timer for all interval timings...
Simon Farnsworth -
r30975:22fbca1d default
parent child Browse files
Show More
@@ -55,17 +55,15 b' except ImportError:'
55 import mercurial.util
55 import mercurial.util
56 import mercurial.dispatch
56 import mercurial.dispatch
57
57
58 import time
59
60 def timer(func, title=None):
58 def timer(func, title=None):
61 results = []
59 results = []
62 begin = time.time()
60 begin = mercurial.util.timer()
63 count = 0
61 count = 0
64 while True:
62 while True:
65 ostart = os.times()
63 ostart = os.times()
66 cstart = time.time()
64 cstart = mercurial.util.timer()
67 r = func()
65 r = func()
68 cstop = time.time()
66 cstop = mercurial.util.timer()
69 ostop = os.times()
67 ostop = os.times()
70 count += 1
68 count += 1
71 a, b = ostart, ostop
69 a, b = ostart, ostop
@@ -190,13 +190,13 b' def stub_timer(fm, func, title=None):'
190
190
191 def _timer(fm, func, title=None):
191 def _timer(fm, func, title=None):
192 results = []
192 results = []
193 begin = time.time()
193 begin = util.timer()
194 count = 0
194 count = 0
195 while True:
195 while True:
196 ostart = os.times()
196 ostart = os.times()
197 cstart = time.time()
197 cstart = util.timer()
198 r = func()
198 r = func()
199 cstop = time.time()
199 cstop = util.timer()
200 ostop = os.times()
200 ostop = os.times()
201 count += 1
201 count += 1
202 a, b = ostart, ostop
202 a, b = ostart, ostop
@@ -9,7 +9,6 b' from __future__ import absolute_import'
9
9
10 import array
10 import array
11 import struct
11 import struct
12 import time
13
12
14 from .node import (
13 from .node import (
15 bin,
14 bin,
@@ -21,6 +20,7 b' from . import ('
21 encoding,
20 encoding,
22 error,
21 error,
23 scmutil,
22 scmutil,
23 util,
24 )
24 )
25
25
26 array = array.array
26 array = array.array
@@ -261,7 +261,7 b' class branchcache(dict):'
261 missing heads, and a generator of nodes that are strictly a superset of
261 missing heads, and a generator of nodes that are strictly a superset of
262 heads missing, this function updates self to be correct.
262 heads missing, this function updates self to be correct.
263 """
263 """
264 starttime = time.time()
264 starttime = util.timer()
265 cl = repo.changelog
265 cl = repo.changelog
266 # collect new branch entries
266 # collect new branch entries
267 newbranches = {}
267 newbranches = {}
@@ -314,7 +314,7 b' class branchcache(dict):'
314 self.tiprev = tiprev
314 self.tiprev = tiprev
315 self.filteredhash = scmutil.filteredhash(repo, self.tiprev)
315 self.filteredhash = scmutil.filteredhash(repo, self.tiprev)
316
316
317 duration = time.time() - starttime
317 duration = util.timer() - starttime
318 repo.ui.log('branchcache', 'updated %s branch cache in %.4f seconds\n',
318 repo.ui.log('branchcache', 'updated %s branch cache in %.4f seconds\n',
319 repo.filtername, duration)
319 repo.filtername, duration)
320
320
@@ -123,7 +123,7 b' def dispatch(req):'
123 return -1
123 return -1
124
124
125 msg = ' '.join(' ' in a and repr(a) or a for a in req.args)
125 msg = ' '.join(' ' in a and repr(a) or a for a in req.args)
126 starttime = time.time()
126 starttime = util.timer()
127 ret = None
127 ret = None
128 try:
128 try:
129 ret = _runcatch(req)
129 ret = _runcatch(req)
@@ -135,7 +135,7 b' def dispatch(req):'
135 raise
135 raise
136 ret = -1
136 ret = -1
137 finally:
137 finally:
138 duration = time.time() - starttime
138 duration = util.timer() - starttime
139 req.ui.flush()
139 req.ui.flush()
140 req.ui.log("commandfinish", "%s exited %s after %0.2f seconds\n",
140 req.ui.log("commandfinish", "%s exited %s after %0.2f seconds\n",
141 msg, ret or 0, duration)
141 msg, ret or 0, duration)
@@ -9,7 +9,6 b' from __future__ import absolute_import'
9
9
10 import os
10 import os
11 import sys
11 import sys
12 import time
13
12
14 from .i18n import _
13 from .i18n import _
15 from . import (
14 from . import (
@@ -88,7 +87,7 b' def _pythonhook(ui, repo, name, hname, f'
88 % (hname, funcname))
87 % (hname, funcname))
89
88
90 ui.note(_("calling hook %s: %s\n") % (hname, funcname))
89 ui.note(_("calling hook %s: %s\n") % (hname, funcname))
91 starttime = time.time()
90 starttime = util.timer()
92
91
93 try:
92 try:
94 r = obj(ui=ui, repo=repo, hooktype=name, **args)
93 r = obj(ui=ui, repo=repo, hooktype=name, **args)
@@ -106,7 +105,7 b' def _pythonhook(ui, repo, name, hname, f'
106 ui.traceback()
105 ui.traceback()
107 return True, True
106 return True, True
108 finally:
107 finally:
109 duration = time.time() - starttime
108 duration = util.timer() - starttime
110 ui.log('pythonhook', 'pythonhook-%s: %s finished in %0.2f seconds\n',
109 ui.log('pythonhook', 'pythonhook-%s: %s finished in %0.2f seconds\n',
111 name, funcname, duration)
110 name, funcname, duration)
112 if r:
111 if r:
@@ -118,7 +117,7 b' def _pythonhook(ui, repo, name, hname, f'
118 def _exthook(ui, repo, name, cmd, args, throw):
117 def _exthook(ui, repo, name, cmd, args, throw):
119 ui.note(_("running hook %s: %s\n") % (name, cmd))
118 ui.note(_("running hook %s: %s\n") % (name, cmd))
120
119
121 starttime = time.time()
120 starttime = util.timer()
122 env = {}
121 env = {}
123
122
124 # make in-memory changes visible to external process
123 # make in-memory changes visible to external process
@@ -145,7 +144,7 b' def _exthook(ui, repo, name, cmd, args, '
145 cwd = pycompat.getcwd()
144 cwd = pycompat.getcwd()
146 r = ui.system(cmd, environ=env, cwd=cwd)
145 r = ui.system(cmd, environ=env, cwd=cwd)
147
146
148 duration = time.time() - starttime
147 duration = util.timer() - starttime
149 ui.log('exthook', 'exthook-%s: %s finished in %0.2f seconds\n',
148 ui.log('exthook', 'exthook-%s: %s finished in %0.2f seconds\n',
150 name, cmd, duration)
149 name, cmd, duration)
151 if r:
150 if r:
@@ -8,7 +8,6 b''
8 from __future__ import absolute_import, print_function
8 from __future__ import absolute_import, print_function
9
9
10 import contextlib
10 import contextlib
11 import time
12
11
13 from .i18n import _
12 from .i18n import _
14 from . import (
13 from . import (
@@ -66,7 +65,7 b' def flameprofile(ui, fp):'
66 collapse_recursion = True
65 collapse_recursion = True
67 thread = flamegraph.ProfileThread(fp, 1.0 / freq,
66 thread = flamegraph.ProfileThread(fp, 1.0 / freq,
68 filter_, collapse_recursion)
67 filter_, collapse_recursion)
69 start_time = time.clock()
68 start_time = util.timer()
70 try:
69 try:
71 thread.start()
70 thread.start()
72 yield
71 yield
@@ -74,7 +73,7 b' def flameprofile(ui, fp):'
74 thread.stop()
73 thread.stop()
75 thread.join()
74 thread.join()
76 print('Collected %d stack frames (%d unique) in %2.2f seconds.' % (
75 print('Collected %d stack frames (%d unique) in %2.2f seconds.' % (
77 time.clock() - start_time, thread.num_frames(),
76 util.timer() - start_time, thread.num_frames(),
78 thread.num_frames(unique=True)))
77 thread.num_frames(unique=True)))
79
78
80 @contextlib.contextmanager
79 @contextlib.contextmanager
@@ -12,7 +12,6 b' import errno'
12 import hashlib
12 import hashlib
13 import stat
13 import stat
14 import tempfile
14 import tempfile
15 import time
16
15
17 from .i18n import _
16 from .i18n import _
18 from .node import short
17 from .node import short
@@ -905,10 +904,10 b' def _upgraderepo(ui, srcrepo, dstrepo, r'
905 # the operation nearly instantaneous and atomic (at least in well-behaved
904 # the operation nearly instantaneous and atomic (at least in well-behaved
906 # environments).
905 # environments).
907 ui.write(_('replacing store...\n'))
906 ui.write(_('replacing store...\n'))
908 tstart = time.time()
907 tstart = util.timer()
909 util.rename(srcrepo.spath, backupvfs.join('store'))
908 util.rename(srcrepo.spath, backupvfs.join('store'))
910 util.rename(dstrepo.spath, srcrepo.spath)
909 util.rename(dstrepo.spath, srcrepo.spath)
911 elapsed = time.time() - tstart
910 elapsed = util.timer() - tstart
912 ui.write(_('store replacement complete; repository was inconsistent for '
911 ui.write(_('store replacement complete; repository was inconsistent for '
913 '%0.1fs\n') % elapsed)
912 '%0.1fs\n') % elapsed)
914
913
@@ -8,7 +8,6 b''
8 from __future__ import absolute_import
8 from __future__ import absolute_import
9
9
10 import struct
10 import struct
11 import time
12
11
13 from .i18n import _
12 from .i18n import _
14 from . import (
13 from . import (
@@ -297,7 +296,7 b' def consumev1(repo, fp, filecount, bytec'
297 (filecount, util.bytecount(bytecount)))
296 (filecount, util.bytecount(bytecount)))
298 handled_bytes = 0
297 handled_bytes = 0
299 repo.ui.progress(_('clone'), 0, total=bytecount, unit=_('bytes'))
298 repo.ui.progress(_('clone'), 0, total=bytecount, unit=_('bytes'))
300 start = time.time()
299 start = util.timer()
301
300
302 # TODO: get rid of (potential) inconsistency
301 # TODO: get rid of (potential) inconsistency
303 #
302 #
@@ -340,7 +339,7 b' def consumev1(repo, fp, filecount, bytec'
340 # streamclone-ed file at next access
339 # streamclone-ed file at next access
341 repo.invalidate(clearfilecache=True)
340 repo.invalidate(clearfilecache=True)
342
341
343 elapsed = time.time() - start
342 elapsed = util.timer() - start
344 if elapsed <= 0:
343 if elapsed <= 0:
345 elapsed = 0.001
344 elapsed = 0.001
346 repo.ui.progress(_('clone'), None)
345 repo.ui.progress(_('clone'), None)
@@ -14,7 +14,6 b' from __future__ import absolute_import'
14
14
15 import array
15 import array
16 import errno
16 import errno
17 import time
18
17
19 from .node import (
18 from .node import (
20 bin,
19 bin,
@@ -344,7 +343,7 b' def _readtagcache(ui, repo):'
344 # potentially expensive search.
343 # potentially expensive search.
345 return ([], {}, valid, None, True)
344 return ([], {}, valid, None, True)
346
345
347 starttime = time.time()
346 starttime = util.timer()
348
347
349 # Now we have to lookup the .hgtags filenode for every new head.
348 # Now we have to lookup the .hgtags filenode for every new head.
350 # This is the most expensive part of finding tags, so performance
349 # This is the most expensive part of finding tags, so performance
@@ -359,7 +358,7 b' def _readtagcache(ui, repo):'
359
358
360 fnodescache.write()
359 fnodescache.write()
361
360
362 duration = time.time() - starttime
361 duration = util.timer() - starttime
363 ui.log('tagscache',
362 ui.log('tagscache',
364 '%d/%d cache hits/lookups in %0.4f '
363 '%d/%d cache hits/lookups in %0.4f '
365 'seconds\n',
364 'seconds\n',
@@ -2797,13 +2797,13 b' def timed(func):'
2797 '''
2797 '''
2798
2798
2799 def wrapper(*args, **kwargs):
2799 def wrapper(*args, **kwargs):
2800 start = time.time()
2800 start = timer()
2801 indent = 2
2801 indent = 2
2802 _timenesting[0] += indent
2802 _timenesting[0] += indent
2803 try:
2803 try:
2804 return func(*args, **kwargs)
2804 return func(*args, **kwargs)
2805 finally:
2805 finally:
2806 elapsed = time.time() - start
2806 elapsed = timer() - start
2807 _timenesting[0] -= indent
2807 _timenesting[0] -= indent
2808 stderr.write('%s%s: %s\n' %
2808 stderr.write('%s%s: %s\n' %
2809 (' ' * _timenesting[0], func.__name__,
2809 (' ' * _timenesting[0], func.__name__,
General Comments 0
You need to be logged in to leave comments. Login now