roscpp using simulated time

edit

I am trying to run gmapping_slam on some old data to improve the position estimate and during my use of the resulting /map -> /odom I realized the stamp on the transforms were using the current walltime rather than the simulated time.

So I setup an experiment to narrow down the cause of this.

I created two simple examples using ros Time in c++ and python:

Python:

#!/usr/bin/env python

import roslib; roslib.load_manifest('time_example')
import rospy

def main():
    rospy.init_node('time_exmaple')

    r = rospy.Rate(5)
    while not rospy.is_shutdown():
        rospy.loginfo("The time is: %f" % rospy.Time.now().to_sec())
        r.sleep()

if __name__ == '__main__':
    main()

C++:

#include "ros/ros.h"

int main(int argc, char **argv) {
  ros::init(argc, argv, "teleop_server");
  ros::NodeHandle n;

  ros::Rate r (5);
  while (ros::ok()) {
    ROS_INFO("The time is: %f", ros::Time::now().toSec());
    ros::spinOnce();
    r.sleep();
  }

}

Then I created a roscore instance:

∫ roscore
... logging to /home/william/.ros/log/1bd2d176-1bd5-11e1-a585-002564acbaae/roslaunch-GDRS-Workstation-16779.log
Checking log directory for disk usage. This may take awhile.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.

started roslaunch server http://GDRS-Workstation:53680/
ros_comm version 1.6.5

SUMMARY
========

PARAMETERS
 * /rosversion
 * /rosdistro

NODES

auto-starting new master
process[master]: started with pid [16794]
ROS_MASTER_URI=http://GDRS-Workstation:11311/

setting /run_id to 1bd2d176-1bd5-11e1-a585-002564acbaae
process[rosout-1]: started with pid [16807]
started core service [/rosout]

And then in a new terminal I set the use_sim_time parameter with rosparam:

∫ rosparam set use_sim_time 1

In the same terminal I started a bag file I am using.

∫ rosbag play --clock gavlab_and_hallway_2011-04-17-15-09-47.bag 
[ INFO] [1322715599.665805485]: Opening gavlab_and_hallway_2011-04-17-15-09-47.bag

Waiting 0.2 seconds after advertising topics... done.

Hit space to toggle paused, or 's' to step.
 [RUNNING]  Bag Time: 1303070993.265138   Duration: 5.743087 / 715.993344

In a new terminal I ran the Python and then the C++ code:

∫ python nodes/time_example.py 
[INFO] [WallTime: 1322714195.471402] [0.000000] The time is: 0.000000
[INFO] [WallTime: 1322714195.857057] [1303071368.690635] The time is: 1303071368.690635
[INFO] [WallTime: 1322714195.857385] [1303071368.690635] The time is: 1303071368.690635
[INFO] [WallTime: 1322714196.055195] [1303071368.892812] The time is: 1303071368.892812
... SHORTENED MANUALLY
[INFO] [WallTime: 1322714211.060998] [1303071383.899060] The time is: 1303071383.899060
[INFO] [WallTime: 1322714211.257225] [1303071384.091894] The time is: 1303071384.091894
[INFO] [WallTime: 1322714211.453530] [1303071384.294445] The time is: 1303071384.294445
^CTraceback (most recent call last):
  File "nodes/time_example.py", line 15, in <module>
    main()
  File "nodes/time_example.py", line 12, in main
    r.sleep()
  File "/opt/ros/electric/stacks/ros_comm/clients/rospy/src/rospy/timer.py", line 77, in sleep
    sleep(self.sleep_dur - elapsed)
  File "/opt/ros/electric/stacks/ros_comm/clients/rospy/src/rospy/timer.py", line 132, in sleep
    raise rospy.exceptions.ROSInterruptException("ROS shutdown request")
rospy.exceptions.ROSInterruptException: ROS shutdown request
∫ bin/time_example 
[ INFO] [1322714223.326848478]: The time is: 1322714223.326797
[ INFO] [1322714223.526966411]: The time is: 1322714223.526938
[ INFO] [1322714223.726959496]: The time is: 1322714223.726931
[ INFO] [1322714223.926960677]: The time is: 1322714223.926931
... SHORTENED MANUALLY
[ INFO ...