Ask Your Question
11

Putting log messages from non-ROS code into ROS logging system

asked 2012-03-16 04:52:14 -0500

tbh gravatar image

updated 2012-03-16 04:53:54 -0500

I'm writing two new classes:

  • A class that controls a motor control board (mcb)
  • A ROS node that contains an object of the mcb class. This node provides services to the rest of ROS that use the mcb.

The mcb class will be used later on in non-ROS applications and needs to be stand alone. That's not hard to do, but since I'm using ROS now I'd like to use the nice ROS_[INFO|ERROR] logging functionality.

My idea was to have a logfunction function pointer in the mcb class that the caller could supply. That would give the caller the opportunity to print statements to standard output by supplying printf, to log to ROS with the ROS log stuff, or to log some other way by a custom function.

The only problem is that ROS_[INFO|ERROR|etc.] are all macros, and can't be pointed to as far as I know. I also can't wrap the logging macros in functions, because it's not possible to pass ellipses, right?

Does anybody know of a way to provide the logging functionality through a pointer or a stream or something? Or is there any way to put outside log messages into the ROS logging system?

Many thanks!

edit retag flag offensive close merge delete

4 Answers

Sort by ยป oldest newest most voted
6

answered 2012-03-16 06:43:42 -0500

mjcarroll gravatar image

A quick summary, and then on to code samples:

  1. Build your driver node to be completely ROS-agnostic. In your class, define a series of (private) function pointers to logging functions for you different levels, Debug, Info, Error, etc.
  2. In your class, define a few "setters" to update these function pointers.
  3. In your class, create some generic loggers (or use the logging system of your choice), and make these default in the constructor
  4. In your node, create some wrappers to the ROS functions.
  5. When constructing the driver object, make sure to also update the logging function pointers to your new ROS function pointers.

C++

I think a decent example of this is @wjwwood's libsegwayrmp library.

To begin with, he typedef's a few functions:

typedef boost::function<void(const std::string&)> DebugMsgCallback;
typedef boost::function<void(const std::string&)> InfoMsgCallback;
typedef boost::function<void(const std::string&)> ErrorMsgCallback;

And then creates private class variables in his hardware driver;

...
private:
   DebugMsgCallback debug;
   InfoMsgCallback info;
   ErrorMsgCallback error;

And he creates three public mutators to update these function pointers:

void setErrorMsgCallback(ErrorMsgCallback);
void setInfoMsgCallback(InfoMsgCallback);
void setDebugMsgCallback(DebugMsgCallback);

The logging functions can be called in your class by simply doing:

this->error("This is an error message")
this->debug("This is a debug message")
this->info("This is an info message")

So now, to use this WITHOUT ROS, you can create three simple callback functions that just log to the console, or modify these for your own logging suite:

inline void defaultDebugMsgCallback(const std::string &msg) {
    std::cerr << "SegwayRMP Debug: " << msg << std::endl;
}

inline void defaultInfoMsgCallback(const std::string &msg) {
    std::cerr << "SegwayRMP Info: " << msg << std::endl;
}

inline void defaultErrorMsgCallback(const std::string &msg) {
    std::cerr << "SegwayRMP Error: " << msg << std::endl;
}

Or, to use it WITH ROS, you can create some functions that wrap the macros:

void handleDebugMessages(const std::string &msg) {ROS_DEBUG("%s",msg.c_str());}
void handleInfoMessages(const std::string &msg) {ROS_INFO("%s",msg.c_str());}
void handleErrorMessages(const std::string &msg) {ROS_ERROR("%s",msg.c_str());}

When you construct the device driver, you can then update these function pointers to your newly-wrapped functions:

this->segway_rmp->setDebugMsgCallback(handleDebugMessages);
this->segway_rmp->setInfoMsgCallback(handleInfoMessages);
this->segway_rmp->setErrorMsgCallback(handleErrorMessages);

Python

You do a similar thing with Python. I create my hardware interfaces to use the default Python logging built-in. The signature for these functions is:

f(msg, *args)

Which happens to be the same as the ROS logging system.

Using a similar strategy, I create a few function references as class variables:

class DriverObject(object):
    def __init__(self, param1, param2, param3, debug=None, info=None, error=None):
        self.debug = logging.debug                                                   
        self.info = logging.info                                                     
        self.error = logging.error                                                                                                                                         
        if debug:                                                                    
            self.debug = debug                                                       
        if error:                                                                    
            self.error = error                                                       
        if info:                                                                     
            self.info = info

And to use these functions throughout my class, I simply do:

