[ML] Log best hyperparameters and runtime summary (#864)

This PR changes the logging level for the best hyperparameters from TRACE to INFO. It also adds tracking runtime for the hyperparameter optimization steps and logs the total number of steps, mean runtime per iteration and its stdev.

Author: valeriy42

lib/maths/CBoostedTreeImpl.cc

@@ -10,6 +10,7 @@
 #include <core/CLoopProgress.h>
 #include <core/CPersistUtils.h>
 #include <core/CProgramCounters.h>
+#include <core/CStopWatch.h>
 
 #include <maths/CBasicStatisticsPersist.h>
 #include <maths/CBayesianOptimisation.h>
@@ -442,6 +443,10 @@ void CBoostedTreeImpl::train(core::CDataFrame& frame,
         LOG_TRACE(<< "Test loss = " << m_BestForestTestLoss);
 
     } else if (m_CurrentRound < m_NumberRounds || m_BestForest.empty()) {
+        using TMeanVarAccumulator = CBasicStatistics::SSampleMeanVar<double>::TAccumulator;
+        TMeanVarAccumulator timeAccumulator;
+        core::CStopWatch stopWatch;
+        stopWatch.start();
 
         // Hyperparameter optimisation loop.
 
@@ -474,6 +479,8 @@ void CBoostedTreeImpl::train(core::CDataFrame& frame,
             LOG_TRACE(<< "Round " << m_CurrentRound << " state recording started");
             this->recordState(recordTrainStateCallback);
             LOG_TRACE(<< "Round " << m_CurrentRound << " state recording finished");
+
+            timeAccumulator.add(static_cast<float>(stopWatch.lap()));
         }
 
         LOG_TRACE(<< "Test loss = " << m_BestForestTestLoss);
@@ -483,6 +490,12 @@ void CBoostedTreeImpl::train(core::CDataFrame& frame,
         m_BestForest = this->trainForest(frame, this->allTrainingRowsMask(), recordMemoryUsage);
         this->recordState(recordTrainStateCallback);
 
+        timeAccumulator.add(static_cast<float>(stopWatch.stop()));
+
+        LOG_INFO(<< "Training finished after " << m_CurrentRound << " iterations. Time per iteration in ms mean: "
+                 << CBasicStatistics::mean(timeAccumulator) << " std. dev:  "
+                 << std::sqrt(CBasicStatistics::variance(timeAccumulator)));
+
         core::CProgramCounters::counter(counter_t::E_DFTPMTrainedForestNumberTrees) =
             m_BestForest.size();
     }
@@ -1175,10 +1188,10 @@ void CBoostedTreeImpl::restoreBestHyperparameters() {
     m_Eta = m_BestHyperparameters.eta();
     m_EtaGrowthRatePerTree = m_BestHyperparameters.etaGrowthRatePerTree();
     m_FeatureBagFraction = m_BestHyperparameters.featureBagFraction();
-    LOG_TRACE(<< "regularization* = " << m_Regularization.print()
-              << ", downsample factor* = " << m_DownsampleFactor << ", eta* = " << m_Eta
-              << ", eta growth rate per tree* = " << m_EtaGrowthRatePerTree
-              << ", feature bag fraction* = " << m_FeatureBagFraction);
+    LOG_INFO(<< "Best hyperparameters: regularization* = " << m_Regularization.print()
+             << ", downsample factor* = " << m_DownsampleFactor << ", eta* = " << m_Eta
+             << ", eta growth rate per tree* = " << m_EtaGrowthRatePerTree
+             << ", feature bag fraction* = " << m_FeatureBagFraction);
 }
 
 std::size_t CBoostedTreeImpl::numberHyperparametersToTune() const {