cython

1
# cython: linetrace=True
2
# distutils: define_macros=CYTHON_TRACE_NOGIL=1
3
# mode: run
4
# tag: trace
5

6
import sys
7
import gc
8
from contextlib import contextmanager
9

10
from cpython.ref cimport PyObject, Py_INCREF, Py_XDECREF
11

12
cdef extern from "frameobject.h":
13
    ctypedef struct PyFrameObject:
14
        PyObject *f_trace
15

16
from cpython.pystate cimport (
17
    Py_tracefunc,
18
    PyTrace_CALL, PyTrace_EXCEPTION, PyTrace_LINE, PyTrace_RETURN,
19
    PyTrace_C_CALL, PyTrace_C_EXCEPTION, PyTrace_C_RETURN)
20

21
cdef extern from *:
22
    void PyEval_SetProfile(Py_tracefunc cfunc, PyObject *obj)
23
    void PyEval_SetTrace(Py_tracefunc cfunc, PyObject *obj)
24

25

26
map_trace_types = {
27
    PyTrace_CALL:        'call',
28
    PyTrace_EXCEPTION:   'exception',
29
    PyTrace_LINE:        'line',
30
    PyTrace_RETURN:      'return',
31
    PyTrace_C_CALL:      'ccall',
32
    PyTrace_C_EXCEPTION: 'cexc',
33
    PyTrace_C_RETURN:    'cret',
34
}.get
35

36

37
cdef int trace_trampoline(PyObject* _traceobj, PyFrameObject* _frame, int what, PyObject* _arg) except -1:
38
    """
39
    This is (more or less) what CPython does in sysmodule.c, function trace_trampoline().
40
    """
41
    cdef PyObject *tmp
42

43
    if what == PyTrace_CALL:
44
        if _traceobj is NULL:
45
            return 0
46
        callback = <object>_traceobj
47
    elif _frame.f_trace:
48
        callback = <object>_frame.f_trace
49
    else:
50
        return 0
51

52
    frame = <object>_frame
53
    arg = <object>_arg if _arg else None
54

55
    try:
56
        result = callback(frame, what, arg)
57
    except:
58
        PyEval_SetTrace(NULL, NULL)
59
        tmp = _frame.f_trace
60
        _frame.f_trace = NULL
61
        Py_XDECREF(tmp)
62
        raise
63

64
    if result is not None:
65
        # A bug in Py2.6 prevents us from calling the Python-level setter here,
66
        # or otherwise we would get miscalculated line numbers. Was fixed in Py2.7.
67
        tmp = _frame.f_trace
68
        Py_INCREF(result)
69
        _frame.f_trace = <PyObject*>result
70
        Py_XDECREF(tmp)
71

72
    return 0
73

74

75
def _create_trace_func(trace):
76
    local_names = {}
77

78
    def _trace_func(frame, event, arg):
79
        trace.append((frame.f_code.co_name, map_trace_types(event, event), frame.f_lineno - frame.f_code.co_firstlineno))
80

81
        lnames = frame.f_code.co_varnames
82
        if frame.f_code.co_name in local_names:
83
            assert lnames == local_names[frame.f_code.co_name]
84
        else:
85
            local_names[frame.f_code.co_name] = lnames
86

87
        # Currently, the locals dict is empty for Cython code, but not for Python code.
88
        if frame.f_code.co_name.startswith('py_'):
89
            # Change this when we start providing proper access to locals.
90
            assert frame.f_locals, frame.f_code.co_name
91
        else:
92
            assert not frame.f_locals, frame.f_code.co_name
93

94
        return _trace_func
95
    return _trace_func
96

97

98
def _create_failing_call_trace_func(trace):
99
    func = _create_trace_func(trace)
100
    def _trace_func(frame, event, arg):
101
        if event == PyTrace_CALL:
102
            raise ValueError("failing call trace!")
103

104
        func(frame, event, arg)
105
        return _trace_func
106

107
    return _trace_func
108

109

110
def _create__failing_line_trace_func(trace):
111
    func = _create_trace_func(trace)
112
    def _trace_func(frame, event, arg):
113
        if event == PyTrace_LINE and trace:
114
            if trace and trace[0] == frame.f_code.co_name:
115
                # first line in the right function => fail!
116
                raise ValueError("failing line trace!")
117

118
        func(frame, event, arg)
119
        return _trace_func
120
    return _trace_func
121

122

123
def _create_disable_tracing(trace):
124
    func = _create_trace_func(trace)
125
    def _trace_func(frame, event, arg):
