From 57221d8e836eb6a5fcd80844625f375fbc6a6b24 Mon Sep 17 00:00:00 2001 From: Bastien Montagne Date: Fri, 20 Apr 2018 16:04:27 +0200 Subject: More debug timing info from main RNA diffing func. --- source/blender/makesrna/intern/rna_access.c | 46 ++++++++++++++++++++++++----- 1 file changed, 38 insertions(+), 8 deletions(-) (limited to 'source') diff --git a/source/blender/makesrna/intern/rna_access.c b/source/blender/makesrna/intern/rna_access.c index 42eb7b81c37..59d0095e3fb 100644 --- a/source/blender/makesrna/intern/rna_access.c +++ b/source/blender/makesrna/intern/rna_access.c @@ -7470,12 +7470,21 @@ bool RNA_struct_override_matches( const bool do_create = (flags & RNA_OVERRIDE_COMPARE_CREATE) != 0; const bool do_restore = (flags & RNA_OVERRIDE_COMPARE_RESTORE) != 0; +//#define DEBUG_OVERRIDE_TIMEIT #ifdef DEBUG_OVERRIDE_TIMEIT - static float _sum_time = 0.0f; - static float _num_time = 0.0f; - double _timeit_time; + static float _sum_time_global = 0.0f; + static float _num_time_global = 0.0f; + double _timeit_time_global; + static float _sum_time_diffing = 0.0f; + static float _delta_time_diffing = 0.0f; + static int _num_delta_time_diffing = 0.0f; + static float _num_time_diffing = 0.0f; + double _timeit_time_diffing; + if (!root_path) { - _timeit_time = PIL_check_seconds_timer(); + _delta_time_diffing = 0.0f; + _num_delta_time_diffing = 0; + _timeit_time_global = PIL_check_seconds_timer(); } #endif @@ -7525,6 +7534,7 @@ bool RNA_struct_override_matches( } } else { + /* This is rather slow, but is not much called, so not really worth optimizing. */ rna_path = RNA_path_from_ID_to_property(ptr_local, prop_local); } if (rna_path == NULL) { @@ -7538,11 +7548,25 @@ bool RNA_struct_override_matches( continue; } +#ifdef DEBUG_OVERRIDE_TIMEIT + if (!root_path) { + _timeit_time_diffing = PIL_check_seconds_timer(); + } +#endif + eRNAOverrideMatchResult report_flags = 0; const int diff = rna_property_override_diff( ptr_local, ptr_reference, NULL, prop_local, prop_reference, rna_path, RNA_EQ_STRICT, override, flags, &report_flags); +#ifdef DEBUG_OVERRIDE_TIMEIT + if (!root_path) { + const float _delta_time = (float)(PIL_check_seconds_timer() - _timeit_time_diffing); + _delta_time_diffing += _delta_time; + _num_delta_time_diffing++; + } +#endif + matching = matching && diff == 0; if (r_report_flags) { *r_report_flags |= report_flags; @@ -7597,12 +7621,18 @@ bool RNA_struct_override_matches( #ifdef DEBUG_OVERRIDE_TIMEIT if (!root_path) { - const float _delta_time = (float)(PIL_check_seconds_timer() - _timeit_time); - _sum_time += _delta_time; - _num_time++; + const float _delta_time = (float)(PIL_check_seconds_timer() - _timeit_time_global); + _sum_time_global += _delta_time; + _num_time_global++; + _sum_time_diffing += _delta_time_diffing; + _num_time_diffing++; printf("ID: %s\n", ((ID *)ptr_local->id.data)->name); printf("time end (%s): %.6f\n", __func__, _delta_time); - printf("time averaged (%s): %.6f (total: %.6f, in %d runs)\n", __func__, (_sum_time / _num_time), _sum_time, (int)_num_time); + printf("time averaged (%s): %.6f (total: %.6f, in %d runs)\n", __func__, + (_sum_time_global / _num_time_global), _sum_time_global, (int)_num_time_global); + printf("diffing time end (%s): %.6f (in %d runs)\n", __func__, _delta_time_diffing, _num_delta_time_diffing); + printf("diffing time averaged (%s): %.6f (total: %.6f, in %d runs)\n", __func__, + (_sum_time_diffing / _num_time_diffing), _sum_time_diffing, (int)_num_time_diffing); } #endif -- cgit v1.2.3