How to retrieve the line number where a C++ function is called from python using pybind11

Question

I'm trying to make a C++ logger class for embedded python script with pybind11. How can I retrieve the line number where a C++ function is called from python?

I have something like this in C++:

class PythonLogger
{
public:
    PythonLogger(const std::string& filename)  { /* opens log file */ }
    ~PythonLogger() { /* closes log file */ }
    void log(const std::string& msg) {
        // writes formated log message to log file:
        // [<current time>] [<script file name>:<line number>]: msg
        // "line number" here should be the line number where 
        // this function is called inside python script
    }
private:
    <some file class> log_file;
};
typedef std::shared_ptr<PythonLogger> PythonLoggerPtr;

PYBIND11_EMBEDDED_MODULE(PythonLogger, m) {
    py::class_<PythonLogger, PythonLoggerPtr>(m, "Logger")
        .def("debug", &PythonLogger::debug);
}

int main()
{
    py::scoped_interpreter guard{};
    PythonLoggerPtr logger = std::make_shared<PythonLogger>("python_log.log");
    try
    {
        auto script = py::module_::import("script");
        script.import("PythonLogger");
        script.attr("logger") = logger;
        auto func = script.attr("func");
        func();
    }
    catch (const std::exception& e)
    {
        std::print("{}\n", e.what());
    }
}

Please ignore that I didn't actually include any headers in this code.

In script.py:

def func():
    logger.debug("debug message")

And if I run this code, it should write this to the log file:

[<current time>] [script.py:2]: debug message

Related/dupe: What advantages does C++20's std::source_location have over the pre-defined macros FILE, LINE and FUNCTION? — Richard
– Richard, Commented Dec 11, 2023 at 15:22
Or Print the file name, line number and function name of a calling function - C Prog — Richard
– Richard, Commented Dec 11, 2023 at 15:24
@JesperJuhl @user12002570 No, I want to retreive the line number inside the python script, in my example, I should get line number 2, because logger.debug() is called at the second line, but std::source_location only gives me where it'called in c++ — Eliv_
– Eliv_, Commented Dec 11, 2023 at 15:36
@Eliv_ Then it's up to the Python script to give the file name and the line number to the C++ function. A function cannot know who will call it (nor anything from an outer context). — Fareanor
– Fareanor, Commented Dec 11, 2023 at 15:47

Dan Mašek · Accepted Answer · 2023-12-11 20:04:57Z

One possibility is to inspect the Python call stack from the C++ function and grab the info about the caller from there. This approach might involve a noticeable overhead -- I haven't measured it, but it would be a good idea before you use this in production.

You could do this using the standard inspect module, for example by calling inspect.stack().

py::module inspect_mod = py::module::import("inspect");
py::list frames = inspect_mod.attr("stack")();

This function returns a list of frame information objects, and we're interested in the first one.

py::object calling_frame = frames[0];

Now, we want to grab attributes filename (a string) and lineno (an integer).

py::str filename_py = calling_frame.attr("filename");
py::int_ line_no_py = calling_frame.attr("lineno");

Next, cast them into C++ types.

auto const filename = filename_py.cast<std::string>();
auto const line_no = line_no_py.cast<uint32_t>();

And now you can generate your desired log message.

Example code:

#include <chrono>
#include <cstdint>
#include <iomanip>
#include <iostream>
#include <string>

#include <pybind11/pybind11.h>
#include <pybind11/embed.h>

namespace py = pybind11;


PYBIND11_EMBEDDED_MODULE(testmodule, m)
{
    m.def("test_log", [](py::str message) {
        py::module inspect_mod = py::module::import("inspect");
        py::list frames = inspect_mod.attr("stack")();
        py::object calling_frame = frames[0];
        py::str filename_py = calling_frame.attr("filename");
        py::int_ line_no_py = calling_frame.attr("lineno");
        auto const filename = filename_py.cast<std::string>();
        auto const line_no = line_no_py.cast<uint32_t>();

        using std::chrono::system_clock;
        auto const timestamp = system_clock::to_time_t(system_clock::now());

        std::cout << "["
            << std::put_time(std::localtime(&timestamp), "%FT%T%z")
            << "] [" << filename << ":" << line_no << "]: "
            << message.cast<std::string>() << "\n";
    });
}

int main()
{
    py::scoped_interpreter guard{};

    try {
        py::exec(R"(\
import testmodule
import test_script

test_script.foo()
testmodule.test_log("From embedded code fragment.")
)");
    } catch (py::error_already_set& e) {
        std::cerr << e.what() << "\n";
    }

}

Python script test_script.py used by the above example:

import testmodule

def foo():
    testmodule.test_log("On line 4 in foo().")

testmodule.test_log("On line 6.")

Example output:

g:\example>so07.exe
[2023-12-11T18:31:39+0100] [g:\example\test_script.py:6]: On line 6.
[2023-12-11T18:31:39+0100] [g:\example\test_script.py:4]: On line 4 in foo().
[2023-12-11T18:31:39+0100] [<string>:7]: From embedded code fragment.

Notes

One improvement would be to cache the inspect.stack function in persistent logger object, so you don't need to fetch it for every message.

Another would be to rewrite it to directly use Python C API to extract the relevant frame info without round-trip to the inspect implementation. One some further inspection, this might be a moving target relying on implementation details that can (and do) change over time. Some avenues for research nevertheless:

Alternate Approach

After reading through the code of the inspect module, I've arrived at following approach using sys._getframe and the frame object directly:

py::module sys_mod = py::module::import("sys");
py::object calling_frame = sys_mod.attr("_getframe")(0);
py::str filename_py = calling_frame.attr("f_code").attr("co_filename");
py::int_ line_no_py = calling_frame.attr("f_lineno");

The rest would be the same.

Cache the result of sys_mod.attr("_getframe") to avoid fetching it every time.

py::object getframe_fn = py::module::import("sys").attr("_getframe");

// ... sometime later ...
py::object calling_frame = getframe_fn(0);

However, if you do cache that function, you will probably have to make sure the cached object's lifetime doesn't exceed the lifetime of the interpreter. I'll leave it up to the reader to figure that out and handle.

TooTone · Accepted Answer · 2023-12-11 17:41:30Z

You can use the built-in Python inspect module.

In your PythonLogger::debug function (which you called log but registered as debug, you can write:

        auto locals = py::dict();
        py::exec(
            R"(
import inspect
frame_minus_one = inspect.getouterframes(inspect.currentframe())[-1]
filename=frame_minus_one.filename
lineno=frame_minus_one.lineno
    )",
            py::globals(),
            locals);
        const auto filename = locals["filename"].cast<std::string>();
        const auto lineno = locals["lineno"].cast<int>();

You may need to wrap this in a scoped interpreter guard.

FYI full code below (that builds on C++20, so I've replaced the C++23 std::print)

#include <format>
#include <iostream>
#include <pybind11/embed.h>

namespace py = pybind11;

class PythonLogger
{
public:
    PythonLogger(std::ostream& os) : _os(os) {}
    void debug(std::string_view msg)
    {
        auto locals = py::dict();
        py::exec(
            R"(
import inspect
frame_minus_one = inspect.getouterframes(inspect.currentframe())[-1]
filename=frame_minus_one.filename
lineno=frame_minus_one.lineno
    )",
            py::globals(),
            locals);
        const auto filename = locals["filename"].cast<std::string>();
        const auto lineno = locals["lineno"].cast<int>();
        _os << std::format("[{}:{}] {}", filename, lineno, msg) << '\n';
    }

private:
    std::ostream& _os;
};

using PythonLoggerPtr = std::shared_ptr<PythonLogger>;

PYBIND11_EMBEDDED_MODULE(PythonLogger, m)
{
    py::class_<PythonLogger, PythonLoggerPtr>(m, "Logger").def("debug", &PythonLogger::debug);
}

int main()
{
    py::scoped_interpreter guard{};
    PythonLoggerPtr logger = std::make_shared<PythonLogger>(std::cout);
    try
    {
        auto script = py::module_::import("script");
        script.import("PythonLogger");
        script.attr("logger") = logger;
        auto func = script.attr("func");
        func();
    }
    catch (const std::exception& e)
    {
        std::cout << e.what() << '\n';
    }
}

There you go, have an upvote :) Good to see someone else was thinking along the same lines :)
very decent of you sir :) .... I would prefer your answer to mine in prod.

Collectives™ on Stack Overflow

How to retrieve the line number where a C++ function is called from python using pybind11

2 Answers 2

Notes

Alternate Approach

Comments

2 Comments

Your Answer

Linked

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

Notes

Alternate Approach

Comments

2 Comments

Your Answer

Sign up or log in

Post as a guest

Linked

Related