From 98d54800241a1536ec452073f5a8402cdcfe68d0 Mon Sep 17 00:00:00 2001 From: Adam Johnson Date: Sun, 11 Jun 2017 20:35:40 -0400 Subject: [PATCH] Implement rudimentary progress reporter A common complaint that I have heard (and have nyself) is that there is little indication of what Korman is doing in the background. In PyPRP, the raw export log was dumped to the console, and many liked to watch it travel by as an indicator of progress. As such, I have implemented a rudimentary progress monitor that outputs to the console into the export logger. Unfortunately, there is no "easy" way to show progress in the Blender UI currently. Korman makes the assumption that nothing will touch Blender's context while it is executing. Attempts to mvoe the exporter into a background thread have all resulted in spectacular failures. So, this will have to do for now. --- korman/exporter/convert.py | 52 ++++++++++++--- korman/exporter/etlight.py | 46 ++++++++++---- korman/exporter/logger.py | 123 +++++++++++++++++++++++++++++++----- korman/exporter/material.py | 5 ++ korman/exporter/mesh.py | 13 ++-- 5 files changed, 196 insertions(+), 43 deletions(-) diff --git a/korman/exporter/convert.py b/korman/exporter/convert.py index 9416588..81eb6b5 100644 --- a/korman/exporter/convert.py +++ b/korman/exporter/convert.py @@ -43,9 +43,6 @@ class Exporter: def run(self): with logger.ExportLogger(self._op.filepath) as self.report: - self.report.msg("Exporting '{}.age'", self.age_name) - start = time.perf_counter() - # Step 0: Init export resmgr and stuff self.mgr = manager.ExportManager(self) self.mesh = mesh.MeshConverter(self) @@ -54,6 +51,18 @@ class Exporter: self.animation = animation.AnimationConverter(self) self.sumfile = sumfile.SumFile() + # Step 0.9: Init the progress mgr + self.report.progress_add_step("Collecting Objects") + self.report.progress_add_step("Harvesting Actors") + if self._op.bake_lighting: + etlight.LightBaker.add_progress_steps(self.report) + self.report.progress_add_step("Exporting Scene Objects") + self.report.progress_add_step("Exporting Logic Nodes") + self.report.progress_add_step("Finalizing Plasma Logic") + self.report.progress_add_step("Exporting Textures") + self.report.progress_add_step("Composing Geometry") + self.report.progress_start("EXPORTING AGE") + # Step 1: Create the age info and the pages self._export_age_info() @@ -90,17 +99,18 @@ class Exporter: # Step 5.1: Save out the export report. # If the export fails and this doesn't save, we have bigger problems than # these little warnings and notices. + self.report.progress_end() self.report.save() - # And finally we crow about how awesomely fast we are... - end = time.perf_counter() - self.report.msg("\nExported {}.age in {:.2f} seconds", self.age_name, end-start) - def _bake_static_lighting(self): oven = etlight.LightBaker(self.report) oven.bake_static_lighting(self._objects) def _collect_objects(self): + self.report.progress_advance() + self.report.progress_range = len(bpy.data.objects) + inc_progress = self.report.progress_increment + # Grab a naive listing of enabled pages age = bpy.context.scene.world.plasma_age pages_enabled = frozenset([page.name for page in age.pages if page.enabled]) @@ -135,6 +145,7 @@ class Exporter: self._objects.append(obj) elif page not in all_pages: error.add(page, obj.name) + inc_progress() error.raise_if_error() def _export_age_info(self): @@ -186,7 +197,11 @@ class Exporter: return so.coord.object def _export_scene_objects(self): + self.report.progress_advance() + self.report.progress_range = len(self._objects) + inc_progress = self.report.progress_increment log_msg = self.report.msg + for bl_obj in self._objects: log_msg("\n[SceneObject '{}']".format(bl_obj.name)) @@ -213,6 +228,7 @@ class Exporter: for mod in bl_obj.plasma_modifiers.modifiers: log_msg("Exporting '{}' modifier".format(mod.bl_label), indent=1) mod.export(self, bl_obj, sceneobject) + inc_progress() def _export_empty_blobj(self, so, bo): # We don't need to do anything here. This function just makes sure we don't error out @@ -230,18 +246,30 @@ class Exporter: self.report.msg("No material(s) on the ObData, so no drawables", indent=1) def _export_referenced_node_trees(self): + self.report.progress_advance() + self.report.progress_range = len(self.want_node_trees) + inc_progress = self.report.progress_increment + self.report.msg("\nChecking Logic Trees...") - need_to_export = ((name, bo, so) for name, (bo, so) in self.want_node_trees.items() - if name not in self.node_trees_exported) + need_to_export = [(name, bo, so) for name, (bo, so) in self.want_node_trees.items() + if name not in self.node_trees_exported] + self.report.progress_value = len(self.want_node_trees) - len(need_to_export) + for tree, bo, so in need_to_export: self.report.msg("NodeTree '{}'", tree, indent=1) bpy.data.node_groups[tree].export(self, bo, so) + inc_progress() def _harvest_actors(self): + self.report.progress_advance() + self.report.progress_range = len(self._objects) + len(bpy.data.textures) + inc_progress = self.report.progress_increment + for bl_obj in self._objects: for mod in bl_obj.plasma_modifiers.modifiers: if mod.enabled: self.actors.update(mod.harvest_actors()) + inc_progress() # This is a little hacky, but it's an edge case... I guess? # We MUST have CoordinateInterfaces for EnvironmentMaps (DCMs, bah) @@ -251,6 +279,7 @@ class Exporter: viewpt = envmap.viewpoint_object if viewpt is not None: self.actors.add(viewpt.name) + inc_progress() def has_coordiface(self, bo): if bo.type in {"CAMERA", "EMPTY", "LAMP"}: @@ -269,6 +298,10 @@ class Exporter: return False def _post_process_scene_objects(self): + self.report.progress_advance() + self.report.progress_range = len(self._objects) + inc_progress = self.report.progress_increment + mat_mgr = self.mesh.material for bl_obj in self._objects: sceneobject = self.mgr.find_object(plSceneObject, bl=bl_obj) @@ -291,3 +324,4 @@ class Exporter: proc = getattr(mod, "post_export", None) if proc is not None: proc(self, bl_obj, sceneobject) + inc_progress() diff --git a/korman/exporter/etlight.py b/korman/exporter/etlight.py index c938520..e3c4d98 100644 --- a/korman/exporter/etlight.py +++ b/korman/exporter/etlight.py @@ -27,9 +27,25 @@ class LightBaker: def __init__(self, report=None): self._lightgroups = {} - self._report = report if report is not None else ExportLogger() + if report is None: + self._report = ExportLogger() + self.add_progress_steps(self._report) + self._report.progress_start("PREVIEWING LIGHTING") + self._own_report = True + else: + self._report = report + self._own_report = False self._uvtexs = {} + def __del__(self): + if self._own_report: + self._report.progress_end() + + @staticmethod + def add_progress_steps(report): + report.progress_add_step("Searching for Bahro") + report.progress_add_step("Baking Static Lighting") + def _apply_render_settings(self, toggle, vcols): render = bpy.context.scene.render toggle.track(render, "use_textures", False) @@ -79,11 +95,15 @@ class LightBaker: return result def _bake_static_lighting(self, bake, toggle): + inc_progress = self._report.progress_increment + # Step 0.9: Make all layers visible. # This prevents context operators from phailing. bpy.context.scene.layers = (True,) * _NUM_RENDER_LAYERS # Step 1: Prepare... Apply UVs, etc, etc, etc + self._report.progress_advance() + self._report.progress_range = len(bake) self._report.msg("Preparing to bake...", indent=1) for key in bake.keys(): if key[0] == "lightmap": @@ -103,21 +123,23 @@ class LightBaker: bake[key].pop(i) else: raise RuntimeError(key[0]) + inc_progress() self._report.msg(" ...") # Step 2: BAKE! + self._report.progress_advance() + self._report.progress_range = len(bake) for key, value in bake.items(): - if not value: - continue - - if key[0] == "lightmap": - self._report.msg("{} Lightmap(s) [H:{:X}]", len(value), hash(key), indent=1) - self._bake_lightmaps(value, key[1:]) - elif key[0] == "vcol": - self._report.msg("{} Crap Light(s)", len(value), indent=1) - self._bake_vcols(value) - else: - raise RuntimeError(key[0]) + if value: + if key[0] == "lightmap": + self._report.msg("{} Lightmap(s) [H:{:X}]", len(value), hash(key), indent=1) + self._bake_lightmaps(value, key[1:]) + elif key[0] == "vcol": + self._report.msg("{} Crap Light(s)", len(value), indent=1) + self._bake_vcols(value) + else: + raise RuntimeError(key[0]) + inc_progress() # Return how many thingos we baked return sum(map(len, bake.values())) diff --git a/korman/exporter/logger.py b/korman/exporter/logger.py index b12d8d2..6fe3f30 100644 --- a/korman/exporter/logger.py +++ b/korman/exporter/logger.py @@ -15,21 +15,30 @@ from pathlib import Path import sys +import time + +_HEADING_SIZE = 50 class ExportLogger: def __init__(self, age_path=None): self._porting = [] self._warnings = [] - self._age_path = age_path + self._age_path = Path(age_path) if age_path is not None else None self._file = None + self._progress_steps = [] + self._step_id = -1 + self._step_max = 0 + self._step_progress = 0 + self._time_start_overall = 0 + self._time_start_step = 0 + def __enter__(self): assert self._age_path is not None # Make the log file name from the age file path -- this ensures we're not trying to write # the log file to the same directory Blender.exe is in, which might be a permission error - my_path = Path(self._age_path) - my_path = my_path.with_name("{}_export".format(my_path.stem)).with_suffix(".log") + my_path = self._age_path.with_name("{}_export".format(self._age_path.stem)).with_suffix(".log") self._file = open(str(my_path), "w") return self @@ -37,15 +46,101 @@ class ExportLogger: self._file.close() return False + def progress_add_step(self, name): + assert self._step_id == -1 + self._progress_steps.append(name) + + def progress_advance(self): + """Advances the progress bar to the next step""" + if self._step_id != -1: + self._progress_print_step(done=True) + assert self._step_id < len(self._progress_steps) + + self._step_id += 1 + self._step_max = 0 + self._step_progress = 0 + self._time_start_step = time.perf_counter() + self._progress_print_step() + + def progress_complete_step(self): + """Manually completes the current step""" + assert self._step_id != -1 + self._progress_print_step(done=True) + + def progress_end(self): + self._progress_print_step(done=True) + assert self._step_id+1 == len(self._progress_steps) + + export_time = time.perf_counter() - self._time_start_overall + if self._age_path is not None: + self.msg("\nExported '{}' in {:.2f}s", self._age_path.name, export_time) + print("\nEXPORTED '{}' IN {:.2f}s".format(self._age_path.name, export_time)) + else: + print("\nCOMPLETED IN {:.2f}s".format(export_time)) + self._progress_print_heading() + print() + + def progress_increment(self): + """Increments the progress of the current step""" + assert self._step_id != -1 + self._step_progress += 1 + if self._step_max != 0: + self._progress_print_step() + + def _progress_print_heading(self, text=None): + if text: + num_chars = len(text) + border = "-" * int((_HEADING_SIZE - (num_chars + 2)) / 2) + pad = " " if num_chars % 2 == 1 else "" + print(border, " ", pad, text, " ", border, sep="") + else: + print("-" * _HEADING_SIZE) + + def _progress_print_step(self, done=False): + if done: + stage = "DONE IN {:.2f}s".format(time.perf_counter() - self._time_start_step) + end = "\n" + else: + if self._step_max != 0: + stage = "{} of {}".format(self._step_progress, self._step_max) + else: + stage = "" + end = "\r" + print("{}\t(step {}/{}): {}".format(self._progress_steps[self._step_id], self._step_id+1, + len(self._progress_steps), stage), + end=end) + + def _progress_get_max(self): + return self._step_max + def _progress_set_max(self, value): + assert self._step_id != -1 + self._step_max = value + self._progress_print_step() + progress_range = property(_progress_get_max, _progress_set_max) + + def progress_start(self, action): + if self._age_path is not None: + self.msg("Exporting '{}'", self._age_path.name) + self._progress_print_heading("Korman") + self._progress_print_heading(action) + self._time_start_overall = time.perf_counter() + + def _progress_get_current(self): + return self._step_progress + def _progress_set_current(self, value): + assert self._step_id != -1 + self._step_progress = value + if self._step_max != 0: + self._progress_print_step() + progress_value = property(_progress_get_current, _progress_set_current) + def msg(self, *args, **kwargs): assert args - indent = kwargs.get("indent", 0) - msg = "{}{}".format(" " * indent, args[0]) - if len(args) > 1: - msg = msg.format(*args[1:], **kwargs) - if self._file is None: - print(msg) - else: + if self._file is not None: + indent = kwargs.get("indent", 0) + msg = "{}{}".format(" " * indent, args[0]) + if len(args) > 1: + msg = msg.format(*args[1:], **kwargs) self._file.writelines((msg, "\n")) def port(self, *args, **kwargs): @@ -54,9 +149,7 @@ class ExportLogger: msg = "{}PORTING: {}".format(" " * indent, args[0]) if len(args) > 1: msg = msg.format(*args[1:], **kwargs) - if self._file is None: - print(msg) - else: + if self._file is not None: self._file.writelines((msg, "\n")) self._porting.append(args[0]) @@ -70,8 +163,6 @@ class ExportLogger: msg = "{}WARNING: {}".format(" " * indent, args[0]) if len(args) > 1: msg = msg.format(*args[1:], **kwargs) - if self._file is None: - print(msg) - else: + if self._file is not None: self._file.writelines((msg, "\n")) self._warnings.append(args[0]) diff --git a/korman/exporter/material.py b/korman/exporter/material.py index 43d769b..f66f52d 100644 --- a/korman/exporter/material.py +++ b/korman/exporter/material.py @@ -618,6 +618,10 @@ class MaterialConverter: self._pending[key].append(layer.key) def finalize(self): + self._report.progress_advance() + self._report.progress_range = len(self._pending) + inc_progress = self._report.progress_increment + for key, layers in self._pending.items(): name = str(key) self._report.msg("\n[Mipmap '{}']", name) @@ -683,6 +687,7 @@ class MaterialConverter: else: mipmap = pages[page] layer.object.texture = mipmap.key + inc_progress() def get_materials(self, bo): return self._obj2mat.get(bo, []) diff --git a/korman/exporter/mesh.py b/korman/exporter/mesh.py index 2aa2692..711243c 100644 --- a/korman/exporter/mesh.py +++ b/korman/exporter/mesh.py @@ -174,11 +174,15 @@ class MeshConverter: def finalize(self): """Prepares all baked Plasma geometry to be flushed to the disk""" + self._report.progress_advance() + self._report.progress_range = len(self._dspans) + inc_progress = self._report.progress_increment + log_msg = self._report.msg + log_msg("\nFinalizing Geometry") for loc in self._dspans.values(): for dspan in loc.values(): - self._report.msg("\n[DrawableSpans '{}']", dspan.key.name) - self._report.msg("Composing geometry data", indent=1) + log_msg("[DrawableSpans '{}']", dspan.key.name, indent=1) # This mega-function does a lot: # 1. Converts SourceSpans (geospans) to Icicles and bakes geometry into plGBuffers @@ -186,10 +190,7 @@ class MeshConverter: # 3. Builds the plSpaceTree # 4. Clears the SourceSpans dspan.composeGeometry(True, True) - - # Might as well say something else just to fascinate anyone who is playing along - # at home (and actually enjoys reading these lawgs) - self._report.msg("Bounds and SpaceTree in the saddle", indent=1) + inc_progress() def _export_geometry(self, bo, mesh, materials, geospans): geodata = [_GeoData(len(mesh.vertices)) for i in materials]