SLAM mesasge filter dropping message

sardanian commented 10 months ago

Please provide the following information:

OS: (e.g. Ubuntu 22.04)
ROS Distro: (e.g. Humble)
Built from source or installed: insalled from raspian image for turtlebot4

Expected behaviour Generating a map should not produce large amounts of message filter dropping message

Actual behaviour I am getting a lot of discarded messages

This is my output:


user@computer:~/Downloads$ ros2 launch turtlebot4_navigation slam.launch.py
[INFO] [launch]: All log files can be found below /home/user/.ros/log/2023-10-11-23-15-21-327347-computer-7977
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [sync_slam_toolbox_node-1]: process started with pid [7978]
[sync_slam_toolbox_node-1] [INFO] [1697087721.424149761] [slam_toolbox]: Node using stack size 40000000
[sync_slam_toolbox_node-1] [INFO] [1697087721.435828375] [slam_toolbox]: Using solver plugin solver_plugins::CeresSolver
[sync_slam_toolbox_node-1] [INFO] [1697087721.435886946] [slam_toolbox]: CeresSolver: Using SCHUR_JACOBI preconditioner.
[sync_slam_toolbox_node-1] [INFO] [1697087723.430620302] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.090 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087723.630950400] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.241 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087723.868820742] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.373 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087723.871198663] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.509 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087724.071487629] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.656 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087724.311704044] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.791 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087724.401690539] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087723.938 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087724.490325569] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.073 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087724.690850216] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.220 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087724.802423535] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.355 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087725.002618594] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.491 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087725.236899710] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.638 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087725.294754014] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.773 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087725.352776871] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087724.921 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087725.399212436] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087725.056 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087725.599652175] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087725.203 for reason 'the timestamp on the message is earlier than all the data in the transform cache'
[sync_slam_toolbox_node-1] [INFO] [1697087725.891923458] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087725.338 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087725.892160902] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087725.473 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] Registering sensor: [Custom Described Lidar]
[sync_slam_toolbox_node-1] [INFO] [1697087779.118472563] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087778.557 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087779.121278858] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087778.692 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087779.122423366] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087778.827 for reason 'discarding message because the queue is full'
[sync_slam_toolbox_node-1] [INFO] [1697087779.271873016] [slam_toolbox]: Message Filter dropping message: frame 'rplidar_link' at time 1697087778.975 for reason 'discarding message because the queue is full'

mixed with:

user@computer:~/Downloads$ ros2 launch turtlebot4_viz view_robot.launch.py
[INFO] [launch]: All log files can be found below /home/pariah/.ros/log/2023-10-11-23-15-27-973118-computer-8031
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [rviz2-1]: process started with pid [8032]
[rviz2-1] [INFO] [1697087728.573930752] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-1] [INFO] [1697087728.574036964] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-1] [INFO] [1697087728.592085176] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-1] [INFO] [1697087746.386290957] [rviz2]: Trying to create a map of size 286 x 99 using 1 swatches
[rviz2-1] [INFO] [1697087747.856740177] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.262 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087747.984923331] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.390 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087748.112900518] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.538 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087748.240801072] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.672 for reason 'discarding message because the queue is full'
[rviz2-1] [ERROR] [1697087748.246776573] [rviz2]: Lookup would require extrapolation into the future.  Requested time 1697087748.218695 but the latest data is at time 1697087748.187471, when looking up transform from frame [rplidar_link] to frame [map]
[rviz2-1] [INFO] [1697087779.151958000] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.820 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087779.184435132] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087746.954 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087779.248751315] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087747.102 for reason 'discarding message because the queue is full'
[rviz2-1] [INFO] [1697087779.280316702] [rviz2]: Message Filter dropping message: frame 'rplidar_link' at time 1697087747.237 for reason 'discarding message because the queue is full'

To Reproduce Provide the steps to reproduce: I set up discover server (simple server was giving these same messages but not as often). Simple server setup was also much slower.

commands are above

hilary-luo commented 10 months ago

Are you seeing any issues with the performance of the system?

Having dropped messages in your rviz terminal only impacts the visualization in rviz. Having dropped messages in your slam terminal generally means that your pc is struggling to keep up with the messages, it may not have enough power to process the data at the rate that is being asked.

In general dropped messages are impacted by the quality of your network and processing power of whatever system you are processing them on. If you are not experiencing performance issues (rviz is being reasonably responsive and mapping is being accurate within the expectations of the mapping tool being used) then I wouldn't say there is any issue here.

If the timestamp errors are presistent and interfering with operation then try the solution shown here: https://github.com/turtlebot/turtlebot4/issues/216

hilary-luo commented 9 months ago

This issue is being closed due to inactivity. If you are still experiencing the issue, feel free to reopen this ticket when you are ready to continue the troubleshooting process.

turtlebot / turtlebot4

SLAM mesasge filter dropping message #285