Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

Frequent Nav2 smoother_server timeout (and no global costmap) on repeated navigation launches #555

Open
slowrunner opened this issue Feb 23, 2025 · 2 comments
Open

Frequent Nav2 smoother_server timeout (and no global costmap) on repeated navigation launches #555

slowrunner opened this issue Feb 23, 2025 · 2 comments
Assignees
@RustyCPR @smatarCPR
Labels
troubleshooting System not working as expected, may be user error.

Comments

@slowrunner
Copy link

slowrunner commented Feb 23, 2025 •
edited
Loading

Robot Model

Turtlebot4 Lite

ROS distro

Jazzy

Networking Configuration

Discovery Server

OS

Ubuntu 24.04

Built from source or installed?

Built from Source

Package version

turtlebot4/turtlebot4 dc744fe
turtlebot4/turtlebot4_robot 28e115f

MODEL:lite ││ VERSION:2.0.2 ││ ROS:Jazzy ││ HOSTNAME:turtlebot4

Nav2:

ubuntu@TB5WaLI:~/TB5-WaLI/wali_ws$ dpkg -l | grep nav2
ii  ros-jazzy-nav2-amcl                              1.3.4-1noble.20250124.133806            arm64        amcl is a probabilistic localization system for a robot moving in 2D.
ii  ros-jazzy-nav2-behavior-tree                     1.3.4-1noble.20250124.133719            arm64        Nav2 behavior tree wrappers, nodes, and utilities
ii  ros-jazzy-nav2-behaviors                         1.3.4-1noble.20250124.140546            arm64        Nav2 behavior server
ii  ros-jazzy-nav2-bringup                           1.3.4-1noble.20250202.030606            arm64        Bringup scripts and configurations for the Nav2 stack
ii  ros-jazzy-nav2-bt-navigator                      1.3.4-1noble.20250124.140450            arm64        Nav2 BT Navigator Server
ii  ros-jazzy-nav2-collision-monitor                 1.3.4-1noble.20250124.135321            arm64        Collision Monitor
ii  ros-jazzy-nav2-common                            1.3.4-1noble.20241228.023417            arm64        Common support functionality used throughout the navigation 2 stack
ii  ros-jazzy-nav2-constrained-smoother              1.3.4-1noble.20250124.140642            arm64        Ceres constrained smoother
ii  ros-jazzy-nav2-controller                        1.3.4-1noble.20250124.140727            arm64        Controller action interface
ii  ros-jazzy-nav2-core                              1.3.4-1noble.20250124.140110            arm64        A set of headers for plugins core to the Nav2 stack
ii  ros-jazzy-nav2-costmap-2d                        1.3.4-1noble.20250124.133850            arm64        This package provides an implementation of a 2D costmap that takes in sensor data from the world, builds a 2D or 3D occupancy grid of the data (depending on whether a voxel based implementation is used), and inflates costs in a 2D costmap based on the occupancy grid and a user specified inflation radius.
ii  ros-jazzy-nav2-dwb-controller                    1.3.4-1noble.20250124.141607            arm64        ROS2 controller (DWB) metapackage
ii  ros-jazzy-nav2-graceful-controller               1.3.4-1noble.20250124.140853            arm64        Graceful motion controller
ii  ros-jazzy-nav2-lifecycle-manager                 1.3.4-1noble.20250124.133541            arm64        A controller/manager for the lifecycle nodes of the Navigation 2 system
ii  ros-jazzy-nav2-map-server                        1.3.4-1noble.20250124.134126            arm64        Refactored map server for ROS2 Navigation
ii  ros-jazzy-nav2-minimal-tb3-sim                   1.0.1-1noble.20250117.052748            arm64        Nav2 Minimum TurtleBot3 Simulation
ii  ros-jazzy-nav2-minimal-tb4-description           1.0.1-1noble.20250115.220908            arm64        Nav2's minimum Turtlebot4 Description package
ii  ros-jazzy-nav2-minimal-tb4-sim                   1.0.1-1noble.20250117.052747            arm64        Nav2 Minimum TurtleBot4 Simulation
ii  ros-jazzy-nav2-mppi-controller                   1.3.4-1noble.20250124.141035            arm64        nav2_mppi_controller
ii  ros-jazzy-nav2-msgs                              1.3.4-1noble.20241228.023703            arm64        Messages and service files for the Nav2 stack
ii  ros-jazzy-nav2-navfn-planner                     1.3.4-1noble.20250124.141054            arm64        Nav2 NavFn planner
ii  ros-jazzy-nav2-planner                           1.3.4-1noble.20250124.141052            arm64        Nav2 planner server package
ii  ros-jazzy-nav2-regulated-pure-pursuit-controller 1.3.4-1noble.20250124.141228            arm64        Regulated Pure Pursuit Controller
ii  ros-jazzy-nav2-rotation-shim-controller          1.3.4-1noble.20250124.141346            arm64        Rotation Shim Controller
ii  ros-jazzy-nav2-rviz-plugins                      1.3.4-1noble.20250124.133917            arm64        Navigation 2 plugins for rviz
ii  ros-jazzy-nav2-simple-commander                  1.3.4-1noble.20241228.024908            arm64        An importable library for writing mobile robot applications in python3
ii  ros-jazzy-nav2-smac-planner                      1.3.4-1noble.20250124.141349            arm64        Smac global planning plugin: A*, Hybrid-A*, State Lattice
ii  ros-jazzy-nav2-smoother                          1.3.4-1noble.20250124.141354            arm64        Smoother action interface
ii  ros-jazzy-nav2-theta-star-planner                1.3.4-1noble.20250124.141416            arm64        Theta* Global Planning Plugin
ii  ros-jazzy-nav2-util                              1.3.4-1noble.20250124.133118            arm64        Nav2 utilities
ii  ros-jazzy-nav2-velocity-smoother                 1.3.4-1noble.20250124.134246            arm64        Nav2's Output velocity smoother
ii  ros-jazzy-nav2-voxel-grid                        1.3.4-1noble.20241228.024344            arm64        voxel_grid provides an implementation of an efficient 3D voxel grid.
ii  ros-jazzy-nav2-waypoint-follower                 1.3.4-1noble.20250124.141420            arm64        A waypoint follower navigation server

