debug logging in ecal_registration_provider

improved sample massive_pub_sub to demonstrate registration provide / receive locking performance issue

ecal/core/src/registration/ecal_registration_provider.cpp

@@ -147,34 +147,42 @@ namespace eCAL
 
       // and add process registration sample
       sample_list.samples.push_back(Registration::GetProcessRegisterSample());
+      //std::cout << "CRegistrationProvider::RegisterSendThread sample_list size Process    : " << sample_list.samples.size() << std::endl;
 
 #if ECAL_CORE_SUBSCRIBER
       // add subscriber registrations
       if (g_subgate() != nullptr) g_subgate()->GetRegistrations(sample_list);
+      //std::cout << "CRegistrationProvider::RegisterSendThread sample_list size SubScriber : " << sample_list.samples.size() << std::endl;
 #endif
 
 #if ECAL_CORE_PUBLISHER
       // add publisher registrations
       if (g_pubgate() != nullptr) g_pubgate()->GetRegistrations(sample_list);
+      //std::cout << "CRegistrationProvider::RegisterSendThread sample_list size Publisher  : " << sample_list.samples.size() << std::endl;
 #endif
 
 #if ECAL_CORE_SERVICE
       // add server registrations
       if (g_servicegate() != nullptr) g_servicegate()->GetRegistrations(sample_list);
+      //std::cout << "CRegistrationProvider::RegisterSendThread sample_list size Server     : " << sample_list.samples.size() << std::endl;
 
       // add client registrations
       if (g_clientgate() != nullptr) g_clientgate()->GetRegistrations(sample_list);
+      //std::cout << "CRegistrationProvider::RegisterSendThread sample_list size Clients    : " << sample_list.samples.size() << std::endl;
 #endif
 
-      // send collected registration sample list
-      m_reg_sender->SendSampleList(sample_list);
-
-      // send asynchronously applied samples at the end of the registration loop
+      // append additional applied (un)registration samples
       {
+        //std::cout << "CRegistrationProvider::RegisterSendThread  AQUIRE MUTEX (m_applied_sample_list_mtx)" << std::endl;
         const std::lock_guard<std::mutex> lock(m_applied_sample_list_mtx);
-        m_reg_sender->SendSampleList(m_applied_sample_list);
+        //std::cout << "CRegistrationProvider::RegisterSendThread  GOT MUTEX    (m_applied_sample_list_mtx)" << std::endl;
+        sample_list.samples.splice(sample_list.samples.end(), m_applied_sample_list.samples);
         m_applied_sample_list.samples.clear();
       }
+
+      // send collected registration sample list
+      m_reg_sender->SendSampleList(sample_list);
+      std::cout << "CRegistrationProvider::RegisterSendThread  LIST SENT" << std::endl;
     }
   }
 }

ecal/samples/cpp/benchmarks/massive_pub_sub/src/massive_pub_sub.cpp

@@ -82,7 +82,7 @@ int main(int argc, char** argv)
 
     // calculate the duration
     auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
-    std::cout << "Time taken for subscriber creation: " << duration << " milliseconds" << std::endl;
+    std::cout << "Time taken for subscriber creation: " << duration << " milliseconds" << std::endl << std::endl;
   }
 
   // sleep for a few seconds
@@ -114,12 +114,65 @@ int main(int argc, char** argv)
 
     // calculate the duration
     auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
-    std::cout << "Time taken for publisher creation: " << duration << " milliseconds" << std::endl;
+    std::cout << "Time taken for publisher creation: " << duration << " milliseconds" << std::endl << std::endl;
   }
-  std::cout << std::endl;
 
   // sleep for a few seconds
-  std::this_thread::sleep_for(std::chrono::seconds(final_sleep_sec));
+  std::this_thread::sleep_for(std::chrono::seconds(in_between_sleep_sec));
+
+  // wait for full registration
+  std::cout << "Wait for publisher/subscriber registration." << std::endl;
+  {
+    // start time measurement
+    auto start_time = std::chrono::high_resolution_clock::now();
+
+    size_t num_pub(0);
+    size_t num_sub(0);
+    while ((num_pub < publisher_number) || (num_sub < subscriber_number))
+    {
+      num_pub = eCAL::Registration::GetPublisherIDs().size();
+      num_sub = eCAL::Registration::GetSubscriberIDs().size();
+
+      std::cout << "Registered publisher : " << num_pub << std::endl;
+      std::cout << "Registered subscriber: " << num_sub << std::endl;
+
+      // sleep for 1000 milliseconds
+      std::this_thread::sleep_for(std::chrono::milliseconds(1000));
+    }
+
+    // stop time measurement
+    auto end_time = std::chrono::high_resolution_clock::now();
+
+    // calculate the duration
+    auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
+    std::cout << "Time taken to get all registered: " << duration << " milliseconds" << std::endl << std::endl;
+  }
+
+  // get publisher information
+  std::cout << "Get publisher information. (";
+  size_t num_pub(0);
+  {
+    // start time measurement
+    auto start_time = std::chrono::high_resolution_clock::now();
+
+    const auto pub_ids = eCAL::Registration::GetPublisherIDs();
+    num_pub = pub_ids.size();
+    for (const auto& id : pub_ids)
+    {
+      eCAL::Registration::SQualityTopicInfo topic_info;
+      eCAL::Registration::GetPublisherInfo(id, topic_info);
+    }
+
+    // stop time measurement
+    auto end_time = std::chrono::high_resolution_clock::now();
+
+    // calculate the duration
+    auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
+    std::cout << num_pub << ")" << std::endl << "Time taken to get publisher information: " << duration << " milliseconds" << std::endl << std::endl;
+  }
+
+  // sleep for a few seconds
+  //std::this_thread::sleep_for(std::chrono::seconds(final_sleep_sec));
 
   // finalize eCAL API
   eCAL::Finalize();