|
1
|
|
|
from __future__ import print_function |
|
2
|
|
|
|
|
3
|
|
|
import sys |
|
4
|
|
|
import timeit |
|
5
|
|
|
from collections import defaultdict, OrderedDict |
|
6
|
|
|
|
|
7
|
|
|
|
|
8
|
|
|
class Profile(object): |
|
9
|
|
|
"""A profile of hierarchical timers. |
|
10
|
|
|
|
|
11
|
|
|
Keeps track of timings performed with :class:`Timer`. It also keeps |
|
12
|
|
|
track of the way these timings were nested and makes use of this |
|
13
|
|
|
information when reporting. |
|
14
|
|
|
|
|
15
|
|
|
""" |
|
16
|
|
|
def __init__(self): |
|
17
|
|
|
self.total = defaultdict(int) |
|
18
|
|
|
self.current = [] |
|
19
|
|
|
self.order = OrderedDict() |
|
20
|
|
|
|
|
21
|
|
|
def enter(self, name): |
|
22
|
|
|
self.current.append(name) |
|
23
|
|
|
# We record the order in which sections were first called |
|
24
|
|
|
self.order[tuple(self.current)] = None |
|
25
|
|
|
|
|
26
|
|
|
def exit(self, t): |
|
27
|
|
|
self.total[tuple(self.current)] += t |
|
28
|
|
|
self.current.pop() |
|
29
|
|
|
|
|
30
|
|
|
def report(self, f=sys.stderr): |
|
31
|
|
|
"""Print a report of timing information to standard output. |
|
32
|
|
|
|
|
33
|
|
|
Parameters |
|
34
|
|
|
---------- |
|
35
|
|
|
f : object, optional |
|
36
|
|
|
An object with a ``write`` method that accepts string inputs. |
|
37
|
|
|
Can be a file object, ``sys.stdout``, etc. Defaults to |
|
38
|
|
|
``sys.stderr``. |
|
39
|
|
|
|
|
40
|
|
|
""" |
|
41
|
|
|
total = sum(v for k, v in self.total.items() if len(k) == 1) |
|
42
|
|
|
|
|
43
|
|
|
def print_report(keys, level=0): |
|
44
|
|
|
subtotal = 0 |
|
45
|
|
|
for key in keys: |
|
46
|
|
|
if len(key) > level + 1: |
|
47
|
|
|
continue |
|
48
|
|
|
subtotal += self.total[key] |
|
49
|
|
|
section = ' '.join(key[-1].split('_')) |
|
50
|
|
|
section = section[0].upper() + section[1:] |
|
51
|
|
|
print('{:30}{:15.2f}{:15.2%}'.format( |
|
52
|
|
|
level * ' ' + section, self.total[key], |
|
53
|
|
|
self.total[key] / total |
|
54
|
|
|
), file=f) |
|
55
|
|
|
children = [k for k in keys |
|
56
|
|
|
if k[level] == key[level] and |
|
57
|
|
|
len(k) > level + 1] |
|
58
|
|
|
child_total = print_report(children, level + 1) |
|
59
|
|
|
if children: |
|
60
|
|
|
print('{:30}{:15.2f}{:15.2%}'.format( |
|
61
|
|
|
(level + 1) * ' ' + 'Other', |
|
62
|
|
|
self.total[key] - child_total, |
|
63
|
|
|
(self.total[key] - child_total) / total |
|
64
|
|
|
), file=f) |
|
65
|
|
|
return subtotal |
|
66
|
|
|
|
|
67
|
|
|
print('{:30}{:>15}{:>15}'.format('Section', 'Time', '% of total'), |
|
68
|
|
|
file=f) |
|
69
|
|
|
print('-' * 60, file=f) |
|
70
|
|
|
if total: |
|
71
|
|
|
print_report(self.order.keys()) |
|
72
|
|
|
else: |
|
73
|
|
|
print('No profile information collected.', file=f) |
|
74
|
|
|
|
|
75
|
|
|
|
|
76
|
|
|
class Timer(object): |
|
77
|
|
|
"""A context manager to time the execution time of code within it. |
|
78
|
|
|
|
|
79
|
|
|
This timer is attached to a :class:`Profile` object that it reports |
|
80
|
|
|
timings to. The :class:`Profile` object accumulates the timings. |
|
81
|
|
|
Timers can be nested, which the :class:`Profile` will automatically |
|
82
|
|
|
keep track of and use in its reporting. |
|
83
|
|
|
|
|
84
|
|
|
Parameters |
|
85
|
|
|
---------- |
|
86
|
|
|
name : str |
|
87
|
|
|
The name of this section. Expected to adhere to variable naming |
|
88
|
|
|
styles. |
|
89
|
|
|
profile : :class:`Profile` |
|
90
|
|
|
The profile of the main loop. This is the object this context |
|
91
|
|
|
manager will report the execution time to. The accumulation and |
|
92
|
|
|
processing of timing information is handled by this object. |
|
93
|
|
|
|
|
94
|
|
|
Notes |
|
95
|
|
|
----- |
|
96
|
|
|
Timings are reported using :func:`timeit.default_timer`. |
|
97
|
|
|
|
|
98
|
|
|
""" |
|
99
|
|
|
def __init__(self, name, profile): |
|
100
|
|
|
self.name = name |
|
101
|
|
|
self.profile = profile |
|
102
|
|
|
|
|
103
|
|
|
def __enter__(self): |
|
104
|
|
|
self.profile.enter(self.name) |
|
105
|
|
|
self.start = timeit.default_timer() |
|
106
|
|
|
|
|
107
|
|
|
def __exit__(self, *args): |
|
108
|
|
|
self.profile.exit(timeit.default_timer() - self.start) |
|
109
|
|
|
|
mila-udem /
blocks
