Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RosOutHandler loses exception info #1441

Closed
pbaughman opened this issue Jun 21, 2018 · 0 comments
Closed

RosOutHandler loses exception info #1441

pbaughman opened this issue Jun 21, 2018 · 0 comments

Comments

@pbaughman
Copy link

pbaughman commented Jun 21, 2018

The issue I'm seeing

The way the emit method sends python LogRecord methods to _rosout loses any traceback or exception information that may have been part of the LogRecord

To see the issue, first take a look at the StreamHandler's emit method. This method calls self.format on the LogRecord which, by default, uses the LogRecord's getMessage() method, caches the result as LogRecord.message (behavior documented here), and then glues on any extra exception messages and tracebacks (documented here). Finally, the value returned from 'format' is what's emitted.

The RosOutHandler's emit method works differently. Instead of calling self.format and passing the returned value down to _rosout, it just calls LogRecord.getMessage() and passes that returned value down. That means only LogRecord.msg % LogRecord.args will be sent out on the wire, and anything in LogRecord.exc_info is lost. It also prevents a use applied formatter from doing anything when attached to the RosOutHandler

Maybe this is OK?

I'm not sure if there's a way to get an exc_info into a LogRecord created by rospy.logwhatever or not. I suppose if nothing in ROS attempts to create a LogRecord with an exc_info field, then it's OK from a stricly ROS perspective that this information doesn't make it to /rosout?

We're running into this issue because I'm plumbing the python logger to /rosout so we have methods like logger.exception, and can pass exc_info to any logger.whatever method as a kwarg

A few different suggestions to fix

  • Send self.format(record) as the msg argument to _rosout so that the RosOutHandler behaves like the Handlers provided by the python library (This seems like the right fix to me)
class RosOutHandler(logging.Handler):
   def emit(self, record):
      _rosout(_logging_to_rospy_levels[record.levelno], self.format(record),  # <------- This
record.filename, record.lineno, record.funcName)
  • The RosOutHandler method could check if record.message exists. If it doesn't exist, create it by doing record.message = record.getMessage() and send record.message down to _rosout. This preserves the existing behavior of not sending exception tracebacks to _rosout, but it also allows someone to subclass the RosOutHandler and populate record.message themselves however they want before emitting them
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants