Port system tests in nav2_system_tests

[stevedanomodolor]

---

Basic Info

Info	Please fill out this column
Ticket(s) this addresses	(add tickets here #1)
Primary OS tested on	(Ubuntu, MacOS, Windows)
Robotic platform tested on	(Steve's Robot, gazebo simulation of Tally, hardware turtlebot)
Does this PR contain AI generated software?	(No; Yes and it is marked inline in the code)

---

Description of contribution in a few bullet points

• Related to https://github.com/ros-navigation/navigation2/issues/4455

  ---

  Future work that may be required in bullet points

  For Maintainers:

  • [ ] Check that any new parameters added are updated in docs.nav2.org
  • [ ] Check that any significant change is added to the migration guide
  • [ ] Check that any new features OR changes to existing behaviors are reflected in the tuning guide
  • [ ] Check that any new functions have Doxygen added
  • [ ] Check that any new features have test coverage
  • [ ] Check that any new plugins is added to the plugins page
  • [ ] If BT Node, Additionally: add to BT's XML index of nodes for groot, BT package's readme table, and BT library lists

[stevedanomodolor]

@SteveMacenski I have a question about something I am experiencing. I ported just the test_bt_navigator for now. When I run the test for the first time, everything works fine,

root@stevedan:/opt/overlay_ws/build/nav2_system_tests/src/system# ctest -V -R test_bt_navigator
UpdateCTestConfiguration  from :/opt/overlay_ws/build/nav2_system_tests/src/system/DartConfiguration.tcl
UpdateCTestConfiguration  from :/opt/overlay_ws/build/nav2_system_tests/src/system/DartConfiguration.tcl
Test project /opt/overlay_ws/build/nav2_system_tests/src/system
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 1
    Start 1: test_bt_navigator

1: Test command: /usr/bin/python3 "-u" "/opt/ros/rolling/share/ament_cmake_test/cmake/run_test.py" "/opt/overlay_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=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/opt/overlay_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/opt/overlay_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/opt/overlay_ws/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_to_pose_w_replanning_and_recovery.xml" "TESTER=nav_to_pose_tester_node.py" "ASTAR=True" "CONTROLLER=nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController" "PLANNER=nav2_navfn_planner::NavfnPlanner" "--command" "/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py"
1: Working Directory: /opt/overlay_ws/build/nav2_system_tests/src/system
1: Test timeout computed to be: 180
1: -- run_test.py: extra environment variables:
1:  - ASTAR=True
1:  - BT_NAVIGATOR_XML=navigate_to_pose_w_replanning_and_recovery.xml
1:  - CONTROLLER=nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController
1:  - GAZEBO_MODEL_PATH=/opt/overlay_ws/src/navigation2/nav2_system_tests/models
1:  - PLANNER=nav2_navfn_planner::NavfnPlanner
1:  - TESTER=nav_to_pose_tester_node.py
1:  - TEST_DIR=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system
1:  - TEST_MAP=/opt/overlay_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml
1:  - TEST_WORLD=/opt/overlay_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world
1: -- run_test.py: invoking following command in '/opt/overlay_ws/build/nav2_system_tests/src/system':
1:  - /opt/overlay_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py
1: [INFO] [launch]: All log files can be found below /root/.ros/log/2024-06-16-05-54-09-982712-stevedan-596
1: [INFO] [launch]: Default logging verbosity is set to INFO
1: [INFO] [ruby $(which gz) sim-1]: process started with pid [599]
1: [INFO] [parameter_bridge-2]: process started with pid [601]
1: [INFO] [create-3]: process started with pid [603]
1: [INFO] [static_transform_publisher-4]: process started with pid [604]
1: [INFO] [static_transform_publisher-5]: process started with pid [605]
1: [INFO] [map_server-6]: process started with pid [606]
1: [INFO] [amcl-7]: process started with pid [607]
1: [INFO] [lifecycle_manager-8]: process started with pid [608]
1: [INFO] [controller_server-9]: process started with pid [609]
1: [INFO] [smoother_server-10]: process started with pid [618]
1: [INFO] [planner_server-11]: process started with pid [631]
1: [INFO] [behavior_server-12]: process started with pid [636]
1: [INFO] [bt_navigator-13]: process started with pid [664]
1: [INFO] [waypoint_follower-14]: process started with pid [693]
1: [INFO] [velocity_smoother-15]: process started with pid [702]
1: [INFO] [collision_monitor-16]: process started with pid [711]
1: [INFO] [opennav_docking-17]: process started with pid [714]
1: [INFO] [lifecycle_manager-18]: process started with pid [723]
1: [INFO] [tester_node-19]: process started with pid [748]
1: [create-3] [INFO] [1718517250.499694689] [ros_gz_sim]: Requesting list of world names.
1: [static_transform_publisher-4] [WARN] [1718517250.427545734] []: Old-style arguments are deprecated; see --help for new-style arguments
1: [static_transform_publisher-4] [INFO] [1718517250.486287347] [static_transform_publisher_ySNmsptUgfhc4p0S]: Spinning until stopped - publishing transform
1: [static_transform_publisher-4] translation: ('0.000000', '0.000000', '0.000000')
1: [static_transform_publisher-4] rotation: ('0.000000', '0.000000', '0.000000', '1.000000')
1: [static_transform_publisher-4] from 'base_footprint' to 'base_link'
1: [static_transform_publisher-5] [WARN] [1718517250.404850301] []: Old-style arguments are deprecated; see --help for new-style arguments
1: [static_transform_publisher-5] [INFO] [1718517250.442697140] [static_transform_publisher_IWvSfLgsogyr8CeW]: Spinning until stopped - publishing transform
1: [static_transform_publisher-5] translation: ('0.000000', '0.000000', '0.000000')
1: [static_transform_publisher-5] rotation: ('0.000000', '0.000000', '0.000000', '1.000000')
1: [static_transform_publisher-5] from 'base_link' to 'base_scan'
1: [map_server-6] [INFO] [1718517250.583412902] [map_server]: 
1: [map_server-6]   map_server lifecycle node launched. 
1: [map_server-6]   Waiting on external lifecycle transitions to activate
1: [map_server-6]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [map_server-6] [INFO] [1718517250.583507516] [map_server]: Creating
1: [behavior_server-12] [INFO] [1718517250.583024128] [behavior_server]: 
1: [behavior_server-12]     behavior_server lifecycle node launched. 
1: [behavior_server-12]     Waiting on external lifecycle transitions to activate
1: [behavior_server-12]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [lifecycle_manager-8] [INFO] [1718517250.685063760] [lifecycle_manager_localization]: Creating
1: [lifecycle_manager-8] [INFO] [1718517250.714857017] [lifecycle_manager_localization]: Creating and initializing lifecycle service clients
1: [controller_server-9] [INFO] [1718517250.761054909] [controller_server]: 
1: [controller_server-9]    controller_server lifecycle node launched. 
1: [controller_server-9]    Waiting on external lifecycle transitions to activate
1: [controller_server-9]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [smoother_server-10] [INFO] [1718517250.772282074] [smoother_server]: 
1: [smoother_server-10]     smoother_server lifecycle node launched. 
1: [smoother_server-10]     Waiting on external lifecycle transitions to activate
1: [smoother_server-10]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [smoother_server-10] [INFO] [1718517250.790477582] [smoother_server]: Creating smoother server
1: [controller_server-9] [INFO] [1718517250.796313798] [controller_server]: Creating controller server
1: [amcl-7] [INFO] [1718517250.801992024] [amcl]: 
1: [amcl-7]     amcl lifecycle node launched. 
1: [amcl-7]     Waiting on external lifecycle transitions to activate
1: [amcl-7]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [amcl-7] [INFO] [1718517250.803444505] [amcl]: Creating
1: [velocity_smoother-15] [INFO] [1718517250.886840490] [velocity_smoother]: 
1: [velocity_smoother-15]   velocity_smoother lifecycle node launched. 
1: [velocity_smoother-15]   Waiting on external lifecycle transitions to activate
1: [velocity_smoother-15]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [lifecycle_manager-8] [INFO] [1718517250.903346358] [lifecycle_manager_localization]: Starting managed nodes bringup...
1: [lifecycle_manager-8] [INFO] [1718517250.903393874] [lifecycle_manager_localization]: Configuring map_server
1: [planner_server-11] [INFO] [1718517250.920046378] [planner_server]: 
1: [planner_server-11]  planner_server lifecycle node launched. 
1: [planner_server-11]  Waiting on external lifecycle transitions to activate
1: [planner_server-11]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [planner_server-11] [INFO] [1718517250.923893983] [planner_server]: Creating
1: [collision_monitor-16] [INFO] [1718517250.936558203] [collision_monitor]: 
1: [collision_monitor-16]   collision_monitor lifecycle node launched. 
1: [collision_monitor-16]   Waiting on external lifecycle transitions to activate
1: [collision_monitor-16]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [controller_server-9] [INFO] [1718517251.020422983] [local_costmap.local_costmap]: 
1: [controller_server-9]    local_costmap lifecycle node launched. 
1: [controller_server-9]    Waiting on external lifecycle transitions to activate
1: [controller_server-9]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [controller_server-9] [INFO] [1718517251.040457434] [local_costmap.local_costmap]: Creating Costmap
1: [waypoint_follower-14] [INFO] [1718517251.052892611] [waypoint_follower]: 
1: [waypoint_follower-14]   waypoint_follower lifecycle node launched. 
1: [waypoint_follower-14]   Waiting on external lifecycle transitions to activate
1: [waypoint_follower-14]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [waypoint_follower-14] [INFO] [1718517251.057861089] [waypoint_follower]: Creating
1: [lifecycle_manager-18] [INFO] [1718517251.127663795] [lifecycle_manager_navigation]: Creating
1: [bt_navigator-13] [INFO] [1718517251.128169204] [bt_navigator]: 
1: [bt_navigator-13]    bt_navigator lifecycle node launched. 
1: [bt_navigator-13]    Waiting on external lifecycle transitions to activate
1: [bt_navigator-13]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [bt_navigator-13] [INFO] [1718517251.132818337] [bt_navigator]: Creating
1: [map_server-6] [INFO] [1718517251.138536654] [map_server]: Configuring
1: [map_server-6] [INFO] [map_io]: Loading yaml file: /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.yaml
1: [map_server-6] [DEBUG] [map_io]: resolution: 0.05
1: [map_server-6] [DEBUG] [map_io]: origin[0]: -10
1: [map_server-6] [DEBUG] [map_io]: origin[1]: -10
1: [map_server-6] [DEBUG] [map_io]: origin[2]: 0
1: [map_server-6] [DEBUG] [map_io]: free_thresh: 0.196
1: [map_server-6] [DEBUG] [map_io]: occupied_thresh: 0.65
1: [map_server-6] [DEBUG] [map_io]: mode: trinary
1: [map_server-6] [DEBUG] [map_io]: negate: 0
1: [map_server-6] [INFO] [map_io]: Loading image_file: /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.pgm
1: [planner_server-11] [INFO] [1718517251.142410998] [global_costmap.global_costmap]: 
1: [planner_server-11]  global_costmap lifecycle node launched. 
1: [planner_server-11]  Waiting on external lifecycle transitions to activate
1: [planner_server-11]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [planner_server-11] [INFO] [1718517251.143821071] [global_costmap.global_costmap]: Creating Costmap
1: [map_server-6] [DEBUG] [map_io]: Read map /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.pgm: 384 X 384 map @ 0.05 m/cell
1: [lifecycle_manager-18] [INFO] [1718517251.183099651] [lifecycle_manager_navigation]: Creating and initializing lifecycle service clients
1: [opennav_docking-17] [INFO] [1718517251.209964942] [docking_server]: 
1: [opennav_docking-17]     docking_server lifecycle node launched. 
1: [opennav_docking-17]     Waiting on external lifecycle transitions to activate
1: [opennav_docking-17]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [opennav_docking-17] [INFO] [1718517251.210161506] [docking_server]: Creating docking_server
1: [lifecycle_manager-8] [INFO] [1718517251.210303024] [lifecycle_manager_localization]: Configuring amcl
1: [amcl-7] [INFO] [1718517251.210906606] [amcl]: Configuring
1: [amcl-7] [INFO] [1718517251.210986127] [amcl]: initTransforms
1: [amcl-7] [INFO] [1718517251.242431152] [amcl]: initPubSub
1: [amcl-7] [INFO] [1718517251.270657727] [amcl]: Subscribed to map topic.
1: [lifecycle_manager-8] [INFO] [1718517251.297798038] [lifecycle_manager_localization]: Activating map_server
1: [map_server-6] [INFO] [1718517251.298066434] [map_server]: Activating
1: [map_server-6] [INFO] [1718517251.298410849] [map_server]: Creating bond (map_server) to lifecycle manager.
1: [amcl-7] [INFO] [1718517251.301340824] [amcl]: Received a 384 X 384 map @ 0.050 m/pix
1: [lifecycle_manager-8] [INFO] [1718517251.420018243] [lifecycle_manager_localization]: Server map_server connected with bond.
1: [lifecycle_manager-8] [INFO] [1718517251.420062858] [lifecycle_manager_localization]: Activating amcl
1: [amcl-7] [INFO] [1718517251.421347621] [amcl]: Activating
1: [amcl-7] [INFO] [1718517251.421504875] [amcl]: Creating bond (amcl) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517251.453281232] [lifecycle_manager_navigation]: Starting managed nodes bringup...
1: [lifecycle_manager-18] [INFO] [1718517251.453380509] [lifecycle_manager_navigation]: Configuring controller_server
1: [controller_server-9] [INFO] [1718517251.456245218] [controller_server]: Configuring controller interface
1: [controller_server-9] [INFO] [1718517251.456267988] [controller_server]: getting progress checker plugins..
1: [controller_server-9] [INFO] [1718517251.456388354] [controller_server]: getting goal checker plugins..
1: [controller_server-9] [INFO] [1718517251.456437535] [controller_server]: Controller frequency set to 20.0000Hz
1: [controller_server-9] [INFO] [1718517251.456463226] [local_costmap.local_costmap]: Configuring
1: [controller_server-9] [INFO] [1718517251.488840908] [local_costmap.local_costmap]: Using plugin "voxel_layer"
1: [controller_server-9] [INFO] [1718517251.515395744] [local_costmap.local_costmap]: Subscribed to Topics: scan
1: [parameter_bridge-2] [INFO] [1718517251.517391530] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/clock (gz.msgs.Clock) -> clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517251.519595305] [ros_gz_bridge]: Creating GZ->ROS Bridge: [joint_states (gz.msgs.Model) -> joint_states (sensor_msgs/msg/JointState)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517251.526823501] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/odom (gz.msgs.Odometry) -> odom (nav_msgs/msg/Odometry)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517251.544521742] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/tf (gz.msgs.Pose_V) -> tf (tf2_msgs/msg/TFMessage)] (Lazy 0)
1: [lifecycle_manager-8] [INFO] [1718517251.547152934] [lifecycle_manager_localization]: Server amcl connected with bond.
1: [lifecycle_manager-8] [INFO] [1718517251.547187503] [lifecycle_manager_localization]: Managed nodes are active
1: [lifecycle_manager-8] [INFO] [1718517251.547196970] [lifecycle_manager_localization]: Creating bond timer...
1: [controller_server-9] [INFO] [1718517251.551179840] [local_costmap.local_costmap]: Initialized plugin "voxel_layer"
1: [controller_server-9] [INFO] [1718517251.551210308] [local_costmap.local_costmap]: Using plugin "inflation_layer"
1: [controller_server-9] [INFO] [1718517251.551712518] [local_costmap.local_costmap]: Initialized plugin "inflation_layer"
1: [parameter_bridge-2] [INFO] [1718517251.561087402] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/imu (gz.msgs.IMU) -> imu (sensor_msgs/msg/Imu)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517251.564416272] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/scan (gz.msgs.LaserScan) -> scan (sensor_msgs/msg/LaserScan)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517251.567557699] [ros_gz_bridge]: Creating ROS->GZ Bridge: [cmd_vel (geometry_msgs/msg/Twist) -> /cmd_vel (gz.msgs.Twist)] (Lazy 0)
1: [controller_server-9] [INFO] [1718517251.646212074] [controller_server]: Created progress_checker : progress_checker of type nav2_controller::SimpleProgressChecker
1: [controller_server-9] [INFO] [1718517251.646535011] [controller_server]: Controller Server has progress_checker  progress checkers available.
1: [controller_server-9] [INFO] [1718517251.647168465] [controller_server]: Created goal checker : general_goal_checker of type nav2_controller::SimpleGoalChecker
1: [controller_server-9] [INFO] [1718517251.647402933] [controller_server]: Controller Server has general_goal_checker  goal checkers available.
1: [controller_server-9] [INFO] [1718517251.649392531] [controller_server]: Created controller : FollowPath of type nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517251.671303529] [controller_server]: Controller Server has FollowPath  controllers available.
1: [tester_node-19] [INFO] [1718517251.681548120] [nav2_tester]: Starting tester, robot going from -2.0, -0.5 to 0.0, 2.0.
1: [lifecycle_manager-18] [INFO] [1718517251.709763989] [lifecycle_manager_navigation]: Configuring smoother_server
1: [smoother_server-10] [INFO] [1718517251.713863408] [smoother_server]: Configuring smoother server
1: [smoother_server-10] [INFO] [1718517251.756291542] [smoother_server]: Created smoother : simple_smoother of type nav2_smoother::SimpleSmoother
1: [smoother_server-10] [INFO] [1718517251.758887126] [smoother_server]: Smoother Server has simple_smoother  smoothers available.
1: [create-3] [INFO] [1718517251.773739802] [ros_gz_sim]: Requested creation of entity.
1: [create-3] [INFO] [1718517251.773781713] [ros_gz_sim]: OK creation of entity.
1: [lifecycle_manager-18] [INFO] [1718517251.787047307] [lifecycle_manager_navigation]: Configuring planner_server
1: [planner_server-11] [INFO] [1718517251.787503671] [planner_server]: Configuring
1: [planner_server-11] [INFO] [1718517251.787546019] [global_costmap.global_costmap]: Configuring
1: [planner_server-11] [INFO] [1718517251.802306066] [global_costmap.global_costmap]: Using plugin "static_layer"
1: [planner_server-11] [INFO] [1718517251.818337628] [global_costmap.global_costmap]: Subscribing to the map topic (/map) with transient local durability
1: [planner_server-11] [INFO] [1718517251.821788858] [global_costmap.global_costmap]: Initialized plugin "static_layer"
1: [planner_server-11] [INFO] [1718517251.821813769] [global_costmap.global_costmap]: Using plugin "obstacle_layer"
1: [planner_server-11] [INFO] [1718517251.823072433] [global_costmap.global_costmap]: Subscribed to Topics: scan
1: [planner_server-11] [INFO] [1718517251.839541753] [global_costmap.global_costmap]: Initialized plugin "obstacle_layer"
1: [planner_server-11] [INFO] [1718517251.839578790] [global_costmap.global_costmap]: Using plugin "inflation_layer"
1: [planner_server-11] [INFO] [1718517251.840160158] [global_costmap.global_costmap]: Initialized plugin "inflation_layer"
1: [planner_server-11] [INFO] [1718517251.894103210] [global_costmap.global_costmap]: StaticLayer: Resizing costmap to 384 X 384 at 0.050000 m/pix
1: [planner_server-11] [INFO] [1718517251.894863208] [planner_server]: Created global planner plugin GridBased of type nav2_navfn_planner::NavfnPlanner
1: [planner_server-11] [INFO] [1718517251.894897399] [planner_server]: Configuring plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517251.898173961] [planner_server]: Planner Server has GridBased  planners available.
1: [INFO] [create-3]: process has finished cleanly [pid 603]
1: [lifecycle_manager-18] [INFO] [1718517251.943812594] [lifecycle_manager_navigation]: Configuring behavior_server
1: [behavior_server-12] [INFO] [1718517251.944107696] [behavior_server]: Configuring
1: [behavior_server-12] [INFO] [1718517251.958594713] [behavior_server]: Creating behavior plugin spin of type nav2_behaviors::Spin
1: [behavior_server-12] [INFO] [1718517251.961567896] [behavior_server]: Creating behavior plugin backup of type nav2_behaviors::BackUp
1: [behavior_server-12] [INFO] [1718517251.966259489] [behavior_server]: Creating behavior plugin drive_on_heading of type nav2_behaviors::DriveOnHeading
1: [behavior_server-12] [INFO] [1718517251.968508010] [behavior_server]: Creating behavior plugin assisted_teleop of type nav2_behaviors::AssistedTeleop
1: [behavior_server-12] [INFO] [1718517251.973197336] [behavior_server]: Creating behavior plugin wait of type nav2_behaviors::Wait
1: [behavior_server-12] [INFO] [1718517251.989595885] [behavior_server]: Configuring spin
1: [behavior_server-12] [INFO] [1718517252.008867673] [behavior_server]: Configuring backup
1: [behavior_server-12] [INFO] [1718517252.040388411] [behavior_server]: Configuring drive_on_heading
1: [behavior_server-12] [INFO] [1718517252.053128598] [behavior_server]: Configuring assisted_teleop
1: [behavior_server-12] [INFO] [1718517252.061192832] [behavior_server]: Configuring wait
1: [lifecycle_manager-18] [INFO] [1718517252.066860542] [lifecycle_manager_navigation]: Configuring velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517252.067101171] [velocity_smoother]: Configuring velocity smoother
1: [lifecycle_manager-18] [INFO] [1718517252.074608832] [lifecycle_manager_navigation]: Configuring collision_monitor
1: [collision_monitor-16] [INFO] [1718517252.075011103] [collision_monitor]: Configuring
1: [collision_monitor-16] [INFO] [1718517252.086319822] [collision_monitor]: [FootprintApproach]: Creating Polygon
1: [collision_monitor-16] [INFO] [1718517252.086527664] [collision_monitor]: [FootprintApproach]: Polygon points are not defined. Using dynamic subscription instead.
1: [collision_monitor-16] [INFO] [1718517252.088081372] [collision_monitor]: [FootprintApproach]: Making footprint subscriber on /local_costmap/published_footprint topic
1: [collision_monitor-16] [INFO] [1718517252.090713349] [collision_monitor]: [scan]: Creating Scan
1: [lifecycle_manager-18] [INFO] [1718517252.115918532] [lifecycle_manager_navigation]: Configuring bt_navigator
1: [bt_navigator-13] [INFO] [1718517252.116810084] [bt_navigator]: Configuring
1: [bt_navigator-13] [INFO] [1718517252.129360493] [bt_navigator]: Creating navigator id navigate_to_pose of type nav2_bt_navigator::NavigateToPoseNavigator
1: [bt_navigator-13] [INFO] [1718517252.243664377] [bt_navigator]: Creating navigator id navigate_through_poses of type nav2_bt_navigator::NavigateThroughPosesNavigator
1: [lifecycle_manager-18] [INFO] [1718517252.288469786] [lifecycle_manager_navigation]: Configuring waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517252.288712972] [waypoint_follower]: Configuring
1: [waypoint_follower-14] [INFO] [1718517252.363161082] [waypoint_follower]: Created waypoint_task_executor : wait_at_waypoint of type nav2_waypoint_follower::WaitAtWaypoint
1: [lifecycle_manager-18] [INFO] [1718517252.364060081] [lifecycle_manager_navigation]: Configuring docking_server
1: [opennav_docking-17] [INFO] [1718517252.364327652] [docking_server]: Configuring docking_server
1: [opennav_docking-17] [INFO] [1718517252.364420715] [docking_server]: Controller frequency set to 50.0000Hz
1: [opennav_docking-17] [INFO] [1718517252.408881946] [docking_server]: Created charging dock plugin simple_charging_dock of type opennav_docking::SimpleChargingDock
1: [opennav_docking-17] [INFO] [1718517252.427838453] [docking_server]: Loading docks from parameter file.
1: [opennav_docking-17] [INFO] [1718517252.428648403] [docking_server]: Docking Server has 1 dock types and 1 dock instances available.
1: [lifecycle_manager-18] [INFO] [1718517252.432728857] [lifecycle_manager_navigation]: Activating controller_server
1: [controller_server-9] [INFO] [1718517252.432979532] [controller_server]: Activating
1: [controller_server-9] [INFO] [1718517252.433010417] [local_costmap.local_costmap]: Activating
1: [controller_server-9] [INFO] [1718517252.433017956] [local_costmap.local_costmap]: Checking transform
1: [controller_server-9] [INFO] [1718517252.433051888] [local_costmap.local_costmap]: Timed out waiting for transform from base_link to odom to become available, tf error: Invalid frame ID "odom" passed to canTransform argument target_frame - frame does not exist
1: [ruby $(which gz) sim-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="imu_link"]/sensor[@name="tb3_imu"]/gz_frame_id:/opt/overlay_ws/install/nav2_minimal_tb3_sim/share/nav2_minimal_tb3_sim/urdf/gz_waffle.sdf:L51]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
1: [ruby $(which gz) sim-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="base_scan"]/sensor[@name="hls_lfcd_lds"]/gz_frame_id:/opt/overlay_ws/install/nav2_minimal_tb3_sim/share/nav2_minimal_tb3_sim/urdf/gz_waffle.sdf:L140]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
1: [ruby $(which gz) sim-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="camera_link"]/sensor[@name="intel_realsense_r200_depth"]/gz_frame_id:/opt/overlay_ws/install/nav2_minimal_tb3_sim/share/nav2_minimal_tb3_sim/urdf/gz_waffle.sdf:L380]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
1: [controller_server-9] [INFO] [1718517252.933744942] [local_costmap.local_costmap]: Timed out waiting for transform from base_link to odom to become available, tf error: Invalid frame ID "odom" passed to canTransform argument target_frame - frame does not exist
1: [ruby $(which gz) sim-1] libEGL warning: egl: failed to create dri2 screen
1: [ruby $(which gz) sim-1] libEGL warning: egl: failed to create dri2 screen
1: [ruby $(which gz) sim-1] libEGL warning: egl: failed to create dri2 screen
1: [controller_server-9] [INFO] [1718517253.433201583] [local_costmap.local_costmap]: start
1: [amcl-7] [INFO] [1718517253.542547547] [amcl]: createLaserObject
1: [controller_server-9] [INFO] [1718517253.684330833] [controller_server]: Activating controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517253.684383808] [controller_server]: Creating bond (controller_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517253.790041506] [lifecycle_manager_navigation]: Server controller_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517253.790088693] [lifecycle_manager_navigation]: Activating smoother_server
1: [smoother_server-10] [INFO] [1718517253.790497257] [smoother_server]: Activating
1: [smoother_server-10] [INFO] [1718517253.790542229] [smoother_server]: Creating bond (smoother_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517253.896422979] [lifecycle_manager_navigation]: Server smoother_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517253.896460862] [lifecycle_manager_navigation]: Activating planner_server
1: [planner_server-11] [INFO] [1718517253.896734478] [planner_server]: Activating
1: [planner_server-11] [INFO] [1718517253.896763523] [global_costmap.global_costmap]: Activating
1: [planner_server-11] [INFO] [1718517253.896770967] [global_costmap.global_costmap]: Checking transform
1: [planner_server-11] [INFO] [1718517253.896802222] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [INFO] [1718517254.354670135] [amcl]: Message Filter dropping message: frame 'base_scan' at time 0.002 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
1: [planner_server-11] [INFO] [1718517254.396857359] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517254.896848453] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517255.396854284] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517255.411193357] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517255.896850357] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517256.397512369] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517256.896889658] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517257.396849577] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517257.542597201] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517257.896849265] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517258.396848149] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517258.896848542] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517259.396827528] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517259.733115472] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517259.896848629] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517260.396848313] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517260.896847129] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517261.401747381] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [tester_node-19] [INFO] [1718517261.682187638] [nav2_tester]: Waiting for amcl to become active
1: [tester_node-19] [INFO] [1718517261.687077580] [nav2_tester]: Getting amcl state...
1: [tester_node-19] [INFO] [1718517261.688157835] [nav2_tester]: Result of get_state: active
1: [amcl-7] [WARN] [1718517261.844321048] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517261.896851183] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517262.396851075] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517262.896880521] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517263.396849789] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517263.896878096] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517263.939236720] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517264.396853276] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517264.897309906] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517265.396852036] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517265.896864114] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517266.271063377] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517266.396851378] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [tester_node-19] [INFO] [1718517266.688735603] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517266.689222627] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517266.689438206] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517266.689519234] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 12.619000 but the latest data is at time 12.614000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517266.689535774] [amcl]: Setting pose (12.619000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517266.689697370] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517266.690168127] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517266.690611376] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517266.690723081] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517266.690768812] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 12.620000 but the latest data is at time 12.614000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517266.690782909] [amcl]: Setting pose (12.620000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517266.690992082] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517266.691442982] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517266.691780186] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517266.691882645] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517266.691918441] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 12.621000 but the latest data is at time 12.614000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517266.691928223] [amcl]: Setting pose (12.621000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517266.692219736] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517266.692618033] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517266.692957232] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517266.693249825] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517266.693290749] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 12.623000 but the latest data is at time 12.614000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517266.693303475] [amcl]: Setting pose (12.623000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517266.693403308] [nav2_tester]: Waiting for amcl_pose to be received
1: [planner_server-11] [INFO] [1718517266.896849323] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [tester_node-19] [INFO] [1718517266.909517548] [nav2_tester]: Received amcl_pose
1: [tester_node-19] [INFO] [1718517266.909946628] [nav2_tester]: Waiting for bt_navigator to become active
1: [tester_node-19] [INFO] [1718517266.911430286] [nav2_tester]: Getting bt_navigator state...
1: [tester_node-19] [INFO] [1718517266.916120702] [nav2_tester]: Result of get_state: inactive
1: [planner_server-11] [INFO] [1718517267.396894566] [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 13.260000 but the earliest data is at time 13.800000, when looking up transform from frame [base_link] to frame [map]
1: [planner_server-11] [INFO] [1718517267.896878681] [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 13.668000 but the earliest data is at time 13.800000, when looking up transform from frame [base_link] to frame [map]
1: [planner_server-11] [INFO] [1718517268.396941130] [global_costmap.global_costmap]: start
1: [planner_server-11] [INFO] [1718517269.448178988] [planner_server]: Activating plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517269.449458013] [planner_server]: Creating bond (planner_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517269.554512291] [lifecycle_manager_navigation]: Server planner_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517269.554570411] [lifecycle_manager_navigation]: Activating behavior_server
1: [behavior_server-12] [INFO] [1718517269.555040174] [behavior_server]: Activating
1: [behavior_server-12] [INFO] [1718517269.555078570] [behavior_server]: Activating spin
1: [behavior_server-12] [INFO] [1718517269.555098496] [behavior_server]: Activating backup
1: [behavior_server-12] [INFO] [1718517269.555110601] [behavior_server]: Activating drive_on_heading
1: [behavior_server-12] [INFO] [1718517269.555124757] [behavior_server]: Activating assisted_teleop
1: [behavior_server-12] [INFO] [1718517269.555136512] [behavior_server]: Activating wait
1: [behavior_server-12] [INFO] [1718517269.555154912] [behavior_server]: Creating bond (behavior_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517269.665607185] [lifecycle_manager_navigation]: Server behavior_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517269.665670800] [lifecycle_manager_navigation]: Activating velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517269.666002431] [velocity_smoother]: Activating
1: [velocity_smoother-15] [INFO] [1718517269.666066416] [velocity_smoother]: Creating bond (velocity_smoother) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517269.771288367] [lifecycle_manager_navigation]: Server velocity_smoother connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517269.771323387] [lifecycle_manager_navigation]: Activating collision_monitor
1: [collision_monitor-16] [INFO] [1718517269.771625906] [collision_monitor]: Activating
1: [collision_monitor-16] [INFO] [1718517269.771658914] [collision_monitor]: Creating bond (collision_monitor) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517269.880083487] [lifecycle_manager_navigation]: Server collision_monitor connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517269.880127199] [lifecycle_manager_navigation]: Activating bt_navigator
1: [bt_navigator-13] [INFO] [1718517269.880455869] [bt_navigator]: Activating
1: [bt_navigator-13] [INFO] [1718517269.985275096] [bt_navigator]: Creating bond (bt_navigator) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517270.093934695] [lifecycle_manager_navigation]: Server bt_navigator connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517270.093969992] [lifecycle_manager_navigation]: Activating waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517270.095566500] [waypoint_follower]: Activating
1: [waypoint_follower-14] [INFO] [1718517270.095629336] [waypoint_follower]: Creating bond (waypoint_follower) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517270.208818092] [lifecycle_manager_navigation]: Server waypoint_follower connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517270.208850566] [lifecycle_manager_navigation]: Activating docking_server
1: [opennav_docking-17] [INFO] [1718517270.209182692] [docking_server]: Activating docking_server
1: [opennav_docking-17] [INFO] [1718517270.224725772] [docking_server]: Creating bond (docking_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517270.334991656] [lifecycle_manager_navigation]: Server docking_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517270.335074542] [lifecycle_manager_navigation]: Managed nodes are active
1: [lifecycle_manager-18] [INFO] [1718517270.335089951] [lifecycle_manager_navigation]: Creating bond timer...
1: [tester_node-19] [INFO] [1718517271.917450391] [nav2_tester]: Getting bt_navigator state...
1: [tester_node-19] [INFO] [1718517271.918860008] [nav2_tester]: Result of get_state: active
1: [tester_node-19] [INFO] [1718517276.919354935] [nav2_tester]: Waiting for 'NavigateToPose' action server
1: [tester_node-19] [INFO] [1718517276.920201495] [nav2_tester]: Sending goal request...
1: [bt_navigator-13] [INFO] [1718517276.921149849] [bt_navigator]: Begin navigating from current location (-2.00, -0.50) to (0.00, 2.00)
1: [tester_node-19] [INFO] [1718517276.921630436] [nav2_tester]: Goal accepted
1: [tester_node-19] [INFO] [1718517276.922115097] [nav2_tester]: Waiting for 'NavigateToPose' action to complete
1: [controller_server-9] [INFO] [1718517276.942199847] [controller_server]: Received a goal, begin computing control effort.
1: [controller_server-9] [WARN] [1718517276.942276810] [controller_server]: No goal checker was specified in parameter 'current_goal_checker'. Server will use only plugin loaded general_goal_checker . This warning will appear once.
1: [controller_server-9] [WARN] [1718517276.942293249] [controller_server]: No progress checker was specified in parameter 'current_progress_checker'. Server will use only plugin loaded progress_checker . This warning will appear once.
1: [parameter_bridge-2] [INFO] [1718517276.976888404] [ros_gz_bridge]: Passing message from ROS geometry_msgs/msg/Twist to Gazebo gz.msgs.Twist (showing msg only once per type)
1: [bt_navigator-13] [WARN] [1718517276.995390955] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517277.561675501] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517277.728269022] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517277.993079459] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517278.174076403] [nav2_tester]: Received amcl_pose
1: [tester_node-19] [INFO] [1718517278.632524504] [nav2_tester]: Received amcl_pose
1: [tester_node-19] [INFO] [1718517279.026059968] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517279.042420865] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517279.185471075] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517279.301893707] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517279.502075288] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517279.823365342] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517280.042403629] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517280.909608398] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517281.093748076] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517281.420919567] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.421457233] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.441917818] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.462899211] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.502354615] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.903829691] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517281.963473548] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517282.092887811] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517282.124671648] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517283.092403208] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517283.221869631] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517283.277891461] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517283.785609722] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517283.801950848] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517284.142438081] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517284.396915292] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517285.092960960] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517285.142410778] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517285.294413361] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517285.599868293] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517286.192405747] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517286.283523784] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517286.377035084] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517286.404714043] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517286.562313539] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517286.829970525] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517286.835636223] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517287.193838801] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517287.399726620] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517287.441898324] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517287.455634194] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517287.474775659] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517287.505304214] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517287.725893464] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517287.759391273] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517288.130883076] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517288.242404775] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517288.380099068] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517288.870778323] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517289.242401780] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517289.611475913] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517289.729873163] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517289.751104813] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517289.790799441] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517289.962162713] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517290.050816801] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517290.070296010] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517290.292403875] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517290.361216500] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517290.392665998] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517290.621221926] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517291.292401956] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517292.002026545] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517292.292406783] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517292.629903642] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517293.214053746] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517293.272635872] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517293.342403346] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517294.014034626] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517294.082768555] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517294.132786411] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517294.207681255] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517294.342855577] [controller_server]: Passing new path to controller.
1: [tester_node-19] [INFO] [1718517294.649634574] [nav2_tester]: Received amcl_pose
1: [controller_server-9] [INFO] [1718517295.247364643] [controller_server]: Reached the goal!
1: [bt_navigator-13] [INFO] [1718517295.273669779] [bt_navigator]: Goal succeeded
1: [tester_node-19] [INFO] [1718517295.314140722] [nav2_tester]: Goal succeeded!
1: [tester_node-19] [INFO] [1718517295.314584272] [nav2_tester]: Setting goal pose
1: [tester_node-19] [INFO] [1718517295.315131281] [nav2_tester]: Waiting 60 seconds for robot to reach goal
1: [tester_node-19] [INFO] [1718517295.315696966] [nav2_tester]: Distance from goal is: 0.28066272342504783
1: [tester_node-19] [INFO] [1718517295.316098096] [nav2_tester]: *** GOAL REACHED ***
1: [tester_node-19] [INFO] [1718517295.316482497] [nav2_tester]: Test PASSED
1: [tester_node-19] [INFO] [1718517295.316864135] [nav2_tester]: Shutting down
1: [bt_navigator-13] [INFO] [1718517295.318192176] [bt_navigator]: Begin navigating from current location (-0.20, 1.92) to (0.00, 2.00)
1: [bt_navigator-13] [WARN] [1718517295.330326521] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517295.341785077] [controller_server]: Received a goal, begin computing control effort.
1: [controller_server-9] [INFO] [1718517295.342048404] [controller_server]: Reached the goal!
1: [tester_node-19] [INFO] [1718517295.345769977] [nav2_tester]: Shutting down navigation lifecycle manager...
1: [bt_navigator-13] [WARN] [1718517295.347591282] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [INFO] [1718517295.348677898] [bt_navigator]: Goal succeeded
1: [lifecycle_manager-18] [INFO] [1718517295.347719211] [lifecycle_manager_navigation]: Terminating bond timer...
1: [lifecycle_manager-18] [INFO] [1718517295.347747688] [lifecycle_manager_navigation]: Shutting down managed nodes...
1: [lifecycle_manager-18] [INFO] [1718517295.347754954] [lifecycle_manager_navigation]: Deactivate, cleanup, and shutdown nodes
1: [lifecycle_manager-18] [INFO] [1718517295.347761110] [lifecycle_manager_navigation]: Deactivating docking_server
1: [opennav_docking-17] [INFO] [1718517295.349241335] [docking_server]: Deactivating docking_server
1: [tester_node-19] [INFO] [1718517295.373955795] [nav2_tester]: Received amcl_pose
1: [opennav_docking-17] [INFO] [1718517295.385675913] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517295.503133272] [lifecycle_manager_navigation]: Deactivating waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517295.503457175] [waypoint_follower]: Deactivating
1: [waypoint_follower-14] [INFO] [1718517295.503503268] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517295.616011688] [lifecycle_manager_navigation]: Deactivating bt_navigator
1: [bt_navigator-13] [INFO] [1718517295.616355905] [bt_navigator]: Deactivating
1: [bt_navigator-13] [INFO] [1718517295.616434010] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517295.729509475] [lifecycle_manager_navigation]: Deactivating collision_monitor
1: [collision_monitor-16] [INFO] [1718517295.736673143] [collision_monitor]: Deactivating
1: [collision_monitor-16] [INFO] [1718517295.736714211] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517295.848586573] [lifecycle_manager_navigation]: Deactivating velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517295.849291293] [velocity_smoother]: Deactivating
1: [velocity_smoother-15] [INFO] [1718517295.849343933] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517295.961945622] [lifecycle_manager_navigation]: Deactivating behavior_server
1: [behavior_server-12] [INFO] [1718517295.962219256] [behavior_server]: Deactivating
1: [behavior_server-12] [INFO] [1718517295.962290671] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517296.074685070] [lifecycle_manager_navigation]: Deactivating planner_server
1: [planner_server-11] [INFO] [1718517296.075199076] [planner_server]: Deactivating
1: [planner_server-11] [INFO] [1718517296.075251320] [global_costmap.global_costmap]: Deactivating
1: [planner_server-11] [INFO] [1718517296.397144714] [planner_server]: Deactivating plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517296.397179440] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517296.509135268] [lifecycle_manager_navigation]: Deactivating smoother_server
1: [smoother_server-10] [INFO] [1718517296.509443521] [smoother_server]: Deactivating
1: [smoother_server-10] [INFO] [1718517296.509476663] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517296.621690476] [lifecycle_manager_navigation]: Deactivating controller_server
1: [controller_server-9] [INFO] [1718517296.622298374] [controller_server]: Deactivating
1: [controller_server-9] [INFO] [1718517296.622353951] [controller_server]: Deactivating controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517296.622389785] [local_costmap.local_costmap]: Deactivating
1: [controller_server-9] [INFO] [1718517296.634006763] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517296.745747733] [lifecycle_manager_navigation]: Cleaning up docking_server
1: [opennav_docking-17] [INFO] [1718517296.746329769] [docking_server]: Cleaning up docking_server
1: [lifecycle_manager-18] [INFO] [1718517296.759818389] [lifecycle_manager_navigation]: Cleaning up waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517296.760092117] [waypoint_follower]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517296.785058417] [lifecycle_manager_navigation]: Cleaning up bt_navigator
1: [bt_navigator-13] [INFO] [1718517296.789983325] [bt_navigator]: Cleaning up
1: [bt_navigator-13] [INFO] [1718517296.929438848] [bt_navigator]: Completed Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517296.940435874] [lifecycle_manager_navigation]: Cleaning up collision_monitor
1: [collision_monitor-16] [INFO] [1718517296.940727287] [collision_monitor]: Cleaning up
1: [collision_monitor-16] [INFO] [1718517296.940757981] [collision_monitor]: [FootprintApproach]: Destroying Polygon
1: [collision_monitor-16] [INFO] [1718517296.940769438] [collision_monitor]: [scan]: Destroying Scan
1: [lifecycle_manager-18] [INFO] [1718517296.953707435] [lifecycle_manager_navigation]: Cleaning up velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517296.954135404] [velocity_smoother]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517296.955026712] [lifecycle_manager_navigation]: Cleaning up behavior_server
1: [behavior_server-12] [INFO] [1718517296.956560864] [behavior_server]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517297.096843434] [lifecycle_manager_navigation]: Cleaning up planner_server
1: [planner_server-11] [INFO] [1718517297.098220124] [planner_server]: Cleaning up
1: [planner_server-11] [INFO] [1718517297.118251407] [global_costmap.global_costmap]: Cleaning up
1: [planner_server-11] [INFO] [1718517297.130399049] [planner_server]: Cleaning up plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517297.130457036] [planner_server]: Destroying plugin GridBased of type NavfnPlanner
1: [lifecycle_manager-18] [INFO] [1718517297.150959938] [lifecycle_manager_navigation]: Cleaning up smoother_server
1: [smoother_server-10] [INFO] [1718517297.151212471] [smoother_server]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517297.173786186] [lifecycle_manager_navigation]: Cleaning up controller_server
1: [controller_server-9] [INFO] [1718517297.174095820] [controller_server]: Cleaning up
1: [controller_server-9] [INFO] [1718517297.174120713] [controller_server]: Cleaning up controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517297.174183222] [local_costmap.local_costmap]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517297.218257873] [lifecycle_manager_navigation]: Shutting down docking_server
1: [opennav_docking-17] [INFO] [1718517297.220318806] [docking_server]: Shutting down docking_server
1: [lifecycle_manager-18] [INFO] [1718517297.220644149] [lifecycle_manager_navigation]: Shutting down waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517297.220833039] [waypoint_follower]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.222494205] [lifecycle_manager_navigation]: Shutting down bt_navigator
1: [bt_navigator-13] [INFO] [1718517297.232477762] [bt_navigator]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.236672616] [lifecycle_manager_navigation]: Shutting down collision_monitor
1: [collision_monitor-16] [INFO] [1718517297.236895879] [collision_monitor]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.237160138] [lifecycle_manager_navigation]: Shutting down velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517297.237309127] [velocity_smoother]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.237550409] [lifecycle_manager_navigation]: Shutting down behavior_server
1: [behavior_server-12] [INFO] [1718517297.238097589] [behavior_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.238428122] [lifecycle_manager_navigation]: Shutting down planner_server
1: [planner_server-11] [INFO] [1718517297.239276227] [planner_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.239862028] [lifecycle_manager_navigation]: Shutting down smoother_server
1: [smoother_server-10] [INFO] [1718517297.240278690] [smoother_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.240676163] [lifecycle_manager_navigation]: Shutting down controller_server
1: [controller_server-9] [INFO] [1718517297.242591351] [controller_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517297.242989825] [lifecycle_manager_navigation]: Destroying lifecycle service clients
1: [lifecycle_manager-18] [INFO] [1718517297.272234211] [lifecycle_manager_navigation]: Managed nodes have been shut down
1: [tester_node-19] [INFO] [1718517297.325374284] [nav2_tester]: Shutting down navigation lifecycle manager complete.
1: [tester_node-19] [INFO] [1718517297.334402240] [nav2_tester]: Shutting down localization lifecycle manager...
1: [lifecycle_manager-8] [INFO] [1718517297.337804368] [lifecycle_manager_localization]: Terminating bond timer...
1: [lifecycle_manager-8] [INFO] [1718517297.337853194] [lifecycle_manager_localization]: Shutting down managed nodes...
1: [lifecycle_manager-8] [INFO] [1718517297.337864448] [lifecycle_manager_localization]: Deactivate, cleanup, and shutdown nodes
1: [lifecycle_manager-8] [INFO] [1718517297.337872437] [lifecycle_manager_localization]: Deactivating amcl
1: [amcl-7] [INFO] [1718517297.346004737] [amcl]: Deactivating
1: [amcl-7] [INFO] [1718517297.346048970] [amcl]: Destroying bond (amcl) to lifecycle manager.
1: [lifecycle_manager-8] [INFO] [1718517297.468123181] [lifecycle_manager_localization]: Deactivating map_server
1: [map_server-6] [INFO] [1718517297.473788434] [map_server]: Deactivating
1: [map_server-6] [INFO] [1718517297.473820994] [map_server]: Destroying bond (map_server) to lifecycle manager.
1: [lifecycle_manager-8] [INFO] [1718517297.589979998] [lifecycle_manager_localization]: Cleaning up amcl
1: [amcl-7] [INFO] [1718517297.590323121] [amcl]: Cleaning up
1: [lifecycle_manager-8] [INFO] [1718517297.622032189] [lifecycle_manager_localization]: Cleaning up map_server
1: [map_server-6] [INFO] [1718517297.624471806] [map_server]: Cleaning up
1: [lifecycle_manager-8] [INFO] [1718517297.630127831] [lifecycle_manager_localization]: Shutting down amcl
1: [amcl-7] [INFO] [1718517297.630979763] [amcl]: Shutting down
1: [lifecycle_manager-8] [INFO] [1718517297.632394518] [lifecycle_manager_localization]: Shutting down map_server
1: [map_server-6] [INFO] [1718517297.633034215] [map_server]: Shutting down
1: [lifecycle_manager-8] [INFO] [1718517297.633375205] [lifecycle_manager_localization]: Destroying lifecycle service clients
1: [lifecycle_manager-8] [INFO] [1718517297.635187964] [lifecycle_manager_localization]: Managed nodes have been shut down
1: [tester_node-19] [INFO] [1718517297.657658236] [nav2_tester]: Shutting down localization lifecycle manager complete
1: [tester_node-19] [INFO] [1718517297.658733243] [nav2_tester]: Done Shutting Down.
1: [tester_node-19] [INFO] [1718517297.659556457] [nav2_tester]: Exiting passed
1: [INFO] [tester_node-19]: process has finished cleanly [pid 748]
1: [INFO] [lifecycle_manager-18]: sending signal 'SIGINT' to process[lifecycle_manager-18]
1: [INFO] [opennav_docking-17]: sending signal 'SIGINT' to process[opennav_docking-17]
1: [INFO] [collision_monitor-16]: sending signal 'SIGINT' to process[collision_monitor-16]
1: [INFO] [velocity_smoother-15]: sending signal 'SIGINT' to process[velocity_smoother-15]
1: [INFO] [waypoint_follower-14]: sending signal 'SIGINT' to process[waypoint_follower-14]
1: [INFO] [bt_navigator-13]: sending signal 'SIGINT' to process[bt_navigator-13]
1: [INFO] [behavior_server-12]: sending signal 'SIGINT' to process[behavior_server-12]
1: [INFO] [planner_server-11]: sending signal 'SIGINT' to process[planner_server-11]
1: [INFO] [smoother_server-10]: sending signal 'SIGINT' to process[smoother_server-10]
1: [INFO] [controller_server-9]: sending signal 'SIGINT' to process[controller_server-9]
1: [INFO] [lifecycle_manager-8]: sending signal 'SIGINT' to process[lifecycle_manager-8]
1: [INFO] [amcl-7]: sending signal 'SIGINT' to process[amcl-7]
1: [INFO] [map_server-6]: sending signal 'SIGINT' to process[map_server-6]
1: [INFO] [static_transform_publisher-5]: sending signal 'SIGINT' to process[static_transform_publisher-5]
1: [INFO] [static_transform_publisher-4]: sending signal 'SIGINT' to process[static_transform_publisher-4]
1: [INFO] [parameter_bridge-2]: sending signal 'SIGINT' to process[parameter_bridge-2]
1: [INFO] [ruby $(which gz) sim-1]: sending signal 'SIGINT' to process[ruby $(which gz) sim-1]
1: [lifecycle_manager-18] [INFO] [1718517297.959215756] [rclcpp]: signal_handler(signum=2)
1: [lifecycle_manager-18] [INFO] [1718517297.959300742] [lifecycle_manager_navigation]: Running Nav2 LifecycleManager rcl preshutdown (lifecycle_manager_navigation)
1: [lifecycle_manager-18] [INFO] [1718517297.960174091] [lifecycle_manager_navigation]: Destroying lifecycle_manager_navigation
1: [opennav_docking-17] [INFO] [1718517297.962516475] [rclcpp]: signal_handler(signum=2)
1: [opennav_docking-17] [INFO] [1718517297.962583764] [docking_server]: Running Nav2 LifecycleNode rcl preshutdown (docking_server)
1: [opennav_docking-17] [INFO] [1718517297.962627791] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
1: [opennav_docking-17] [INFO] [1718517297.963364114] [docking_server]: Destroying
1: [collision_monitor-16] [INFO] [1718517297.966320481] [rclcpp]: signal_handler(signum=2)
1: [collision_monitor-16] [INFO] [1718517297.966940296] [collision_monitor]: Running Nav2 LifecycleNode rcl preshutdown (collision_monitor)
1: [collision_monitor-16] [INFO] [1718517297.966991357] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
1: [collision_monitor-16] [INFO] [1718517297.968225895] [collision_monitor]: Destroying
1: [velocity_smoother-15] [INFO] [1718517297.969171194] [rclcpp]: signal_handler(signum=2)
1: [velocity_smoother-15] [INFO] [1718517297.969294299] [velocity_smoother]: Running Nav2 LifecycleNode rcl preshutdown (velocity_smoother)
1: [velocity_smoother-15] [INFO] [1718517297.969337143] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
1: [velocity_smoother-15] [INFO] [1718517297.969970734] [velocity_smoother]: Destroying
1: [waypoint_follower-14] [INFO] [1718517297.972580324] [rclcpp]: signal_handler(signum=2)
1: [waypoint_follower-14] [INFO] [1718517297.972681770] [waypoint_follower]: Running Nav2 LifecycleNode rcl preshutdown (waypoint_follower)
1: [waypoint_follower-14] [INFO] [1718517297.972732447] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
1: [waypoint_follower-14] [INFO] [1718517297.973581663] [waypoint_follower]: Destroying
1: [bt_navigator-13] [INFO] [1718517297.976663488] [rclcpp]: signal_handler(signum=2)
1: [bt_navigator-13] [INFO] [1718517297.976729424] [bt_navigator]: Running Nav2 LifecycleNode rcl preshutdown (bt_navigator)
1: [bt_navigator-13] [INFO] [1718517297.976775049] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
1: [behavior_server-12] [INFO] [1718517297.983058496] [rclcpp]: signal_handler(signum=2)
1: [behavior_server-12] [INFO] [1718517297.983188752] [behavior_server]: Running Nav2 LifecycleNode rcl preshutdown (behavior_server)
1: [behavior_server-12] [INFO] [1718517297.983268074] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
1: [bt_navigator-13] [INFO] [1718517297.983651383] [bt_navigator]: Destroying
1: [planner_server-11] [INFO] [1718517297.989957106] [rclcpp]: signal_handler(signum=2)
1: [planner_server-11] [INFO] [1718517297.990020898] [planner_server]: Running Nav2 LifecycleNode rcl preshutdown (planner_server)
1: [planner_server-11] [INFO] [1718517297.990054544] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
1: [planner_server-11] [INFO] [1718517297.992610067] [global_costmap.global_costmap]: Destroying
1: [planner_server-11] [ERROR] [1718517297.992636137] [global_costmap.global_costmap]: Unable to start transition 5 from current state shuttingdown: Could not publish transition: publisher's context is invalid, at ./src/rcl/publisher.c:423, at ./src/rcl_lifecycle.c:368
1: [planner_server-11] [WARN] [1718517297.992642579] [rclcpp_lifecycle]: Shutdown error in destruction of LifecycleNode: final state(unconfigured)
1: [behavior_server-12] [INFO] [1718517297.994198337] [behavior_server]: Destroying
1: [smoother_server-10] [INFO] [1718517298.015409263] [rclcpp]: signal_handler(signum=2)
1: [smoother_server-10] [INFO] [1718517298.015467722] [smoother_server]: Running Nav2 LifecycleNode rcl preshutdown (smoother_server)
1: [smoother_server-10] [INFO] [1718517298.015504048] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
1: [controller_server-9] [INFO] [1718517298.017732769] [rclcpp]: signal_handler(signum=2)
1: [controller_server-9] [INFO] [1718517298.017822650] [controller_server]: Running Nav2 LifecycleNode rcl preshutdown (controller_server)
1: [controller_server-9] [INFO] [1718517298.017879169] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
1: [smoother_server-10] [INFO] [1718517298.018866129] [smoother_server]: Destroying
1: [lifecycle_manager-8] [INFO] [1718517298.021756337] [rclcpp]: signal_handler(signum=2)
1: [lifecycle_manager-8] [INFO] [1718517298.021902418] [lifecycle_manager_localization]: Running Nav2 LifecycleManager rcl preshutdown (lifecycle_manager_localization)
1: [controller_server-9] [INFO] [1718517298.026086424] [local_costmap.local_costmap]: Destroying
1: [controller_server-9] [ERROR] [1718517298.026118062] [local_costmap.local_costmap]: Unable to start transition 5 from current state shuttingdown: Could not publish transition: publisher's context is invalid, at ./src/rcl/publisher.c:423, at ./src/rcl_lifecycle.c:368
1: [controller_server-9] [WARN] [1718517298.026124802] [rclcpp_lifecycle]: Shutdown error in destruction of LifecycleNode: final state(unconfigured)
1: [controller_server-9] [INFO] [1718517298.036221770] [controller_server]: Destroying
1: [lifecycle_manager-8] [INFO] [1718517298.026249614] [lifecycle_manager_localization]: Destroying lifecycle_manager_localization
1: [planner_server-11] [INFO] [1718517298.041084307] [planner_server]: Destroying
1: [amcl-7] [INFO] [1718517298.041746392] [rclcpp]: signal_handler(signum=2)
1: [map_server-6] [INFO] [1718517298.044225458] [rclcpp]: signal_handler(signum=2)
1: [map_server-6] [INFO] [1718517298.044311726] [map_server]: Running Nav2 LifecycleNode rcl preshutdown (map_server)
1: [map_server-6] [INFO] [1718517298.044348181] [map_server]: Destroying bond (map_server) to lifecycle manager.
1: [map_server-6] [INFO] [1718517298.044718287] [map_server]: Destroying
1: [amcl-7] [INFO] [1718517298.048745108] [amcl]: Running Nav2 LifecycleNode rcl preshutdown (amcl)
1: [amcl-7] [INFO] [1718517298.048787727] [amcl]: Destroying bond (amcl) to lifecycle manager.
1: [amcl-7] [INFO] [1718517298.050518742] [amcl]: Destroying
1: [static_transform_publisher-5] [INFO] [1718517298.061749369] [rclcpp]: signal_handler(signum=2)
1: [static_transform_publisher-4] [INFO] [1718517298.066980666] [rclcpp]: signal_handler(signum=2)
1: [parameter_bridge-2] [INFO] [1718517298.072782117] [rclcpp]: signal_handler(signum=2)
1: [INFO] [lifecycle_manager-18]: process has finished cleanly [pid 723]
1: [INFO] [velocity_smoother-15]: process has finished cleanly [pid 702]
1: [INFO] [opennav_docking-17]: process has finished cleanly [pid 714]
1: [INFO] [behavior_server-12]: process has finished cleanly [pid 636]
1: [INFO] [waypoint_follower-14]: process has finished cleanly [pid 693]
1: [INFO] [smoother_server-10]: process has finished cleanly [pid 618]
1: [INFO] [collision_monitor-16]: process has finished cleanly [pid 711]
1: [INFO] [lifecycle_manager-8]: process has finished cleanly [pid 608]
1: [INFO] [map_server-6]: process has finished cleanly [pid 606]
1: [INFO] [amcl-7]: process has finished cleanly [pid 607]
1: [INFO] [controller_server-9]: process has finished cleanly [pid 609]
1: [INFO] [static_transform_publisher-5]: process has finished cleanly [pid 605]
1: [INFO] [parameter_bridge-2]: process has finished cleanly [pid 601]
1: [INFO] [static_transform_publisher-4]: process has finished cleanly [pid 604]
1: [INFO] [planner_server-11]: process has finished cleanly [pid 631]
1: [INFO] [bt_navigator-13]: process has finished cleanly [pid 664]
1: [ERROR] [ruby $(which gz) sim-1]: process[ruby $(which gz) sim-1] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
1: [INFO] [ruby $(which gz) sim-1]: sending signal 'SIGTERM' to process[ruby $(which gz) sim-1]
1: [ERROR] [ruby $(which gz) sim-1]: process has died [pid 599, exit code -15, cmd 'ruby $(which gz) sim -r -s /opt/overlay_ws/install/nav2_minimal_tb3_sim/share/nav2_minimal_tb3_sim/worlds/tb3_sandbox.sdf.xacro --force-version 8'].
1: [INFO] [launch]: process[ruby $(which gz) sim-1] was required: shutting down launched system
1: -- run_test.py: return code 0
1: -- run_test.py: generate result file '/opt/overlay_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml' with successful test
1/1 Test #1: test_bt_navigator ................   Passed   53.33 sec