self.debug("This is a debug message")
self.error("This is an error message"
self.info("This is an info message")

And when I want to use the class within a ROS ... (more)

edit flag offensive delete link more

Comments

This is pretty much what I originally wanted to do, but I was only thinking in a c mindset, trying to wrap variadic functions like printf. Thanks for putting me in a c++ mindset. This worked great. For those who come after: boost::lexical_cast for the win.

tbh gravatar imagetbh ( 2012-03-19 12:01:23 -0500 )edit

Yeah, I hope that wasn't too confusing. I tried to dig through the code for the meaty bits for you, and it STILL came out as a wall of code.

mjcarroll gravatar imagemjcarroll ( 2012-03-19 14:08:47 -0500 )edit
1

Wouldn't it be possible to use the python module `logging` in the agnostic code and let the wrapper somehow connect the own logger to the ROS logging? I'm trying that but not that successful. Update: probably got that, await my answer..

felix k gravatar imagefelix k ( 2013-12-11 03:40:21 -0500 )edit
4

answered 2013-12-12 07:01:23 -0500

felix k gravatar image

I'll propose a more pythonic way to merge a separate logging into roslogging. Feedback welcome!

  1. Pros
  2. Cons/Todos
  3. How To

1. Pros

  • Just use the standard python logging module, featuring formatting, namespacing hierarchy, log levels etc. pp.
  • If the library is used without modifying its logging like above, the logs are written to console in the given formatting
  • If only the forwarding code above is executed, the logs are written to console using ROS (so the formatting matches the rest of the program)
  • If additionally the wrapping/user code calls rospy.init_node(..), the logs are automatically published on /rosout
  • The logging namespace hierarchy is viewable in the logger level GUIs and for each namespace a level can be set, affecting console and rosout output as usual.

2. Cons/Todos

  • Logs issued right after init_node without any delay might not be published. I don't know where that buffer is missing, but have never experienced that with the default rospy logging (rospy.log*) so it could be fixable.

3. How To

In the ROS-agnostic library add: (named rgoap in this case, the file being rgoap/__init__.py):

## logging

import logging
_logger = logging.getLogger('rgoap')
"""The logger used in this library"""
_logger.setLevel(logging.INFO)

# add default console output
_loghandler = logging.StreamHandler()
_loghandler.setLevel(logging.INFO)
_loghandler.setFormatter(logging.Formatter('[%(levelname)s] %(message)s'))
_logger.addHandler(_loghandler)

def remove_default_loghandler():
    """Call this to mute this library or to prevent duplicate messages
    when adding another log handler to the logger named 'rgoap'."""
    _logger.removeHandler(_loghandler)

In the library's code files just log via:

import logging
_logger = logging.getLogger('rgoap') # you can also use dotted namespaces like 'rgoap.planner'!

def my_func():
    _logger.info("Hello %s", "World")

In the ROS-wrapper for that library add: (for example in rgoap_ros/__init__.py)

import rgoap
import rospy

### set up rgoap-ros interface

## forward rgoap's logging to ROS
import logging

# ..for console output
import rosgraph.roslogging as _rl
logging.getLogger('rgoap').addHandler(_rl.RosStreamHandler())

# ..for network output (/rosout)
import rospy.impl.rosout as _ro
logging.getLogger('rgoap').addHandler(_ro.RosOutHandler())

# remove the default console output
rgoap.remove_default_loghandler()
edit flag offensive delete link more

Comments

Thanks for sharing this. About the cons: I experienced this also with the ROS logging functions. I think it is just a general limitation of publishers (when they start publishing directly after creation, subscribers are not yet ready to receive).

Felix Widmaier gravatar imageFelix Widmaier ( 2018-10-12 07:50:27 -0500 )edit
4

answered 2012-03-16 06:38:38 -0500

dornhege gravatar image

updated 2012-03-16 06:41:53 -0500

As a simple form I use this header: ros_printouts.h

#ifndef ROS_PRINTOUTS_H
#define ROS_PRINTOUTS_H

/// Compatibility header for non-ros build

#if ROS_BUILD
    // Nothing to do, use the ROS functionality
#else

    #define ROS_DEBUG_STREAM(args) \
    cout << args << endl;

    #define ROS_INFO_STREAM(args) \
    cout << args << endl;


    #define ROS_DEBUG \
        printf 

    #define ROS_INFO \
        printf 

    #define ROS_WARN \
        printf 

    #define ROS_ERROR \
        printf 

    #define ROS_FATAL \
        printf

    #define ROS_ASSERT assert

#endif

#endif
edit flag offensive delete link more

Comments

I hadn't thought of that! The only downside is ROS logging functions append a newline character while printf doesn't. So I'd have everything on one line if not using newline in each statement or a bunch of skipped lines in the ROS log if I did. Really just annoying, tho - a definite possibility.

tbh gravatar imagetbh ( 2012-03-16 07:01:06 -0500 )edit
2

http://octomap.sourceforge.net/doxygen/octomap__types_8h_source.html is an example similar to this that handles the newline stuff as well as variadic arguments. Note that this makes more sense for a standalone lib if your logging defines are things like "MYLIBRARY_DEBUG" instead of "ROS_DEBUG".

Eric Perko gravatar imageEric Perko ( 2012-03-19 15:35:13 -0500 )edit
3

answered 2015-08-19 08:33:36 -0500

drewm1980 gravatar image

updated 2015-08-19 08:34:15 -0500

I ran into similar issues. The ROS logging macros are numerous and defined 5 or more levels deep, so whenever you pass the wrong one of the plethora of stringy types in C++, you get several screenfulls of preprocessor error.

If you're developing in C++11, you can use closures to bring back a measure of explicitly typed sanity:

    auto log_info =  [] (const std::string & str) {ROS_INFO_STREAM(str);};
    auto log_warning =  [] (const std::string & str) {ROS_WARNING_STREAM(str);};
    auto log_error =  [] (const std::string & str) {ROS_ERROR_STREAM(str);};

There are probably many ways of defining the above closures; there may be a better one for your code. Doing it this way decomposes the task of fixing the types in the call sites in your code from the much harder problem of figuring out which types will actually work in ROS's macros.

I'm sure there are reasonable historical reasons for why ROS is code generating header files full of macros nested 5 levels deep, but IMHO it has resulted in an unreasonable level of complexity for something as simple as logging a string. Perhaps someone can post an example of what all the macros actually boil down to in the end.

edit flag offensive delete link more

Your Answer

Please start posting anonymously - your entry will be published after you log in or create a new account.

Add Answer

Question Tools

4 followers

Stats

Asked: 2012-03-16 04:52:14 -0500

Seen: 2,224 times

Last updated: Aug 19 '15