2
# tag: monitoring, trace
3
# cython: language_level=3
4
# cython: profile=True, linetrace=True
5
# distutils: define_macros = CYTHON_TRACE_NOGIL=1
10
from collections import defaultdict
11
from contextlib import contextmanager
12
from functools import partial
15
from sys import monitoring as smon
19
FUNC_EVENTS = GEN_EVENTS = ()
26
TOOL_ID = smon.PROFILER_ID
27
FUNC_EVENTS = (E.PY_START, E.PY_RETURN, E.RAISE)
28
GEN_EVENTS = FUNC_EVENTS + (E.PY_RESUME, E.PY_YIELD) # , E.STOP_ITERATION)
29
event_name = {1 << event_id: name for name, event_id in vars(E).items()}.get
33
# python3 -c 'import sys_monitoring as sm; sm.print_event_traces()' > pytrace.log
34
# Then compile the module and run:
35
# python3 -c 'import sys_monitoring as sm; sm.print_event_traces()' > cytrace.log
36
# Compare the two logs.
38
ALL_EVENTS = sorted([(name, value) for (name, value) in vars(E).items() if value != 0], key=operator.itemgetter(1))
40
@cython.profile(False)
41
@cython.linetrace(False)
42
def print_event_traces():
43
trace_events(test_profile)
44
trace_events(test_generators)
46
@cython.profile(False)
47
@cython.linetrace(False)
48
def trace_events(func=None, events=ALL_EVENTS):
49
event_set = E.NO_EVENTS
50
for _, event in events:
53
last_code_obj = [None]
55
@cython.profile(False)
56
@cython.linetrace(False)
57
def print_event(event, code_obj, offset, *args):
58
if last_code_obj[0] is not code_obj:
59
last_code_obj[0] = code_obj
61
print(f"{event}, {code_obj.co_name}:{code_obj.co_firstlineno}, {offset}{', ' if args else ''}", *args)
64
smon.use_tool_id(TOOL_ID, 'cython-test')
65
for name, event in events:
66
smon.register_callback(TOOL_ID, event, partial(print_event, name))
67
smon.set_events(TOOL_ID, event_set)
69
result = func(1) if func is not None else test_profile(1)
72
smon.set_events(TOOL_ID, event_set)
73
for _, event in events:
74
smon.register_callback(TOOL_ID, event, None)
75
smon.free_tool_id(TOOL_ID)
82
>>> from itertools import combinations
84
>>> smon.use_tool_id(TOOL_ID, 'cython-test')
86
>>> with monitored_events(events=()) as collected_events:
87
... print(test_profile(0))
89
>>> list(collected_events.items()) # test_profile(0)
92
>>> with monitored_events(events=()) as collected_events:
93
... print(test_profile(1))
95
>>> list(collected_events.items()) # test_profile(1)
98
>>> with monitored_events(events=()) as collected_events:
99
... print(test_profile(2))
101
>>> list(collected_events.items()) # test_profile(2)
105
## Testing combinations of events:
107
>>> for num_events in range(1, len(FUNC_EVENTS)+1): # doctest: +REPORT_NDIFF
108
... for event_set in combinations(FUNC_EVENTS, num_events):
109
... print(f"--- {names(event_set)} ---")
110
... with monitored_events(events=event_set + (E.RERAISE, E.PY_UNWIND)) as collected_events:
111
... result = test_profile(10)
113
... print_events(collected_events)
114
... assert_events(event_set, collected_events['test_profile']) # test_profile(10)
118
f_cpdef PY_START [20]
120
f_inline PY_START [10]
121
f_inline_prof PY_START [10]
122
f_nogil_prof PY_START [10]
123
f_raise PY_START [20], PY_UNWIND [20]
124
f_reraise PY_START [10], PY_UNWIND [10], RERAISE [10]
125
f_return_default PY_START [10]
126
f_return_none PY_START [10]
127
f_withgil_prof PY_START [10]
129
m_classmethod PY_START [10]
130
m_cpdef PY_START [20]
132
m_staticmethod PY_START [10]
133
test_profile PY_START [1]
136
f_cdef PY_RETURN [10]
137
f_cpdef PY_RETURN [20]
139
f_inline PY_RETURN [10]
140
f_inline_prof PY_RETURN [10]
141
f_nogil_prof PY_RETURN [10]
142
f_raise PY_UNWIND [20]
143
f_reraise PY_UNWIND [10], RERAISE [10]
144
f_return_default PY_RETURN [10]
145
f_return_none PY_RETURN [10]
146
f_withgil_prof PY_RETURN [10]
147
m_cdef PY_RETURN [10]
148
m_classmethod PY_RETURN [10]
149
m_cpdef PY_RETURN [20]
151
m_staticmethod PY_RETURN [10]
152
test_profile PY_RETURN [1]
155
f_raise RAISE [20], PY_UNWIND [20]
156
f_reraise RAISE [10], PY_UNWIND [10], RERAISE [10]
157
test_profile RAISE [20]
158
--- PY_START, PY_RETURN ---
160
f_cdef PY_START [10], PY_RETURN [10]
161
f_cpdef PY_START [20], PY_RETURN [20]
162
f_def PY_START [10], PY_RETURN [10]
163
f_inline PY_START [10], PY_RETURN [10]
164
f_inline_prof PY_START [10], PY_RETURN [10]
165
f_nogil_prof PY_START [10], PY_RETURN [10]
166
f_raise PY_START [20], PY_UNWIND [20]
167
f_reraise PY_START [10], PY_UNWIND [10], RERAISE [10]
168
f_return_default PY_START [10], PY_RETURN [10]
169
f_return_none PY_START [10], PY_RETURN [10]
170
f_withgil_prof PY_START [10], PY_RETURN [10]
171
m_cdef PY_START [10], PY_RETURN [10]
172
m_classmethod PY_START [10], PY_RETURN [10]
173
m_cpdef PY_START [20], PY_RETURN [20]
174
m_def PY_START [20], PY_RETURN [20]
175
m_staticmethod PY_START [10], PY_RETURN [10]
176
test_profile PY_START [1], PY_RETURN [1]
177
--- PY_START, RAISE ---
180
f_cpdef PY_START [20]
182
f_inline PY_START [10]
183
f_inline_prof PY_START [10]
184
f_nogil_prof PY_START [10]
185
f_raise PY_START [20], RAISE [20], PY_UNWIND [20]
186
f_reraise PY_START [10], RAISE [10], PY_UNWIND [10], RERAISE [10]
187
f_return_default PY_START [10]
188
f_return_none PY_START [10]
189
f_withgil_prof PY_START [10]
191
m_classmethod PY_START [10]
192
m_cpdef PY_START [20]
194
m_staticmethod PY_START [10]
195
test_profile PY_START [1], RAISE [20]
196
--- PY_RETURN, RAISE ---
198
f_cdef PY_RETURN [10]
199
f_cpdef PY_RETURN [20]
201
f_inline PY_RETURN [10]
202
f_inline_prof PY_RETURN [10]
203
f_nogil_prof PY_RETURN [10]
204
f_raise RAISE [20], PY_UNWIND [20]
205
f_reraise RAISE [10], PY_UNWIND [10], RERAISE [10]
206
f_return_default PY_RETURN [10]
207
f_return_none PY_RETURN [10]
208
f_withgil_prof PY_RETURN [10]
209
m_cdef PY_RETURN [10]
210
m_classmethod PY_RETURN [10]
211
m_cpdef PY_RETURN [20]
213
m_staticmethod PY_RETURN [10]
214
test_profile PY_RETURN [1], RAISE [20]
215
--- PY_START, PY_RETURN, RAISE ---
217
f_cdef PY_START [10], PY_RETURN [10]
218
f_cpdef PY_START [20], PY_RETURN [20]
219
f_def PY_START [10], PY_RETURN [10]
220
f_inline PY_START [10], PY_RETURN [10]
221
f_inline_prof PY_START [10], PY_RETURN [10]
222
f_nogil_prof PY_START [10], PY_RETURN [10]
223
f_raise PY_START [20], RAISE [20], PY_UNWIND [20]
224
f_reraise PY_START [10], RAISE [10], PY_UNWIND [10], RERAISE [10]
225
f_return_default PY_START [10], PY_RETURN [10]
226
f_return_none PY_START [10], PY_RETURN [10]
227
f_withgil_prof PY_START [10], PY_RETURN [10]
228
m_cdef PY_START [10], PY_RETURN [10]
229
m_classmethod PY_START [10], PY_RETURN [10]
230
m_cpdef PY_START [20], PY_RETURN [20]
231
m_def PY_START [20], PY_RETURN [20]
232
m_staticmethod PY_START [10], PY_RETURN [10]
233
test_profile PY_START [1], PY_RETURN [1], RAISE [20]
236
## Testing generators:
238
>>> with monitored_events(events=GEN_EVENTS, function_name='f_generator') as collected_events:
239
... gen = f_generator()
240
... for i in gen: print(i)
243
>>> print_events(collected_events) # f_generator
244
f_generator PY_START [1], PY_RESUME [2], PY_RETURN [1], PY_YIELD [2]
247
>>> with monitored_events(events=GEN_EVENTS, function_name='test_generators') as collected_events:
248
... test_generators()
249
>>> print_events(collected_events) # test_generators()
250
f_generator PY_START [1], PY_RESUME [2], PY_RETURN [1], PY_YIELD [2]
251
f_generator_exception PY_START [1], PY_RESUME [1], PY_YIELD [1], RAISE [1]
252
f_generator_expr PY_START [1], PY_RETURN [1]
253
test_generators PY_START [1], PY_RETURN [1]
256
## Testing line events:
258
>>> events = (E.PY_START, E.PY_RETURN)
259
>>> for num_events in range(1, len(events)+1): # doctest: +REPORT_NDIFF
260
... for event_set in combinations(events, num_events):
261
... event_set += (E.RAISE, E.LINE)
262
... print(f"--- {names(event_set)} ---")
263
... with monitored_events(events=event_set + (E.RERAISE, E.PY_UNWIND)) as (collected_events, collected_line_events):
264
... result = test_profile(10)
266
... print_events(collected_events)
267
... assert_events(event_set, collected_events['test_profile']) # test_profile(10)
268
--- PY_START, LINE, RAISE ---
270
f_cdef PY_START [10], LINE [10]
271
f_cpdef PY_START [20], LINE [20]
272
f_def PY_START [10], LINE [10]
273
f_inline PY_START [10], LINE [10]
274
f_inline_prof PY_START [10], LINE [10]
275
f_nogil_prof PY_START [10], LINE [10]
276
f_raise PY_START [20], LINE [20], RAISE [20], PY_UNWIND [20]
277
f_reraise PY_START [10], LINE [50], RAISE [10], PY_UNWIND [10], RERAISE [10]
278
f_return_default PY_START [10], LINE [10]
279
f_return_none PY_START [10], LINE [10]
280
f_withgil_prof PY_START [10], LINE [10]
281
m_cdef PY_START [10], LINE [10]
282
m_classmethod PY_START [10], LINE [10]
283
m_cpdef PY_START [20], LINE [20]
284
m_def PY_START [20], LINE [20]
285
m_staticmethod PY_START [10], LINE [10]
286
test_profile PY_START [1], LINE [385], RAISE [20]
287
--- PY_RETURN, LINE, RAISE ---
289
f_cdef PY_RETURN [10], LINE [10]
290
f_cpdef PY_RETURN [20], LINE [20]
291
f_def PY_RETURN [10], LINE [10]
292
f_inline PY_RETURN [10], LINE [10]
293
f_inline_prof PY_RETURN [10], LINE [10]
294
f_nogil_prof PY_RETURN [10], LINE [10]
295
f_raise LINE [20], RAISE [20], PY_UNWIND [20]
296
f_reraise LINE [50], RAISE [10], PY_UNWIND [10], RERAISE [10]
297
f_return_default PY_RETURN [10], LINE [10]
298
f_return_none PY_RETURN [10], LINE [10]
299
f_withgil_prof PY_RETURN [10], LINE [10]
300
m_cdef PY_RETURN [10], LINE [10]
301
m_classmethod PY_RETURN [10], LINE [10]
302
m_cpdef PY_RETURN [20], LINE [20]
303
m_def PY_RETURN [20], LINE [20]
304
m_staticmethod PY_RETURN [10], LINE [10]
305
test_profile PY_RETURN [1], LINE [385], RAISE [20]
306
--- PY_START, PY_RETURN, LINE, RAISE ---
308
f_cdef PY_START [10], PY_RETURN [10], LINE [10]
309
f_cpdef PY_START [20], PY_RETURN [20], LINE [20]
310
f_def PY_START [10], PY_RETURN [10], LINE [10]
311
f_inline PY_START [10], PY_RETURN [10], LINE [10]
312
f_inline_prof PY_START [10], PY_RETURN [10], LINE [10]
313
f_nogil_prof PY_START [10], PY_RETURN [10], LINE [10]
314
f_raise PY_START [20], LINE [20], RAISE [20], PY_UNWIND [20]
315
f_reraise PY_START [10], LINE [50], RAISE [10], PY_UNWIND [10], RERAISE [10]
316
f_return_default PY_START [10], PY_RETURN [10], LINE [10]
317
f_return_none PY_START [10], PY_RETURN [10], LINE [10]
318
f_withgil_prof PY_START [10], PY_RETURN [10], LINE [10]
319
m_cdef PY_START [10], PY_RETURN [10], LINE [10]
320
m_classmethod PY_START [10], PY_RETURN [10], LINE [10]
321
m_cpdef PY_START [20], PY_RETURN [20], LINE [20]
322
m_def PY_START [20], PY_RETURN [20], LINE [20]
323
m_staticmethod PY_START [10], PY_RETURN [10], LINE [10]
324
test_profile PY_START [1], PY_RETURN [1], LINE [385], RAISE [20]
327
## Testing fused functions:
329
>>> with monitored_events(events=FUNC_EVENTS, function_name='call_fused_functions') as collected_events:
330
... call_fused_functions()
331
>>> print_events(collected_events) # call_fused_functions()
332
call_fused_functions PY_START [1], PY_RETURN [1]
335
>>> smon.free_tool_id(TOOL_ID)
340
return ', '.join([event_name(1 << event_id) for event_id in sorted(event_ids)])
343
def print_events(collected_events):
344
def event_sum(event_id, event_counts):
345
count = sum(event_counts)
346
if not cython.compiled and event_id == E.RERAISE and count == 20:
347
# CPython bug, see https://github.com/python/cpython/issues/118360
351
for func_name, line_counts in sorted(collected_events.items()):
353
', '.join(f"{names([event_id])} [{event_sum(event_id, counts.values())}]" for event_id, counts in sorted(line_counts.items())))
356
def assert_events(expected_events, collected_events, loops=10):
357
missing = set(expected_events).difference(collected_events)
358
surplus = set(collected_events).difference(expected_events)
361
print(f"Expected: [{names(expected_events)}], missing: [{names(missing)}]")
363
print(f"Expected: [{names(expected_events)}], surplus: [{names(surplus)}]")
365
collected_events = {name: dict(values) for name, values in collected_events.items()}
369
@cython.profile(False)
370
@cython.linetrace(False)
371
def monitored_events(events=FUNC_EVENTS, function_name="test_profile"):
372
event_set = E.NO_EVENTS
376
collected_events = defaultdict(lambda: defaultdict(lambda: defaultdict(int)))
377
collected_line_events = defaultdict(int)
379
@cython.profile(False)
380
@cython.linetrace(False)
381
def count_event(event, code_obj, offset, *args):
382
if not (code_obj.co_name.startswith('f_') or code_obj.co_name.startswith('m_') or code_obj.co_name == function_name):
383
return smon.DISABLE if event != E.RAISE else None
384
if ' (wrapper)' in code_obj.co_name:
385
return # ignore cpdef wrapper
386
if not cython.compiled and 'noprof' in code_obj.co_name:
387
return smon.DISABLE if event != E.RAISE else None
390
collected_line_events[offset] += 1
391
assert offset in (line for line, *_ in code_obj.co_positions()), f"{code_obj.co_name}: {offset} in {list(code_obj.co_positions())}"
392
collected_events[code_obj.co_name][event][offset] += 1
396
smon.register_callback(TOOL_ID, event, partial(count_event, event))
397
smon.set_events(TOOL_ID, event_set)
398
if event_set & E.LINE:
399
yield collected_events, collected_line_events
401
yield collected_events
403
smon.set_events(TOOL_ID, event_set)
405
smon.register_callback(TOOL_ID, event, None)
411
def test_profile(N: cython.long):
426
n += f_inline_prof(i)
428
n += f_nogil_noprof(i)
430
n += f_withgil_noprof(i)
431
n += f_withgil_prof(i)
433
retval = f_return_none(i)
434
assert retval is None, retval
435
retval = f_return_default(i)
436
assert retval == (0 if cython.compiled else None), retval
444
n += CyA.m_staticmethod(i)
445
n += a.m_classmethod(i)
450
n += py_a.pym_staticmethod(i)
451
n += py_a.pym_classmethod(i)
463
def f_def(a: cython.long):
467
def f_cdef(a: cython.long) -> cython.long:
471
def f_cpdef(a: cython.long) -> cython.long:
476
def f_inline(a: cython.long) -> cython.long:
482
def f_inline_prof(a: cython.long) -> cython.long:
485
@cython.profile(False)
486
@cython.linetrace(False)
488
def f_noprof(a: cython.long) -> cython.long:
493
def f_raise(_: cython.long) -> cython.long:
498
def f_reraise(a: cython.long) -> cython.long:
506
@cython.profile(False)
507
@cython.linetrace(False)
510
def f_withgil_noprof(a: cython.long) -> cython.long:
516
def f_withgil_prof(a: cython.long) -> cython.long:
519
@cython.profile(False)
520
@cython.linetrace(False)
523
def f_nogil_noprof(a: cython.long) -> cython.long:
529
def f_nogil_prof(a: cython.long) -> cython.long:
533
def f_return_none(_: cython.long):
537
def f_return_default(_: cython.long) -> cython.long:
543
def m_def(self, a: cython.long):
547
def m_cpdef(self, a: cython.long):
551
def m_cdef(self, a: cython.long) -> cython.long:
556
def m_classmethod(cls, a: cython.long) -> cython.long:
561
def m_staticmethod(a: cython.long) -> cython.long:
566
def pym_def(self, a: cython.long):
570
def pym_classmethod(cls, a: cython.long) -> cython.long:
574
def pym_staticmethod(a: cython.long) -> cython.long:
580
def test_generators(_=None):
582
call_generator_exception()
592
def call_generator_exception():
594
list(f_generator_exception())
598
def f_generator_exception():
602
def f_generator_expr():
603
e = (x for x in range(10))
609
def call_fused_functions():
611
assert 5 == fused_func_def['short'](3)
612
assert 5 == fused_func_def['int'](3)
613
assert 5 == fused_func_def['double'](3)
614
assert 5 == fused_func_def['float'](3)
615
assert 5 == fused_func_def['long'](3)
617
assert 5.0 == fused_func_def(3.0)
618
assert 5 == fused_func_def(3)
621
assert 5 == fused_func_cfunc[cython.short](3)
622
assert 5 == fused_func_cfunc[cython.int](3)
623
assert 5 == fused_func_cfunc[cython.double](3)
624
assert 5 == fused_func_cfunc[cython.float](3)
625
assert 5 == fused_func_cfunc[cython.long](3)
627
assert 5.0 == fused_func_cfunc(3.0)
628
assert 5 == fused_func_cfunc(3)
631
def fused_func_def(x: cython.numeric) -> cython.numeric:
635
def fused_func_cfunc(x: cython.numeric) -> cython.numeric: