From 2352cdf2954ae6741267cff0b33a40204a2b11bf Mon Sep 17 00:00:00 2001 From: "Becker, Lukas" Date: Mon, 28 Oct 2024 09:33:35 +0100 Subject: [PATCH] SILKit-1607: Fix PR requests --- Demos/Can/CanDemo.cpp | 5 ++-- Demos/PubSub/PubSubDemo.cpp | 5 ++-- .../core/vasio/ConnectKnownParticipants.cpp | 2 +- .../core/vasio/ConnectKnownParticipants.hpp | 4 +-- .../services/logging/ILoggerInternal.hpp | 8 ++--- .../services/logging/MessageTracing.hpp | 23 +++++++------- .../orchestration/SystemStateTracker.cpp | 30 +++++++++---------- .../orchestration/TimeConfiguration.hpp | 1 - .../orchestration/TimeSyncService.cpp | 17 +++++------ 9 files changed, 43 insertions(+), 52 deletions(-) diff --git a/Demos/Can/CanDemo.cpp b/Demos/Can/CanDemo.cpp index db7bfe369..5cef427fd 100644 --- a/Demos/Can/CanDemo.cpp +++ b/Demos/Can/CanDemo.cpp @@ -198,7 +198,7 @@ int main(int argc, char** argv) std::cout << "now=" << now << ", duration=" << duration << std::endl; SendFrame(canController, logger); std::this_thread::sleep_for(sleepTimePerTick); - }, + }, 5ms); } else @@ -207,8 +207,7 @@ int main(int argc, char** argv) [sleepTimePerTick](std::chrono::nanoseconds now, std::chrono::nanoseconds duration) { std::cout << "now=" << now << ", duration=" << duration << std::endl; std::this_thread::sleep_for(sleepTimePerTick); - }, - 5ms); + }, 5ms); } auto finalStateFuture = lifecycleService->StartLifecycle(); diff --git a/Demos/PubSub/PubSubDemo.cpp b/Demos/PubSub/PubSubDemo.cpp index 6171d56a5..527426b49 100644 --- a/Demos/PubSub/PubSubDemo.cpp +++ b/Demos/PubSub/PubSubDemo.cpp @@ -232,7 +232,7 @@ int main(int argc, char** argv) PublishData(gpsPublisher, temperaturePublisher); } std::this_thread::sleep_for(1s); - }, + }, 1s); } else @@ -242,8 +242,7 @@ int main(int argc, char** argv) auto nowMs = std::chrono::duration_cast(now); std::cout << "now=" << nowMs.count() << "ms" << std::endl; std::this_thread::sleep_for(1s); - }, - 1s); + }, 1s); } auto finalStateFuture = lifecycleService->StartLifecycle(); diff --git a/SilKit/source/core/vasio/ConnectKnownParticipants.cpp b/SilKit/source/core/vasio/ConnectKnownParticipants.cpp index 1d4414daf..f52d3da08 100644 --- a/SilKit/source/core/vasio/ConnectKnownParticipants.cpp +++ b/SilKit/source/core/vasio/ConnectKnownParticipants.cpp @@ -61,7 +61,7 @@ ConnectKnownParticipants::ConnectKnownParticipants(IIoContext& ioContext, IConne } -void ConnectKnownParticipants::SetLogger(SilKit::Services::Logging::ILoggerInternal& logger) +void ConnectKnownParticipants::SetLogger(SilKit::Services::Logging::ILogger& logger) { SILKIT_ASSERT(_logger == nullptr); _logger = &logger; diff --git a/SilKit/source/core/vasio/ConnectKnownParticipants.hpp b/SilKit/source/core/vasio/ConnectKnownParticipants.hpp index 39a70e161..3202276ec 100644 --- a/SilKit/source/core/vasio/ConnectKnownParticipants.hpp +++ b/SilKit/source/core/vasio/ConnectKnownParticipants.hpp @@ -139,7 +139,7 @@ class ConnectKnownParticipants IConnectKnownParticipantsListener* _listener{nullptr}; ConnectKnownParticipantsSettings _settings; - SilKit::Services::Logging::ILoggerInternal* _logger{nullptr}; + SilKit::Services::Logging::ILogger* _logger{nullptr}; std::promise> _knownParticipants; std::atomic _connectStage{ConnectStage::INVALID}; @@ -152,7 +152,7 @@ class ConnectKnownParticipants IConnectKnownParticipantsListener& listener, const ConnectKnownParticipantsSettings& settings); - void SetLogger(SilKit::Services::Logging::ILoggerInternal& logger); + void SetLogger(SilKit::Services::Logging::ILogger& logger); void SetKnownParticipants(const std::vector& peerInfos); void StartConnecting(); diff --git a/SilKit/source/services/logging/ILoggerInternal.hpp b/SilKit/source/services/logging/ILoggerInternal.hpp index 41af90544..649534139 100644 --- a/SilKit/source/services/logging/ILoggerInternal.hpp +++ b/SilKit/source/services/logging/ILoggerInternal.hpp @@ -25,6 +25,8 @@ WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */ #include "silkit/services/logging/ILogger.hpp" +#include "StructuredLoggingKeys.hpp" + #include "SilKitFmtFormatters.hpp" #include "fmt/format.h" #include @@ -90,12 +92,6 @@ class LoggerMessage _msg = std::move(newMsg); } - template - void FormatKeyValue(Key&& key, fmt::format_string fmt) - { - _keyValues[std::forward(key)] = fmt::format(fmt); - } - template void SetKeyValue(Key&& key, Value&& value) { diff --git a/SilKit/source/services/logging/MessageTracing.hpp b/SilKit/source/services/logging/MessageTracing.hpp index 2c09d9093..55af1e7ea 100644 --- a/SilKit/source/services/logging/MessageTracing.hpp +++ b/SilKit/source/services/logging/MessageTracing.hpp @@ -54,41 +54,40 @@ void TraceRx(Logging::ILoggerInternal* logger, const Core::IServiceEndpoint* add const Core::ServiceDescriptor& from) { Logging::LoggerMessage lm{logger, Logging::Level::Trace}; - lm.SetMessage("Recv event"); + lm.SetMessage("Recv message"); - std::unordered_map serviceDescriptorKVs{addr->GetServiceDescriptor().to_keyValues()}; - for (const auto& pair : serviceDescriptorKVs) + for (const auto& pair : addr->GetServiceDescriptor().to_keyValues()) { lm.SetKeyValue(pair.first, pair.second); } - lm.SetKeyValue("msg", (fmt::format("{}", msg))); + lm.SetKeyValue(Logging::Keys::MSG, (fmt::format("{}", msg))); auto virtualTimeStamp = GetTimestamp(msg); if (virtualTimeStamp != std::chrono::nanoseconds::duration::min()) { - lm.SetKeyValue("VirtualTimeNS", (fmt::format("{}", virtualTimeStamp.count() ))); + lm.SetKeyValue(Logging::Keys::VIRTUAL_TIME_NS, (fmt::format("{}", virtualTimeStamp.count()))); } - lm.SetKeyValue("From", from.GetParticipantName()); + lm.SetKeyValue(Logging::Keys::FROM, from.GetParticipantName()); lm.Dispatch(); - //Logging::Trace(logger, "Recv on {} from {}: {}", addr->GetServiceDescriptor(), from.GetParticipantName(), msg); } template void TraceTx(Logging::ILoggerInternal* logger, const Core::IServiceEndpoint* addr, const SilKitMessageT& msg) { Logging::LoggerMessage lm{logger, Logging::Level::Trace}; - lm.SetMessage("Send event"); - std::unordered_map serviceDescriptorKVs{addr->GetServiceDescriptor().to_keyValues()}; - for (const auto& pair : serviceDescriptorKVs) + lm.SetMessage("Send message"); + + for (const auto& pair : addr->GetServiceDescriptor().to_keyValues()) { lm.SetKeyValue(pair.first, pair.second); } - lm.SetKeyValue("msg", (fmt::format("{}", msg))); + + lm.SetKeyValue(Logging::Keys::MSG, (fmt::format("{}", msg))); auto virtualTimeStamp = GetTimestamp(msg); if (virtualTimeStamp != std::chrono::nanoseconds::duration::min()) { - lm.SetKeyValue("VirtualTimeNS", (fmt::format("{}", virtualTimeStamp.count() ))); + lm.SetKeyValue(Logging::Keys::VIRTUAL_TIME_NS, (fmt::format("{}", virtualTimeStamp.count()))); } lm.Dispatch(); } diff --git a/SilKit/source/services/orchestration/SystemStateTracker.cpp b/SilKit/source/services/orchestration/SystemStateTracker.cpp index 7e92befe5..1d6c15bc0 100644 --- a/SilKit/source/services/orchestration/SystemStateTracker.cpp +++ b/SilKit/source/services/orchestration/SystemStateTracker.cpp @@ -142,9 +142,9 @@ auto SystemStateTracker::UpdateParticipantStatus(const ParticipantStatus& newPar { Log::LoggerMessage lm{_logger, Log::Level::Debug}; lm.SetMessage("Updating participant status"); - lm.SetKeyValue("ParticipantName", participantName); - lm.SetKeyValue("OldParticipantState", fmt::format("{}", oldParticipantState)); - lm.SetKeyValue("NewParticipantState", fmt::format("{}", newParticipantState)); + lm.SetKeyValue(Log::Keys::PARTICIPANT_NAME, participantName); + lm.SetKeyValue(Log::Keys::OLD_PARTICIPANT_STATE, fmt::format("{}", oldParticipantState)); + lm.SetKeyValue(Log::Keys::NEW_PARTICIPANT_STATE, fmt::format("{}", newParticipantState)); lm.Dispatch(); } // Check if transition from the old to the new participant state is valid @@ -154,11 +154,11 @@ auto SystemStateTracker::UpdateParticipantStatus(const ParticipantStatus& newPar Log::LoggerMessage lm{_logger, logLevel}; lm.SetMessage("SystemMonitor detected invalid ParticipantState transition!"); - lm.SetKeyValue("ParticipantName", participantName); - lm.SetKeyValue("OldParticipantState", fmt::format("{}", oldParticipantState)); - lm.SetKeyValue("NewParticipantState", fmt::format("{}", newParticipantState)); - lm.SetKeyValue("EnterTime", FormatTimePoint(newParticipantStatus.enterTime)); - lm.SetKeyValue("EnterReason", newParticipantStatus.enterReason); + lm.SetKeyValue(Log::Keys::PARTICIPANT_NAME, participantName); + lm.SetKeyValue(Log::Keys::OLD_PARTICIPANT_STATE, fmt::format("{}", oldParticipantState)); + lm.SetKeyValue(Log::Keys::NEW_PARTICIPANT_STATE, fmt::format("{}", newParticipantState)); + lm.SetKeyValue(Log::Keys::ENTER_TIME, FormatTimePoint(newParticipantStatus.enterTime)); + lm.SetKeyValue(Log::Keys::ENTER_REASON, newParticipantStatus.enterReason); lm.Dispatch(); // NB: Failing validation doesn't actually stop the participants state from being changed, it just logs the @@ -183,7 +183,7 @@ auto SystemStateTracker::UpdateParticipantStatus(const ParticipantStatus& newPar { Log::LoggerMessage lm{_logger, Log::Level::Debug}; lm.SetMessage("The participant state has changed!"); - lm.SetKeyValue("ParticipantName", participantName); + lm.SetKeyValue(Log::Keys::PARTICIPANT_NAME, participantName); lm.Dispatch(); } @@ -195,9 +195,9 @@ auto SystemStateTracker::UpdateParticipantStatus(const ParticipantStatus& newPar { Log::LoggerMessage lm{_logger, Log::Level::Debug}; lm.SetMessage("Computed new system state update!"); - lm.SetKeyValue("ParticipantName", participantName); - lm.SetKeyValue("OldSystemState", fmt::format("{}", oldSystemState)); - lm.SetKeyValue("NewSystemState", fmt::format("{}", newSystemState)); + lm.SetKeyValue(Log::Keys::PARTICIPANT_NAME, participantName); + lm.SetKeyValue(Log::Keys::OLD_PARTICIPANT_STATE, fmt::format("{}", oldSystemState)); + lm.SetKeyValue(Log::Keys::NEW_PARTICIPANT_STATE, fmt::format("{}", newSystemState)); lm.Dispatch(); } @@ -205,9 +205,9 @@ auto SystemStateTracker::UpdateParticipantStatus(const ParticipantStatus& newPar { Log::LoggerMessage lm{_logger, Log::Level::Debug}; lm.SetMessage("The system state has changed!"); - lm.SetKeyValue("ParticipantName", participantName); - lm.SetKeyValue("OldSystemState", fmt::format("{}", oldSystemState)); - lm.SetKeyValue("NewSystemState", fmt::format("{}", newSystemState)); + lm.SetKeyValue(Log::Keys::PARTICIPANT_NAME, participantName); + lm.SetKeyValue(Log::Keys::OLD_PARTICIPANT_STATE, fmt::format("{}", oldSystemState)); + lm.SetKeyValue(Log::Keys::NEW_PARTICIPANT_STATE, fmt::format("{}", newSystemState)); lm.Dispatch(); _systemState = newSystemState; diff --git a/SilKit/source/services/orchestration/TimeConfiguration.hpp b/SilKit/source/services/orchestration/TimeConfiguration.hpp index 17a917205..af29776bd 100755 --- a/SilKit/source/services/orchestration/TimeConfiguration.hpp +++ b/SilKit/source/services/orchestration/TimeConfiguration.hpp @@ -25,7 +25,6 @@ WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */ #include #include "OrchestrationDatatypes.hpp" -//#include "silkit/services/logging/ILogger.hpp" #include "ILoggerInternal.hpp" namespace SilKit { diff --git a/SilKit/source/services/orchestration/TimeSyncService.cpp b/SilKit/source/services/orchestration/TimeSyncService.cpp index 6e398937c..93dc8655f 100644 --- a/SilKit/source/services/orchestration/TimeSyncService.cpp +++ b/SilKit/source/services/orchestration/TimeSyncService.cpp @@ -473,7 +473,7 @@ void TimeSyncService::ReceiveMsg(const IServiceEndpoint* from, const NextSimTask { Logging::LoggerMessage lm{_logger, Logging::Level::Debug}; lm.SetMessage("Received NextSimTask from participant \'{}\' but TimeSyncPolicy is not yet configured"); - lm.SetKeyValue("ParticipantName", from->GetServiceDescriptor().GetParticipantName()); + lm.SetKeyValue(Logging::Keys::PARTICIPANT_NAME, from->GetServiceDescriptor().GetParticipantName()); lm.Dispatch(); } } @@ -492,8 +492,8 @@ void TimeSyncService::ExecuteSimStep(std::chrono::nanoseconds timePoint, std::ch { Logging::LoggerMessage lm{_logger, Logging::Level::Trace}; lm.SetMessage("Starting next Simulation Step."); - lm.SetKeyValue("WaitingTime", fmt::format("{}", std::chrono::duration_cast(_waitTimeMonitor.CurrentDuration()).count())); - lm.SetKeyValue("VirtualTimeNS", fmt::format("{}", timePoint.count())); + lm.SetKeyValue(Logging::Keys::WAITING_TIME, fmt::format("{}", std::chrono::duration_cast(_waitTimeMonitor.CurrentDuration()).count())); + lm.SetKeyValue(Logging::Keys::VIRTUAL_TIME_NS, fmt::format("{}", timePoint.count())); lm.Dispatch(); } @@ -536,8 +536,8 @@ void TimeSyncService::LogicalSimStepCompleted(std::chrono::durationAdd(1); Logging::LoggerMessage lm{_logger, Logging::Level::Trace}; lm.SetMessage("Finished Simulation Step."); - lm.SetKeyValue("ExecutionTime", fmt::format("{}", logicalSimStepTimeMs.count())); - lm.SetKeyValue("VirtualTimeNS", fmt::format("{}", Now().count())); + lm.SetKeyValue(Logging::Keys::EXECUTION_TIME, fmt::format("{}", logicalSimStepTimeMs.count())); + lm.SetKeyValue(Logging::Keys::VIRTUAL_TIME_NS, fmt::format("{}", Now().count())); lm.Dispatch(); _waitTimeMonitor.StartMeasurement(); } @@ -678,7 +678,7 @@ bool TimeSyncService::ParticipantHasAutonomousSynchronousCapability(const std::s Logging::LoggerMessage lm{_participant->GetLoggerInternal(), Logging::Level::Error}; lm.SetMessage("Participant does not support simulations with participants that use an autonomous lifecycle " "and virtual time synchronization. Please consider upgrading Participant. Aborting simulation..."); - lm.SetKeyValue("ParticipantName", participantName); + lm.SetKeyValue(Logging::Keys::PARTICIPANT_NAME, participantName); lm.Dispatch(); return false; } @@ -694,7 +694,7 @@ bool TimeSyncService::AbortHopOnForCoordinatedParticipants() const Logging::LoggerMessage lm{_participant->GetLoggerInternal(), Logging::Level::Error}; lm.SetMessage("This participant is running with a coordinated lifecycle and virtual time synchronization and wants " "to join an already running simulation. This is not allowed, aborting simulation..."); - lm.SetKeyValue("ParticipantName", _participant->GetParticipantName()); + lm.SetKeyValue(Logging::Keys::PARTICIPANT_NAME, _participant->GetParticipantName()); lm.Dispatch(); _participant->GetSystemController()->AbortSimulation(); @@ -771,7 +771,7 @@ void TimeSyncService::StartWallClockCouplingThread() // AsyncSimStepHandler not completed? Execution is lagging behind. Don't send the NextSimStep now, but after completion. Logging::LoggerMessage lm{_participant->GetLoggerInternal(), Logging::Level::Warn}; lm.SetMessage("Simulation step was not completed in time to achieve wall clock coupling."); - lm.SetKeyValue("ParticipantName", _participant->GetParticipantName()); + lm.SetKeyValue(Logging::Keys::PARTICIPANT_NAME, _participant->GetParticipantName()); lm.Dispatch(); _wallClockReachedBeforeCompletion = true; @@ -797,7 +797,6 @@ void TimeSyncService::StopWallClockCouplingThread() } } -// todo: evtl weg bool TimeSyncService::IsBlocking() const { return _timeConfiguration.IsBlocking();