diff options
author | Aras Pranckevicius <aras@nesnausk.org> | 2022-07-01 12:17:50 +0300 |
---|---|---|
committer | Aras Pranckevicius <aras@nesnausk.org> | 2022-07-01 12:17:50 +0300 |
commit | e7a21275c0f1bfb0e8bbeda384e5b46131e48b93 (patch) | |
tree | 91d9cd8f1dba9a35b0a51a51f344975f9e99ee3d /source/blender/io | |
parent | 4527dd1ce4784292cd3b8dd3764b9cd843020f9a (diff) |
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
Diffstat (limited to 'source/blender/io')
-rw-r--r-- | source/blender/io/alembic/exporter/abc_export_capi.cc | 12 | ||||
-rw-r--r-- | source/blender/io/alembic/intern/alembic_capi.cc | 12 | ||||
-rw-r--r-- | source/blender/io/usd/intern/usd_capi_export.cc | 12 | ||||
-rw-r--r-- | source/blender/io/usd/intern/usd_capi_import.cc | 12 |
4 files changed, 48 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 diff --git a/source/blender/io/alembic/intern/alembic_capi.cc b/source/blender/io/alembic/intern/alembic_capi.cc index cd6750341a8..27df23b38c6 100644 --- a/source/blender/io/alembic/intern/alembic_capi.cc +++ b/source/blender/io/alembic/intern/alembic_capi.cc @@ -50,6 +50,7 @@ #include "BLI_math.h" #include "BLI_path_util.h" #include "BLI_string.h" +#include "BLI_timeit.hh" #include "WM_api.h" #include "WM_types.h" @@ -434,8 +435,17 @@ struct ImportJobData { bool was_cancelled; bool import_ok; bool is_background_job; + blender::timeit::TimePoint start_time; }; +static void report_job_duration(const ImportJobData *data) +{ + blender::timeit::Nanoseconds duration = blender::timeit::Clock::now() - data->start_time; + std::cout << "Alembic import of '" << data->filename << "' took "; + blender::timeit::print_duration(duration); + std::cout << '\n'; +} + static void import_startjob(void *user_data, short *stop, short *do_update, float *progress) { SCOPE_TIMER("Alembic import, objects reading and creation"); @@ -445,6 +455,7 @@ static void import_startjob(void *user_data, short *stop, short *do_update, floa data->stop = stop; data->do_update = do_update; data->progress = progress; + data->start_time = blender::timeit::Clock::now(); WM_set_locked_interface(data->wm, true); @@ -649,6 +660,7 @@ static void import_endjob(void *user_data) } WM_main_add_notifier(NC_SCENE | ND_FRAME, data->scene); + report_job_duration(data); } static void import_freejob(void *user_data) diff --git a/source/blender/io/usd/intern/usd_capi_export.cc b/source/blender/io/usd/intern/usd_capi_export.cc index d9995117b70..1033f85181c 100644 --- a/source/blender/io/usd/intern/usd_capi_export.cc +++ b/source/blender/io/usd/intern/usd_capi_export.cc @@ -27,6 +27,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" @@ -42,8 +43,17 @@ struct ExportJobData { USDExportParams params; bool export_ok; + timeit::TimePoint start_time; }; +static void report_job_duration(const ExportJobData *data) +{ + timeit::Nanoseconds duration = timeit::Clock::now() - data->start_time; + std::cout << "USD export of '" << data->filepath << "' took "; + 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. */ @@ -53,6 +63,7 @@ static void export_startjob(void *customdata, { ExportJobData *data = static_cast<ExportJobData *>(customdata); data->export_ok = false; + data->start_time = timeit::Clock::now(); G.is_rendering = true; WM_set_locked_interface(data->wm, true); @@ -151,6 +162,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::usd diff --git a/source/blender/io/usd/intern/usd_capi_import.cc b/source/blender/io/usd/intern/usd_capi_import.cc index 4118205d87f..13ae6f4d4c0 100644 --- a/source/blender/io/usd/intern/usd_capi_import.cc +++ b/source/blender/io/usd/intern/usd_capi_import.cc @@ -30,6 +30,7 @@ #include "BLI_math_rotation.h" #include "BLI_path_util.h" #include "BLI_string.h" +#include "BLI_timeit.hh" #include "DEG_depsgraph.h" #include "DEG_depsgraph_build.h" @@ -132,8 +133,17 @@ struct ImportJobData { char error_code; bool was_canceled; bool import_ok; + timeit::TimePoint start_time; }; +static void report_job_duration(const ImportJobData *data) +{ + timeit::Nanoseconds duration = timeit::Clock::now() - data->start_time; + std::cout << "USD import of '" << data->filepath << "' took "; + timeit::print_duration(duration); + std::cout << '\n'; +} + static void import_startjob(void *customdata, short *stop, short *do_update, float *progress) { ImportJobData *data = static_cast<ImportJobData *>(customdata); @@ -143,6 +153,7 @@ static void import_startjob(void *customdata, short *stop, short *do_update, flo data->progress = progress; data->was_canceled = false; data->archive = nullptr; + data->start_time = timeit::Clock::now(); WM_set_locked_interface(data->wm, true); G.is_break = false; @@ -337,6 +348,7 @@ static void import_endjob(void *customdata) } WM_main_add_notifier(NC_SCENE | ND_FRAME, data->scene); + report_job_duration(data); } static void import_freejob(void *user_data) |