diff --git a/roottest/root/ntuple/metrics/CMakeLists.txt b/roottest/root/ntuple/metrics/CMakeLists.txt index 24fb47b881f7b..61b762854f78b 100644 --- a/roottest/root/ntuple/metrics/CMakeLists.txt +++ b/roottest/root/ntuple/metrics/CMakeLists.txt @@ -1,6 +1,6 @@ ROOTTEST_ADD_TEST(metrics_env_enabled MACRO test_rntuple_metrics_env.C - ENVIRONMENT ROOT_EXPORT_RNTUPLE_METRICS=metrics_env_enabled.root + ENVIRONMENT ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS=metrics_env_enabled.root OUTREF metrics_env_enabled.ref) ROOTTEST_ADD_TEST(metrics_env_disabled diff --git a/roottest/root/ntuple/metrics/metrics_env_enabled.ref b/roottest/root/ntuple/metrics/metrics_env_enabled.ref index 289372a209b92..378512a40c9b7 100644 --- a/roottest/root/ntuple/metrics/metrics_env_enabled.ref +++ b/roottest/root/ntuple/metrics/metrics_env_enabled.ref @@ -1,3 +1,4 @@ Processing test_rntuple_metrics_env.C... Metrics enabled: true nPageCommitted: 1 +Warning in : Merging RNTuples is experimental diff --git a/tree/ntuple/inc/ROOT/RNTupleMetrics.hxx b/tree/ntuple/inc/ROOT/RNTupleMetrics.hxx index 965234e254851..2eb0e6ee990b3 100644 --- a/tree/ntuple/inc/ROOT/RNTupleMetrics.hxx +++ b/tree/ntuple/inc/ROOT/RNTupleMetrics.hxx @@ -283,8 +283,8 @@ using RNTupleAtomicTimer = RNTupleTimer> fCounters; std::vector fObservedMetrics; std::string fName; + std::string fNTupleName; + std::string fExportPath; bool fIsEnabled = false; + bool fHasAttemptedToExport = false; bool Contains(const std::string &name) const; + void CollectCounters(std::vector> &counters) const; + void ExportToRootFile(); public: - explicit RNTupleMetrics(const std::string &name) : fName(name) + explicit RNTupleMetrics(const std::string &name) : RNTupleMetrics(name, "") {} + RNTupleMetrics(const std::string &name, const std::string &ntupleName) + : fName(name), fNTupleName(ntupleName), fExportPath(GetMetricsExportPath()) { - // TODO: Use the value of `GetMetricsExportPath` to save the contents of the metrics in a `.root` file - if (!GetMetricsExportPath().empty()) + if (!fExportPath.empty()) Enable(); } RNTupleMetrics(const RNTupleMetrics &other) = delete; RNTupleMetrics & operator=(const RNTupleMetrics &other) = delete; RNTupleMetrics(RNTupleMetrics &&other) = default; RNTupleMetrics & operator=(RNTupleMetrics &&other) = default; - ~RNTupleMetrics() = default; + ~RNTupleMetrics(); // TODO(jblomer): return a reference template @@ -332,7 +338,7 @@ public: const RNTuplePerfCounter *GetCounter(std::string_view name) const; void ObserveMetrics(RNTupleMetrics &observee); - static const std::string &GetMetricsExportPath(); + static std::string GetMetricsExportPath(); void Print(std::ostream &output, const std::string &prefix = "") const; void Enable(); diff --git a/tree/ntuple/src/RNTupleMetrics.cxx b/tree/ntuple/src/RNTupleMetrics.cxx index 5bd4538bfae15..d32f5263a205f 100644 --- a/tree/ntuple/src/RNTupleMetrics.cxx +++ b/tree/ntuple/src/RNTupleMetrics.cxx @@ -14,11 +14,39 @@ #include +#include +#include +#include +#include +#include +#include + +#include +#include +#include #include +#include +#include #include +#include -#include +namespace { + +std::mutex &GetMetricsExportMutex() +{ + static std::mutex mutex; + return mutex; +} + +thread_local bool gSuppressMetricsExport = false; + +struct RSuppressMetaMetrics { + RSuppressMetaMetrics() { gSuppressMetricsExport = true; } + ~RSuppressMetaMetrics() { gSuppressMetricsExport = false; } +}; + +} // anonymous namespace ROOT::Experimental::Detail::RNTuplePerfCounter::~RNTuplePerfCounter() { @@ -93,12 +121,95 @@ void ROOT::Experimental::Detail::RNTupleMetrics::ObserveMetrics(RNTupleMetrics & fObservedMetrics.push_back(&observee); } -const std::string &ROOT::Experimental::Detail::RNTupleMetrics::GetMetricsExportPath() +std::string ROOT::Experimental::Detail::RNTupleMetrics::GetMetricsExportPath() { - static const std::string path = []() -> std::string { - if (const char *env = gSystem->Getenv("ROOT_EXPORT_RNTUPLE_METRICS"); env && *env) - return env; - return ""; - }(); - return path; + if (gSuppressMetricsExport) + return {}; + + if (const char *env = gSystem->Getenv("ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS"); env && *env) + return env; + + return {}; +} + +ROOT::Experimental::Detail::RNTupleMetrics::~RNTupleMetrics() +{ + if (R__unlikely(fHasAttemptedToExport)) { + R__LOG_INFO(ROOT::Internal::NTupleLog()) << "metrics export was already attempted: not retrying"; + return; + } + + if (!fIsEnabled) { + R__LOG_INFO(ROOT::Internal::NTupleLog()) << "metrics disabled"; + return; + } + + if (fNTupleName.empty()) { + R__LOG_INFO(ROOT::Internal::NTupleLog()) << "no ntuple name set"; + return; + } + + ExportToRootFile(); + + fHasAttemptedToExport = true; +} + +void ROOT::Experimental::Detail::RNTupleMetrics::CollectCounters( + std::vector> &counters) const +{ + for (const auto &counter : fCounters) + counters.emplace_back(fName, counter.get()); + for (const auto *observed : fObservedMetrics) + observed->CollectCounters(counters); +} + +void ROOT::Experimental::Detail::RNTupleMetrics::ExportToRootFile() +{ + if (fExportPath.empty()) { + R__LOG_INFO(ROOT::Internal::NTupleLog()) << "no export path set"; + return; + } + + std::vector> counters; + CollectCounters(counters); + + if (R__unlikely(counters.empty())) { + R__LOG_INFO(ROOT::Internal::NTupleLog()) << "no counters to export for '" << fNTupleName << "'"; + return; + } + + // Avoid inifinite recursion (an RNTupleWriter is created to print the metrics) + RSuppressMetaMetrics suppressGuard; + + auto model = ROOT::RNTupleModel::Create(); + for (const auto &[componentName, counter] : counters) { + const std::string fieldName = componentName + "_" + counter->GetName(); + if (const auto *calc = dynamic_cast(counter)) + *model->MakeField(fieldName) = calc->GetValue(); + else + *model->MakeField(fieldName) = counter->GetValueAsInt(); + } + + TMemFile memoryFile(fNTupleName.c_str(), "RECREATE"); + { + auto writer = ROOT::RNTupleWriter::Append(std::move(model), fNTupleName, memoryFile); + writer->Fill(); + writer->CommitDataset(); + } + + std::lock_guard lock(GetMetricsExportMutex()); + + TFileMerger merger; + merger.SetMergeOptions(std::string_view("rntuple.MergingMode=Union")); + + if (!merger.OutputFile(fExportPath.c_str(), "UPDATE")) { + R__LOG_ERROR(ROOT::Internal::NTupleLog()) << "cannot open metrics export file '" << fExportPath << "'"; + return; + } + + if (!merger.AddFile(&memoryFile) || !merger.PartialMerge(TFileMerger::kAll | TFileMerger::kIncremental)) { + R__LOG_ERROR(ROOT::Internal::NTupleLog()) + << "cannot merge metrics for '" << fNTupleName << "' into '" << fExportPath << "'"; + return; + } } diff --git a/tree/ntuple/src/RNTupleParallelWriter.cxx b/tree/ntuple/src/RNTupleParallelWriter.cxx index 453d6805b9287..6729a4d317212 100644 --- a/tree/ntuple/src/RNTupleParallelWriter.cxx +++ b/tree/ntuple/src/RNTupleParallelWriter.cxx @@ -129,7 +129,7 @@ class RPageSynchronizingSink : public RPageSink { ROOT::RNTupleParallelWriter::RNTupleParallelWriter(std::unique_ptr model, std::unique_ptr sink) - : fSink(std::move(sink)), fModel(std::move(model)), fMetrics("RNTupleParallelWriter") + : fSink(std::move(sink)), fModel(std::move(model)), fMetrics("RNTupleParallelWriter", fSink->GetNTupleName()) { if (fModel->GetRegisteredSubfieldNames().size() > 0) { throw RException(R__FAIL("cannot create an RNTupleParallelWriter from a model with registered subfields")); diff --git a/tree/ntuple/src/RNTupleReader.cxx b/tree/ntuple/src/RNTupleReader.cxx index 3672603186efc..896f05e75c8cf 100644 --- a/tree/ntuple/src/RNTupleReader.cxx +++ b/tree/ntuple/src/RNTupleReader.cxx @@ -153,7 +153,7 @@ void ROOT::RNTupleReader::InitPageSource(bool enableMetrics) ROOT::RNTupleReader::RNTupleReader(std::unique_ptr model, std::unique_ptr source, const ROOT::RNTupleReadOptions &options) - : fSource(std::move(source)), fModel(std::move(model)), fMetrics("RNTupleReader") + : fSource(std::move(source)), fModel(std::move(model)), fMetrics("RNTupleReader", fSource->GetNTupleName()) { // TODO(jblomer): properly support projected fields auto &projectedFields = ROOT::Internal::GetProjectedFieldsOfModel(*fModel); @@ -167,7 +167,7 @@ ROOT::RNTupleReader::RNTupleReader(std::unique_ptr model, ROOT::RNTupleReader::RNTupleReader(std::unique_ptr source, const ROOT::RNTupleReadOptions &options) - : fSource(std::move(source)), fModel(nullptr), fMetrics("RNTupleReader") + : fSource(std::move(source)), fModel(nullptr), fMetrics("RNTupleReader", fSource->GetNTupleName()) { InitPageSource(options.GetEnableMetrics()); } diff --git a/tree/ntuple/src/RNTupleWriter.cxx b/tree/ntuple/src/RNTupleWriter.cxx index eec45995faf14..2c320794a6e69 100644 --- a/tree/ntuple/src/RNTupleWriter.cxx +++ b/tree/ntuple/src/RNTupleWriter.cxx @@ -37,7 +37,7 @@ static bool IsReservedRNTupleAttrSetName(std::string_view name) ROOT::RNTupleWriter::RNTupleWriter(std::unique_ptr model, std::unique_ptr sink) - : fFillContext(std::move(model), std::move(sink)), fMetrics("RNTupleWriter") + : fFillContext(std::move(model), std::move(sink)), fMetrics("RNTupleWriter", fFillContext.fSink->GetNTupleName()) { #ifdef R__USE_IMT if (IsImplicitMTEnabled() && diff --git a/tree/ntuple/test/ntuple_metrics.cxx b/tree/ntuple/test/ntuple_metrics.cxx index 4f7deb7d8262c..0245aca2d87a0 100644 --- a/tree/ntuple/test/ntuple_metrics.cxx +++ b/tree/ntuple/test/ntuple_metrics.cxx @@ -1,3 +1,6 @@ +#include "TEnv.h" +#include "TKey.h" +#include "TSystem.h" #include "ntuple_test.hxx" #include @@ -154,3 +157,100 @@ TEST(Metrics, IOMetrics) EXPECT_GT(szFile->GetValueAsInt(), 0); } } + +namespace { + +void writeDummyEntries(std::string_view fileName, std::string_view rNTupleName) +{ + constexpr std::size_t kNEntries = 1000; + auto model = RNTupleModel::Create(); + auto pt = model->MakeField("float_field"); + + auto writer = RNTupleWriter::Recreate(std::move(model), rNTupleName, fileName); + + for (std::size_t i = 0; i < kNEntries; ++i) { + *pt = static_cast(i); + writer->Fill(); + } + writer->CommitDataset(); +} + +void readMetrics(const std::string fileName, std::ostream &output) +{ + TFile file(fileName.c_str()); + + std::set ntupleNames; + for (auto *keyObject : *file.GetListOfKeys()) { + auto *key = static_cast(keyObject); + if (std::string(key->GetClassName()) == "ROOT::RNTuple") + ntupleNames.insert(key->GetName()); + } + + for (const auto &ntupleName : ntupleNames) { + auto reader = ROOT::RNTupleReader::Open(ntupleName, fileName); + const auto &descriptor = reader->GetDescriptor(); + + output << ntupleName << "\n\n"; + for (auto counterId : descriptor.GetFieldZero().GetLinkIds()) { + std::string fieldName = descriptor.GetFieldDescriptor(counterId).GetFieldName(); + std::string type = descriptor.GetFieldDescriptor(counterId).GetTypeName(); + + output << std::string(8, ' ') << fieldName << "\n"; + } + output << "\n"; + } +} +} // namespace + +TEST(Metrics, EnvironmentVariableExport) +{ + FileRaii fileGuard("test_environment_variable_export_export.root"); + + const std::string metricsFileName = "environment_variable_export_metrics.root"; + + gSystem->Setenv("ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS", metricsFileName.c_str()); + + writeDummyEntries(fileGuard.GetPath().c_str(), "rntuple_name_1"); + writeDummyEntries(fileGuard.GetPath().c_str(), "rntuple_name_1"); + writeDummyEntries(fileGuard.GetPath().c_str(), "rntuple_name_2"); + + gSystem->Unsetenv("ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS"); + + std::stringstream printedMetricsStream; + readMetrics(metricsFileName, printedMetricsStream); + + const std::string printedMetricsString = std::move(printedMetricsStream).str(); + const std::string expected = R"(rntuple_name_1 + + RPageSinkBuf_ParallelZip + RPageSinkBuf_timeWallZip + RPageSinkBuf_timeWallCriticalSection + RPageSinkBuf_timeCpuZip + RPageSinkBuf_timeCpuCriticalSection + RPageSinkFile_nPageCommitted + RPageSinkFile_szWritePayload + RPageSinkFile_szZip + RPageSinkFile_timeWallWrite + RPageSinkFile_timeWallZip + RPageSinkFile_timeCpuWrite + RPageSinkFile_timeCpuZip + +rntuple_name_2 + + RPageSinkBuf_ParallelZip + RPageSinkBuf_timeWallZip + RPageSinkBuf_timeWallCriticalSection + RPageSinkBuf_timeCpuZip + RPageSinkBuf_timeCpuCriticalSection + RPageSinkFile_nPageCommitted + RPageSinkFile_szWritePayload + RPageSinkFile_szZip + RPageSinkFile_timeWallWrite + RPageSinkFile_timeWallZip + RPageSinkFile_timeCpuWrite + RPageSinkFile_timeCpuZip + +)"; + + EXPECT_EQ(printedMetricsString, expected); +}