From 4059ce138265bc10796a6c4debd8c8ba49338e28 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 08:57:36 -0800 Subject: [PATCH 1/7] Add stopwatch class to utils --- pretext/utils.py | 28 ++++++++++++++++++++++++++++ 1 file changed, 28 insertions(+) diff --git a/pretext/utils.py b/pretext/utils.py index 602b5faf..eca2211a 100644 --- a/pretext/utils.py +++ b/pretext/utils.py @@ -12,6 +12,7 @@ import socketserver import socket import subprocess +import time as time import logging import logging.handlers import psutil @@ -1104,3 +1105,30 @@ def rs_methods( f"PTX-BUG: Format {format} not recognized for running ext_rs_methods. Something is wrong with the pretext script." ) return None + + +class Stopwatch: + """A simple stopwatch class for measuring elapsed time.""" + + """print_log set to false disables logging of elapsed time """ + + def __init__(self, name: str = "", print_log: bool = True): + self.name = name + self.print_log = print_log + self.start_time = time.time() + self.last_log_time = self.start_time + + def reset(self): + """Reset the log timer to the current time.""" + self.last_log_time = time.time() + + def log(self, timepoint_description: str = ""): + """Print a log message with the elapsed time since the last log event.""" + if self.print_log: + cur_time = time.time() + elapsed_time = cur_time - self.start_time + since_last_log_time = cur_time - self.last_log_time + self.reset() + log.debug( + f"** Timing report from {self.name}: {timepoint_description}, {since_last_log_time:.2f}s since last watch reset. {elapsed_time:.2f}s total elapsed time." + ) From 12a6fdb7dd621ef9407c1ddcab28bc6618e23351 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 08:59:13 -0800 Subject: [PATCH 2/7] Measure project parse time --- pretext/cli.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/pretext/cli.py b/pretext/cli.py index a7b04723..60e2cfd7 100644 --- a/pretext/cli.py +++ b/pretext/cli.py @@ -112,6 +112,9 @@ def main(ctx: click.Context, targets: bool) -> None: Use the `--help` option on any CLI command to learn more, for example, `pretext build --help`. """ + time_logger = utils.Stopwatch("core ", True) + time_logger.log("core started") + # the targets option just lists targets in the current project if targets: if (pp := utils.project_path()) is not None: @@ -136,7 +139,9 @@ def main(ctx: click.Context, targets: bool) -> None: return # In all other cases we need to know whether we are in a directory for a project. if (pp := utils.project_path()) is not None: + time_logger.log("starting project parse") project = Project.parse(pp) + time_logger.log("project parsed") log.info(f"PreTeXt project found in `{utils.project_path()}`.") logger.add_log_file_handler(pp / "logs") From ad68bb6004b3b6434de2ef536112e95fdbcb1e33 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 08:35:16 -0800 Subject: [PATCH 3/7] Don't always inspect source for Runestone target --- pretext/project/__init__.py | 26 +++----------------------- 1 file changed, 3 insertions(+), 23 deletions(-) diff --git a/pretext/project/__init__.py b/pretext/project/__init__.py index d9bad097..931b60f0 100644 --- a/pretext/project/__init__.py +++ b/pretext/project/__init__.py @@ -368,29 +368,9 @@ def post_validate(self) -> None: if server.name not in self_server_names: self.server.append(server) - # For the Runestone format, determine the ``, which specifies the `output_dir`. - if self.format == Format.HTML and self.platform == Platform.RUNESTONE: - # We expect `d_list == ["document-id contents here"]`. - d_list = self.source_element().xpath("/pretext/docinfo/document-id/text()") - if isinstance(d_list, list): - if len(d_list) != 1: - raise ValueError( - "Only one `document-id` tag is allowed in a PreTeXt document." - ) - # NB as of 2025-04-08, we are no longer setting the output directory automatically for - # Runestone targets. This must be managed by the project.ptx file or by a client script. - # The commented code below is how we used to do this. - - # d = d_list[0] - # assert isinstance(d, str) - # # Use the correct number of `../` to undo the project's `output-dir`, so the output from the build is located in the correct directory of `published/document-id`. - # self.output_dir = Path( - # f"{'../'*len(self._project.output_dir.parents)}published/{d}" - # ) - else: - raise ValueError( - "The `document-id` tag must be defined for the Runestone format." - ) + # NB as of 2025-04-08, we are no longer setting the output directory automatically for + # Runestone targets. This must be managed by the project.ptx file or by a client script. + # Check history here for how that was done. def source_abspath(self) -> Path: return self._project.source_abspath() / self.source From 0e7f3ef775f85baceee83ea0b11d70c7ea8abbc7 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 09:33:25 -0800 Subject: [PATCH 4/7] Measure target build time --- pretext/project/__init__.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/pretext/project/__init__.py b/pretext/project/__init__.py index 931b60f0..24c270b3 100644 --- a/pretext/project/__init__.py +++ b/pretext/project/__init__.py @@ -661,13 +661,19 @@ def build( # Add cli.version to stringparams. Use only the major and minor version numbers. self.stringparams["cli.version"] = VERSION[: VERSION.rfind(".")] + time_logger = utils.Stopwatch("Target::build()", True) + time_logger.log("build started") + # Check for xml syntax errors and quit if xml invalid: if not utils.xml_syntax_is_valid(self.source_abspath()): raise RuntimeError("XML syntax for source file is invalid") if not utils.xml_syntax_is_valid(self.publication_abspath(), "publication"): raise RuntimeError("XML syntax for publication file is invalid") + time_logger.log("XML syntax validated") + # Validate xml against schema; continue with warning if invalid: utils.xml_source_validates_against_schema(self.source_abspath()) + time_logger.log("source validated against schema") # Clean output upon request if clean: @@ -678,6 +684,7 @@ def build( # verify that a webwork_representations.xml file exists if it is needed; generated if needed. self.ensure_webwork_reps() + time_logger.log("webwork representations ensured") # Generate needed assets unless requested not to. if generate: @@ -734,7 +741,9 @@ def build( log.warning( "The platform host in the publication file is not set to runestone. Since the requested target has @platform='runestone', we will override the publication file's platform host." ) + time_logger.log("building HTML") utils.ensure_css_node_modules() + time_logger.log("node set") core.html( xml=self.source_abspath(), pub_file=self.publication_abspath().as_posix(), @@ -746,6 +755,7 @@ def build( dest_dir=self.output_dir_abspath().as_posix(), ext_rs_methods=utils.rs_methods, ) + time_logger.log("done building HTML") if self.platform != Platform.RUNESTONE: # On non-runestone builds, we try to create a codechat mapping for authors. try: @@ -754,6 +764,7 @@ def build( self._project.abspath(), self.output_dir_abspath().as_posix(), ) + time_logger.log("done mapping codechat") except Exception as e: log.warning( "Failed to map codechat path to xml id; codechat will not work." From bdb7d5e40a63b2c6d014ee58a4145095056aaa76 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 09:33:02 -0800 Subject: [PATCH 5/7] Cache results of Target.source_element() --- pretext/project/__init__.py | 23 ++++++++++++++++------- 1 file changed, 16 insertions(+), 7 deletions(-) diff --git a/pretext/project/__init__.py b/pretext/project/__init__.py index 24c270b3..842d45fe 100644 --- a/pretext/project/__init__.py +++ b/pretext/project/__init__.py @@ -128,6 +128,8 @@ class Target(pxml.BaseXmlModel, tag="target", search_mode=SearchMode.UNORDERED): # # A path to the root source for this target, relative to the project's `source` path. source: Path = pxml.attr(default=Path("main.ptx")) + # Cache of assembled source element. + _source_element: t.Optional[ET._Element] = None # A path to the publication file for this target, relative to the project's `publication` path. This is mostly validated by `post_validate`. publication: Path = pxml.attr(default=None) latex_engine: LatexEngine = pxml.attr( @@ -388,14 +390,21 @@ def original_source_element(self) -> ET._Element: def source_element(self) -> ET._Element: """ Returns the root element for the assembled source, after processing with the "version-only" assembly. + Caches the result for future calls. """ - assembled = core.assembly_internal( - xml=self.source_abspath(), - pub_file=self.publication_abspath().as_posix(), - stringparams=self.stringparams.copy(), - method="version", - ) - return assembled.getroot() + if self._source_element is None: + log.debug( + f"Parsing source element for target {self.name}", + ) + self._source_element = core.assembly_internal( + xml=self.source_abspath(), + pub_file=self.publication_abspath().as_posix(), + stringparams=self.stringparams.copy(), + method="version", + ) + else: + log.debug(f"Using cached source_element for target {self.name}") + return self._source_element.getroot() def publication_abspath(self) -> Path: return self._project.publication_abspath() / self.publication From 77d99d59162b15a680cb52e589cbc796343d230d Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 09:38:30 -0800 Subject: [PATCH 6/7] Rely on Target.source_element for XML syntax validation --- pretext/project/__init__.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/pretext/project/__init__.py b/pretext/project/__init__.py index 842d45fe..3657642b 100644 --- a/pretext/project/__init__.py +++ b/pretext/project/__init__.py @@ -674,7 +674,11 @@ def build( time_logger.log("build started") # Check for xml syntax errors and quit if xml invalid: - if not utils.xml_syntax_is_valid(self.source_abspath()): + try: + # Access the source_element to trigger assembly if it hasn't been done yet. + self.source_element() + except Exception as e: + log.error(f"Error assembling source file: {e}") raise RuntimeError("XML syntax for source file is invalid") if not utils.xml_syntax_is_valid(self.publication_abspath(), "publication"): raise RuntimeError("XML syntax for publication file is invalid") From 25aa3bc3486302f40c81a52b8be0bc0dba5ae474 Mon Sep 17 00:00:00 2001 From: Andrew Scholer Date: Wed, 10 Dec 2025 08:44:39 -0800 Subject: [PATCH 7/7] Schema validation reuses existing ETree --- pretext/project/__init__.py | 2 +- pretext/utils.py | 8 ++------ 2 files changed, 3 insertions(+), 7 deletions(-) diff --git a/pretext/project/__init__.py b/pretext/project/__init__.py index 3657642b..d9ea5266 100644 --- a/pretext/project/__init__.py +++ b/pretext/project/__init__.py @@ -685,7 +685,7 @@ def build( time_logger.log("XML syntax validated") # Validate xml against schema; continue with warning if invalid: - utils.xml_source_validates_against_schema(self.source_abspath()) + utils.xml_validates_against_schema(self.source_element()) time_logger.log("source validated against schema") # Clean output upon request diff --git a/pretext/utils.py b/pretext/utils.py index eca2211a..d55a6b3b 100644 --- a/pretext/utils.py +++ b/pretext/utils.py @@ -204,17 +204,13 @@ def xml_syntax_is_valid(xmlfile: Path, root_tag: str = "pretext") -> bool: return True -def xml_source_validates_against_schema(xmlfile: Path) -> bool: +def xml_validates_against_schema(etree: ET) -> bool: # get path to RelaxNG schema file: schemarngfile = resources.resource_base_path() / "core" / "schema" / "pretext.rng" # Open schemafile for validation: relaxng = ET.RelaxNG(file=schemarngfile) - # Parse xml file: - source_xml = ET.parse(xmlfile) - source_xml.xinclude() - # just for testing # ---------------- # relaxng.validate(source_xml) @@ -223,7 +219,7 @@ def xml_source_validates_against_schema(xmlfile: Path) -> bool: # validate against schema try: - relaxng.assertValid(source_xml) + relaxng.assertValid(etree) log.info("PreTeXt source passed schema validation.") except ET.DocumentInvalid as err: log.debug(