From 13b6849d70a0645f978ea1ed0f1c87355885b651 Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Thu, 12 Feb 2026 09:31:21 -0500 Subject: [PATCH 1/6] Start adding logging --- quickbake/__init__.py | 8 ++++++++ quickbake/op.py | 48 ++++++++++++++++++++++++++++++++++++++++++- 2 files changed, 55 insertions(+), 1 deletion(-) diff --git a/quickbake/__init__.py b/quickbake/__init__.py index b976cf5..80b1683 100644 --- a/quickbake/__init__.py +++ b/quickbake/__init__.py @@ -1,11 +1,18 @@ +import logging + import bpy from .op import RENDER_OT_bake from .panel import RENDER_PT_main from .properties import QuickBakeToolPropertyGroup +_log = logging.getLogger(__name__) +_log.setLevel(logging.DEBUG) +_log.addHandler(logging.StreamHandler()) + def register(): + _log.debug("Register extension") bpy.utils.register_class(RENDER_OT_bake) bpy.utils.register_class(RENDER_PT_main) bpy.utils.register_class(QuickBakeToolPropertyGroup) @@ -15,6 +22,7 @@ def register(): def unregister(): + _log.debug("Unregister extension") bpy.utils.unregister_class(RENDER_OT_bake) bpy.utils.unregister_class(RENDER_PT_main) bpy.utils.unregister_class(QuickBakeToolPropertyGroup) diff --git a/quickbake/op.py b/quickbake/op.py index cee516f..05c8514 100644 --- a/quickbake/op.py +++ b/quickbake/op.py @@ -1,8 +1,12 @@ +import logging + import bpy from bpy_extras.node_shader_utils import PrincipledBSDFWrapper from .properties import MaterialMode, QuickBakeToolPropertyGroup +_log = logging.getLogger(__name__) + class RENDER_OT_bake(bpy.types.Operator): """Do the bake.""" @@ -48,12 +52,15 @@ def poll(cls, context): return obj is not None and obj.type == "MESH" def execute(self, context: bpy.types.Context): + _log.info("Begin execution") + # Keeping type hints happy, should not be possible scene = context.scene assert scene is not None, "Context must have a scene, got None" # Make sure cycles is the current render engine if scene.render.engine != "CYCLES": + _log.info("Setting render engine to cycles") scene.render.engine = "CYCLES" # type: ignore self.report({"WARNING"}, "Changed render engine to Cycles") @@ -64,11 +71,13 @@ def execute(self, context: bpy.types.Context): # This should be enforces by cls.poll() but is here to be sure if obj is None: + _log.error("No active object") self.report({"ERROR"}, "No active object") return {"CANCELLED"} # canceled because nothing was altered / needs undo # This should be enforces by cls.poll() but is here to be sure if obj.type != "MESH": + _log.error("Expected active object to be mesh, got %s", obj.type) self.report({"ERROR"}, "Active object must be a mesh") return {"CANCELLED"} # canceled because nothing was altered / needs undo @@ -101,6 +110,8 @@ def execute(self, context: bpy.types.Context): if props.uv_enabled: passes.append(("UV", True)) + _log.debug("Render passes will be %s", passes) + # Keeping type hints happy assert isinstance(obj.data, bpy.types.Mesh), "Object is not a mesh" mesh = obj.data @@ -110,6 +121,7 @@ def execute(self, context: bpy.types.Context): images = {} for layer, is_data in passes: + _log.info("Starting layer %s", layer) self.report({"INFO"}, f"Starting layer {layer}") image_name = f"{props.bake_name}_{layer.lower()}" @@ -117,13 +129,21 @@ def execute(self, context: bpy.types.Context): # Create image or use existing img = bpy.data.images.get(image_name) if img is None: + _log.info("Creating image %s", image_name) img = bpy.data.images.new( image_name, props.bake_size, props.bake_size, is_data=is_data ) + else: + _log.debug("Using existing image %s", image_name) images[layer] = img # Assign image to bake node in all materials for mat, texture_node in bake_nodes: + _log.debug( + "Assigning image to texture node %s in material %s", + texture_node.name, + mat.name, + ) # TODO type ignore if it works texture_node.image = img # type: ignore texture_node.select = True @@ -133,9 +153,11 @@ def execute(self, context: bpy.types.Context): filepath = "" save_mode = "INTERNAL" if props.save_img: - filepath = f"{props.save_path}/{props.bake_name}_{layer}" save_mode = "EXTERNAL" + filepath = f"{props.save_path}/{props.bake_name}_{layer}" + _log.debug("Images will be saved externally to %s", filepath) + _log.info("Starting bake for layer %s", layer) bpy.ops.object.bake( type=layer, # type: ignore pass_filter={"COLOR"}, # TODO change this for other textures @@ -144,6 +166,7 @@ def execute(self, context: bpy.types.Context): save_mode=save_mode, filepath=filepath, ) + _log.info("Finished bake for layer %s", layer) self.cleanup_image_nodes(mesh) @@ -173,19 +196,25 @@ def execute(self, context: bpy.types.Context): def unwrap_object(self, mesh: bpy.types.Mesh) -> bpy.types.MeshUVLoopLayer: uv_name = "bake_uv" + _log.debug("Unwrapping mesh %s with uv layer %s", mesh.name, uv_name) # Use existing or create new uv layer for baking bake_uv = mesh.uv_layers.get(uv_name) if bake_uv is None: + _log.info("Creating new uv layer %s", uv_name) bake_uv = mesh.uv_layers.new(name=uv_name) + else: + _log.debug("Reusing existing uv layer %s", uv_name) # Store currently active layer active_layer = None for layer in mesh.uv_layers: if layer.active: active_layer = layer + _log.debug("Currently active uv layer is %s", active_layer.name) break + _log.debug("Start unwrapping mesh %s", mesh.name) # Unwrap the object bake_uv.active = True bpy.ops.object.mode_set(mode="EDIT") @@ -193,9 +222,11 @@ def unwrap_object(self, mesh: bpy.types.Mesh) -> bpy.types.MeshUVLoopLayer: bpy.ops.uv.smart_project(island_margin=0.001) bpy.ops.object.mode_set(mode="OBJECT") bake_uv.active = False + _log.debug("Finished unwrapping mesh %s", mesh.name) # Restore active layer if active_layer is not None: + _log.debug("Restoring active uv layer %s", active_layer.name) active_layer.active = True return bake_uv @@ -211,19 +242,27 @@ def create_image_nodes( for mat in mesh.materials: if mat is None or mat.node_tree is None: + _log.warning("Found null material in mesh %s", mesh.name) null_count += 1 continue + _log.debug("Enabling nodes for material %s", mat.name) # Enable nodes if not already mat.use_nodes = True texture_node = mat.node_tree.get(node_name) if texture_node is None: + _log.info("Creating texture node for material %s", mat.name) texture_node = mat.node_tree.nodes.new("ShaderNodeTexImage") texture_node.name = node_name + else: + _log.debug("Using existing texture node %s", texture_node.name) + image_nodes.append((mat, texture_node)) + _log.info("Created %d nodes in mesh %s", len(image_nodes), mesh.name) + # Notify user if any materials were unusable if null_count > 0: self.report({"WARNING"}, f"Mesh {mesh.name} has {null_count} null material") @@ -232,14 +271,21 @@ def create_image_nodes( def cleanup_image_nodes(self, mesh: bpy.types.Mesh): node_name = "bake_image" + _log.info("Cleaning up bake texture node %s in msh %s", node_name, mesh.name) for mat in mesh.materials: if mat is None or mat.node_tree is None: + _log.warning("Found null material in mesh %s", mesh.name) continue node = mat.node_tree.get(node_name) if node is not None: + _log.debug("Removing node %s from material %s", node.name, mat.name) mat.node_tree.nodes.remove(node) + else: + _log.warning( + "Failed to find node %s in material %s", node_name, mat.name + ) def create_material( self, From eecacb3df2bf8dfa5b17d679887ecb5b86493ca3 Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Fri, 13 Feb 2026 05:14:26 -0500 Subject: [PATCH 2/6] Bug fix cleanup bake nodes --- quickbake/op.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/quickbake/op.py b/quickbake/op.py index 05c8514..64dbadd 100644 --- a/quickbake/op.py +++ b/quickbake/op.py @@ -278,7 +278,7 @@ def cleanup_image_nodes(self, mesh: bpy.types.Mesh): _log.warning("Found null material in mesh %s", mesh.name) continue - node = mat.node_tree.get(node_name) + node = mat.node_tree.nodes.get(node_name) if node is not None: _log.debug("Removing node %s from material %s", node.name, mat.name) mat.node_tree.nodes.remove(node) From 4010c117c9a1c5d3f44283fe9b35bf8bc0b71387 Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Fri, 13 Feb 2026 05:14:58 -0500 Subject: [PATCH 3/6] Only enable logger when developing --- quickbake/__init__.py | 8 ++++++-- quickbake/util.py | 14 ++++++++++++++ 2 files changed, 20 insertions(+), 2 deletions(-) create mode 100644 quickbake/util.py diff --git a/quickbake/__init__.py b/quickbake/__init__.py index 80b1683..9773628 100644 --- a/quickbake/__init__.py +++ b/quickbake/__init__.py @@ -5,10 +5,14 @@ from .op import RENDER_OT_bake from .panel import RENDER_PT_main from .properties import QuickBakeToolPropertyGroup +from .util import is_development + _log = logging.getLogger(__name__) -_log.setLevel(logging.DEBUG) -_log.addHandler(logging.StreamHandler()) + +if is_development(): + _log.setLevel(logging.DEBUG) + _log.addHandler(logging.StreamHandler()) def register(): diff --git a/quickbake/util.py b/quickbake/util.py new file mode 100644 index 0000000..dad8ac0 --- /dev/null +++ b/quickbake/util.py @@ -0,0 +1,14 @@ +import os + +import tomllib + + +def _get_version(): + if os.path.exists("quickbake/blender_manifest.toml"): + with open("quickbake/blender_manifest.toml", "rb") as f: + data = tomllib.load(f) + return data.get("version") + + +def is_development(): + return _get_version() == "0.0.0" From f0d86e0c18e2769a56d78933c5b25ccea665cc83 Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Fri, 13 Feb 2026 05:15:06 -0500 Subject: [PATCH 4/6] Enable blender debug --- Makefile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Makefile b/Makefile index fe9a851..d846e4c 100644 --- a/Makefile +++ b/Makefile @@ -14,7 +14,7 @@ install: cp -r quickbake/* $(INSTALL_DIR)/ run: install - blender "example/Metal Box.blend" + blender --debug "example/Metal Box.blend" checks: lint test From 6d7fc87d7bd1f8176cc095aad5f1126733f5b218 Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Fri, 13 Feb 2026 05:15:17 -0500 Subject: [PATCH 5/6] more logging --- quickbake/op.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/quickbake/op.py b/quickbake/op.py index 64dbadd..2d138a7 100644 --- a/quickbake/op.py +++ b/quickbake/op.py @@ -178,10 +178,15 @@ def execute(self, context: bpy.types.Context): # Duplicate object and assign material to new if props.mat_mode == MaterialMode.DUPLICATE: + _log.info("Duplicating object before assigning material") bpy.ops.object.duplicate() + _log.debug("Hiding original object %s", obj.name) obj.hide_set(True) # Get new object obj = context.active_object + _log.debug( + "New object is named %s", obj.name if obj is not None else "None" + ) # Keeping type hints happy assert obj is not None, "Object is None" @@ -189,9 +194,11 @@ def execute(self, context: bpy.types.Context): # Assign or Copy if props.mat_mode != MaterialMode.CREATE: + _log.info("Assigning material %s to object %s", mat.name, obj.name) obj.data.materials.clear() obj.active_material = mat + _log.info("Finished execution") return {"FINISHED"} def unwrap_object(self, mesh: bpy.types.Mesh) -> bpy.types.MeshUVLoopLayer: @@ -286,6 +293,10 @@ def cleanup_image_nodes(self, mesh: bpy.types.Mesh): _log.warning( "Failed to find node %s in material %s", node_name, mat.name ) + _log.debug( + "Material %s has nodes %s", mat.name, list(mat.node_tree.nodes) + ) + self.report({"WARNING"}, f"Failed to cleanup material {mat.name}") def create_material( self, From fb2026c227f8b708e9def7b2c88151dcf0ba7d8b Mon Sep 17 00:00:00 2001 From: Thomas Harrison Date: Fri, 13 Feb 2026 05:29:09 -0500 Subject: [PATCH 6/6] more logging --- quickbake/op.py | 42 ++++++++++++++++++++++++++++++++++++++---- 1 file changed, 38 insertions(+), 4 deletions(-) diff --git a/quickbake/op.py b/quickbake/op.py index 2d138a7..8fb7a05 100644 --- a/quickbake/op.py +++ b/quickbake/op.py @@ -118,7 +118,7 @@ def execute(self, context: bpy.types.Context): uv_layer = self.unwrap_object(mesh) bake_nodes = self.create_image_nodes(mesh) - images = {} + images: dict[str, bpy.types.Image] = {} for layer, is_data in passes: _log.info("Starting layer %s", layer) @@ -303,11 +303,12 @@ def create_material( props: QuickBakeToolPropertyGroup, uv_layer: bpy.types.MeshUVLoopLayer, passes: list[tuple[str, bool]], - images: dict, + images: dict[str, bpy.types.Image], ): # Create Material mat = bpy.data.materials.get(props.bake_name) if mat is None: + _log.debug("Creating material %s", props.bake_name) mat = bpy.data.materials.new(props.bake_name) mat.use_nodes = True @@ -324,6 +325,7 @@ def create_material( # Texture coordinate node for uv map uv_node = shader_nodes.get("Texture Coordinate") if uv_node is None: + _log.debug("Creating uv node in material %s", mat.name) uv_node = shader_nodes.new(type="ShaderNodeUVMap") uv_node.location.x = -1100 uv_node.uv_map = uv_layer.name # type: ignore @@ -331,6 +333,7 @@ def create_material( # Mapping node for position, scale, rotation mapping_node = shader_nodes.get("Texture Coordinate") if mapping_node is None: + _log.debug("Creating mapping node in material %s", mat.name) mapping_node = shader_nodes.new(type="ShaderNodeMapping") mapping_node.location.x = -900 @@ -344,31 +347,62 @@ def create_material( tex_node = mat.node_tree.get(layer) if tex_node is None: + _log.debug( + "Creating image texture node for layer %s in material %s", + layer, + mat.name, + ) tex_node = shader_nodes.new(type="ShaderNodeTexImage") tex_node.location.x = -700 tex_node.location.y = y tex_node.image = images[layer] # type: ignore + _log.debug( + "Assigned image %s to image texture node %s", + images[layer].name, + tex_node.name, + ) links.new(mapping_node.outputs["Vector"], tex_node.inputs["Vector"]) + _log.debug( + "Linked mapping node %s output to image texture %s vector input", + mapping_node.name, + tex_node.name, + ) - shader_input = self.layer_input_map.get(layer, "") - if shader_input: + if shader_input := self.layer_input_map.get(layer): if layer == "NORMAL": normal_map_node = shader_nodes.get("Normal Map") if normal_map_node is None: + _log.debug("Creating normal map node in material %s", mat.name) normal_map_node = shader_nodes.new(type="ShaderNodeNormalMap") normal_map_node.location.x = -400 normal_map_node.location.y = y + _log.debug( + "Linking image texture %s color output to normal map %s color input", + tex_node.name, + normal_map_node.name, + ) links.new( tex_node.outputs["Color"], normal_map_node.inputs["Color"] ) + + _log.debug( + "Linking normal map %s color output to shader %s input", + normal_map_node.name, + shader_input, + ) links.new( normal_map_node.outputs["Normal"], principled_node.inputs[shader_input], ) else: + _log.debug( + "Connecting layer image texture for layer %s to shader input %s", + layer, + shader_input, + ) links.new( tex_node.outputs["Color"], principled_node.inputs[shader_input] )