2

I have ROS2 package written in python (with usage of rclpy) with ROS2 node. Inside this node I want to use node logger, lets say in following way:

def __init__(self):
    self.get_logger().info("Starting my node!")
    self.get_logger().warn("My node has already started!")

This works perfectly with standard python build, but when I want to build it using Cython (because code is going to production) I encounter error: Logger severity cannot be changed between calls. This is caused by implementation of CallerId:

class CallerId(
        namedtuple('CallerId', ['function_name', 'file_path', 'line_number', 'last_index'])):

    def __new__(cls, frame=None):
        if not frame:
            frame = _find_caller(inspect.currentframe())
        return super(CallerId, cls).__new__(
            cls,
            function_name=frame.f_code.co_name,
            file_path=os.path.abspath(inspect.getframeinfo(frame).filename),
            line_number=frame.f_lineno,
            last_index=frame.f_lasti,  # To distinguish between two callers on the same line
        )

in file rcutils_logger.py. I understand perfectly that after "cythonization" of file my inspect module won't work anymore (because every call to inspect functions returns same line/file), but I am unable to fix it. Has anyone encountered similar problems before?

Improve this question
2
  • Hi complikator! Could you find any solution to this? I have encountered the same problem. Commented Nov 3, 2023 at 14:55
  • Not really, I read source code of rclpy and I have not found any solution Commented Nov 3, 2023 at 17:11

3 Answers 3

Reset to default
1

I am using a workaround which is far from a perfect solution but it might help you / someone else:

    def _cython_workaround(log_function):
    """Workaround for cython to accept the logger functions."""
      if cython.compiled:
        def wrapper(msg, *args, **kwargs):
            try:
                log_function(msg, *args, **kwargs)
            except Exception:
                # catch without re-raise
                # TODO: 'Logger severity cannot be changed between calls.'
                # https://stackoverflow.com/questions/77287788/cannot-log-in-ros2-node-after-building-with-cython
                msg = log_function.__name__.upper() + ": " + msg
                logger.info(msg, *args, **kwargs)
        return wrapper
    else:
        return log_function

And then you need to duck-type your composite and the logger itself, since the rclpy implementation does log as well. Also, since the problem comes from changing logging severity between calls, you need to make sure the first log is called is of the same severity used above.

    if cython.compiled:
        # make sure that the first log message has the severity level 
        # INFO set, otherwise the logger will (re)raise on exception
        logger.info("Cython compiled")
        composite.info = logger.info
        composite.debug = _cython_workaround(logger.debug)
        # ...

        # prevent rclpy implementation from raising on exception when itself logs something
        logger.debug = composite.info
        logger.warning = composite.warning
        # ...   
    else:
        composite.info = logger.info
        composite.debug = logger.debug
        # ...

This is not yet very well tested. The logger does log sometimes fine in another severity level, so probably there is a better workaround. And any filters set raise as well! so loosing "throtle_duration_sec..." or "once=True" may trouble you as well.

Improve this answer
Sign up to request clarification or add additional context in comments.

4 Comments

Thank you for this solution. This is not exactly what I wanted but I appreciate your effort
Yes, I know. I hope someone comes up with a solution for this. Or maybe a newer ROS version solves the problem. I am for the moment stuck with galactic.
Does it work without issues on Galactic?
Not really, things keep coming up. See edits.
1

Thank you all for the suggestions. I've managed to implement something that satisfies my needs but isn't actually a solution to the problem.

I've implemented a simple wrapper around Node, which overloads the get_logger method, thus creating a new one on each call, so it means that assuming you don't access the logger by saving it in a variable every logger has exactly one call with same severity.

from uuid import uuid4

from rclpy.impl.rcutils_logger import RcutilsLogger as RosLogger
from rclpy.node import Node


class NodeAdapter(Node):
    def __init__(self, node_name: str, *args, **kwargs) -> None:
        super().__init__(node_name, *args, **kwargs)

    def get_logger(self) -> RosLogger:
        unique_logger_name = f"{uuid4()}"
        return self._logger.get_child(unique_logger_name)
Improve this answer

Comments

-1

I have check the rclpy library, it is assigning the caller id based on the module and which the logging is called also setting the Severity level for that. Simple Example:

{
   'main_module' : info_severity,
   'funtion1' : warn_severity,
   'function2' : error_severity
}

if your severity changing on the same module it will throw the error.

if you try to create a functions inside your python code for each log and call that wherever that particular logs needed, the problem will be fixed,

def error(message):
   ....

def warn(message):
  ....
Improve this answer

4 Comments

I think you misunderstood the question above. What you've said is actually true, but the problem is that after compiling code with cython everything is in the same module.
I've got a workaround which is good enough. I've created NodeWrapper with an overloaded get_logger() method, the new method returns a new instance of the logger for every call. I will post an answer here as soon as I find some free time to do it :)
Did you manage? I got invested into this xD @complikator
@M.K Have you found any solution to this problem?

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.