From 914664bf27b7bd339d09e3243fdbe4e5d54ef785 Mon Sep 17 00:00:00 2001
From: Robert Schumacher <roschuma@microsoft.com>
Date: Sat, 4 Mar 2017 06:48:59 -0800
Subject: [PATCH] [vcpkg-ci] Display per-package timing information.

---
 toolsrc/include/vcpkg_Strings.h |  5 +++++
 toolsrc/src/commands_ci.cpp     | 24 ++++++++++++++++--------
 2 files changed, 21 insertions(+), 8 deletions(-)

diff --git a/toolsrc/include/vcpkg_Strings.h b/toolsrc/include/vcpkg_Strings.h
index 8d5d7135b..5b536e5e1 100644
--- a/toolsrc/include/vcpkg_Strings.h
+++ b/toolsrc/include/vcpkg_Strings.h
@@ -19,6 +19,11 @@ namespace vcpkg::Strings::details
         return s;
     }
 
+    inline long long to_printf_arg(const long long s)
+    {
+        return s;
+    }
+
     inline double to_printf_arg(const double s)
     {
         return s;
diff --git a/toolsrc/src/commands_ci.cpp b/toolsrc/src/commands_ci.cpp
index 2b7ba89d6..ac5aaecc2 100644
--- a/toolsrc/src/commands_ci.cpp
+++ b/toolsrc/src/commands_ci.cpp
@@ -43,24 +43,31 @@ namespace vcpkg::Commands::CI
         Environment::ensure_utilities_on_path(paths);
 
         std::vector<BuildResult> results;
+        std::vector<std::chrono::milliseconds::rep> timing;
         const ElapsedTime timer = ElapsedTime::createStarted();
         size_t counter = 0;
         const size_t package_count = install_plan.size();
         for (const package_spec_with_install_plan& action : install_plan)
         {
+            const ElapsedTime build_timer = ElapsedTime::createStarted();
             counter++;
-            System::println("Starting package %d/%d: %s. Time Elapsed: %s", counter, package_count, action.spec.toString(), timer.toString());
+            System::println("Starting package %d/%d: %s", counter, package_count, action.spec.toString());
+
+            timing.push_back(-1);
+            results.push_back(BuildResult::NULLVALUE);
+
             try
             {
                 if (action.plan.plan_type == install_plan_type::ALREADY_INSTALLED)
                 {
-                    results.push_back(BuildResult::SUCCEEDED);
+                    results.back() = BuildResult::SUCCEEDED;
                     System::println(System::color::success, "Package %s is already installed", action.spec);
                 }
                 else if (action.plan.plan_type == install_plan_type::BUILD_AND_INSTALL)
                 {
                     const BuildResult result = Commands::Build::build_package(*action.plan.source_pgh, action.spec, paths, paths.port_dir(action.spec), status_db);
-                    results.push_back(result);
+                    timing.back() = build_timer.elapsed<std::chrono::milliseconds>().count();
+                    results.back() = result;
                     if (result != BuildResult::SUCCEEDED)
                     {
                         System::println(System::color::error, Build::create_error_message(result, action.spec));
@@ -72,9 +79,9 @@ namespace vcpkg::Commands::CI
                 }
                 else if (action.plan.plan_type == install_plan_type::INSTALL)
                 {
-                    results.push_back(BuildResult::SUCCEEDED);
+                    results.back() = BuildResult::SUCCEEDED;
                     Install::install_package(paths, *action.plan.binary_pgh, &status_db);
-                    System::println(System::color::success, "Package %s is installed", action.spec);
+                    System::println(System::color::success, "Package %s is installed from cache", action.spec);
                 }
                 else
                     Checks::unreachable();
@@ -82,11 +89,12 @@ namespace vcpkg::Commands::CI
             catch (const std::exception& e)
             {
                 System::println(System::color::error, "Error: Could not install package %s: %s", action.spec, e.what());
-                exit(EXIT_FAILURE);
+                results.back() = BuildResult::NULLVALUE;
             }
+            System::println("Elapsed time for package %s: %s", action.spec, build_timer.toString());
         }
 
-        System::println(timer.toString());
+        System::println("Total time taken: %s", timer.toString());
 
         for (size_t i = 0; i < results.size(); i++)
         {
@@ -95,7 +103,7 @@ namespace vcpkg::Commands::CI
                 continue;
             }
 
-            System::println("%s: %s", install_plan[i].spec.toString(), Build::to_string(results[i]));
+            System::println("%s: %s: %dms", install_plan[i].spec.toString(), Build::to_string(results[i]), timing[i]);
         }
 
         std::map<BuildResult, int> summary;