Update logger messages

jdent02 · Apr 7, 2020 · bce232d · bce232d
1 parent 66f9313
commit bce232d
Show file tree

Hide file tree

Showing 10 changed files with 53 additions and 29 deletions.
diff --git a/translators/cameras/final.py b/translators/cameras/final.py
@@ -39,6 +39,7 @@
 class RenderCameraTranslator(Translator):
 
     def __init__(self, cam, asset_handler):
+        logger.debug(f"appleseed: Creating final render camera translator for {cam.name_full}")
         super().__init__(cam, asset_handler)
 
         self.__as_camera = None
@@ -53,6 +54,7 @@ def bl_camera(self):
         return self._bl_obj
 
     def create_entities(self, depsgraph, context=None, engine=None):
+        logger.debug(f"appleseed: Creating final render camera entity for {self.obj_name}")
         self.__cam_model = self.__get_model()
 
         self.__as_camera = asr.Camera(self.__cam_model, "Camera", {})
@@ -62,7 +64,7 @@ def create_entities(self, depsgraph, context=None, engine=None):
         self.__as_camera.set_parameters(self.__as_cam_params)
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
-        logger.debug("appleseed: Flushing camera entity, num xform keys = %s", self.__as_camera.transform_sequence().size())
+        logger.debug(f"appleseed: Flushing final render camera entity into project, num xform keys = {self.__as_camera.transform_sequence().size()}")
 
         self.__as_camera.transform_sequence().optimize()
 

