Referencing Compile Time "filename", "lineno", and "function" references.

[Jonathan Marks]

Hi Folks,

Is there a way to access the the compile time "filename", "lineno" and "function" references for the code being compiled?  For debugging / tracing I would like an automagic way to reference the filename, lineno, and function calling the debug/trace statement.

There is no python stack frame to inspect in the calling of Cython C functions.  I am hoping that there is a method, similar to accessing the __FILENAME__, __LINENO__ , and __FUNCTION__, macros gcc automagicly defines that can be used in sprintf(). in C.

Thanks for any help o n this.

[Stefan Behnel]

Hi,

Jonathan Marks schrieb am 12.12.21 um 15:21:

> Is there a way to access the the compile time "filename", "lineno" and
> "function" references for the code being compiled? For debugging / tracing
> I would like an automagic way to reference the filename, lineno, and
> function calling the debug/trace statement.
>
> There is no python stack frame to inspect in the calling of Cython C
> functions.

Specifically for tracing, frames *are* being instantiated. Could you maybe
say a bit more about your use cases, what you are trying to achieve, what
you tried and what didn't work?

Stefan

[Jonathan Marks]

Thanks for the prompt response Stefan

Ideally I would like to bring over the following functionality from C.  This is watered down example C code so showing the functionality I would like to implement in Cython.

local header file.

>>>>>>>

#ifdef DEBUG

      #define TRC(args...)      trace(__FILE__, __LINE__, __FUNCTION__, ## args)

#else

      #define TRC(args...)

 . . . . . . .

int trace(const char *sFile, UINT32 nLine, const char *sFn,  const char *fmt, ...);

<<<<<<<<

local utility file

>>>>>>>>>>>>

int trace(const char *sFile, UINT32 nLine, const char *sFn,  const char *fmt, ...)

{

va_list pAp

char sBfr[LINE_LEN];

      va_start (pAp, sFmt);
      vsnprintf (sBfr, LINE_LEN, sFmt, pAp);
      va_end (pAp);

      return fprintf (fTrace,"%s:%u:%s:%s", sFile, nLine, sFn, sBfr);

};

<<<<<<<<<

Trace is only produces compiled code when DEBUG is set and then the use of trace() throughout the code will prefix the output with the source filename, line and function, so I know where to go in the code when it does not do what is expected.  I am hoping I will be able to implement the equivalent or an alternative in Cython code.

Thanks.

Jonathan

[Jonathan Marks]

PS:  This is the code I use for python code, but unfortunately it does not see the compiled Cython stack frame in Cython.

if DEBUG:
     from inspect import getframeinfo, stack
     from sys import stderr

     def DBG(*args, **kwargs):
     caller = getframeinfo(stack()[1][0])
     print(f":{os.path.basename(caller.filename)}:{caller.lineno}:{caller.function}():", *args, file=stderr, flush=True, **kwargs)

On Sunday, 12 December 2021 at 16:32:43 UTC+2 Stefan Behnel wrote:

[da-woods]

So if you're interested in the C line, file, and function you could just use your existing TRC function. Include it in Cython with:

cdef extern from *:

    """

    /* your C TRC code goes here */

    """

    void TRC(...)

and then use TRC in Cython.

If you want it done on at the Cython line level then maybe line tracing is what you're after (see https://cython.readthedocs.io/en/latest/src/tutorial/profiling_tutorial.html)? It's not something I've ever really used though so couldn't give much detail.

I would think that Cython line-tracing is probably the right tool and what you should use.

David

--

---
You received this message because you are subscribed to the Google Groups "cython-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cython-users...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/cython-users/beb94e84-5ccd-42b9-80b7-4372f2c0a81dn%40googlegroups.com.

[Jonathan Marks]

Thanks for your help David.

Following the path recommended, I have read up on line tracing and how to activate it in Cython.  All good there, but now, how I do I access the line tracing internals to obtain the filename, line number and function call to put in the trace statement during run time?

Accessing this information during run time is second prize. (Which is a gazillion times better than no prize at all).  However first prize would be to access this information during compile time.  If only Cython could make pre-defined names available for the filename, lineno, and function available in the same way it does for UNAME_SYSNAME, etc, during compile time. . .

Any further help or suggestions for ether run-time or compile-time approaches is greatly appreciated.

Many thanks

Jonathan 

[Jonathan Marks]

Hi Folks,

I am still stuck with this challenge.  Perhaps a re-phrasing of what I am seeking.  From within Cython compiled code with "# cython: profile=True", how is the profiling stack frame interrogated to retrieve the names, cython (not C) source file line numbers, and function name, from within the executing code?

Any pointers (mind the pun) will be greatly appreciated.

Thanks

Jonathan

[da-woods]

Maybe I'm slightly misunderstanding what you need but here's a simple example:

# is_profiled.pyx    - this is just an example file to be illustrate some cython code running

#
# cython: linetrace=True
# distutils: define_macros=CYTHON_TRACE=1

def func(n):
    sum = 0
    for i in range(n):
        if i%2:
            sum += 1
        else:
            sum *= 2

# do_profiling.pyx

# cython: language_level=3

from cpython.pystate cimport PyFrameObject, Py_tracefunc
from cpython cimport PyObject

cdef extern from "frameobject.h":
    pass
cdef extern from *:
    void PyEval_SetTrace(Py_tracefunc, o)

cdef int tracefunc(PyObject* o, PyFrameObject* frame, int what, PyObject *arg):
    a = <object> arg if arg else "<No arg>"
    print(<object>frame, what, a)
    
from is_profiled import func

