-
Notifications
You must be signed in to change notification settings - Fork 559
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
Warn: Did not receive data since 5 seconds! #1054
Comments
I never played with the astra on ros2, but the input data you are feeding rtabmap with looks pretty bad:
What is the delay and frame rate of the input topics?
If you don't have a solid 30 Hz on all topics, please report the issue on the camera driver repo. I cannot help more. Not also testing VSLAM in front of a white wall is a bad idea. |
Oh my goodness, I've realized that my rates are all around 4 or even lower!
I'll leave and seek help in the camera's issue tracker. Thank you very much! |
@matlabbe I also am experiencing this warning in ROS1 (rtabmap 0.21.4). And I traced it. In my case of using approximate sync, I found out that the synchronizer ( Here is what happens:
The thing is that this callback, through some nested calls, calls So what I think happens is that Essentially
[ WARN] - /rtabmap/rtabmap: [01:28:24.914341] *******
**** SYNC CALLBACK, timenow [1689820113.546681]
image = 1689820100.205681
depth = 1689820100.205681
caminf= 1689820100.205681
ptcld = 1689820100.194628
#######
[ WARN] - /rtabmap/rtabmap: [01:28:24.916490] ***** CALLING CoreWrapper::process() ********* [1689820113.556744] 1689820100.194628
[ WARN] - /rtabmap/rtabmap: [01:28:25.282195] *** SyncDiagnostic::diagnosticTimerCallback [1689820113.923028 - 1689820100.093715 = 13.829312]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [01:28:26.273966] *** SyncDiagnostic::diagnosticTimerCallback [1689820114.915351 - 1689820100.093715 = 14.821635]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [01:28:27.276261] *** SyncDiagnostic::diagnosticTimerCallback [1689820115.917313 - 1689820100.093715 = 15.823598]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [01:28:27.561429] ***** TICK inside CoreWrapper::process() ********* [1689820116.201607] 1689820100.194628
[ WARN] - /rtabmap/rtabmap: [01:28:27.561517] ***** CommonDataSubscriber::tick() ********* [1689820116.201607] 1689820100.194628
[ WARN] - /rtabmap/rtabmap: [01:28:27.561658] ***** SyncDiagnostic::tick() ********* [1689820116.201607] 1689820100.194628 (1689820100.194628)
[ INFO] - /rtabmap/rtabmap: [01:28:27.561708] rtabmap (45): Rate=0.10s, Limit=0.000s, Conversion=0.0020s, RTAB-Map=2.3828s, Maps update=0.2565s pub=0.0055s (local map=19, WM=19)
[ WARN] - /rtabmap/rtabmap: [01:28:27.562239] *******
**** SYNC CALLBACK, timenow [1689820116.201607]
image = 1689820100.305749
depth = 1689820100.305749
caminf= 1689820100.305749
ptcld = 1689820100.295455
#######
[ WARN] - /rtabmap/rtabmap: [01:28:27.563827] ***** CALLING CoreWrapper::process() ********* [1689820116.201607] 1689820100.295455
[ WARN] - /rtabmap/rtabmap: [01:28:28.276021] *** SyncDiagnostic::diagnosticTimerCallback [1689820116.917387 - 1689820100.194628 = 16.722759]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [01:28:29.277586] *** SyncDiagnostic::diagnosticTimerCallback [1689820117.918586 - 1689820100.194628 = 17.723958]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /navsat_transform: [01:28:29.287836] Transform from base_link to map was unavailable for the time requested. Using latest instead.
[ WARN] - /rtabmap/rtabmap: [01:28:30.276383] *** SyncDiagnostic::diagnosticTimerCallback [1689820118.917223 - 1689820100.194628 = 18.722595]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /move_base_flex: [01:28:30.288976] Map update loop missed its desired rate of 25.0000Hz... the loop actually took 0.0508 seconds
[ WARN] - /rtabmap/rtabmap: [01:28:30.435319] ***** TICK inside CoreWrapper::process() ********* [1689820119.068099] 1689820100.295455
[ WARN] - /rtabmap/rtabmap: [01:28:30.435403] ***** CommonDataSubscriber::tick() ********* [1689820119.068099] 1689820100.295455
[ WARN] - /rtabmap/rtabmap: [01:28:30.435516] ***** SyncDiagnostic::tick() ********* [1689820119.068099] 1689820100.295455 (1689820100.295455)
[ INFO] - /rtabmap/rtabmap: [01:28:30.435551] rtabmap (46): Rate=0.10s, Limit=0.000s, Conversion=0.0015s, RTAB-Map=2.4862s, Maps update=0.3787s pub=0.0065s (local map=19, WM=19)
[ WARN] - /rtabmap/rtabmap: [01:28:30.435977] *******
**** SYNC CALLBACK, timenow [1689820119.068099]
image = 1689820100.405816
depth = 1689820100.405816
caminf= 1689820100.405816
ptcld = 1689820100.396348
####### I'm actually not sure about So @matlabbe , any solutions for this? Maybe make |
I also tried to hard code the queue size of the synchronizer policy. I tried So I tried #define SYNC_DECL4(CLASS, PREFIX, APPROX, QUEUE_SIZE, SUB0, SUB1, SUB2, SUB3) \
if(APPROX) \
{ \
PREFIX##ApproximateSync_ = new message_filters::Synchronizer<PREFIX##ApproximateSyncPolicy>( \
PREFIX##ApproximateSyncPolicy(2), SUB0, SUB1, SUB2, SUB3); \
PREFIX##ApproximateSync_->registerCallback(boost::bind(&CLASS::PREFIX##Callback, this, boost::placeholders::_1, boost::placeholders::_2, boost::placeholders::_3, boost::placeholders::_4)); \
} \
else \
{ \
PREFIX##ExactSync_ = new message_filters::Synchronizer<PREFIX##ExactSyncPolicy>( \
PREFIX##ExactSyncPolicy(2), SUB0, SUB1, SUB2, SUB3); \
PREFIX##ExactSync_->registerCallback(boost::bind(&CLASS::PREFIX##Callback, this, boost::placeholders::_1, boost::placeholders::_2, boost::placeholders::_3, boost::placeholders::_4)); \
} \
subscribedTopicsMsg_ = uFormat("\n%s subscribed to (%s sync):\n %s \\\n %s \\\n %s \\\n %s", \
name_.c_str(), \
APPROX?"approx":"exact", \
SUB0.getTopic().c_str(), \
SUB1.getTopic().c_str(), \
SUB2.getTopic().c_str(), \
SUB3.getTopic().c_str()); When the queue size = 2, it works fine-ish, some are still late: [ WARN] - /rtabmap/rtabmap: [06:48:34.843377] *******
**** SYNC CALLBACK, timenow [1689820002.448316]
image = 1689819995.429335
depth = 1689819995.429335
caminf= 1689819995.429335
ptcld = 1689819995.501687
#######
[ WARN] - /rtabmap/rtabmap: [06:48:34.845505] ***** CALLING CoreWrapper::process() ********* [1689820002.448316] 1689819995.501687
[ WARN] - /rtabmap/rtabmap: [06:48:35.403065] *** SyncDiagnostic::diagnosticTimerCallback [1689820003.011595 - 1689819995.400859 = 7.610736]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [06:48:36.412948] *** SyncDiagnostic::diagnosticTimerCallback [1689820004.021142 - 1689819995.400859 = 8.620283]
/rtabmap/rtabmap: [COMMON_DATA] Did not receive data since 5 seconds! Make sure the input topics are published ("$ rostopic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=200).
/rtabmap/rtabmap subscribed to (approx sync):
/realsense/color/image_raw \
/realsense/aligned_depth_to_color/image_raw \
/realsense/color/camera_info \
/velodyne_points
[ WARN] - /rtabmap/rtabmap: [06:48:36.869964] ***** TICK inside CoreWrapper::process() ********* [1689820004.475136] 1689819995.501687
[ WARN] - /rtabmap/rtabmap: [06:48:36.870035] ***** CommonDataSubscriber::tick() ********* [1689820004.475136] 1689819995.501687
[ WARN] - /rtabmap/rtabmap: [06:48:36.870119] ***** SyncDiagnostic::tick() ********* [1689820004.475136] 1689819995.501687 (1689819995.501687)
[ INFO] - /rtabmap/rtabmap: [06:48:36.870156] rtabmap (4): Rate=0.10s, Limit=0.000s, Conversion=0.0021s, RTAB-Map=1.7466s, Maps update=0.2711s pub=0.0066s (local map=1, WM=1)
[ WARN] - /rtabmap/rtabmap: [06:48:37.023094] *******
**** SYNC CALLBACK, timenow [1689820004.626130]
image = 1689820004.369122
depth = 1689820004.369122
caminf= 1689820004.369122
ptcld = 1689820004.377366
####### Note the time on |
You should not have to hard-code the queue size, there is a parameter called What is the frame rate of all topics? If Another comment, when synchronizing with a lidar, I recommend to synchronize the image topics together with rgbd_sync node before rtabmap node, then set |
Here:
@matlabbe The So if you want the synchronizer's to call your callback with the latest synchronized set, the queue size should be 1. BUT there is an issue with giving it So for the synchronizer I made a simple test node to verify this behaviour. The callback registered to the synchronizer just sleeps for 1 second to simulate large processing time. Then we can compare the time the callback gets called, and the sensor data time stamps it contains: C++ code
#include "ros/ros.h"
#include <message_filters/subscriber.h>
#include <message_filters/synchronizer.h>
#include <message_filters/sync_policies/approximate_time.h>
#include <sensor_msgs/Image.h>
#include <sensor_msgs/PointCloud2.h>
#include <sensor_msgs/CameraInfo.h>
// using namespace sensor_msgs;
using namespace message_filters;
void callback( const sensor_msgs::ImageConstPtr& rgbMsg,
const sensor_msgs::CameraInfoConstPtr& rgbinfoMsg,
const sensor_msgs::ImageConstPtr& depthMsg,
const sensor_msgs::PointCloud2ConstPtr& pclMsg)
{
ROS_WARN("\n*********\nnow =[%f]\nrgb = %f\nrgbinf= %f\ndepth = %f\npcl = %f\n##################\n",
ros::Time::now().toSec(),
rgbMsg->header.stamp.toSec(),
rgbinfoMsg->header.stamp.toSec(),
depthMsg->header.stamp.toSec(),
pclMsg->header.stamp.toSec());
ros::Duration(1.0).sleep();
}
int main(int argc, char** argv)
{
ros::init(argc, argv, "sync_trial_node");
ros::NodeHandle nh, pnh("~");
int sync_qsize, sub_qsize;
pnh.param<int>("sync_qsize", sync_qsize, 2);
pnh.param<int>("sub_qsize", sub_qsize, 110);
ROS_INFO("\nSync queue size: %d\nSub queue size: %d", sync_qsize, sub_qsize);
message_filters::Subscriber<sensor_msgs::Image> rgb_sub(nh, "/realsense/color/image_raw", sub_qsize);
message_filters::Subscriber<sensor_msgs::CameraInfo> rgbinfo_sub(nh, "/realsense/color/camera_info", sub_qsize);
message_filters::Subscriber<sensor_msgs::Image> depth_sub(nh, "/realsense/aligned_depth_to_color/image_raw", sub_qsize);
message_filters::Subscriber<sensor_msgs::PointCloud2> pcl_sub(nh, "/velodyne_points", sub_qsize);
typedef sync_policies::ApproximateTime<sensor_msgs::Image, sensor_msgs::CameraInfo, sensor_msgs::Image, sensor_msgs::PointCloud2> MySyncPolicy;
// ApproximateTime takes a queue size as its constructor argument, hence MySyncPolicy(10)
Synchronizer<MySyncPolicy> sync(MySyncPolicy(sync_qsize), rgb_sub, rgbinfo_sub, depth_sub, pcl_sub);
sync.registerCallback(boost::bind(&callback, _1, _2, _3, _4));
ros::spin();
return 0;
} I tested this for 1, 2, and 100 synchronizer queue sizes, and let it run for about 20 seconds:
Output for `sync_qsize=1`, `sub_qsize=100`
wakoko79@wakoko79:~$ rosrun sync_test sync_test_node _sync_qsize:=1 _sub_qsize:=100
[ INFO] - /sync_trial_node: [02:30:48.566164]
Sync queue size: 1
Sub queue size: 100
Output for sync_qsize=2, sub_qsize=100
wakoko79@wakoko79:~$ rosrun sync_test sync_test_node _sync_qsize:=2 _sub_qsize:=100
[ INFO] - /sync_trial_node: [02:31:31.672168]
Sync queue size: 2
Sub queue size: 100
[ WARN] - /sync_trial_node: [02:31:32.005978]
*********
now =[1689820208.806427]
rgb = 1689820208.718220
rgbinf= 1689820208.718220
depth = 1689820208.718220
pcl = 1689820208.720201
##################
[ WARN] - /sync_trial_node: [02:31:33.014487]
*********
now =[1689820209.814953]
rgb = 1689820208.818292
rgbinf= 1689820208.818292
depth = 1689820208.818292
pcl = 1689820208.821064
##################
[ WARN] - /sync_trial_node: [02:31:34.020093]
*********
now =[1689820210.819814]
rgb = 1689820208.918363
rgbinf= 1689820208.918363
depth = 1689820208.918363
pcl = 1689820208.921933
##################
[ WARN] - /sync_trial_node: [02:31:35.027587]
*********
now =[1689820211.828824]
rgb = 1689820209.018435
rgbinf= 1689820209.018435
depth = 1689820209.018435
pcl = 1689820209.022824
##################
[ WARN] - /sync_trial_node: [02:31:36.034529]
*********
now =[1689820212.835800]
rgb = 1689820209.051792
rgbinf= 1689820209.051792
depth = 1689820209.051792
pcl = 1689820209.123662
##################
[ WARN] - /sync_trial_node: [02:31:37.099321]
*********
now =[1689820213.897344]
rgb = 1689820213.755279
rgbinf= 1689820213.755279
depth = 1689820213.755279
pcl = 1689820213.763216
##################
[ WARN] - /sync_trial_node: [02:31:38.108904]
*********
now =[1689820214.906992]
rgb = 1689820213.855351
rgbinf= 1689820213.855351
depth = 1689820213.855351
pcl = 1689820213.864086
##################
[ WARN] - /sync_trial_node: [02:31:39.112230]
*********
now =[1689820215.912743]
rgb = 1689820213.955424
rgbinf= 1689820213.955424
depth = 1689820213.955424
pcl = 1689820213.964952
##################
[ WARN] - /sync_trial_node: [02:31:40.114531]
*********
now =[1689820216.915519]
rgb = 1689820214.055496
rgbinf= 1689820214.055496
depth = 1689820214.055496
pcl = 1689820214.065827
##################
[ WARN] - /sync_trial_node: [02:31:41.122092]
*********
now =[1689820217.924499]
rgb = 1689820214.088854
rgbinf= 1689820214.088854
depth = 1689820214.088854
pcl = 1689820214.166635
##################
[ WARN] - /sync_trial_node: [02:31:42.190173]
*********
now =[1689820218.987670]
rgb = 1689820218.892457
rgbinf= 1689820218.892457
depth = 1689820218.892457
pcl = 1689820218.907067
##################
[ WARN] - /sync_trial_node: [02:31:43.188243]
*********
now =[1689820219.989167]
rgb = 1689820218.992533
rgbinf= 1689820218.992533
depth = 1689820218.992533
pcl = 1689820219.007971
##################
[ WARN] - /sync_trial_node: [02:31:44.192573]
*********
now =[1689820220.993857]
rgb = 1689820219.092609
rgbinf= 1689820219.092609
depth = 1689820219.092609
pcl = 1689820219.108885
##################
[ WARN] - /sync_trial_node: [02:31:45.202502]
*********
now =[1689820222.003085]
rgb = 1689820219.192685
rgbinf= 1689820219.192685
depth = 1689820219.192685
pcl = 1689820219.209673
##################
[ WARN] - /sync_trial_node: [02:31:46.210550]
*********
now =[1689820223.012719]
rgb = 1689820219.226044
rgbinf= 1689820219.226044
depth = 1689820219.226044
pcl = 1689820219.311415
##################
[ WARN] - /sync_trial_node: [02:31:47.279730]
*********
now =[1689820224.081603]
rgb = 1689820223.962808
rgbinf= 1689820223.962808
depth = 1689820223.962808
pcl = 1689820223.950265
##################
[ WARN] - /sync_trial_node: [02:31:48.290906]
*********
now =[1689820225.091037]
rgb = 1689820224.062885
rgbinf= 1689820224.062885
depth = 1689820224.062885
pcl = 1689820224.050985
##################
[ WARN] - /sync_trial_node: [02:31:49.294884]
*********
now =[1689820226.095892]
rgb = 1689820224.162961
rgbinf= 1689820224.162961
depth = 1689820224.162961
pcl = 1689820224.151842
##################
[ WARN] - /sync_trial_node: [02:31:50.305560]
*********
now =[1689820227.105879]
rgb = 1689820224.263036
rgbinf= 1689820224.263036
depth = 1689820224.263036
pcl = 1689820224.252681
##################
[ WARN] - /sync_trial_node: [02:31:51.387883]
*********
now =[1689820228.186120]
rgb = 1689820228.099112
rgbinf= 1689820228.099112
depth = 1689820228.099112
pcl = 1689820228.085403
##################
[ WARN] - /sync_trial_node: [02:31:52.393389]
*********
now =[1689820229.194146]
rgb = 1689820228.199185
rgbinf= 1689820228.199185
depth = 1689820228.199185
pcl = 1689820228.186225
##################
Output for sync_qsize=100, sub_qsize=100 (this is how rtabmap works currently same queue_size)
wakoko79@wakoko79:~$ rosrun sync_test sync_test_node _sync_qsize:=100 _sub_qsize:=100
[ INFO] - /sync_trial_node: [02:45:03.681519]
Sync queue size: 100
Sub queue size: 100
[ WARN] - /sync_trial_node: [02:45:03.993621]
*********
now =[1689820001.021314]
rgb = 1689820000.933259
rgbinf= 1689820000.933259
depth = 1689820000.933259
pcl = 1689820000.948110
##################
[ WARN] - /sync_trial_node: [02:45:04.998791]
*********
now =[1689820002.022843]
rgb = 1689820001.033334
rgbinf= 1689820001.033334
depth = 1689820001.033334
pcl = 1689820001.048989
##################
[ WARN] - /sync_trial_node: [02:45:05.998849]
*********
now =[1689820003.026338]
rgb = 1689820001.133407
rgbinf= 1689820001.133407
depth = 1689820001.133407
pcl = 1689820001.149865
##################
[ WARN] - /sync_trial_node: [02:45:07.007156]
*********
now =[1689820004.035149]
rgb = 1689820001.266839
rgbinf= 1689820001.266839
depth = 1689820001.266839
pcl = 1689820001.251910
##################
[ WARN] - /sync_trial_node: [02:45:08.023551]
*********
now =[1689820005.045595]
rgb = 1689820001.667135
rgbinf= 1689820001.667135
depth = 1689820001.667135
pcl = 1689820001.654354
##################
[ WARN] - /sync_trial_node: [02:45:09.016998]
*********
now =[1689820006.046685]
rgb = 1689820001.767209
rgbinf= 1689820001.767209
depth = 1689820001.767209
pcl = 1689820001.755058
##################
[ WARN] - /sync_trial_node: [02:45:10.022815]
*********
now =[1689820007.051297]
rgb = 1689820001.867283
rgbinf= 1689820001.867283
depth = 1689820001.867283
pcl = 1689820001.855880
##################
[ WARN] - /sync_trial_node: [02:45:11.023796]
*********
now =[1689820008.051796]
rgb = 1689820001.967357
rgbinf= 1689820001.967357
depth = 1689820001.967357
pcl = 1689820001.956763
##################
[ WARN] - /sync_trial_node: [02:45:12.027495]
*********
now =[1689820009.054271]
rgb = 1689820002.067431
rgbinf= 1689820002.067431
depth = 1689820002.067431
pcl = 1689820002.057604
##################
[ WARN] - /sync_trial_node: [02:45:13.111250]
*********
now =[1689820010.135901]
rgb = 1689820003.668599
rgbinf= 1689820003.668599
depth = 1689820003.668599
pcl = 1689820003.671361
##################
[ WARN] - /sync_trial_node: [02:45:14.118357]
*********
now =[1689820011.144026]
rgb = 1689820003.735317
rgbinf= 1689820003.735317
depth = 1689820003.735317
pcl = 1689820003.772213
##################
[ WARN] - /sync_trial_node: [02:45:15.153733]
*********
now =[1689820012.175366]
rgb = 1689820004.669337
rgbinf= 1689820004.669337
depth = 1689820004.669337
pcl = 1689820004.679966
##################
[ WARN] - /sync_trial_node: [02:45:16.147501]
*********
now =[1689820013.177642]
rgb = 1689820004.736052
rgbinf= 1689820004.736052
depth = 1689820004.736052
pcl = 1689820004.780798
##################
[ WARN] - /sync_trial_node: [02:45:17.169854]
*********
now =[1689820014.190341]
rgb = 1689820005.703416
rgbinf= 1689820005.703416
depth = 1689820005.703416
pcl = 1689820005.688570
##################
[ WARN] - /sync_trial_node: [02:45:18.161268]
*********
now =[1689820015.190870]
rgb = 1689820005.736773
rgbinf= 1689820005.736773
depth = 1689820005.736773
pcl = 1689820005.789418
##################
[ WARN] - /sync_trial_node: [02:45:19.170538]
*********
now =[1689820016.199950]
rgb = 1689820006.670760
rgbinf= 1689820006.704116
depth = 1689820006.670760
pcl = 1689820006.697172
##################
[ WARN] - /sync_trial_node: [02:45:20.170835]
*********
now =[1689820017.200271]
rgb = 1689820007.204465
rgbinf= 1689820007.204465
depth = 1689820007.204465
pcl = 1689820007.201520
##################
[ WARN] - /sync_trial_node: [02:45:21.179618]
*********
now =[1689820018.209414]
rgb = 1689820008.205193
rgbinf= 1689820008.205193
depth = 1689820008.205193
pcl = 1689820008.210075
##################
[ WARN] - /sync_trial_node: [02:45:22.182341]
*********
now =[1689820019.211623]
rgb = 1689820009.205835
rgbinf= 1689820009.205835
depth = 1689820009.205835
pcl = 1689820009.218675
##################
[ WARN] - /sync_trial_node: [02:45:23.190317]
*********
now =[1689820020.219882]
rgb = 1689820009.639480
rgbinf= 1689820009.639480
depth = 1689820009.639480
pcl = 1689820010.227273
##################
[ WARN] - /sync_trial_node: [02:45:24.195161]
*********
now =[1689820021.224373]
rgb = 1689820011.207329
rgbinf= 1689820011.207329
depth = 1689820011.207329
pcl = 1689820011.235857
##################
So it is either change how rtabmap's callbacks work (maybe make it store data to cache instead of processing it) or edit the
I'll also try this later. =) |
Do you tell me that all this time that example was wrong?! We used to do "sync_qsize=10, sub_qsize=1" by default (like the example) till it was not working anymore on ros noetic: ed564c3 So now we have Note that another way to see the delay over time is to do:
I'll try on our robots this week if I see a large difference, in particular for visual odometry (which still use "sync_qsize=10, sub_qsize=1" approach) if that could decrease the delay we are seeing. For the rate of your topics, with current code, a |
No. What I'm saying is it is not good to make a singular
Honestly, "sync_qsize=10, sub_qsize=1" might be better.
This prompts the user to increase the Here are plots of the time differences of different These graphs shows that increasing individual topic queue size ( So the way Say you have 2 topics I mentioned this in my previous comment:
I still think that the tick should be called directly inside the callback that is called by the synchronizer, just before calling So I made a helper function to make things work. It did work, but I'm not sure if this is OK or if the current implementation is intended. Anyway, it achieved the goal of making the callback called by the synchronizer return fast by not waiting on the processing by rtabmap. It works still even on the current implementation of Here is a plot for the delays, which is run on the actual rtabmap_ros code: Processed just means that I passed on the data to be processed as normal, unprocessed means that the callback was called, but did not process the syncronized messages set since
|
We could definitely add a second queue size parameter, maybe called |
…meters for more fine tuning of topic synchronization (#1054)
With the commit above, we can now set a different queue size for input topics (called That change will be ported to ros2 with next master->ros2 merge. cheers, |
@matlabbe BTW, I made a threaded version of the callbacks to keep the time spent in the Synchronizer callback minimal. I'm not sure though if this behaviour is OK though. I can request a pull if you like.=) |
I added a thread for the odometry nodes, which seems to have fixed the issue there. I tried to do something similar for rtabmap node (a different implementation than yours but the idea was the same), but I aborted after realizing that making it thread-safe would be a lot of work. In your case, it works as long as you don't call any rtabmap services. For ros1, I am not sure what is the simplest thread-safe solution to do... I think a ROS2 solution would be to have a MultiThreadedExecutor for rtabmap node, then set message filter sync callbacks to one callback group, then set all services in another callback group. Then the thread you launch from a sync callback would need to be launched in the same callback group than the one used for the services. That way, we make sure we cannot execute a service callback while a rtabmap update is running. To integrate the rtabmap update loop with the executor (instead of a disjoint thread), we could use a Timer (with same callback group than the services) that triggers a callback checking (every 100 ms?) if new data is received, then proceeds with the update. The "data" would be protected by a mutex, between the message filter callbacks and the Timer callback. If the timer callback is not done with current update and message filter receives new data, it will just overwrite the buffered one or discard current one till it knows the timer is not using the data buffer anymore. I'll try create a PR with this approach soon and compare with your approach. EDIT: To avoid having a Timer spinning adding delay or using CPU for throttling, I don't know if the executor can do that, but if we could just tell the executor to trigger a specified callback in the services callback group (similar than in Qt when we call a slot from a different thread, it is executed in thread of the slot), that would be the most efficient. |
hi,everyone i Using Ros2 Foxy inside a Jetson jeston agx orin with ubuntu 20.4 and a astro pro , for some reason launching examples
###########
ros2 launch rtabmap_launch rtabmap.launch.py
rtabmap_args:="--delete_db_on_start"
rgb_topic:=/camera/color/image_raw
depth_topic:=/camera/depth/image_raw
camera_info_topic:=/camera/color/camera_info
frame_id:=base_link
approx_sync:=true
qos:=2
rviz:=true
queue_size:=20
subscribe_odom_info:=false
###############
[rtabmap_viz-3] [WARN] [1697700727.832576678] [rtabmap.rtabmap_viz]: rtabmap_viz: Did not receive data since 5 seconds! Make sure the input topics are published ("$ ros2 topic hz my_topic") and the timestamps in their header are set. If topics are coming from different computers, make sure the clocks of the computers are synchronized ("ntpdate"). If topics are not published at the same rate, you could increase "queue_size" parameter (current=20).
#############
I ensure that I have synchronized the time using NTP.
The text was updated successfully, but these errors were encountered: