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, 12 insertions, 0 deletions

diff --git a/source/blender/io/alembic/exporter/abc_export_capi.cc b/source/blender/io/alembic/exporter/abc_export_capi.cc
index 5554fb505a4..dfca89e2c6d 100644
--- a/source/blender/io/alembic/exporter/abc_export_capi.cc
+++ b/source/blender/io/alembic/exporter/abc_export_capi.cc
@@ -24,6 +24,7 @@
 #include "BLI_fileops.h"
 #include "BLI_path_util.h"
 #include "BLI_string.h"
+#include "BLI_timeit.hh"
 
 #include "WM_api.h"
 #include "WM_types.h"
@@ -44,6 +45,7 @@ struct ExportJobData {
 
   bool was_canceled;
   bool export_ok;
+  blender::timeit::TimePoint start_time;
 };
 
 namespace blender::io::alembic {
@@ -59,6 +61,14 @@ static void build_depsgraph(Depsgraph *depsgraph, const bool visible_objects_onl
   }
 }
 
+static void report_job_duration(const ExportJobData *data)
+{
+  blender::timeit::Nanoseconds duration = blender::timeit::Clock::now() - data->start_time;
+  std::cout << "Alembic export of '" << data->filename << "' took ";
+  blender::timeit::print_duration(duration);
+  std::cout << '\n';
+}
+
 static void export_startjob(void *customdata,
                             /* Cannot be const, this function implements wm_jobs_start_callback.
                              * NOLINTNEXTLINE: readability-non-const-parameter. */
@@ -68,6 +78,7 @@ static void export_startjob(void *customdata,
 {
   ExportJobData *data = static_cast<ExportJobData *>(customdata);
   data->was_canceled = false;
+  data->start_time = blender::timeit::Clock::now();
 
   G.is_rendering = true;
   WM_set_locked_interface(data->wm, true);
@@ -177,6 +188,7 @@ static void export_endjob(void *customdata)
 
   G.is_rendering = false;
   WM_set_locked_interface(data->wm, false);
+  report_job_duration(data);
 }
 
 }  // namespace blender::io::alembic