Print winning iteration and runtime in CLI (dotnet#288)

* Print best metric and runtime

* Print best metric and runtime

* Line endings in AutoMLEngine.cs

* Rename time column to duration to match Python SDK

* Revert to MicroAccuracy and MacroAccuracy spellings

* Revert spelling of BinaryClassificationMetricsAgent to BinaryMetricsAgent to reduce merge conflicts

* Revert spelling of MulticlassMetricsAgent to MultiMetricsAgent to reduce merge conflicts

* missed some files

* Fix merge conflict

* Update AutoMLEngine.cs

Author: justinormont

src/Microsoft.ML.Auto/API/RunResult.cs

@@ -15,11 +15,11 @@ public sealed class RunResult<T>
         public ITransformer Model { get { return _modelContainer.GetModel(); } }
         public Exception Exception { get; private set; }
         public string TrainerName { get; private set; }
-        public int RuntimeInSeconds { get; private set; }
+        public double RuntimeInSeconds { get; private set; }
         public IEstimator<ITransformer> Estimator { get; private set; }
 
         internal Pipeline Pipeline { get; private set; }
-        internal int PipelineInferenceTimeInSeconds { get; private set; }
+        internal double PipelineInferenceTimeInSeconds { get; private set; }
 
         private readonly ModelContainer _modelContainer;
 
@@ -28,8 +28,8 @@ internal RunResult(ModelContainer modelContainer,
             IEstimator<ITransformer> estimator,
             Pipeline pipeline,
             Exception exception,
-            int runtimeInSeconds,
-            int pipelineInferenceTimeInSeconds)
+            double runtimeInSeconds,
+            double pipelineInferenceTimeInSeconds)
         {
             _modelContainer = modelContainer;
             ValidationMetrics = metrics;

src/Microsoft.ML.Auto/Experiment/Experiment.cs

@@ -101,8 +101,8 @@ public List<RunResult<T>> Execute()
                     // evaluate pipeline
                     runResult = ProcessPipeline(pipeline);
 
-                    runResult.RuntimeInSeconds = (int)iterationStopwatch.Elapsed.TotalSeconds;
-                    runResult.PipelineInferenceTimeInSeconds = (int)getPiplelineStopwatch.Elapsed.TotalSeconds;
+                    runResult.RuntimeInSeconds = iterationStopwatch.Elapsed.TotalSeconds;
+                    runResult.PipelineInferenceTimeInSeconds = getPiplelineStopwatch.Elapsed.TotalSeconds;
                 }
                 catch (Exception ex)
                 {

src/Microsoft.ML.Auto/Experiment/MetricsAgents/BinaryMetricsAgent.cs

@@ -2,7 +2,6 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 // See the LICENSE file in the project root for more information.
 
-using System;
 using Microsoft.ML.Data;
 
 namespace Microsoft.ML.Auto
@@ -18,6 +17,11 @@ public BinaryMetricsAgent(BinaryClassificationMetric optimizingMetric)
 
         public double GetScore(BinaryClassificationMetrics metrics)
         {
+            if (metrics == null)
+            {
+                return double.NaN;
+            }
+
             switch (_optimizingMetric)
             {
                 case BinaryClassificationMetric.Accuracy:

src/Microsoft.ML.Auto/Experiment/MetricsAgents/MultiMetricsAgent.cs

@@ -17,6 +17,11 @@ public MultiMetricsAgent(MulticlassClassificationMetric optimizingMetric)
 
         public double GetScore(MultiClassClassifierMetrics metrics)
         {
+            if (metrics == null)
+            {
+                return double.NaN;
+            }
+
             switch (_optimizingMetric)
             {
                 case MulticlassClassificationMetric.MacroAccuracy:

src/Microsoft.ML.Auto/Experiment/MetricsAgents/RegressionMetricsAgent.cs

@@ -17,6 +17,11 @@ public RegressionMetricsAgent(RegressionMetric optimizingMetric)
 
         public double GetScore(RegressionMetrics metrics)
         {
+            if (metrics == null)
+            {
+                return double.NaN;
+            }
+
             switch (_optimizingMetric)
             {
                 case RegressionMetric.MeanAbsoluteError:

src/Microsoft.ML.Auto/Experiment/SuggestedPipelineResult.cs

@@ -38,8 +38,8 @@ internal class SuggestedPipelineResult<T> : SuggestedPipelineResult
         public ModelContainer ModelContainer { get; set; }
         public Exception Exception { get; set; }
 
-        public int RuntimeInSeconds { get; set; }
-        public int PipelineInferenceTimeInSeconds { get; set; }
+        public double RuntimeInSeconds { get; set; }
+        public double PipelineInferenceTimeInSeconds { get; set; }
 
         public SuggestedPipelineResult(T evaluatedMetrics, IEstimator<ITransformer> estimator,
             ModelContainer modelContainer, SuggestedPipeline pipeline, double score, Exception exception)

src/mlnet/AutoML/AutoMLEngine.cs

@@ -50,13 +50,15 @@ public ColumnInferenceResults InferColumns(MLContext context, ColumnInformation
 
             if (taskKind == TaskKind.BinaryClassification)
             {
-                var progressReporter = new ProgressHandlers.BinaryClassificationHandler();
+                var optimizationMetric = new BinaryExperimentSettings().OptimizingMetric;
+                var progressReporter = new ProgressHandlers.BinaryClassificationHandler(optimizationMetric);
                 var result = context.Auto()
                     .CreateBinaryClassificationExperiment(new BinaryExperimentSettings()
                     {
                         MaxExperimentTimeInSeconds = settings.MaxExplorationTime,
                         ProgressHandler = progressReporter,
-                        EnableCaching = this.enableCaching
+                        EnableCaching = this.enableCaching,
+                        OptimizingMetric = optimizationMetric
                     })
                     .Execute(trainData, validationData, columnInformation);
                 logger.Log(LogLevel.Info, Strings.RetrieveBestPipeline);
@@ -67,12 +69,14 @@ public ColumnInferenceResults InferColumns(MLContext context, ColumnInformation
 
             if (taskKind == TaskKind.Regression)
             {
-                var progressReporter = new ProgressHandlers.RegressionHandler();
+                var optimizationMetric = new RegressionExperimentSettings().OptimizingMetric;
+                var progressReporter = new ProgressHandlers.RegressionHandler(optimizationMetric);
                 var result = context.Auto()
                     .CreateRegressionExperiment(new RegressionExperimentSettings()
                     {
                         MaxExperimentTimeInSeconds = settings.MaxExplorationTime,
                         ProgressHandler = progressReporter,
+                        OptimizingMetric = optimizationMetric,
                         EnableCaching = this.enableCaching
                     }).Execute(trainData, validationData, columnInformation);
                 logger.Log(LogLevel.Info, Strings.RetrieveBestPipeline);
@@ -83,13 +87,15 @@ public ColumnInferenceResults InferColumns(MLContext context, ColumnInformation
 
             if (taskKind == TaskKind.MulticlassClassification)
             {
-                var progressReporter = new ProgressHandlers.MulticlassClassificationHandler();
+                var optimizationMetric = new MulticlassExperimentSettings().OptimizingMetric;
+                var progressReporter = new ProgressHandlers.MulticlassClassificationHandler(optimizationMetric);
 
                 var experimentSettings = new MulticlassExperimentSettings()
                 {
                     MaxExperimentTimeInSeconds = settings.MaxExplorationTime,
                     ProgressHandler = progressReporter,
-                    EnableCaching = this.enableCaching
+                    EnableCaching = this.enableCaching,
+                    OptimizingMetric = optimizationMetric
                 };
 
                 // Inclusion list for currently supported learners. Need to remove once we have codegen support for all other learners.

src/mlnet/Utilities/ConsolePrinter.cs

@@ -12,43 +12,44 @@ internal class ConsolePrinter
         private static NLog.Logger logger = NLog.LogManager.GetCurrentClassLogger();
 
 
-        internal static void PrintBinaryClassificationMetrics(int iteration, string trainerName, BinaryClassificationMetrics metrics)
+        internal static void PrintMetrics(int iteration, string trainerName, BinaryClassificationMetrics metrics, double bestMetric, double runtimeInSeconds)
         {
-            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.Accuracy ?? double.NaN,9:F4} {metrics?.Auc ?? double.NaN,8:F4} {metrics?.Auprc ?? double.NaN,8:F4} {metrics?.F1Score ?? double.NaN,9:F4}");
+            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.Accuracy ?? double.NaN,9:F4} {metrics?.Auc ?? double.NaN,8:F4} {metrics?.Auprc ?? double.NaN,8:F4} {metrics?.F1Score ?? double.NaN,9:F4} {bestMetric,8:F4} {runtimeInSeconds,9:F1}");
         }
 
-        internal static void PrintMulticlassClassificationMetrics(int iteration, string trainerName, MultiClassClassifierMetrics metrics)
+        internal static void PrintMetrics(int iteration, string trainerName, MultiClassClassifierMetrics metrics, double bestMetric, double runtimeInSeconds)
         {
-            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.AccuracyMicro ?? double.NaN,14:F4} {metrics?.AccuracyMacro ?? double.NaN,14:F4}");
+            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.AccuracyMicro ?? double.NaN,14:F4} {metrics?.AccuracyMacro ?? double.NaN,14:F4} {bestMetric,14:F4} {runtimeInSeconds,9:F1}");
         }
 
-        internal static void PrintRegressionMetrics(int iteration, string trainerName, RegressionMetrics metrics)
+        internal static void PrintMetrics(int iteration, string trainerName, RegressionMetrics metrics, double bestMetric, double runtimeInSeconds)
         {
-            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.RSquared ?? double.NaN,9:F4} {metrics?.LossFn ?? double.NaN,12:F2} {metrics?.L1 ?? double.NaN,15:F2} {metrics?.L2 ?? double.NaN,15:F2} {metrics?.Rms ?? double.NaN,12:F2}");
+            logger.Log(LogLevel.Info, $"{iteration,-4} {trainerName,-35} {metrics?.RSquared ?? double.NaN,9:F4} {metrics?.LossFn ?? double.NaN,12:F2} {metrics?.L1 ?? double.NaN,15:F2} {metrics?.L2 ?? double.NaN,15:F2} {metrics?.Rms ?? double.NaN,12:F2} {bestMetric,12:F4} {runtimeInSeconds,9:F1}");
         }
 
+
         internal static void PrintBinaryClassificationMetricsHeader()
         {
             logger.Log(LogLevel.Info, $"*************************************************");
             logger.Log(LogLevel.Info, $"*       {Strings.MetricsForBinaryClassModels}     ");
             logger.Log(LogLevel.Info, $"*------------------------------------------------");
-            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"Accuracy",9} {"AUC",8} {"AUPRC",8} {"F1-score",9}");
+            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"Accuracy",9} {"AUC",8} {"AUPRC",8} {"F1-score",9} {"Best",8} {"Duration",9}");
         }
 
         internal static void PrintMulticlassClassificationMetricsHeader()
         {
             logger.Log(LogLevel.Info, $"*************************************************");
             logger.Log(LogLevel.Info, $"*       {Strings.MetricsForMulticlassModels}     ");
             logger.Log(LogLevel.Info, $"*------------------------------------------------");
-            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"AccuracyMicro",14} {"AccuracyMacro",14}");
+            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"AccuracyMicro",14} {"AccuracyMacro",14} {"Best",14} {"Duration",9}");
         }
 
         internal static void PrintRegressionMetricsHeader()
         {
             logger.Log(LogLevel.Info, $"*************************************************");
             logger.Log(LogLevel.Info, $"*       {Strings.MetricsForRegressionModels}     ");
             logger.Log(LogLevel.Info, $"*------------------------------------------------");
-            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"R2-Score",9} {"LossFn",12} {"Absolute-loss",15} {"Squared-loss",15} {"RMS-loss",12}");
+            logger.Log(LogLevel.Info, $"{" ",-4} {"Trainer",-35} {"R2-Score",9} {"LossFn",12} {"Absolute-loss",15} {"Squared-loss",15} {"RMS-loss",12} {"Best",12} {"Duration",9}");
         }
 
         internal static void PrintBestPipelineHeader()

src/mlnet/Utilities/ProgressHandlers.cs

@@ -10,49 +10,94 @@ namespace Microsoft.ML.CLI.Utilities
 {
     internal class ProgressHandlers
     {
+        private static int MetricComparator(double a, double b, bool isMaximizing)
+        {
+            return (isMaximizing ? a.CompareTo(b) : -a.CompareTo(b));
+        }
+
         internal class RegressionHandler : IProgress<RunResult<RegressionMetrics>>
         {
-            int iterationIndex;
-            public RegressionHandler()
+            private readonly bool isMaximizing;
+            private readonly Func<RunResult<RegressionMetrics>, double> GetScore;
+            private RunResult<RegressionMetrics> bestResult;
+            private int iterationIndex;
+
+            public RegressionHandler(RegressionMetric optimizationMetric)
             {
+                isMaximizing = new OptimizingMetricInfo(optimizationMetric).IsMaximizing;
+                GetScore = (RunResult<RegressionMetrics> result) => new RegressionMetricsAgent(optimizationMetric).GetScore(result?.ValidationMetrics);
                 ConsolePrinter.PrintRegressionMetricsHeader();
             }
 
             public void Report(RunResult<RegressionMetrics> iterationResult)
             {
                 iterationIndex++;
-                ConsolePrinter.PrintRegressionMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics);
+                UpdateBestResult(iterationResult);
+                ConsolePrinter.PrintMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics, GetScore(bestResult), iterationResult.RuntimeInSeconds);
+            }
+
+            private void UpdateBestResult(RunResult<RegressionMetrics> iterationResult)
+            {
+                if (MetricComparator(GetScore(iterationResult), GetScore(bestResult), isMaximizing) > 0)
+                    bestResult = iterationResult;
             }
         }
 
         internal class BinaryClassificationHandler : IProgress<RunResult<BinaryClassificationMetrics>>
         {
-            int iterationIndex;
-            internal BinaryClassificationHandler()
+            private readonly bool isMaximizing;
+            private readonly Func<RunResult<BinaryClassificationMetrics>, double> GetScore;
+            private RunResult<BinaryClassificationMetrics> bestResult;
+            private int iterationIndex;
+
+            public BinaryClassificationHandler(BinaryClassificationMetric optimizationMetric)
             {
+                isMaximizing = new OptimizingMetricInfo(optimizationMetric).IsMaximizing;
+                GetScore = (RunResult<BinaryClassificationMetrics> result) => new BinaryMetricsAgent(optimizationMetric).GetScore(result?.ValidationMetrics);
                 ConsolePrinter.PrintBinaryClassificationMetricsHeader();
             }
 
             public void Report(RunResult<BinaryClassificationMetrics> iterationResult)
             {
                 iterationIndex++;
-                ConsolePrinter.PrintBinaryClassificationMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics);
+                UpdateBestResult(iterationResult);
+                ConsolePrinter.PrintMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics, GetScore(bestResult), iterationResult.RuntimeInSeconds);
+            }
+
+            private void UpdateBestResult(RunResult<BinaryClassificationMetrics> iterationResult)
+            {
+                if (MetricComparator(GetScore(iterationResult), GetScore(bestResult), isMaximizing) > 0)
+                    bestResult = iterationResult;
             }
         }
 
         internal class MulticlassClassificationHandler : IProgress<RunResult<MultiClassClassifierMetrics>>
         {
-            int iterationIndex;
-            internal MulticlassClassificationHandler()
+            private readonly bool isMaximizing;
+            private readonly Func<RunResult<MultiClassClassifierMetrics>, double> GetScore;
+            private RunResult<MultiClassClassifierMetrics> bestResult;
+            private int iterationIndex;
+
+            public MulticlassClassificationHandler(MulticlassClassificationMetric optimizationMetric)
             {
+                isMaximizing = new OptimizingMetricInfo(optimizationMetric).IsMaximizing;
+                GetScore = (RunResult<MultiClassClassifierMetrics> result) => new MultiMetricsAgent(optimizationMetric).GetScore(result?.ValidationMetrics);
                 ConsolePrinter.PrintMulticlassClassificationMetricsHeader();
             }
 
             public void Report(RunResult<MultiClassClassifierMetrics> iterationResult)
             {
                 iterationIndex++;
-                ConsolePrinter.PrintMulticlassClassificationMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics);
+                UpdateBestResult(iterationResult);
+                ConsolePrinter.PrintMetrics(iterationIndex, iterationResult.TrainerName, iterationResult.ValidationMetrics, GetScore(bestResult), iterationResult.RuntimeInSeconds);
+            }
+
+            private void UpdateBestResult(RunResult<MultiClassClassifierMetrics> iterationResult)
+            {
+                if (MetricComparator(GetScore(iterationResult), GetScore(bestResult), isMaximizing) > 0)
+                    bestResult = iterationResult;
             }
         }
+
     }
 }