Improve debug messages (fix #77)

- There were numerous "Triggered oudate_vtk_status" debug messages
  in JSON import due to communication of changes downstream.
  Changed debug message locations to avoid message repetitions.
- Improved also other debug messages.

cache.py

@@ -133,9 +133,9 @@ def map_node(cls, node, vtk_obj=None):
         treeIdMap[node.node_id] = tree
 
         if node.node_id == nodeMaxId:
-            l.debug("Mapped new node: %s, id %d" % (node.name, node.node_id))
+            l.debug("Mapped new node: %s, id #%d" % (node.name, node.node_id))
         else:
-            l.debug("Remapped old node: %s, id %d" % (node.name, node.node_id))
+            l.debug("Remapped old node: %s, id #%d" % (node.name, node.node_id))
 
     @classmethod
     def unmap_node(cls, node):
@@ -150,7 +150,7 @@ def unmap_node(cls, node):
             del treeIdMap[node.node_id]
         if node.node_id in vtkCache:
             del vtkCache[node.node_id]
-        l.debug("Unmapped node: %s, id %d" % (node.name, node.node_id))
+        l.debug("Unmapped node: %s, id #%d" % (node.name, node.node_id))
 
     @classmethod
     def get_node(cls, node_id: int):

core.py

@@ -642,14 +642,15 @@ def outdate_vtk_status(self, context):
         """Set node VTK status to out-of-date and notify downstream when a
         property value is changed in UI.
         """
-        l.debug(self.name + ": Triggered outdate_vtk_status")
         update_mode = bpy.context.scene.bvtknodes_settings.update_mode
         if update_mode == "update-current":
+            l.debug(self.name + ": Setting VTK status out-of-date")
             self.set_vtk_status("out-of-date")
             self.update_vtk()
         else:
             self.notify_downstream(vtk_status="out-of-date")
         if update_mode == "update-all":
+            l.debug(self.name + ": Calling update for all nodes")
             BVTKCache.update_all()
 
     def update(self):

tree.py

@@ -222,6 +222,7 @@ def node_from_dict(nodes, node_dict):
     # if not hasattr(bpy.types, idname):
     #    l.error('Node type not found ' + idname)
     # else:
+    l.debug("Inserting node: %r" % idname)
     new_node = nodes.new(type=idname)
     additional_property_values = None
     for prop in node_dict:
@@ -252,6 +253,7 @@ def link_from_dict(nodes, links, new_link_dict):
         from_socket = gosbi(from_node, new_link_dict["from_socket_identifier"])
         to_socket = gisbi(to_node, new_link_dict["to_socket_identifier"])
         if to_socket and from_socket:
+            l.debug("Inserting link from %r to %r" % (from_node.name, to_node.name))
             links.new(to_socket, from_socket)