Depsgraph: Move evaluation debug prints to depsgraph
authorSergey Sharybin <sergey.vfx@gmail.com>
Fri, 16 Mar 2018 10:14:38 +0000 (11:14 +0100)
committerSergey Sharybin <sergey.vfx@gmail.com>
Fri, 16 Mar 2018 10:14:38 +0000 (11:14 +0100)
This way we can easily control format and keep it consistent.

And also possibly do other trickery, like coloring addresses!

source/blender/blenkernel/intern/anim_sys.c
source/blender/blenkernel/intern/armature_update.c
source/blender/blenkernel/intern/curve.c
source/blender/blenkernel/intern/mask_evaluate.c
source/blender/blenkernel/intern/mesh.c
source/blender/blenkernel/intern/movieclip.c
source/blender/blenkernel/intern/object_update.c
source/blender/blenkernel/intern/particle_system.c
source/blender/blenkernel/intern/rigidbody.c
source/blender/depsgraph/DEG_depsgraph.h
source/blender/depsgraph/intern/depsgraph.cc

index 095ef6f..e2c3713 100644 (file)
@@ -76,6 +76,8 @@
 
 #include "atomic_ops.h"
 
+#include "DEG_depsgraph.h"
+
 /* ***************************************** */
 /* AnimData API */
 
@@ -2918,15 +2920,13 @@ void BKE_animsys_evaluate_all_animation(Main *main, Scene *scene, float ctime)
 /* ************** */
 /* Evaluation API */
 
-#define DEBUG_PRINT if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-
 void BKE_animsys_eval_animdata(EvaluationContext *eval_ctx, ID *id)
 {
        AnimData *adt = BKE_animdata_from_id(id);
        Scene *scene = NULL; /* XXX: this is only needed for flushing RNA updates,
                              * which should get handled as part of the dependency graph instead...
                              */
-       DEBUG_PRINT("%s on %s, time=%f\n\n", __func__, id->name, (double)eval_ctx->ctime);
+       DEG_debug_print_eval_time(__func__, id->name, id, eval_ctx->ctime);
        BKE_animsys_evaluate_animdata(scene, id, adt, eval_ctx->ctime, ADT_RECALC_ANIM);
 }
 
@@ -2939,11 +2939,8 @@ void BKE_animsys_eval_driver(EvaluationContext *eval_ctx,
        PointerRNA id_ptr;
        bool ok = false;
 
-       DEBUG_PRINT("%s on %s (%s[%d])\n",
-                   __func__,
-                   id->name,
-                   fcu->rna_path,
-                   fcu->array_index);
+       DEG_debug_print_eval_subdata_index(
+               __func__, id->name, id, "fcu", fcu->rna_path, fcu, fcu->array_index);
 
        RNA_id_pointer_create(id, &id_ptr);
 
@@ -2976,5 +2973,3 @@ void BKE_animsys_eval_driver(EvaluationContext *eval_ctx,
                }
        }
 }
-
-#undef DEBUG_PRINT
index 2e9b2f7..e6bb0d6 100644 (file)
 
 #include "DEG_depsgraph.h"
 
-#ifdef WITH_LEGACY_DEPSGRAPH
-#  define DEBUG_PRINT if (!DEG_depsgraph_use_legacy() && G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-#else
-#  define DEBUG_PRINT if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-#endif
-
 /* ********************** SPLINE IK SOLVER ******************* */
 
 /* Temporary evaluation tree data used for Spline IK */
