Create debug output for execution time per stage and not found sounds

created debug output for sounds not found on exporting stage
and for execution time for each stage

copying.md

@@ -148,6 +148,7 @@ _the openage authors_ are:
 | Zoltán Ács                  | zoli111                     | acszoltan111 à gmail dawt com                     |
 | Trevor Slocum               | tslocum                     | trevor à rocket9labs dawt com                     |
 | Munawar Hafiz               | munahaf                     | munawar dawt hafiz à gmail dawt com               |
+| Fábio Barkoski              | fabiobarkoski               | fabiobarkoskii à gmail dawt com               |
 
 If you're a first-time committer, add yourself to the above list. This is not
 just for legal reasons, but also to keep an overview of all those nicknames.

openage/convert/processor/export/media_exporter.py

@@ -80,6 +80,8 @@ def export(
                 info("-- Exporting graphics files...")
 
             elif media_type is MediaType.SOUNDS:
+                kwargs["loglevel"] = args.debug_info
+                kwargs["debugdir"] = args.debugdir
                 export_func = MediaExporter._export_sound
                 info("-- Exporting sound files...")
 
@@ -225,6 +227,10 @@ def _export_graphics(
             from ...value_object.read.media.sld import SLD
             image = SLD(media_file.read())
 
+        else:
+            raise SyntaxError(f"Source file {source_file.name} has an unrecognized extension: "
+                              f"{source_file.suffix.lower()}")
+
         packer_cache = None
         compr_cache = None
         if cache_info:
@@ -284,6 +290,7 @@ def _export_sound(
         export_request: MediaExportRequest,
         sourcedir: Path,
         exportdir: Path,
+        **kwargs
     ) -> None:
         """
         Convert and export a sound file.
@@ -307,7 +314,7 @@ def _export_sound(
                 media_file = infile.read()
 
         else:
-            # TODO: Filter files that do not exist out sooner
+            debug_info.debug_not_found_sounds(kwargs["debugdir"], kwargs["loglevel"], source_file)
             return
 
         from ...service.export.opus.opusenc import encode
@@ -466,6 +473,10 @@ def _get_media_cache(
             from ...value_object.read.media.sld import SLD
             image = SLD(media_file.read())
 
+        else:
+            raise SyntaxError(f"Source file {source_file.name} has an unrecognized extension: "
+                              f"{source_file.suffix.lower()}")
+
         from .texture_merge import merge_frames
         texture = Texture(image, palettes)
         merge_frames(texture)

openage/convert/service/debug_info.py

@@ -677,3 +677,47 @@ def debug_media_cache(
 
     with logfile.open("w") as log:
         log.write(logtext)
+
+
+def debug_execution_time(debugdir: Directory, loglevel: int, stages_time: dict[str, float]) -> None:
+    """
+    Create debug output for execution time for each stage
+
+    :param debugdir: Output directory for the debug info.
+    :type debugdir: Directory
+    :param loglevel: Determines how detailed the output is.
+    :type loglevel: int
+    :param stages_time: Dict with execution time for each stage.
+    :type stages_time: dict
+    """
+    if loglevel < 1:
+        return
+
+    logfile = debugdir["execution_time"]
+    logtext = "".join(f"{k}: {v}\n" for k, v in stages_time.items())
+
+    with logfile.open("w") as log:
+        log.write(logtext)
+
+
+def debug_not_found_sounds(debugdir: Directory, loglevel: int, sound: Path) -> None:
+    """
+    Create debug output for execution time for each stage
+
+    :param debugdir: Output directory for the debug info.
+    :type debugdir: Directory
+    :param loglevel: Determines how detailed the output is.
+    :type loglevel: int
+    :param sound: Sound object with path and name values.
+    :type sound: Path
+    """
+    if loglevel < 6:
+        return
+
+    logfile = debugdir.joinpath("export/not_found_sounds")[sound.stem]
+
+    path = [part.decode() for part in sound.parts]
+    logtext = f"name: {sound.name}\npath: {'/'.join(path)}"
+
+    with logfile.open("w") as log:
+        log.write(logtext)

openage/convert/tool/driver.py

@@ -8,13 +8,14 @@
 """
 from __future__ import annotations
 import typing
+import timeit
 
 
 from ...log import info, dbg
 from ..processor.export.modpack_exporter import ModpackExporter
 from ..service.debug_info import debug_gamedata_format
 from ..service.debug_info import debug_string_resources, \
-    debug_registered_graphics, debug_modpack
+    debug_registered_graphics, debug_modpack, debug_execution_time
 from ..service.init.changelog import (ASSET_VERSION)
 from ..service.read.gamedata import get_gamespec
 from ..service.read.palette import get_palettes
@@ -64,7 +65,7 @@ def convert_metadata(args: Namespace) -> None:
     gamedata_path = args.targetdir.joinpath('gamedata')
     if gamedata_path.exists():
         gamedata_path.removerecursive()
-
+    read_start = timeit.default_timer()
     # Read .dat
     debug_gamedata_format(args.debugdir, args.debug_info, args.game_version)
     gamespec = get_gamespec(args.srcdir, args.game_version, not args.flag("no_pickle_cache"))
@@ -84,16 +85,31 @@ def convert_metadata(args: Namespace) -> None:
     existing_graphics = get_existing_graphics(args)
     debug_registered_graphics(args.debugdir, args.debug_info, existing_graphics)
 
+    read_end = timeit.default_timer()
+
+    conversion_start = timeit.default_timer()
     # Convert
     modpacks = args.converter.convert(gamespec,
                                       args,
                                       string_resources,
                                       existing_graphics)
 
+    conversion_end = timeit.default_timer()
+
+    export_start = timeit.default_timer()
     for modpack in modpacks:
         ModpackExporter.export(modpack, args)
         debug_modpack(args.debugdir, args.debug_info, modpack)
 
+    export_end = timeit.default_timer()
+
+    stages_time = {
+        "read": read_end - read_start,
+        "convert": conversion_end - conversion_start,
+        "export": export_end - export_start,
+    }
+    debug_execution_time(args.debugdir, args.debug_info, stages_time)
+
     # TODO: player palettes
     # player_palette = PlayerColorTable(palette)
     # data_formatter.add_data(player_palette.dump("player_palette"))