From cad15ee6679e59c0f2015382d95d0aeab142785d Mon Sep 17 00:00:00 2001 From: Arkadiusz Szczepkowicz Date: Mon, 8 Jul 2024 17:51:37 +0200 Subject: [PATCH] #2187: Add tests for user tracing behavior --- tests/unit/trace/test_trace_user.cc | 353 ++++++++++++++++++++++++++++ 1 file changed, 353 insertions(+) create mode 100644 tests/unit/trace/test_trace_user.cc diff --git a/tests/unit/trace/test_trace_user.cc b/tests/unit/trace/test_trace_user.cc new file mode 100644 index 0000000000..1533df5657 --- /dev/null +++ b/tests/unit/trace/test_trace_user.cc @@ -0,0 +1,353 @@ +/* +//@HEADER +// ***************************************************************************** +// +// test_trace_user.cc +// DARMA/vt => Virtual Transport +// +// Copyright 2019-2021 National Technology & Engineering Solutions of Sandia, LLC +// (NTESS). Under the terms of Contract DE-NA0003525 with NTESS, the U.S. +// Government retains certain rights in this software. +// +// Redistribution and use in source and binary forms, with or without +// modification, are permitted provided that the following conditions are met: +// +// * Redistributions of source code must retain the above copyright notice, +// this list of conditions and the following disclaimer. +// +// * Redistributions in binary form must reproduce the above copyright notice, +// this list of conditions and the following disclaimer in the documentation +// and/or other materials provided with the distribution. +// +// * Neither the name of the copyright holder nor the names of its +// contributors may be used to endorse or promote products derived from this +// software without specific prior written permission. +// +// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" +// AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE +// IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE +// ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE +// LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR +// CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF +// SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS +// INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN +// CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) +// ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE +// POSSIBILITY OF SUCH DAMAGE. +// +// Questions? Contact darma@sandia.gov +// +// ***************************************************************************** +//@HEADER +*/ + +#include "test_parallel_harness.h" +#include "test_helpers.h" + +#if vt_check_enabled(trace_enabled) + +#include +#include + +#include +#include + +namespace vt { namespace tests { namespace unit { + +struct TestTraceUser : TestParallelHarness { + // Set dir for tracing to be the same as test name + void addAdditionalArgs() override { + trace_dir = fmt::format( + "--vt_trace_dir={}", + ::testing::UnitTest::GetInstance()->current_test_info()->name()); + addArgs(trace_dir); + addArgs(flush); + } + + virtual void TearDown() override { + TestHarnessAny::TearDown(); + } + + static void stopVt() { + try { + vt::theSched()->runSchedulerWhile([] { return !rt->isTerminated(); }); + } catch (std::exception& e) { + ADD_FAILURE() << fmt::format("Caught an exception: {}\n", e.what()); + } + +#if DEBUG_TEST_HARNESS_PRINT + auto const& my_node = theContext()->getNode(); + fmt::print("my_node={}, tearing down runtime\n", my_node); +#endif + + CollectiveOps::finalize(); + } + +private: + std::string trace_dir; + // must be != 0 for the test to work + std::string flush = "--vt_trace_flush_size=100"; +}; + +void validateLine(const std::string line, int& time) { + using vt::trace::eTraceConstants; + + // skip header (starts with P) + if (line.front() == 80) { + return; + } + // Split to tokens + std::stringstream stream(line); + std::vector tokens; + std::string token; + while (stream >> token) { + tokens.push_back(token); + } + + // validate the start time + int start_time = 0; + bool check_time = true; + eTraceConstants type = static_cast(std::stoi(tokens[0])); + switch(type) { + case eTraceConstants::Creation: // 1 + case eTraceConstants::BeginProcessing: // 2 + case eTraceConstants::EndProcessing: // 3 + start_time = std::stoi(tokens[3]); + break; + case eTraceConstants::UserEvent: // 13 + case eTraceConstants::UserSupplied: // 26 + case eTraceConstants::BeginUserEventPair: // 98 + case eTraceConstants::EndUserEventPair: // 99 + start_time = std::stoi(tokens[2]); + break; + case eTraceConstants::BeginComputation: // 6 + case eTraceConstants::EndComputation: // 7 + case eTraceConstants::BeginIdle: // 14 + case eTraceConstants::EndIdle: // 15 + case eTraceConstants::UserSuppliedNote: // 28 + case eTraceConstants::UserSuppliedBracketedNote: // 29 + start_time = std::stoi(tokens[1]); + break; + default: + check_time = false; + } + + if (check_time) { + EXPECT_GE(start_time, time); + time = start_time; + } +} + +void validateAllTraceFiles() { + std::string test_name = + ::testing::UnitTest::GetInstance()->current_test_info()->name(); + std::filesystem::path path = std::filesystem::current_path() / test_name / ""; + std::string ext = ".gz"; + + // iterate over files in test output directory + for (const auto& file : std::filesystem::directory_iterator(path)) { + if (file.path().extension() == ext) { + auto log_file_ = + std::make_shared(gzopen(file.path().c_str(), "rb")); + EXPECT_TRUE(nullptr != log_file_); + + // should be more than enough + char buffer[4096]; + int bytesRead = gzread(*log_file_, buffer, sizeof(buffer)); + EXPECT_GT(bytesRead, 0); + + std::istringstream stream(std::string(buffer, bytesRead)); + + int lastStartTime = 0; + std::string line; + // read line by line all validate start time + while (std::getline(stream, line)) { + validateLine(line, lastStartTime); + } + } + } +} + +TEST_F(TestTraceUser, trace_user_add_note_pre_epi) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + // Only the begging of the note + { + trace::addUserNotePre("some note", 2); + trace::addUserNoteEpi("some note", 2); // will crash without it + } + // Two opening notes with the same id + { + // trace::addUserNotePre("note 1", 5); // will crash + // trace::addUserNotePre("note 2", 5); // will crash + } + // note with events in between + { + trace::addUserEvent(901); + trace::addUserNotePre("TEST NOTE", 10); + trace::addUserEvent(902); + trace::addUserNoteEpi("TEST NOTE", 10); + trace::addUserEvent(903); + } + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +TEST_F(TestTraceUser, trace_user_scoped_event_hash) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + // single event + { + trace::TraceScopedEventHash("test_event"); + } + // a few events + { + auto ev1 = trace::TraceScopedEventHash("test_event_1"); + auto ev2 = trace::TraceScopedEventHash("test_event_2"); + auto ev3 = trace::TraceScopedEventHash("test_event_3"); + } + // nested events + { + auto ev1 = trace::TraceScopedEventHash("test_event_1"); + { + auto ev2 = trace::TraceScopedEventHash("test_event_2"); + { + auto ev3 = trace::TraceScopedEventHash("test_event_3"); + } + } + } + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +TEST_F(TestTraceUser, trace_user_scoped_event) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + // single event + { + trace::TraceScopedEvent(123); + } + // a few events + { + auto ev1 = trace::TraceScopedEvent(1); + auto ev2 = trace::TraceScopedEvent(2); + auto ev3 = trace::TraceScopedEvent(3); + } + // nested + { + auto ev1 = trace::TraceScopedEvent(123); + { + auto ev2 = trace::TraceScopedEvent(123); + { + auto ev3 = trace::TraceScopedEvent(123); + } + } + } + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +TEST_F(TestTraceUser, trace_user_scoped_note) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + // single note + { + trace::TraceScopedNote(123); + trace::TraceScopedNote("Some note", 456); + + auto note1 = trace::TraceScopedNote(1); + auto note2 = trace::TraceScopedNote("note", 2); + auto note3 = trace::TraceScopedNote(3); + } + // nested + { + auto note11 = trace::TraceScopedNote(123); + auto note12 = trace::TraceScopedNote("test", 456); + { + auto note21 = trace::TraceScopedNote(123); + auto note22 = trace::TraceScopedNote("test 2", 456); + { + auto note31 = trace::TraceScopedNote(123); + auto note32 = trace::TraceScopedNote("test 3", 456); + } + } + } + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +TEST_F(TestTraceUser, trace_user_note_bracketed) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + theTrace()->addUserNoteBracketedBeginTime("", 10); + theTrace()->addUserNoteBracketedBeginTime("", 10); + theTrace()->addUserNoteBracketedBeginTime("", 10); + theTrace()->addUserNoteBracketedBeginTime("", 12); + + theTrace()->addUserEvent(901); + trace::addUserNote("Note 0"); + theTrace()->addUserEvent(902); + + theTrace()->addUserNoteBracketedEndTime("INNER INNER INNER TEST NOTE 10", 12); + trace::addUserNote("Note 1"); + theTrace()->addUserNoteBracketedEndTime("INNER INNER TEST NOTE 10", 10); + trace::addUserNote("Note 2"); + theTrace()->addUserNoteBracketedEndTime("INNER TEST NOTE 10", 10); + trace::addUserNote("Note 3"); + theTrace()->addUserNoteBracketedEndTime("OUTER TEST NOTE 10", 10); + trace::addUserNote("Note 4"); + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +TEST_F(TestTraceUser, trace_user_bracketed_event) { + if (!theTrace()->checkDynamicRuntimeEnabled()) { + TestTraceUser::stopVt(); + GTEST_SKIP() << "trace tests require --vt_trace to be set"; + } + + theTrace()->addUserEvent(124); + theTrace()->addUserNote("Some Note"); + + theTrace()->addUserEventBracketedBegin(1); + theTrace()->addUserEventBracketedBegin(2); + theTrace()->addUserEventBracketedEnd(2); + theTrace()->addUserEventBracketedBegin(3); + + theTrace()->addUserEventManual(123); + theTrace()->addUserData(123456789); + + theTrace()->addUserEventBracketedEnd(1); + theTrace()->addUserEventBracketedEnd(3); + + theTrace()->addUserNote("Some Note 2"); + theTrace()->addUserData(123456); + theTrace()->addUserEvent(124); + + TestTraceUser::stopVt(); + validateAllTraceFiles(); +} + +}}} // end namespace vt::tests::unit + +#endif // vt_check_enabled(trace_enabled)