Ask Your Question
12

ROS log file change of time-stamping format

asked 2014-06-25 04:26:17 -0500

Default format of time stamping in ROS logs are in unix time format i.e [ INFO] [1403686233.193723830]: i want this to be changed to ISO 8601 format i.e 2014-06-19T19:12:32Z

i found a option to disable it using export ROSCONSOLE_FORMAT but not able to change format.

how can i do this ?

edit retag flag offensive close merge delete

Comments

1

I am interested in this as well. Did you find a solution?

SR gravatar imageSR ( 2014-11-21 04:49:46 -0500 )edit

I want that, too!

Stephan gravatar imageStephan ( 2015-09-25 04:31:55 -0500 )edit
1

It looks like it just uses the output stream operator of ros::Time : https://github.com/ros/ros_comm/blame...

Stephan gravatar imageStephan ( 2015-09-25 04:35:23 -0500 )edit

Did you find a solution? I am also looking for it.

Orchaldir gravatar imageOrchaldir ( 2016-04-22 05:46:23 -0500 )edit

Any update on this? I too would like this option

shoemakerlevy9 gravatar imageshoemakerlevy9 ( 2017-04-10 14:43:05 -0500 )edit

I've been looking for this too. This seems like a significant flaw in the logging system, I am going nuts looking through log files constantly translating the timestamps to find out when things really occurred.

knxa gravatar imageknxa ( 2017-09-26 02:02:54 -0500 )edit

2 Answers

Sort by ยป oldest newest most voted
2

answered 2018-01-15 17:45:03 -0500

Cerin gravatar image

After much digging around, I found this is possible, but the current logging architecture in ROS Kinetic makes it quite clunky. The problem is that even though ROS uses Python's logging module and provides its own user-customizable logging configuration file, the custom log stream handler defined in rosgraph.roslogging.RosStreamHandler completely ignores the formatting options specified in the configuration file, and hard-codes its own format. Although this is not good, it can still be overridden, but it's a bit more work.

Here's what I did to change the log's timestamp to a datetime.

  1. Define your own logging configuration file by copying the default at /opt/ros/kinetic/share/rosgraph/conf/python_logging.conf and pasting it to somewhere in your project folder (preferrably a "conf" directory).
  2. Create a "logging.py" somewhere in your project folder (preferrably a Python package) and subclass RosStreamHandler like:

    from __future__ import absolute_import import os import time import logging import sys import datetime

    from rosgraph.roslogging import RosStreamHandler as _RosStreamHandler, _logging_to_rospy_names, _defaultFormatter

    class RosStreamHandler(_RosStreamHandler):

    def emit(self, record):
        level, color = _logging_to_rospy_names[record.levelname]
        record_message = _defaultFormatter.format(record)
        msg = os.environ.get('ROSCONSOLE_FORMAT', '[${severity}] [${time}]: ${message}')
        msg = msg.replace('${severity}', level)
        msg = msg.replace('${message}', str(record_message))
        msg = msg.replace('${walltime}', '%f' % time.time())
        msg = msg.replace('${thread}', str(record.thread))
        msg = msg.replace('${logger}', str(record.name))
        msg = msg.replace('${file}', str(record.pathname))
        msg = msg.replace('${line}', str(record.lineno))
        msg = msg.replace('${function}', str(record.funcName))
        try:
            from rospy import get_name
            node_name = get_name()
        except ImportError:
            node_name = '<unknown_node_name>'
        msg = msg.replace('${node}', node_name)
        time_str = datetime.datetime.now().strftime('%Y-%m-%d %H:%M:%S')
        msg = msg.replace('${time}', time_str)
        msg += '\n'
        if record.levelno < logging.WARNING:
            self._write(sys.stdout, msg, color)
        else:
            self._write(sys.stderr, msg, color)
    
  3. In your custom python_logging.conf find the line that says:

     class=rosgraph.roslogging.RosStreamHandler
    

    and change it to point to your new class. If your project's Python package is called "myrobot", and you created logging.py directly inside that, this would look like:

    class=rosgraph.logging.RosStreamHandler
    
  4. Now apply it. To test this, I created a simple test_node.py that looks like:

    #!/usr/bin/env python
    import time
    import inspect
    import rospy
    rospy.init_node('test_node')
    while 1:
        rospy.loginfo("Waiting for 1 second...")
        time.sleep(1)
    

    and associated launch file. To use your custom logging configuration, export the ROS_PYTHON_LOG_CONFIG_FILE environment variable when running any node like:

    export ROS_PYTHON_LOG_CONFIG_FILE=myrobot/config/logging.conf; roslaunch myrobot test_node.launch
    

The output I get is:

[INFO] [2018-01-15 18:36:55]: Waiting for 1 second...
[INFO] [2018-01-15 18:36:56]: Waiting for 1 second...
[INFO] [2018-01-15 18:36:57]: Waiting for 1 second...
[INFO] [2018-01-15 18:36:58]: Waiting for 1 second...

Now clearly, this is a relatively large amount of work to change something relatively minor. Hopefully this is fixed in the next ROS release so it's a lot easier to customize.

edit flag offensive delete link more

Comments

1

+1 for showing your solution, but:

Hopefully this is fixed in the next ROS release

the chances of that happening will be infinitely larger if someone contributes the 'fix'. Perhaps that someone could be you?

gvdhoorn gravatar imagegvdhoorn ( 2018-01-16 02:49:51 -0500 )edit

I'll consider it. I've submitted a few pull requests before to fix bugs I've found, and they've always been ignored or rejected, which is really disheartening. I'm happy to contribute, but I also don't want to waste my time.

Cerin gravatar imageCerin ( 2018-01-26 10:33:11 -0500 )edit
1

Working with an open-source community can be difficult, I agree. It helps if you include maintainers/reviewers in your development process though: that way you can avoid having to redo things because of design decisions that you made that the maintainer isn't comfortable merging.

gvdhoorn gravatar imagegvdhoorn ( 2018-01-27 04:50:15 -0500 )edit

Also: changes to core components -- with a lot of history, and a large installed base -- are under extra scrutiny, as they can have a large impact if something is not up to standards. Haphazerdly introducing changes to components such as the logging systems should be avoided.

gvdhoorn gravatar imagegvdhoorn ( 2018-01-27 04:51:39 -0500 )edit

I assume that a similar change needs to be made for roscpp?

Stephan gravatar imageStephan ( 2018-07-06 03:17:14 -0500 )edit
-1

answered 2018-03-30 12:52:31 -0500

You can also just export a format string:

export ROSCONSOLE_FORMAT='[${severity}] [${time} ${node}] [${file}:${function}:${line}]: ${message}'
edit flag offensive delete link more

Comments

I explicitly mentioned ROSCONSOLE_FORMAT doesn't work in my question... Your example does not change the formatting of the time component.

Cerin gravatar imageCerin ( 2018-03-30 17:35:25 -0500 )edit

Your Answer

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

Add Answer

Question Tools

2 followers

Stats

Asked: 2014-06-25 04:26:17 -0500

Seen: 2,051 times

Last updated: Mar 30 '18