[ros-users] tf, use_sim_time, --clock, and bag files

I have a vexing "bug." Perhaps someone can clarify. For reference, I'm
using cturtle binaries, running "rosbag play --clock mybagfile.bag" and have
set /use_sim_time to true in both my python code and using rosparam.

Basically, when I try to wait for a transform, this works:

            rospy.logout( 'Time read: %d.%d' % ( mymsg.header.stamp.secs,
mymsg.header.stamp.nsecs ))
            now = rospy.Time.now()
            rospy.logout( 'Rospy Now: %d.%d' % ( now.secs, now.nsecs ))
            self.tf_listener.waitForTransform( frame, '/map',
                                               rospy.Time(),

                                               timeout = rospy.Duration(0.1)
)

Whereas this fails:

            rospy.logout( 'Time read: %d.%d' % ( mymsg.header.stamp.secs,
mymsg.header.stamp.nsecs ))
            now = rospy.Time.now()
            rospy.logout( 'Rospy Now: %d.%d' % ( now.secs, now.nsecs ))
            self.tf_listener.waitForTransform( frame, '/map',
                                               mymsg.header.stamp,
                                               timeout = rospy.Duration(0.1)
)

This also fails:

            rospy.logout( 'Time read: %d.%d' % ( mymsg.header.stamp.secs,
mymsg.header.stamp.nsecs ))
            now = rospy.Time.now()
            rospy.logout( 'Rospy Now: %d.%d' % ( now.secs, now.nsecs ))
            self.tf_listener.waitForTransform( frame, '/map',
                                               rospy.Time.now(),
                                               timeout = rospy.Duration(0.1)
)

The only (subtle) difference is that the "working" version is waiting for
the transform at Time 0.0, which just gets the latest available transform,
but both mymsg.header.stamp and rospy.Time.now() fail with the following
exception message:

[INFO] 1282625415.289159: PF: Awaiting necessary tf transforms.
[INFO] 1282625417.263204: PF: All tf transforms ready. # Using rospy.Time(0)
[INFO] 1282625417.318107: PF: Starting particle filter!
[INFO] 1282625418.667938: Time read: 1282347068.759572982
[INFO] 1282625418.668339: Rospy Now: 1282347068.760468681
[INFO] 1282625418.769964: PF: tf unavailable. Skipping read (1).
You requested a transform that is 278350010.097 miliseconds in the past,
but the most recent transform in the tf buffer is 278350024.236 miliseconds
old.

<class 'tf.Exception'>

You'll notice that the roscore time from logout is the (correct) simtime.
Using "rosrun tf view_frames" also shows that the frames are 278350010ish
milliseconds old. The /clock message is being (correctly) published by the
bag file...

Is this somehow "expected" behavior, or is there a bug in tf that prevents
the use of simtime?



~Travis Deyle
PhD student @ Georgia Tech's Healthcare Robotics Lab
Co-Founder www.Hizook.com -- Robotics News for Academics & Professionals