diff --git a/src/bonsai/bonsai/bim/module/debug/operator.py b/src/bonsai/bonsai/bim/module/debug/operator.py index 8aa85481e0..6248a36e3d 100644 --- a/src/bonsai/bonsai/bim/module/debug/operator.py +++ b/src/bonsai/bonsai/bim/module/debug/operator.py @@ -18,12 +18,14 @@ import contextlib import io +import itertools import logging import os import platform import random import subprocess import sys +import threading import time from collections import defaultdict from pathlib import Path @@ -929,6 +931,49 @@ class PipInstall(bpy.types.Operator): return {"FINISHED"} +class _ConsoleSpinner: + """Animate a spinner on the real stdout while a blocking call runs on the main thread. + + Writes to ``sys.__stdout__`` so it isn't swallowed by ``contextlib.redirect_stdout()``, + which the drawing search uses to silence ``create_drawing``'s own output. The animation + runs on a daemon thread that only touches stdout (never bpy data), so it's safe while a + synchronous ``bpy.ops`` call blocks the main thread. + """ + + def __init__(self, message: str = "Working"): + self.message = message + self._stop = threading.Event() + self._thread: Union[threading.Thread, None] = None + self._start_time = 0.0 + + def __enter__(self) -> "_ConsoleSpinner": + self._start_time = time.time() + if sys.__stdout__ is not None: + self._thread = threading.Thread(target=self._spin, daemon=True) + self._thread.start() + return self + + def _spin(self) -> None: + out = sys.__stdout__ + assert out is not None + for frame in itertools.cycle("|/-\\"): + if self._stop.wait(0.1): + break + elapsed = time.time() - self._start_time + out.write(f"\r {frame} {self.message} ({elapsed:0.0f}s) ") + out.flush() + + def __exit__(self, *args: object) -> None: + self._stop.set() + if self._thread is not None: + self._thread.join() + out = sys.__stdout__ + if out is not None: + # Clear the spinner line so it doesn't linger before the next print. + out.write("\r" + " " * (len(self.message) + 24) + "\r") + out.flush() + + class DebugActiveDrawing(bpy.types.Operator): bl_idname = "bim.debug_active_drawing" bl_label = "Search Active Drawing For Failing Elements" @@ -967,7 +1012,8 @@ class DebugActiveDrawing(bpy.types.Operator): def elem_label(e: ifcopenshell.entity_instance) -> str: name = getattr(e, "Name", None) or "?" - return f"#{e.id()} {e.is_a()} '{name}'" + guid = getattr(e, "GlobalId", None) or "?" + return f"#{e.id()} {e.is_a()} '{name}' ({guid})" # run create drawing with sync for once # to make sure everything is actually in sync @@ -985,6 +1031,33 @@ class DebugActiveDrawing(bpy.types.Operator): pset = tool.Pset.get_element_pset(drawing, "EPset_Drawing") failing_elements: list[ifcopenshell.entity_instance] = [] + # Figure out which generation stage actually reproduces the failure so the + # bisection below can run ONLY that stage. The three stages (underlay, linework, + # annotation) produce independent SVGs, and re-running the expensive underlay/ + # linework stages on every bisection step is what makes this operator slow -- + # a single full create_drawing can take ~1 minute. Isolating the failing stage + # can cut each iteration (and thus the whole search) by more than half. + STAGES = ("underlay", "linework", "annotation") + + def create_drawing_fails(**stage_toggles: bool) -> bool: + try: + with _ConsoleSpinner("Isolating failing stage"), contextlib.redirect_stdout(io.StringIO()): + bpy.ops.bim.create_drawing(sync=False, **stage_toggles) + return False + except Exception: + return True + + # Default: run everything (used if we can't isolate a single failing stage). + active_stages = {f"should_generate_{s}": True for s in STAGES} + for stage in ("annotation", "linework", "underlay"): + only_stage = {f"should_generate_{s}": (s == stage) for s in STAGES} + if create_drawing_fails(**only_stage): + active_stages = only_stage + print(f"{CYAN}Failure reproduces in the '{stage}' stage -- bisecting with only that stage.{END}") + break + else: + print(f"{CYAN}Could not isolate a single failing stage -- bisecting with all stages (slower).{END}") + def drawing_fails_to_load(chunk_to_include: set[ifcopenshell.entity_instance]) -> bool: current_elements = all_elements - chunk_to_include excluded_guids = ", ".join([e.GlobalId for e in current_elements if hasattr(e, "GlobalId")]) @@ -993,8 +1066,10 @@ class DebugActiveDrawing(bpy.types.Operator): ifcopenshell.api.pset.edit_pset(ifc_file, pset=pset, properties={"Exclude": new_exclude}) try: - with contextlib.redirect_stdout(io.StringIO()): - bpy.ops.bim.create_drawing(sync=False) + with _ConsoleSpinner(f"Testing {len(chunk_to_include)} element(s)"), contextlib.redirect_stdout( + io.StringIO() + ): + bpy.ops.bim.create_drawing(sync=False, **active_stages) failed = False except Exception: failed = True diff --git a/src/bonsai/bonsai/bim/module/drawing/operator.py b/src/bonsai/bonsai/bim/module/drawing/operator.py index d6594364bf..e4a761952f 100644 --- a/src/bonsai/bonsai/bim/module/drawing/operator.py +++ b/src/bonsai/bonsai/bim/module/drawing/operator.py @@ -24,6 +24,7 @@ import os import shutil import subprocess import time +import traceback from math import radians from pathlib import Path from timeit import default_timer as timer @@ -261,11 +262,19 @@ class CreateDrawing(bpy.types.Operator): description="Could save some time if you're sure IFC and current Blender session are already in sync", default=True, ) + # Stage toggles, mainly for bim.debug_active_drawing so it can reproduce a failure + # by running only the culprit stage instead of the full (slow) generation each time. + should_generate_underlay: bpy.props.BoolProperty(name="Generate Underlay", default=True, options={"SKIP_SAVE"}) + should_generate_linework: bpy.props.BoolProperty(name="Generate Linework", default=True, options={"SKIP_SAVE"}) + should_generate_annotation: bpy.props.BoolProperty(name="Generate Annotation", default=True, options={"SKIP_SAVE"}) if TYPE_CHECKING: print_all: bool open_viewer: bool sync: bool + should_generate_underlay: bool + should_generate_linework: bool + should_generate_annotation: bool drawing_name: str is_manifold_cache: dict[str, bool] @@ -298,6 +307,23 @@ class CreateDrawing(bpy.types.Operator): return self.execute(context) def execute(self, context): + try: + return self._execute(context) + except Exception: + # Print the full traceback so developers (and `bim.debug_active_drawing`, + # which bisects the drawing to find the offending element) still get it. + traceback.print_exc() + drawing_name = getattr(self, "drawing_name", None) or "?" + self.report( + {"ERROR"}, + f"Failed to create drawing '{drawing_name}'. This is usually caused by a corrupt or " + "out-of-bounds element in the drawing (e.g. an annotation with a runaway coordinate). " + "Run Debug > 'Search Active Drawing For Failing Elements' (bpy.ops.bim.debug_active_drawing) " + "to locate the offending element.", + ) + return {"CANCELLED"} + + def _execute(self, context): self.props = tool.Drawing.get_document_props() assert context.scene and context.scene.camera @@ -356,7 +382,9 @@ class CreateDrawing(bpy.types.Operator): annotation_svg = None with profile("Generate underlay"): - if ifcopenshell.util.element.get_pset(self.drawing, "EPset_Drawing", "HasUnderlay"): + if self.should_generate_underlay and ifcopenshell.util.element.get_pset( + self.drawing, "EPset_Drawing", "HasUnderlay" + ): drawing_style = self.cprops.get_active_drawing_style() if not drawing_style: self.report( @@ -384,16 +412,14 @@ class CreateDrawing(bpy.types.Operator): underlay_svg = self.generate_underlay(context) with profile("Generate linework"): - if tool.Drawing.is_camera_orthographic(): + if self.should_generate_linework and tool.Drawing.is_camera_orthographic(): if self.cprops.linework_mode == "OPENCASCADE": linework_svg = self.generate_linework(context) elif self.cprops.linework_mode == "FREESTYLE": linework_svg = self.generate_freestyle_linework(context) - elif self.cprops.linework_mode == "FREESTYLE": - linework_svg = self.generate_freestyle_linework(context) with profile("Generate annotation"): - if tool.Drawing.is_camera_orthographic(): + if self.should_generate_annotation and tool.Drawing.is_camera_orthographic(): annotation_svg = self.generate_annotation(context) with profile("Combine SVG layers"):