System test failures occur when running 100s of times #1079
Comments
|
Update from @dirk-thomas: resolved by ros2/rclcpp#837 Failure case (1): FastRTPS - gazebo crashes - this is a failure we see randomly Edit: This one occurred 2/100 times. Added by @dirk-thomas: Log from dirk-thomas experiencing the same failure in the 10: Test command: /usr/bin/python3 "-u" "/home/dthomas/ros2/ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/dthomas/ros2/ws_nav/build/nav2_system_tests/test_results/nav2_system_tests/test_localization.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_MAP=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_EXECUTABLE=/home/dthomas/ros2/ws_nav/build/nav2_system_tests/src/localization/test_localization_node" "TEST_WORLD=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/models" "--command" "/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/src/localization/test_localization_launch.py" The location where the error message is coming from: https://github.com/ros2/rclcpp/blob/4feecc594559927cdc7689f5e73c6f210608aebc/rclcpp/include/rclcpp/strategies/allocator_memory_strategy.hpp#L236-L242 After some quick debugging the executor resizes the wait set with 6 guard conditions: https://github.com/ros2/rclcpp/blob/4feecc594559927cdc7689f5e73c6f210608aebc/rclcpp/src/rclcpp/executor.cpp#L451-L455 🪲 So this looks like a race condition that a different thread adds a condition between the check and the actual use. |
|
Failure case (2): this one is a dwb crash, no idea why, also occurred 2/100 times when running FastRTPS We can probably add some exception handling to dwb to 'try catch' whatever's happening here and at least print out a message. |
|
I expect this thread to grow pretty quickly due to the large number of different error cases. Therefore I recommend we label each different case with a unique number, like Also lets focus on FastRTS for now. For each failure case please include the full output of the test and not only a part. |
|
Failure case (3):
Full output of the `test_localization` test10: Test command: /usr/bin/python3 "-u" "/home/dthomas/ros2/ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/dthomas/ros2/ws_nav/build/nav2_system_tests/test_results/nav2_system_tests/test_localization.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_MAP=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_EXECUTABLE=/home/dthomas/ros2/ws_nav/build/nav2_system_tests/src/localization/test_localization_node" "TEST_WORLD=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/models" "--command" "/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/src/localization/test_localization_launch.py" |
|
I tested RTI Connext RTI Connext - failed 45/100 times |
|
I experienced the failure (1) reported above and attached my full log to the comment: #1079 (comment) |
@crdelsey Please keep this focused for now on FastRTPS. Otherwise this ticket will explode in length and become unmanagable. |
|
Actually looking at the FastRTPS fails, this is the best it has ever looked. The 2 fails I saw yesterday I saw 2x each, and don't look like RMW/DDS issues at all. I believe 1.9.0 might have fixed some issues (at least I hope). I will run another 100 runs this morning. If someone else can run another 100, that would be a good comparison. |
|
The last two times I ran FastRTPS (Tuesday and today) I got 8 and 4 failures out of 100, respectively. |
@crdelsey Please post specific failure cases with the necessary details in separate comments. These summary numbers aren't helpful in determining what causes them. |
|
Sorry. That data was requested in the thread above. I won't post those numbers again unless something is substantially different. |
|
@dirk-thomas - I think the statistical numbers are relevant. The fact that Carl and I got similar numbers is good data to have, it means I probably didn't get 'lucky' and that overall FastRTPS has improved vs. Dashing where we were seeing ~85% pass rate. We do need the logs also, but please don't mark those comments as off-topic. @crdelsey - can you triage the fails you saw? Do you still have the logs? |
We can use a different category - maybe "resolved"? The goal if this thread is to identify exact failures and resolve them. While the statistics are valuable they don't help with this goal. Therefore I would prefer to fold all comment not describing a specific failure - otherwise the length of this ticket will make it impossible to enumerate / iterate on the actual failures. |
|
@dirk-thomas - BTW the failure (1) above is the same failure seen in the build farm: Thank you for debugging it, are you going to file a bug in rclcpp? |
|
The referenced PR should fix failure (1). |
|
Failure case (4): Running another 100x with FastRTPS, same build, same system, this time 12/100 failed. The first fail I see is this: This may be a bug in amcl, not sure as I've not seen this one before. Full output of the test10: Test command: /usr/bin/python3 "-u" "/home/mkhansen/ros2_dev/ros2_ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_DIR=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_w_replanning_and_recovery.xml" "ASTAR=True" "--command" "/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py"10: Test timeout computed to be: 120 0% tests passed, 1 tests failed out of 1 Total Test time (real) = 120.11 sec The following tests FAILED: |
I've seen that one for a while, but only as amcl was shutting down. I don't think I've ever seen it cause the shutdown. |
It may only be a symptom, not the cause of the failure. Looking at the amcl code, I can see where it could try to free memory that's already been freed here: We can either check for a null before calling map_free(map_) and pf_free(pf_) or check inside those functions before calling free() itself. The latter is probably safer. I'll file a new issue for this. |
|
Please use the latest state when testing. ros2/rclcpp#837 has been merged which resolves the failure (1). |
|
Failure case (5)
Full output of the `test_planner` test9: Test command: /usr/bin/python3 "-u" "/home/dthomas/ros2/ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/dthomas/ros2/ws_nav/build/nav2_system_tests/test_results/nav2_system_tests/test_planner.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_LAUNCH_DIR=" "TEST_EXECUTABLE=/home/dthomas/ros2/ws_nav/build/nav2_system_tests/src/planning/test_planner_node" "TEST_MAP=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/maps/map.pgm" "--command" "/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/src/planning/test_planner_launch.py" |
|
This didn't actually fail the
|
|
Failure case (6):
Full output of the `test_bt_navigator_with_dijkstra` test12: Test command: /usr/bin/python3 "-u" "/home/dthomas/ros2/ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/dthomas/ros2/ws_nav/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator_with_dijkstra.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_DIR=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_w_replanning_and_recovery.xml" "ASTAR=False" "--command" "/home/dthomas/ros2/ws_nav/src/navigation2/nav2_system_tests/src/system/test_system_launch.py" Also reported here: ros2/rclcpp#827 |
|
Ignore (5) and any fails within test_planner for now. PR #1083 is fixing that test. I'm only running the bt_navigator test for my runs of 100. |
|
Fail (7) - this is new to me. Map server failing to load the map:
10: Test command: /usr/bin/python3 "-u" "/home/mkhansen/ros2_dev/ros2_ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_localization.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_EXECUTABLE=/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/src/localization/test_localization_node" "TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models" "--command" "/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/localization/test_localization_launch.py"
10: Test timeout computed to be: 60
10: -- run_test.py: extra environment variables:
10: - TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world
10: - TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml
10: - TEST_EXECUTABLE=/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/src/localization/test_localization_node
10: - GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models
10: -- run_test.py: invoking following command in '/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests':
10: - /home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/localization/test_localization_launch.py
10: [INFO] [launch]: All log files can be found below /home/mkhansen/.ros/log/2019-08-30-16-55-19-205802-mkhansen-desk-29879
10: [INFO] [launch]: Default logging verbosity is set to INFO
10: [INFO] [gzserver-1]: process started with pid [29883]
10: [INFO] [static_transform_publisher-2]: process started with pid [29884]
10: [INFO] [static_transform_publisher-3]: process started with pid [29885]
10: [INFO] [map_server-4]: process started with pid [29886]
10: [INFO] [amcl-5]: process started with pid [29887]
10: [INFO] [lifecycle_manager-6]: process started with pid [29888]
10: [INFO] [test_localization_node-7]: process started with pid [29889]
10: [static_transform_publisher-3] [INFO] []: LOOPING due to no latching at the moment
10: [static_transform_publisher-2] [INFO] []: LOOPING due to no latching at the moment
10: [test_localization_node-7] Running main() from /home/mkhansen/ros2_dev/ros2_ws/install/gtest_vendor/src/gtest_vendor/src/gtest_main.cc
10: [test_localization_node-7] [==========] Running 1 test from 1 test case.
10: [test_localization_node-7] [----------] Global test environment set-up.
10: [test_localization_node-7] [----------] 1 test from TestAmclPose
10: [test_localization_node-7] [ RUN ] TestAmclPose.SimpleAmclTest
10: [lifecycle_manager-6] [INFO] [lifecycle_manager]: Creating
10: [lifecycle_manager-6] [INFO] [lifecycle_manager]: Starting the system bringup...
10: [lifecycle_manager-6] [INFO] [lifecycle_manager]: Creating and initializing lifecycle service clients
10: [lifecycle_manager-6] [INFO] [lifecycle_manager]: Configuring and activating map_server
10: [amcl-5] [INFO] [amcl]: Creating
10: [map_server-4] [INFO] [map_server]: Creating
10: [map_server-4] [INFO] [map_server]: Configuring
10: [map_server-4] [INFO] [map_server]: OccGridLoader: Creating
10: [map_server-4] [INFO] [map_server]: OccGridLoader: Configuring
10: [map_server-4] [ERROR] [map_server]: Failed to load image file /home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml/map_circular.pgm for reason: Magick: Unable to open file (/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml/map_circular.pgm) reported by magick/blob.c:3002 (OpenBlob)
10: [map_server-4] [ERROR] []: Caught exception in callback for transition 10
10: [map_server-4] [ERROR] []: Original error: Failed to load map image file.
10: [map_server-4] [WARN] []: Error occurred while doing error handling.
10: [map_server-4] [FATAL] [map_server]: Lifecycle node entered error state
10: [lifecycle_manager-6] [ERROR] [lifecycle_manager]: Failed to change state for node: map_server
10: [lifecycle_manager-6] [ERROR] [lifecycle_manager]: Failed to bring up node: map_server, aborting bringup
10: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Wheel pair 1 separation set to [0.160000m]
10: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Wheel pair 1 diameter set to [0.066000m]
10: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Subscribed to [/cmd_vel]
10: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Advertise odometry on [/odom]
10: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Publishing odom transforms between [odom] and [base_footprint]
10: [gzserver-1] [INFO] [turtlebot3_joint_state]: Going to publish joint [wheel_left_joint]
10: [gzserver-1] [INFO] [turtlebot3_joint_state]: Going to publish joint [wheel_right_joint]
[Processing: nav2_system_tests]
10: [static_transform_publisher-3] [INFO] []: LOOPING due to no latching at the moment
10: [static_transform_publisher-2] [INFO] []: LOOPING due to no latching at the moment
[Processing: nav2_system_tests]
Test #10: test_localization ................***Timeout 60.07 sec
|
possibly responsible for heisenbug ros-navigation#1079 (comment)
possibly responsible for heisenbug #1079 (comment)
|
Fail case (8) 11: Test command: /usr/bin/python3 "-u" "/home/mkhansen/ros2_dev/ros2_ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_DIR=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_w_replanning_and_recovery.xml" "ASTAR=True" "--command" "/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py" 0% tests passed, 1 tests failed out of 1 |
|
Fail case (9) - dwb_controller crashes. We see this about 1% of the time. I'll file a bug on this.
11: Test command: /usr/bin/python3 "-u" "/home/mkhansen/ros2_dev/ros2_ws/install/ament_cmake_test/share/ament_cmake_test/cmake/run_test.py" "/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_DIR=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_w_replanning_and_recovery.xml" "ASTAR=True" "--command" "/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py"
11: Test timeout computed to be: 120
11: -- run_test.py: extra environment variables:
11: - ASTAR=True
11: - TEST_WORLD=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world
11: - BT_NAVIGATOR_XML=navigate_w_replanning_and_recovery.xml
11: - GAZEBO_MODEL_PATH=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/models
11: - TEST_MAP=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml
11: - TEST_DIR=/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system
11: -- run_test.py: invoking following command in '/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/src/system':
11: - /home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py
11: [INFO] [launch]: All log files can be found below /home/mkhansen/.ros/log/2019-09-03-13-00-36-057690-mkhansen-desk-5718
11: [INFO] [launch]: Default logging verbosity is set to INFO
11: [INFO] [gzserver-1]: process started with pid [5721]
11: [INFO] [static_transform_publisher-2]: process started with pid [5722]
11: [INFO] [static_transform_publisher-3]: process started with pid [5723]
11: [INFO] [map_server-4]: process started with pid [5724]
11: [INFO] [world_model-5]: process started with pid [5725]
11: [INFO] [gdb-6]: process started with pid [5726]
11: [INFO] [gdb-7]: process started with pid [5727]
11: [INFO] [navfn_planner-8]: process started with pid [5728]
11: [INFO] [recoveries_node-9]: process started with pid [5729]
11: [INFO] [bt_navigator-10]: process started with pid [5750]
11: [INFO] [lifecycle_manager-11]: process started with pid [5771]
11: [INFO] [test_system_node-12]: process started with pid [5781]
11: [static_transform_publisher-2] [INFO] []: LOOPING due to no latching at the moment
11: [static_transform_publisher-3] [INFO] []: LOOPING due to no latching at the moment
11: [map_server-4] [INFO] [map_server]: Creating
11: [world_model-5] [INFO] [world_model]: Creating World Model
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Creating Costmap
11: [navfn_planner-8] [INFO] [navfn_planner]: Creating
11: [recoveries_node-9] [INFO] [recoveries]: Configuring Spin
11: [recoveries_node-9] [INFO] [recoveries]: Configuring BackUp
11: [bt_navigator-10] [INFO] [bt_navigator]: Creating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Creating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Starting the system bringup...
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Creating and initializing lifecycle service clients
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating map_server
11: [map_server-4] [INFO] [map_server]: Configuring
11: [map_server-4] [INFO] [map_server]: OccGridLoader: Creating
11: [map_server-4] [INFO] [map_server]: OccGridLoader: Configuring
11: [map_server-4] [INFO] [map_server]: Activating
11: [map_server-4] [INFO] [map_server]: OccGridLoader: Activating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating amcl
11: [gdb-7] GNU gdb (Ubuntu 8.1-0ubuntu3) 8.1.0.20180409-git
11: [gdb-7] Copyright (C) 2018 Free Software Foundation, Inc.
11: [gdb-7] License GPLv3+: GNU GPL version 3 or later
11: [gdb-7] This is free software: you are free to change and redistribute it.
11: [gdb-7] There is NO WARRANTY, to the extent permitted by law. Type "show copying"
11: [gdb-7] and "show warranty" for details.
11: [gdb-7] This GDB was configured as "x86_64-linux-gnu".
11: [gdb-7] Type "show configuration" for configuration details.
11: [gdb-7] For bug reporting instructions, please see:
11: [gdb-7] .
11: [gdb-7] Find the GDB manual and other documentation resources online at:
11: [gdb-7] .
11: [gdb-7] For help, type "help".
11: [gdb-7] Type "apropos word" to search for commands related to "word"...
11: [gdb-7] Reading symbols from /home/mkhansen/ros2_dev/navigation2_ws/install/dwb_controller/lib/dwb_controller/dwb_controller...(no debugging symbols found)...done.
11: [gdb-7] Starting program: /home/mkhansen/ros2_dev/navigation2_ws/install/dwb_controller/lib/dwb_controller/dwb_controller __params:=/home/mkhansen/ros2_dev/navigation2_ws/install/nav2_bringup/share/nav2_bringup/launch/nav2_params.yaml
11: [gdb-6] GNU gdb (Ubuntu 8.1-0ubuntu3) 8.1.0.20180409-git
11: [gdb-6] Copyright (C) 2018 Free Software Foundation, Inc.
11: [gdb-6] License GPLv3+: GNU GPL version 3 or later
11: [gdb-6] This is free software: you are free to change and redistribute it.
11: [gdb-6] There is NO WARRANTY, to the extent permitted by law. Type "show copying"
11: [gdb-6] and "show warranty" for details.
11: [gdb-6] This GDB was configured as "x86_64-linux-gnu".
11: [gdb-6] Type "show configuration" for configuration details.
11: [gdb-6] For bug reporting instructions, please see:
11: [gdb-6] .
11: [gdb-6] Find the GDB manual and other documentation resources online at:
11: [gdb-6] .
11: [gdb-6] For help, type "help".
11: [gdb-6] Type "apropos word" to search for commands related to "word"...
11: [gdb-6] Reading symbols from /home/mkhansen/ros2_dev/navigation2_ws/install/nav2_amcl/lib/nav2_amcl/amcl...(no debugging symbols found)...done.
11: [gdb-6] Starting program: /home/mkhansen/ros2_dev/navigation2_ws/install/nav2_amcl/lib/nav2_amcl/amcl __params:=/home/mkhansen/ros2_dev/navigation2_ws/install/nav2_bringup/share/nav2_bringup/launch/nav2_params.yaml
11: [test_system_node-12] [INFO] [nav2_tester]: Starting test_system_node
11: [test_system_node-12] [INFO] [nav2_tester]: Waiting for a few seconds for all nodes to initialize
11: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Wheel pair 1 separation set to [0.160000m]
11: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Wheel pair 1 diameter set to [0.066000m]
11: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Subscribed to [/cmd_vel]
11: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Advertise odometry on [/odom]
11: [gzserver-1] [INFO] [turtlebot3_diff_drive]: Publishing odom transforms between [odom] and [base_footprint]
11: [gzserver-1] [INFO] [turtlebot3_joint_state]: Going to publish joint [wheel_left_joint]
11: [gzserver-1] [INFO] [turtlebot3_joint_state]: Going to publish joint [wheel_right_joint]
11: [gdb-7] [Thread debugging using libthread_db enabled]
11: [gdb-7] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
11: [gdb-6] [Thread debugging using libthread_db enabled]
11: [gdb-6] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
11: [gdb-7] [New Thread 0x7fffef638700 (LWP 5900)]
11: [gdb-7] [New Thread 0x7fffeee37700 (LWP 5901)]
11: [gdb-7] [New Thread 0x7fffee636700 (LWP 5902)]
11: [gdb-7] [New Thread 0x7fffede35700 (LWP 5903)]
11: [gdb-7] [New Thread 0x7fffed634700 (LWP 5904)]
11: [gdb-7] [New Thread 0x7fffece33700 (LWP 5905)]
11: [gdb-7] [New Thread 0x7fffd7fff700 (LWP 5906)]
11: [gdb-7] [New Thread 0x7fffd77fe700 (LWP 5907)]
11: [gdb-6] [New Thread 0x7ffff01b9700 (LWP 5908)]
11: [gdb-6] [New Thread 0x7fffef9b8700 (LWP 5909)]
11: [gdb-6] [New Thread 0x7fffef1b7700 (LWP 5910)]
11: [gdb-6] [New Thread 0x7fffee9b6700 (LWP 5911)]
11: [gdb-6] [New Thread 0x7fffee1b5700 (LWP 5912)]
11: [gdb-6] [New Thread 0x7fffed9b4700 (LWP 5913)]
11: [gdb-6] [New Thread 0x7fffed0b2700 (LWP 5914)]
11: [gdb-6] [New Thread 0x7fffd7fff700 (LWP 5915)]
11: [gdb-7] [New Thread 0x7fffd67da700 (LWP 5916)]
11: [gdb-7] [INFO] [dwb_controller]: Creating
11: [gdb-7] [New Thread 0x7fffd5fd9700 (LWP 5917)]
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Creating Costmap
11: [gdb-7] [New Thread 0x7fffd57d8700 (LWP 5918)]
11: [gdb-6] [New Thread 0x7fffd71ef700 (LWP 5919)]
11: [gdb-6] [INFO] [amcl]: Creating
11: [gdb-6] [INFO] [amcl]: Configuring
11: [gdb-6] [INFO] [amcl]: initTransforms
11: [gdb-6] [New Thread 0x7fffd61ce700 (LWP 5920)]
11: [gdb-6] [INFO] [amcl]: initPubSub
11: [gdb-6] [INFO] [amcl]: Subscribed to map topic.
11: [gdb-6] [INFO] [amcl]: Activating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating world_model
11: [world_model-5] [INFO] [world_model]: Configuring
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Configuring
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Using plugin "static_layer"
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Using plugin "obstacle_layer"
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Subscribed to Topics: scan
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Using plugin "inflation_layer"
11: [world_model-5] [INFO] [world_model]: Activating
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Activating
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Checking transform
11: [world_model-5] [INFO] [global_costmap.global_costmap]: StaticLayer: Resizing costmap to 384 X 384 at 0.050000 m/pix
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00039 timeout was 1.
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00043 timeout was 1.
11: [gdb-6] [INFO] [amcl_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.201 for reason(0)
11: [gdb-6] [INFO] [amcl_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.401 for reason(0)
11: [gdb-6] [INFO] [amcl_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.600 for reason(0)
11: [gdb-6] [INFO] [amcl_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.801 for reason(0)
11: [gdb-6] [INFO] [amcl_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.001 for reason(0)
11: [gdb-6] [WARN] [amcl]: Waiting for map....
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00994 timeout was 1.
11: [test_system_node-12] [INFO] [nav2_tester]: Getting amcl state...
11: [test_system_node-12] [INFO] [nav2_tester]: Result of get_state: active
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00951 timeout was 1.
11: [gdb-6] [WARN] [amcl]: Waiting for map....
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00947 timeout was 1.
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00948 timeout was 1.
11: [gdb-6] [WARN] [amcl]: Waiting for map....
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00039 timeout was 1.
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00012 timeout was 1.
11: [test_system_node-12] [INFO] [nav2_tester]: Setting initial pose
11: [test_system_node-12] [INFO] [nav2_tester]: Publishing Initial Pose
11: [gdb-6] [INFO] [amcl]: initialPoseReceived
11: [gdb-6] [INFO] [amcl]: Setting pose (1567540846.855911): -2.000 -0.500 0.000
11: [test_system_node-12] [INFO] [nav2_tester]: Waiting for amcl_pose to be received
11: [test_system_node-12] [INFO] [nav2_tester]: Setting initial pose
11: [test_system_node-12] [INFO] [nav2_tester]: Publishing Initial Pose
11: [gdb-6] [INFO] [amcl]: initialPoseReceived
11: [gdb-6] [INFO] [amcl]: Setting pose (1567540846.859687): -2.000 -0.500 0.000
11: [test_system_node-12] [INFO] [nav2_tester]: Waiting for amcl_pose to be received
11: [gdb-6] [WARN] [amcl]: Waiting for map....
11: [test_system_node-12] [INFO] [nav2_tester]: Setting initial pose
11: [test_system_node-12] [INFO] [nav2_tester]: Publishing Initial Pose
11: [gdb-6] [INFO] [amcl]: initialPoseReceived
11: [gdb-6] [INFO] [amcl]: Setting pose (1567540847.863519): -2.000 -0.500 0.000
11: [test_system_node-12] [INFO] [nav2_tester]: Waiting for amcl_pose to be received
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00961 timeout was 1.
11: [gdb-6] [INFO] [amcl]: Received a 384 X 384 map @ 0.050 m/pix
11: [gdb-6] [INFO] [amcl]: Setting pose (1567540848.207401): -2.000 -0.500 0.000
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.201 for reason(0)
11: [gdb-6] [INFO] [amcl]: createLaserObject
11: [test_system_node-12] [INFO] [nav2_tester]: Received amcl_pose
11: [test_system_node-12] [INFO] [nav2_tester]: test_InitialPose PASSED
11: [test_system_node-12] [INFO] [nav2_tester]: Getting bt_navigator state...
11: [test_system_node-12] [INFO] [nav2_tester]: Result of get_state: unconfigured
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.600 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 1.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Lookup would require extrapolation into the past. Requested time 11.96000 but the earliest data is at time 12.20100, when looking up transform from frame [base_link] to frame [map]. canTransform returned after 1.00353 timeout was 1.
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap.global_costmap]: start
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating dwb_controller
11: [gdb-7] [INFO] [dwb_controller]: Configuring
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Configuring
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Using plugin "static_layer"
11: [gdb-7] [New Thread 0x7fffbffff700 (LWP 5927)]
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Using plugin "obstacle_layer"
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Subscribed to Topics:
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Using plugin "inflation_layer"
11: [gdb-7] [INFO] [dwb_controller]: Setting transform_tolerance to 0.100000
11: [gdb-7] [INFO] [dwb_controller]: DWBLocalPlanner
11: [gdb-7] [INFO] [dwb_controller]: Using critic "RotateToGoal" (dwb_critics::RotateToGoalCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "Oscillation" (dwb_critics::OscillationCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "ObstacleFootprint" (dwb_critics::ObstacleFootprintCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "GoalAlign" (dwb_critics::GoalAlignCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "PathAlign" (dwb_critics::PathAlignCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "PathDist" (dwb_critics::PathDistCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Using critic "GoalDist" (dwb_critics::GoalDistCritic)
11: [gdb-7] [INFO] [dwb_controller]: Critic plugin initialized
11: [gdb-7] [INFO] [dwb_controller]: Controller frequency set to 20.0000Hz
11: [gdb-7] [INFO] [dwb_controller]: Activating
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Activating
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Checking transform
11: [gdb-7] [INFO] [local_costmap.local_costmap]: StaticLayer: Resizing costmap to 384 X 384 at 0.050000 m/pix
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 2.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 3.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 3.200 for reason(0)
11: [gdb-7] [INFO] [local_costmap.local_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: . canTransform returned after 1.00968 timeout was 1.
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 3.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 3.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 3.801 for reason(0)
11: [gdb-7] [INFO] [local_costmap.local_costmap]: start
11: [gdb-7] [New Thread 0x7fffbdd43700 (LWP 5928)]
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating navfn_planner
11: [navfn_planner-8] [INFO] [navfn_planner]: Configuring
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 4.001 for reason(0)
11: [navfn_planner-8] [INFO] [navfn_planner]: Activating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Configuring and activating bt_navigator
11: [bt_navigator-10] [INFO] [bt_navigator]: Configuring
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: Waiting for "ComputePathToPose" action server
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: "ComputePathToPose" BtActionNode initialized
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: Waiting for "FollowPath" action server
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: "FollowPath" BtActionNode initialized
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: Waiting for "/local_costmap/clear_entirely_local_costmap" service
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: "ClearEntireCostmap" BtServiceNode initialized
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: Waiting for "/global_costmap/clear_entirely_global_costmap" service
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: "ClearEntireCostmap" BtServiceNode initialized
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: Waiting for "Spin" action server
11: [bt_navigator-10] [INFO] [bt_navigator_client_node]: "Spin" BtActionNode initialized
11: [bt_navigator-10] [INFO] [bt_navigator]: Activating
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: The system is active
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 4.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 4.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 4.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 4.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 5.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 5.200 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 5.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 5.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 5.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 6.001 for reason(0)
11: [test_system_node-12] [INFO] [nav2_tester]: Getting bt_navigator state...
11: [test_system_node-12] [INFO] [nav2_tester]: Result of get_state: active
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 6.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 6.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 6.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 6.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 7.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 7.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 7.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 7.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 7.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 8.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 8.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 8.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 8.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 8.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 9.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 9.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 9.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 9.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 9.800 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 10.001 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 10.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 10.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 10.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 10.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 11.001 for reason(0)
11: [test_system_node-12] [INFO] [nav2_tester]: Setting goal pose
11: [bt_navigator-10] [INFO] [bt_navigator]: Begin navigating from current location to (0.00, 2.00)
11: [test_system_node-12] [INFO] [nav2_tester]: Waiting 60 seconds for robot to reach goal
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 11.201 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 11.401 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 11.601 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 11.801 for reason(0)
11: [world_model-5] [INFO] [global_costmap_rclcpp_node]: [signalFailure] Drop message: frame 'base_scan' at time 12.001 for reason(0)
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [gdb-7] [INFO] [dwb_controller]: Received a goal, begin following path
11: [gdb-7] [New Thread 0x7fffbd542700 (LWP 5935)]
11: [gdb-7]
11: [gdb-7] Thread 15 "dwb_controller" received signal SIGSEGV, Segmentation fault.
11: [gdb-7] [Switching to Thread 0x7fffbd542700 (LWP 5935)]
11: [gdb-7] 0x00007fffbe16afd3 in costmap_queue::CostmapQueue::enqueueCell(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int) ()
11: [gdb-7] from /home/mkhansen/ros2_dev/navigation2_ws/install/dwb_critics/lib/libdwb_critics.so
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [static_transform_publisher-2] [INFO] []: LOOPING due to no latching at the moment
11: [static_transform_publisher-3] [INFO] []: LOOPING due to no latching at the moment
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [bt_navigator-10] terminate called after throwing an instance of 'rclcpp::exceptions::RCLError'
11: [bt_navigator-10] what(): error taking status: error not set
11: [ERROR] [bt_navigator-10]: process has died [pid 5750, exit code -6, cmd '/home/mkhansen/ros2_dev/navigation2_ws/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args __node:=bt_navigator __params:=/tmp/launch_params_l0_vldxt __params:=/tmp/launch_params_t6dv09vk'].
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [static_transform_publisher-2] [INFO] []: LOOPING due to no latching at the moment
11: [static_transform_publisher-3] [INFO] []: LOOPING due to no latching at the moment
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [INFO] [nav2_tester]: Distance from goal is: 3.2015621187164243
11: [test_system_node-12] [ERROR] [nav2_tester]: Robot timed out reaching its goal!
11: [test_system_node-12] [ERROR] [nav2_tester]: Test FAILED
11: [test_system_node-12] /home/mkhansen/ros2_dev/ros2_ws/install/rclpy/lib/python3.6/site-packages/rclpy/node.py:1091: UserWarning: Pass an explicit 'qos_profile' argument
11: [test_system_node-12] warnings.warn("Pass an explicit 'qos_profile' argument")
11: [test_system_node-12] /home/mkhansen/ros2_dev/ros2_ws/install/rclpy/lib/python3.6/site-packages/rclpy/node.py:1156: UserWarning: Pass an explicit 'qos_profile' argument
11: [test_system_node-12] warnings.warn("Pass an explicit 'qos_profile' argument")
11: [ERROR] [test_system_node-12]: process has died [pid 5781, exit code 1, cmd '/home/mkhansen/ros2_dev/navigation2_ws/src/navigation2/nav2_system_tests/src/system/test_system_node.py'].
11: [INFO] [lifecycle_manager-11]: sending signal 'SIGINT' to process[lifecycle_manager-11]
11: [INFO] [recoveries_node-9]: sending signal 'SIGINT' to process[recoveries_node-9]
11: [INFO] [navfn_planner-8]: sending signal 'SIGINT' to process[navfn_planner-8]
11: [INFO] [gdb-7]: sending signal 'SIGINT' to process[gdb-7]
11: [INFO] [gdb-6]: sending signal 'SIGINT' to process[gdb-6]
11: [INFO] [world_model-5]: sending signal 'SIGINT' to process[world_model-5]
11: [INFO] [map_server-4]: sending signal 'SIGINT' to process[map_server-4]
11: [INFO] [static_transform_publisher-3]: sending signal 'SIGINT' to process[static_transform_publisher-3]
11: [INFO] [static_transform_publisher-2]: sending signal 'SIGINT' to process[static_transform_publisher-2]
11: [INFO] [map_server-4]: process has finished cleanly [pid 5724]
11: [INFO] [gzserver-1]: sending signal 'SIGINT' to process[gzserver-1]
11: [lifecycle_manager-11] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [lifecycle_manager-11] [INFO] [lifecycle_manager]: Destroying
11: [recoveries_node-9] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [navfn_planner-8] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [gdb-7] Quit
11: [navfn_planner-8] [INFO] [navfn_planner]: Destroying
11: [world_model-5] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [map_server-4] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [world_model-5] [INFO] [world_model]: Destroying
11: [gdb-6]
11: [gdb-6] Thread 1 "amcl" received signal SIGINT, Interrupt.
11: [gdb-6] 0x00007ffff52159f3 in futex_wait_cancelable (private=,
11: [gdb-6] expected=0, futex_word=0x555555834ee0)
11: [gdb-6] at ../sysdeps/unix/sysv/linux/futex-internal.h:88
11: [gdb-6] 88 ../sysdeps/unix/sysv/linux/futex-internal.h: No such file or directory.
11: [static_transform_publisher-3] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [static_transform_publisher-2] [INFO] [rclcpp]: signal_handler(signal_value=2)
11: [INFO] [static_transform_publisher-3]: process has finished cleanly [pid 5723]
11: [INFO] [world_model-5]: process has finished cleanly [pid 5725]
11: [INFO] [static_transform_publisher-2]: process has finished cleanly [pid 5722]
11: [INFO] [recoveries_node-9]: process has finished cleanly [pid 5729]
11: [INFO] [navfn_planner-8]: process has finished cleanly [pid 5728]
11: [INFO] [lifecycle_manager-11]: process has finished cleanly [pid 5771]
11: [INFO] [gzserver-1]: process has finished cleanly [pid 5721]
11: [ERROR] [gdb-7]: process[gdb-7] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
11: [ERROR] [gdb-6]: process[gdb-6] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
11: [INFO] [gdb-7]: sending signal 'SIGTERM' to process[gdb-7]
11: [INFO] [gdb-6]: sending signal 'SIGTERM' to process[gdb-6]
11: [gdb-7] Exception ignored in:
11: [gdb-7] Traceback (most recent call last):
11: [gdb-7] File "/usr/share/gdb/python/gdb/__init__.py", line 43, in flush
11: [gdb-7] def flush(self):
11: [gdb-7] KeyboardInterrupt
11: [gdb-6] Exception ignored in:
11: [gdb-6] Traceback (most recent call last):
11: [gdb-6] File "/usr/share/gdb/python/gdb/__init__.py", line 43, in flush
11: [gdb-6] def flush(self):
11: [gdb-6] KeyboardInterrupt
11: [INFO] [gdb-6]: process has finished cleanly [pid 5726]
11: [INFO] [gdb-7]: process has finished cleanly [pid 5727]
11: [gdb-6] (gdb)
11: [gdb-7] (gdb) (gdb)
11: -- run_test.py: return code 1
11: -- run_test.py: generate result file '/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml' with failed test
11: -- run_test.py: verify result file '/home/mkhansen/ros2_dev/navigation2_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml'
1/1 Test #11: test_bt_navigator ................***Failed 88.51 sec
|
|
After updating to the latest ROS2 and Nav2, I get fail case (8) 100% of the time. I believe the primary error in the log is I believe this problem ultimately triggers the lifecycle manager problem cited. |
* remove nav2_robot package * remove CMakeList and package.xml dependence on nav2_robot * robot_util classes for publishing and states * changing all users of robot_ to their appropriate eq. * changing the controller to use the nav2_utils velocity publisher wrapper as well * adding shared locks properly to share get resources * correct namespace nav2_robot -> nav2_util * remove sharedptr references * resolve merge conflicts * Setting default to use AMCL topic to true * fix rebase/merge conflicts deleting robot package * removing old maintainers from navigation1 * Switch from map service to topic (#885) * Add parameter to disable map server * Move parameter check to getParameters * Uncrustify * Don't mark static layer as current until we have a map * Make sure static layer gets initialized Make sure static layer gets initialized, even with an empty layer, so it doesn't crash if you disable the map service and enable the obstacle layer * remove map service from static layer Only use map topic instead Subscribe to map topic with default transient local volatility Add parameter "map_subscribe_transient_local" (default=true) for backwards compatibility with volatile publishers * Change AMCL to use only the map topic, not map service * remove now-unused MapServiceClient * uncrustify * only set current_=true when first map received * Fix nav2_costmap inflation tests. * Fixing collision tester test. * Revert "uncrustify" This reverts commit 82f88a7. This uncrustify failure is enforced differently depending on whether we are on the dashing branch or on the master branch. This particular commit is only appropriate on the dashing branch, but is already present there. * change primitives to recoveries (#705) * change primitives to recoveries * changing all over new bringups with nav2_recoveries * renaming primitive_name -> recovery_name * stop robot on cancel in recovery * fixed recovery node halt bug * removing nav2_robot package * adding lifecycle publisher for dwb * Removing unneeded tf initialization calls * Remove dedicated thread from costmap * Add support for new createTimerInterface API * Fix system test launch file. * updated the build scripts for ROS2 Dashing (#924) * run build from anywhere in tree * renaming dependencies because its driving me up a wall autocomplete for nav doesnt work * remove extra files re-introduced in PR #704 * set align critics scale to 0 (#936) * fix typo in build tool updates * Nav2-rviz-plugin changes. (#937) * I added a timeout to spin_until_future_complete, so rviz doesn't get frozen if something goes wrong in the navigation stack. I did some changes in the start navigation; - changed the funtion type to boolean - added returns to the funtion, so it will return false if something goes wrong. I changed goal_tool added a if statement to check if start_navigation doesn't return false before calling any other functions in goal_tool * made the code cleaner and changed the error messages. Reduced the timeout value to 3 seconds. The timeouts will be parametrized in the future. * added timeout parameter * fix linter failures in Rviz plugin (#979) * I added a timeout to spin_until_future_complete, so rviz doesn't get frozen if something goes wrong in the navigation stack. I did some changes in the start navigation; - changed the funtion type to boolean - added returns to the funtion, so it will return false if something goes wrong. I changed goal_tool added a if statement to check if start_navigation doesn't return false before calling any other functions in goal_tool * made the code cleaner and changed the error messages. Reduced the timeout value to 3 seconds. The timeouts will be parametrized in the future. * added timeout parameter * Update navigation_dialog.cpp * Update navigation_dialog.hpp * Update navigation_dialog.cpp * Update navigation_dialog.hpp * Fixing typo in dependencies (#982) * Fixing typo in dependencies * Also remove some duplicate dependencies * Fixing robot_state_publisher dependency * Add support to change the local controller rate. (#970) * Add back parameter to configure DWA rate * Report out if we missed our control loop time. * Fix the dashing build on OSRF build farm. (#935) All our builds have boost installed due to other dependencies, so we've never run into this. The build farm must build with all other dependencies removed somehow. * bump for release to 0.2.2 * Fix for TEB local planner buildable (#981) Signed-off-by: vinnamkim <vinnam.kim@gmail.com> * adding rate loops where applicable (#743) * adding rate loops where applicable * throttle while loops with sleep_for * sleep_dir -> sleep_dur * enabling closed-loop control in spin (#983) * implemented controlled spin * remove files reintroduced (#991) * collision checkers in recoveries now look sufficiently far ahead in the local coordinate frame * removing whitespace * revert to global: need PR for TF positioning merged before can fix that * Creating a simple action server to be able to invoke Random Crawl from BT (#945) added random crawl action to bt * amcl particlecloud is best effort (#1003) Signed-off-by: Mikael Arguedas <mikael.arguedas@gmail.com> * Disable displaying RobotModel in Rviz by default (#1001) * returning failed if recovery cannot be completed due to collision * backing out collision detection into a new fuction * removing extraneous visualization from tests that have been removed * revert my own config * make ye old linter happy * Footprint subscriber const topic Signed-off-by: Shane Loretz <sloretz@osrfoundation.org> * Costmap subscriber const topic Signed-off-by: Shane Loretz <sloretz@osrfoundation.org> * fixing PR feedback to stopRobot() in better location and parameterization * removing unnecessary smart pointers that dont effect lifecycle * lifecycle executor doesnt need to be a pointer * removing extra PR template field in application no one uses * Reorganize some of the BehaviorTree-related code (#957) * Reorganize some of the BehaviorTree-related code. Eliminate the NavigateToPoseBehaviorTree class, merging it with the BehaviorTreeEngine. Put clear_entirely service client with the others in nav2_util. Move RecoveryNode to nav2_behavior_tree with the other BT nodes. * Remove method signature that isn't implemented yet * Add a missing dependency * Address a couple linter issues * Tf based positioning (#993) * remove topic based positioning for TF and removing extraneous build fields * robot utils complete for getting positioning from TF * readding the custom logger for getting current pose * remove extra TODO * fixing fun crustyness * pass by ref not shared ptr * wrapping costmap 2d's get pose with util * revert costmap 2d plugin initialization swap * fixing more uncrustified issues while I wait * adding transform listener to buffers * adding tf listeners and missing dependencies * editing test cases * trying no exception * first stab at unit tests with TF2 for costmap 2D integration test * adding the create timer interface * adding updated pose info for testing * com'n crusty code, why are you different in CI? * fixing merge conflicts p2 * remove unnecessary CMake code to remove warning (#1005) Signed-off-by: Mikael Arguedas <mikael.arguedas@gmail.com> * disabling by default the debug markers for local planner (#1007) * adding deprecation warning for topic-based goal navigation * fixing spin recovery * incorrect topic names * Provide correct path to default map (#987) * Extend the costmap's namespace with the hosting node's namespace (#999) * Parameter dumping utility (#902) * Add a parameter dumping utility to nav2_utils * Add some convenience functions to simplify declaring parameters * Add some examples for AMCL * Remove stray example file * Default to dumping all nodes; throw/catch exceptions * Address some review feedback * Fix node name collisions (#1020) * Fix node name collisions Make sure service clients have a unique node name (this was a problem in recoveries nodes) Delimit ros arguments with new `--ros-args`,`--` * Uncrustify * Fixing linter failures introduced in master (#1029) * Fixing linter failures introduced in master * Sort of fix test_occ_grid_cpp test but disable since it's flaky * Disable failing test_collision_checker test * Recovery using odometric poses and costmaps (#1023) * recovery behaviors using the odometric positioning for pose estimation * use local costmap information in recoveries * fixing costmap namespacing for collision detector * odometry based recoveries with collision checker global frame model * on download, rosdep all necessary items, calling on each build is redundant * doing rosdep install in a single call * removing extraneous cd * adding recoveries XML to simulation launch file (#1031) * adding recoveries XML to simulation launch file * fix typo from name vs frame odom * refactor goal handle into panel clean up remove extra log info * remove nav2 goal tool and address review feedback * fix lint issue * send pose via qt signal through goal tool * remove navigation dialog minor clean up * use enum for action states fix compile issues remove extra semicolons fix uncrustify * add QBasicTimer cleanup timer * remove more unnecessary headers * Add parallel testing jobs for each rmw vendor * Fix yaml * Fix yaml * Use custom version of nightly instead * Extend workflow for rmw testing on release * Fix typo * Try speeding up build by omitting job limit * Ensure checksum.txt exist for restoring cache * Set --load-average +1 from -j For a 2CPU/4096MB CI resource * Reorganized executor and add caching nonce Improve env DRY'ness by using separate executors Enable debug builds Add nonce to caching to help avoid caching key collisions between debug and release workflow paths * Fix awk to print env to checksum * Add .dockerhub build hooks and add FROM_IMAGE to arguments * Switch to custom docker repo * Use symlinks to place Dockerfile with hooks Tweak build hook to compensate for dockhub assumptions DockerHub repo build rules: source: master tag: master Dockerfile: /.dockerhub/nightly/Dockerfile source: master tag: master-rmw Dockerfile: /.dockerhub/nightly-rmw/Dockerfile source: /^.*-devel$ tag: {sourceref} Dockerfile: /.dockerhub/devel/Dockerfile * Have CI Dockerfile use ccache * Add .dockerignore to avoid braking build cache So tweaking unrelated files doesn't invalidate: COPY ./ navigation2/ * Word wrap long command * Combine ccache with Circle CI caching * Correct terms for underlay and overlay upstream -> underlay navigation2,build,source -> overlay * Change setup_underlay to setup_dependencies * Share ccache across overlay and underlay * Correct typo * Add new line * Always save ccache avoid unnecessary checking step * Hack to avoid breaking docker build cache for COPY when changing Dockerfile itself. This shouldn't be needed, but does not seem to work without ** ¯\_(ツ)_/¯ * Add adjustable build failure behavior When FAIL_ON_BUILD_FAILURE is unset failures from colcon build will be supressed allowing for docker build to succeed. This prevents DockerHub CI images from becoming stale when branch build brakes, previously blocking DockerHub CI image builds. * Enable nightly release tests now that docker CI builds unset FAIL_ON_BUILD_FAILURE thus its status is less indicative of master build breaking * Avoid cache collisions for PRs with same branch name by including unique PR number into cache key CircleCI branch name substitution using {{ .Branch }} does not prefix names with the repo name. Thus PRs from separate forks using the same branch name could collide. https://circleci.com/docs/2.0/env-vars/#built-in-environment-variables https://circleci.com/docs/2.0/configuration-reference/#save_cache * Do not share underlay cache across branchs/PRs * Abridge lengthening cache key names * Account for failed underlay builds if we don't happen to clean the underlay when we keep the underlay from the docker image Copy logic to overlay for consistency in behavior * Add epoch to cache key given caches are immutable and use spaceless string concatenation in yaml to split long key names into multiple lines. Given the immutability of caches, and that cache key matching is prefix based, {{ epoch }} must be the last part of the cache-save key. https://discuss.circleci.com/t/add-mechanism-to-update-existing-cache-key/9014/13 https://circleci.com/docs/2.0/caching/#restoring-cache https://circleci.com/docs/2.0/configuration-reference/#save_cache https://stackoverflow.com/questions/3790454/how-do-i-break-a-string-over-multiple-lines/21699210#comment65667554_21699210 * Clean workspace incase build_failed * Improve underlay build cache By only copying .repo file for vcs import of underlay and move overlay copy just before rosdep install for overlay * Remove duplicate copy of overlay .repos file given the dockerfile now copies this directly into the overlay wrokspace * Rename workspaces to underlay and overlay To complete the standardization of terminology ros_ws -> underlay_ws nav2_ws -> overlay_ws * Add on_checkout anchor to make config more DRY * Target nonfree tag to include connext * Add ccache stats command to print and zero ccache statistics as well as ccache version and config after restore of ccache cache and after each underlay/overlay build * Cleanup code coverage pipline Use offical Codecov orb for uploading make the coverage script more DRY * Remove unnecessary indents * Split debuild build and test and make release tests more DRY * Shorten config * Print out lcov command when runing script * Use to avoid infinite recursion * Add common_environment refrence and make jobs more DRY * Store ccache logs for CI debugging * Simplify code coverage script to prevent untented shell glob expansion * Rename fields * Store test result * Copy test results into expected directory structure See directory structure example in https://circleci.com/docs/2.0/configuration-reference/#store_test_results * Store test artifacts for debug uploaded results * Support parallel testing * Fix xargs line splitting * Run colcon test-results to fail on test errors Needed to use return status from test-results * Lookup historical timing data by classname for split-by E.g. "costmap_queue.CostmapQueue" in `costmap_queue/utest.gtest.xml` : <testsuites tests="5" failures="0" disabled="0" errors="0" timestamp="2019-08-12T06:57:26" time="0.499" name="AllTests"> <script/> <testsuite name="CostmapQueue" tests="5" failures="0" disabled="0" errors="0" time="0.499"> <testcase name="basicQueue" status="run" time="0" classname="costmap_queue.CostmapQueue"/> <testcase name="bigTest" status="run" time="0.496" classname="costmap_queue.CostmapQueue"/> <testcase name="linearQueue" status="run" time="0" classname="costmap_queue.CostmapQueue"/> <testcase name="crossQueue" status="run" time="0.001" classname="costmap_queue.CostmapQueue"/> <testcase name="limitedQueue" status="run" time="0.002" classname="costmap_queue.CostmapQueue"/> </testsuite> </testsuites> * Show split count and omit unneeded xargs * Simplify build using colcon mixins and add build args for underlay and overlay mixins * Override mixing in build hook * Rename build hooks and tags * Build overlay with same settings to maximize ccache hit rate * Correct mixin typo * Make checksum.txt more informative by piping message into directly into file for debugging and simplify digests inclusion for spotting hash diffs * Fixing up paths for codecov.io report (#1036) * Update .dockerignore Co-Authored-By: Carl Delsey <carl.r.delsey@intel.com> * Move rwm jobs back into nightly workflow * Set genhtml as default and add case for ci * Refactor config using commands * Use paths instead of env * Revert ccache anchor name * Fix install linking * Avoid using paths as keys prefix matching fails when key includes slashes * Rename yaml anchor * Make sure lcov is installed for CI * Fix the build due to access specifiers (#1040) No idea why this builds under GCC but these changes were needed to build under clang. * Mark timerEvent override (#1037) * Add dummy Dockerfiles for setting repository links on Docker Hub * Set exit and print trace in script * Tweek tag names * nav2_util::duration_from_seconds -> rclcpp::Duration::from_seconds (#1048) * nav2_util::duration_from_seconds -> rclcpp::Duration::from_seconds * Update nav2_costmap_2d/plugins/static_layer.cpp oops! Co-Authored-By: Carl Delsey <carl.r.delsey@intel.com> * Rewrite nav2_map_server (#989) Add GraphicsMagick API and use it to implement map_saver, map_loader Removes dependency on SDL, creates installation dependency on libgraphicsmagick++; apt package libgraphicsmagick++1-dev Allows saving in trinary, raw, or scale mode. Added configurable image format pgm, png, etc. Add warning when using scale mode with opaque format. Remove SDL from map server Extract repeated MapMode to shared enum class Switch writing YAML to same library that reads it (yaml-cpp) Add --help alias to map saver -h Extract map yaml loading to its own function, with better error messages. Also fixed crash due to misuse of std::string constructor. * Migrate image tag to rosplanning repo * Enable AMCL to initialize at the origin, under control of a parameter * Make sure everything shuts down cleanly * Some cleanup and linting * Address review feedback * Also have to update the YAML file * Remove the connection object for now. Needs further investigation * Find all uses of yaw to quaternion and use new function * Simplify a quaternion copy * Restore COLCON_IGNORE file * Oops. Missed a package dependency * Fixing a rebase error * Add missing dependencies to system tests (#1059) Signed-off-by: Louise Poubel <louise@openrobotics.org> * add tf2_geometry_msgs dependency * Fix the updown test. (#1061) * Fixing linter errors, accidentally commited. * Export envs for arg in build hook * Remove the setSimTime() method - not needed anymore * Remove ros2param package dependency * Fix indentation (#1065) * BT Service node & implementations (#1055) * generic ros service caller BT node * BT specialty service callers using BT node service * rename to reinitialize global localization * uncrustify/lint * changes per PR requests * changing pose topics to goal_pose * Removing deprecation warning * Removing an accidentally re-introduced file * use seconds in Duration * Enable global planner tester (#927) * use duration from seconds * Add ctest loop script to system tests * Set line buffering to 1 in system test launch * Update README * Update README for using ctest_loop script * Recombine AMCL library components with AMCL to have consistent license (#1074) * Move AMCL library files back to nav2_amcl package * Fixing up naming so things compile again * Transition copyright disable check to follow eig3 files. * Transition amcl files license to LGPL 2.1 * Adding missing copyright headers to nav2_bringup package * Adding missing copyright headers to nav2_common * Fixing up include guard to match coding style * Reformatting license to pass the copyright check The change here is only whitespace changes - line length and paragraph spacing, as well as the addition of the license title * Relicensing file to better match the existing package * Fixing readme to account for the new change * Begin updating nav2_behavior_tree README * Continue update of nav2_behavior_tree readme * Add link to behavior tree basic nodes to README Adding a link to the upstream documentation on behaviortree.dev * Clarify Licensing throughout the repo (#1080) * Add proper SPDX license IDs and repo LICENSE file * Fixing a minor linter typo * Use python yaml safe loader (#1085) * Null-terminate string to dirname function (#1093) possibly responsible for heisenbug #1079 (comment) * Update to latest v2 BT Library (#1088) * Revert CreateTimer change * Revert "nav2_util::duration_from_seconds -> rclcpp::Duration::from_seconds (#1048)" This reverts commit 7c473cd. * Fix dependency exports * Fixing missing boost dependency
|
@crdelsey @mkhansen-intel is there any update w.r.t the above? have you had the chance to retry with the latest ROS2 and if so how frequently are you seeing which errors? Also, if folks need to use the latest ROS2, does that imply they need to use the latest navigation stack (rather than 0.2.4) as well? Thanks! |
|
@AAlon yes if you're using master ROS2 you should use our master as well |
|
The referenced PR ros2/rcl#501 only resolves the "This error state is being overwritten" problem reported in (8). The actual error "Failed to finish transition 3" will still be there. |
|
Going by the comments made by @crdelsey and @mkhansen-intel two weeks ago I thought there were still numerous pending issues here...? just want to make sure it was closed on purpose and not by accident. |
Actually, with the latest ROS2 master (aka Eloquent), I'm not seeing any of these issues anymore. I am seeing some other issues occasionally, and will file separate issues for those, but I believe those are in our stack. This is now closed! 👍 |
|
Sorry, I used a wording in a referenced PR which GitHub interpreted to close this issue when it was merged - I rephrased it just now. I will reopen since it seems there are still numerous issues pending (at least it is not obvious to me that they were fixed). Due to the un-structure of this thread it is pretty hard to tell though what items are still remaining... |
|
I'm re-closing this, since I'm not seeing these issues anymore. I'm running more tests 100's of times and will file individual issues as I find them. @dirk-thomas - THANKS for your help with this. The fixes you made do seem to help. |
Bug report
This is not a single issue, but a meta-ticket for discussing the system test failures that are occurring.
For example, I ran the system test using the method in #1076 with three different RMW implementations and got these results:
FastRTPS - failed 4/100 times
OpenSplice - failed 17/100 times
CycloneDDS - failed 23/100 times
Required Info:
Steps to reproduce issue
See PR #1076
Expected behavior
Tests should pass 100/100 times
Actual behavior
FastRTPS - failed 4/100 times
OpenSplice - failed 17/100 times
CycloneDDS - failed 23/100 times
Additional information
I'll update the ticket with more info in the comments.
The text was updated successfully, but these errors were encountered: