diff --git a/SilKit/IntegrationTests/CMakeLists.txt b/SilKit/IntegrationTests/CMakeLists.txt index 0d24a9f3e..eeb072161 100644 --- a/SilKit/IntegrationTests/CMakeLists.txt +++ b/SilKit/IntegrationTests/CMakeLists.txt @@ -255,6 +255,22 @@ add_silkit_test_to_executable(SilKitIntegrationTests SOURCES ITest_Config.cpp ) +# ============================================================ +# End-to-end integration tests +# ============================================================ + +add_silkit_test_to_executable(SilKitIntegrationTests + SOURCES ITest_HealthCheck.cpp +) + +add_silkit_test_to_executable(SilKitIntegrationTests + SOURCES ITest_PcapTracing.cpp +) + +add_silkit_test_to_executable(SilKitIntegrationTests + SOURCES ITest_DomainSockets.cpp +) + add_silkit_test_to_executable(SilKitIntegrationTests - SOURCES ITest_RemoteLogging.cpp + SOURCES ITest_ConfigPrecedence.cpp ) diff --git a/SilKit/IntegrationTests/ITest_ConfigPrecedence.cpp b/SilKit/IntegrationTests/ITest_ConfigPrecedence.cpp new file mode 100644 index 000000000..53eeec993 --- /dev/null +++ b/SilKit/IntegrationTests/ITest_ConfigPrecedence.cpp @@ -0,0 +1,146 @@ +// SPDX-FileCopyrightText: 2026 Vector Informatik GmbH +// +// SPDX-License-Identifier: MIT + +// Values in the participant configuration take precedence over the values passed to the API. + +#include +#include +#include + +#include "silkit/SilKit.hpp" +#include "silkit/services/all.hpp" +#include "silkit/services/orchestration/all.hpp" +#include "silkit/vendor/CreateSilKitRegistry.hpp" + +#include "SimTestHarness.hpp" + +#include "gmock/gmock.h" +#include "gtest/gtest.h" + +namespace { + +using namespace std::chrono_literals; +using namespace SilKit::Services::Can; +using namespace SilKit::Services::Orchestration; + +class ITest_ConfigPrecedence : public testing::Test +{ +protected: + void SetUp() override + { + _registry = SilKit::Vendor::Vector::CreateSilKitRegistry(SilKit::Config::ParticipantConfigurationFromString("")); + _registryUri = _registry->StartListening("silkit://127.0.0.1:0"); + } + + std::unique_ptr _registry; + std::string _registryUri; +}; + +TEST_F(ITest_ConfigPrecedence, participant_name_from_configuration_overrides_api_argument) +{ + auto observer = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(""), "Observer", + _registryUri); + auto* systemMonitor = observer->CreateSystemMonitor(); + + std::promise connectedPromise; + bool connectedSeen = false; + systemMonitor->SetParticipantConnectedHandler([&](const ParticipantConnectionInformation& info) { + if (info.participantName != "Observer" && !connectedSeen) + { + connectedSeen = true; + connectedPromise.set_value(info.participantName); + } + }); + + auto participant = SilKit::CreateParticipant( + SilKit::Config::ParticipantConfigurationFromString("ParticipantName: NameFromConfiguration"), "NameFromApi", + _registryUri); + + auto connected = connectedPromise.get_future(); + ASSERT_EQ(connected.wait_for(10s), std::future_status::ready); + EXPECT_EQ(connected.get(), "NameFromConfiguration"); + EXPECT_FALSE(systemMonitor->IsParticipantConnected("NameFromApi")); +} + +TEST_F(ITest_ConfigPrecedence, registry_uri_from_configuration_overrides_api_argument) +{ + // Nothing listens on port 1. If the API argument were used, creating the participant would throw. + const auto unreachableRegistryUri = "silkit://127.0.0.1:1"; + const auto config = R"( +Middleware: + RegistryUri: )" + _registryUri + "\n"; + + std::unique_ptr participant; + EXPECT_NO_THROW(participant = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(config), + "Participant", unreachableRegistryUri)); + EXPECT_NE(participant, nullptr); +} + +TEST_F(ITest_ConfigPrecedence, api_registry_uri_is_used_if_configuration_has_none) +{ + std::unique_ptr participant; + EXPECT_NO_THROW(participant = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(""), + "Participant", _registryUri)); +} + +// The CAN controller of the writer is created on network "NetworkFromApi", but its configuration moves it to +// "SharedNetwork", where the reader listens. The frame only arrives if the configured network is used. +TEST(ITest_ConfigPrecedenceNetwork, controller_network_from_configuration_overrides_api_argument) +{ + const auto writerConfig = R"( +CanControllers: +- Name: CAN1 + Network: SharedNetwork +)"; + + SilKit::Tests::SimTestHarnessArgs args; + args.syncParticipantNames = {"CanWriter", "CanReader"}; + args.deferParticipantCreation = true; + SilKit::Tests::SimTestHarness testHarness{args}; + + auto* writer = testHarness.GetParticipant("CanWriter", writerConfig); + auto* writerController = writer->Participant()->CreateCanController("CAN1", "NetworkFromApi"); + writer->GetOrCreateLifecycleService()->SetCommunicationReadyHandler([writerController] { + writerController->SetBaudRate(500'000, 0, 0); + writerController->Start(); + }); + writer->GetOrCreateTimeSyncService()->SetSimulationStepHandler( + [writerController](std::chrono::nanoseconds, std::chrono::nanoseconds) { + CanFrame frame{}; + frame.canId = 42; + frame.dlc = 1; + std::array payload{0x2a}; + frame.dataField = SilKit::Util::MakeSpan(payload); + writerController->SendFrame(frame); + }, 1ms); + + auto* reader = testHarness.GetParticipant("CanReader", ""); + auto* readerController = reader->Participant()->CreateCanController("CAN1", "SharedNetwork"); + reader->GetOrCreateLifecycleService()->SetCommunicationReadyHandler([readerController] { + readerController->SetBaudRate(500'000, 0, 0); + readerController->Start(); + }); + reader->GetOrCreateTimeSyncService()->SetSimulationStepHandler( + [reader](std::chrono::nanoseconds now, std::chrono::nanoseconds) { + // Stop in any case, so a wrong network fails the expectation below instead of timing out. + if (now >= 50ms) + { + reader->Stop(); + } + }, 1ms); + + bool received = false; + readerController->AddFrameHandler([reader, &received](ICanController*, const CanFrameEvent& event) { + if (event.frame.canId == 42 && !received) + { + received = true; + reader->Stop(); + } + }); + + ASSERT_TRUE(testHarness.Run(10s)); + EXPECT_TRUE(received) << "The writer must send on the network from its configuration"; +} + +} // namespace diff --git a/SilKit/IntegrationTests/ITest_DomainSockets.cpp b/SilKit/IntegrationTests/ITest_DomainSockets.cpp new file mode 100644 index 000000000..66947a8ed --- /dev/null +++ b/SilKit/IntegrationTests/ITest_DomainSockets.cpp @@ -0,0 +1,75 @@ +// SPDX-FileCopyrightText: 2026 Vector Informatik GmbH +// +// SPDX-License-Identifier: MIT + +// Participants on the same host connect via local domain sockets by default, and via TCP if domain sockets are +// disabled. + +#include + +#include "silkit/SilKit.hpp" +#include "silkit/vendor/CreateSilKitRegistry.hpp" + +#include "IntegrationTestUtils.hpp" + +#include "gmock/gmock.h" +#include "gtest/gtest.h" + +namespace { + +using IntegrationTestUtils::MakeUniqueLogName; +using IntegrationTestUtils::ScopedLogFiles; + +auto MakeConfig(const std::string& logName, const std::string& middleware) -> std::string +{ + return R"( +Logging: + FlushLevel: Trace + Sinks: + - Type: File + Level: Debug + LogName: )" + logName + "\n" + middleware; +} + +// Connects two participants to a registry and returns the log of the first one. +auto ConnectTwoParticipants(const std::string& middleware) -> std::string +{ + ScopedLogFiles logFiles{MakeUniqueLogName("ITest_DomainSockets")}; + + auto registry = SilKit::Vendor::Vector::CreateSilKitRegistry(SilKit::Config::ParticipantConfigurationFromString("")); + const auto registryUri = registry->StartListening("silkit://127.0.0.1:0"); + { + const auto config = SilKit::Config::ParticipantConfigurationFromString(MakeConfig(logFiles.Prefix(), middleware)); + auto first = SilKit::CreateParticipant(config, "First", registryUri); + // The second participant connects to the first one, which logs the incoming connection. + auto second = SilKit::CreateParticipant(config, "Second", registryUri); + } + return logFiles.ReadAll(); +} + +TEST(ITest_DomainSockets, participants_connect_via_domain_sockets_by_default) +{ + const auto log = ConnectTwoParticipants(""); + + EXPECT_THAT(log, testing::HasSubstr("Connected to registry at 'local://")) + << "The connection to a registry on the same host must use local domain sockets"; + EXPECT_THAT(log, testing::Not(testing::HasSubstr("Connected to registry at 'tcp://"))); + EXPECT_THAT(log, testing::HasSubstr("New connection from [local=local://")) + << "The connection between participants on the same host must use local domain sockets"; +} + +TEST(ITest_DomainSockets, participants_connect_via_tcp_if_domain_sockets_are_disabled) +{ + const auto log = ConnectTwoParticipants(R"( +Middleware: + EnableDomainSockets: false +)"); + + // The registry still offers its local:// acceptor, which shows up in the log, but must not be used. + EXPECT_THAT(log, testing::HasSubstr("Connected to registry at 'tcp://")); + EXPECT_THAT(log, testing::Not(testing::HasSubstr("Connected to registry at 'local://"))); + EXPECT_THAT(log, testing::HasSubstr("New connection from [local=tcp://")); + EXPECT_THAT(log, testing::Not(testing::HasSubstr("New connection from [local=local://"))); +} + +} // namespace diff --git a/SilKit/IntegrationTests/ITest_HealthCheck.cpp b/SilKit/IntegrationTests/ITest_HealthCheck.cpp new file mode 100644 index 000000000..945ed317a --- /dev/null +++ b/SilKit/IntegrationTests/ITest_HealthCheck.cpp @@ -0,0 +1,206 @@ +// SPDX-FileCopyrightText: 2026 Vector Informatik GmbH +// +// SPDX-License-Identifier: MIT + +// Health monitoring: a participant whose simulation step exceeds the configured SoftResponseTimeout logs a warning, +// one that exceeds the HardResponseTimeout goes to the Error state, and the disconnect of a participant is observed +// by the others. + +#include +#include +#include +#include +#include + +#include "silkit/SilKit.hpp" +#include "silkit/services/orchestration/all.hpp" +#include "silkit/vendor/CreateSilKitRegistry.hpp" + +#include "IntegrationTestUtils.hpp" + +#include "gmock/gmock.h" +#include "gtest/gtest.h" + +namespace { + +using namespace std::chrono_literals; +using namespace SilKit::Services::Orchestration; +using IntegrationTestUtils::MakeUniqueLogName; +using IntegrationTestUtils::ScopedLogFiles; + +class ITest_HealthCheck : public testing::Test +{ +protected: + void SetUp() override + { + _registry = SilKit::Vendor::Vector::CreateSilKitRegistry(SilKit::Config::ParticipantConfigurationFromString("")); + _registryUri = _registry->StartListening("silkit://127.0.0.1:0"); + } + + // A single synchronized participant in autonomous mode does not need a system controller. + // The first simulation step blocks for stepDuration, all following steps return immediately. + struct SlowParticipant + { + SlowParticipant(const std::string& config, const std::string& registryUri, std::chrono::milliseconds stepDuration) + { + participant = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(config), + "SlowParticipant", registryUri); + lifecycleService = participant->CreateLifecycleService({OperationMode::Autonomous}); + auto* timeSyncService = lifecycleService->CreateTimeSyncService(); + + timeSyncService->SetSimulationStepHandler( + [this, stepDuration](std::chrono::nanoseconds now, std::chrono::nanoseconds) { + if (!firstStepDone) + { + std::this_thread::sleep_for(stepDuration); + firstStepDone = true; + } + if (now >= 10ms && !stopRequested.exchange(true)) + { + stepsAfterSlowStepPromise.set_value(); + } + }, 1ms); + } + + std::unique_ptr participant; + ILifecycleService* lifecycleService{nullptr}; + bool firstStepDone{false}; + std::atomic stopRequested{false}; + std::promise stepsAfterSlowStepPromise; + }; + + std::unique_ptr _registry; + std::string _registryUri; +}; + +TEST_F(ITest_HealthCheck, soft_response_timeout_logs_warning_and_simulation_continues) +{ + ScopedLogFiles logFiles{MakeUniqueLogName("ITest_HealthCheck_Soft")}; + const auto config = R"( +HealthCheck: + SoftResponseTimeout: 50 +Logging: + FlushLevel: Trace + Sinks: + - Type: File + Level: Warn + LogName: )" + logFiles.Prefix() + "\n"; + + { + SlowParticipant slow{config, _registryUri, 300ms}; + auto finalState = slow.lifecycleService->StartLifecycle(); + + auto continued = slow.stepsAfterSlowStepPromise.get_future(); + ASSERT_EQ(continued.wait_for(10s), std::future_status::ready) + << "The simulation must continue after a soft response timeout"; + EXPECT_EQ(slow.lifecycleService->State(), ParticipantState::Running); + + slow.lifecycleService->Stop("test done"); + ASSERT_EQ(finalState.wait_for(10s), std::future_status::ready); + EXPECT_EQ(finalState.get(), ParticipantState::Shutdown); + } + + EXPECT_THAT(logFiles.ReadAll(), testing::HasSubstr("SimStep did not finish within soft time limit")); +} + +TEST_F(ITest_HealthCheck, no_warning_if_step_finishes_within_soft_response_timeout) +{ + ScopedLogFiles logFiles{MakeUniqueLogName("ITest_HealthCheck_InTime")}; + const auto config = R"( +HealthCheck: + SoftResponseTimeout: 2000 + HardResponseTimeout: 4000 +Logging: + FlushLevel: Trace + Sinks: + - Type: File + Level: Warn + LogName: )" + logFiles.Prefix() + "\n"; + + { + SlowParticipant slow{config, _registryUri, 20ms}; + auto finalState = slow.lifecycleService->StartLifecycle(); + + auto continued = slow.stepsAfterSlowStepPromise.get_future(); + ASSERT_EQ(continued.wait_for(10s), std::future_status::ready); + + slow.lifecycleService->Stop("test done"); + ASSERT_EQ(finalState.wait_for(10s), std::future_status::ready); + EXPECT_EQ(finalState.get(), ParticipantState::Shutdown); + } + + const auto log = logFiles.ReadAll(); + EXPECT_THAT(log, testing::Not(testing::HasSubstr("soft time limit"))); + EXPECT_THAT(log, testing::Not(testing::HasSubstr("hard time limit"))); +} + +TEST_F(ITest_HealthCheck, hard_response_timeout_puts_participant_into_error_state) +{ + const auto config = R"( +HealthCheck: + SoftResponseTimeout: 20 + HardResponseTimeout: 50 +)"; + + SlowParticipant slow{config, _registryUri, 300ms}; + + std::promise errorPromise; + std::atomic errorSeen{false}; + auto* systemMonitor = slow.participant->CreateSystemMonitor(); + systemMonitor->AddParticipantStatusHandler([&](const ParticipantStatus& status) { + if (status.participantName == "SlowParticipant" && status.state == ParticipantState::Error + && !errorSeen.exchange(true)) + { + errorPromise.set_value(status.enterReason); + } + }); + + auto finalState = slow.lifecycleService->StartLifecycle(); + + auto error = errorPromise.get_future(); + ASSERT_EQ(error.wait_for(10s), std::future_status::ready) + << "A simulation step exceeding the hard response timeout must put the participant into the Error state"; + EXPECT_THAT(error.get(), testing::HasSubstr("SimStep did not finish within hard time limit")); + + // Stopping from the Error state shuts the participant down. + slow.lifecycleService->Stop("test done"); + ASSERT_EQ(finalState.wait_for(10s), std::future_status::ready); + EXPECT_EQ(finalState.get(), ParticipantState::Shutdown); +} + +TEST_F(ITest_HealthCheck, disconnect_is_observed_by_other_participants) +{ + auto observer = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(""), "Observer", + _registryUri); + auto* systemMonitor = observer->CreateSystemMonitor(); + + std::promise connectedPromise; + std::promise disconnectedPromise; + systemMonitor->SetParticipantConnectedHandler([&](const ParticipantConnectionInformation& info) { + if (info.participantName == "Leaver") + { + connectedPromise.set_value(); + } + }); + systemMonitor->SetParticipantDisconnectedHandler([&](const ParticipantConnectionInformation& info) { + if (info.participantName == "Leaver") + { + disconnectedPromise.set_value(); + } + }); + + auto leaver = SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(""), "Leaver", + _registryUri); + + ASSERT_EQ(connectedPromise.get_future().wait_for(10s), std::future_status::ready); + EXPECT_TRUE(systemMonitor->IsParticipantConnected("Leaver")); + + // Destroying the participant closes its connections without any lifecycle transitions. + leaver.reset(); + + ASSERT_EQ(disconnectedPromise.get_future().wait_for(10s), std::future_status::ready) + << "The observer must be notified when another participant disconnects"; + EXPECT_FALSE(systemMonitor->IsParticipantConnected("Leaver")); +} + +} // namespace diff --git a/SilKit/IntegrationTests/ITest_Lin.cpp b/SilKit/IntegrationTests/ITest_Lin.cpp index 19cab9aa5..a0a2ba6ca 100644 --- a/SilKit/IntegrationTests/ITest_Lin.cpp +++ b/SilKit/IntegrationTests/ITest_Lin.cpp @@ -524,4 +524,160 @@ TEST_F(ITest_Lin, sync_lin_simulation) EXPECT_EQ(masterRecvFrames[LinFrameStatus::LIN_RX_OK][0].data, (std::array{3, 4, 3, 4, 3, 4, 3, 4})); } + +// LIN master and slave go through several go-to-sleep / wakeup cycles and exchange frames after every wakeup, so a +// slave that does not return from sleep is detected. sync_lin_simulation only covers a single cycle. + +constexpr LinId dataFrameId = 16; +constexpr size_t numberOfCycles = 3; + +auto MakeDataFrame(uint8_t cycle) -> LinFrame +{ + LinFrame frame; + frame.id = dataFrameId; + frame.checksumModel = LinChecksumModel::Classic; + frame.dataLength = 8; + frame.data = {cycle, cycle, cycle, cycle, cycle, cycle, cycle, cycle}; + return frame; +} + +TEST_F(ITest_Lin, repeated_sleep_and_wakeup_cycles) +{ + SilKit::Tests::SimTestHarnessArgs args; + args.syncParticipantNames = {"LinMaster", "LinSlave"}; + SilKit::Tests::SimTestHarness testHarness{args}; + + // --- Master: send a data frame, then the go-to-sleep command, wait for the wakeup of the slave, repeat. + enum class MasterPhase + { + SendData, + WaitForDataSent, + SendGoToSleep, + WaitForWakeup, + Done + }; + + auto* master = testHarness.GetParticipant("LinMaster"); + auto* masterController = master->Participant()->CreateLinController("LIN1", "LIN_1"); + MasterPhase masterPhase = MasterPhase::SendData; + size_t masterWakeups = 0; + size_t masterDataFramesSent = 0; + + master->GetOrCreateLifecycleService()->SetCommunicationReadyHandler([masterController] { + LinControllerConfig config; + config.controllerMode = LinControllerMode::Master; + config.baudRate = 20'000; + masterController->Init(config); + }); + masterController->AddFrameStatusHandler([&](ILinController*, const LinFrameStatusEvent& event) { + if (event.frame.id == dataFrameId && event.status == LinFrameStatus::LIN_TX_OK + && masterPhase == MasterPhase::WaitForDataSent) + { + masterDataFramesSent++; + masterPhase = MasterPhase::SendGoToSleep; + } + }); + masterController->AddWakeupHandler([&](ILinController* controller, const LinWakeupEvent&) { + if (masterPhase != MasterPhase::WaitForWakeup) + { + return; + } + controller->WakeupInternal(); + masterWakeups++; + masterPhase = masterWakeups < numberOfCycles ? MasterPhase::SendData : MasterPhase::Done; + }); + master->GetOrCreateTimeSyncService()->SetSimulationStepHandler( + [&](std::chrono::nanoseconds now, std::chrono::nanoseconds) { + switch (masterPhase) + { + case MasterPhase::SendData: + ASSERT_EQ(masterController->Status(), LinControllerStatus::Operational); + masterPhase = MasterPhase::WaitForDataSent; + masterController->SendFrame(MakeDataFrame(static_cast(masterWakeups)), + LinFrameResponseType::MasterResponse); + break; + case MasterPhase::SendGoToSleep: + masterPhase = MasterPhase::WaitForWakeup; + masterController->GoToSleep(); + EXPECT_EQ(masterController->Status(), LinControllerStatus::Sleep); + break; + case MasterPhase::Done: + master->Stop(); + break; + default: + break; + } + if (now > 1s) + { + ADD_FAILURE() << "LIN sleep/wakeup cycles did not finish in time"; + master->Stop(); + } + }, 1ms); + + // --- Slave: receive the data frame, enter sleep on the go-to-sleep command and wake the bus 5ms later. + auto* slave = testHarness.GetParticipant("LinSlave"); + auto* slaveController = slave->Participant()->CreateLinController("LIN1", "LIN_1"); + std::vector slaveDataFrames; + size_t slaveDataFramesInSleep = 0; + size_t slaveSleeps = 0; + std::chrono::nanoseconds slaveNow{0}; + std::chrono::nanoseconds slaveWakeupTime = std::chrono::nanoseconds::max(); + + slave->GetOrCreateLifecycleService()->SetCommunicationReadyHandler([slaveController] { + LinControllerConfig config; + config.controllerMode = LinControllerMode::Slave; + config.baudRate = 20'000; + LinFrameResponse dataResponse; + dataResponse.frame = MakeDataFrame(0); + dataResponse.responseMode = LinFrameResponseMode::Rx; + LinFrameResponse goToSleepResponse; + goToSleepResponse.frame = GoToSleepFrame(); + goToSleepResponse.responseMode = LinFrameResponseMode::Rx; + config.frameResponses = {dataResponse, goToSleepResponse}; + slaveController->Init(config); + }); + slaveController->AddFrameStatusHandler([&](ILinController* controller, const LinFrameStatusEvent& event) { + if (event.frame.id != dataFrameId || event.status != LinFrameStatus::LIN_RX_OK) + { + return; + } + slaveDataFrames.push_back(event.frame); + if (controller->Status() == LinControllerStatus::Sleep) + { + slaveDataFramesInSleep++; + } + }); + slaveController->AddGoToSleepHandler([&](ILinController* controller, const LinGoToSleepEvent&) { + controller->GoToSleepInternal(); + slaveSleeps++; + slaveWakeupTime = slaveNow + 5ms; + }); + slave->GetOrCreateTimeSyncService()->SetSimulationStepHandler( + [&](std::chrono::nanoseconds now, std::chrono::nanoseconds) { + slaveNow = now; + if (now >= slaveWakeupTime) + { + slaveWakeupTime = std::chrono::nanoseconds::max(); + EXPECT_EQ(slaveController->Status(), LinControllerStatus::Sleep); + slaveController->Wakeup(); + EXPECT_EQ(slaveController->Status(), LinControllerStatus::Operational) + << "The slave must be operational again after sending the wakeup pulse"; + } + }, 1ms); + + ASSERT_TRUE(testHarness.Run(10s)); + + EXPECT_EQ(masterDataFramesSent, numberOfCycles); + EXPECT_EQ(masterWakeups, numberOfCycles); + EXPECT_EQ(slaveSleeps, numberOfCycles); + EXPECT_EQ(slaveDataFramesInSleep, 0u); + ASSERT_EQ(slaveDataFrames.size(), numberOfCycles) << "The slave must receive a data frame after every wakeup"; + for (size_t cycle = 0; cycle < numberOfCycles; ++cycle) + { + EXPECT_EQ(slaveDataFrames[cycle].data[0], cycle); + } + EXPECT_EQ(masterController->Status(), LinControllerStatus::Operational); + EXPECT_EQ(slaveController->Status(), LinControllerStatus::Operational); +} + } //end namespace diff --git a/SilKit/IntegrationTests/ITest_Logging.cpp b/SilKit/IntegrationTests/ITest_Logging.cpp index b3f9cd909..386792c27 100644 --- a/SilKit/IntegrationTests/ITest_Logging.cpp +++ b/SilKit/IntegrationTests/ITest_Logging.cpp @@ -2,6 +2,7 @@ // // SPDX-License-Identifier: MIT +#include #include #include #include @@ -10,10 +11,14 @@ #include #include "silkit/SilKit.hpp" +#include "silkit/services/all.hpp" #include "silkit/services/flexray/string_utils.hpp" #include "silkit/services/logging/ILogger.hpp" #include "silkit/vendor/CreateSilKitRegistry.hpp" +#include "IntegrationTestUtils.hpp" +#include "SimTestHarness.hpp" + #include "gmock/gmock.h" #include "gtest/gtest.h" @@ -25,6 +30,9 @@ namespace fs = std::filesystem; using namespace std::chrono_literals; using namespace SilKit::Services::Logging; +using IntegrationTestUtils::FindLogFiles; +using IntegrationTestUtils::LogFilePrefix; + const std::string participantName{"LoggingParticipant"}; const std::string simpleLogName{"ITest_Logging_Simple"}; const std::string jsonLogName{"ITest_Logging_Json"}; @@ -77,28 +85,11 @@ class ITest_Logging : public testing::Test RemoveLogFiles(); } - // The sinks append a participant name and a timestamp to the configured log name, so the files can only - // be identified by their prefix. - static auto FindLogFiles(const std::string& logName) -> std::vector - { - const auto prefix = logName + "_"; - - std::vector logFiles; - for (const auto& entry : fs::directory_iterator{fs::current_path()}) - { - if (entry.is_regular_file() && entry.path().filename().string().compare(0, prefix.size(), prefix) == 0) - { - logFiles.push_back(entry.path()); - } - } - return logFiles; - } - static void RemoveLogFiles() { for (const auto& logName : {simpleLogName, jsonLogName}) { - for (const auto& logFile : FindLogFiles(logName)) + for (const auto& logFile : FindLogFiles(LogFilePrefix(logName))) { std::error_code ec; fs::remove(logFile, ec); @@ -108,7 +99,7 @@ class ITest_Logging : public testing::Test static auto ReadLogFile(const std::string& logName) -> std::string { - const auto logFiles = FindLogFiles(logName); + const auto logFiles = FindLogFiles(LogFilePrefix(logName)); EXPECT_EQ(logFiles.size(), 1u) << "Expected exactly one log file for '" << logName << "'"; if (logFiles.size() != 1u) { @@ -124,7 +115,7 @@ class ITest_Logging : public testing::Test } }; -TEST_F(ITest_Logging, log_message_with_braces_is_not_parsed_as_format_string) +TEST_F(ITest_Logging, log_message_with_braces_is_not_parsed_as_format_striLogFilePrefixng) { const auto bracedMessage = MakeBracedMessage(); ASSERT_THAT(bracedMessage, testing::HasSubstr("{pattern=Wus, channel=A @ 12.796ms}")); @@ -158,4 +149,249 @@ TEST_F(ITest_Logging, log_message_with_braces_is_not_parsed_as_format_string) EXPECT_THAT(jsonLog, testing::HasSubstr(unbalancedMessage)); } +// Creates a participant with the given configuration, logs one message per level and destroys the participant again, +// which flushes and closes its file sinks. +void LogOneMessagePerLevel(const std::string& config, const std::string& name) +{ + auto registry = SilKit::Vendor::Vector::CreateSilKitRegistry(SilKit::Config::ParticipantConfigurationFromString("")); + const auto registryUri = registry->StartListening("silkit://127.0.0.1:0"); + + auto participant = + SilKit::CreateParticipant(SilKit::Config::ParticipantConfigurationFromString(config), name, registryUri); + auto* logger = participant->GetLogger(); + logger->Trace("message-at-level-trace"); + logger->Debug("message-at-level-debug"); + logger->Info("message-at-level-info"); + logger->Warn("message-at-level-warn"); + logger->Error("message-at-level-error"); + logger->Critical("message-at-level-critical"); +} + +// Each sink only receives messages at or above its level. +TEST_F(ITest_Logging, sink_level_filters_messages_below_the_configured_level) +{ + IntegrationTestUtils::ScopedLogFiles warnLog{IntegrationTestUtils::MakeUniqueLogName("ITest_LogLevel_Warn")}; + IntegrationTestUtils::ScopedLogFiles traceLog{ + IntegrationTestUtils::MakeUniqueLogName("ITest_LogLevel_Trace")}; + + LogOneMessagePerLevel(R"( +Logging: + FlushLevel: Trace + Sinks: + - Type: File + Level: Warn + LogName: )" + warnLog.Prefix() + R"( + - Type: File + Level: Trace + LogName: )" + traceLog.Prefix() + "\n", + participantName); + + const auto warn = warnLog.ReadAll(); + EXPECT_THAT(warn, testing::Not(testing::HasSubstr("message-at-level-trace"))); + EXPECT_THAT(warn, testing::Not(testing::HasSubstr("message-at-level-debug"))); + EXPECT_THAT(warn, testing::Not(testing::HasSubstr("message-at-level-info"))); + EXPECT_THAT(warn, testing::HasSubstr("message-at-level-warn")); + EXPECT_THAT(warn, testing::HasSubstr("message-at-level-error")); + EXPECT_THAT(warn, testing::HasSubstr("message-at-level-critical")); + + // The second sink of the same participant is not affected by the level of the first one. + const auto trace = traceLog.ReadAll(); + for (const auto* level : {"trace", "debug", "info", "warn", "error", "critical"}) + { + EXPECT_THAT(trace, testing::HasSubstr(std::string{"message-at-level-"} + level)); + } +} + +TEST_F(ITest_Logging, sink_level_off_writes_nothing) +{ + IntegrationTestUtils::ScopedLogFiles offLog{IntegrationTestUtils::MakeUniqueLogName("ITest_LogLevel_Off")}; + + LogOneMessagePerLevel(R"( +Logging: + Sinks: + - Type: File + Level: Off + LogName: )" + offLog.Prefix() + "\n", + participantName); + + EXPECT_THAT(offLog.ReadAll(), testing::Not(testing::HasSubstr("message-at-level-"))); +} + +// Additional file sink: the file is named +// "__.jsonl" (File sinks default to the Json format) and each participant writes +// its own file. +TEST_F(ITest_Logging, file_sink_writes_one_file_per_participant_named_after_log_name_and_participant) +{ + IntegrationTestUtils::ScopedLogFiles fileLog{IntegrationTestUtils::MakeUniqueLogName("ITest_FileSink")}; + const auto config = R"( +Logging: + Sinks: + - Type: Stdout + Level: Info + - Type: File + Level: Info + LogName: )" + fileLog.Prefix() + "\n"; + + LogOneMessagePerLevel(config, "FileSinkParticipantA"); + LogOneMessagePerLevel(config, "FileSinkParticipantB"); + + const auto logFiles = IntegrationTestUtils::FindLogFiles(fileLog.Prefix()); + ASSERT_EQ(logFiles.size(), 2u); + for (const auto& name : {"FileSinkParticipantA", "FileSinkParticipantB"}) + { + const auto expectedPrefix = fileLog.Prefix() + "_" + name + "_"; + const auto logFile = std::find_if(logFiles.begin(), logFiles.end(), [&expectedPrefix](const fs::path& path) { + return path.filename().string().rfind(expectedPrefix, 0) == 0; + }); + ASSERT_NE(logFile, logFiles.end()) << "No log file starting with " << expectedPrefix; + EXPECT_EQ(logFile->extension().string(), ".jsonl"); + EXPECT_THAT(IntegrationTestUtils::ReadTextFile(*logFile), testing::HasSubstr("message-at-level-info")); + } +} + + +// --------------------------------------------------------------------------------------------------------------------- +// Remote logging +// --------------------------------------------------------------------------------------------------------------------- + +const std::string sender1InfoMessage = "remote-log-from-sender-1"; +const std::string sender2InfoMessage = "remote-log-from-sender-2"; +const std::string sender1WarnMessage = "remote-warning-from-sender-1"; +const std::string receiverOwnMessage = "local-log-from-receiver"; + +// Runs Sender1, Sender2 and Receiver for a few simulation steps. In their first step, the senders log an info message +// and Sender1 additionally a warning; the receiver logs a message of its own. Returns the receiver's file sink contents. +auto RunRemoteLoggingSimulation(const std::string& senderConfig, const std::string& receiverLoggingSection) + -> std::string +{ + const auto receiverLogName = IntegrationTestUtils::MakeUniqueLogName("itest_remote_logging"); + const auto filePrefix = LogFilePrefix(receiverLogName, "Receiver"); + IntegrationTestUtils::ScopedLogFiles cleanup{filePrefix}; + + const auto receiverConfig = R"( +Logging: +)" + receiverLoggingSection + R"( + FlushLevel: Trace + Sinks: + - Type: File + Level: Trace + LogName: )" + receiverLogName + "\n"; + + SilKit::Tests::SimTestHarnessArgs testHarnessArgs; + testHarnessArgs.syncParticipantNames = {"Sender1", "Sender2", "Receiver"}; + testHarnessArgs.deferParticipantCreation = true; + + SilKit::Tests::SimTestHarness testHarness{testHarnessArgs}; + + auto* sender1 = testHarness.GetParticipant("Sender1", senderConfig); + auto* sender2 = testHarness.GetParticipant("Sender2", senderConfig); + auto* receiver = testHarness.GetParticipant("Receiver", receiverConfig); + + auto* sender1Lifecycle = sender1->GetOrCreateLifecycleService(); + auto* sender1TimeSync = sender1->GetOrCreateTimeSyncService(); + auto* sender2TimeSync = sender2->GetOrCreateTimeSyncService(); + auto* receiverTimeSync = receiver->GetOrCreateTimeSyncService(); + + auto* sender1Logger = sender1->GetLogger(); + auto* sender2Logger = sender2->GetLogger(); + auto* receiverLogger = receiver->GetLogger(); + + bool sender1Logged{false}; + bool sender2Logged{false}; + bool receiverLogged{false}; + + sender1TimeSync->SetSimulationStepHandler([&](std::chrono::nanoseconds now, std::chrono::nanoseconds) { + if (!sender1Logged) + { + sender1Logged = true; + sender1Logger->Info(sender1InfoMessage); + sender1Logger->Warn(sender1WarnMessage); + } + + if (now >= 5ms) + { + sender1Lifecycle->Stop("remote logging test done"); + } + }, + 1ms); + + sender2TimeSync->SetSimulationStepHandler([&](std::chrono::nanoseconds /*now*/, std::chrono::nanoseconds) { + if (!sender2Logged) + { + sender2Logged = true; + sender2Logger->Info(sender2InfoMessage); + } + }, + 1ms); + + receiverTimeSync->SetSimulationStepHandler([&](std::chrono::nanoseconds /*now*/, std::chrono::nanoseconds) { + if (!receiverLogged) + { + receiverLogged = true; + receiverLogger->Info(receiverOwnMessage); + } + }, + 1ms); + + EXPECT_TRUE(testHarness.Run(5s)); + testHarness.ResetParticipants(); + + const auto logFiles = IntegrationTestUtils::FindLogFiles(filePrefix); + EXPECT_EQ(logFiles.size(), 1u) << "Expected exactly one receiver log file with prefix " << filePrefix; + return logFiles.empty() ? std::string{} : IntegrationTestUtils::ReadTextFile(logFiles.front()); +} + +const std::string remoteTraceSenderConfig = R"( +Logging: + Sinks: + - Type: Remote + Level: Trace +)"; + +TEST_F(ITest_Logging, remote_logging_two_senders_one_receiver) +{ + const auto logContent = RunRemoteLoggingSimulation(remoteTraceSenderConfig, " LogFromRemotes: true"); + + EXPECT_THAT(logContent, testing::HasSubstr(sender1InfoMessage)); + EXPECT_THAT(logContent, testing::HasSubstr(sender1WarnMessage)); + EXPECT_THAT(logContent, testing::HasSubstr(sender2InfoMessage)); + EXPECT_THAT(logContent, testing::HasSubstr(receiverOwnMessage)); +} + +// A participant that does not set LogFromRemotes must not receive the log messages of other participants. +TEST_F(ITest_Logging, log_from_remotes_false_ignores_remote_messages) +{ + const auto logContent = RunRemoteLoggingSimulation(remoteTraceSenderConfig, " LogFromRemotes: false"); + + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender1InfoMessage))); + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender1WarnMessage))); + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender2InfoMessage))); + EXPECT_THAT(logContent, testing::HasSubstr(receiverOwnMessage)); +} + +TEST_F(ITest_Logging, log_from_remotes_defaults_to_false) +{ + const auto logContent = RunRemoteLoggingSimulation(remoteTraceSenderConfig, ""); + + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender1InfoMessage))); + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender2InfoMessage))); + EXPECT_THAT(logContent, testing::HasSubstr(receiverOwnMessage)); +} + +// The level of the sender's Remote sink decides which messages are sent at all. +TEST_F(ITest_Logging, remote_sink_level_filters_on_the_sender_side) +{ + const auto senderConfig = R"( +Logging: + Sinks: + - Type: Remote + Level: Warn +)"; + const auto logContent = RunRemoteLoggingSimulation(senderConfig, " LogFromRemotes: true"); + + EXPECT_THAT(logContent, testing::HasSubstr(sender1WarnMessage)); + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender1InfoMessage))); + EXPECT_THAT(logContent, testing::Not(testing::HasSubstr(sender2InfoMessage))); +} + } // namespace diff --git a/SilKit/IntegrationTests/ITest_PcapTracing.cpp b/SilKit/IntegrationTests/ITest_PcapTracing.cpp new file mode 100644 index 000000000..d72392393 --- /dev/null +++ b/SilKit/IntegrationTests/ITest_PcapTracing.cpp @@ -0,0 +1,327 @@ +// SPDX-FileCopyrightText: 2026 Vector Informatik GmbH +// +// SPDX-License-Identifier: MIT + +// PCAP tracing to a file and to a pipe: Ethernet frames of a controller with a PCAP trace sink end up in a valid PCAP +// stream. The stream is parsed here without SIL Kit internals, the same way an external tool like Wireshark reads it. + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "silkit/services/all.hpp" + +#include "SimTestHarness.hpp" +#include "EthernetHelpers.hpp" + +#include "gmock/gmock.h" +#include "gtest/gtest.h" + +#if defined(_WIN32) +#ifndef WIN32_LEAN_AND_MEAN +#define WIN32_LEAN_AND_MEAN +#endif +#ifndef NOMINMAX +#define NOMINMAX // MinGW's libstdc++ already defines it +#endif +#include +#else +#include +#include +#endif + +namespace { + +using namespace std::chrono_literals; +using namespace SilKit::Services::Ethernet; +using SilKit::IntegrationTests::CreateEthernetFrameFromString; +using SilKit::IntegrationTests::EthernetEtherType; +using SilKit::IntegrationTests::EthernetFrameHeaderSize; +using SilKit::IntegrationTests::EthernetMac; + +constexpr uint32_t pcapMagicMicroseconds = 0xa1b2c3d4; +constexpr uint32_t pcapMagicNanoseconds = 0xa1b23c4d; +constexpr uint32_t linkTypeEthernet = 1; +constexpr size_t numberOfFrames = 5; + +struct PcapPacket +{ + uint32_t tsSec; + uint32_t tsFraction; + std::vector data; +}; + +struct PcapStream +{ + uint32_t magic{0}; + uint16_t versionMajor{0}; + uint16_t versionMinor{0}; + uint32_t linkType{0}; + std::vector packets; +}; + +// Parses a little-endian PCAP stream (https://www.ietf.org/archive/id/draft-ietf-opsawg-pcap-04.html). +auto ParsePcap(const std::vector& bytes) -> PcapStream +{ + PcapStream result; + size_t offset = 0; + auto read32 = [&bytes, &offset]() { + uint32_t value; + std::memcpy(&value, bytes.data() + offset, sizeof(value)); + offset += sizeof(value); + return value; + }; + auto read16 = [&bytes, &offset]() { + uint16_t value; + std::memcpy(&value, bytes.data() + offset, sizeof(value)); + offset += sizeof(value); + return value; + }; + + if (bytes.size() < 24) + { + ADD_FAILURE() << "PCAP stream is shorter than its global header: " << bytes.size() << " bytes"; + return result; + } + result.magic = read32(); + result.versionMajor = read16(); + result.versionMinor = read16(); + offset += 4 + 4 + 4; // thiszone, sigfigs, snaplen + result.linkType = read32(); + + while (offset + 16 <= bytes.size()) + { + PcapPacket packet; + packet.tsSec = read32(); + packet.tsFraction = read32(); + const auto includedLength = read32(); + offset += 4; // original length + if (offset + includedLength > bytes.size()) + { + ADD_FAILURE() << "Truncated PCAP packet record"; + break; + } + packet.data.assign(bytes.begin() + offset, bytes.begin() + offset + includedLength); + offset += includedLength; + result.packets.push_back(std::move(packet)); + } + EXPECT_EQ(offset, bytes.size()) << "Trailing bytes after the last PCAP packet record"; + return result; +} + +auto ReadBinaryFile(const std::filesystem::path& path) -> std::vector +{ + std::ifstream stream{path, std::ios::binary}; + return std::vector{std::istreambuf_iterator{stream}, std::istreambuf_iterator{}}; +} + +auto MessageForFrame(size_t index) -> std::string +{ + // Pad to the minimum Ethernet frame length of 60 bytes. + std::string message = "PCAP test frame " + std::to_string(index); + message.resize(60 - EthernetFrameHeaderSize, ' '); + return message; +} + +auto MakeWriterConfig(const std::string& sinkType, const std::string& outputPath) -> std::string +{ + return R"( +EthernetControllers: +- Name: ETH1 + Network: LINK1 + UseTraceSinks: + - PcapSink +Tracing: + TraceSinks: + - Name: PcapSink + Type: )" + sinkType + R"( + OutputPath: )" + outputPath + "\n"; +} + +// EthWriter sends one frame per millisecond, EthReader stops the simulation after receiving all of them. +void RunEthernetSimulation(const std::string& writerConfig) +{ + SilKit::Tests::SimTestHarnessArgs args; + args.syncParticipantNames = {"EthWriter", "EthReader"}; + args.deferParticipantCreation = true; + SilKit::Tests::SimTestHarness testHarness{args}; + + auto* writer = testHarness.GetParticipant("EthWriter", writerConfig); + auto* writerController = writer->Participant()->CreateEthernetController("ETH1", "LINK1"); + writer->GetOrCreateLifecycleService()->SetCommunicationReadyHandler( + [writerController] { writerController->Activate(); }); + + size_t numSent = 0; + writer->GetOrCreateTimeSyncService()->SetSimulationStepHandler( + [writerController, &numSent](std::chrono::nanoseconds, std::chrono::nanoseconds) { + if (numSent < numberOfFrames) + { + const EthernetMac destination{0x12, 0x23, 0x45, 0x67, 0x89, 0x9a}; + const EthernetMac source{0x9a, 0x89, 0x67, 0x45, 0x23, 0x12}; + const EthernetEtherType etherType{0x0800}; + writerController->SendFrame( + EthernetFrame{CreateEthernetFrameFromString(destination, source, etherType, MessageForFrame(numSent))}); + numSent++; + } + }, 1ms); + + auto* reader = testHarness.GetParticipant("EthReader", ""); + auto* readerController = reader->Participant()->CreateEthernetController("ETH1", "LINK1"); + reader->GetOrCreateLifecycleService()->SetCommunicationReadyHandler( + [readerController] { readerController->Activate(); }); + reader->GetOrCreateTimeSyncService()->SetSimulationStepHandler([](auto, auto) {}, 1ms); + + size_t numReceived = 0; + readerController->AddFrameHandler([reader, &numReceived](IEthernetController*, const EthernetFrameEvent&) { + if (++numReceived == numberOfFrames) + { + reader->Stop(); + } + }); + + ASSERT_TRUE(testHarness.Run(10s)); + EXPECT_EQ(numReceived, numberOfFrames); + // Destroying the participants closes the trace sinks. + testHarness.ResetParticipants(); +} + +void ExpectFramesInPcap(const PcapStream& pcap) +{ + EXPECT_THAT(pcap.magic, testing::AnyOf(pcapMagicMicroseconds, pcapMagicNanoseconds)); + EXPECT_EQ(pcap.versionMajor, 2u); + EXPECT_EQ(pcap.versionMinor, 4u); + EXPECT_EQ(pcap.linkType, linkTypeEthernet); + + ASSERT_EQ(pcap.packets.size(), numberOfFrames) << "Each sent frame must be traced exactly once"; + for (size_t i = 0; i < pcap.packets.size(); ++i) + { + const auto& data = pcap.packets[i].data; + ASSERT_GE(data.size(), EthernetFrameHeaderSize); + const std::string payload(data.begin() + EthernetFrameHeaderSize, data.end()); + EXPECT_EQ(payload, MessageForFrame(i)); + if (i > 0) + { + const auto& previous = pcap.packets[i - 1]; + EXPECT_TRUE(std::tie(previous.tsSec, previous.tsFraction) + < std::tie(pcap.packets[i].tsSec, pcap.packets[i].tsFraction)) + << "Frames are sent at increasing simulation times"; + } + } +} + +TEST(ITest_PcapTracing, pcap_file_sink_contains_all_sent_frames) +{ + const auto path = std::filesystem::current_path() + / ("ITest_PcapTracing_" + std::to_string(std::chrono::steady_clock::now().time_since_epoch().count()) + + ".pcap"); + + RunEthernetSimulation(MakeWriterConfig("PcapFile", path.generic_string())); + + ASSERT_TRUE(std::filesystem::exists(path)) << "The PCAP file was not created"; + ExpectFramesInPcap(ParsePcap(ReadBinaryFile(path))); + + std::error_code ec; + std::filesystem::remove(path, ec); +} + +// Reads the whole PCAP stream from the named pipe the sink creates. The sink writes the first bytes when the first +// frame is traced and blocks until a reader is connected. +class PipeReader +{ +public: + explicit PipeReader(std::string pipeName) + : _thread{[this, pipeName] { Read(pipeName); }} + { + } + + ~PipeReader() + { + _abort = true; + if (_thread.joinable()) + { + _thread.join(); + } + } + + auto Join() -> std::vector + { + _thread.join(); + return _bytes; + } + +private: + void Read(const std::string& pipeName) + { + const auto deadline = std::chrono::steady_clock::now() + 10s; +#if defined(_WIN32) + const auto path = "\\\\.\\pipe\\" + pipeName; + HANDLE handle = INVALID_HANDLE_VALUE; + while (handle == INVALID_HANDLE_VALUE && !_abort && std::chrono::steady_clock::now() < deadline) + { + handle = CreateFileA(path.c_str(), GENERIC_READ, 0, nullptr, OPEN_EXISTING, 0, nullptr); + if (handle == INVALID_HANDLE_VALUE) + { + std::this_thread::sleep_for(10ms); + } + } + if (handle == INVALID_HANDLE_VALUE) + { + return; + } + // Reading ends with ERROR_BROKEN_PIPE when the sink closes the pipe. + char buffer[65536]; + DWORD numRead = 0; + while (ReadFile(handle, buffer, sizeof(buffer), &numRead, nullptr) || GetLastError() == ERROR_MORE_DATA) + { + _bytes.insert(_bytes.end(), buffer, buffer + numRead); + numRead = 0; + } + CloseHandle(handle); +#else + while (!std::filesystem::exists(pipeName) && !_abort && std::chrono::steady_clock::now() < deadline) + { + std::this_thread::sleep_for(10ms); + } + const int fd = ::open(pipeName.c_str(), O_RDONLY); + if (fd < 0) + { + return; + } + char buffer[65536]; + ssize_t numRead = 0; + while ((numRead = ::read(fd, buffer, sizeof(buffer))) > 0) + { + _bytes.insert(_bytes.end(), buffer, buffer + numRead); + } + ::close(fd); +#endif + } + + std::atomic _abort{false}; + std::vector _bytes; + std::thread _thread; +}; + +TEST(ITest_PcapTracing, pcap_pipe_sink_streams_all_sent_frames) +{ + const auto uniqueName = "ITest_PcapPipe_" + std::to_string(std::chrono::steady_clock::now().time_since_epoch().count()); +#if defined(_WIN32) + const auto pipeName = uniqueName; +#else + const auto pipeName = (std::filesystem::temp_directory_path() / uniqueName).string(); +#endif + + PipeReader pipeReader{pipeName}; + RunEthernetSimulation(MakeWriterConfig("PcapPipe", pipeName)); + + ExpectFramesInPcap(ParsePcap(pipeReader.Join())); +} + +} // namespace diff --git a/SilKit/IntegrationTests/ITest_RemoteLogging.cpp b/SilKit/IntegrationTests/ITest_RemoteLogging.cpp deleted file mode 100644 index bfbc3a297..000000000 --- a/SilKit/IntegrationTests/ITest_RemoteLogging.cpp +++ /dev/null @@ -1,162 +0,0 @@ -// SPDX-FileCopyrightText: 2026 Vector Informatik GmbH -// -// SPDX-License-Identifier: MIT - -#include -#include -#include -#include -#include -#include -#include - -#include "silkit/services/all.hpp" - -#include "SimTestHarness.hpp" - -#include "gtest/gtest.h" -#include "gmock/gmock.h" - -namespace { - -using namespace std::chrono_literals; -using namespace SilKit::Tests; - -auto ReadTextFile(const std::filesystem::path& filePath) -> std::string -{ - std::ifstream in{filePath}; - return std::string{std::istreambuf_iterator{in}, std::istreambuf_iterator{}}; -} - -auto FindLogFiles(const std::string& logNamePrefix) -> std::vector -{ - std::vector candidates; - - for (const auto& entry : std::filesystem::directory_iterator{std::filesystem::current_path()}) - { - if (!entry.is_regular_file()) - { - continue; - } - - const auto filename = entry.path().filename().string(); - if (filename.rfind(logNamePrefix, 0) == 0 && entry.path().extension() == ".jsonl") - { - candidates.emplace_back(entry.path()); - } - } - - return candidates; -} - -struct ScopedLogFileCleanup -{ - explicit ScopedLogFileCleanup(std::string prefix) - : _prefix{std::move(prefix)} - { - } - - ~ScopedLogFileCleanup() - { - for (const auto& entry : std::filesystem::directory_iterator{std::filesystem::current_path()}) - { - if (!entry.is_regular_file()) - { - continue; - } - - const auto filename = entry.path().filename().string(); - if (filename.rfind(_prefix, 0) == 0 && entry.path().extension() == ".jsonl") - { - std::error_code ec; - std::filesystem::remove(entry.path(), ec); - } - } - } - - std::string _prefix; -}; - -TEST(ITest_RemoteLogging, test_remote_logging_two_senders_one_receiver) -{ - const auto uniqueSuffix = std::to_string(std::chrono::steady_clock::now().time_since_epoch().count()); - const auto receiverLogName = "itest_remote_logging_" + uniqueSuffix; - const auto filePrefix = receiverLogName + "_Receiver_"; - ScopedLogFileCleanup cleanup{filePrefix}; - - const auto senderConfig = R"( -Logging: - Sinks: - - Type: Remote - Level: Trace -)"; - - const auto receiverConfig = R"( -Logging: - LogFromRemotes: true - FlushLevel: Trace - Sinks: - - Type: File - Level: Trace - LogName: )" + receiverLogName + "\n"; - - SimTestHarnessArgs testHarnessArgs; - testHarnessArgs.syncParticipantNames = {"Sender1", "Sender2", "Receiver"}; - testHarnessArgs.deferParticipantCreation = true; - - SimTestHarness testHarness{testHarnessArgs}; - - auto* sender1 = testHarness.GetParticipant("Sender1", senderConfig); - auto* sender2 = testHarness.GetParticipant("Sender2", senderConfig); - auto* receiver = testHarness.GetParticipant("Receiver", receiverConfig); - - auto* sender1Lifecycle = sender1->GetOrCreateLifecycleService(); - auto* sender1TimeSync = sender1->GetOrCreateTimeSyncService(); - auto* sender2TimeSync = sender2->GetOrCreateTimeSyncService(); - auto* receiverTimeSync = receiver->GetOrCreateTimeSyncService(); - - auto* sender1Logger = sender1->GetLogger(); - auto* sender2Logger = sender2->GetLogger(); - - const std::string sender1Message = "remote-log-from-sender-1"; - const std::string sender2Message = "remote-log-from-sender-2"; - - bool sender1Logged{false}; - bool sender2Logged{false}; - - sender1TimeSync->SetSimulationStepHandler([&](std::chrono::nanoseconds now, std::chrono::nanoseconds) { - if (!sender1Logged) - { - sender1Logged = true; - sender1Logger->Info(sender1Message); - } - - if (now >= 5ms) - { - sender1Lifecycle->Stop("remote logging test done"); - } - }, - 1ms); - - sender2TimeSync->SetSimulationStepHandler([&](std::chrono::nanoseconds /*now*/, std::chrono::nanoseconds) { - if (!sender2Logged) - { - sender2Logged = true; - sender2Logger->Info(sender2Message); - } - }, - 1ms); - - receiverTimeSync->SetSimulationStepHandler([](std::chrono::nanoseconds /*now*/, std::chrono::nanoseconds) {}, 1ms); - - ASSERT_TRUE(testHarness.Run(5s)); - - const auto logFiles = FindLogFiles(filePrefix); - ASSERT_EQ(logFiles.size(), 1u) << "Expected exactly one receiver log file with prefix " << filePrefix; - - const auto logContent = ReadTextFile(logFiles.front()); - EXPECT_THAT(logContent, testing::HasSubstr(sender1Message)); - EXPECT_THAT(logContent, testing::HasSubstr(sender2Message)); -} - -} // namespace diff --git a/SilKit/IntegrationTests/IntegrationTestUtils.hpp b/SilKit/IntegrationTests/IntegrationTestUtils.hpp index f84c285cc..8818f5025 100644 --- a/SilKit/IntegrationTests/IntegrationTestUtils.hpp +++ b/SilKit/IntegrationTests/IntegrationTestUtils.hpp @@ -13,14 +13,22 @@ #include #include #include +#include +#include +#include +#include -#if __unix__ +#if !defined(_WIN32) #include #include #include -#endif //__unix__ +#include // unlink +#endif -#if _WIN32 +#if defined(_WIN32) +#ifndef NOMINMAX +#define NOMINMAX // keep std::min/std::max and std::numeric_limits<>::min/max usable +#endif #include //for 'HANDLE' #endif //__WIN32 @@ -84,7 +92,7 @@ struct Pipe { using buffer_t = std::vector; Pipe() = delete; -#ifdef WIN32 +#ifdef _WIN32 HANDLE handle = INVALID_HANDLE_VALUE; Pipe(const std::string& pipeName) @@ -178,21 +186,21 @@ struct Pipe #endif }; -size_t getFileSize(const std::string& name) +inline size_t getFileSize(const std::string& name) { auto ifs = std::ifstream{name, std::ios::binary | std::ios::ate}; - return ifs.tellg(); + return static_cast(ifs.tellg()); } -bool fileExists(const std::string& name) +inline bool fileExists(const std::string& name) { auto ifs = std::ifstream{name, std::ios::in}; return ifs.good(); } -void removeTempFile(const std::string& fileName) +inline void removeTempFile(const std::string& fileName) { -#if WIN32 +#if defined(_WIN32) auto ok = DeleteFileA(fileName.c_str()); if (!ok) { @@ -207,7 +215,7 @@ void removeTempFile(const std::string& fileName) #endif } -std::string randomString(size_t len) +inline std::string randomString(size_t len) { static const std::string chars = "ABCDEFGHIJKLMNOPQRSTUVWXYZ" "abcdefghijklmnopqrstuvwxyz" @@ -223,4 +231,90 @@ std::string randomString(size_t len) } +// File sinks write "__.txt" (or ".jsonl") into the working directory, so a log +// file can only be found by its prefix. The unique suffix keeps concurrent or leftover test runs apart. +inline auto MakeUniqueLogName(const std::string& base) -> std::string +{ + return base + "_" + std::to_string(std::chrono::steady_clock::now().time_since_epoch().count()); +} + +// The prefix of the files a File sink with the given LogName writes, for all participants or for one participant. +inline auto LogFilePrefix(const std::string& logName) -> std::string +{ + return logName + "_"; +} + +inline auto LogFilePrefix(const std::string& logName, const std::string& participantName) -> std::string +{ + return LogFilePrefix(logName) + participantName + "_"; +} + +// Tests run in parallel processes that share the working directory, so files may vanish while it is scanned. Only the +// non-throwing overloads are used: a throwing directory_iterator in a destructor would terminate the test process. +inline auto FindLogFiles(const std::string& prefix) -> std::vector +{ + std::vector logFiles; + std::error_code ec; + for (std::filesystem::directory_iterator it{std::filesystem::current_path(), ec}, end; !ec && it != end; + it.increment(ec)) + { + std::error_code statusEc; + if (it->is_regular_file(statusEc) && it->path().filename().string().rfind(prefix, 0) == 0) + { + logFiles.push_back(it->path()); + } + } + return logFiles; +} + +inline auto ReadTextFile(const std::filesystem::path& path) -> std::string +{ + std::ifstream stream{path}; + std::stringstream contents; + contents << stream.rdbuf(); + return contents.str(); +} + +// Removes all log files starting with the given prefix when going out of scope. +class ScopedLogFiles +{ +public: + explicit ScopedLogFiles(std::string prefix) + : _prefix{std::move(prefix)} + { + } + + ~ScopedLogFiles() + { + for (const auto& logFile : FindLogFiles(_prefix)) + { + std::error_code ec; + std::filesystem::remove(logFile, ec); + } + } + + ScopedLogFiles(const ScopedLogFiles&) = delete; + ScopedLogFiles& operator=(const ScopedLogFiles&) = delete; + + auto Prefix() const -> const std::string& + { + return _prefix; + } + + // Concatenated contents of all matching files. Empty if no file exists. + auto ReadAll() const -> std::string + { + std::string contents; + for (const auto& logFile : FindLogFiles(_prefix)) + { + contents += ReadTextFile(logFile); + } + return contents; + } + +private: + std::string _prefix; +}; + + } // end namespace IntegrationTestUtils