126
        if frame.f_lineno - frame.f_code.co_firstlineno == 2:
127
            PyEval_SetTrace(NULL, NULL)
128
            return None
129

130
        func(frame, event, arg)
131
        return _trace_func
132

133
    return _trace_func
134

135

136
def cy_add(a,b):
137
    x = a + b     # 1
138
    return x      # 2
139

140

141
def cy_add_with_nogil(a,b):
142
    cdef int z, x=a, y=b         # 1
143
    with nogil:                  # 2
144
        z = 0                    # 3
145
        z += cy_add_nogil(x, y)  # 4
146
    return z                     # 5
147

148

149
def global_name(global_name):
150
    # See GH #1836: accessing "frame.f_locals" deletes locals from globals dict.
151
    return global_name + 321
152

153

154
cdef int cy_add_nogil(int a, int b) except -1 nogil:
155
    x = a + b   # 1
156
    return x    # 2
157

158

159
def cy_try_except(func):
160
    try:
161
        return func()
162
    except KeyError as exc:
163
        raise AttributeError(exc.args[0])
164

165

166
# CPython 3.11 has an issue when these Python functions are implemented inside of doctests and the trace function fails.
167
# https://github.com/python/cpython/issues/94381
168
plain_python_functions = {}
169
exec("""
170
def py_add(a,b):
171
    x = a+b
172
    return x
173

174
def py_add_with_nogil(a,b):
175
    x=a; y=b                     # 1
176
    for _ in range(1):           # 2
177
        z = 0                    # 3
178
        z += py_add(x, y)        # 4
179
    return z
180

181
def py_return(retval=123): return retval
182

183
def py_try_except(func):
184
    try:
185
        return func()
186
    except KeyError as exc:
187
        raise AttributeError(exc.args[0])
188
""", plain_python_functions)
189

190

191
@contextmanager
192
def gc_off():
193
    was_enabled = gc.isenabled()
194
    gc.disable()
195
    try:
196
        yield
197
    finally:
198
        if was_enabled:
199
            gc.enable()
200

201

202
def run_trace(func, *args, bint with_sys=False):
203
    """
204
    >>> py_add = plain_python_functions['py_add']
205
    >>> run_trace(py_add, 1, 2)
206
    [('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
207
    >>> run_trace(cy_add, 1, 2)
208
    [('cy_add', 'call', 0), ('cy_add', 'line', 1), ('cy_add', 'line', 2), ('cy_add', 'return', 2)]
209

210
    >>> run_trace(py_add, 1, 2, with_sys=True)
211
    [('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
212
    >>> run_trace(cy_add, 1, 2, with_sys=True)
213
    [('cy_add', 'call', 0), ('cy_add', 'line', 1), ('cy_add', 'line', 2), ('cy_add', 'return', 2)]
214

215
    >>> result = run_trace(cy_add_with_nogil, 1, 2)
216
    >>> result[:5]
217
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1), ('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 3), ('cy_add_with_nogil', 'line', 4)]
218
    >>> result[5:9]
219
    [('cy_add_nogil', 'call', 0), ('cy_add_nogil', 'line', 1), ('cy_add_nogil', 'line', 2), ('cy_add_nogil', 'return', 2)]
220
    >>> result[9:]
221
    [('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 5), ('cy_add_with_nogil', 'return', 5)]
222

223
    >>> result = run_trace(cy_add_with_nogil, 1, 2, with_sys=True)
224
    >>> result[:5]  # sys
225
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1), ('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 3), ('cy_add_with_nogil', 'line', 4)]
226
    >>> result[5:9]  # sys
227
    [('cy_add_nogil', 'call', 0), ('cy_add_nogil', 'line', 1), ('cy_add_nogil', 'line', 2), ('cy_add_nogil', 'return', 2)]
228
    >>> result[9:]  # sys
229
    [('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 5), ('cy_add_with_nogil', 'return', 5)]
230

231
    >>> py_add_with_nogil = plain_python_functions['py_add_with_nogil']
232
    >>> result = run_trace(py_add_with_nogil, 1, 2)
233
    >>> result[:5]  # py
234
    [('py_add_with_nogil', 'call', 0), ('py_add_with_nogil', 'line', 1), ('py_add_with_nogil', 'line', 2), ('py_add_with_nogil', 'line', 3), ('py_add_with_nogil', 'line', 4)]
235
    >>> result[5:9]  # py
236
    [('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
237
    >>> result[9:]  # py
238
    [('py_add_with_nogil', 'line', 2), ('py_add_with_nogil', 'line', 5), ('py_add_with_nogil', 'return', 5)]
239

240
    >>> run_trace(global_name, 123)
241
    [('global_name', 'call', 0), ('global_name', 'line', 2), ('global_name', 'return', 2)]
242
    >>> run_trace(global_name, 111)
243
    [('global_name', 'call', 0), ('global_name', 'line', 2), ('global_name', 'return', 2)]
244
    >>> run_trace(global_name, 111, with_sys=True)
245
    [('global_name', 'call', 0), ('global_name', 'line', 2), ('global_name', 'return', 2)]
246
    >>> run_trace(global_name, 111, with_sys=True)
247
    [('global_name', 'call', 0), ('global_name', 'line', 2), ('global_name', 'return', 2)]
248
    """
