diff options
author | Jon Newson <jon_newson@ieee.org> | 2016-02-25 07:14:06 +1100 |
---|---|---|
committer | Jon Newson <jon_newson@ieee.org> | 2016-02-25 07:14:06 +1100 |
commit | c1f468abad6717fcabc2d812e34f4217215e70a8 (patch) | |
tree | 8ee1d7fe6463eaf5edad736d8d7b058a360b78f1 /service/pixelated/support/__init__.py | |
parent | 47df3a86d7cf412d766f8a1fdd1e9b9fe15bfb45 (diff) | |
parent | 6160633ab9a54238974af3cf498024ad98fc977e (diff) |
Merge commit '6160633ab9a54238974af3cf498024ad98fc977e'
* commit '6160633ab9a54238974af3cf498024ad98fc977e':
Fix repositore clone url
Returning 'not-sign' for no signature information
Only do initial sync on session creation
Improve stopwatch output
Improve error message if send mail fails
Diffstat (limited to 'service/pixelated/support/__init__.py')
-rw-r--r-- | service/pixelated/support/__init__.py | 30 |
1 files changed, 26 insertions, 4 deletions
diff --git a/service/pixelated/support/__init__.py b/service/pixelated/support/__init__.py index 80ecaa2e..9ac52fe0 100644 --- a/service/pixelated/support/__init__.py +++ b/service/pixelated/support/__init__.py @@ -22,13 +22,34 @@ from twisted.internet import defer log = logging.getLogger(__name__) +def _start_stopwatch(): + return (time.time(), time.clock()) + + +def _stop_stopwatch(start): + start_time, start_clock = start + end_clock = time.clock() + end_time = time.time() + clock_duration = end_clock - start_clock + time_duration = end_time - start_time + if time_duration < 0.00000001: # avoid division by zero + time_duration = 0.00000001 + + estimate_percent_io = ((time_duration - clock_duration) / time_duration) * 100.0 + + return time_duration, clock_duration, estimate_percent_io + + def log_time(f): @wraps(f) def wrapper(*args, **kwds): - start = time.clock() + start = _start_stopwatch() + result = f(*args, **kwds) - log.info('Needed %f ms to execute %s' % ((time.clock() - start), f)) + + time_duration, clock_duration, estimate_percent_io = _stop_stopwatch(start) + log.info('Needed %fs (%fs cpu time, %.2f%% spent outside process) to execute %s' % (time_duration, clock_duration, estimate_percent_io, f)) return result @@ -38,12 +59,13 @@ def log_time(f): def log_time_deferred(f): def log_time(result, start): - log.info('after callback: Needed %f ms to execute %s' % ((time.clock() - start), f)) + time_duration, clock_duration, estimate_percent_io = _stop_stopwatch(start) + log.info('after callback: Needed %fs (%fs cpu time, %.2f%% spent outside process) to execute %s' % (time_duration, clock_duration, estimate_percent_io, f)) return result @wraps(f) def wrapper(*args, **kwds): - start = time.clock() + start = _start_stopwatch() result = f(*args, **kwds) if isinstance(result, defer.Deferred): result.addCallback(log_time, start=start) |