[Debug] Add debugging support for timestamps in socket communication (optional)

CMakeLists.txt

@@ -19,12 +19,17 @@ include(CTest)
 # TODO check how this can be added (supported from CMake 3.17)
 # list(APPEND CMAKE_CTEST_ARGUMENTS "--output-on-failure")
 
-OPTION ( CO_SIM_IO_BUILD_MPI          "Enable MPI communication and MPI examples" OFF )
-OPTION ( CO_SIM_IO_BUILD_C            "Building the CoSimIO for C"                OFF )
-OPTION ( CO_SIM_IO_BUILD_PYTHON       "Building the CoSimIO for Python"           OFF )
-OPTION ( CO_SIM_IO_BUILD_FORTRAN      "Building the CoSimIO for Fortran"          OFF )
-OPTION ( CO_SIM_IO_STRICT_COMPILER    "Compiler has more warnings"                OFF )
-OPTION ( CO_SIM_IO_BUILD_TESTING      "Build tests"                               ${BUILD_TESTING} )
+OPTION ( CO_SIM_IO_BUILD_MPI          "Enable MPI communication and MPI examples"             OFF )
+OPTION ( CO_SIM_IO_BUILD_C            "Building the CoSimIO for C"                            OFF )
+OPTION ( CO_SIM_IO_BUILD_PYTHON       "Building the CoSimIO for Python"                       OFF )
+OPTION ( CO_SIM_IO_BUILD_FORTRAN      "Building the CoSimIO for Fortran"                      OFF )
+OPTION ( CO_SIM_IO_STRICT_COMPILER    "Compiler has more warnings"                            OFF )
+OPTION ( CO_SIM_IO_TIMESTAMP_DEBUG    "Additional timestamp debugging info in communications" OFF )
+OPTION ( CO_SIM_IO_BUILD_TESTING      "Build tests"                              ${BUILD_TESTING} )
+
+if (${CO_SIM_IO_TIMESTAMP_DEBUG})
+    add_definitions( -DCO_SIM_IO_TIMESTAMP_DEBUG )
+endif(${CO_SIM_IO_TIMESTAMP_DEBUG})
 
 if(NOT DEFINED CO_SIM_IO_BUILD_TYPE)
     if(CMAKE_BUILD_TYPE)

co_sim_io/includes/communication/base_socket_communication.hpp

@@ -69,6 +69,8 @@ class CO_SIM_IO_API BaseSocketCommunication : public Communication
     void SendSize(const std::uint64_t Size);
 
     std::uint64_t ReceiveSize();
+
+    void DebugTimeInfo(const std::string& rLabel, const std::string& rMessage) const;
 };
 
 } // namespace Internals

co_sim_io/sources/communication/base_socket_communication.cpp

@@ -11,6 +11,11 @@
 //
 
 // System includes
+#ifdef CO_SIM_IO_TIMESTAMP_DEBUG
+#include <chrono>
+#include <ctime>
+#include <iomanip>
+#endif
 
 // Project includes
 #include "includes/communication/base_socket_communication.hpp"
@@ -37,9 +42,13 @@ Info BaseSocketCommunication<TSocketType>::ConnectDetail(const Info& I_Info)
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("ConnectDetail", "Before connect");
+
     // required such that asio keeps listening for incoming messages
     mContextThread = std::thread([this]() { mAsioContext.run(); });
 
+    DebugTimeInfo("ConnectDetail", "After connect");
+
     return Info();
 
     CO_SIM_IO_CATCH
@@ -50,14 +59,18 @@ Info BaseSocketCommunication<TSocketType>::DisconnectDetail(const Info& I_Info)
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("DisconnectDetail", "Before disconnect");
+
     // Request the context to close
     mAsioContext.stop();
 
     // Tidy up the context thread
     if (mContextThread.joinable()) mContextThread.join();
 
     mpAsioSocket->close();
-    mpAsioSocket.reset(); // important to release the resouces (otherwise crashes in Win with release compilation)
+    mpAsioSocket.reset(); // important to release the resources (otherwise crashes in Win with release compilation)
+
+    DebugTimeInfo("DisconnectDetail", "After disconnect");
 
     return Info();
 