249
    trace = []
250
    trace_func = _create_trace_func(trace)
251
    with gc_off():
252
        if with_sys:
253
            sys.settrace(trace_func)
254
        else:
255
            PyEval_SetTrace(<Py_tracefunc>trace_trampoline, <PyObject*>trace_func)
256
        try:
257
            func(*args)
258
        finally:
259
            if with_sys:
260
                sys.settrace(None)
261
            else:
262
                PyEval_SetTrace(NULL, NULL)
263
    return trace
264

265

266
def run_trace_with_exception(func, bint with_sys=False, bint fail=False, call_func=cy_try_except):
267
    """
268
    >>> py_return = plain_python_functions["py_return"]
269
    >>> run_trace_with_exception(py_return)
270
    OK: 123
271
    [('cy_try_except', 'call', 0), ('cy_try_except', 'line', 1), ('cy_try_except', 'line', 2), ('py_return', 'call', 0), ('py_return', 'line', 0), ('py_return', 'return', 0), ('cy_try_except', 'return', 2)]
272
    >>> run_trace_with_exception(py_return, with_sys=True)
273
    OK: 123
274
    [('cy_try_except', 'call', 0), ('cy_try_except', 'line', 1), ('cy_try_except', 'line', 2), ('py_return', 'call', 0), ('py_return', 'line', 0), ('py_return', 'return', 0), ('cy_try_except', 'return', 2)]
275

276
    >>> run_trace_with_exception(py_return, fail=True)
277
    ValueError('failing line trace!')
278
    [('cy_try_except', 'call', 0)]
279

280
    #>>> run_trace_with_exception(lambda: 123, with_sys=True, fail=True)
281
    #ValueError('huhu')
282
    #[('call', 0), ('line', 1), ('line', 2), ('call', 0), ('line', 0), ('return', 0), ('return', 2)]
283

284
    >>> def py_raise_exc(exc=KeyError('huhu')): raise exc
285
    >>> run_trace_with_exception(py_raise_exc)
286
    AttributeError('huhu')
287
    [('cy_try_except', 'call', 0), ('cy_try_except', 'line', 1), ('cy_try_except', 'line', 2), ('py_raise_exc', 'call', 0), ('py_raise_exc', 'line', 0), ('py_raise_exc', 'exception', 0), ('py_raise_exc', 'return', 0), ('cy_try_except', 'line', 3), ('cy_try_except', 'line', 4), ('cy_try_except', 'return', 4)]
288
    >>> run_trace_with_exception(py_raise_exc, with_sys=True)
289
    AttributeError('huhu')
290
    [('cy_try_except', 'call', 0), ('cy_try_except', 'line', 1), ('cy_try_except', 'line', 2), ('py_raise_exc', 'call', 0), ('py_raise_exc', 'line', 0), ('py_raise_exc', 'exception', 0), ('py_raise_exc', 'return', 0), ('cy_try_except', 'line', 3), ('cy_try_except', 'line', 4), ('cy_try_except', 'return', 4)]
291
    >>> run_trace_with_exception(py_raise_exc, fail=True)
292
    ValueError('failing line trace!')
293
    [('cy_try_except', 'call', 0)]
294

295
    # Py3.9 issues a spurious additional line event after raising the final exception, so use +ELLIPSIS.
296
    >>> py_try_except = plain_python_functions['py_try_except']
297
    >>> run_trace_with_exception(py_raise_exc, call_func=py_try_except)  # doctest: +ELLIPSIS
298
    AttributeError('huhu')
299
    [('py_try_except', 'call', 0), ('py_try_except', 'line', 1), ('py_try_except', 'line', 2), ('py_raise_exc', 'call', 0), ('py_raise_exc', 'line', 0), ('py_raise_exc', 'exception', 0), ('py_raise_exc', 'return', 0), ('py_try_except', 'exception', 2), ('py_try_except', 'line', 3), ('py_try_except', 'line', 4), ('py_try_except', 'exception', 4), ...('py_try_except', 'return', 4)]
300
    >>> run_trace_with_exception(py_raise_exc, with_sys=True, call_func=py_try_except)  # doctest: +ELLIPSIS
301
    AttributeError('huhu')
302
    [('py_try_except', 'call', 0), ('py_try_except', 'line', 1), ('py_try_except', 'line', 2), ('py_raise_exc', 'call', 0), ('py_raise_exc', 'line', 0), ('py_raise_exc', 'exception', 0), ('py_raise_exc', 'return', 0), ('py_try_except', 'exception', 2), ('py_try_except', 'line', 3), ('py_try_except', 'line', 4), ('py_try_except', 'exception', 4), ...('py_try_except', 'return', 4)]
303
    >>> run_trace_with_exception(py_raise_exc, fail=True, call_func=py_try_except)
304
    ValueError('failing line trace!')
305
    [('py_try_except', 'call', 0)]
306

307
    #>>> run_trace_with_exception(raise_exc, with_sys=True, fail=True)
308
    #ValueError('huhu')
309
    #[('call', 0), ('line', 1), ('line', 2), ('call', 0), ('line', 0), ('exception', 0), ('return', 0), ('line', 3), ('line', 4), ('return', 4)]
310
    """