The following tests passed:
    test_bt_navigator

100% tests passed, 0 tests failed out of 1

Total Test time (real) =  53.33 sec

When I run for the second time, the estimation of the robot pose goes awall and return a wrong value hence in some scenario the robot is not able to find a path to the goal.

root@stevedan:/opt/overlay_ws/build/nav2_system_tests/src/system# ctest -V -R test_bt_navigator
UpdateCTestConfiguration  from :/opt/overlay_ws/build/nav2_system_tests/src/system/DartConfiguration.tcl
UpdateCTestConfiguration  from :/opt/overlay_ws/build/nav2_system_tests/src/system/DartConfiguration.tcl
Test project /opt/overlay_ws/build/nav2_system_tests/src/system
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 1
    Start 1: test_bt_navigator

1: Test command: /usr/bin/python3 "-u" "/opt/ros/rolling/share/ament_cmake_test/cmake/run_test.py" "/opt/overlay_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=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system" "TEST_MAP=/opt/overlay_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml" "TEST_WORLD=/opt/overlay_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world" "GAZEBO_MODEL_PATH=/opt/overlay_ws/src/navigation2/nav2_system_tests/models" "BT_NAVIGATOR_XML=navigate_to_pose_w_replanning_and_recovery.xml" "TESTER=nav_to_pose_tester_node.py" "ASTAR=True" "CONTROLLER=nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController" "PLANNER=nav2_navfn_planner::NavfnPlanner" "--command" "/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py"
1: Working Directory: /opt/overlay_ws/build/nav2_system_tests/src/system
1: Test timeout computed to be: 180
1: -- run_test.py: extra environment variables:
1:  - ASTAR=True
1:  - BT_NAVIGATOR_XML=navigate_to_pose_w_replanning_and_recovery.xml
1:  - CONTROLLER=nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController
1:  - GAZEBO_MODEL_PATH=/opt/overlay_ws/src/navigation2/nav2_system_tests/models
1:  - PLANNER=nav2_navfn_planner::NavfnPlanner
1:  - TESTER=nav_to_pose_tester_node.py
1:  - TEST_DIR=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system
1:  - TEST_MAP=/opt/overlay_ws/src/navigation2/nav2_system_tests/maps/map_circular.yaml
1:  - TEST_WORLD=/opt/overlay_ws/src/navigation2/nav2_system_tests/worlds/turtlebot3_ros2_demo.world
1: -- run_test.py: invoking following command in '/opt/overlay_ws/build/nav2_system_tests/src/system':
1:  - /opt/overlay_ws/src/navigation2/nav2_system_tests/src/system/test_system_launch.py
1: [INFO] [launch]: All log files can be found below /root/.ros/log/2024-06-16-05-55-07-601116-stevedan-1058
1: [INFO] [launch]: Default logging verbosity is set to INFO
1: [INFO] [ruby $(which gz) sim-1]: process started with pid [1061]
1: [INFO] [parameter_bridge-2]: process started with pid [1062]
1: [INFO] [create-3]: process started with pid [1064]
1: [INFO] [static_transform_publisher-4]: process started with pid [1065]
1: [INFO] [static_transform_publisher-5]: process started with pid [1067]
1: [INFO] [map_server-6]: process started with pid [1068]
1: [INFO] [amcl-7]: process started with pid [1069]
1: [INFO] [lifecycle_manager-8]: process started with pid [1074]
1: [INFO] [controller_server-9]: process started with pid [1075]
1: [INFO] [smoother_server-10]: process started with pid [1078]
1: [INFO] [planner_server-11]: process started with pid [1079]
1: [INFO] [behavior_server-12]: process started with pid [1080]
1: [INFO] [bt_navigator-13]: process started with pid [1081]
1: [INFO] [waypoint_follower-14]: process started with pid [1138]
1: [INFO] [velocity_smoother-15]: process started with pid [1156]
1: [INFO] [collision_monitor-16]: process started with pid [1162]
1: [INFO] [opennav_docking-17]: process started with pid [1166]
1: [INFO] [lifecycle_manager-18]: process started with pid [1179]
1: [INFO] [tester_node-19]: process started with pid [1204]
1: [create-3] [INFO] [1718517308.190857555] [ros_gz_sim]: Requesting list of world names.
1: [static_transform_publisher-4] [WARN] [1718517308.068524946] []: Old-style arguments are deprecated; see --help for new-style arguments
1: [static_transform_publisher-4] [INFO] [1718517308.094771035] [static_transform_publisher_76CNJsYlBWXxq0ww]: Spinning until stopped - publishing transform
1: [static_transform_publisher-4] translation: ('0.000000', '0.000000', '0.000000')
1: [static_transform_publisher-4] rotation: ('0.000000', '0.000000', '0.000000', '1.000000')
1: [static_transform_publisher-4] from 'base_footprint' to 'base_link'
1: [static_transform_publisher-5] [WARN] [1718517308.082501761] []: Old-style arguments are deprecated; see --help for new-style arguments
1: [static_transform_publisher-5] [INFO] [1718517308.199892895] [static_transform_publisher_A6u84JqH5SxHGYf6]: Spinning until stopped - publishing transform
1: [static_transform_publisher-5] translation: ('0.000000', '0.000000', '0.000000')
1: [static_transform_publisher-5] rotation: ('0.000000', '0.000000', '0.000000', '1.000000')
1: [static_transform_publisher-5] from 'base_link' to 'base_scan'
1: [bt_navigator-13] [INFO] [1718517308.262626477] [bt_navigator]: 
1: [bt_navigator-13]    bt_navigator lifecycle node launched. 
1: [bt_navigator-13]    Waiting on external lifecycle transitions to activate
1: [bt_navigator-13]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [bt_navigator-13] [INFO] [1718517308.275355197] [bt_navigator]: Creating
1: [amcl-7] [INFO] [1718517308.334181274] [amcl]: 
1: [amcl-7]     amcl lifecycle node launched. 
1: [amcl-7]     Waiting on external lifecycle transitions to activate
1: [amcl-7]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [amcl-7] [INFO] [1718517308.339377584] [amcl]: Creating
1: [lifecycle_manager-8] [INFO] [1718517308.359215610] [lifecycle_manager_localization]: Creating
1: [lifecycle_manager-8] [INFO] [1718517308.388205303] [lifecycle_manager_localization]: Creating and initializing lifecycle service clients
1: [create-3] [INFO] [1718517308.395196443] [ros_gz_sim]: Requested creation of entity.
1: [create-3] [INFO] [1718517308.395232321] [ros_gz_sim]: OK creation of entity.
1: [map_server-6] [INFO] [1718517308.443144297] [map_server]: 
1: [map_server-6]   map_server lifecycle node launched. 
1: [map_server-6]   Waiting on external lifecycle transitions to activate
1: [map_server-6]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [map_server-6] [INFO] [1718517308.443260618] [map_server]: Creating
1: [smoother_server-10] [INFO] [1718517308.477552351] [smoother_server]: 
1: [smoother_server-10]     smoother_server lifecycle node launched. 
1: [smoother_server-10]     Waiting on external lifecycle transitions to activate
1: [smoother_server-10]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [lifecycle_manager-8] [INFO] [1718517308.537190739] [lifecycle_manager_localization]: Starting managed nodes bringup...
1: [lifecycle_manager-8] [INFO] [1718517308.537236188] [lifecycle_manager_localization]: Configuring map_server
1: [INFO] [create-3]: process has finished cleanly [pid 1064]
1: [map_server-6] [INFO] [1718517308.543272146] [map_server]: Configuring
1: [map_server-6] [INFO] [map_io]: Loading yaml file: /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.yaml
1: [map_server-6] [DEBUG] [map_io]: resolution: 0.05
1: [map_server-6] [DEBUG] [map_io]: origin[0]: -10
1: [map_server-6] [DEBUG] [map_io]: origin[1]: -10
1: [map_server-6] [DEBUG] [map_io]: origin[2]: 0
1: [map_server-6] [DEBUG] [map_io]: free_thresh: 0.196
1: [map_server-6] [DEBUG] [map_io]: occupied_thresh: 0.65
1: [map_server-6] [DEBUG] [map_io]: mode: trinary
1: [map_server-6] [DEBUG] [map_io]: negate: 0
1: [map_server-6] [INFO] [map_io]: Loading image_file: /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.pgm
1: [opennav_docking-17] [INFO] [1718517308.570438334] [docking_server]: 
1: [opennav_docking-17]     docking_server lifecycle node launched. 
1: [opennav_docking-17]     Waiting on external lifecycle transitions to activate
1: [opennav_docking-17]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [opennav_docking-17] [INFO] [1718517308.570636528] [docking_server]: Creating docking_server
1: [lifecycle_manager-18] [INFO] [1718517308.608256522] [lifecycle_manager_navigation]: Creating
1: [smoother_server-10] [INFO] [1718517308.609727586] [smoother_server]: Creating smoother server
1: [lifecycle_manager-18] [INFO] [1718517308.615109359] [lifecycle_manager_navigation]: Creating and initializing lifecycle service clients
1: [controller_server-9] [INFO] [1718517308.655677703] [controller_server]: 
1: [controller_server-9]    controller_server lifecycle node launched. 
1: [controller_server-9]    Waiting on external lifecycle transitions to activate
1: [controller_server-9]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [map_server-6] [DEBUG] [map_io]: Read map /opt/overlay_ws/install/nav2_bringup/share/nav2_bringup/maps/tb3_sandbox.pgm: 384 X 384 map @ 0.05 m/cell
1: [behavior_server-12] [INFO] [1718517308.717420541] [behavior_server]: 
1: [behavior_server-12]     behavior_server lifecycle node launched. 
1: [behavior_server-12]     Waiting on external lifecycle transitions to activate
1: [behavior_server-12]     See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [velocity_smoother-15] [INFO] [1718517308.745952394] [velocity_smoother]: 
1: [velocity_smoother-15]   velocity_smoother lifecycle node launched. 
1: [velocity_smoother-15]   Waiting on external lifecycle transitions to activate
1: [velocity_smoother-15]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [controller_server-9] [INFO] [1718517308.755139603] [controller_server]: Creating controller server
1: [collision_monitor-16] [INFO] [1718517308.793645652] [collision_monitor]: 
1: [collision_monitor-16]   collision_monitor lifecycle node launched. 
1: [collision_monitor-16]   Waiting on external lifecycle transitions to activate
1: [collision_monitor-16]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [lifecycle_manager-8] [INFO] [1718517308.820585688] [lifecycle_manager_localization]: Configuring amcl
1: [waypoint_follower-14] [INFO] [1718517308.861948641] [waypoint_follower]: 
1: [waypoint_follower-14]   waypoint_follower lifecycle node launched. 
1: [waypoint_follower-14]   Waiting on external lifecycle transitions to activate
1: [waypoint_follower-14]   See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [waypoint_follower-14] [INFO] [1718517308.863480049] [waypoint_follower]: Creating
1: [planner_server-11] [INFO] [1718517308.876578970] [planner_server]: 
1: [planner_server-11]  planner_server lifecycle node launched. 
1: [planner_server-11]  Waiting on external lifecycle transitions to activate
1: [planner_server-11]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [planner_server-11] [INFO] [1718517308.894927180] [planner_server]: Creating
1: [controller_server-9] [INFO] [1718517308.975883837] [local_costmap.local_costmap]: 
1: [controller_server-9]    local_costmap lifecycle node launched. 
1: [controller_server-9]    Waiting on external lifecycle transitions to activate
1: [controller_server-9]    See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [controller_server-9] [INFO] [1718517308.978839583] [local_costmap.local_costmap]: Creating Costmap
1: [planner_server-11] [INFO] [1718517309.043252204] [global_costmap.global_costmap]: 
1: [planner_server-11]  global_costmap lifecycle node launched. 
1: [planner_server-11]  Waiting on external lifecycle transitions to activate
1: [planner_server-11]  See https://design.ros2.org/articles/node_lifecycle.html for more information.
1: [planner_server-11] [INFO] [1718517309.044364500] [global_costmap.global_costmap]: Creating Costmap
1: [parameter_bridge-2] [INFO] [1718517309.158786214] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/clock (gz.msgs.Clock) -> clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517309.163853928] [ros_gz_bridge]: Creating GZ->ROS Bridge: [joint_states (gz.msgs.Model) -> joint_states (sensor_msgs/msg/JointState)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517309.174415784] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/odom (gz.msgs.Odometry) -> odom (nav_msgs/msg/Odometry)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517309.208698863] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/tf (gz.msgs.Pose_V) -> tf (tf2_msgs/msg/TFMessage)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517309.243426118] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/imu (gz.msgs.IMU) -> imu (sensor_msgs/msg/Imu)] (Lazy 0)
1: [parameter_bridge-2] [INFO] [1718517309.270184799] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/scan (gz.msgs.LaserScan) -> scan (sensor_msgs/msg/LaserScan)] (Lazy 0)
1: [amcl-7] [INFO] [1718517309.272341240] [amcl]: Configuring
1: [amcl-7] [INFO] [1718517309.272422565] [amcl]: initTransforms
1: [amcl-7] [INFO] [1718517309.304338907] [amcl]: initPubSub
1: [lifecycle_manager-18] [INFO] [1718517309.321396917] [lifecycle_manager_navigation]: Starting managed nodes bringup...
1: [lifecycle_manager-18] [INFO] [1718517309.321439025] [lifecycle_manager_navigation]: Configuring controller_server
1: [controller_server-9] [INFO] [1718517309.322142137] [controller_server]: Configuring controller interface
1: [controller_server-9] [INFO] [1718517309.322162225] [controller_server]: getting progress checker plugins..
1: [controller_server-9] [INFO] [1718517309.322544828] [controller_server]: getting goal checker plugins..
1: [controller_server-9] [INFO] [1718517309.322639161] [controller_server]: Controller frequency set to 20.0000Hz
1: [controller_server-9] [INFO] [1718517309.322671662] [local_costmap.local_costmap]: Configuring
1: [parameter_bridge-2] [INFO] [1718517309.331897232] [ros_gz_bridge]: Creating ROS->GZ Bridge: [cmd_vel (geometry_msgs/msg/Twist) -> /cmd_vel (gz.msgs.Twist)] (Lazy 0)
1: [controller_server-9] [INFO] [1718517309.339675128] [local_costmap.local_costmap]: Using plugin "voxel_layer"
1: [amcl-7] [INFO] [1718517309.344642178] [amcl]: Subscribed to map topic.
1: [controller_server-9] [INFO] [1718517309.357477171] [local_costmap.local_costmap]: Subscribed to Topics: scan
1: [lifecycle_manager-8] [INFO] [1718517309.387240297] [lifecycle_manager_localization]: Activating map_server
1: [map_server-6] [INFO] [1718517309.390584480] [map_server]: Activating
1: [map_server-6] [INFO] [1718517309.391869517] [map_server]: Creating bond (map_server) to lifecycle manager.
1: [amcl-7] [INFO] [1718517309.394137027] [amcl]: Received a 384 X 384 map @ 0.050 m/pix
1: [controller_server-9] [INFO] [1718517309.403625607] [local_costmap.local_costmap]: Initialized plugin "voxel_layer"
1: [controller_server-9] [INFO] [1718517309.403656879] [local_costmap.local_costmap]: Using plugin "inflation_layer"
1: [controller_server-9] [INFO] [1718517309.404959135] [local_costmap.local_costmap]: Initialized plugin "inflation_layer"
1: [controller_server-9] [INFO] [1718517309.459252834] [controller_server]: Created progress_checker : progress_checker of type nav2_controller::SimpleProgressChecker
1: [controller_server-9] [INFO] [1718517309.459940884] [controller_server]: Controller Server has progress_checker  progress checkers available.
1: [controller_server-9] [INFO] [1718517309.460775050] [controller_server]: Created goal checker : general_goal_checker of type nav2_controller::SimpleGoalChecker
1: [controller_server-9] [INFO] [1718517309.461551648] [controller_server]: Controller Server has general_goal_checker  goal checkers available.
1: [controller_server-9] [INFO] [1718517309.467243710] [controller_server]: Created controller : FollowPath of type nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517309.491321920] [controller_server]: Controller Server has FollowPath  controllers available.
1: [lifecycle_manager-8] [INFO] [1718517309.506851999] [lifecycle_manager_localization]: Server map_server connected with bond.
1: [lifecycle_manager-8] [INFO] [1718517309.506891519] [lifecycle_manager_localization]: Activating amcl
1: [amcl-7] [INFO] [1718517309.507886650] [amcl]: Activating
1: [amcl-7] [INFO] [1718517309.507922220] [amcl]: Creating bond (amcl) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517309.531267367] [lifecycle_manager_navigation]: Configuring smoother_server
1: [smoother_server-10] [INFO] [1718517309.533884851] [smoother_server]: Configuring smoother server
1: [amcl-7] [INFO] [1718517309.557804715] [amcl]: createLaserObject
1: [smoother_server-10] [INFO] [1718517309.573029692] [smoother_server]: Created smoother : simple_smoother of type nav2_smoother::SimpleSmoother
1: [smoother_server-10] [INFO] [1718517309.580167273] [smoother_server]: Smoother Server has simple_smoother  smoothers available.
1: [lifecycle_manager-18] [INFO] [1718517309.614365977] [lifecycle_manager_navigation]: Configuring planner_server
1: [planner_server-11] [INFO] [1718517309.616251686] [planner_server]: Configuring
1: [planner_server-11] [INFO] [1718517309.616300819] [global_costmap.global_costmap]: Configuring
1: [lifecycle_manager-8] [INFO] [1718517309.617469795] [lifecycle_manager_localization]: Server amcl connected with bond.
1: [lifecycle_manager-8] [INFO] [1718517309.617516861] [lifecycle_manager_localization]: Managed nodes are active
1: [lifecycle_manager-8] [INFO] [1718517309.617530839] [lifecycle_manager_localization]: Creating bond timer...
1: [planner_server-11] [INFO] [1718517309.641147903] [global_costmap.global_costmap]: Using plugin "static_layer"
1: [planner_server-11] [INFO] [1718517309.654936892] [global_costmap.global_costmap]: Subscribing to the map topic (/map) with transient local durability
1: [planner_server-11] [INFO] [1718517309.659432863] [global_costmap.global_costmap]: Initialized plugin "static_layer"
1: [planner_server-11] [INFO] [1718517309.659461440] [global_costmap.global_costmap]: Using plugin "obstacle_layer"
1: [planner_server-11] [INFO] [1718517309.661517042] [global_costmap.global_costmap]: Subscribed to Topics: scan
1: [planner_server-11] [INFO] [1718517309.683400798] [global_costmap.global_costmap]: Initialized plugin "obstacle_layer"
1: [planner_server-11] [INFO] [1718517309.683442041] [global_costmap.global_costmap]: Using plugin "inflation_layer"
1: [planner_server-11] [INFO] [1718517309.686067658] [global_costmap.global_costmap]: Initialized plugin "inflation_layer"
1: [tester_node-19] [INFO] [1718517309.753419603] [nav2_tester]: Starting tester, robot going from -2.0, -0.5 to 0.0, 2.0.
1: [planner_server-11] [INFO] [1718517309.782226612] [global_costmap.global_costmap]: StaticLayer: Resizing costmap to 384 X 384 at 0.050000 m/pix
1: [planner_server-11] [INFO] [1718517309.782930723] [planner_server]: Created global planner plugin GridBased of type nav2_navfn_planner::NavfnPlanner
1: [planner_server-11] [INFO] [1718517309.783176739] [planner_server]: Configuring plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517309.784346064] [planner_server]: Planner Server has GridBased  planners available.
1: [lifecycle_manager-18] [INFO] [1718517309.839995727] [lifecycle_manager_navigation]: Configuring behavior_server
1: [behavior_server-12] [INFO] [1718517309.840459615] [behavior_server]: Configuring
1: [behavior_server-12] [INFO] [1718517309.857413186] [behavior_server]: Creating behavior plugin spin of type nav2_behaviors::Spin
1: [behavior_server-12] [INFO] [1718517309.860757543] [behavior_server]: Creating behavior plugin backup of type nav2_behaviors::BackUp
1: [behavior_server-12] [INFO] [1718517309.877309492] [behavior_server]: Creating behavior plugin drive_on_heading of type nav2_behaviors::DriveOnHeading
1: [behavior_server-12] [INFO] [1718517309.881313352] [behavior_server]: Creating behavior plugin assisted_teleop of type nav2_behaviors::AssistedTeleop
1: [behavior_server-12] [INFO] [1718517309.893052628] [behavior_server]: Creating behavior plugin wait of type nav2_behaviors::Wait
1: [behavior_server-12] [INFO] [1718517309.912218552] [behavior_server]: Configuring spin
1: [behavior_server-12] [INFO] [1718517309.939336970] [behavior_server]: Configuring backup
1: [behavior_server-12] [INFO] [1718517309.959864781] [behavior_server]: Configuring drive_on_heading
1: [behavior_server-12] [INFO] [1718517309.985236044] [behavior_server]: Configuring assisted_teleop
1: [behavior_server-12] [INFO] [1718517310.026868554] [behavior_server]: Configuring wait
1: [lifecycle_manager-18] [INFO] [1718517310.057798324] [lifecycle_manager_navigation]: Configuring velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517310.061860612] [velocity_smoother]: Configuring velocity smoother
1: [lifecycle_manager-18] [INFO] [1718517310.066056953] [lifecycle_manager_navigation]: Configuring collision_monitor
1: [collision_monitor-16] [INFO] [1718517310.069934363] [collision_monitor]: Configuring
1: [collision_monitor-16] [INFO] [1718517310.106229798] [collision_monitor]: [FootprintApproach]: Creating Polygon
1: [collision_monitor-16] [INFO] [1718517310.106673648] [collision_monitor]: [FootprintApproach]: Polygon points are not defined. Using dynamic subscription instead.
1: [collision_monitor-16] [INFO] [1718517310.108543818] [collision_monitor]: [FootprintApproach]: Making footprint subscriber on /local_costmap/published_footprint topic
1: [collision_monitor-16] [INFO] [1718517310.112884105] [collision_monitor]: [scan]: Creating Scan
1: [lifecycle_manager-18] [INFO] [1718517310.151916237] [lifecycle_manager_navigation]: Configuring bt_navigator
1: [bt_navigator-13] [INFO] [1718517310.153081300] [bt_navigator]: Configuring
1: [bt_navigator-13] [INFO] [1718517310.171858102] [bt_navigator]: Creating navigator id navigate_to_pose of type nav2_bt_navigator::NavigateToPoseNavigator
1: [bt_navigator-13] [INFO] [1718517310.360341931] [bt_navigator]: Creating navigator id navigate_through_poses of type nav2_bt_navigator::NavigateThroughPosesNavigator
1: [lifecycle_manager-18] [INFO] [1718517310.438189431] [lifecycle_manager_navigation]: Configuring waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517310.439233974] [waypoint_follower]: Configuring
1: [waypoint_follower-14] [INFO] [1718517310.558825021] [waypoint_follower]: Created waypoint_task_executor : wait_at_waypoint of type nav2_waypoint_follower::WaitAtWaypoint
1: [lifecycle_manager-18] [INFO] [1718517310.574129303] [lifecycle_manager_navigation]: Configuring docking_server
1: [opennav_docking-17] [INFO] [1718517310.581874093] [docking_server]: Configuring docking_server
1: [opennav_docking-17] [INFO] [1718517310.581956906] [docking_server]: Controller frequency set to 50.0000Hz
1: [opennav_docking-17] [INFO] [1718517310.684270697] [docking_server]: Created charging dock plugin simple_charging_dock of type opennav_docking::SimpleChargingDock
1: [opennav_docking-17] [INFO] [1718517310.735134556] [docking_server]: Loading docks from parameter file.
1: [opennav_docking-17] [INFO] [1718517310.736014778] [docking_server]: Docking Server has 1 dock types and 1 dock instances available.
1: [lifecycle_manager-18] [INFO] [1718517310.749749621] [lifecycle_manager_navigation]: Activating controller_server
1: [controller_server-9] [INFO] [1718517310.754614220] [controller_server]: Activating
1: [controller_server-9] [INFO] [1718517310.754719961] [local_costmap.local_costmap]: Activating
1: [controller_server-9] [INFO] [1718517310.754728375] [local_costmap.local_costmap]: Checking transform
1: [controller_server-9] [INFO] [1718517310.754845522] [local_costmap.local_costmap]: start
1: [controller_server-9] [INFO] [1718517310.955678212] [controller_server]: Activating controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517310.955730997] [controller_server]: Creating bond (controller_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517311.063216869] [lifecycle_manager_navigation]: Server controller_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517311.063255613] [lifecycle_manager_navigation]: Activating smoother_server
1: [smoother_server-10] [INFO] [1718517311.065862876] [smoother_server]: Activating
1: [smoother_server-10] [INFO] [1718517311.065923186] [smoother_server]: Creating bond (smoother_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517311.172004743] [lifecycle_manager_navigation]: Server smoother_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517311.172040821] [lifecycle_manager_navigation]: Activating planner_server
1: [planner_server-11] [INFO] [1718517311.172362024] [planner_server]: Activating
1: [planner_server-11] [INFO] [1718517311.172397962] [global_costmap.global_costmap]: Activating
1: [planner_server-11] [INFO] [1718517311.172405555] [global_costmap.global_costmap]: Checking transform
1: [planner_server-11] [INFO] [1718517311.172438490] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517311.672493893] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517311.888309819] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517312.172483173] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517312.672481887] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517313.175412541] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517313.672482224] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517314.172487386] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517314.337593544] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517314.672489567] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517315.172551872] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517315.672485376] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517316.172491146] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517316.473732519] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517316.672483603] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517317.172483961] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517317.672483751] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517318.172486057] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517318.672483349] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517318.720928796] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517319.172483354] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517319.672482316] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [tester_node-19] [INFO] [1718517319.754734494] [nav2_tester]: Waiting for amcl to become active
1: [tester_node-19] [INFO] [1718517319.762079785] [nav2_tester]: Getting amcl state...
1: [tester_node-19] [INFO] [1718517319.763511311] [nav2_tester]: Result of get_state: active
1: [planner_server-11] [INFO] [1718517320.172506609] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517320.672502046] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517320.850674563] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517321.172491913] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517321.672487359] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517322.172481729] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517322.672503098] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517323.172491193] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [amcl-7] [WARN] [1718517323.270375739] [amcl]: AMCL cannot publish a pose or update the transform. Please set the initial pose...
1: [planner_server-11] [INFO] [1718517323.672497405] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517324.172504829] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [planner_server-11] [INFO] [1718517324.672484126] [global_costmap.global_costmap]: Timed out waiting for transform from base_link to map to become available, tf error: Invalid frame ID "map" passed to canTransform argument target_frame - frame does not exist
1: [tester_node-19] [INFO] [1718517324.764010940] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517324.764400621] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517324.764751482] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517324.764855208] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 62.823000 but the latest data is at time 62.798000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517324.764879348] [amcl]: Setting pose (62.823000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517324.764929627] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517324.765346730] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517324.765835549] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517324.765959783] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517324.766008776] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 62.824000 but the latest data is at time 62.798000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517324.766022598] [amcl]: Setting pose (62.824000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517324.766206609] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517324.766687867] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517324.767063569] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517324.767181354] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517324.767227065] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 62.825000 but the latest data is at time 62.798000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517324.767239196] [amcl]: Setting pose (62.825000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517324.767552221] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517324.767922286] [nav2_tester]: Setting initial pose
1: [tester_node-19] [INFO] [1718517324.768270044] [nav2_tester]: Publishing Initial Pose
1: [amcl-7] [INFO] [1718517324.768433643] [amcl]: initialPoseReceived
1: [amcl-7] [WARN] [1718517324.768484160] [amcl]: Failed to transform initial pose in time (Lookup would require extrapolation into the future.  Requested time 62.827000 but the latest data is at time 62.798000, when looking up transform from frame [base_footprint] to frame [odom])
1: [amcl-7] [INFO] [1718517324.768497029] [amcl]: Setting pose (62.827000): -2.000 -0.500 0.000
1: [tester_node-19] [INFO] [1718517324.768691806] [nav2_tester]: Waiting for amcl_pose to be received
1: [tester_node-19] [INFO] [1718517324.785998670] [nav2_tester]: Received amcl_pose
1: [tester_node-19] [INFO] [1718517324.786417570] [nav2_tester]: Waiting for bt_navigator to become active
1: [tester_node-19] [INFO] [1718517324.790986018] [nav2_tester]: Getting bt_navigator state...
1: [tester_node-19] [INFO] [1718517324.794702054] [nav2_tester]: Result of get_state: inactive
1: [planner_server-11] [INFO] [1718517325.172578520] [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 63.036000 but the earliest data is at time 63.800000, when looking up transform from frame [base_link] to frame [map]
1: [planner_server-11] [INFO] [1718517325.672543618] [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 63.546000 but the earliest data is at time 63.800000, when looking up transform from frame [base_link] to frame [map]
1: [planner_server-11] [INFO] [1718517326.172575241] [global_costmap.global_costmap]: start
1: [planner_server-11] [INFO] [1718517327.223649056] [planner_server]: Activating plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517327.225019316] [planner_server]: Creating bond (planner_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517327.330071858] [lifecycle_manager_navigation]: Server planner_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517327.330109681] [lifecycle_manager_navigation]: Activating behavior_server
1: [behavior_server-12] [INFO] [1718517327.330408248] [behavior_server]: Activating
1: [behavior_server-12] [INFO] [1718517327.330428467] [behavior_server]: Activating spin
1: [behavior_server-12] [INFO] [1718517327.330438487] [behavior_server]: Activating backup
1: [behavior_server-12] [INFO] [1718517327.330446167] [behavior_server]: Activating drive_on_heading
1: [behavior_server-12] [INFO] [1718517327.330452973] [behavior_server]: Activating assisted_teleop
1: [behavior_server-12] [INFO] [1718517327.330459358] [behavior_server]: Activating wait
1: [behavior_server-12] [INFO] [1718517327.330469669] [behavior_server]: Creating bond (behavior_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517327.444411772] [lifecycle_manager_navigation]: Server behavior_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517327.444450714] [lifecycle_manager_navigation]: Activating velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517327.445319086] [velocity_smoother]: Activating
1: [velocity_smoother-15] [INFO] [1718517327.445373268] [velocity_smoother]: Creating bond (velocity_smoother) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517327.557155772] [lifecycle_manager_navigation]: Server velocity_smoother connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517327.557197024] [lifecycle_manager_navigation]: Activating collision_monitor
1: [collision_monitor-16] [INFO] [1718517327.557567123] [collision_monitor]: Activating
1: [collision_monitor-16] [INFO] [1718517327.557613762] [collision_monitor]: Creating bond (collision_monitor) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517327.665278415] [lifecycle_manager_navigation]: Server collision_monitor connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517327.665314212] [lifecycle_manager_navigation]: Activating bt_navigator
1: [bt_navigator-13] [INFO] [1718517327.665813957] [bt_navigator]: Activating
1: [bt_navigator-13] [INFO] [1718517327.858346905] [bt_navigator]: Creating bond (bt_navigator) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517327.967371742] [lifecycle_manager_navigation]: Server bt_navigator connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517327.967409893] [lifecycle_manager_navigation]: Activating waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517327.967728345] [waypoint_follower]: Activating
1: [waypoint_follower-14] [INFO] [1718517327.967758882] [waypoint_follower]: Creating bond (waypoint_follower) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517328.074261914] [lifecycle_manager_navigation]: Server waypoint_follower connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517328.074302268] [lifecycle_manager_navigation]: Activating docking_server
1: [opennav_docking-17] [INFO] [1718517328.076821015] [docking_server]: Activating docking_server
1: [opennav_docking-17] [INFO] [1718517328.093634614] [docking_server]: Creating bond (docking_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517328.204316832] [lifecycle_manager_navigation]: Server docking_server connected with bond.
1: [lifecycle_manager-18] [INFO] [1718517328.204353253] [lifecycle_manager_navigation]: Managed nodes are active
1: [lifecycle_manager-18] [INFO] [1718517328.204361274] [lifecycle_manager_navigation]: Creating bond timer...
1: [tester_node-19] [INFO] [1718517329.796499918] [nav2_tester]: Getting bt_navigator state...
1: [tester_node-19] [INFO] [1718517329.798258434] [nav2_tester]: Result of get_state: active
1: [tester_node-19] [INFO] [1718517334.798940386] [nav2_tester]: Waiting for 'NavigateToPose' action server
1: [tester_node-19] [INFO] [1718517334.799686077] [nav2_tester]: Sending goal request...
1: [bt_navigator-13] [INFO] [1718517334.800630560] [bt_navigator]: Begin navigating from current location (-2.00, -0.50) to (0.00, 2.00)
1: [tester_node-19] [INFO] [1718517334.801141618] [nav2_tester]: Goal accepted
1: [tester_node-19] [INFO] [1718517334.801772099] [nav2_tester]: Waiting for 'NavigateToPose' action to complete
1: [controller_server-9] [INFO] [1718517334.822575692] [controller_server]: Received a goal, begin computing control effort.
1: [controller_server-9] [WARN] [1718517334.822636629] [controller_server]: No goal checker was specified in parameter 'current_goal_checker'. Server will use only plugin loaded general_goal_checker . This warning will appear once.
1: [controller_server-9] [WARN] [1718517334.822656362] [controller_server]: No progress checker was specified in parameter 'current_progress_checker'. Server will use only plugin loaded progress_checker . This warning will appear once.
1: [parameter_bridge-2] [INFO] [1718517334.876498205] [ros_gz_bridge]: Passing message from ROS geometry_msgs/msg/Twist to Gazebo gz.msgs.Twist (showing msg only once per type)
1: [bt_navigator-13] [WARN] [1718517334.911300361] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517335.093876712] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517335.849881440] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517335.862946544] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517335.877746627] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517335.941171361] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517335.973949410] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.174224232] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.237512128] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.557422153] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.563794833] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.668150555] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517336.699071916] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517336.753849154] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517336.798046071] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517336.922860235] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517337.034366094] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.053221572] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.089854522] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.368063952] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.377952279] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.401873973] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.502056560] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.535108490] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.642517515] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.744074486] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.783556176] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.794644278] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.802143567] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517337.827450070] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517337.925740384] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517338.037962702] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.069759351] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517338.188770045] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517338.246121584] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.248140403] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.333285109] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.638845633] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.701324214] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.857905939] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.869895084] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.901977725] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.929956154] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517338.971087651] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517338.974846594] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517339.001902742] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.138331412] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.141990873] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.164018640] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.307234816] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.314830900] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.334065287] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.390032582] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.395322543] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517339.496322346] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517339.834379481] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517339.968401646] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517339.973738092] [controller_server]: Passing new path to controller.
1: [bt_navigator-13] [WARN] [1718517340.114152739] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.524776046] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [tester_node-19] [INFO] [1718517340.605941971] [nav2_tester]: Received amcl_pose
1: [bt_navigator-13] [WARN] [1718517340.684939521] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.721840484] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.726074069] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.753993724] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.758254508] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [WARN] [1718517340.766293690] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [planner_server-11] [WARN] [1718517340.964534402] [planner_server]: GridBased plugin failed to plan from (-0.99, -0.73) to (0.00, 2.00): "Failed to create plan with tolerance of: 0.500000"
1: [planner_server-11] [WARN] [1718517340.964591050] [planner_server]: [compute_path_to_pose] [ActionServer] Aborting handle.
1: [planner_server-11] [INFO] [1718517340.976631252] [global_costmap.global_costmap]: Received request to clear entirely the global_costmap
1: [bt_navigator-13] [WARN] [1718517340.993032179] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [controller_server-9] [INFO] [1718517341.022912565] [controller_server]: Passing new path to controller.
1: [controller_server-9] [ERROR] [1718517341.023073222] [controller_server]: Path is empty.
1: [controller_server-9] [WARN] [1718517341.023129473] [controller_server]: [follow_path] [ActionServer] Aborting handle.
1: [bt_navigator-13] [ERROR] [1718517341.070273306] [bt_navigator_navigate_to_pose_rclcpp_node]: Failed to get result for compute_path_to_pose in node halt!
1: [bt_navigator-13] [WARN] [1718517341.070543814] [BehaviorTreeEngine]: Behavior Tree tick rate 100.00 was exceeded!
1: [bt_navigator-13] [ERROR] [1718517341.070675513] [bt_navigator]: Goal failed
1: [bt_navigator-13] [WARN] [1718517341.070711527] [bt_navigator]: [navigate_to_pose] [ActionServer] Aborting handle.
1: [tester_node-19] [INFO] [1718517341.076921204] [nav2_tester]: Goal failed with status code: 6
1: [tester_node-19] [ERROR] [1718517341.077375515] [nav2_tester]: Test FAILED
1: [tester_node-19] [INFO] [1718517341.077934793] [nav2_tester]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517341.083615406] [lifecycle_manager_navigation]: Terminating bond timer...
1: [lifecycle_manager-18] [INFO] [1718517341.083695956] [lifecycle_manager_navigation]: Shutting down managed nodes...
1: [lifecycle_manager-18] [INFO] [1718517341.083711437] [lifecycle_manager_navigation]: Deactivate, cleanup, and shutdown nodes
1: [lifecycle_manager-18] [INFO] [1718517341.083722984] [lifecycle_manager_navigation]: Deactivating docking_server
1: [tester_node-19] [INFO] [1718517341.084128456] [nav2_tester]: Shutting down navigation lifecycle manager...
1: [opennav_docking-17] [INFO] [1718517341.087712740] [docking_server]: Deactivating docking_server
1: [opennav_docking-17] [INFO] [1718517341.104886211] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
1: [planner_server-11] [INFO] [1718517341.176755008] [planner_server]: Goal was canceled. Canceling planning action.
1: [planner_server-11] [WARN] [1718517341.176842962] [planner_server]: [compute_path_to_pose] [ActionServer] Client requested to cancel the goal. Cancelling.
1: [lifecycle_manager-18] [INFO] [1718517341.220636854] [lifecycle_manager_navigation]: Deactivating waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517341.220954186] [waypoint_follower]: Deactivating
1: [waypoint_follower-14] [INFO] [1718517341.220993423] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517341.333510524] [lifecycle_manager_navigation]: Deactivating bt_navigator
1: [bt_navigator-13] [INFO] [1718517341.333822181] [bt_navigator]: Deactivating
1: [bt_navigator-13] [INFO] [1718517341.333898242] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517341.447377702] [lifecycle_manager_navigation]: Deactivating collision_monitor
1: [collision_monitor-16] [INFO] [1718517341.480131704] [collision_monitor]: Deactivating
1: [collision_monitor-16] [INFO] [1718517341.480178120] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517341.592392670] [lifecycle_manager_navigation]: Deactivating velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517341.592692572] [velocity_smoother]: Deactivating
1: [velocity_smoother-15] [INFO] [1718517341.592725296] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517341.704651854] [lifecycle_manager_navigation]: Deactivating behavior_server
1: [behavior_server-12] [INFO] [1718517341.705466060] [behavior_server]: Deactivating
1: [behavior_server-12] [INFO] [1718517341.705689693] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517341.829750695] [lifecycle_manager_navigation]: Deactivating planner_server
1: [planner_server-11] [INFO] [1718517341.830720078] [planner_server]: Deactivating
1: [planner_server-11] [INFO] [1718517341.830758014] [global_costmap.global_costmap]: Deactivating
1: [planner_server-11] [INFO] [1718517342.172774400] [planner_server]: Deactivating plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517342.172818854] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517342.286214589] [lifecycle_manager_navigation]: Deactivating smoother_server
1: [smoother_server-10] [INFO] [1718517342.286713629] [smoother_server]: Deactivating
1: [smoother_server-10] [INFO] [1718517342.286761524] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517342.399096059] [lifecycle_manager_navigation]: Deactivating controller_server
1: [controller_server-9] [INFO] [1718517342.399440831] [controller_server]: Deactivating
1: [controller_server-9] [INFO] [1718517342.399482135] [controller_server]: Deactivating controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517342.399508663] [local_costmap.local_costmap]: Deactivating
1: [controller_server-9] [INFO] [1718517342.555131600] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517342.673748499] [lifecycle_manager_navigation]: Cleaning up docking_server
1: [opennav_docking-17] [INFO] [1718517342.677796863] [docking_server]: Cleaning up docking_server
1: [lifecycle_manager-18] [INFO] [1718517342.686550619] [lifecycle_manager_navigation]: Cleaning up waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517342.687417919] [waypoint_follower]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517342.722041692] [lifecycle_manager_navigation]: Cleaning up bt_navigator
1: [bt_navigator-13] [INFO] [1718517342.726054162] [bt_navigator]: Cleaning up
1: [bt_navigator-13] [INFO] [1718517342.953841492] [bt_navigator]: Completed Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517342.995522284] [lifecycle_manager_navigation]: Cleaning up collision_monitor
1: [collision_monitor-16] [INFO] [1718517342.996337436] [collision_monitor]: Cleaning up
1: [collision_monitor-16] [INFO] [1718517342.996390548] [collision_monitor]: [FootprintApproach]: Destroying Polygon
1: [collision_monitor-16] [INFO] [1718517342.996409990] [collision_monitor]: [scan]: Destroying Scan
1: [lifecycle_manager-18] [INFO] [1718517343.005067835] [lifecycle_manager_navigation]: Cleaning up velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517343.005313241] [velocity_smoother]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517343.006591682] [lifecycle_manager_navigation]: Cleaning up behavior_server
1: [behavior_server-12] [INFO] [1718517343.006804280] [behavior_server]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517343.055429755] [lifecycle_manager_navigation]: Cleaning up planner_server
1: [planner_server-11] [INFO] [1718517343.055679238] [planner_server]: Cleaning up
1: [planner_server-11] [INFO] [1718517343.078257758] [global_costmap.global_costmap]: Cleaning up
1: [planner_server-11] [INFO] [1718517343.095631235] [planner_server]: Cleaning up plugin GridBased of type NavfnPlanner
1: [planner_server-11] [INFO] [1718517343.095817786] [planner_server]: Destroying plugin GridBased of type NavfnPlanner
1: [lifecycle_manager-18] [INFO] [1718517343.125572740] [lifecycle_manager_navigation]: Cleaning up smoother_server
1: [smoother_server-10] [INFO] [1718517343.125807955] [smoother_server]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517343.149347604] [lifecycle_manager_navigation]: Cleaning up controller_server
1: [controller_server-9] [INFO] [1718517343.149587571] [controller_server]: Cleaning up
1: [controller_server-9] [INFO] [1718517343.149610828] [controller_server]: Cleaning up controller: FollowPath of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
1: [controller_server-9] [INFO] [1718517343.149656866] [local_costmap.local_costmap]: Cleaning up
1: [lifecycle_manager-18] [INFO] [1718517343.180305306] [lifecycle_manager_navigation]: Shutting down docking_server
1: [opennav_docking-17] [INFO] [1718517343.185725819] [docking_server]: Shutting down docking_server
1: [lifecycle_manager-18] [INFO] [1718517343.186248123] [lifecycle_manager_navigation]: Shutting down waypoint_follower
1: [waypoint_follower-14] [INFO] [1718517343.188380356] [waypoint_follower]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.188799804] [lifecycle_manager_navigation]: Shutting down bt_navigator
1: [bt_navigator-13] [INFO] [1718517343.189000838] [bt_navigator]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.189332842] [lifecycle_manager_navigation]: Shutting down collision_monitor
1: [collision_monitor-16] [INFO] [1718517343.189523479] [collision_monitor]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.189811405] [lifecycle_manager_navigation]: Shutting down velocity_smoother
1: [velocity_smoother-15] [INFO] [1718517343.190089763] [velocity_smoother]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.190569470] [lifecycle_manager_navigation]: Shutting down behavior_server
1: [behavior_server-12] [INFO] [1718517343.190897072] [behavior_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.191247517] [lifecycle_manager_navigation]: Shutting down planner_server
1: [planner_server-11] [INFO] [1718517343.191398933] [planner_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.210044161] [lifecycle_manager_navigation]: Shutting down smoother_server
1: [smoother_server-10] [INFO] [1718517343.211499960] [smoother_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.212405321] [lifecycle_manager_navigation]: Shutting down controller_server
1: [controller_server-9] [INFO] [1718517343.212577944] [controller_server]: Shutting down
1: [lifecycle_manager-18] [INFO] [1718517343.212939058] [lifecycle_manager_navigation]: Destroying lifecycle service clients
1: [lifecycle_manager-18] [INFO] [1718517343.248485050] [lifecycle_manager_navigation]: Managed nodes have been shut down
1: [tester_node-19] [INFO] [1718517343.263297239] [nav2_tester]: Shutting down navigation lifecycle manager complete.
1: [lifecycle_manager-8] [INFO] [1718517343.266340387] [lifecycle_manager_localization]: Terminating bond timer...
1: [lifecycle_manager-8] [INFO] [1718517343.266390171] [lifecycle_manager_localization]: Shutting down managed nodes...
1: [lifecycle_manager-8] [INFO] [1718517343.266402668] [lifecycle_manager_localization]: Deactivate, cleanup, and shutdown nodes
1: [lifecycle_manager-8] [INFO] [1718517343.266412207] [lifecycle_manager_localization]: Deactivating amcl
1: [amcl-7] [INFO] [1718517343.266674443] [amcl]: Deactivating
1: [amcl-7] [INFO] [1718517343.266702499] [amcl]: Destroying bond (amcl) to lifecycle manager.
1: [tester_node-19] [INFO] [1718517343.266862078] [nav2_tester]: Shutting down localization lifecycle manager...
1: [lifecycle_manager-8] [INFO] [1718517343.388051575] [lifecycle_manager_localization]: Deactivating map_server
1: [map_server-6] [INFO] [1718517343.388469899] [map_server]: Deactivating
1: [map_server-6] [INFO] [1718517343.388517082] [map_server]: Destroying bond (map_server) to lifecycle manager.
1: [lifecycle_manager-8] [INFO] [1718517343.504915488] [lifecycle_manager_localization]: Cleaning up amcl
1: [amcl-7] [INFO] [1718517343.505138896] [amcl]: Cleaning up
1: [lifecycle_manager-8] [INFO] [1718517343.521203798] [lifecycle_manager_localization]: Cleaning up map_server
1: [map_server-6] [INFO] [1718517343.523324749] [map_server]: Cleaning up
1: [lifecycle_manager-8] [INFO] [1718517343.543516061] [lifecycle_manager_localization]: Shutting down amcl
1: [amcl-7] [INFO] [1718517343.544682213] [amcl]: Shutting down
1: [lifecycle_manager-8] [INFO] [1718517343.551770161] [lifecycle_manager_localization]: Shutting down map_server
1: [map_server-6] [INFO] [1718517343.552051242] [map_server]: Shutting down
1: [lifecycle_manager-8] [INFO] [1718517343.552466911] [lifecycle_manager_localization]: Destroying lifecycle service clients
1: [lifecycle_manager-8] [INFO] [1718517343.556973015] [lifecycle_manager_localization]: Managed nodes have been shut down
1: [tester_node-19] [INFO] [1718517343.564772427] [nav2_tester]: Shutting down localization lifecycle manager complete
1: [tester_node-19] [INFO] [1718517343.565249475] [nav2_tester]: Done Shutting Down.
1: [tester_node-19] [INFO] [1718517343.565811610] [nav2_tester]: Exiting failed
1: [ERROR] [tester_node-19]: process has died [pid 1204, exit code 1, cmd '/opt/overlay_ws/src/navigation2/nav2_system_tests/src/system/nav_to_pose_tester_node.py -r -2.0 -0.5 0.0 2.0 -e True'].
1: [INFO] [lifecycle_manager-18]: sending signal 'SIGINT' to process[lifecycle_manager-18]
1: [INFO] [opennav_docking-17]: sending signal 'SIGINT' to process[opennav_docking-17]
1: [INFO] [collision_monitor-16]: sending signal 'SIGINT' to process[collision_monitor-16]
1: [INFO] [velocity_smoother-15]: sending signal 'SIGINT' to process[velocity_smoother-15]
1: [INFO] [waypoint_follower-14]: sending signal 'SIGINT' to process[waypoint_follower-14]
1: [INFO] [bt_navigator-13]: sending signal 'SIGINT' to process[bt_navigator-13]
1: [INFO] [behavior_server-12]: sending signal 'SIGINT' to process[behavior_server-12]
1: [INFO] [planner_server-11]: sending signal 'SIGINT' to process[planner_server-11]
1: [INFO] [smoother_server-10]: sending signal 'SIGINT' to process[smoother_server-10]
1: [INFO] [controller_server-9]: sending signal 'SIGINT' to process[controller_server-9]
1: [INFO] [lifecycle_manager-8]: sending signal 'SIGINT' to process[lifecycle_manager-8]
1: [INFO] [amcl-7]: sending signal 'SIGINT' to process[amcl-7]
1: [INFO] [map_server-6]: sending signal 'SIGINT' to process[map_server-6]
1: [INFO] [static_transform_publisher-5]: sending signal 'SIGINT' to process[static_transform_publisher-5]
1: [INFO] [static_transform_publisher-4]: sending signal 'SIGINT' to process[static_transform_publisher-4]
1: [INFO] [parameter_bridge-2]: sending signal 'SIGINT' to process[parameter_bridge-2]
1: [INFO] [ruby $(which gz) sim-1]: sending signal 'SIGINT' to process[ruby $(which gz) sim-1]
1: [lifecycle_manager-18] [INFO] [1718517343.852468731] [rclcpp]: signal_handler(signum=2)
1: [lifecycle_manager-18] [INFO] [1718517343.852597316] [lifecycle_manager_navigation]: Running Nav2 LifecycleManager rcl preshutdown (lifecycle_manager_navigation)
1: [opennav_docking-17] [INFO] [1718517343.858272552] [rclcpp]: signal_handler(signum=2)
1: [opennav_docking-17] [INFO] [1718517343.858334874] [docking_server]: Running Nav2 LifecycleNode rcl preshutdown (docking_server)
1: [opennav_docking-17] [INFO] [1718517343.858385636] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
1: [lifecycle_manager-18] [INFO] [1718517343.858595029] [lifecycle_manager_navigation]: Destroying lifecycle_manager_navigation
1: [collision_monitor-16] [INFO] [1718517343.858902911] [rclcpp]: signal_handler(signum=2)
1: [collision_monitor-16] [INFO] [1718517343.861823299] [collision_monitor]: Running Nav2 LifecycleNode rcl preshutdown (collision_monitor)
1: [collision_monitor-16] [INFO] [1718517343.861869040] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
1: [velocity_smoother-15] [INFO] [1718517343.863845967] [rclcpp]: signal_handler(signum=2)
1: [collision_monitor-16] [INFO] [1718517343.866424768] [collision_monitor]: Destroying
1: [opennav_docking-17] [INFO] [1718517343.866518485] [docking_server]: Destroying
1: [waypoint_follower-14] [INFO] [1718517343.866871013] [rclcpp]: signal_handler(signum=2)
1: [velocity_smoother-15] [INFO] [1718517343.869793419] [velocity_smoother]: Running Nav2 LifecycleNode rcl preshutdown (velocity_smoother)
1: [velocity_smoother-15] [INFO] [1718517343.869845611] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
1: [waypoint_follower-14] [INFO] [1718517343.870131360] [waypoint_follower]: Running Nav2 LifecycleNode rcl preshutdown (waypoint_follower)
1: [waypoint_follower-14] [INFO] [1718517343.870175413] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
1: [bt_navigator-13] [INFO] [1718517343.873566433] [rclcpp]: signal_handler(signum=2)
1: [bt_navigator-13] [INFO] [1718517343.873643021] [bt_navigator]: Running Nav2 LifecycleNode rcl preshutdown (bt_navigator)
1: [bt_navigator-13] [INFO] [1718517343.873687960] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
1: [velocity_smoother-15] [INFO] [1718517343.874599723] [velocity_smoother]: Destroying
1: [waypoint_follower-14] [INFO] [1718517343.877845063] [waypoint_follower]: Destroying
1: [bt_navigator-13] [INFO] [1718517343.879828653] [bt_navigator]: Destroying
1: [behavior_server-12] [INFO] [1718517343.880843571] [rclcpp]: signal_handler(signum=2)
1: [behavior_server-12] [INFO] [1718517343.885766509] [behavior_server]: Running Nav2 LifecycleNode rcl preshutdown (behavior_server)
1: [behavior_server-12] [INFO] [1718517343.885821570] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
1: [behavior_server-12] [INFO] [1718517343.886757520] [behavior_server]: Destroying
1: [planner_server-11] [INFO] [1718517343.887118334] [rclcpp]: signal_handler(signum=2)
1: [planner_server-11] [INFO] [1718517343.887176463] [planner_server]: Running Nav2 LifecycleNode rcl preshutdown (planner_server)
1: [planner_server-11] [INFO] [1718517343.887212107] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
1: [planner_server-11] [INFO] [1718517343.889047963] [global_costmap.global_costmap]: Destroying
1: [planner_server-11] [ERROR] [1718517343.889073520] [global_costmap.global_costmap]: Unable to start transition 5 from current state shuttingdown: Could not publish transition: publisher's context is invalid, at ./src/rcl/publisher.c:423, at ./src/rcl_lifecycle.c:368
1: [planner_server-11] [WARN] [1718517343.889079385] [rclcpp_lifecycle]: Shutdown error in destruction of LifecycleNode: final state(unconfigured)
1: [planner_server-11] [INFO] [1718517343.922457750] [planner_server]: Destroying
1: [smoother_server-10] [INFO] [1718517343.925098837] [rclcpp]: signal_handler(signum=2)
1: [smoother_server-10] [INFO] [1718517343.925756554] [smoother_server]: Running Nav2 LifecycleNode rcl preshutdown (smoother_server)
1: [smoother_server-10] [INFO] [1718517343.925806530] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
1: [smoother_server-10] [INFO] [1718517343.926415380] [smoother_server]: Destroying
1: [controller_server-9] [INFO] [1718517343.929756937] [rclcpp]: signal_handler(signum=2)
1: [controller_server-9] [INFO] [1718517343.929842355] [controller_server]: Running Nav2 LifecycleNode rcl preshutdown (controller_server)
1: [controller_server-9] [INFO] [1718517343.929885213] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
1: [controller_server-9] [INFO] [1718517343.930878572] [local_costmap.local_costmap]: Destroying
1: [controller_server-9] [ERROR] [1718517343.930905415] [local_costmap.local_costmap]: Unable to start transition 5 from current state shuttingdown: Could not publish transition: publisher's context is invalid, at ./src/rcl/publisher.c:423, at ./src/rcl_lifecycle.c:368
1: [controller_server-9] [WARN] [1718517343.930913855] [rclcpp_lifecycle]: Shutdown error in destruction of LifecycleNode: final state(unconfigured)
1: [lifecycle_manager-8] [INFO] [1718517343.939069377] [rclcpp]: signal_handler(signum=2)
1: [lifecycle_manager-8] [INFO] [1718517343.941796469] [lifecycle_manager_localization]: Running Nav2 LifecycleManager rcl preshutdown (lifecycle_manager_localization)
1: [controller_server-9] [INFO] [1718517343.941410337] [controller_server]: Destroying
1: [amcl-7] [INFO] [1718517343.950542731] [rclcpp]: signal_handler(signum=2)
1: [map_server-6] [INFO] [1718517343.953248237] [rclcpp]: signal_handler(signum=2)
1: [map_server-6] [INFO] [1718517343.953316082] [map_server]: Running Nav2 LifecycleNode rcl preshutdown (map_server)
1: [map_server-6] [INFO] [1718517343.953346976] [map_server]: Destroying bond (map_server) to lifecycle manager.
1: [map_server-6] [INFO] [1718517343.957215012] [map_server]: Destroying
1: [amcl-7] [INFO] [1718517343.953752197] [amcl]: Running Nav2 LifecycleNode rcl preshutdown (amcl)
1: [amcl-7] [INFO] [1718517343.953792773] [amcl]: Destroying bond (amcl) to lifecycle manager.
1: [amcl-7] [INFO] [1718517343.954897783] [amcl]: Destroying
1: [lifecycle_manager-8] [INFO] [1718517343.965950506] [lifecycle_manager_localization]: Destroying lifecycle_manager_localization
1: [static_transform_publisher-5] [INFO] [1718517343.982699491] [rclcpp]: signal_handler(signum=2)
1: [static_transform_publisher-4] [INFO] [1718517343.988387746] [rclcpp]: signal_handler(signum=2)
1: [parameter_bridge-2] [INFO] [1718517343.991695365] [rclcpp]: signal_handler(signum=2)
1: [INFO] [velocity_smoother-15]: process has finished cleanly [pid 1156]
1: [INFO] [behavior_server-12]: process has finished cleanly [pid 1080]
1: [INFO] [lifecycle_manager-18]: process has finished cleanly [pid 1179]
1: [INFO] [opennav_docking-17]: process has finished cleanly [pid 1166]
1: [INFO] [waypoint_follower-14]: process has finished cleanly [pid 1138]
1: [INFO] [collision_monitor-16]: process has finished cleanly [pid 1162]
1: [INFO] [smoother_server-10]: process has finished cleanly [pid 1078]
1: [INFO] [amcl-7]: process has finished cleanly [pid 1069]
1: [INFO] [bt_navigator-13]: process has finished cleanly [pid 1081]
1: [INFO] [lifecycle_manager-8]: process has finished cleanly [pid 1074]
1: [INFO] [map_server-6]: process has finished cleanly [pid 1068]
1: [INFO] [controller_server-9]: process has finished cleanly [pid 1075]
1: [INFO] [static_transform_publisher-5]: process has finished cleanly [pid 1067]
1: [INFO] [static_transform_publisher-4]: process has finished cleanly [pid 1065]
1: [INFO] [parameter_bridge-2]: process has finished cleanly [pid 1062]
1: [INFO] [planner_server-11]: process has finished cleanly [pid 1079]
1: [ERROR] [ruby $(which gz) sim-1]: process[ruby $(which gz) sim-1] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
1: [INFO] [ruby $(which gz) sim-1]: sending signal 'SIGTERM' to process[ruby $(which gz) sim-1]
1: [ERROR] [ruby $(which gz) sim-1]: process has died [pid 1061, exit code -15, cmd 'ruby $(which gz) sim -r -s /opt/overlay_ws/install/nav2_minimal_tb3_sim/share/nav2_minimal_tb3_sim/worlds/tb3_sandbox.sdf.xacro --force-version 8'].
1: [INFO] [launch]: process[ruby $(which gz) sim-1] was required: shutting down launched system
1: -- run_test.py: return code 1
1: -- run_test.py: generate result file '/opt/overlay_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml' with failed test
1: -- run_test.py: verify result file '/opt/overlay_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_bt_navigator.xml'
1/1 Test #1: test_bt_navigator ................***Failed   41.62 sec

