summaryrefslogtreecommitdiff
path: root/service/pixelated/support/__init__.py
blob: 0685f48dd45f3975a9e8eb1dd66f6f818cfe3e7d (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
#
# Copyright (c) 2014 ThoughtWorks, Inc.
#
# Pixelated is free software: you can redistribute it and/or modify
# it under the terms of the GNU Affero General Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# Pixelated is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU Affero General Public License for more details.
#
# You should have received a copy of the GNU Affero General Public License
# along with Pixelated. If not, see <http://www.gnu.org/licenses/>.
import time
from functools import wraps
from twisted.internet import defer
from twisted.logger import Logger


log = Logger()


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 = _start_stopwatch()

        result = f(*args, **kwds)

        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

    return wrapper


def log_time_deferred(f):

    def log_time(result, start):
        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 = _start_stopwatch()
        result = f(*args, **kwds)
        if isinstance(result, defer.Deferred):
            result.addCallback(log_time, start=start)
        else:
            log.warn('No Deferred returned, perhaps need to re-order annotations?')
        return result

    return wrapper