311
    trace = [call_func.__name__ if fail else 'NO ERROR']
312
    trace_func = _create__failing_line_trace_func(trace) if fail else _create_trace_func(trace)
313
    with gc_off():
314
        if with_sys:
315
            sys.settrace(trace_func)
316
        else:
317
            PyEval_SetTrace(<Py_tracefunc>trace_trampoline, <PyObject*>trace_func)
318
        try:
319
            try:
320
                retval = call_func(func)
321
            except ValueError as exc:
322
                print("%s(%r)" % (type(exc).__name__, str(exc)))
323
            except AttributeError as exc:
324
                print("%s(%r)" % (type(exc).__name__, str(exc)))
325
            else:
326
                print('OK: %r' % retval)
327
        finally:
328
            if with_sys:
329
                sys.settrace(None)
330
            else:
331
                PyEval_SetTrace(NULL, NULL)
332
    return trace[1:]
333

334

335
def fail_on_call_trace(func, *args):
336
    """
337
    >>> py_add = plain_python_functions["py_add"]
338
    >>> fail_on_call_trace(py_add, 1, 2)
339
    Traceback (most recent call last):
340
    ValueError: failing call trace!
341

342
    >>> fail_on_call_trace(cy_add, 1, 2)
343
    Traceback (most recent call last):
344
    ValueError: failing call trace!
345
    """
346
    trace = []
347
    trace_func = _create_failing_call_trace_func(trace)
348
    with gc_off():
349
        PyEval_SetTrace(<Py_tracefunc>trace_trampoline, <PyObject*>trace_func)
350
        try:
351
            func(*args)
352
        finally:
353
            PyEval_SetTrace(NULL, NULL)
354
    assert not trace
355

356

357
def fail_on_line_trace(fail_func, add_func, nogil_add_func):
358
    """
359
    >>> result = fail_on_line_trace(None, cy_add, cy_add_with_nogil)
360
    >>> len(result)
361
    17
362
    >>> result[:5]
363
    ['NO ERROR', ('cy_add', 'call', 0), ('cy_add', 'line', 1), ('cy_add', 'line', 2), ('cy_add', 'return', 2)]
364
    >>> result[5:10]
365
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1), ('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 3), ('cy_add_with_nogil', 'line', 4)]
366
    >>> result[10:14]
367
    [('cy_add_nogil', 'call', 0), ('cy_add_nogil', 'line', 1), ('cy_add_nogil', 'line', 2), ('cy_add_nogil', 'return', 2)]
368
    >>> result[14:]
369
    [('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 5), ('cy_add_with_nogil', 'return', 5)]
370

371
    >>> py_add = plain_python_functions["py_add"]
372
    >>> py_add_with_nogil = plain_python_functions['py_add_with_nogil']
373
    >>> result = fail_on_line_trace(None, py_add, py_add_with_nogil)
374
    >>> len(result)
375
    17
376
    >>> result[:5]  # py
377
    ['NO ERROR', ('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
378
    >>> result[5:10]  # py
379
    [('py_add_with_nogil', 'call', 0), ('py_add_with_nogil', 'line', 1), ('py_add_with_nogil', 'line', 2), ('py_add_with_nogil', 'line', 3), ('py_add_with_nogil', 'line', 4)]
380
    >>> result[10:14]  # py
381
    [('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
382
    >>> result[14:]  # py
383
    [('py_add_with_nogil', 'line', 2), ('py_add_with_nogil', 'line', 5), ('py_add_with_nogil', 'return', 5)]
384

385
    >>> result = fail_on_line_trace('cy_add_with_nogil', cy_add, cy_add_with_nogil)
386
    failing line trace!
387
    >>> result
388
    ['cy_add_with_nogil', ('cy_add', 'call', 0), ('cy_add', 'line', 1), ('cy_add', 'line', 2), ('cy_add', 'return', 2), ('cy_add_with_nogil', 'call', 0)]
389

390
    >>> result = fail_on_line_trace('py_add_with_nogil', py_add, py_add_with_nogil)  # py
391
    failing line trace!
392
    >>> result  # py
393
    ['py_add_with_nogil', ('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2), ('py_add_with_nogil', 'call', 0)]
394

395
    >>> result = fail_on_line_trace('cy_add_nogil', cy_add, cy_add_with_nogil)
396
    failing line trace!
397
    >>> result[:5]
398
    ['cy_add_nogil', ('cy_add', 'call', 0), ('cy_add', 'line', 1), ('cy_add', 'line', 2), ('cy_add', 'return', 2)]
399
    >>> result[5:]
400
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1), ('cy_add_with_nogil', 'line', 2), ('cy_add_with_nogil', 'line', 3), ('cy_add_with_nogil', 'line', 4), ('cy_add_nogil', 'call', 0)]
401

402
    >>> result = fail_on_line_trace('py_add', py_add, py_add_with_nogil)  # py
403
    failing line trace!
404
    >>> result[:5]  # py
405
    ['py_add', ('py_add', 'call', 0), ('py_add', 'line', 1), ('py_add', 'line', 2), ('py_add', 'return', 2)]
406
    >>> result[5:]  # py
407
    [('py_add_with_nogil', 'call', 0), ('py_add_with_nogil', 'line', 1), ('py_add_with_nogil', 'line', 2), ('py_add_with_nogil', 'line', 3), ('py_add_with_nogil', 'line', 4), ('py_add', 'call', 0)]
408
    """
409
    cdef int x = 1
410
    trace = ['NO ERROR']
411
    exception = None
412
    trace_func = _create__failing_line_trace_func(trace)
413
    with gc_off():
414
        PyEval_SetTrace(<Py_tracefunc>trace_trampoline, <PyObject*>trace_func)
415
        try:
416
            x += 1
417
            add_func(1, 2)
418
            x += 1
419
            if fail_func:
420
                trace[0] = fail_func  # trigger error on first line
421
            x += 1
422
            nogil_add_func(3, 4)
423
            x += 1
424
        except Exception as exc:
425
            exception = str(exc)
426
        finally:
427
            PyEval_SetTrace(NULL, NULL)
428
    if exception:
429
        print(exception)
430
    else:
431
        assert x == 5
432
    return trace
433

434

435
def disable_trace(func, *args, bint with_sys=False):
436
    """
437
    >>> py_add = plain_python_functions["py_add"]
438
    >>> disable_trace(py_add, 1, 2)
439
    [('py_add', 'call', 0), ('py_add', 'line', 1)]
440
    >>> disable_trace(py_add, 1, 2, with_sys=True)
441
    [('py_add', 'call', 0), ('py_add', 'line', 1)]
442

443
    >>> disable_trace(cy_add, 1, 2)
444
    [('cy_add', 'call', 0), ('cy_add', 'line', 1)]
445
    >>> disable_trace(cy_add, 1, 2, with_sys=True)
446
    [('cy_add', 'call', 0), ('cy_add', 'line', 1)]
447

448
    >>> disable_trace(cy_add_with_nogil, 1, 2)
449
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1)]
450
    >>> disable_trace(cy_add_with_nogil, 1, 2, with_sys=True)
451
    [('cy_add_with_nogil', 'call', 0), ('cy_add_with_nogil', 'line', 1)]
452
    """
453
    trace = []
454
    trace_func = _create_disable_tracing(trace)
455
    with gc_off():
456
        if with_sys:
457
            sys.settrace(trace_func)
458
        else:
459
            PyEval_SetTrace(<Py_tracefunc>trace_trampoline, <PyObject*>trace_func)
460
        try:
461
            func(*args)
462
        finally:
463
            if with_sys:
464
                sys.settrace(None)
465
            else:
466
                PyEval_SetTrace(NULL, NULL)
467
    return trace
468