Type of issue

Navigation (SLAM, Nav2 etc.)

Expected behaviour

Nav2 launch will start all required nodes successfully, every time

Actual behaviour

First time running navigation, (after a cold boot), seems to always succeed launching all nodes and navigating well.

For subsequent navigation launches, local cost map will be published, but global cost map will not.

I often have to ctrl-c, and restart navigation multiple times before both global cost map will appear and navigation will respond to a goal.

Error messages

No "error" messages appear

This warning means navigation launch will not be successful:

[smoother_server-2] [WARN] [1740264179.627696824] [smoother_server.rclcpp]: failed to send response to /smoother_server/change_state (timeout): client will not receive response, at ./src/rmw_response.cpp:153, at ./src/rcl/service.c:400

To Reproduce

Use nav2.yaml and localization.yaml parameter files with changes:

edit params/nav2.yaml
- remove all ```use_sim_time: true```
- and comment or remove:
# robot_state_publisher:
#   ros__parameters:
#      use_sim_time: true

edit params/localization.yaml
- remove all ```use_sim_time: true```
  1. Cold Boot
  2. On Visualization Platform: Launch Rviz2
ros2 launch turtlebot4_viz view_navigation.launch.py  (if not modified overlay params:=full_path_to/localization.yaml)
  1. On RPi: Launch localization with map of home (from tb4 async slam):
ros2 launch turtlebot4_navigation localization.launch.py map:=/home/ubuntu/TB5-WaLI/wali_ws/maps/tb4_nav_async_w_chrony.map.yaml
  1. On RPi: Launch navigation:
ros2 launch turtlebot4_navigation localization.launch.py map:=/home/ubuntu/TB5-WaLI/wali_ws/maps/tb4_nav_async_w_chrony.map.yaml

  1. Give an initial pose

  2. Watch for global and local costmaps to appear

  • If do not appear: Ctrl-c navigation, look back in log for
[planner_server-3] [WARN] [1740264294.156083284] [planner_server.rclcpp]: failed to send response to /planner_server/change_state (timeout): client will not receive response, at ./src/rmw_response.cpp:153, at ./src/rcl/service.c:400
  • Repeat starting at step 4 until both global and local costmaps appear

Other notes

Bad_nav2.log
good_nav2.log

nav2.yaml.txt
localization.yaml.txt

htop:

Image

Probably not relevant:

--------- Chrony for Create3 Testing --------

Create3 to Raspberry Pi Time Sync With Chrony

