sysrap/tests/EventTimingProfileTest.cc

0001 #include <algorithm>
0002 #include <atomic>
0003 #include <cassert>
0004 #include <chrono>
0005 #include <cstdlib>
0006 #include <filesystem>
0007 #include <fstream>
0008 #include <set>
0009 #include <sstream>
0010 #include <stdexcept>
0011 #include <string>
0012 #include <thread>
0013 #include <unistd.h>
0014 #include <vector>
0015
0016 #include "EventTiming.hh"
0017 #include "SEvt.hh"
0018
0019 namespace
0020 {
0021 namespace fs = std::filesystem;
0022
0023 EventTimingSample KnownSample(
0024     std::int64_t steady_ns,
0025     std::int64_t wall_us,
0026     std::int64_t vm_kb,
0027     std::int64_t rss_kb)
0028 {
0029     EventTimingSample sample{};
0030     sample.valid_mask = EventTimingSample::bit(EventTimingCapture::Monotonic) | EventTimingSample::bit(EventTimingCapture::Wall) | EventTimingSample::bit(EventTimingCapture::Memory);
0031     sample.steady_time_ns = steady_ns;
0032     sample.wall_time_us = wall_us;
0033     sample.vm_kb = vm_kb;
0034     sample.rss_kb = rss_kb;
0035     return sample;
0036 }
0037
0038 fs::path TestDirectory()
0039 {
0040     return fs::temp_directory_path() /
0041            ("EventTimingProfileTest-" + std::to_string(static_cast<long long>(::getpid())));
0042 }
0043
0044 void WriteText(const fs::path& path, const std::string& text)
0045 {
0046     std::ofstream output(path, std::ios::binary | std::ios::trunc);
0047     assert(output);
0048     output << text;
0049     output.close();
0050     assert(output);
0051 }
0052
0053 void ExpectCsvError(const fs::path& path, const std::string& text, std::size_t line)
0054 {
0055     WriteText(path, text);
0056     bool threw = false;
0057     try
0058     {
0059         (void)EventTimingProfile::ReadFile(path);
0060     }
0061     catch (const std::runtime_error& error)
0062     {
0063         const std::string message = error.what();
0064         threw = message.find(path.string()) != std::string::npos && message.find("line " + std::to_string(line)) != std::string::npos;
0065     }
0066     assert(threw);
0067 }
0068
0069 void ExpectInvalidPath(const char* pattern)
0070 {
0071     EventTimingProfile::Configure(true, pattern, 12);
0072     bool threw = false;
0073     try
0074     {
0075         (void)EventTimingProfile::Path();
0076     }
0077     catch (const std::invalid_argument&)
0078     {
0079         threw = true;
0080     }
0081     assert(threw);
0082 }
0083
0084 void TestDisabledFastPath(const fs::path& directory)
0085 {
0086     const fs::path output = directory / "disabled.csv";
0087     EventTimingProfile::Configure(false, output);
0088
0089     EventTimingProfile::Clear();
0090     EventTimingProfile::SetTag(4);
0091     const EventTimingSample sample = EventTimingProfile::Mark("disabled");
0092     EventTimingProfile::Write();
0093     EventTimingProfile::UnsetTag();
0094
0095     assert(sample.has(EventTimingCapture::Monotonic));
0096     assert(!sample.has(EventTimingCapture::Wall));
0097     assert(!sample.has(EventTimingCapture::Memory));
0098     assert(EventTimingProfile::Size() == 0u);
0099     assert(!fs::exists(output));
0100 }
0101
0102 void TestCollectionTagsAndRss()
0103 {
0104     EventTimingProfile::Configure(true);
0105     assert(EventTimingProfile::Path() == fs::path{"event_timing_profile.csv"});
0106     EventTimingProfile::Clear();
0107     EventTimingProfile::UnsetTag();
0108
0109     const EventTimingSample first = KnownSample(100, 1000, 10000, 5000);
0110     const EventTimingSample second = KnownSample(200, 1100, 10030, 5020);
0111
0112     EventTimingProfile::SetTag(7, "A%0.3d_");
0113     assert(EventTimingProfile::HasTag());
0114     assert(EventTimingProfile::Tag() == "A007_");
0115     EventTimingProfile::Add("head", first, "first");
0116     EventTimingProfile::Add("tail", second, "second");
0117
0118     const auto records = EventTimingProfile::Records();
0119     assert(records.size() == 2u);
0120     assert(records[0].name == "A007_head");
0121     assert(records[0].metadata == "first");
0122     assert(records[1].name == "A007_tail");
0123     assert(EventTimingProfile::DeltaRssKb() == 20);
0124     assert(EventTimingProfile::RangeRssKb() == 20);
0125     assert(EventTimingProfile::Describe().find("A007_tail") != std::string::npos);
0126     assert(EventTimingProfile::Annotation({{"slice", 2}, {"max_slot_M", 16}}) == "slice=2,max_slot_M=16");
0127
0128     std::atomic<bool> child_has_tag{false};
0129     std::thread       child([&child_has_tag] {
0130         child_has_tag = EventTimingProfile::HasTag();
0131         EventTimingProfile::SetTag(3, "T%02d_");
0132         assert(EventTimingProfile::Tag() == "T03_");
0133         EventTimingProfile::UnsetTag();
0134     });
0135     child.join();
0136     assert(!child_has_tag);
0137     assert(EventTimingProfile::Tag() == "A007_");
0138     EventTimingProfile::UnsetTag();
0139 }
0140
0141 void TestCollectionOrdersCapturedSamples()
0142 {
0143     EventTimingProfile::Configure(true);
0144     EventTimingProfile::Clear();
0145     EventTimingProfile::UnsetTag();
0146
0147     EventTimingProfile::Add("late", KnownSample(300, 1300, 10030, 5030));
0148     EventTimingProfile::Add("early", KnownSample(100, 1100, 10010, 5010));
0149     EventTimingProfile::Add("middle", KnownSample(200, 1200, 10020, 5020));
0150
0151     const auto records = EventTimingProfile::Records();
0152     assert(records.size() == 3u);
0153     assert(records[0].name == "early");
0154     assert(records[1].name == "middle");
0155     assert(records[2].name == "late");
0156     assert(EventTimingProfile::DeltaRssKb() == 10);
0157     assert(EventTimingProfile::RangeRssKb() == 20);
0158 }
0159
0160 void TestEndOfRunMarkIsUntagged(const fs::path& directory)
0161 {
0162     EventTimingProfile::Configure(true, directory / "end-of-run.csv");
0163     EventTimingProfile::Clear();
0164     EventTimingProfile::SetTag(2);
0165
0166     SEvt::EndOfRun();
0167
0168     const auto records = EventTimingProfile::Records();
0169     assert(records.size() == 1u);
0170     assert(records[0].name == "SEvt__EndOfRun");
0171     assert(EventTimingProfile::Tag() == "A002_");
0172     EventTimingProfile::UnsetTag();
0173 }
0174
0175 void TestCsvRoundTripAndErrors(const fs::path& directory)
0176 {
0177     const std::string              annotation = "slice=2,\"quoted\"\nsecond line";
0178     const EventTimingProfileRecord record{
0179         "A000_QSim__simulate_LEND",
0180         KnownSample(1'234'567, 1'760'000'000'000'000, 4000, 2000),
0181         annotation,
0182     };
0183
0184     const std::string  csv = EventTimingProfile::SerializeCsv({record});
0185     std::istringstream input(csv);
0186     const auto         parsed = EventTimingProfile::ParseCsv(input, "round-trip.csv");
0187     assert(parsed.size() == 1u);
0188     assert(parsed[0].name == record.name);
0189     assert(parsed[0].sample == record.sample);
0190     assert(parsed[0].metadata == annotation);
0191
0192     ExpectCsvError(
0193         directory / "unterminated.csv",
0194         "name,wall_time_us,steady_time_ns,vm_kb,rss_kb,metadata\n"
0195         "mark,1,2,3,4,\"unterminated\n",
0196         2);
0197     ExpectCsvError(
0198         directory / "non-integer.csv",
0199         "name,wall_time_us,steady_time_ns,vm_kb,rss_kb,metadata\n"
0200         "mark,1,nope,3,4,\n",
0201         2);
0202     ExpectCsvError(
0203         directory / "bad-header.csv",
0204         "wrong,wall_time_us,steady_time_ns,vm_kb,rss_kb,metadata\n",
0205         1);
0206     ExpectCsvError(
0207         directory / "wrong-columns.csv",
0208         "name,wall_time_us,steady_time_ns,vm_kb,rss_kb,metadata\n"
0209         "mark,1,2,3,4\n",
0210         2);
0211 }
0212
0213 void TestSnapshotsAndPaths(const fs::path& directory)
0214 {
0215     const fs::path output = directory / "profile.csv";
0216     EventTimingProfile::Configure(true, output);
0217
0218     EventTimingProfile::Clear();
0219     EventTimingProfile::Add("first", KnownSample(10, 100, 1000, 500));
0220     EventTimingProfile::Write(EventTimingWriteMode::Replace);
0221
0222     EventTimingProfile::Clear();
0223     EventTimingProfile::Add("second", KnownSample(20, 200, 1100, 510));
0224     EventTimingProfile::Write(EventTimingWriteMode::Replace);
0225     auto records = EventTimingProfile::ReadFile(output);
0226     assert(records.size() == 1u);
0227     assert(records[0].name == "second");
0228
0229     EventTimingProfile::Clear();
0230     EventTimingProfile::Add("third", KnownSample(30, 300, 1200, 520));
0231     EventTimingProfile::Write(EventTimingWriteMode::Append);
0232     records = EventTimingProfile::ReadFile(output);
0233     assert(records.size() == 2u);
0234     assert(records[0].name == "second");
0235     assert(records[1].name == "third");
0236
0237     for (const fs::directory_entry& entry : fs::directory_iterator(directory))
0238         assert(entry.path().filename().string().find(".tmp.") == std::string::npos);
0239
0240     const fs::path indexed = directory / "profile_%05d.csv";
0241     EventTimingProfile::Configure(true, indexed, 12);
0242     assert(EventTimingProfile::Path() == directory / "profile_00012.csv");
0243
0244     ExpectInvalidPath("profile_%s.csv");
0245     ExpectInvalidPath("profile_%n.csv");
0246     ExpectInvalidPath("profile_%d_%d.csv");
0247     ExpectInvalidPath("profile_%");
0248     ExpectInvalidPath("profile_%*d.csv");
0249 }
0250
0251 void TestConcurrentMarksAndSnapshots()
0252 {
0253     EventTimingProfile::Configure(true);
0254     EventTimingProfile::Clear();
0255     EventTimingProfile::UnsetTag();
0256
0257     std::atomic<bool>        start{false};
0258     std::atomic<int>         complete{0};
0259     std::vector<std::thread> threads;
0260     for (int thread_index = 0; thread_index < 4; ++thread_index)
0261     {
0262         threads.emplace_back([thread_index, &start, &complete] {
0263             while (!start.load(std::memory_order_acquire))
0264                 std::this_thread::yield();
0265             EventTimingProfile::SetTag(thread_index, "T%02d_");
0266             for (int record_index = 0; record_index < 100; ++record_index)
0267             {
0268                 EventTimingProfile::Add(
0269                     "item",
0270                     KnownSample(
0271                         thread_index * 1000 + record_index,
0272                         10000 + thread_index * 1000 + record_index,
0273                         2000,
0274                         1000));
0275             }
0276             EventTimingProfile::UnsetTag();
0277             complete.fetch_add(1, std::memory_order_release);
0278         });
0279     }
0280
0281     start.store(true, std::memory_order_release);
0282     while (complete.load(std::memory_order_acquire) != 4)
0283     {
0284         const auto         snapshot = EventTimingProfile::Records();
0285         const std::string  csv = EventTimingProfile::SerializeCsv(snapshot);
0286         std::istringstream input(csv);
0287         const auto         parsed = EventTimingProfile::ParseCsv(input, "snapshot.csv");
0288         assert(parsed.size() == snapshot.size());
0289     }
0290     for (std::thread& thread : threads)
0291         thread.join();
0292
0293     const auto records = EventTimingProfile::Records();
0294     assert(records.size() == 400u);
0295     std::set<std::string> prefixes;
0296     for (const EventTimingProfileRecord& record : records)
0297     {
0298         assert(record.name.size() == 8u);
0299         assert(record.name.substr(0, 1) == "T");
0300         assert(record.name.substr(4) == "item");
0301         prefixes.insert(record.name.substr(0, 4));
0302     }
0303     assert(prefixes == std::set<std::string>({"T00_", "T01_", "T02_", "T03_"}));
0304     assert(!EventTimingProfile::HasTag());
0305 }
0306 } // namespace
0307
0308 int main()
0309 {
0310     const fs::path directory = TestDirectory();
0311     fs::remove_all(directory);
0312     fs::create_directories(directory);
0313
0314     TestDisabledFastPath(directory);
0315     TestCollectionTagsAndRss();
0316     TestCollectionOrdersCapturedSamples();
0317     TestEndOfRunMarkIsUntagged(directory);
0318     TestCsvRoundTripAndErrors(directory);
0319     TestSnapshotsAndPaths(directory);
0320     TestConcurrentMarksAndSnapshots();
0321
0322     EventTimingProfile::Clear();
0323     EventTimingProfile::UnsetTag();
0324     EventTimingProfile::Configure(false);
0325     fs::remove_all(directory);
0326     return 0;
0327 }