0% tests passed, 1 tests failed out of 1

Total Test time (real) =  41.62 sec

The following tests FAILED:
      1 - test_bt_navigator (Failed)
Errors while running CTest

It seem it is caching something somehow. The behavior is consistent. See the video below with rviz. The test runs fine but since the location estimate is wrong, it fails during the planning/navigation path. I suspect that the Odom tf is not cleaned properly.

https://github.com/ros-navigation/navigation2/assets/61468301/2875aeb3-54ba-467c-957e-67225986e15c

[mergify[bot]]

This pull request is in conflict. Could you fix it @stevedanomodolor?

[SteveMacenski]

@stevedanomodolor can you check if gazebo is still running? That seems to be the issue that its not shutting down so the instance is still up keeping the robot alive at its position. Between tests, check htop for GZ sim running. If you kill -9 that process, does the second one now work as expected?

Is this reasonably deterministic or how often does this happen? It was maybe 1/100 in CI for Gazebo Classic which caused a level of flakiness, but wasn't frequent enough that caused us much concern. If this is deterministic or like 1+/20 that is a problem.

[stevedanomodolor]

@SteveMacenski it deterministic and it happens consistently. The first time it works, on the second time it fails. When i run multiple tests at once, like the test_bt_navigator tests, the first one passes but the seconds fails with the same behavior. Just to add info, I am running everything using dockers, and I always almost(not to say always) have to shut down the docker and restart ot again for it to work.