@@ -73,8 +86,13 @@ double BaseSocketCommunication<TSocketType>::SendString(
 
     SendSize(rData.size()); // serves also as synchronization for time measurement
 
+    DebugTimeInfo("SendString", "Before send");
+
     const auto start_time(std::chrono::steady_clock::now());
     asio::write(*mpAsioSocket, asio::buffer(rData.data(), rData.size()));
+
+    DebugTimeInfo("SendString", "After send");
+
     return Utilities::ElapsedSeconds(start_time);
 
     CO_SIM_IO_CATCH
@@ -89,9 +107,14 @@ double BaseSocketCommunication<TSocketType>::ReceiveString(
 
     std::size_t received_size = ReceiveSize(); // serves also as synchronization for time measurement
 
+    DebugTimeInfo("ReceiveString", "Before receive");
+
     const auto start_time(std::chrono::steady_clock::now());
     rData.resize(received_size);
     asio::read(*mpAsioSocket, asio::buffer(&(rData.front()), received_size));
+
+    DebugTimeInfo("ReceiveString", "After receive");
+
     return Utilities::ElapsedSeconds(start_time);
 
     CO_SIM_IO_CATCH
@@ -104,10 +127,15 @@ double BaseSocketCommunication<TSocketType>::SendDataContainer(
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("SendDataContainer", "Before send");
+
     SendSize(rData.size()); // serves also as synchronization for time measurement
 
     const auto start_time(std::chrono::steady_clock::now());
     asio::write(*mpAsioSocket, asio::buffer(rData.data(), rData.size()*sizeof(double)));
+
+    DebugTimeInfo("SendDataContainer", "After send");
+
     return Utilities::ElapsedSeconds(start_time);
 
     CO_SIM_IO_CATCH
@@ -120,11 +148,16 @@ double BaseSocketCommunication<TSocketType>::ReceiveDataContainer(
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("ReceiveDataContainer", "Before receive");
+
     std::size_t received_size = ReceiveSize(); // serves also as synchronization for time measurement
 
     const auto start_time(std::chrono::steady_clock::now());
     rData.resize(received_size);
     asio::read(*mpAsioSocket, asio::buffer(rData.data(), rData.size()*sizeof(double)));
+
+    DebugTimeInfo("ReceiveDataContainer", "After receive");
+
     return Utilities::ElapsedSeconds(start_time);
 
     CO_SIM_IO_CATCH
@@ -135,8 +168,15 @@ void BaseSocketCommunication<TSocketType>::SendSize(const std::uint64_t Size)
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("SendSize", "Before send");
+#ifdef CO_SIM_IO_TIMESTAMP_DEBUG
+    CO_SIM_IO_INFO("CoSimIO::SendSize") << Size << std::endl;
+#endif
+
     asio::write(*mpAsioSocket, asio::buffer(&Size, sizeof(Size)));
 
+    DebugTimeInfo("SendSize", "After send");
+
     CO_SIM_IO_CATCH
 }
 
@@ -145,13 +185,42 @@ std::uint64_t BaseSocketCommunication<TSocketType>::ReceiveSize()
 {
     CO_SIM_IO_TRY
 
+    DebugTimeInfo("ReceiveSize", "Before receive");
+
     std::uint64_t imp_size_u;
     asio::read(*mpAsioSocket, asio::buffer(&imp_size_u, sizeof(imp_size_u)));
+
+    DebugTimeInfo("ReceiveSize", "After receive");
+#ifdef CO_SIM_IO_TIMESTAMP_DEBUG
+    CO_SIM_IO_INFO("CoSimIO::ReceiveSize") << imp_size_u << std::endl;
+#endif
+
     return imp_size_u;
 
     CO_SIM_IO_CATCH
 }
 
+template<class TSocketType>
+void BaseSocketCommunication<TSocketType>::DebugTimeInfo(
+    const std::string& rLabel,
+    const std::string& rMessage
+    ) const
+{
+#ifdef CO_SIM_IO_TIMESTAMP_DEBUG
+    // Get the current time
+    auto now = std::chrono::system_clock::now();
+
+    // Convert to time_t to get calendar time
+    std::time_t now_time = std::chrono::system_clock::to_time_t(now);
+
+    // Convert to local time
+    std::tm local_time = *std::localtime(&now_time);
+
+    // Convert to calendar time to get localtime
+    CO_SIM_IO_INFO("CoSimIO::" + rLabel) << rMessage << " time: " << std::put_time(&local_time, "%H:%M:%S") << std::endl;
+#endif
+}
+
 template class BaseSocketCommunication<asio::ip::tcp::socket>;
 template class BaseSocketCommunication<asio::local::stream_protocol::socket>;