IO: print import & export times of Alembic & USD

Many existing importers/exporters do log the time it takes to system
console (some others log more information too). In particular, OBJ
(C++ & python), STL (C++ & python), PLY, glTF2 all log the time it
takes. However, neither USD nor Alembic do. And also it's harder to
know the time it takes there from a profiler, since all the work
normally is done on a background job and is split between several
threads (so you can't just find some top-level function and see how
much time it took).

This change:

- Adds import/export time logging to USD & Alembic importer/exporter,
- In the time utility class (also used by OBJ & STL), improve the
  output formatting: 1) print only one decimal digit, 2) for long
  times, print seconds and also produce a hours:minutes:seconds form.

Reviewed By: Michael Kowalski, Kévin Dietrich
Differential Revision: https://developer.blender.org/D15170

1 files changed, 14 insertions, 4 deletions

diff --git a/source/blender/blenlib/intern/timeit.cc b/source/blender/blenlib/intern/timeit.cc
index f11f9c4ad94..7a8cf8da038 100644
--- a/source/blender/blenlib/intern/timeit.cc
+++ b/source/blender/blenlib/intern/timeit.cc
@@ -3,19 +3,29 @@
 #include "BLI_timeit.hh"
 
 #include <algorithm>
+#include <iomanip>
 
 namespace blender::timeit {
 
 void print_duration(Nanoseconds duration)
 {
-  if (duration < std::chrono::microseconds(100)) {
+  using namespace std::chrono;
+  if (duration < microseconds(100)) {
     std::cout << duration.count() << " ns";
   }
-  else if (duration < std::chrono::seconds(5)) {
-    std::cout << duration.count() / 1.0e6 << " ms";
+  else if (duration < seconds(5)) {
+    std::cout << std::fixed << std::setprecision(1) << duration.count() / 1.0e6 << " ms";
+  }
+  else if (duration > seconds(90)) {
+    /* Long durations: print seconds, and also H:m:s */
+    const auto dur_hours = duration_cast<hours>(duration);
+    const auto dur_mins = duration_cast<minutes>(duration - dur_hours);
+    const auto dur_sec = duration_cast<seconds>(duration - dur_hours - dur_mins);
+    std::cout << std::fixed << std::setprecision(1) << duration.count() / 1.0e9 << " s ("
+              << dur_hours.count() << "H:" << dur_mins.count() << "m:" << dur_sec.count() << "s)";
   }
   else {
-    std::cout << duration.count() / 1.0e9 << " s";
+    std::cout << std::fixed << std::setprecision(1) << duration.count() / 1.0e9 << " s";
   }
 }