[ntuple] Add ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS

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

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 <TFileMerger::MergeRecursive>: Merging RNTuples is experimental

tree/ntuple/inc/ROOT/RNTupleMetrics.hxx

@@ -283,8 +283,8 @@ using RNTupleAtomicTimer = RNTupleTimer<RNTupleAtomicCounter, RNTupleTickCounter
 
 The class owns the counters.
 
-If the environment variable `ROOT_EXPORT_RNTUPLE_METRICS` is set, metrics are automatically enabled on
-construction, and any counter added afterwards through MakeCounter() is enabled as well.
+If the environment variable `ROOT_EXPERIMENTAL_EXPORT_RNTUPLE_METRICS` is set, metrics are automatically enabled
+on construction, and any counter added afterwards through MakeCounter() is enabled as well.
 */
 // clang-format on
 class RNTupleMetrics {
@@ -295,22 +295,28 @@ private:
    std::vector<std::unique_ptr<RNTuplePerfCounter>> fCounters;
    std::vector<RNTupleMetrics *> 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<std::pair<std::string, const RNTuplePerfCounter *>> &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 <typename CounterPtrT, class... Args>
@@ -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();

tree/ntuple/src/RNTupleMetrics.cxx

@@ -14,11 +14,39 @@
 
 #include <ROOT/RNTupleMetrics.hxx>
 
+#include <ROOT/RConfig.hxx>
+#include <ROOT/RField.hxx>
+#include <ROOT/RLogger.hxx>
+#include <ROOT/RNTupleModel.hxx>
+#include <ROOT/RNTupleUtils.hxx>
+#include <ROOT/RNTupleWriter.hxx>
+
+#include <TFile.h>
+#include <TFileMerger.h>
+#include <TMemFile.h>
 #include <TSystem.h>
 
+#include <cstdint>
+#include <mutex>
 #include <ostream>
+#include <vector>
 
-#include <iostream>
+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<std::pair<std::string, const RNTuplePerfCounter *>> &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<std::pair<std::string, const RNTuplePerfCounter *>> 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<const RNTupleCalcPerf *>(counter))
+         *model->MakeField<double>(fieldName) = calc->GetValue();
+      else
+         *model->MakeField<std::int64_t>(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<std::mutex> 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;
+   }
 }

tree/ntuple/src/RNTupleParallelWriter.cxx

@@ -129,7 +129,7 @@ class RPageSynchronizingSink : public RPageSink {
 
 ROOT::RNTupleParallelWriter::RNTupleParallelWriter(std::unique_ptr<ROOT::RNTupleModel> model,
                                                    std::unique_ptr<RPageSink> 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"));

tree/ntuple/src/RNTupleReader.cxx

@@ -153,7 +153,7 @@ void ROOT::RNTupleReader::InitPageSource(bool enableMetrics)
 ROOT::RNTupleReader::RNTupleReader(std::unique_ptr<ROOT::RNTupleModel> model,
                                    std::unique_ptr<ROOT::Internal::RPageSource> 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<ROOT::RNTupleModel> model,
 
 ROOT::RNTupleReader::RNTupleReader(std::unique_ptr<ROOT::Internal::RPageSource> 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());
 }

tree/ntuple/src/RNTupleWriter.cxx

@@ -37,7 +37,7 @@ static bool IsReservedRNTupleAttrSetName(std::string_view name)
 
 ROOT::RNTupleWriter::RNTupleWriter(std::unique_ptr<ROOT::RNTupleModel> model,
                                    std::unique_ptr<ROOT::Internal::RPageSink> 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() &&

tree/ntuple/test/ntuple_metrics.cxx

@@ -1,3 +1,6 @@
+#include "TEnv.h"
+#include "TKey.h"
+#include "TSystem.h"
 #include "ntuple_test.hxx"
 
 #include <cmath>
@@ -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>("float_field");
+
+   auto writer = RNTupleWriter::Recreate(std::move(model), rNTupleName, fileName);
+
+   for (std::size_t i = 0; i < kNEntries; ++i) {
+      *pt = static_cast<float>(i);
+      writer->Fill();
+   }
+   writer->CommitDataset();
+}
+
+void readMetrics(const std::string fileName, std::ostream &output)
+{
+   TFile file(fileName.c_str());
+
+   std::set<std::string> ntupleNames;
+   for (auto *keyObject : *file.GetListOfKeys()) {
+      auto *key = static_cast<TKey *>(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);
+}