@@ -565,7 +559,7 @@ void BKE_pose_eval_init(EvaluationContext *UNUSED(eval_ctx),
 {
        bPoseChannel *pchan;
 
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
 
        BLI_assert(ob->type == OB_ARMATURE);
 
@@ -587,7 +581,7 @@ void BKE_pose_eval_init_ik(EvaluationContext *UNUSED(eval_ctx),
                            Object *ob,
                            bPose *UNUSED(pose))
 {
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
        BLI_assert(ob->type == OB_ARMATURE);
        const float ctime = BKE_scene_frame_get(scene); /* not accurate... */
        bArmature *arm = (bArmature *)ob->data;
@@ -608,7 +602,8 @@ void BKE_pose_eval_bone(EvaluationContext *UNUSED(eval_ctx),
                         Object *ob,
                         bPoseChannel *pchan)
 {
-       DEBUG_PRINT("%s on %s pchan %s\n", __func__, ob->id.name, pchan->name);
+       DEG_debug_print_eval_subdata(
+               __func__, ob->id.name, ob, "pchan", pchan->name, pchan);
        BLI_assert(ob->type == OB_ARMATURE);
        bArmature *arm = (bArmature *)ob->data;
        if (arm->edbo || (arm->flag & ARM_RESTPOS)) {
@@ -643,7 +638,8 @@ void BKE_pose_constraints_evaluate(EvaluationContext *UNUSED(eval_ctx),
                                    Object *ob,
                                    bPoseChannel *pchan)
 {
-       DEBUG_PRINT("%s on %s pchan %s\n", __func__, ob->id.name, pchan->name);
+       DEG_debug_print_eval_subdata(
+               __func__, ob->id.name, ob, "pchan", pchan->name, pchan);
        bArmature *arm = (bArmature *)ob->data;
        if (arm->flag & ARM_RESTPOS) {
                return;
@@ -663,7 +659,7 @@ void BKE_pose_bone_done(EvaluationContext *UNUSED(eval_ctx),
                         bPoseChannel *pchan)
 {
        float imat[4][4];
-       DEBUG_PRINT("%s on pchan %s\n", __func__, pchan->name);
+       DEG_debug_print_eval(__func__, pchan->name, pchan);
        if (pchan->bone) {
                invert_m4_m4(imat, pchan->bone->arm_mat);
                mul_m4_m4m4(pchan->chan_mat, pchan->pose_mat, imat);
@@ -675,7 +671,8 @@ void BKE_pose_iktree_evaluate(EvaluationContext *UNUSED(eval_ctx),
                               Object *ob,
                               bPoseChannel *rootchan)
 {
-       DEBUG_PRINT("%s on %s pchan %s\n", __func__, ob->id.name, rootchan->name);
+       DEG_debug_print_eval_subdata(
+               __func__, ob->id.name, ob, "rootchan", rootchan->name, rootchan);
        BLI_assert(ob->type == OB_ARMATURE);
        const float ctime = BKE_scene_frame_get(scene); /* not accurate... */
        bArmature *arm = (bArmature *)ob->data;
@@ -689,8 +686,10 @@ void BKE_pose_splineik_evaluate(EvaluationContext *UNUSED(eval_ctx),
                                 Scene *scene,
                                 Object *ob,
                                 bPoseChannel *rootchan)
+
 {
-       DEBUG_PRINT("%s on %s pchan %s\n", __func__, ob->id.name, rootchan->name);
+       DEG_debug_print_eval_subdata(
+               __func__, ob->id.name, ob, "rootchan", rootchan->name, rootchan);
        BLI_assert(ob->type == OB_ARMATURE);
        const float ctime = BKE_scene_frame_get(scene); /* not accurate... */
        bArmature *arm = (bArmature *)ob->data;
@@ -706,7 +705,7 @@ void BKE_pose_eval_flush(EvaluationContext *UNUSED(eval_ctx),
                          bPose *UNUSED(pose))
 {
        float ctime = BKE_scene_frame_get(scene); /* not accurate... */
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
        BLI_assert(ob->type == OB_ARMATURE);
 
        /* 6. release the IK tree */
@@ -718,7 +717,7 @@ void BKE_pose_eval_flush(EvaluationContext *UNUSED(eval_ctx),
 void BKE_pose_eval_proxy_copy(EvaluationContext *UNUSED(eval_ctx), Object *ob)
 {
        BLI_assert(ID_IS_LINKED(ob) && ob->proxy_from != NULL);
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
        if (BKE_pose_copy_result(ob->pose, ob->proxy_from->pose) == false) {
                printf("Proxy copy error, lib Object: %s proxy Object: %s\n",
                       ob->id.name + 2, ob->proxy_from->id.name + 2);
index f075974..943cab0 100644 (file)
@@ -65,6 +65,8 @@
 #include "BKE_object.h"
 #include "BKE_material.h"
 
+#include "DEG_depsgraph.h"
+
 /* globals */
 
 /* local */
@@ -5253,9 +5255,7 @@ void BKE_curve_rect_from_textbox(const struct Curve *cu, const struct TextBox *t
 void BKE_curve_eval_geometry(EvaluationContext *UNUSED(eval_ctx),
                              Curve *curve)
 {
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s on %s\n", __func__, curve->id.name);
-       }
+       DEG_debug_print_eval(__func__, curve->id.name, curve);
        if (curve->bb == NULL || (curve->bb->flag & BOUNDBOX_DIRTY)) {
                BKE_curve_texspace_calc(curve);
        }
index 9875b74..889f65d 100644 (file)
@@ -46,6 +46,7 @@
 #include "BKE_global.h"
 #include "BKE_mask.h"
 
+#include "DEG_depsgraph.h"
 
 unsigned int BKE_mask_spline_resolution(MaskSpline *spline, int width, int height)
 {
@@ -897,11 +898,9 @@ void BKE_mask_layer_evaluate_deform(MaskLayer *masklay, const float ctime)
        }
 }
 
-#define DEBUG_PRINT if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-
 void BKE_mask_eval_animation(struct EvaluationContext *eval_ctx, Mask *mask)
 {
-       DEBUG_PRINT("%s on %s (%p)\n", __func__, mask->id.name, mask);
+       DEG_debug_print_eval(__func__, mask->id.name, mask);
        for (MaskLayer *mask_layer = mask->masklayers.first;
             mask_layer != NULL;
             mask_layer = mask_layer->next)
@@ -912,7 +911,7 @@ void BKE_mask_eval_animation(struct EvaluationContext *eval_ctx, Mask *mask)
 
 void BKE_mask_eval_update(struct EvaluationContext *eval_ctx, Mask *mask)
 {
-       DEBUG_PRINT("%s on %s (%p)\n", __func__, mask->id.name, mask);
+       DEG_debug_print_eval(__func__, mask->id.name, mask);
        for (MaskLayer *mask_layer = mask->masklayers.first;
             mask_layer != NULL;
             mask_layer = mask_layer->next)
index 34cc480..c8b4451 100644 (file)
@@ -2636,9 +2636,7 @@ Mesh *BKE_mesh_new_from_object(
 void BKE_mesh_eval_geometry(EvaluationContext *UNUSED(eval_ctx),
                             Mesh *mesh)
 {
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s on %s\n", __func__, mesh->id.name);
-       }
+       DEG_debug_print_eval(__func__, mesh->id.name, mesh);
        if (mesh->bb == NULL || (mesh->bb->flag & BOUNDBOX_DIRTY)) {
                BKE_mesh_texspace_calc(mesh);
        }
index 6073075..9ed715d 100644 (file)
 #include "IMB_imbuf.h"
 #include "IMB_moviecache.h"
 
+#include "DEG_depsgraph.h"
+
 #ifdef WITH_OPENEXR
 #  include "intern/openexr/openexr_multi.h"
 #endif
 
-#define DEBUG_PRINT if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-
 /*********************** movieclip buffer loaders *************************/
 
 static int sequence_guess_offset(const char *full_name, int head_len, unsigned short numlen)
@@ -1611,6 +1611,6 @@ bool BKE_movieclip_put_frame_if_possible(MovieClip *clip,
 
 void BKE_movieclip_eval_update(struct EvaluationContext *UNUSED(eval_ctx), MovieClip *clip)
 {
-       DEBUG_PRINT("%s on %s (%p)\n", __func__, clip->id.name, clip);
+       DEG_debug_print_eval(__func__, clip->id.name, clip);
        BKE_tracking_dopesheet_tag_update(&clip->tracking);
 }
index 85cf7d8..e2e28d4 100644 (file)
 
 #include "DEG_depsgraph.h"
 
-#ifdef WITH_LEGACY_DEPSGRAPH
-#  define DEBUG_PRINT if (!DEG_depsgraph_use_legacy() && G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-#else
-#  define DEBUG_PRINT if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) printf
-#endif
-
 static ThreadMutex material_lock = BLI_MUTEX_INITIALIZER;
 
 void BKE_object_eval_local_transform(EvaluationContext *UNUSED(eval_ctx),
                                      Object *ob)
 {
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
 
        /* calculate local matrix */
        BKE_object_to_mat4(ob, ob->obmat);
@@ -90,7 +84,7 @@ void BKE_object_eval_parent(EvaluationContext *UNUSED(eval_ctx),
        float tmat[4][4];
        float locmat[4][4];
 
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
 
        /* get local matrix (but don't calculate it, as that was done already!) */
        // XXX: redundant?
@@ -119,7 +113,7 @@ void BKE_object_eval_constraints(EvaluationContext *UNUSED(eval_ctx),
        bConstraintOb *cob;
        float ctime = BKE_scene_frame_get(scene);
 
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
 
        /* evaluate constraints stack */
        /* TODO: split this into:
@@ -137,7 +131,7 @@ void BKE_object_eval_constraints(EvaluationContext *UNUSED(eval_ctx),
 
 void BKE_object_eval_done(EvaluationContext *UNUSED(eval_ctx), Object *ob)
 {
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
 
        /* Set negative scale flag in object. */
        if (is_negative_m4(ob->obmat)) ob->transflag |= OB_NEG_SCALE;
@@ -332,7 +326,7 @@ void BKE_object_eval_uber_data(EvaluationContext *eval_ctx,
                                Scene *scene,
                                Object *ob)
 {
-       DEBUG_PRINT("%s on %s\n", __func__, ob->id.name);
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
        BLI_assert(ob->type != OB_ARMATURE);
        BKE_object_handle_data_update(eval_ctx, scene, ob);
 
@@ -343,7 +337,7 @@ void BKE_object_eval_cloth(EvaluationContext *UNUSED(eval_ctx),
                            Scene *scene,
                            Object *object)
 {
-       DEBUG_PRINT("%s on %s\n", __func__, object->id.name);
+       DEG_debug_print_eval(__func__, object->id.name, object);
        BKE_ptcache_object_reset(scene, object, PTCACHE_RESET_DEPSGRAPH);
 }
 
index 2a1e0f5..1a18528 100644 (file)
@@ -93,6 +93,7 @@
 #include "PIL_time.h"
 
 #include "RE_shader_ext.h"
+#include "DEG_depsgraph.h"
 
 /* fluid sim particle import */
 #ifdef WITH_MOD_FLUID
@@ -4405,8 +4406,6 @@ void BKE_particle_system_eval_init(EvaluationContext *UNUSED(eval_ctx),
                                    Scene *scene,
                                    Object *ob)
 {
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s on %s\n", __func__, ob->id.name);
-       }
+       DEG_debug_print_eval(__func__, ob->id.name, ob);
        BKE_ptcache_object_reset(scene, ob, PTCACHE_RESET_DEPSGRAPH);
 }
index 56e65b6..c10f54a 100644 (file)
@@ -66,6 +66,8 @@
 #include "BKE_rigidbody.h"
 #include "BKE_scene.h"
 
+#include "DEG_depsgraph.h"
+
 /* ************************************** */
 /* Memory Management */
 
@@ -1689,11 +1691,7 @@ void BKE_rigidbody_rebuild_sim(EvaluationContext *UNUSED(eval_ctx),
                                Scene *scene)
 {
        float ctime = BKE_scene_frame_get(scene);
-
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s at %f\n", __func__, ctime);
-       }
-
+       DEG_debug_print_eval_time(__func__, scene->id.name, scene, ctime);
        /* rebuild sim data (i.e. after resetting to start of timeline) */
        if (BKE_scene_check_rigidbody_active(scene)) {
                BKE_rigidbody_rebuild_world(scene, ctime);
@@ -1704,11 +1702,7 @@ void BKE_rigidbody_eval_simulation(EvaluationContext *UNUSED(eval_ctx),
                                    Scene *scene)
 {
        float ctime = BKE_scene_frame_get(scene);
-
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s at %f\n", __func__, ctime);
-       }
-
+       DEG_debug_print_eval_time(__func__, scene->id.name, scene, ctime);
        /* evaluate rigidbody sim */
        if (BKE_scene_check_rigidbody_active(scene)) {
                BKE_rigidbody_do_simulation(scene, ctime);
@@ -1721,11 +1715,7 @@ void BKE_rigidbody_object_sync_transforms(EvaluationContext *UNUSED(eval_ctx),
 {
        RigidBodyWorld *rbw = scene->rigidbody_world;
        float ctime = BKE_scene_frame_get(scene);
-
-       if (G.debug & G_DEBUG_DEPSGRAPH_EVAL) {
-               printf("%s on %s\n", __func__, ob->id.name);
-       }
-
+       DEG_debug_print_eval_time(__func__, ob->id.name, ob, ctime);
        /* read values pushed into RBO from sim/cache... */
        BKE_rigidbody_sync_transforms(rbw, ob, ctime);
 }
index 0837f14..72e90f4 100644 (file)
@@ -208,6 +208,32 @@ void DEG_editors_set_update_cb(DEG_EditorUpdateIDCb id_func,
 
 void DEG_editors_update_pre(struct Main *bmain, struct Scene *scene, bool time);
 
+/* Evaluation Debug ------------------------------ */
+
+void DEG_debug_print_eval(const char* function_name,
+                          const char* object_name,
+                          const void* object_address);
+
+void DEG_debug_print_eval_subdata(const char *function_name,
+                                  const char *object_name,
+                                  const void *object_address,
+                                  const char *subdata_comment,
+                                  const char *subdata_name,
+                                  const void *subdata_address);
+
+void DEG_debug_print_eval_subdata_index(const char *function_name,
+                                        const char *object_name,
+                                        const void *object_address,
+                                        const char *subdata_comment,
+                                        const char *subdata_name,
+                                        const void *subdata_address,
+                                        const int subdata_index);
+
+void DEG_debug_print_eval_time(const char* function_name,
+                               const char* object_name,
+                               const void* object_address,
+                               float time);
+
 #ifdef __cplusplus
 } /* extern "C" */
 #endif
index 2e87786..f8e12ef 100644 (file)
@@ -494,3 +494,60 @@ void DEG_editors_update_pre(Main *bmain, Scene *scene, bool time)
                DEG::deg_editor_update_scene_pre_cb(bmain, scene, time);
        }
 }
+
+void DEG_debug_print_eval(const char *function_name,
+                          const char *object_name,
+                          const void *object_address)
+{
+       if ((G.debug & G_DEBUG_DEPSGRAPH_EVAL) == 0) {
+               return;
+       }
+       printf("%s on %s (%p)\n", function_name, object_name, object_address);
+}
+
+void DEG_debug_print_eval_subdata(const char *function_name,
+                                  const char *object_name,
+                                  const void *object_address,
+                                  const char *subdata_comment,
+                                  const char *subdata_name,
+                                  const void *subdata_address)
+{
+       if ((G.debug & G_DEBUG_DEPSGRAPH_EVAL) == 0) {
+               return;
+       }
+       printf("%s on %s (%p) %s %s (%p)\n",
+              function_name,
+              object_name, object_address,
+              subdata_comment,
+              subdata_name, subdata_address);
+}
+
+void DEG_debug_print_eval_subdata_index(const char *function_name,
+                                        const char *object_name,
+                                        const void *object_address,
+                                        const char *subdata_comment,
+                                        const char *subdata_name,
+                                        const void *subdata_address,
+                                        const int subdata_index)
+{
+       if ((G.debug & G_DEBUG_DEPSGRAPH_EVAL) == 0) {
+               return;
+       }
+       printf("%s on %s (%p) %s %s[%d] (%p)\n",
+              function_name,
+              object_name, object_address,
+              subdata_comment,
+              subdata_name, subdata_index, subdata_address);
+}
+
+void DEG_debug_print_eval_time(const char *function_name,
+                               const char *object_name,
+                               const void *object_address,
+                               float time)
+{
+       if ((G.debug & G_DEBUG_DEPSGRAPH_EVAL) == 0) {
+               return;
+       }
+       printf("%s on %s (%p) at time %f\n",
+              function_name, object_name, object_address, time);
+}