Different publishing frequency of consecutive publishers

edit

I am trying to understand the ROS message transport system better. My current system, which runs on rospy and Kinetic and is completely local to one computer, consists of the following:

1. A PointCloud2 topic "cloud_raw" from the camera driver (rostopic hz = 30Hz and bw = 300Mbps)
2. An Image topic "image_raw" from the same camera driver (rostopic hz = 30Hz and bw = 30Mbps)
3. My node's message_filters.ApproximateTimeSynchronizer that syncs both topics, whose callback simply buffers both's latest message.
4. My node's long processing function (about 0.2s) in the main loop. It scoops from said buffer and does its thing.
5. My node's two publishers, one for testing and one that publishes said heavy function's output.

The code looks like this:

buffer_latest = None

def sync_callback(image, cloud):
    buffer_latest = [image, cloud]

image_sub = message_filters.Subscriber("image_raw", Image)
cloud_sub = message_filters.Subscriber("cloud_raw", PointCloud2)

ts = message_filters.ApproximateTimeSynchronizer([image_sub, cloud_sub], 1, 0.1, allow_headerless=False)
ts.registerCallback(sync_callback)

test_pub = rospy.Publisher("test", Empty, queue_size=1)
output_pub = rospy.Publisher("output", PointCloud2, queue_size=1)

def run():
    test_pub.publish(Empty()) # <------------------------ first publisher in question

    input_data = buffer_latest
    processed_cloud = heavy_processing(input_data)

    output_pub.publish(processed_cloud)  # <------------- second publisher in question

while not rospy.is_shutdown():
    run()

Now when I do rostopic hz, "output" returns 4.2Hz whereas "test" returns 4.8Hz.

Before I trip on myself and ask any dumb(er) questions... what is the reason for the difference in frequency? Shouldn't both topics be published at different times, i.e. "output" 0.2s after "test", but at exactly the same frequency?