Create3 Time Sync:

  • ntpd logs being called every 11 minutes
  • ntpd writes /etc/timestamp on the hour with format YYYYMMDDhhmmss
  • declared ignoring reply delay 0.00x too high
    • 1m25s after called in periodic mode
    • 18s after
  • requests time from server
    • ntpd defaults to increasing delay from 64 to 1024 seconds
    • have seen over an hour between checks in while true; do uptime; sudo chronyc clients; echo -e "\n"; sleep 5; done
    • 35min between checks in these cases:
 08:37:27 up  9:05,  3 users,  load average: 0.37, 0.30, 0.27
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  75      0  11   -   35m       0      0   -     -


 08:37:32 up  9:06,  3 users,  load average: 0.34, 0.30, 0.27
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  76      0  11   -     3       0      0   -     -

Feb 22 13:37:28 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.006313 is too high, ignoring

 09:12:36 up  9:41,  3 users,  load average: 0.39, 0.34, 0.30
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  76      0  11   -   35m       0      0   -     -


 09:13:06 up  9:41,  3 users,  load average: 0.35, 0.34, 0.30
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  77      0  11   -    22       0      0   -     -

 09:47:05 up 10:15,  3 users,  load average: 0.17, 0.24, 0.26
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  77      0  11   -   34m       0      0   -     -


 09:47:35 up 10:16,  3 users,  load average: 0.17, 0.23, 0.25
Hostname                      NTP   Drop Int IntL Last     Cmd   Drop Int  Last
===============================================================================
192.168.186.2                  78      0  11   -     1       0      0   -     -



Last two time checks used without ignoring

ntpd in Create3 Log:

Feb 22 08:00:00 iRobot-883C456BE1E840DC89E64B28B4F75B53 cron.info crond[1092]: USER root pid 32374 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp
Feb 22 08:00:51 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice create-platform: [INFO] [1740211251.187931899] [_do_not_use.system_health]: CPU usage: max 81 [%] mean 76 [%] RAM usage: 33/59 [MB]
...
Feb 22 08:01:51 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 08:12:51 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 08:23:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 08:34:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 08:45:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 08:56:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 09:00:00 iRobot-883C456BE1E840DC89E64B28B4F75B53 cron.info crond[1092]: USER root pid 8815 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp
...
Feb 22 09:07:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 09:18:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 09:29:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 09:31:17 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004333 is too high, ignoring
...
Feb 22 09:40:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 09:51:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:00:00 iRobot-883C456BE1E840DC89E64B28B4F75B53 cron.info crond[1092]: USER root pid 17651 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp
...
Feb 22 10:02:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:13:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:24:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:35:53 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:46:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 10:57:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 11:00:00 iRobot-883C456BE1E840DC89E64B28B4F75B53 cron.info crond[1092]: USER root pid 26492 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp
...
Feb 22 11:08:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 11:19:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 11:30:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 11:41:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 11:52:54 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: Script called in periodic mode
...
Feb 22 12:00:00 iRobot-883C456BE1E840DC89E64B28B4F75B53 cron.info crond[1092]: USER root pid 2937 cmd /bin/date -u +%4Y%2m%2d%2H%2M%2S > /etc/timestamp

and just the "ignoring":

Feb 22 04:34:55 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.002324 is too high, ignoring
Feb 22 04:36:34 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.002588 is too high, ignoring
Feb 22 04:39:16 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004066 is too high, ignoring
Feb 22 04:40:52 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.001715 is too high, ignoring
Feb 22 04:45:15 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.003801 is too high, ignoring
Feb 22 04:50:40 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.003124 is too high, ignoring
Feb 22 05:17:06 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.006006 is too high, ignoring
Feb 22 05:30:11 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.005027 is too high, ignoring
Feb 22 05:47:51 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.005942 is too high, ignoring
Feb 22 06:00:55 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004014 is too high, ignoring
Feb 22 06:35:32 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004222 is too high, ignoring
Feb 22 07:19:21 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.003059 is too high, ignoring
Feb 22 09:31:17 iRobot-883C456BE1E840DC89E64B28B4F75B53 user.notice ntpd: ntpd: reply from 192.168.186.3: delay 0.004333 is too high, ignoring
@slowrunner slowrunner added the troubleshooting System not working as expected, may be user error. label Feb 23, 2025
@slowrunner
Copy link
Author

slowrunner commented Feb 24, 2025 •
edited
Loading

Is this related to #466 ? That issue is on Humble; I'm on Jazzy apparently seeing similar issue.

@slowrunner
Copy link
Author

I have submitted a discussion post on the navigation2 repo:

Improve Navigation2 Launch Reliability? Frequent smoother_server timeout #4947

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@RustyCPR RustyCPR

@smatarCPR smatarCPR

Labels
troubleshooting System not working as expected, may be user error.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@slowrunner @RustyCPR @smatarCPR