Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Problem not to run halt correctly in bt_action_node #3848

Closed
CihatAltiparmak opened this issue Oct 1, 2023 · 2 comments
Closed

Problem not to run halt correctly in bt_action_node #3848

CihatAltiparmak opened this issue Oct 1, 2023 · 2 comments
Labels
in progress

Comments

@CihatAltiparmak
Copy link
Contributor

CihatAltiparmak commented Oct 1, 2023 •
edited
Loading

Bug report

Required Info:

  • Operating System: Ubuntu 22.04.3 LTS (Jammy Jellyfish)
  • ROS2 Version: Rolling
  • Version or commit hash: 42670c0
  • Package: nav2_behavior_tree

Description of the debug

When bt_action_node is halted before goal is completed, it is wait that the goal cancels but not wait that corresponding result_callback finish its job. This brings about not to run return_callback on time.

Expected behavior

When bt_action_node is halted, if corresponding goal is not completed, it should be cancelled goal and triggered on_cancelled callback as soon as result_callback of corresponding goal.

Example:
tested on fixed version with new test case 

[==========] Running 3 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 3 tests from BTActionNodeTestFixture
[ RUN      ] BTActionNodeTestFixture.test_server_timeout_success
[INFO] [1696115562.369772159] [fibonacci_node]: Goal is received..
[INFO] [1696115562.372381439] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.372449402] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.372459457] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.372467514] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.399797082] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696115562.400117689] [fibonacci_node]: Goal is received..
[WARN] [1696115562.420314587] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
[INFO] [1696115562.500597589] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.500720054] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.500750949] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.500777890] [fibonacci_node]: Goal is feedbacking.
[       OK ] BTActionNodeTestFixture.test_server_timeout_success (146 ms)
[ RUN      ] BTActionNodeTestFixture.test_server_timeout_failure
[INFO] [1696115562.517242055] [fibonacci_node]: Goal is received..
[WARN] [1696115562.607679797] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
[INFO] [1696115562.607779583] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696115562.617928910] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.618053432] [fibonacci_node]: Goal is received..
[INFO] [1696115562.643561865] [fibonacci_node]: Goal is feedbacking.
[       OK ] BTActionNodeTestFixture.test_server_timeout_failure (177 ms)
[ RUN      ] BTActionNodeTestFixture.test_server_cancel
[INFO] [1696115562.691858205] [fibonacci_node]: Goal is received..
[INFO] [1696115562.694168168] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.744286127] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.794286136] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.844289791] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.894289973] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.944271683] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115562.994283654] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.044274036] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.094300868] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.144290212] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.191882925] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696115563.194281769] [fibonacci_node]: Goal is canceling.
[INFO] [1696115563.194488821] [fibonacci_node]: Goal is received..
[INFO] [1696115563.196825651] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.246898272] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.296907588] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.346878787] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.396942015] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.446884970] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.496937918] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.546887427] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.596942564] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.646888989] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.696866105] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.746948518] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.796937509] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.846880042] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696115563.891885037] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696115563.896869056] [fibonacci_node]: Goal is canceling.
[       OK ] BTActionNodeTestFixture.test_server_cancel (1223 ms)
[----------] 3 tests from BTActionNodeTestFixture (1547 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test suite ran. (1565 ms total)
[  PASSED  ] 3 tests.

Actual behavior

When bt_action_node is halted, if corresponding goal is not completed, it's cancelled goal but not triggered on_cancelled callback as soon as result_callback of corresponding goal.

Example:
tested on current version with new test case 

[==========] Running 3 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 3 tests from BTActionNodeTestFixture
[ RUN      ] BTActionNodeTestFixture.test_server_timeout_success
[INFO] [1696108379.002220192] [fibonacci_node]: Goal is received..
[INFO] [1696108379.004713719] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.004780406] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.004795524] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.004809114] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.032193949] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696108379.032453403] [fibonacci_node]: Goal is received..
[WARN] [1696108379.052975003] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
[INFO] [1696108379.133070636] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.133182788] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.133211336] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.133233461] [fibonacci_node]: Goal is feedbacking.
[       OK ] BTActionNodeTestFixture.test_server_timeout_success (152 ms)
[ RUN      ] BTActionNodeTestFixture.test_server_timeout_failure
[INFO] [1696108379.151498461] [fibonacci_node]: Goal is received..
[WARN] [1696108379.241635426] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
[INFO] [1696108379.241739630] [bt_action_node_test_fixture]: Tree is halting.
[INFO] [1696108379.252277279] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.252380287] [fibonacci_node]: Goal is received..
[INFO] [1696108379.277881534] [fibonacci_node]: Goal is feedbacking.
[       OK ] BTActionNodeTestFixture.test_server_timeout_failure (177 ms)
[ RUN      ] BTActionNodeTestFixture.test_server_cancel
[INFO] [1696108379.328595353] [fibonacci_node]: Goal is received..
[INFO] [1696108379.330908688] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.380994297] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.431020035] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.481026478] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.530985800] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.581019693] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.631024159] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.681022296] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.731017380] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.781026289] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.828634063] [bt_action_node_test_fixture]: Tree is halting.
/home/nav_ws/src/navigation2/nav2_behavior_tree/test/plugins/action/test_bt_action_node.cpp:443: Failure
Expected equality of these values:
  on_cancelled_triggered
    Which is: false
  true
[INFO] [1696108379.829193971] [fibonacci_node]: Goal is received..
[INFO] [1696108379.830984797] [fibonacci_node]: Goal is canceling.
[INFO] [1696108379.831522230] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.881610684] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.931639105] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108379.981594191] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.031633841] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.081623700] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.131602613] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.181603073] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.231639431] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.281636402] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.331600897] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.381621817] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.431643660] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.481588516] [fibonacci_node]: Goal is feedbacking.
[INFO] [1696108380.528579163] [bt_action_node_test_fixture]: Tree is halting.
/home/nav_ws/src/navigation2/nav2_behavior_tree/test/plugins/action/test_bt_action_node.cpp:475: Failure
Expected equality of these values:
  on_cancelled_triggered
    Which is: false
  true
[INFO] [1696108380.531588490] [fibonacci_node]: Goal is canceling.
[  FAILED  ] BTActionNodeTestFixture.test_server_cancel (1215 ms)
[----------] 3 tests from BTActionNodeTestFixture (1545 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test suite ran. (1561 ms total)
[  PASSED  ] 2 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] BTActionNodeTestFixture.test_server_cancel

 1 FAILED TEST

Additional information

For more information about this bug, please look at this discussion

I think it should be added new test case for the scenairo to halt bt_action_node before goal execution is completed.

I tested on ros::rolling docker image.

My question on this bug

https://github.com/ros-planning/navigation2/blob/42670c0d7bbe3712afde83550a3747fac1f19c4a/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L363-366

Is this part still necessary after this bug is solved? I think about it but i haven't found it.
@CihatAltiparmak CihatAltiparmak mentioned this issue Oct 1, 2023
Merged
7 tasks
@SteveMacenski
Copy link
Member

SteveMacenski commented Oct 2, 2023 •
edited
Loading

Great to point out and I appreciate the test case! I've responded in your PR. I believe that bit of code you point out at the end is still required due to the rcl_action bug. We have checks like that in the WPF and in other locations. I wouldn't remove it unless we could prove that this is the only error causing it

@CihatAltiparmak
Copy link
Contributor Author

Hello @SteveMacenski , i have commited according to your feedback. Thanks for feedback.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
in progress
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@SteveMacenski @CihatAltiparmak