RGB frames arrive late, skipped and ignored

[makaveli10]

Getting warnings of skipping old frames and not recieving expected frames.

running carla ros bridge with the following parameters: fixed_delta_seconds = 0.05 synchronous_mode = True synchronous_mode_wait_for_vehicle_control_command = False RgbCamera x1 "sensor_tick": 0.1

Getting these warnings which causes the rgb image panel to never receive and display images:

The configuration and fixes mentioned in this issue doesn't work either

[INFO] [1646664373.678571, 0.000000]:   port: 2000
[INFO] [1646664373.680715, 0.000000]:   timeout: 200
[INFO] [1646664373.683091, 0.000000]:   passive: 
[INFO] [1646664373.685222, 0.000000]:   synchronous_mode: True
[INFO] [1646664373.687799, 0.000000]:   synchronous_mode_wait_for_vehicle_control_command: False
[INFO] [1646664373.690228, 0.000000]:   fixed_delta_seconds: 0.05
[INFO] [1646664373.692422, 0.000000]:   register_all_sensors: True
[INFO] [1646664373.693894, 0.000000]:   town: 
[INFO] [1646664373.695490, 0.000000]:   ego_vehicle: {'role_name': '["ego", "hero", "ego_vehicle", "hero0", "hero1", "hero2", "hero3", "hero4", "hero5", "hero6", "hero7", "hero8", "hero9"]'}
[INFO] [1646664382.841315, 0.000000]: Object (type='sensor.pseudo.traffic_lights', id='traffic_lights') spawned successfully as 10000.
[INFO] [1646664382.846315, 0.000000]: Object (type='sensor.pseudo.objects', id='objects') spawned successfully as 10001.
[INFO] [1646664382.851327, 0.000000]: Object (type='sensor.pseudo.actor_list', id='actor_list') spawned successfully as 10002.
[INFO] [1646664382.857926, 0.000000]: Object (type='sensor.pseudo.markers', id='markers') spawned successfully as 10003.
[INFO] [1646664382.861996, 0.000000]: Object (type='sensor.pseudo.opendrive_map', id='map') spawned successfully as 10004.
[WARN] [1646664382.863698, 0.000000]: Invalid spawnpoint ''
[WARN] [1646664382.864691, 0.000000]: ego_vehicle: Could not use spawn point from parameters, the spawn point from config file will be used.
[INFO] [1646664382.865497, 0.000000]: Spawn point selected at random
[INFO] [1646664383.196817, 0.000000]: Object (type='vehicle.tesla.model3', id='ego_vehicle') spawned successfully as 47.
[INFO] [1646664383.529516, 0.000000]: Object (type='sensor.camera.rgb', id='rgb_view') spawned successfully as 48.
[INFO] [1646664383.535489, 0.000000]: Object (type='actor.pseudo.control', id='control') spawned successfully as 10005.
[INFO] [1646664383.867047, 0.000000]: Object (type='sensor.lidar.ray_cast', id='lidar') spawned successfully as 49.
[INFO] [1646664384.220652, 0.000000]: Object (type='sensor.camera.semantic_segmentation', id='semantic_segmentation_front') spawned successfully as 50.
2022-03-07 20:16:24+0530 [-] [INFO] [1646664384.347315, 0.000000]: Client connected.  1 clients total.
2022-03-07 20:16:24+0530 [-] [INFO] [1646664384.441632, 0.000000]: [Client 0] Subscribed to /clock
2022-03-07 20:16:24+0530 [-] [INFO] [1646664384.445567, 0.000000]: [Client 0] Subscribed to /carla/debug_marker
[INFO] [1646664384.630313, 0.000000]: Object (type='sensor.other.gnss', id='gnss') spawned successfully as 51.
[INFO] [1646664385.040540, 0.000000]: Object (type='sensor.other.imu', id='imu') spawned successfully as 52.
[INFO] [1646664385.046513, 0.000000]: Object (type='sensor.pseudo.tf', id='tf') spawned successfully as 10006.
[INFO] [1646664385.052295, 0.000000]: Object (type='sensor.pseudo.objects', id='objects') spawned successfully as 10007.
[INFO] [1646664385.054966, 0.000000]: Created Spectator(id=24)
[INFO] [1646664385.057732, 0.000000]: Created Traffic(id=25)
[INFO] [1646664385.059976, 0.000000]: Created Traffic(id=26)
[INFO] [1646664385.060110, 0.000000]: Object (type='sensor.pseudo.odom', id='odometry') spawned successfully as 10008.
[INFO] [1646664385.061606, 0.000000]: Created Traffic(id=27)
[INFO] [1646664385.063151, 0.000000]: Created Traffic(id=28)
[INFO] [1646664385.064457, 0.000000]: Created Traffic(id=29)
[INFO] [1646664385.064897, 0.000000]: Object (type='sensor.pseudo.speedometer', id='speedometer') spawned successfully as 10009.
[INFO] [1646664385.065765, 0.000000]: Created Traffic(id=30)
[INFO] [1646664385.067148, 0.000000]: Created Traffic(id=31)
[INFO] [1646664385.068427, 0.000000]: Created TrafficLight(id=32)
[INFO] [1646664385.069492, 0.000000]: Created TrafficLight(id=33)
[INFO] [1646664385.069499, 0.000000]: Object (type='actor.pseudo.control', id='control') spawned successfully as 10010.
[INFO] [1646664385.070855, 0.000000]: All objects spawned.
[INFO] [1646664385.071559, 0.000000]: Created TrafficLight(id=34)
[INFO] [1646664385.072755, 0.000000]: Created TrafficLight(id=35)
[INFO] [1646664385.073846, 0.000000]: Created TrafficLight(id=36)
[INFO] [1646664385.074932, 0.000000]: Created TrafficLight(id=37)
[INFO] [1646664385.076087, 0.000000]: Created TrafficLight(id=38)
[INFO] [1646664385.077621, 0.000000]: Created TrafficLight(id=39)
[INFO] [1646664385.078920, 0.000000]: Created TrafficLight(id=40)
[INFO] [1646664385.079928, 0.000000]: Created TrafficLight(id=41)
[INFO] [1646664385.080853, 0.000000]: Created TrafficLight(id=42)
[INFO] [1646664385.081809, 0.000000]: Created TrafficLight(id=43)
[INFO] [1646664385.083081, 0.000000]: Created TrafficLight(id=44)
[INFO] [1646664385.084244, 0.000000]: Created TrafficLight(id=45)
[INFO] [1646664385.085424, 0.000000]: Created TrafficLight(id=46)
[INFO] [1646664385.088078, 0.000000]: Created TrafficLightsSensor(id=10000)
[INFO] [1646664385.090013, 0.000000]: Created ObjectSensor(id=10001)
[INFO] [1646664385.091337, 0.000000]: Created ActorListSensor(id=10002)
2022-03-07 20:16:27+0530 [-] [INFO] [1646664387.506613, 0.000000]: [Client 0] Subscribed to /carla/markers/static
[INFO] [1646664429.992575, 0.000000]: Created MarkerSensor(id=10003)
[INFO] [1646664429.999198, 0.000000]: Created OpenDriveSensor(id=10004)
[INFO] [1646664431.074202, 0.000000]: Created EgoVehicle(id=47)
[INFO] [1646664431.077083, 0.000000]: Created RgbCamera(id=48)
[INFO] [1646664431.080232, 0.000000]: Created ActorControl(id=10005)
[INFO] [1646664431.082760, 0.000000]: Created Lidar(id=49)
[INFO] [1646664431.085829, 0.000000]: Created SemanticSegmentationCamera(id=50)
[INFO] [1646664431.087352, 0.000000]: Created Gnss(id=51)
[INFO] [1646664431.088901, 0.000000]: Created ImuSensor(id=52)
[INFO] [1646664431.089701, 0.000000]: Created TFSensor(id=10006)
[INFO] [1646664431.091440, 0.000000]: Created ObjectSensor(id=10007)
[INFO] [1646664431.093084, 0.000000]: Created OdometrySensor(id=10008)
[INFO] [1646664431.094718, 0.000000]: Created SpeedometerSensor(id=10009)
[INFO] [1646664431.097034, 0.000000]: Created ActorControl(id=10010)
2022-03-07 20:17:11+0530 [-] [ERROR] [1646664431.433720, 5.315863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664432.764484, 5.315863]: RgbCamera(48): Expected Frame 24 not received
2022-03-07 20:17:13+0530 [-] [INFO] [1646664433.025936, 5.315863]: [Client 0] Subscribed to /carla/ego_vehicle/lidar
2022-03-07 20:17:13+0530 [-] [INFO] [1646664433.029926, 5.315863]: [Client 0] Subscribed to /carla/ego_vehicle/semantic_segmentation_front/image
2022-03-07 20:17:13+0530 [-] [INFO] [1646664433.034994, 5.315863]: [Client 0] Subscribed to /carla/ego_vehicle/vehicle_status
2022-03-07 20:17:13+0530 [-] [INFO] [1646664433.091680, 5.315863]: [Client 0] Subscribed to /carla/ego_vehicle/semantic_segmentation_front/camera_info
2022-03-07 20:17:13+0530 [-] [INFO] [1646664433.096887, 5.315863]: [Client 0] Subscribed to /tf
[WARN] [1646664433.766403, 5.315863]: Lidar(49): Expected Frame 24 not received
[WARN] [1646664434.767848, 5.315863]: SemanticSegmentationCamera(50): Expected Frame 24 not received
[WARN] [1646664435.769136, 5.315863]: Gnss(51): Expected Frame 24 not received
[WARN] [1646664436.771088, 5.315863]: ImuSensor(52): Expected Frame 24 not received
2022-03-07 20:17:17+0530 [-] [ERROR] [1646664437.164349, 5.365863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664438.163766, 5.365863]: RgbCamera(48): Expected Frame 25 not received
[WARN] [1646664439.166358, 5.365863]: Lidar(49): Expected Frame 25 not received
[WARN] [1646664440.168923, 5.365863]: SemanticSegmentationCamera(50): Expected Frame 25 not received
2022-03-07 20:17:21+0530 [-] [ERROR] [1646664441.872930, 5.415863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664442.872883, 5.415863]: RgbCamera(48): Expected Frame 26 not received
[WARN] [1646664443.875808, 5.415863]: Lidar(49): Expected Frame 26 not received
[WARN] [1646664443.878298, 5.415863]: SemanticSegmentationCamera(50): skipping old frame 25, expected 26
2022-03-07 20:17:24+0530 [-] [ERROR] [1646664444.528006, 5.465863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664445.527821, 5.465863]: RgbCamera(48): Expected Frame 27 not received
[WARN] [1646664446.530268, 5.465863]: Lidar(49): Expected Frame 27 not received
2022-03-07 20:17:26+0530 [-] [ERROR] [1646664446.870983, 5.515863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664446.871852, 5.465863]: RgbCamera(48): skipping old frame 25, expected 28
[WARN] [1646664447.875080, 5.515863]: RgbCamera(48): Expected Frame 28 not received
[WARN] [1646664447.878072, 5.515863]: Lidar(49): skipping old frame 25, expected 28
[WARN] [1646664448.880388, 5.515863]: Lidar(49): Expected Frame 28 not received
[WARN] [1646664449.881873, 5.515863]: SemanticSegmentationCamera(50): Expected Frame 28 not received
2022-03-07 20:17:30+0530 [-] [ERROR] [1646664450.219248, 5.565863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664451.219460, 5.565863]: RgbCamera(48): Expected Frame 29 not received
[WARN] [1646664451.221992, 5.565863]: Lidar(49): skipping old frame 26, expected 29
[WARN] [1646664451.224032, 5.565863]: Lidar(49): skipping old frame 27, expected 29
[WARN] [1646664452.113286, 5.565863]: Lidar(49): skipping old frame 28, expected 29
[WARN] [1646664453.114875, 5.565863]: Lidar(49): Expected Frame 29 not received
[WARN] [1646664453.116138, 5.565863]: SemanticSegmentationCamera(50): skipping old frame 28, expected 29
2022-03-07 20:17:34+0530 [-] [ERROR] [1646664454.398227, 5.615863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664455.398138, 5.615863]: RgbCamera(48): Expected Frame 30 not received
[WARN] [1646664455.400962, 5.615863]: Lidar(49): skipping old frame 29, expected 30
[WARN] [1646664457.022535, 5.615863]: SemanticSegmentationCamera(50): Expected Frame 30 not received
2022-03-07 20:17:37+0530 [-] [ERROR] [1646664457.362614, 5.665863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664458.363474, 5.665863]: RgbCamera(48): Expected Frame 31 not received
[WARN] [1646664458.790124, 5.665863]: SemanticSegmentationCamera(50): skipping old frame 30, expected 31
2022-03-07 20:17:40+0530 [-] [ERROR] [1646664460.099127, 5.715863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664460.099535, 5.665863]: RgbCamera(48): skipping old frame 26, expected 32
[WARN] [1646664461.102074, 5.715863]: RgbCamera(48): Expected Frame 32 not received
2022-03-07 20:17:42+0530 [-] [ERROR] [1646664462.145054, 5.765863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664463.146599, 5.765863]: RgbCamera(48): Expected Frame 33 not received
2022-03-07 20:17:44+0530 [-] [ERROR] [1646664464.194476, 5.815863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664464.195107, 5.815863]: RgbCamera(48): skipping old frame 27, expected 34
[WARN] [1646664465.197146, 5.815863]: RgbCamera(48): Expected Frame 34 not received
2022-03-07 20:17:45+0530 [-] [ERROR] [1646664465.905756, 5.865863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664465.906581, 5.815863]: RgbCamera(48): skipping old frame 28, expected 35
[WARN] [1646664466.608336, 5.865863]: RgbCamera(48): skipping old frame 29, expected 35
[WARN] [1646664467.463292, 5.865863]: RgbCamera(48): skipping old frame 30, expected 35
[WARN] [1646664468.197329, 5.865863]: RgbCamera(48): skipping old frame 31, expected 35
[WARN] [1646664468.614002, 5.865863]: RgbCamera(48): skipping old frame 32, expected 35
[WARN] [1646664469.553904, 5.865863]: RgbCamera(48): skipping old frame 33, expected 35
[WARN] [1646664470.343315, 5.865863]: RgbCamera(48): skipping old frame 34, expected 35
2022-03-07 20:17:51+0530 [-] [ERROR] [1646664471.571277, 5.915863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664472.572590, 5.915863]: RgbCamera(48): Expected Frame 36 not received
[WARN] [1646664473.575239, 5.915863]: Lidar(49): Expected Frame 36 not received
2022-03-07 20:17:54+0530 [-] [INFO] [1646664474.537133, 5.915863]: [Client 0] Subscribed to /carla/ego_vehicle/rgb_view/camera_info
2022-03-07 20:17:54+0530 [-] [INFO] [1646664474.541530, 5.915863]: [Client 0] Subscribed to /carla/ego_vehicle/rgb_view/image
2022-03-07 20:17:54+0530 [-] [INFO] [1646664474.545697, 5.915863]: [Client 0] Unsubscribed from /carla/ego_vehicle/semantic_segmentation_front/image
2022-03-07 20:17:54+0530 [-] [INFO] [1646664474.548490, 5.915863]: [Client 0] Unsubscribed from /carla/ego_vehicle/semantic_segmentation_front/camera_info
[WARN] [1646664474.576947, 5.915863]: SemanticSegmentationCamera(50): Expected Frame 36 not received
2022-03-07 20:17:54+0530 [-] [ERROR] [1646664474.914345, 5.965863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664475.915744, 5.965863]: RgbCamera(48): Expected Frame 37 not received
[WARN] [1646664476.074156, 5.965863]: Lidar(49): skipping old frame 36, expected 37
[WARN] [1646664477.076620, 5.965863]: Lidar(49): Expected Frame 37 not received
[WARN] [1646664478.079148, 5.965863]: SemanticSegmentationCamera(50): Expected Frame 37 not received
2022-03-07 20:17:58+0530 [-] [ERROR] [1646664478.423302, 6.015863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664478.424043, 5.965863]: RgbCamera(48): skipping old frame 36, expected 38
[WARN] [1646664479.426067, 6.015863]: RgbCamera(48): Expected Frame 38 not received
[WARN] [1646664480.292639, 6.015863]: Lidar(49): skipping old frame 37, expected 38
[WARN] [1646664481.294348, 6.015863]: Lidar(49): Expected Frame 38 not received
[WARN] [1646664481.296343, 6.015863]: SemanticSegmentationCamera(50): skipping old frame 36, expected 38
[WARN] [1646664482.298230, 6.015863]: SemanticSegmentationCamera(50): Expected Frame 38 not received
[WARN] [1646664482.640211, 6.015863]: RgbCamera(48): skipping old frame 37, expected 39
2022-03-07 20:18:02+0530 [-] [ERROR] [1646664482.641164, 6.065863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664483.643383, 6.065863]: RgbCamera(48): Expected Frame 39 not received
[WARN] [1646664484.646042, 6.065863]: Lidar(49): Expected Frame 39 not received
[WARN] [1646664485.648472, 6.065863]: SemanticSegmentationCamera(50): Expected Frame 39 not received
2022-03-07 20:18:06+0530 [-] [ERROR] [1646664486.042665, 6.115863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664487.044112, 6.115863]: RgbCamera(48): Expected Frame 40 not received
[WARN] [1646664487.046833, 6.115863]: Lidar(49): skipping old frame 38, expected 40
[WARN] [1646664488.050151, 6.115863]: Lidar(49): Expected Frame 40 not received
[WARN] [1646664489.052849, 6.115863]: SemanticSegmentationCamera(50): Expected Frame 40 not received
2022-03-07 20:18:10+0530 [-] [ERROR] [1646664490.710237, 6.165863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664490.834758, 6.165863]: RgbCamera(48): skipping old frame 38, expected 41
[WARN] [1646664491.837759, 6.165863]: RgbCamera(48): Expected Frame 41 not received
[WARN] [1646664492.137992, 6.165863]: Lidar(49): skipping old frame 39, expected 41
[WARN] [1646664493.140932, 6.165863]: Lidar(49): Expected Frame 41 not received
[WARN] [1646664493.143436, 6.165863]: SemanticSegmentationCamera(50): skipping old frame 37, expected 41
[WARN] [1646664494.145774, 6.165863]: SemanticSegmentationCamera(50): Expected Frame 41 not received
2022-03-07 20:18:15+0530 [-] [ERROR] [1646664495.772451, 6.215863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664496.773092, 6.215863]: RgbCamera(48): Expected Frame 42 not received
[WARN] [1646664497.774561, 6.215863]: Lidar(49): Expected Frame 42 not received
[WARN] [1646664497.776212, 6.215863]: SemanticSegmentationCamera(50): skipping old frame 38, expected 42
[WARN] [1646664498.777353, 6.215863]: SemanticSegmentationCamera(50): Expected Frame 42 not received
[WARN] [1646664499.524018, 6.265863]: RgbCamera(48): skipping old frame 39, expected 43
2022-03-07 20:18:19+0530 [-] [ERROR] [1646664499.524103, 6.265863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664500.526066, 6.265863]: RgbCamera(48): Expected Frame 43 not received
[WARN] [1646664500.527426, 6.265863]: Lidar(49): skipping old frame 40, expected 43
[WARN] [1646664501.528836, 6.265863]: Lidar(49): Expected Frame 43 not received
[WARN] [1646664502.531243, 6.265863]: SemanticSegmentationCamera(50): Expected Frame 43 not received
2022-03-07 20:18:23+0530 [-] [ERROR] [1646664503.617996, 6.315863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664504.617571, 6.315863]: RgbCamera(48): Expected Frame 44 not received
[WARN] [1646664505.295584, 6.315863]: Lidar(49): skipping old frame 41, expected 44
[WARN] [1646664506.297133, 6.315863]: Lidar(49): Expected Frame 44 not received
[WARN] [1646664506.300284, 6.315863]: SemanticSegmentationCamera(50): skipping old frame 39, expected 44
[WARN] [1646664507.302677, 6.315863]: SemanticSegmentationCamera(50): Expected Frame 44 not received
2022-03-07 20:18:27+0530 [-] [ERROR] [1646664507.836451, 6.365863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'
[WARN] [1646664507.837931, 6.365863]: RgbCamera(48): skipping old frame 40, expected 45
[WARN] [1646664508.840403, 6.365863]: RgbCamera(48): Expected Frame 45 not received
[WARN] [1646664509.782711, 6.365863]: Lidar(49): skipping old frame 42, expected 45
[WARN] [1646664510.784356, 6.365863]: Lidar(49): Expected Frame 45 not received
[WARN] [1646664510.992531, 6.365863]: SemanticSegmentationCamera(50): skipping old frame 40, expected 45
[WARN] [1646664511.995103, 6.365863]: SemanticSegmentationCamera(50): Expected Frame 45 not received
2022-03-07 20:18:32+0530 [-] [ERROR] [1646664512.427311, 6.415863]: Exception calling subscribe callback: 'Clock' object has no attribute '_buff'

[crabiner]

Hi @makaveli10 Did you modify sensor.py and bridge.py as in the PR Fix highrate sync #592? Can you add the print at the sensor calback to be sure? perhaps you need a different threshold at sensor.py _update_synchronous_sensor check the timestamps for more details