PyEval_SetTrace(tracefunc, None)

func(10)

--------------------------------

what happens is that every time a line of "is_profiled" is run "tracefunc" gets called. You can do what you like with this information. I print it. You could log it using "o" or to a global dict (I'm using None as o in the call to PyEval_SetTrace). That "what" argument is documented https://docs.python.org/3.7/c-api/init.html#c.Py_tracefunc. Most of the information you want should be attributes of the frame.

If you want it more targetted, I think you can apply linetrace as a decorator or in a "with cython.linetrace" block. However you'll still get events from Python code than runs so you may need to filter that.

To view this discussion on the web visit https://groups.google.com/d/msgid/cython-users/2057fd94-306f-4aa3-bf06-51ac1d580c69n%40googlegroups.com.

[Jonathan Marks]

Thanks so much for you help David.  I have cracked it.  This is what I did.

>>>>>>>>>>>>>>

# do_profiling.pyx
# cython: linetrace=False
# cython: language_level=3

import os
from sys import stderr
from time import perf_counter

from cpython.pystate cimport PyFrameObject, Py_tracefunc
from cpython cimport PyObject

cdef extern from "frameobject.h":
     pass
cdef extern from *:
     void PyEval_SetTrace(Py_tracefunc, o)

class TRACEX:
     def __init__(self, Fn = None, Line = -1, Func = None):
         self.Stack = (Fn, Line, Func)

     def set(self, Fn, Line, Funct):
         self.Stack = (Fn, Line, Funct)

     def get(self):
         return self.Stack

cdef int tracefunc(PyObject* o, PyFrameObject* frame, int what, PyObject* arg):

     from inspect import getframeinfo

     Fi = getframeinfo(<object>frame)
     TraceX.set(os.path.basename(Fi.filename), Fi.lineno, Fi.function)

def TRCX(*args, **kwargs):
     Fn, L, Func = TraceX.get()
     print(f"{perf_counter():0.6f}:{Fn}:{L}:{Func}:", *args, file=stderr, flush=True, **kwargs)

PyEval_SetTrace(tracefunc, None) # None)
TraceX = TRACEX()

<<<<<<<<<<<

>>>>>>>>>>>>>>

# is_profiled.pyx

# cython: linetrace=True
# distutils: define_macros=CYTHON_TRACE=1

from sys import stderr

from do_profiling import TRCX

def func(n):
    sum1 = 0
    TRCX("got here")
    for i in range(n):
        dummy_fn1(sum1)

        if i%2:
            sum1 += 1
            TRCX(f"plus sum: {sum1}")
        else:
            sum1 *= 2
            TRCX(f"mult sum: {sum1}")

def dummy_fn1(sum1):
    abc = sum1
    TRCX("got here 1")
    dummy_fn2()

def dummy_fn2():
    dasdef = 234234
    TRCX("got here 2")

<<<<<<<<<<<<<

 >>>>>>>>>>

# tracethis.py

from do_profiling import TRCX
from is_profiled import func

i = 5
for z in range(10):
     TRCX(f"i = {i}")
     i += z

func(15)

<<<<<<<<<<

>>>>>>>>>> Output

0.167374:tracethis.py:11:<module>: i = 5
0.167751:tracethis.py:11:<module>: i = 5
0.168106:tracethis.py:11:<module>: i = 6
0.168460:tracethis.py:11:<module>: i = 8
0.168811:tracethis.py:11:<module>: i = 11
0.169163:tracethis.py:11:<module>: i = 15
0.169515:tracethis.py:11:<module>: i = 20
0.169865:tracethis.py:11:<module>: i = 26
0.170217:tracethis.py:11:<module>: i = 33
0.170567:tracethis.py:11:<module>: i = 41
0.171515:is_profiled.pyx:15:func: got here
0.172437:is_profiled.pyx:27:dummy_fn1: got here 1
0.173067:is_profiled.pyx:32:dummy_fn2: got here 2
0.173851:is_profiled.pyx:23:func: mult sum: 0
0.174637:is_profiled.pyx:27:dummy_fn1: got here 1
0.175263:is_profiled.pyx:32:dummy_fn2: got here 2
0.176043:is_profiled.pyx:20:func: plus sum: 1
0.176822:is_profiled.pyx:27:dummy_fn1: got here 1
0.177448:is_profiled.pyx:32:dummy_fn2: got here 2
0.178226:is_profiled.pyx:23:func: mult sum: 2
0.179003:is_profiled.pyx:27:dummy_fn1: got here 1
0.179627:is_profiled.pyx:32:dummy_fn2: got here 2
0.180406:is_profiled.pyx:20:func: plus sum: 3
0.181183:is_profiled.pyx:27:dummy_fn1: got here 1
0.181808:is_profiled.pyx:32:dummy_fn2: got here 2
0.183051:is_profiled.pyx:23:func: mult sum: 6
0.184307:is_profiled.pyx:27:dummy_fn1: got here 1
0.184966:is_profiled.pyx:32:dummy_fn2: got here 2
0.185760:is_profiled.pyx:20:func: plus sum: 7

 . . . . . .

<<<<<<<<<<

This approach works in both interpreted and compiled code. Just import do_profiling into which ever file *.py or *.pyx.

Hope this helps others out there.

[da-woods]

Glad you got it sorted. As a final note, there are standard library modules like https://docs.python.org/3/library/trace.html that also do similar things (but obviously aren't as flexible and writing your own code)

To view this discussion on the web visit https://groups.google.com/d/msgid/cython-users/74a06af9-5216-41fb-9bca-502123f9e18bn%40googlegroups.com.