ros/geometry — pull request #53 by mikeferguson (2014-02-01 01:29:30+00:00)
Title: Port groovy-devel patch to hydro-devel

I've spent the better part of the afternoon looking into this. It has also shown up here: http://answers.ros.org/question/124061/tf-negative-time-change-messages/

Obviously, this message didn't come up before, and has recently started to. I started by looking into rospy thinking that this had always been in TF, but then found that rospy has no relevant updates in the past 6 months. In tracking down what is going on, I found that this message was only added to TF several months ago (https://github.com/ros/geometry/commit/4b816973950528a4280ae645cffe5eb72996c036).

This has been further adjusted in groovy-devel (https://github.com/ros/geometry/commit/36dbe5c13475701715d1253e3b372ef878a3d781) although the author appears to have assumed that rospy.Time.now() is going non-monotonic, which it does not appear to be doing.

By adding a bunch of debugging output, and hitting my subscriber with two 1khz static_transform_publishers, I was able to see that the basic problem here is that we get a race between two messages. Occasionally, a message starts to be processed, but then is delayed for some time while others are processed. Obviously, the proper fix here is probably a set of mutexes -- however, further investigation is required to make sure we don't hit a deadlock (it's really not clear why the particular message is SO delayed, I saw it being delayed while typically 4-5 other tf messages were processed, then it was...)

It appears the real purpose of this check is to deal with simulated time (if you keep changing the underlying clock, the tf cache would get wonky). Until such time that a better patch can be applied, we really need to stop the hydro-devel branch from randomly dumping a very much valid TF cache (which will then cause all sorts of lookup errors and is causing previously working code to stop working).