Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Feat/migrate gps nav2 system test #4682

Conversation

stevedanomodolor
Copy link
Contributor

@stevedanomodolor stevedanomodolor commented Sep 18, 2024


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

Description of documentation updates required from your changes


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

Copy link
Member

@SteveMacenski SteveMacenski left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe this will require the changes from the turtlebot minimum simulation package to be merged first (then we can add to our repos file to do here + run a sync so those changes will get out into binary format)

Signed-off-by: stevedan <[email protected]>
@stevedanomodolor
Copy link
Contributor Author

I believe this will require the changes from the turtlebot minimum simulation package to be merged first (then we can add to our repos file to do here + run a sync so those changes will get out into binary format)

Yes, made the changes based on the review on the other PR

@SteveMacenski
Copy link
Member

@stevedanomodolor if you update this in your PR https://github.com/ros-navigation/navigation2/blob/main/tools/underlay.repos#L34-L37 to point at main, then it'll get the latest changes including your GPS files that we can have run in CI to actually test them together in Circle. If that passes, we should be good to go!

Signed-off-by: stevedan <[email protected]>
Signed-off-by: stevedan <[email protected]>
@SteveMacenski
Copy link
Member

In this file, there are 3 instances of v26, change it to v27, maybe we need to also break the cache https://github.com/ros-navigation/navigation2/blob/main/.circleci/config.yml

I thought I'd changed the underlay before and had it captured, but maybe vcstools doesn't consider the versions as a change 🤷 (at least I'm hoping so, else maybe there's a problem with this PR -- file naming?)

@stevedanomodolor
Copy link
Contributor Author

stevedanomodolor commented Oct 2, 2024

I Doubt it is a problem with the file because I have verified that and the name is the same. It has something to do with the build tool and how the underws is built, not sure though the problem.

@stevedanomodolor
Copy link
Contributor Author

In this file, there are 3 instances of v26, change it to v27, maybe we need to also break the cache https://github.com/ros-navigation/navigation2/blob/main/.circleci/config.yml

I thought I'd changed the underlay before and had it captured, but maybe vcstools doesn't consider the versions as a change 🤷 (at least I'm hoping so, else maybe there's a problem with this PR -- file naming?)

Not really familiar with th build tool. What do you mean when you say v26 v27

@SteveMacenski
Copy link
Member

There's 3 places in that file we name a cache and we need to break that cache by updating its name so that we pull and rebuild everything from scratch (lines 36, 41, 61). I think what's happening is that its still using the old underlay workspace without your updated files. If it still fails to run the test due to missing files at that point, its probably something in this PR with naming / file locations.

Signed-off-by: stevedan <[email protected]>
@stevedanomodolor
Copy link
Contributor Author

stevedanomodolor commented Oct 3, 2024

@SteveMacenski Still does not work, I tried this locally and it works. I will look more into the cache things to see if we are missing something.

      Start 23: test_gps_waypoint_follower

