More debug timing info from main RNA diffing func.
[blender.git] / source / blender / makesrna / intern / rna_access.c
index 42eb7b81c3729ad2d117f8a4eaf83ee789b42d9f..59d0095e3fb4eb10da399d8487f21676817575c3 100644 (file)
@@ -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