I also ran htop and gazebo does not shut down correctly.

[stevedanomodolor]

After killing the process from ps aux, I was able to run the tests. I do have a workaround to ensure all gz sim are clean after every test, but that does not tackle the root cause of why the gazebo does not shut down correctly.

[SteveMacenski]

@azeey FYI - a gazebo CI deterministic bottleneck with an ... unappealing workaround to SIGKILL GZ at the end of every test since its not going down cleanly in Jazzy/Rolling.

[SteveMacenski]

This is all really great, thanks so much for your time and effort! Lets leave this PR in the current state and not add more to it - add to new PRs instead to keep them bite sized for review / merging. Often 4-5 PRs can be merged and integrated faster than 1 mega-PR

[stevedanomodolor]

This is all really great, thanks so much for your time and effort! Lets leave this PR in the current state and not add more to it - add to new PRs instead to keep them bite sized for review / merging. Often 4-5 PRs can be merged and integrated faster than 1 mega-PR

as soon as this is merged, then I can merge other tests faster because I use the kill gz sim utils

[SteveMacenski]

test/test_copyright.py:22: in test_copyright
    rc = main(argv=['.', 'test'])
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/main.py:117: in main
    file_descriptors[filename] = parse_file(filename)
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/parser.py:171: in parse_file
    d.parse()
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/parser.py:118: in parse
    copyrights, _, _, remaining_block = search_copyright_information(block)
E   ValueError: not enough values to unpack (expected 4, got 2)

Minor linting issue and we can merge!

[stevedanomodolor]

test/test_copyright.py:22: in test_copyright
    rc = main(argv=['.', 'test'])
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/main.py:117: in main
    file_descriptors[filename] = parse_file(filename)
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/parser.py:171: in parse_file
    d.parse()
/opt/ros/rolling/lib/python3.12/site-packages/ament_copyright/parser.py:118: in parse
    copyrights, _, _, remaining_block = search_copyright_information(block)
E   ValueError: not enough values to unpack (expected 4, got 2)

Minor linting issue and we can merge!

How did you check this?. I am not able to see this locally

[SteveMacenski]

Look at the failed CI job - it shows there

[stevedanomodolor]

Look at the failed CI job - it shows there

@SteveMacenski I am not sure exactly why its failing. Am I missing some information somewhere?

[SteveMacenski]

Merged!