diff --git a/translators/cameras/interactive.py b/translators/cameras/interactive.py
@@ -44,7 +44,7 @@ class InteractiveCameraTranslator(Translator):
     """
 
     def __init__(self, cam, asset_handler):
-        logger.debug("appleseed: Creating interactive camera translator")
+        logger.debug(f"appleseed: Creating interactive camera translator for {cam.name_full}")
         super().__init__(cam, asset_handler)
 
         self.__as_camera = None
@@ -63,6 +63,7 @@ def bl_camera(self):
         return self._bl_obj
 
     def create_entities(self, depsgraph, context, engine=None):
+        logger.debug(f"appleseed: Creating interactive camera entity for {self.bl_camera.name_full}")
         self.__view_cam_type = context.region_data.view_perspective
 
         self.__model = self.__get_model()
@@ -72,6 +73,7 @@ def create_entities(self, depsgraph, context, engine=None):
         self.__as_camera = asr.Camera(self.__model, "Camera", self.__cam_params)
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
+        logger.debug(f"appleseed: Flushing interactive camera entity for {self.bl_camera.name_full} into project")
         self.__as_camera.transform_sequence().optimize()
 
         as_scene.cameras().insert(self.__as_camera)

diff --git a/translators/material.py b/translators/material.py
@@ -37,7 +37,7 @@
 class MaterialTranslator(Translator):
 
     def __init__(self, mat, asset_handler):
-        logger.debug("appleseed: Creating material translator for %s", mat.name_full)
+        logger.debug(f"appleseed: Creating material translator for {mat.name_full}")
 
         super().__init__(mat, asset_handler)
 
@@ -63,7 +63,7 @@ def bl_node_tree(self):
         return self._bl_obj.node_tree
 
     def create_entities(self, depsgraph, engine):
-        logger.debug("appleseed: Creating texture entity for %s", self.orig_name)
+        logger.debug(f"appleseed: Creating material entity for {self.orig_name}")
 
         surface_name = f"{self.orig_name}_surface"
 
@@ -82,7 +82,7 @@ def create_entities(self, depsgraph, engine):
         self.__as_shader.set_parameters(self.__as_shader_params)
 
     def flush_entities(self, as_scene, as_assembly, as_project):
-        logger.debug("appleseed: Flushing material data for %s", self.orig_name)
+        logger.debug(f"appleseed: Flushing material entity for {self.orig_name} to project")
 
         if self.__as_nodetree is not None:
             self.__as_nodetree.flush_entities(as_scene, as_assembly, as_project)
@@ -96,9 +96,11 @@ def flush_entities(self, as_scene, as_assembly, as_project):
         self.__as_mat = as_assembly.materials().get_by_name(mat_name)
 
     def update_material(self, bl_scene, engine):
+        logger.debug(f"appleseed: Updating material entity for {self.orig_name}")
         self.__as_nodetree.update_nodetree(bl_scene, engine)
 
     def delete_material(self, as_main_assembly):
+        logger.debug(f"appleseed: Deleting material entity for {self.orig_name}")
         if self.__as_nodetree is not None:
             self.__as_nodetree.delete_nodetree(as_main_assembly)
         self.__as_nodetree = None

diff --git a/translators/nodetree.py b/translators/nodetree.py
@@ -41,7 +41,7 @@
 class NodeTreeTranslator(Translator):
 
     def __init__(self, node_tree, asset_handler, mat_name):
-        logger.debug("appleseed: Creating translator for %s node tree", mat_name)
+        logger.debug(f"appleseed: Creating node tree translator for {mat_name} node tree")
 
         super().__init__(node_tree, asset_handler)
 
@@ -54,7 +54,7 @@ def bl_nodes(self):
         return self._bl_obj.nodes
 
     def create_entities(self, depsgraph, engine):
-        logger.debug("appleseed: Creating entitiy for %s node tree", self.__mat_name)
+        logger.debug(f"appleseed: Creating node tree entitiy for {self.__mat_name} node tree")
 
         tree_name = f"{self.__mat_name}_tree"
 
@@ -63,17 +63,17 @@ def create_entities(self, depsgraph, engine):
         self.__create_shadergroup(depsgraph.scene_eval, engine)
 
     def flush_entities(self, as_scene, as_assembly, as_project):
-        logger.debug("appleseed: Flushing data for %s node tree", self.__mat_name)
+        logger.debug(f"appleseed: Flushing node tree entity {self.__mat_name} to project")
         shader_groupname = self.__as_shader_group.get_name()
         as_assembly.shader_groups().insert(self.__as_shader_group)
         self.__as_shader_group = as_assembly.shader_groups().get_by_name(shader_groupname)
 
     def update_nodetree(self, bl_scene, engine):
-        logger.debug("appleseed: Updating node tree for %s", self.__mat_name)
+        logger.debug(f"appleseed: Updating node tree entity for {self.__mat_name}")
         self.__create_shadergroup(bl_scene, engine)
 
     def delete_nodetree(self, as_main_assembly):
-        logger.debug("appleseed: Deleting node tree for %s", self.__mat_name)
+        logger.debug(f"appleseed: Deleting node tree entity for {self.__mat_name}")
         as_main_assembly.shader_groups().remove(self.__as_shader_group)
         self.__as_shader_group = None
 
@@ -82,7 +82,7 @@ def __create_shadergroup(self, bl_scene, engine):
         for node in self.bl_nodes:
             if isinstance(node, AppleseedOSLNode):
                 if node.node_type == 'osl_surface':
-                    logger.debug("appleseed: Found surface shader for %s node tree", self.__mat_name)
+                    logger.debug(f"appleseed: Found surface shader for {self.__mat_name} node tree")
                     surface_shader = node
                     self.__shader_list = surface_shader.traverse_tree(engine)
                     break
@@ -101,7 +101,7 @@ def __create_shadergroup(self, bl_scene, engine):
                         break
 
         if surface_shader is None:
-            logger.debug("appleseed: No surface shader for %s node tree", self.__mat_name)
+            logger.debug(f"appleseed: No surface shader for {self.__mat_name} node tree")
             return
 
         self.__as_shader_group.clear()
@@ -135,7 +135,7 @@ def __create_shadergroup(self, bl_scene, engine):
 
             if node.node_type == 'osl':
                 shader_file_name = self._asset_handler.process_path(node.file_name, AssetType.SHADER_ASSET)
-                logger.debug("appleseed: Adding %s shader to %s node tree", node.name, self.__mat_name)
+                logger.debug(f"appleseed: Adding {node.name} shader to {self.__mat_name} node tree")
                 self.__as_shader_group.add_shader("shader", shader_file_name, node.name, parameters)
             elif node.node_type == 'osl_script':
                 script = node.script
@@ -146,7 +146,7 @@ def __create_shadergroup(self, bl_scene, engine):
                     code = open(osl_path, 'r')
                     source_code = code.read()
                     code.close()
-                logger.debug("appleseed: Adding %s source shader to %s node tree", node.name, self.__mat_name)
+                logger.debug(f"appleseed: Adding {node.name} source shader to {self.__mat_name} node tree")
                 self.__as_shader_group.add_source_shader("shader", node.bl_idname, node.name, source_code, parameters)
 
             for output in node.outputs:

diff --git a/translators/objects/archive_assembly.py b/translators/objects/archive_assembly.py
@@ -35,6 +35,7 @@
 
 class ArchiveAssemblyTranslator(Translator):
     def __init__(self, archive_obj, asset_handler):
+        logger.debug(f"appleseed: Creating archive asset translator for {archive_obj.name_full}")
         super().__init__(archive_obj, asset_handler)
 
         self.__instance_lib = asr.BlTransformLibrary()
@@ -53,6 +54,7 @@ def instances_size(self):
         return len(self.__instance_lib)
 
     def create_entities(self, bl_scene, context=None):
+        logger.debug(f"appleseed: Creating archive asset entity for {self.orig_name}")
         self.__ass_name = f"{self.orig_name}_ass"
 
         file_path = self._asset_handler.process_path(self._bl_obj.appleseed.archive_path,
@@ -69,6 +71,7 @@ def set_deform_key(self, time, depsgraph, index):
         pass
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
+        logger.debug(f"appleseed: Flushing archive asset entity for {self.orig_name} to project")
         as_main_assembly.assemblies().insert(self.__ass)
         self.__ass = as_main_assembly.assemblies().get_by_name(self.__ass_name)
 
@@ -78,6 +81,7 @@ def flush_instances(self, as_main_assembly):
         self.__instance_lib.flush_instances(as_main_assembly, self.__ass_name)
 
     def update_archive_ass(self, depsgraph):
+        logger.debug(f"appleseed: Updating archive asset entity for {self.orig_name}")
         file_path = self._asset_handler.process_path(self._bl_obj.appleseed.archive_path,
                                                      AssetType.ARCHIVE_ASSET)
 
@@ -89,6 +93,7 @@ def clear_instances(self, as_main_assembly):
         self.__instance_lib.clear_instances(as_main_assembly)
 
     def delete_object(self, as_main_assembly):
+        logger.debug(f"appleseed: Deleting archive asset entity for {self.orig_name}")
         self.clear_instances(as_main_assembly)
 
         as_main_assembly.assemblies().remove(self.__ass)

diff --git a/translators/objects/lamp.py b/translators/objects/lamp.py
@@ -44,6 +44,7 @@
 
 class LampTranslator(Translator):
     def __init__(self, bl_lamp, export_mode, asset_handler):
+        logger.debug(f"appleseed: Creating lamp translator for {bl_lamp.name_full}")
         super().__init__(bl_lamp, asset_handler)
 
         self._bl_obj.appleseed.obj_name = self._bl_obj.name_full
@@ -83,6 +84,7 @@ def instances_size(self):
         return len(self.__instance_lib)
 
     def create_entities(self, depsgraph, deforms_length):
+        logger.debug(f"appleseed: Creating lamp entity for {self.orig_name}")
         as_lamp_data = self.bl_lamp.data.appleseed
 
         self.__lamp_model = self.__get_lamp_model()
@@ -136,6 +138,7 @@ def set_deform_key(self, time, depsgraph, index):
         pass
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
+        logger.debug(f"appleseed: Flushing lamp entity for {self.orig_name} to project")
         self.__instance_lib.optimize_xforms()
 
         needs_assembly = self.__export_mode == ProjectExportMode.INTERACTIVE_RENDER or self.__instance_lib.needs_assembly()
@@ -216,6 +219,7 @@ def flush_entities(self, as_scene, as_main_assembly, as_project):
                 self.__as_mesh_inst = as_main_assembly.object_instances().get_by_name(self.__as_area_lamp_inst_name)
 
     def update_lamp(self, depsgraph, as_main_assembly, as_scene, as_project):
+        logger.debug(f"appleseed: Updating lamp entity for {self.orig_name}")
         as_lamp_data = self.bl_lamp.data.appleseed
 
         current_model = self.__lamp_model
@@ -363,18 +367,17 @@ def flush_instances(self, as_main_assembly):
         self.__instance_lib.flush_instances(as_main_assembly, self.__ass_name)
 
     def delete_object(self, as_main_assembly):
+        logger.debug(f"appleseed: Deleting lamp entity for {self.orig_name}")
         self.clear_instances(as_main_assembly)
 
         if self.__lamp_model != 'area_lamp':
-            print("Removing regular light")
             self.__ass.lights().remove(self.__as_lamp)
             self.__as_lamp = None
 
             as_main_assembly.colors().remove(self.__as_lamp_radiance)
             self.__as_lamp_radiance = None
 
         else:
-            print("Removing area lamp")
             self.__ass.objects().remove(self.__as_area_lamp_mesh)
 
             self.__ass.object_instances().remove(self.__as_area_lamp_inst)

diff --git a/translators/objects/mesh.py b/translators/objects/mesh.py
@@ -38,6 +38,7 @@
 
 class MeshTranslator(Translator):
     def __init__(self, bl_obj, export_mode, asset_handler):
+        logger.debug(f"appleseed: Creating mesh translator for {bl_obj.name_full}")
         super().__init__(bl_obj, asset_handler)
 
         self.__export_mode = export_mode
@@ -77,6 +78,7 @@ def instances_size(self):
         return len(self.__instance_lib)
 
     def create_entities(self, depsgraph, num_def_times):
+        logger.debug(f"appleseed: Creating mesh entity for {self.orig_name}")
         self.__mesh_params = self.__get_mesh_params()
 
         self.__as_mesh = asr.MeshObject(self.orig_name, self.__mesh_params)
@@ -92,7 +94,7 @@ def create_entities(self, depsgraph, num_def_times):
         self.__convert_mesh(me)
 
         if self.__export_mode == ProjectExportMode.PROJECT_EXPORT:
-            logger.debug("Writing mesh file object %s, time = 0", self.orig_name)
+            logger.debug(f"appleseed: Writing mesh file object {self.orig_name}, time = 0")
             self.__write_mesh(self.orig_name)
 
         eval_object.to_mesh_clear()
@@ -109,7 +111,7 @@ def set_deform_key(self, time, depsgraph, index):
         me = eval_object.to_mesh()
 
         if self.__export_mode == ProjectExportMode.PROJECT_EXPORT:
-            logger.debug("Writing mesh file object %s, time = %s", self.orig_name, time)
+            logger.debug(f"appleseed: Writing mesh file object {self.orig_name}, time = {time}")
 
             self.__convert_mesh(me)
             self.__write_mesh(self.orig_name)
@@ -119,7 +121,7 @@ def set_deform_key(self, time, depsgraph, index):
         eval_object.to_mesh_clear()
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
-        logger.debug("appleseed: Flusing mesh for object %s", self.orig_name)
+        logger.debug("appleseed: Flusing mesh entity for {self.orig_name} into project")
 
         if self.__export_mode == ProjectExportMode.PROJECT_EXPORT:
             # Replace the MeshObject by an empty one referencing
@@ -185,6 +187,7 @@ def flush_entities(self, as_scene, as_main_assembly, as_project):
             self.__as_mesh_inst = as_main_assembly.object_instances().get_by_name(self.__obj_inst_name)
 
     def flush_instances(self, as_main_assembly):
+        logger.debug(f"appleseed: Flushing instances for mesh entity {self.orig_name} into project.  Number of instances = {self.__instance_lib.size()}")
         self.__instance_lib.flush_instances(as_main_assembly, self.__ass_name)
 
     def update_obj_instance(self):
@@ -211,6 +214,7 @@ def clear_instances(self, as_main_assembly):
         self.__instance_lib.clear_instances(as_main_assembly)
 
     def delete_object(self, as_main_assembly):
+        logger.debug(f"appleseed: Deleting mesh entity for {self.orig_name}")
         self.clear_instances(as_main_assembly)
 
         self.__ass.objects().remove(self.__as_mesh)
@@ -263,7 +267,7 @@ def __get_material_mappings(self):
                 front_mats["default"] = mat_key
             else:
                 mesh_name = f"{self.obj_name}_obj"
-                logger.debug("Mesh %s has no materials, assigning default material instead", mesh_name)
+                logger.debug("appleseed: Mesh %s has no materials, assigning default material instead", mesh_name)
                 front_mats["default"] = "__default_material"
 
         double_sided_materials = False if self._bl_obj.appleseed.double_sided is False else True
@@ -348,11 +352,11 @@ def __convert_mesh(self, me):
         convert_timer.stop()
         main_timer.stop()
 
-        logger.debug("\nMesh %s converted in: %s", self.obj_name, main_timer.elapsed())
-        logger.debug("  Number of triangles:    %s", len(me.loop_triangles))
-        logger.debug("  Normals converted in:   %s", normal_timer.elapsed())
-        logger.debug("  Looptris converted in:  %s", looptri_timer.elapsed())
-        logger.debug("  C++ conversion in:      %s", convert_timer.elapsed())
+        logger.debug("\nappleseed: Mesh %s converted in: %s", self.obj_name, main_timer.elapsed())
+        logger.debug("             Number of triangles:    %s", len(me.loop_triangles))
+        logger.debug("             Normals converted in:   %s", normal_timer.elapsed())
+        logger.debug("             Looptris converted in:  %s", looptri_timer.elapsed())
+        logger.debug("             C++ conversion in:      %s", convert_timer.elapsed())
 
     def __set_mesh_key(self, me, key_index):
         do_normals = self._bl_obj.data.appleseed.export_normals
@@ -391,7 +395,7 @@ def __write_mesh(self, mesh_name):
         logger.debug("   get_vertex_tangent_count %s", self.__as_mesh.get_vertex_tangent_count())
         logger.debug("   get_motion_segment_count %s", self.__as_mesh.get_motion_segment_count())
 
-        logger.debug("Computed mesh signature for object %s, hash: %s", self.orig_name, bl_hash)
+        logger.debug("appleseed: Computed mesh signature for object %s, hash: %s", self.orig_name, bl_hash)
 
         # Save the mesh filename for later use.
         mesh_filename = f"{bl_hash}.binarymesh"
@@ -401,10 +405,10 @@ def __write_mesh(self, mesh_name):
         mesh_abs_path = os.path.join(self.__geom_dir, mesh_filename)
 
         if not os.path.exists(mesh_abs_path):
-            logger.debug("Writing mesh for object %s to %s", mesh_name, mesh_abs_path)
+            logger.debug("appleseed: Writing mesh for object %s to %s", mesh_name, mesh_abs_path)
             asr.MeshObjectWriter.write(self.__as_mesh, "mesh", mesh_abs_path)
         else:
-            logger.debug("Skipping already saved mesh file for mesh %s", mesh_name)
+            logger.debug("appleseed: Skipping already saved mesh file for mesh %s", mesh_name)
 
     def __object_instance_mesh_name(self, mesh_name):
         if self.__export_mode == ProjectExportMode.PROJECT_EXPORT:

diff --git a/translators/scene.py b/translators/scene.py
@@ -265,7 +265,6 @@ def translate_scene(self, engine, depsgraph, context=None):
         self.__load_searchpaths()
 
         prof_timer.stop()
-        print(f"Scene translated in {prof_timer.elapsed()} seconds.")
         logger.debug("Scene translated in %f seconds.", prof_timer.elapsed())
 
     def update_multiview_camera(self, engine, depsgraph):

diff --git a/translators/textures.py b/translators/textures.py
@@ -41,6 +41,7 @@ class TextureTranslator(Translator):
     """
 
     def __init__(self, bl_texture, asset_handler=None):
+        logger.debug(f"appleseed: Creating texture translator for {bl_texture.name_full}")
         super().__init__(bl_texture, asset_handler)
 
         self.__as_tex = None
@@ -60,6 +61,7 @@ def orig_name(self):
         return self._bl_obj.appleseed.obj_name
 
     def create_entities(self, depsgraph):
+        logger.debug(f"appleseed: Creating texture entity for {self.orig_name}")
         self.__as_tex_params = self.__get_tex_params()
         self.__as_tex = asr.Texture('disk_texture_2d', self.orig_name, self.__as_tex_params, [])
 
@@ -71,6 +73,7 @@ def create_entities(self, depsgraph):
                                                  asr.Transformf(asr.Matrix4f.identity()))
 
     def flush_entities(self, as_scene, as_main_assembly, as_project):
+        logger.debug(f"appleseed: Flushing texture entity for {self.orig_name} to project")
         scene = as_project.get_scene()
         tex_name = self.__as_tex.get_name()
         scene.textures().insert(self.__as_tex)