search

ros-navigation / navigation2

ROS 2 Navigation Framework and System
https://nav2.org/
Other
2.51k stars 1.27k forks source link

bt_service_node and bt_action_node: Don't block BT loop (backport #4214) #4408

Closed christophfroehlich closed 3 months ago

christophfroehlich commented 3 months ago

A manual backport, see https://github.com/ros-navigation/navigation2/pull/4214#issuecomment-2155106153

Same errors as on the iron branch -> seem to be not related

$ colcon test-result
build/nav2_behavior_tree/Testing/20240608-1938/Test.xml: 60 tests, 0 errors, 3 failures, 0 skipped
build/nav2_behavior_tree/test_results/nav2_behavior_tree/cppcheck.xunit.xml: 173 tests, 0 errors, 2 failures, 0 skipped
build/nav2_behavior_tree/test_results/nav2_behavior_tree/test_bt_action_node.gtest.xml: 3 tests, 0 errors, 2 failures, 0 skipped
build/nav2_behavior_tree/test_results/nav2_behavior_tree/test_single_trigger_node.gtest.xml: 1 test, 0 errors, 1 failure, 0 skipped
mergify[bot] commented 3 months ago

@christophfroehlich, all pull requests must be targeted towards the main development branch. Once merged into main, it is possible to backport to @iron, but it must be in main to have these changes reflected into new distributions.

SteveMacenski commented 3 months ago

build/nav2_behavior_tree/Testing/20240608-1938/Test.xml: 60 tests, 0 errors, 3 failures, 0 skipped

The other was 2 and now its 3, so that seems to point to this introducing problems. Please colcon test-result --verbose to print the failures to look at

christophfroehlich commented 3 months ago

Hm, you are right. I don't know where I looked at before, maybe it does not occur every call. I'll have a look why and if there is the same problem on the main branch.

- test_bt_action_node
  <<< failure message
    -- run_test.py: invoking following command in '/workspaces/ros2_iron_ws/build/nav2_behavior_tree/test/plugins/action':
     - /workspaces/ros2_iron_ws/build/nav2_behavior_tree/test/plugins/action/test_bt_action_node --gtest_output=xml:/workspaces/ros2_iron_ws/build/nav2_behavior_tree/test_results/nav2_behavior_tree/test_bt_action_node.gtest.xml
    [==========] Running 3 tests from 1 test suite.
    [----------] Global test environment set-up.
    [----------] 3 tests from BTActionNodeTestFixture
    [ RUN      ] BTActionNodeTestFixture.test_server_timeout_success
    [INFO] [1718088084.232464638] [fibonacci_node]: Goal is received..
    [INFO] [1718088084.234861420] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.234903023] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.234910658] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.234916933] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.262410380] [bt_action_node_test_fixture]: Tree is halting.
    [INFO] [1718088084.262593717] [fibonacci_node]: Goal is received..
    [WARN] [1718088084.283501986] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
    /workspaces/ros2_iron_ws/src/navigation2/nav2_behavior_tree/test/plugins/action/test_bt_action_node.cpp:319: Failure
    Expected equality of these values:
      ticks
        Which is: 3
      2
    [INFO] [1718088084.362887802] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.362951241] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.362960275] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.362964371] [fibonacci_node]: Goal is feedbacking.
    [  FAILED  ] BTActionNodeTestFixture.test_server_timeout_success (142 ms)
    [ RUN      ] BTActionNodeTestFixture.test_server_timeout_failure
    [INFO] [1718088084.370709526] [fibonacci_node]: Goal is received..
    [WARN] [1718088084.460389162] [bt_action_node_test_fixture]: Timed out while waiting for action server to acknowledge goal request for fibonacci
    /workspaces/ros2_iron_ws/src/navigation2/nav2_behavior_tree/test/plugins/action/test_bt_action_node.cpp:364: Failure
    Expected equality of these values:
      ticks
        Which is: 10
      9
    [INFO] [1718088084.470469220] [bt_action_node_test_fixture]: Tree is halting.
    [INFO] [1718088084.470970583] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.471048030] [fibonacci_node]: Goal is received..
    [INFO] [1718088084.496306706] [fibonacci_node]: Goal is feedbacking.
    [  FAILED  ] BTActionNodeTestFixture.test_server_timeout_failure (158 ms)
    [ RUN      ] BTActionNodeTestFixture.test_server_cancel
    [INFO] [1718088084.526633097] [fibonacci_node]: Goal is received..
    [INFO] [1718088084.528859191] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.578946067] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.628943091] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.678946363] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.728943498] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.778933516] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.828950882] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.878944046] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.928923946] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088084.978919547] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.026671152] [bt_action_node_test_fixture]: Tree is halting.
    [INFO] [1718088085.028920482] [fibonacci_node]: Goal is canceling.
    [INFO] [1718088085.029174465] [fibonacci_node]: Goal is received..
    [INFO] [1718088085.031373580] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.081439356] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.131452042] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.181411496] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.231407200] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.281431477] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.331433641] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.381434398] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.431430036] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.481441717] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.531454114] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.581455024] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.631434257] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.681433065] [fibonacci_node]: Goal is feedbacking.
    [INFO] [1718088085.726628428] [bt_action_node_test_fixture]: Tree is halting.
    [INFO] [1718088085.731433222] [fibonacci_node]: Goal is canceling.
    [       OK ] BTActionNodeTestFixture.test_server_cancel (1211 ms)
    [----------] 3 tests from BTActionNodeTestFixture (1511 ms total)

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

     2 FAILED TESTS
SteveMacenski commented 3 months ago

Yeah, please look into that! That is not flaky on the main branch that I am aware of from looking at CI jobs, I've not seen that fail before (but I suppose doesn't mean it hasn't, just that I've never seen it)

christophfroehlich commented 3 months ago

I rebased this on top of origin/iron and cherry-picked #4234. @SteveMacenski it seems that you have fixed the failing test already ;) 

 $ colcon test-result
build/nav2_behavior_tree/Testing/20240624-0739/Test.xml: 61 tests, 0 errors, 2 failures, 0 skipped
build/nav2_behavior_tree/test_results/nav2_behavior_tree/cppcheck.xunit.xml: 176 tests, 0 errors, 2 failures, 0 skipped
build/nav2_behavior_tree/test_results/nav2_behavior_tree/test_single_trigger_node.gtest.xml: 1 test, 0 errors, 1 failure, 0 skipped

Summary: 867 tests, 0 errors, 5 failures, 0 skipped