actionlib done_cb does not get called/throws errors

asked 2016-02-04 09:57:45 -0500

jmueller gravatar image

updated 2016-02-06 10:17:52 -0500

Hi everyone,

after searching through quite a bit of code and questions I gave up and am now posting my question here. I followed the SimpleActionClient/Server Tutorials to write an action for a robot to move from one pose to another (ROS Indigo@Ubuntu 14.04). This is used in a fairly large (and admittedly a little ugly) piece of code that also does some thread juggling and uses multiple Callback Queues. Most of the time, it does it's job and I'm currently running it through a bunch of simulations with a simulated moving robot. While doing so (and only while in the simulations) I have been seeing error messages occasionally that seem to go back to line 443 in simple_action_client.h:

[ERROR] [1454599109.360150730]: Got a callback on a goalHandle that we're not tracking.                 This is an internal SimpleActionClient/ActionClient bug.                 This could also be a GoalID collision

As it mentioned there, I'm putting this off as an internal actionClient bug. It does not affect me for the feedback (as in the link above) but for finished goals. I adapted to that by checking against DONE and LOST in my done_cb:

void nodeToCoordinateConverter::doneCB( const actionlib::SimpleClientGoalState& state,
                                    const flyToResultConstPtr& result){
ROS_DEBUG_STREAM("Finished in state " << state.toString());
ROS_INFO_STREAM("Ended up at " << result->actual.x << " " << result->actual.y << " " << result->actual.z << " " << result->actual.yaw);

if (state == actionlib::SimpleClientGoalState::SUCCEEDED)
{
    arrived = true;
}
else if (state == actionlib::SimpleClientGoalState::LOST)
{
    ROS_WARN("Goal is in state LOST, will assume that I reached the goal...");
    arrived = true;
}}

I'm just mentioning this here in case it might be related to my actual problem.

What happens occasionally is that the whole goal processing just freezes, not calling this callback. Right before setting my goal as succeeded, I give a short info that my goal succeeded like this:

ROS_INFO_STREAM(action_name_ << " succeeded!");
// set the action state to succeeded
as_.setSucceeded(result_);

And usually, my console output will look like this for a goal:

Getting status over the wire.
fly_to succeeded!
Trying to transition to WAITING_FOR_RESULT
Transitioning CommState from ACTIVE to WAITING_FOR_RESULT
Trying to transition to DONE
Transitioning CommState from WAITING_FOR_RESULT to DONE
Transitioning SimpleState from [ACTIVE] to [DONE]
Finished in state SUCCEEDED
Ended up at 32.0361 17.5783 1.502 2.74032

Where the second line is the last from my Server and the two last lines are the first from my client done_cb. Now, sometimes, this just stops for one agent after the message:

fly_to succeeded!

But I don't get any of the further down messages. I looked a little through the simple_action_server_imp.h file and traced my call (through here and here) to publishing on some topic, nothing much can go wrong there (in my opinion). I know that on the other side, the first message

Trying to transition to WAITING_FOR_RESULT

Must come from the CommStateMachine<actionspec>::transitionToState call in /opt/ros/indigo/include/actionlib/client/comm_state_machine_imp.h:CommStateMachine<actionspec>::transitionToState:456 - but I don't know by what ... (more)

edit retag flag offensive close merge delete

Comments

So, I actually tried the idea of logging the action messages together with the remaining stuff in a bag file - and at least for 50 runs (each one taking about 6 Minutes +starting/shutdown, bagfile parsing) the not calling issue did not occur. Could it be the fact that there are now 2 subscribers?

jmueller gravatar image jmueller  ( 2016-02-05 01:10:47 -0500 )edit

Okay, I take that back: it still occurs. Interestingly, all the messages of the action just stop, all that is, but the status messages.

jmueller gravatar image jmueller  ( 2016-02-06 03:38:01 -0500 )edit

Okay, I left that in my head a little and noticed: I can actually find that I don't get feedback and send the goal again when I get no feedback for significantly longer than I would expect. Not exactly the cleanest way, but I will see if this works...

jmueller gravatar image jmueller  ( 2016-02-10 04:06:50 -0500 )edit
2

In Case anyone stumbles upon this: It seems as if the "goal handle not tracked" issue only arises with rather large processor loads. Looking at the feedback messages can be used to get around not getting messages, even though it's not the nicest way. For now, this seems to work for me.

jmueller gravatar image jmueller  ( 2016-02-19 01:14:13 -0500 )edit