23: 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_gps_waypoint_follower.xml" "--package-name" "nav2_system_tests" "--generate-result-on-success" "--env" "TEST_DIR=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/gps_navigation" "--command" "/opt/overlay_ws/src/navigation2/nav2_system_tests/src/gps_navigation/test_case_py.launch.py"
23: Working Directory: /opt/overlay_ws/build/nav2_system_tests/src/gps_navigation
23: Test timeout computed to be: 180
23: -- run_test.py: extra environment variables:
23:  - TEST_DIR=/opt/overlay_ws/src/navigation2/nav2_system_tests/src/gps_navigation
23: -- run_test.py: invoking following command in '/opt/overlay_ws/build/nav2_system_tests/src/gps_navigation':
23:  - /opt/overlay_ws/src/navigation2/nav2_system_tests/src/gps_navigation/test_case_py.launch.py
23: [INFO] [launch]: All log files can be found below /root/.ros/log/2024-10-03-16-45-30-140933-stevedan-5230
23: [INFO] [launch]: Default logging verbosity is set to INFO
23: [INFO] [gz-1]: process started with pid [5234]
23: [INFO] [parameter_bridge-2]: process started with pid [5235]
23: [INFO] [create-3]: process started with pid [5236]
23: [INFO] [robot_state_publisher-4]: process started with pid [5237]
23: [INFO] [controller_server-5]: process started with pid [5238]
23: [INFO] [smoother_server-6]: process started with pid [5239]
23: [INFO] [planner_server-7]: process started with pid [5240]
23: [INFO] [behavior_server-8]: process started with pid [5241]
23: [INFO] [bt_navigator-9]: process started with pid [5242]
23: [INFO] [waypoint_follower-10]: process started with pid [5243]
23: [INFO] [velocity_smoother-11]: process started with pid [5244]
23: [INFO] [collision_monitor-12]: process started with pid [5245]
23: [INFO] [opennav_docking-13]: process started with pid [5246]
23: [INFO] [lifecycle_manager-14]: process started with pid [5249]
23: [INFO] [ekf_node-15]: process started with pid [5254]
23: [INFO] [ekf_node-16]: process started with pid [5255]
23: [INFO] [navsat_transform_node-17]: process started with pid [5256]
23: [INFO] [tester_node-18]: process started with pid [5257]
23: [robot_state_publisher-4] [INFO] [1727973930.545737085] [robot_state_publisher]: Robot initialized
23: [create-3] [INFO] [1727973930.565497337] [ros_gz_sim]: Requesting list of world names.
23: [planner_server-7] [INFO] [1727973930.648968428] [planner_server]: 
23: [planner_server-7] 	planner_server lifecycle node launched. 
23: [planner_server-7] 	Waiting on external lifecycle transitions to activate
23: [planner_server-7] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [bt_navigator-9] [INFO] [1727973930.649329460] [bt_navigator]: 
23: [bt_navigator-9] 	bt_navigator lifecycle node launched. 
23: [bt_navigator-9] 	Waiting on external lifecycle transitions to activate
23: [bt_navigator-9] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [planner_server-7] [INFO] [1727973930.656331840] [planner_server]: Creating
23: [bt_navigator-9] [INFO] [1727973930.656982019] [bt_navigator]: Creating
23: [smoother_server-6] [INFO] [1727973930.677087656] [smoother_server]: 
23: [smoother_server-6] 	smoother_server lifecycle node launched. 
23: [smoother_server-6] 	Waiting on external lifecycle transitions to activate
23: [smoother_server-6] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [smoother_server-6] [INFO] [1727973930.692798008] [smoother_server]: Creating smoother server
23: [behavior_server-8] [INFO] [1727973930.702818087] [behavior_server]: 
23: [behavior_server-8] 	behavior_server lifecycle node launched. 
23: [behavior_server-8] 	Waiting on external lifecycle transitions to activate
23: [behavior_server-8] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [collision_monitor-12] [INFO] [1727973930.705614970] [collision_monitor]: 
23: [collision_monitor-12] 	collision_monitor lifecycle node launched. 
23: [collision_monitor-12] 	Waiting on external lifecycle transitions to activate
23: [collision_monitor-12] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [lifecycle_manager-14] [INFO] [1727973930.726408721] [lifecycle_manager_navigation]: Creating
23: [velocity_smoother-11] [INFO] [1727973930.725429975] [velocity_smoother]: 
23: [velocity_smoother-11] 	velocity_smoother lifecycle node launched. 
23: [velocity_smoother-11] 	Waiting on external lifecycle transitions to activate
23: [velocity_smoother-11] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [opennav_docking-13] [INFO] [1727973930.729164866] [docking_server]: 
23: [opennav_docking-13] 	docking_server lifecycle node launched. 
23: [opennav_docking-13] 	Waiting on external lifecycle transitions to activate
23: [opennav_docking-13] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [opennav_docking-13] [INFO] [1727973930.729398089] [docking_server]: Creating docking_server
23: [waypoint_follower-10] [INFO] [1727973930.738361189] [waypoint_follower]: 
23: [waypoint_follower-10] 	waypoint_follower lifecycle node launched. 
23: [waypoint_follower-10] 	Waiting on external lifecycle transitions to activate
23: [waypoint_follower-10] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [waypoint_follower-10] [INFO] [1727973930.740020835] [waypoint_follower]: Creating
23: [lifecycle_manager-14] [INFO] [1727973930.746816955] [lifecycle_manager_navigation]: Creating and initializing lifecycle service clients
23: [planner_server-7] [INFO] [1727973930.750072297] [global_costmap.global_costmap]: 
23: [planner_server-7] 	global_costmap lifecycle node launched. 
23: [planner_server-7] 	Waiting on external lifecycle transitions to activate
23: [planner_server-7] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [planner_server-7] [INFO] [1727973930.751591719] [global_costmap.global_costmap]: Creating Costmap
23: [controller_server-5] [INFO] [1727973930.756181071] [controller_server]: 
23: [controller_server-5] 	controller_server lifecycle node launched. 
23: [controller_server-5] 	Waiting on external lifecycle transitions to activate
23: [controller_server-5] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [controller_server-5] [INFO] [1727973930.779175824] [controller_server]: Creating controller server
23: [controller_server-5] [INFO] [1727973930.793322027] [local_costmap.local_costmap]: 
23: [controller_server-5] 	local_costmap lifecycle node launched. 
23: [controller_server-5] 	Waiting on external lifecycle transitions to activate
23: [controller_server-5] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
23: [controller_server-5] [INFO] [1727973930.794442725] [local_costmap.local_costmap]: Creating Costmap
23: [create-3] [INFO] [1727973931.147154463] [ros_gz_sim]: Entity creation successfull.
23: [INFO] [create-3]: process has finished cleanly [pid 5236]
23: [lifecycle_manager-14] [INFO] [1727973931.684828442] [lifecycle_manager_navigation]: Starting managed nodes bringup...
23: [lifecycle_manager-14] [INFO] [1727973931.684874275] [lifecycle_manager_navigation]: Configuring controller_server
23: [controller_server-5] [INFO] [1727973931.685251572] [controller_server]: Configuring controller interface
23: [controller_server-5] [INFO] [1727973931.685275876] [controller_server]: getting progress checker plugins..
23: [controller_server-5] [INFO] [1727973931.685417121] [controller_server]: getting goal checker plugins..
23: [controller_server-5] [INFO] [1727973931.685538640] [controller_server]: Controller frequency set to 20.0000Hz
23: [controller_server-5] [INFO] [1727973931.685579435] [local_costmap.local_costmap]: Configuring
23: [controller_server-5] [INFO] [1727973931.692806762] [local_costmap.local_costmap]: Using plugin "voxel_layer"
23: [controller_server-5] [INFO] [1727973931.698629869] [local_costmap.local_costmap]: Subscribed to Topics: scan
23: [controller_server-5] [INFO] [1727973931.709229601] [local_costmap.local_costmap]: Initialized plugin "voxel_layer"
23: [controller_server-5] [INFO] [1727973931.709256035] [local_costmap.local_costmap]: Using plugin "inflation_layer"
23: [controller_server-5] [INFO] [1727973931.709819889] [local_costmap.local_costmap]: Initialized plugin "inflation_layer"
23: [controller_server-5] [INFO] [1727973931.720160961] [controller_server]: Created progress_checker : progress_checker of type nav2_controller::SimpleProgressChecker
23: [controller_server-5] [INFO] [1727973931.720419140] [controller_server]: Controller Server has progress_checker  progress checkers available.
23: [controller_server-5] [INFO] [1727973931.721048624] [controller_server]: Created goal checker : general_goal_checker of type nav2_controller::SimpleGoalChecker
23: [controller_server-5] [INFO] [1727973931.721330352] [controller_server]: Controller Server has general_goal_checker  goal checkers available.
23: [controller_server-5] [INFO] [1727973931.723394197] [controller_server]: Created controller : FollowPath of type nav2_mppi_controller::MPPIController
23: [controller_server-5] [INFO] [1727973931.725091686] [controller_server]: Controller period is equal to model dt. Control sequence shifting is ON
23: [controller_server-5] [INFO] [1727973931.727702839] [controller_server]: ConstraintCritic instantiated with 1 power and 4.000000 weight.
23: [controller_server-5] [INFO] [1727973931.727749408] [controller_server]: Critic loaded : mppi::critics::ConstraintCritic
23: [controller_server-5] [INFO] [1727973931.728748277] [controller_server]: InflationCostCritic instantiated with 1 power and 300.000000 / 0.015000 weights. Critic will collision check based on footprint cost.
23: [controller_server-5] [INFO] [1727973931.728795750] [controller_server]: Critic loaded : mppi::critics::CostCritic
23: [controller_server-5] [INFO] [1727973931.729317508] [controller_server]: GoalCritic instantiated with 1 power and 5.000000 weight.
23: [controller_server-5] [INFO] [1727973931.729377281] [controller_server]: Critic loaded : mppi::critics::GoalCritic
23: [controller_server-5] [INFO] [1727973931.729916464] [controller_server]: GoalAngleCritic instantiated with 1 power, 3.000000 weight, and 0.500000 angular threshold.
23: [controller_server-5] [INFO] [1727973931.729943562] [controller_server]: Critic loaded : mppi::critics::GoalAngleCritic
23: [controller_server-5] [INFO] [1727973931.730822712] [controller_server]: ReferenceTrajectoryCritic instantiated with 1 power and 14.000000 weight
23: [controller_server-5] [INFO] [1727973931.730867211] [controller_server]: Critic loaded : mppi::critics::PathAlignCritic
23: [controller_server-5] [INFO] [1727973931.731403081] [controller_server]: Critic loaded : mppi::critics::PathFollowCritic
23: [controller_server-5] [INFO] [1727973931.732071830] [controller_server]: PathAngleCritic instantiated with 1 power and 2.000000 weight. Mode set to: Forward Preference
23: [controller_server-5] [INFO] [1727973931.732095032] [controller_server]: Critic loaded : mppi::critics::PathAngleCritic
23: [controller_server-5] [INFO] [1727973931.732446580] [controller_server]: PreferForwardCritic instantiated with 1 power and 5.000000 weight.
23: [controller_server-5] [INFO] [1727973931.732475949] [controller_server]: Critic loaded : mppi::critics::PreferForwardCritic
23: [controller_server-5] [INFO] [1727973931.734375103] [controller_server]: Optimizer reset
23: [controller_server-5] [INFO] [1727973931.738243749] [MPPIController]: Configured MPPI Controller: FollowPath
23: [controller_server-5] [INFO] [1727973931.738363826] [controller_server]: Controller Server has FollowPath  controllers available.
23: [lifecycle_manager-14] [INFO] [1727973931.745072557] [lifecycle_manager_navigation]: Configuring smoother_server
23: [smoother_server-6] [INFO] [1727973931.745264902] [smoother_server]: Configuring smoother server
23: [parameter_bridge-2] [INFO] [1727973931.748671553] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/clock (gz.msgs.Clock) -> /clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.750092398] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/joint_states (gz.msgs.Model) -> joint_states (sensor_msgs/msg/JointState)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.753779902] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/odom (gz.msgs.Odometry) -> odom (nav_msgs/msg/Odometry)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.756215690] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/tf (gz.msgs.Pose_V) -> tf (tf2_msgs/msg/TFMessage)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.758745275] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/imu/data (gz.msgs.IMU) -> imu/data (sensor_msgs/msg/Imu)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.759996652] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/scan (gz.msgs.LaserScan) -> scan (sensor_msgs/msg/LaserScan)] (Lazy 0)
23: [parameter_bridge-2] [INFO] [1727973931.761166667] [ros_gz_bridge]: Creating ROS->GZ Bridge: [cmd_vel (geometry_msgs/msg/Twist) -> /cmd_vel (gz.msgs.Twist)] (Lazy 0)
23: [smoother_server-6] [INFO] [1727973931.762172015] [smoother_server]: Created smoother : simple_smoother of type nav2_smoother::SimpleSmoother
23: [smoother_server-6] [INFO] [1727973931.762694820] [smoother_server]: Smoother Server has simple_smoother  smoothers available.
23: [parameter_bridge-2] [INFO] [1727973931.762714753] [ros_gz_bridge]: Creating GZ->ROS Bridge: [/gps/fix (gz.msgs.NavSat) -> gps/fix (sensor_msgs/msg/NavSatFix)] (Lazy 0)
23: [lifecycle_manager-14] [INFO] [1727973931.768878671] [lifecycle_manager_navigation]: Configuring planner_server
23: [planner_server-7] [INFO] [1727973931.769130116] [planner_server]: Configuring
23: [planner_server-7] [INFO] [1727973931.769161086] [global_costmap.global_costmap]: Configuring
23: [planner_server-7] [INFO] [1727973931.779627148] [global_costmap.global_costmap]: Using plugin "obstacle_layer"
23: [planner_server-7] [INFO] [1727973931.786357441] [global_costmap.global_costmap]: Subscribed to Topics: scan
23: [planner_server-7] [INFO] [1727973931.790933238] [global_costmap.global_costmap]: Initialized plugin "obstacle_layer"
23: [planner_server-7] [INFO] [1727973931.790960751] [global_costmap.global_costmap]: Using plugin "inflation_layer"
23: [planner_server-7] [INFO] [1727973931.791583995] [global_costmap.global_costmap]: Initialized plugin "inflation_layer"
23: [planner_server-7] [INFO] [1727973931.809102014] [planner_server]: Created global planner plugin GridBased of type nav2_navfn_planner::NavfnPlanner
23: [planner_server-7] [INFO] [1727973931.809132418] [planner_server]: Configuring plugin GridBased of type NavfnPlanner
23: [planner_server-7] [INFO] [1727973931.809820587] [planner_server]: Planner Server has GridBased  planners available.
23: [lifecycle_manager-14] [INFO] [1727973931.818379445] [lifecycle_manager_navigation]: Configuring behavior_server
23: [behavior_server-8] [INFO] [1727973931.818589581] [behavior_server]: Configuring
23: [behavior_server-8] [INFO] [1727973931.825267707] [behavior_server]: Creating behavior plugin spin of type nav2_behaviors::Spin
23: [behavior_server-8] [INFO] [1727973931.827050333] [behavior_server]: Creating behavior plugin backup of type nav2_behaviors::BackUp
23: [behavior_server-8] [INFO] [1727973931.829587603] [behavior_server]: Creating behavior plugin drive_on_heading of type nav2_behaviors::DriveOnHeading
23: [behavior_server-8] [INFO] [1727973931.832063877] [behavior_server]: Creating behavior plugin assisted_teleop of type nav2_behaviors::AssistedTeleop
23: [behavior_server-8] [INFO] [1727973931.835251602] [behavior_server]: Creating behavior plugin wait of type nav2_behaviors::Wait
23: [behavior_server-8] [INFO] [1727973931.844164476] [behavior_server]: Configuring spin
23: [behavior_server-8] [INFO] [1727973931.849431196] [behavior_server]: Configuring backup
23: [behavior_server-8] [INFO] [1727973931.853007755] [behavior_server]: Configuring drive_on_heading
23: [behavior_server-8] [INFO] [1727973931.856416170] [behavior_server]: Configuring assisted_teleop
23: [behavior_server-8] [INFO] [1727973931.861214158] [behavior_server]: Configuring wait
23: [lifecycle_manager-14] [INFO] [1727973931.865777603] [lifecycle_manager_navigation]: Configuring velocity_smoother
23: [velocity_smoother-11] [INFO] [1727973931.866000600] [velocity_smoother]: Configuring velocity smoother
23: [lifecycle_manager-14] [INFO] [1727973931.870402522] [lifecycle_manager_navigation]: Configuring collision_monitor
23: [collision_monitor-12] [INFO] [1727973931.870764746] [collision_monitor]: Configuring
23: [collision_monitor-12] [INFO] [1727973931.880376646] [collision_monitor]: [scan]: Creating Scan
23: [collision_monitor-12] [INFO] [1727973931.883423953] [collision_monitor]: [FootprintApproach]: Creating Polygon
23: [collision_monitor-12] [INFO] [1727973931.883610599] [collision_monitor]: [FootprintApproach]: Polygon points are not defined. Using dynamic subscription instead.
23: [collision_monitor-12] [INFO] [1727973931.884366796] [collision_monitor]: [FootprintApproach]: Making footprint subscriber on /local_costmap/published_footprint topic
23: [lifecycle_manager-14] [INFO] [1727973931.895351945] [lifecycle_manager_navigation]: Configuring bt_navigator
23: [bt_navigator-9] [INFO] [1727973931.895583573] [bt_navigator]: Configuring
23: [bt_navigator-9] [INFO] [1727973931.902036989] [bt_navigator]: Creating navigator id navigate_to_pose of type nav2_bt_navigator::NavigateToPoseNavigator
23: [bt_navigator-9] [INFO] [1727973931.977343906] [bt_navigator]: Creating navigator id navigate_through_poses of type nav2_bt_navigator::NavigateThroughPosesNavigator
23: [lifecycle_manager-14] [INFO] [1727973931.996552741] [lifecycle_manager_navigation]: Configuring waypoint_follower
23: [waypoint_follower-10] [INFO] [1727973931.996771187] [waypoint_follower]: Configuring
23: [waypoint_follower-10] [INFO] [1727973932.016325022] [waypoint_follower]: Created waypoint_task_executor : wait_at_waypoint of type nav2_waypoint_follower::WaitAtWaypoint
23: [lifecycle_manager-14] [INFO] [1727973932.017012274] [lifecycle_manager_navigation]: Configuring docking_server
23: [opennav_docking-13] [INFO] [1727973932.017211300] [docking_server]: Configuring docking_server
23: [opennav_docking-13] [INFO] [1727973932.017244911] [docking_server]: Controller frequency set to 50.0000Hz
23: [opennav_docking-13] [INFO] [1727973932.040002404] [docking_server]: Created charging dock plugin simple_charging_dock of type opennav_docking::SimpleChargingDock
23: [opennav_docking-13] [INFO] [1727973932.043782506] [docking_server]: Loading docks from parameter file.
23: [opennav_docking-13] [INFO] [1727973932.044162890] [docking_server]: Docking Server has 1 dock types and 1 dock instances available.
23: [lifecycle_manager-14] [INFO] [1727973932.045595735] [lifecycle_manager_navigation]: Activating controller_server
23: [controller_server-5] [INFO] [1727973932.045767448] [controller_server]: Activating
23: [controller_server-5] [INFO] [1727973932.045794995] [local_costmap.local_costmap]: Activating
23: [controller_server-5] [INFO] [1727973932.045803046] [local_costmap.local_costmap]: Checking transform
23: [controller_server-5] [INFO] [1727973932.045832356] [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
23: [controller_server-5] [INFO] [1727973932.545963436] [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
23: [gz-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="imu_link"]/sensor[@name="tb3_imu"]/gz_frame_id:<data-string>:L49]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
23: [gz-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="gps_link"]/sensor[@name="navsat"]/gz_frame_id:<data-string>:L99]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
23: [gz-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="base_scan"]/sensor[@name="hls_lfcd_lds"]/gz_frame_id:<data-string>:L158]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
23: [gz-1] Warning [Utils.cc:132] [/sdf/model[@name="turtlebot3_waffle"]/link[@name="camera_link"]/sensor[@name="intel_realsense_r200_depth"]/gz_frame_id:<data-string>:L385]: XML Element[gz_frame_id], child of element[sensor], not defined in SDF. Copying[gz_frame_id] as children of [sensor].
23: [gz-1] libEGL warning: egl: failed to create dri2 screen
23: [gz-1] libEGL warning: egl: failed to create dri2 screen
23: [gz-1] libEGL warning: egl: failed to create dri2 screen
23: [controller_server-5] [INFO] [1727973933.045920695] [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
23: [controller_server-5] [INFO] [1727973933.545952949] [local_costmap.local_costmap]: start
23: [controller_server-5] [WARN] [1727973933.746994121] [controller_server]: Parameter controller_server.verbose not found
23: [controller_server-5] [INFO] [1727973933.748622543] [controller_server]: Optimizer reset
23: [controller_server-5] [INFO] [1727973933.748782579] [MPPIController]: Activated MPPI Controller: FollowPath
23: [controller_server-5] [INFO] [1727973933.748802174] [controller_server]: Creating bond (controller_server) to lifecycle manager.
23: [navsat_transform_node-17] [INFO] [1727973933.768763021] [navsat_transform]: Datum (latitude, longitude, altitude) is (55.94, -3.19, 0.00)
23: [navsat_transform_node-17] [INFO] [1727973933.768849204] [navsat_transform]: Datum UTM coordinate is (30 north, 488320.74, 6199955.24)
23: [navsat_transform_node-17] [INFO] [1727973933.802056950] [navsat_transform]: Corrected for magnetic declination of 0.0429351, user-specified offset of 0 and meridian convergence of -0.002704. Transform heading factor is now 0.0402311
23: [lifecycle_manager-14] [INFO] [1727973933.853797720] [lifecycle_manager_navigation]: Server controller_server connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973933.853830136] [lifecycle_manager_navigation]: Activating smoother_server
23: [smoother_server-6] [INFO] [1727973933.854041423] [smoother_server]: Activating
23: [smoother_server-6] [INFO] [1727973933.854066061] [smoother_server]: Creating bond (smoother_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973933.958476525] [lifecycle_manager_navigation]: Server smoother_server connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973933.958526125] [lifecycle_manager_navigation]: Activating planner_server
23: [planner_server-7] [INFO] [1727973933.958782313] [planner_server]: Activating
23: [planner_server-7] [INFO] [1727973933.958816927] [global_costmap.global_costmap]: Activating
23: [planner_server-7] [INFO] [1727973933.958826379] [global_costmap.global_costmap]: Checking transform
23: [planner_server-7] [INFO] [1727973933.958945201] [global_costmap.global_costmap]: start
23: [planner_server-7] [INFO] [1727973935.010063608] [planner_server]: Activating plugin GridBased of type NavfnPlanner
23: [planner_server-7] [INFO] [1727973935.011315231] [planner_server]: Creating bond (planner_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.115194864] [lifecycle_manager_navigation]: Server planner_server connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.115231155] [lifecycle_manager_navigation]: Activating behavior_server
23: [behavior_server-8] [INFO] [1727973935.115511287] [behavior_server]: Activating
23: [behavior_server-8] [INFO] [1727973935.115536691] [behavior_server]: Activating spin
23: [behavior_server-8] [INFO] [1727973935.115551239] [behavior_server]: Activating backup
23: [behavior_server-8] [INFO] [1727973935.115561013] [behavior_server]: Activating drive_on_heading
23: [behavior_server-8] [INFO] [1727973935.115570526] [behavior_server]: Activating assisted_teleop
23: [behavior_server-8] [INFO] [1727973935.115580002] [behavior_server]: Activating wait
23: [behavior_server-8] [INFO] [1727973935.115593167] [behavior_server]: Creating bond (behavior_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.220032402] [lifecycle_manager_navigation]: Server behavior_server connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.220070372] [lifecycle_manager_navigation]: Activating velocity_smoother
23: [velocity_smoother-11] [INFO] [1727973935.220303476] [velocity_smoother]: Activating
23: [velocity_smoother-11] [INFO] [1727973935.220346577] [velocity_smoother]: Creating bond (velocity_smoother) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.324836538] [lifecycle_manager_navigation]: Server velocity_smoother connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.324871559] [lifecycle_manager_navigation]: Activating collision_monitor
23: [collision_monitor-12] [INFO] [1727973935.325170988] [collision_monitor]: Activating
23: [collision_monitor-12] [INFO] [1727973935.325202479] [collision_monitor]: Creating bond (collision_monitor) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.429902289] [lifecycle_manager_navigation]: Server collision_monitor connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.429939901] [lifecycle_manager_navigation]: Activating bt_navigator
23: [bt_navigator-9] [INFO] [1727973935.430195086] [bt_navigator]: Activating
23: [bt_navigator-9] [INFO] [1727973935.489755393] [bt_navigator]: Creating bond (bt_navigator) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.595024301] [lifecycle_manager_navigation]: Server bt_navigator connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.595101788] [lifecycle_manager_navigation]: Activating waypoint_follower
23: [waypoint_follower-10] [INFO] [1727973935.595757683] [waypoint_follower]: Activating
23: [waypoint_follower-10] [INFO] [1727973935.595839523] [waypoint_follower]: Creating bond (waypoint_follower) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.702042842] [lifecycle_manager_navigation]: Server waypoint_follower connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.702086279] [lifecycle_manager_navigation]: Activating docking_server
23: [opennav_docking-13] [INFO] [1727973935.702449926] [docking_server]: Activating docking_server
23: [opennav_docking-13] [INFO] [1727973935.712846728] [docking_server]: Creating bond (docking_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727973935.818105597] [lifecycle_manager_navigation]: Server docking_server connected with bond.
23: [lifecycle_manager-14] [INFO] [1727973935.818137908] [lifecycle_manager_navigation]: Managed nodes are active
23: [lifecycle_manager-14] [INFO] [1727973935.818145472] [lifecycle_manager_navigation]: Creating bond timer...
23: [tester_node-18] [INFO] [1727973940.974425673] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727973941.929724922] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [tester_node-18] [INFO] [1727973941.930430196] [nav2_gps_waypoint_tester]: Goal accepted
23: [waypoint_follower-10] [INFO] [1727973941.930671591] [waypoint_follower]: Converted all 3 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727973941.930694617] [waypoint_follower]: Received follow waypoint request with 3 waypoints.
23: [tester_node-18] [INFO] [1727973941.930916200] [nav2_gps_waypoint_tester]: Waiting for 'follow_gps_waypoints' action to complete
23: [bt_navigator-9] [INFO] [1727973941.931326287] [bt_navigator]: Begin navigating from current location (0.00, 0.00) to (-0.05, 0.00)
23: [controller_server-5] [INFO] [1727973941.953093866] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [WARN] [1727973941.953166898] [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.
23: [controller_server-5] [WARN] [1727973941.953184760] [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.
23: [controller_server-5] [INFO] [1727973941.966338108] [controller_server]: Reached the goal!
23: [controller_server-5] [INFO] [1727973941.967606033] [controller_server]: Optimizer reset
23: [parameter_bridge-2] [INFO] [1727973941.991164052] [ros_gz_bridge]: Passing message from ROS geometry_msgs/msg/Twist to Gazebo gz.msgs.Twist (showing msg only once per type)
23: [bt_navigator-9] [INFO] [1727973941.991604526] [bt_navigator]: Goal succeeded
23: [waypoint_follower-10] [INFO] [1727973942.430814183] [waypoint_follower]: Succeeded processing waypoint 0, processing waypoint task execution
23: [waypoint_follower-10] [INFO] [1727973942.430853678] [waypoint_follower]: Arrived at 0'th waypoint, sleeping for 200 milliseconds
23: [waypoint_follower-10] [INFO] [1727973942.632589947] [waypoint_follower]: Task execution at waypoint 0 succeeded
23: [waypoint_follower-10] [INFO] [1727973942.632694319] [waypoint_follower]: Handled task execution on waypoint 0, moving to next.
23: [bt_navigator-9] [INFO] [1727973942.633630666] [bt_navigator]: Begin navigating from current location (-0.00, 0.00) to (-4.92, -1.24)
23: [controller_server-5] [INFO] [1727973942.655165120] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727973943.705317794] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973944.705315695] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973945.755350053] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973946.755319021] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973947.805370640] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973948.805349138] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973949.855351625] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973950.855373313] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973951.905320174] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973952.905356445] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973953.955349031] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973954.955353462] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973956.005316602] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973957.005314647] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973958.055345273] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973959.055354609] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973960.105352153] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973961.105350658] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973962.155318192] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973963.155318265] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973964.205317523] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973965.205335847] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973966.255326679] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973967.255370508] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973967.813812130] [controller_server]: Reached the goal!
23: [controller_server-5] [INFO] [1727973967.814673594] [controller_server]: Optimizer reset
23: [bt_navigator-9] [INFO] [1727973967.844072756] [bt_navigator]: Goal succeeded
23: [waypoint_follower-10] [INFO] [1727973968.532947166] [waypoint_follower]: Succeeded processing waypoint 1, processing waypoint task execution
23: [waypoint_follower-10] [INFO] [1727973968.532974863] [waypoint_follower]: Arrived at 1'th waypoint, sleeping for 200 milliseconds
23: [waypoint_follower-10] [INFO] [1727973968.732638386] [waypoint_follower]: Task execution at waypoint 1 succeeded
23: [waypoint_follower-10] [INFO] [1727973968.732674218] [waypoint_follower]: Handled task execution on waypoint 1, moving to next.
23: [bt_navigator-9] [INFO] [1727973968.733055024] [bt_navigator]: Begin navigating from current location (-4.81, -1.17) to (-4.15, -5.28)
23: [controller_server-5] [INFO] [1727973968.753675675] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727973969.803798866] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973970.853800034] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973971.853836108] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973972.903808022] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973973.903798458] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973974.953795016] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973975.953796845] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973977.003799619] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973978.003794654] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973979.053820290] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973980.053798189] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973981.103796685] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973982.103795936] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973983.153796395] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973984.153796576] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973985.203798085] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973986.203798210] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973987.253894527] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973987.466393466] [controller_server]: Reached the goal!
23: [controller_server-5] [INFO] [1727973987.466790092] [controller_server]: Optimizer reset
23: [bt_navigator-9] [INFO] [1727973987.493345666] [bt_navigator]: Goal succeeded
23: [waypoint_follower-10] [INFO] [1727973988.182852680] [waypoint_follower]: Succeeded processing waypoint 2, processing waypoint task execution
23: [waypoint_follower-10] [INFO] [1727973988.182884032] [waypoint_follower]: Arrived at 2'th waypoint, sleeping for 200 milliseconds
23: [waypoint_follower-10] [INFO] [1727973988.383303099] [waypoint_follower]: Task execution at waypoint 2 succeeded
23: [waypoint_follower-10] [INFO] [1727973988.383338346] [waypoint_follower]: Handled task execution on waypoint 2, moving to next.
23: [waypoint_follower-10] [INFO] [1727973988.383344744] [waypoint_follower]: Completed all 3 waypoints requested.
23: [tester_node-18] [INFO] [1727973988.388560283] [nav2_gps_waypoint_tester]: Goal succeeded!
23: [tester_node-18] [INFO] [1727973988.389176924] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727973988.389910862] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727973988.390416299] [waypoint_follower]: Converted all 1 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727973988.390435178] [waypoint_follower]: Received follow waypoint request with 1 waypoints.
23: [bt_navigator-9] [INFO] [1727973988.390752287] [bt_navigator]: Begin navigating from current location (-4.10, -5.17) to (-0.05, 0.00)
23: [tester_node-18] [INFO] [1727973988.403657274] [nav2_gps_waypoint_tester]: Goal accepted
23: [controller_server-5] [INFO] [1727973988.411425907] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727973989.461557843] [controller_server]: Passing new path to controller.
23: [tester_node-18] [INFO] [1727973990.404600036] [nav2_gps_waypoint_tester]: Sending goal request...
23: [tester_node-18] [INFO] [1727973990.418630122] [nav2_gps_waypoint_tester]: Goal accepted
23: [waypoint_follower-10] [INFO] [1727973990.440473821] [waypoint_follower]: Preempting the goal pose.
23: [waypoint_follower-10] [INFO] [1727973990.440565248] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727973990.440887749] [waypoint_follower]: Converted all 1 GPS waypoint to map frame
23: [bt_navigator-9] [INFO] [1727973990.441429353] [bt_navigator]: Received goal preemption request
23: [bt_navigator-9] [INFO] [1727973990.441550149] [bt_navigator]: Begin navigating from current location (-4.00, -5.14) to (-4.92, -1.24)
23: [controller_server-5] [INFO] [1727973990.461557533] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973991.511562458] [controller_server]: Passing new path to controller.
23: [waypoint_follower-10] [WARN] [1727973992.440826058] [waypoint_follower]: [follow_gps_waypoints] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [bt_navigator-9] [ERROR] [1727973992.461332372] [bt_navigator_navigate_to_pose_rclcpp_node]: Failed to get result for follow_path in node halt!
23: [bt_navigator-9] [WARN] [1727973992.461490851] [bt_navigator]: [navigate_to_pose] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [bt_navigator-9] [INFO] [1727973992.461594201] [bt_navigator]: Goal canceled
23: [controller_server-5] [INFO] [1727973992.461558584] [controller_server]: Cancellation was successful. Stopping the robot.
23: [controller_server-5] [WARN] [1727973992.461589234] [controller_server]: [follow_path] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [controller_server-5] [INFO] [1727973992.462159960] [controller_server]: Optimizer reset
23: [tester_node-18] [INFO] [1727973994.445405671] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727973994.445761902] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727973994.446122581] [waypoint_follower]: Converted all 1 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727973994.446137560] [waypoint_follower]: Received follow waypoint request with 1 waypoints.
23: [bt_navigator-9] [INFO] [1727973994.446392477] [bt_navigator]: Begin navigating from current location (-3.77, -4.74) to (94.04, -1674.69)
23: [planner_server-7] [WARN] [1727973994.446805085] [planner_server]: GridBased plugin failed to plan from (-3.77, -4.74) to (94.04, -1674.69): "Goal Coordinates of(94.042922, -1674.689924) was outside bounds"
23: [planner_server-7] [WARN] [1727973994.446849937] [planner_server]: [compute_path_to_pose] [ActionServer] Aborting handle.
23: [tester_node-18] [INFO] [1727973994.459107337] [nav2_gps_waypoint_tester]: Goal accepted
23: [tester_node-18] [INFO] [1727973994.459694743] [nav2_gps_waypoint_tester]: Waiting for 'follow_gps_waypoints' action to complete
23: [bt_navigator-9] [WARN] [1727973994.476570215] [bt_navigator]: [navigate_to_pose] [ActionServer] Aborting handle.
23: [bt_navigator-9] [ERROR] [1727973994.476645148] [bt_navigator]: Goal failed
23: [waypoint_follower-10] [INFO] [1727973994.846254130] [waypoint_follower]: Failed to process waypoint 0, moving to next.
23: [waypoint_follower-10] [INFO] [1727973994.846302876] [waypoint_follower]: Completed all 1 waypoints requested.
23: [tester_node-18] [INFO] [1727973994.852536333] [nav2_gps_waypoint_tester]: Goal failed to process all waypoints, missed 1 wps.
23: [tester_node-18] [INFO] [1727973994.867640234] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727973994.867983227] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727973994.868757188] [waypoint_follower]: Converted all 3 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727973994.868779791] [waypoint_follower]: Received follow waypoint request with 3 waypoints.
23: [bt_navigator-9] [INFO] [1727973994.869076598] [bt_navigator]: Begin navigating from current location (-3.77, -4.74) to (-0.05, 0.00)
23: [tester_node-18] [INFO] [1727973994.879546167] [nav2_gps_waypoint_tester]: Goal accepted
23: [tester_node-18] [INFO] [1727973994.879952684] [nav2_gps_waypoint_tester]: Waiting for 'follow_gps_waypoints' action to complete
23: [controller_server-5] [INFO] [1727973994.889702948] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727973995.939820947] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973996.989815872] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973997.989816409] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727973999.039818310] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974000.039843813] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974001.089816619] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974002.089818066] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974003.139819184] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974004.139817665] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974005.189872183] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974006.189820377] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974007.240040122] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974008.240054331] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974009.289817296] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974010.289821091] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974011.339815801] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974012.339877188] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974013.389869719] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974014.389868484] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974015.440124695] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974016.439817298] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974017.489820161] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974018.539819612] [controller_server]: Passing new path to controller.
23: [controller_server-5] [INFO] [1727974019.147862353] [controller_server]: Reached the goal!
23: [controller_server-5] [INFO] [1727974019.148543856] [controller_server]: Optimizer reset
23: [bt_navigator-9] [INFO] [1727974019.169736938] [bt_navigator]: Goal succeeded
23: [waypoint_follower-10] [INFO] [1727974019.818882284] [waypoint_follower]: Succeeded processing waypoint 0, processing waypoint task execution
23: [waypoint_follower-10] [INFO] [1727974019.818912938] [waypoint_follower]: Arrived at 0'th waypoint, sleeping for 200 milliseconds
23: [waypoint_follower-10] [INFO] [1727974020.019919216] [waypoint_follower]: Task execution at waypoint 0 succeeded
23: [waypoint_follower-10] [INFO] [1727974020.019953159] [waypoint_follower]: Handled task execution on waypoint 0, moving to next.
23: [bt_navigator-9] [INFO] [1727974020.020404158] [bt_navigator]: Begin navigating from current location (0.01, -0.12) to (94.04, -1674.69)
23: [planner_server-7] [WARN] [1727974020.020898111] [planner_server]: GridBased plugin failed to plan from (0.01, -0.12) to (94.04, -1674.69): "Goal Coordinates of(94.042922, -1674.689924) was outside bounds"
23: [planner_server-7] [WARN] [1727974020.020953022] [planner_server]: [compute_path_to_pose] [ActionServer] Aborting handle.
23: [bt_navigator-9] [WARN] [1727974020.040567155] [bt_navigator]: [navigate_to_pose] [ActionServer] Aborting handle.
23: [bt_navigator-9] [ERROR] [1727974020.040686578] [bt_navigator]: Goal failed
23: [waypoint_follower-10] [WARN] [1727974020.321391947] [waypoint_follower]: Failed to process waypoint 1 in waypoint list and stop on failure is enabled. Terminating action.
23: [waypoint_follower-10] [WARN] [1727974020.321433502] [waypoint_follower]: [follow_gps_waypoints] [ActionServer] Aborting handle.
23: [tester_node-18] [INFO] [1727974020.329796674] [nav2_gps_waypoint_tester]: Goal failed with status code: 6
23: [tester_node-18] [INFO] [1727974020.351632560] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727974020.351973728] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727974020.352012042] [waypoint_follower]: Converted all 0 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727974020.352022284] [waypoint_follower]: Received follow waypoint request with 0 waypoints.
23: [waypoint_follower-10] [ERROR] [1727974020.352027055] [waypoint_follower]: Empty vector of waypoints passed to waypoint following action potentially due to conversation failure or empty request.
23: [waypoint_follower-10] [WARN] [1727974020.352063166] [waypoint_follower]: [follow_gps_waypoints] [ActionServer] Aborting handle.
23: [tester_node-18] [INFO] [1727974020.373107062] [nav2_gps_waypoint_tester]: Goal accepted
23: [tester_node-18] [INFO] [1727974020.373608497] [nav2_gps_waypoint_tester]: Waiting for 'follow_gps_waypoints' action to complete
23: [tester_node-18] [INFO] [1727974020.395016920] [nav2_gps_waypoint_tester]: Goal failed with status code: 6
23: [tester_node-18] [INFO] [1727974020.395820021] [nav2_gps_waypoint_tester]: Sending goal request...
23: [waypoint_follower-10] [INFO] [1727974020.396258973] [waypoint_follower]: Converting GPS waypoints to map Frame..
23: [waypoint_follower-10] [INFO] [1727974020.396977827] [waypoint_follower]: Converted all 3 GPS waypoint to map frame
23: [waypoint_follower-10] [INFO] [1727974020.396995879] [waypoint_follower]: Received follow waypoint request with 3 waypoints.
23: [bt_navigator-9] [INFO] [1727974020.397224869] [bt_navigator]: Begin navigating from current location (0.01, -0.12) to (-0.05, 0.00)
23: [tester_node-18] [INFO] [1727974020.415833937] [nav2_gps_waypoint_tester]: Goal accepted
23: [controller_server-5] [INFO] [1727974020.417730122] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727974020.426849792] [controller_server]: Reached the goal!
23: [controller_server-5] [INFO] [1727974020.427337536] [controller_server]: Optimizer reset
23: [bt_navigator-9] [INFO] [1727974020.447417515] [bt_navigator]: Goal succeeded
23: [waypoint_follower-10] [INFO] [1727974020.847102137] [waypoint_follower]: Succeeded processing waypoint 0, processing waypoint task execution
23: [waypoint_follower-10] [INFO] [1727974020.847129649] [waypoint_follower]: Arrived at 0'th waypoint, sleeping for 200 milliseconds
23: [waypoint_follower-10] [INFO] [1727974021.049774318] [waypoint_follower]: Task execution at waypoint 0 succeeded
23: [waypoint_follower-10] [INFO] [1727974021.049811459] [waypoint_follower]: Handled task execution on waypoint 0, moving to next.
23: [bt_navigator-9] [INFO] [1727974021.050242932] [bt_navigator]: Begin navigating from current location (0.01, -0.12) to (-4.92, -1.24)
23: [controller_server-5] [INFO] [1727974021.070870985] [controller_server]: Received a goal, begin computing control effort.
23: [controller_server-5] [INFO] [1727974022.121058644] [controller_server]: Passing new path to controller.
23: [tester_node-18] [INFO] [1727974022.440928733] [nav2_gps_waypoint_tester]: Waiting for 'follow_gps_waypoints' action to complete
23: [waypoint_follower-10] [WARN] [1727974022.453666085] [waypoint_follower]: [follow_gps_waypoints] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [tester_node-18] [INFO] [1727974022.464669628] [nav2_gps_waypoint_tester]: Goal failed with status code: 5
23: [tester_node-18] [INFO] [1727974022.465017925] [nav2_gps_waypoint_tester]: Shutting down
23: [tester_node-18] [INFO] [1727974022.465343303] [nav2_gps_waypoint_tester]: Destroyed follow_gps_waypoints action client
23: [lifecycle_manager-14] [INFO] [1727974022.467046768] [lifecycle_manager_navigation]: Terminating bond timer...
23: [lifecycle_manager-14] [INFO] [1727974022.467078629] [lifecycle_manager_navigation]: Shutting down managed nodes...
23: [lifecycle_manager-14] [INFO] [1727974022.467089879] [lifecycle_manager_navigation]: Deactivate, cleanup, and shutdown nodes
23: [lifecycle_manager-14] [INFO] [1727974022.467098085] [lifecycle_manager_navigation]: Deactivating docking_server
23: [opennav_docking-13] [INFO] [1727974022.467605193] [docking_server]: Deactivating docking_server
23: [controller_server-5] [INFO] [1727974022.471069358] [controller_server]: Cancellation was successful. Stopping the robot.
23: [controller_server-5] [WARN] [1727974022.471128147] [controller_server]: [follow_path] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [bt_navigator-9] [WARN] [1727974022.471704971] [bt_navigator]: [navigate_to_pose] [ActionServer] Client requested to cancel the goal. Cancelling.
23: [bt_navigator-9] [INFO] [1727974022.471964263] [bt_navigator]: Goal canceled
23: [controller_server-5] [INFO] [1727974022.472961413] [controller_server]: Optimizer reset
23: [opennav_docking-13] [INFO] [1727974022.477283610] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974022.589963848] [lifecycle_manager_navigation]: Deactivating waypoint_follower
23: [waypoint_follower-10] [INFO] [1727974022.590319970] [waypoint_follower]: Deactivating
23: [waypoint_follower-10] [INFO] [1727974022.590365415] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974022.702275223] [lifecycle_manager_navigation]: Deactivating bt_navigator
23: [bt_navigator-9] [INFO] [1727974022.702497142] [bt_navigator]: Deactivating
23: [bt_navigator-9] [INFO] [1727974022.702550607] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974022.814978246] [lifecycle_manager_navigation]: Deactivating collision_monitor
23: [collision_monitor-12] [INFO] [1727974022.815269554] [collision_monitor]: Deactivating
23: [collision_monitor-12] [INFO] [1727974022.815298829] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974022.926927589] [lifecycle_manager_navigation]: Deactivating velocity_smoother
23: [velocity_smoother-11] [INFO] [1727974022.927156811] [velocity_smoother]: Deactivating
23: [velocity_smoother-11] [INFO] [1727974022.927184282] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974023.038627857] [lifecycle_manager_navigation]: Deactivating behavior_server
23: [behavior_server-8] [INFO] [1727974023.039269162] [behavior_server]: Deactivating
23: [behavior_server-8] [INFO] [1727974023.039365190] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974023.151196198] [lifecycle_manager_navigation]: Deactivating planner_server
23: [planner_server-7] [INFO] [1727974023.151504945] [planner_server]: Deactivating
23: [planner_server-7] [INFO] [1727974023.151550956] [global_costmap.global_costmap]: Deactivating
23: [planner_server-7] [INFO] [1727974023.959146269] [planner_server]: Deactivating plugin GridBased of type NavfnPlanner
23: [planner_server-7] [INFO] [1727974023.959201323] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974024.071199287] [lifecycle_manager_navigation]: Deactivating smoother_server
23: [smoother_server-6] [INFO] [1727974024.071501579] [smoother_server]: Deactivating
23: [smoother_server-6] [INFO] [1727974024.071539387] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974024.183351705] [lifecycle_manager_navigation]: Deactivating controller_server
23: [controller_server-5] [INFO] [1727974024.183671269] [controller_server]: Deactivating
23: [controller_server-5] [INFO] [1727974024.183712125] [MPPIController]: Deactivated MPPI Controller: FollowPath
23: [controller_server-5] [INFO] [1727974024.183724623] [local_costmap.local_costmap]: Deactivating
23: [controller_server-5] [INFO] [1727974024.348013109] [controller_server]: Optimizer reset
23: [controller_server-5] [INFO] [1727974024.348057944] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
23: [lifecycle_manager-14] [INFO] [1727974024.459932596] [lifecycle_manager_navigation]: Cleaning up docking_server
23: [opennav_docking-13] [INFO] [1727974024.460247463] [docking_server]: Cleaning up docking_server
23: [lifecycle_manager-14] [INFO] [1727974024.467939327] [lifecycle_manager_navigation]: Cleaning up waypoint_follower
23: [waypoint_follower-10] [INFO] [1727974024.468218626] [waypoint_follower]: Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.477390332] [lifecycle_manager_navigation]: Cleaning up bt_navigator
23: [bt_navigator-9] [INFO] [1727974024.477971411] [bt_navigator]: Cleaning up
23: [bt_navigator-9] [INFO] [1727974024.541357912] [bt_navigator]: Completed Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.551820049] [lifecycle_manager_navigation]: Cleaning up collision_monitor
23: [collision_monitor-12] [INFO] [1727974024.552046222] [collision_monitor]: Cleaning up
23: [collision_monitor-12] [INFO] [1727974024.552072354] [collision_monitor]: [FootprintApproach]: Destroying Polygon
23: [collision_monitor-12] [INFO] [1727974024.552082761] [collision_monitor]: [scan]: Destroying Scan
23: [lifecycle_manager-14] [INFO] [1727974024.558840774] [lifecycle_manager_navigation]: Cleaning up velocity_smoother
23: [velocity_smoother-11] [INFO] [1727974024.559119853] [velocity_smoother]: Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.560398514] [lifecycle_manager_navigation]: Cleaning up behavior_server
23: [behavior_server-8] [INFO] [1727974024.560834988] [behavior_server]: Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.586707594] [lifecycle_manager_navigation]: Cleaning up planner_server
23: [planner_server-7] [INFO] [1727974024.586968651] [planner_server]: Cleaning up
23: [planner_server-7] [INFO] [1727974024.594744928] [global_costmap.global_costmap]: Cleaning up
23: [planner_server-7] [INFO] [1727974024.598438512] [planner_server]: Cleaning up plugin GridBased of type NavfnPlanner
23: [planner_server-7] [INFO] [1727974024.598492053] [planner_server]: Destroying plugin GridBased of type NavfnPlanner
23: [lifecycle_manager-14] [INFO] [1727974024.606162242] [lifecycle_manager_navigation]: Cleaning up smoother_server
23: [smoother_server-6] [INFO] [1727974024.606315151] [smoother_server]: Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.614164844] [lifecycle_manager_navigation]: Cleaning up controller_server
23: [controller_server-5] [INFO] [1727974024.614331409] [controller_server]: Cleaning up
23: [controller_server-5] [INFO] [1727974024.617237084] [MPPIController]: Cleaned up MPPI Controller: FollowPath
23: [controller_server-5] [INFO] [1727974024.617608597] [local_costmap.local_costmap]: Cleaning up
23: [lifecycle_manager-14] [INFO] [1727974024.634270173] [lifecycle_manager_navigation]: Shutting down docking_server
23: [opennav_docking-13] [INFO] [1727974024.634421816] [docking_server]: Shutting down docking_server
23: [lifecycle_manager-14] [INFO] [1727974024.634620395] [lifecycle_manager_navigation]: Shutting down waypoint_follower
23: [waypoint_follower-10] [INFO] [1727974024.634818363] [waypoint_follower]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.635037600] [lifecycle_manager_navigation]: Shutting down bt_navigator
23: [bt_navigator-9] [INFO] [1727974024.635161953] [bt_navigator]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.635327142] [lifecycle_manager_navigation]: Shutting down collision_monitor
23: [collision_monitor-12] [INFO] [1727974024.635447809] [collision_monitor]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.635625342] [lifecycle_manager_navigation]: Shutting down velocity_smoother
23: [velocity_smoother-11] [INFO] [1727974024.635735515] [velocity_smoother]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.635882375] [lifecycle_manager_navigation]: Shutting down behavior_server
23: [behavior_server-8] [INFO] [1727974024.635987272] [behavior_server]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.636151006] [lifecycle_manager_navigation]: Shutting down planner_server
23: [planner_server-7] [INFO] [1727974024.636262780] [planner_server]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.636417450] [lifecycle_manager_navigation]: Shutting down smoother_server
23: [smoother_server-6] [INFO] [1727974024.636530800] [smoother_server]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.636690005] [lifecycle_manager_navigation]: Shutting down controller_server
23: [controller_server-5] [INFO] [1727974024.636808924] [controller_server]: Shutting down
23: [lifecycle_manager-14] [INFO] [1727974024.636971759] [lifecycle_manager_navigation]: Destroying lifecycle service clients
23: [lifecycle_manager-14] [INFO] [1727974024.646233430] [lifecycle_manager_navigation]: Managed nodes have been shut down
23: [tester_node-18] [INFO] [1727974024.654862738] [nav2_gps_waypoint_tester]: lifecycle_manager_navigation/manage_nodes finished
23: [tester_node-18] [INFO] [1727974024.655167234] [nav2_gps_waypoint_tester]: Done Shutting Down.
23: [tester_node-18] [INFO] [1727974024.655444350] [nav2_gps_waypoint_tester]: Exiting passed
23: [INFO] [tester_node-18]: process has finished cleanly [pid 5257]
23: [INFO] [navsat_transform_node-17]: sending signal 'SIGINT' to process[navsat_transform_node-17]
23: [INFO] [ekf_node-16]: sending signal 'SIGINT' to process[ekf_node-16]
23: [INFO] [ekf_node-15]: sending signal 'SIGINT' to process[ekf_node-15]
23: [INFO] [lifecycle_manager-14]: sending signal 'SIGINT' to process[lifecycle_manager-14]
23: [INFO] [opennav_docking-13]: sending signal 'SIGINT' to process[opennav_docking-13]
23: [INFO] [collision_monitor-12]: sending signal 'SIGINT' to process[collision_monitor-12]
23: [INFO] [velocity_smoother-11]: sending signal 'SIGINT' to process[velocity_smoother-11]
23: [INFO] [waypoint_follower-10]: sending signal 'SIGINT' to process[waypoint_follower-10]
23: [INFO] [bt_navigator-9]: sending signal 'SIGINT' to process[bt_navigator-9]
23: [INFO] [behavior_server-8]: sending signal 'SIGINT' to process[behavior_server-8]
23: [INFO] [planner_server-7]: sending signal 'SIGINT' to process[planner_server-7]
23: [INFO] [smoother_server-6]: sending signal 'SIGINT' to process[smoother_server-6]
23: [INFO] [controller_server-5]: sending signal 'SIGINT' to process[controller_server-5]
23: [INFO] [robot_state_publisher-4]: sending signal 'SIGINT' to process[robot_state_publisher-4]
23: [INFO] [parameter_bridge-2]: sending signal 'SIGINT' to process[parameter_bridge-2]
23: [INFO] [gz-1]: sending signal 'SIGINT' to process[gz-1]
23: [navsat_transform_node-17] [INFO] [1727974024.831899744] [rclcpp]: signal_handler(signum=2)
23: [ekf_node-16] [INFO] [1727974024.834163771] [rclcpp]: signal_handler(signum=2)
23: [ekf_node-15] [INFO] [1727974024.836661773] [rclcpp]: signal_handler(signum=2)
23: [lifecycle_manager-14] [INFO] [1727974024.839528207] [rclcpp]: signal_handler(signum=2)
23: [lifecycle_manager-14] [INFO] [1727974024.839625239] [lifecycle_manager_navigation]: Running Nav2 LifecycleManager rcl preshutdown (lifecycle_manager_navigation)
23: [opennav_docking-13] [INFO] [1727974024.842716263] [rclcpp]: signal_handler(signum=2)
23: [opennav_docking-13] [INFO] [1727974024.845505571] [docking_server]: Running Nav2 LifecycleNode rcl preshutdown (docking_server)
23: [opennav_docking-13] [INFO] [1727974024.845557708] [docking_server]: Destroying bond (docking_server) to lifecycle manager.
23: [opennav_docking-13] [INFO] [1727974024.846798478] [docking_server]: Destroying
23: [collision_monitor-12] [INFO] [1727974024.845826575] [rclcpp]: signal_handler(signum=2)
23: [collision_monitor-12] [INFO] [1727974024.845880591] [collision_monitor]: Running Nav2 LifecycleNode rcl preshutdown (collision_monitor)
23: [collision_monitor-12] [INFO] [1727974024.845918211] [collision_monitor]: Destroying bond (collision_monitor) to lifecycle manager.
23: [collision_monitor-12] [INFO] [1727974024.847295339] [collision_monitor]: Destroying
23: [velocity_smoother-11] [INFO] [1727974024.848684625] [rclcpp]: signal_handler(signum=2)
23: [velocity_smoother-11] [INFO] [1727974024.848822822] [velocity_smoother]: Running Nav2 LifecycleNode rcl preshutdown (velocity_smoother)
23: [velocity_smoother-11] [INFO] [1727974024.848886945] [velocity_smoother]: Destroying bond (velocity_smoother) to lifecycle manager.
23: [velocity_smoother-11] [INFO] [1727974024.849790592] [velocity_smoother]: Destroying
23: [lifecycle_manager-14] [INFO] [1727974024.848872257] [lifecycle_manager_navigation]: Destroying lifecycle_manager_navigation
23: [waypoint_follower-10] [INFO] [1727974024.852324688] [rclcpp]: signal_handler(signum=2)
23: [waypoint_follower-10] [INFO] [1727974024.852390755] [waypoint_follower]: Running Nav2 LifecycleNode rcl preshutdown (waypoint_follower)
23: [waypoint_follower-10] [INFO] [1727974024.852432446] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
23: [waypoint_follower-10] [INFO] [1727974024.854611036] [waypoint_follower]: Destroying
23: [bt_navigator-9] [INFO] [1727974024.855329346] [rclcpp]: signal_handler(signum=2)
23: [bt_navigator-9] [INFO] [1727974024.855409523] [bt_navigator]: Running Nav2 LifecycleNode rcl preshutdown (bt_navigator)
23: [bt_navigator-9] [INFO] [1727974024.855451770] [bt_navigator]: Destroying bond (bt_navigator) to lifecycle manager.
23: [bt_navigator-9] [INFO] [1727974024.857213956] [bt_navigator]: Destroying
23: [behavior_server-8] [INFO] [1727974024.859740811] [rclcpp]: signal_handler(signum=2)
23: [behavior_server-8] [INFO] [1727974024.859806550] [behavior_server]: Running Nav2 LifecycleNode rcl preshutdown (behavior_server)
23: [behavior_server-8] [INFO] [1727974024.859849655] [behavior_server]: Destroying bond (behavior_server) to lifecycle manager.
23: [behavior_server-8] [INFO] [1727974024.861971939] [behavior_server]: Destroying
23: [planner_server-7] [INFO] [1727974024.863467701] [rclcpp]: signal_handler(signum=2)
23: [planner_server-7] [INFO] [1727974024.863542487] [planner_server]: Running Nav2 LifecycleNode rcl preshutdown (planner_server)
23: [planner_server-7] [INFO] [1727974024.863581355] [planner_server]: Destroying bond (planner_server) to lifecycle manager.
23: [smoother_server-6] [INFO] [1727974024.867592826] [rclcpp]: signal_handler(signum=2)
23: [smoother_server-6] [INFO] [1727974024.867669451] [smoother_server]: Running Nav2 LifecycleNode rcl preshutdown (smoother_server)
23: [smoother_server-6] [INFO] [1727974024.867712044] [smoother_server]: Destroying bond (smoother_server) to lifecycle manager.
23: [smoother_server-6] [INFO] [1727974024.869059630] [smoother_server]: Destroying
23: [controller_server-5] [INFO] [1727974024.871030130] [rclcpp]: signal_handler(signum=2)
23: [controller_server-5] [INFO] [1727974024.871603596] [controller_server]: Running Nav2 LifecycleNode rcl preshutdown (controller_server)
23: [controller_server-5] [INFO] [1727974024.871667889] [controller_server]: Destroying bond (controller_server) to lifecycle manager.
23: [robot_state_publisher-4] [INFO] [1727974024.875770435] [rclcpp]: signal_handler(signum=2)
23: [planner_server-7] [INFO] [1727974024.879162256] [global_costmap.global_costmap]: Destroying
23: [parameter_bridge-2] [INFO] [1727974024.879580160] [rclcpp]: signal_handler(signum=2)
23: [controller_server-5] [INFO] [1727974024.882098062] [local_costmap.local_costmap]: Destroying
23: [controller_server-5] [INFO] [1727974024.897746994] [controller_server]: Destroying
23: [planner_server-7] [INFO] [1727974024.899753242] [planner_server]: Destroying
23: [INFO] [gz-1]: process has finished cleanly [pid 5234]
23: [INFO] [navsat_transform_node-17]: process has finished cleanly [pid 5256]
23: [INFO] [ekf_node-16]: process has finished cleanly [pid 5255]
23: [INFO] [collision_monitor-12]: process has finished cleanly [pid 5245]
23: [INFO] [lifecycle_manager-14]: process has finished cleanly [pid 5249]
23: [INFO] [ekf_node-15]: process has finished cleanly [pid 5254]
23: [INFO] [waypoint_follower-10]: process has finished cleanly [pid 5243]
23: [INFO] [opennav_docking-13]: process has finished cleanly [pid 5246]
23: [INFO] [velocity_smoother-11]: process has finished cleanly [pid 5244]
23: [INFO] [smoother_server-6]: process has finished cleanly [pid 5239]
23: [INFO] [parameter_bridge-2]: process has finished cleanly [pid 5235]
23: [INFO] [bt_navigator-9]: process has finished cleanly [pid 5242]
23: [INFO] [behavior_server-8]: process has finished cleanly [pid 5241]
23: [INFO] [robot_state_publisher-4]: process has finished cleanly [pid 5237]
23: [INFO] [controller_server-5]: process has finished cleanly [pid 5238]
23: [INFO] [planner_server-7]: process has finished cleanly [pid 5240]
23: -- run_test.py: return code 0
23: -- run_test.py: generate result file '/opt/overlay_ws/build/nav2_system_tests/test_results/nav2_system_tests/test_gps_waypoint_follower.xml' with successful test
23/32 Test #23: test_gps_waypoint_follower ...............   Passed   95.17 sec

@SteveMacenski
Copy link
Member

23/32 Test #23: test_gps_waypoint_follower ............... Passed 95.17 sec

This passed, I'm confused as to the issue (unless that wasn't run in CI?)

I'm seeing in the CI job that the min tb3 sim package is being built https://app.circleci.com/pipelines/github/ros-navigation/navigation2/12760/workflows/77329837-abfa-4597-90f3-c61db97f1b56/jobs/38504 in the 'build workspace /opt/underlay' step.

The post checkout step says:

=== /opt/underlay_ws/src/ros-navigation/nav2_minimal_turtlebot_simulation (git) ===
From ssh://github.com/ros-navigation/nav2_minimal_turtlebot_simulation
   f4eefd0..f0eeedb  main       -> origin/main
Previous HEAD position was 6b64127 bump to 1.0.1 for release of multirobot TB3 working (#12)
Switched to branch 'main'
Your branch is behind 'origin/main' by 1 commit, and can be fast-forwarded.
  (use "git pull" to update your local branch)

It looks like its behind your last commit?

@SteveMacenski
Copy link
Member

@ruffsl can you give us a hand here for a few minutes?

@ruffsl
Copy link
Member

ruffsl commented Oct 3, 2024

Looks like the test case referenced above is passing:

<testsuite name="nav2_system_tests" tests="1" failures="0" time="97.241" errors="0" skipped="0">
<testcase classname="nav2_system_tests" name="test_gps_waypoint_follower.missing_result" time="97.241"> </testcase>
</testsuite>

Only this seemed to fail:

test_docking_server.TestDockingServer.test_docking_server failed
===================================================================================================================================
FAIL: test_docking_server.TestDockingServer.test_docking_server
-----------------------------------------------------------------------------------------------------------------------------------
Traceback (most recent call last):
  File "/opt/overlay_ws/src/navigation2/nav2_docking/opennav_docking/test/test_docking_server.py", line 209, in test_docking_server
    self.assertEqual(self.action_result[0].status, GoalStatus.STATUS_ABORTED)
AssertionError: 4 != 6

But perhaps is just being flaky:

image

@SteveMacenski
Copy link
Member

Rerunning - likely just a fluke! Thanks @ruffsl! I'm curious why changing from 1.0.1 to main didn't break the underlay with a new v27 cache version but the hash did.

@ruffsl
Copy link
Member

ruffsl commented Oct 3, 2024

I'm curious why changing from 1.0.1 to main didn't break the underlay with a new v27 cache version but the hash did.

Umm, was the hash of that repos file with the diff set to main used before in this PR? If so, it may not have invalidated the cache, and restored from a previous cache.

From a underlay cache perspective, these two subsequent commits look the same:

Currently a simple comparison is used to decide if the repos file has changed, and if a re-import is needed:

if ! cmp \
$OVERLAY_WS/src/navigation2/tools/underlay.repos \
$UNDERLAY_WS/underlay.repos >/dev/null 2>&1

Copy link

codecov bot commented Oct 3, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

see 10 files with indirect coverage changes

@SteveMacenski
Copy link
Member

set to main used before in this PR

No, it was set to 1.0.1 before, I asked him to change it to main for the purposes of pulling in main for the scope of this PR

@SteveMacenski SteveMacenski merged commit 4e62a89 into ros-navigation:main Oct 4, 2024
10 of 11 checks passed
@SteveMacenski
Copy link
Member

Thank you so much @stevedanomodolor for your great work here! This is greatly appreciated!

Let me know how your hunt is going and if I can be of help :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants