diff --git a/src/signaloid/benchmarking/automation/README.md b/src/signaloid/benchmarking/automation/README.md index 6c81649..51c57b2 100644 --- a/src/signaloid/benchmarking/automation/README.md +++ b/src/signaloid/benchmarking/automation/README.md @@ -326,8 +326,13 @@ output): `addDistValueTrace` `file:line` directives resolve against unoptimised debug info. Optimisation could change the traced values. To guard against that, each config is also built at `-O2` and its Ux strings are checked - (byte-for-byte) against the `-O0` ones. Any difference is reported as a - warning and does not stop the run. If a config's `-O2` build or run fails, that config is skipped and + (byte-for-byte) against the `-O0` ones. That build is compiled *without* + tracing, because the SDK forces `-O0` whenever tracing is on, so it has no + tracing database. Both sides are therefore read from the runs' stdout, where + printing an uncertain value emits its full Ux string. Any difference is + reported as a warning and does not stop the run. A config in which neither + build printed a Ux string is reported as a warning too, so a run that + verified nothing cannot be mistaken for a passing one. If a config's `-O2` build or run fails, that config is skipped and reported as failing in an `-O2 ux-string verification FAILED` summary (the run still continues). Set `TRACING_VERIFY_OPTFLAGS` to compare against a different level. diff --git a/src/signaloid/benchmarking/automation/check_traced_values_printed.py b/src/signaloid/benchmarking/automation/check_traced_values_printed.py new file mode 100644 index 0000000..87c7812 --- /dev/null +++ b/src/signaloid/benchmarking/automation/check_traced_values_printed.py @@ -0,0 +1,186 @@ +# Copyright (c) 2026, Signaloid. +# +# Permission is hereby granted, free of charge, to any person obtaining a copy +# of this software and associated documentation files (the "Software"), to +# deal in the Software without restriction, including without limitation the +# rights to use, copy, modify, merge, publish, distribute, sublicense, and/or +# sell copies of the Software, and to permit persons to whom the Software is +# furnished to do so, subject to the following conditions: +# +# The above copyright notice and this permission notice shall be included in +# all copies or substantial portions of the Software. +# +# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING +# FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER +# DEALINGS IN THE SOFTWARE. +""" +Check that every Ux string a tracing run recorded was also printed by it. + +The ``-O2`` verification compares the two builds' **stdout**, because the +verification build is compiled without tracing and so has no tracing database +(see ``compare_tracing_ux_strings``). That substitution is only sound while the +SDK prints the same bytes it stores. This module checks exactly that, against +the one run that produces both: the ``-O0`` tracing build writes its traced +values to a database *and* prints them. + +A mismatch here means the printed representation has drifted from the stored +one, which would quietly weaken the ``-O2`` check rather than break it. It is +therefore reported as a warning, and the caller continues. + +Invoked from the bash tracing layer (``get-timings.sh``) as:: + + python3 -m signaloid.benchmarking.automation.check_traced_values_printed \ + [--table TABLE] [--config SUFFIX] + +Exit status is ``0`` when every recorded value was printed, ``1`` when any was +not or when the database recorded nothing, and ``2`` when the check could not +be performed. +""" + +import argparse +import sqlite3 +import sys +from contextlib import closing + +from signaloid.benchmarking.automation.compare_tracing_ux_strings import ( + load_ux_strings, +) + +# Enough to name which traced expression is missing from stdout. +_IDENTITY_COLUMNS = ( + "Expression_DeclarationFileName", + "Expression_Name", + "Expression_DeclarationLineNumber", +) + +# A single Athens-16 value runs to several hundred characters, so reports +# truncate. See compare_tracing_ux_strings for the same reasoning. +_REPORTED_PREFIX_LENGTH = 80 + + +def load_recorded_values(db_path: str, table: str) -> dict[str, tuple[object, ...]]: + """ + Load the distinct Ux strings a tracing run wrote, with one identity each. + + Args: + db_path: Path to the tracing SQLite database. + table: Name of the traced-values table (e.g. ``TracingTable``). + + Returns: + Mapping from Ux string to the identity tuple of an expression that + produced it. One identity is kept per distinct value, which is all the + report needs to point at the offending expression. + """ + columns = ", ".join(f'"{column}"' for column in _IDENTITY_COLUMNS) + query = f'SELECT {columns}, Dist_Value FROM "{table}"' + recorded: dict[str, tuple[object, ...]] = {} + with closing(sqlite3.connect(db_path)) as connection: + for row in connection.execute(query): + recorded.setdefault(row[-1], tuple(row[:-1])) + return recorded + + +def find_unprinted_values( + db_path: str, stdout_path: str, table: str +) -> tuple[list[tuple[str, tuple[object, ...]]], int]: + """ + Find recorded Ux strings that the same run did not print. + + Args: + db_path: Path to the tracing SQLite database. + stdout_path: Captured stdout of the same run. + table: Name of the traced-values table. + + Returns: + A tuple of (unprinted values with their identities, number of distinct + values recorded). + """ + recorded = load_recorded_values(db_path, table) + printed = set(load_ux_strings(stdout_path)) + unprinted = [ + (value, identity) + for value, identity in recorded.items() + if value not in printed + ] + return unprinted, len(recorded) + + +def _format_identity(identity: tuple[object, ...]) -> str: + """Render an identity tuple as ``expr @ file:line``.""" + file_name, name, line = identity + return f"{name} @ {file_name}:{line}" + + +def main() -> int: + """ + Parse arguments, run the cross-check, and report the result. + + Returns: + ``0`` when every recorded value was printed, ``1`` when any was not or + when nothing was recorded, and ``2`` when the check could not run. + """ + parser = argparse.ArgumentParser( + description=( + "Check that every Ux string a tracing run recorded in its " + "database was also printed to stdout by that same run." + ), + ) + parser.add_argument("tracing_db", help="Tracing DB written by the -O0 run.") + parser.add_argument("stdout_path", help="Captured stdout of the same run.") + parser.add_argument( + "--table", + default="TracingTable", + help="Name of the traced-values table (default: TracingTable).", + ) + parser.add_argument( + "--config", + default=None, + help="Optional config suffix, included in messages for context.", + ) + args = parser.parse_args() + + scope = f" for config '{args.config}'" if args.config else "" + + try: + unprinted, recorded_count = find_unprinted_values( + args.tracing_db, args.stdout_path, args.table + ) + except (OSError, sqlite3.Error) as exc: + print( + f"WARNING: db-vs-stdout check{scope} could not run on " + f"{args.tracing_db} and {args.stdout_path}: {exc}", + file=sys.stderr, + ) + return 2 + + if recorded_count == 0: + print( + f"WARNING: db-vs-stdout check{scope}: the tracing run recorded no " + f"Ux strings, so nothing was cross-checked." + ) + return 1 + + if not unprinted: + print( + f"db-vs-stdout check{scope}: OK — all {recorded_count} recorded " + f"Ux string(s) also appear in the run's stdout." + ) + return 0 + + print( + f"WARNING: db-vs-stdout check{scope}: {len(unprinted)} of " + f"{recorded_count} recorded Ux string(s) were not printed by the same " + f"run. The -O2 check compares stdout, so it no longer covers these." + ) + for value, identity in unprinted: + print(f" NOT PRINTED {_format_identity(identity)}") + print(f" recorded: {value[:_REPORTED_PREFIX_LENGTH]}") + return 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/src/signaloid/benchmarking/automation/check_traced_values_printed_test.py b/src/signaloid/benchmarking/automation/check_traced_values_printed_test.py new file mode 100644 index 0000000..90c2def --- /dev/null +++ b/src/signaloid/benchmarking/automation/check_traced_values_printed_test.py @@ -0,0 +1,140 @@ +# Copyright (c) 2026, Signaloid. +# +# Permission is hereby granted, free of charge, to any person obtaining a copy +# of this software and associated documentation files (the "Software"), to +# deal in the Software without restriction, including without limitation the +# rights to use, copy, modify, merge, publish, distribute, sublicense, and/or +# sell copies of the Software, and to permit persons to whom the Software is +# furnished to do so, subject to the following conditions: +# +# The above copyright notice and this permission notice shall be included in +# all copies or substantial portions of the Software. +# +# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING +# FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER +# DEALINGS IN THE SOFTWARE. +import sqlite3 +import tempfile +import unittest +from collections.abc import Sequence +from pathlib import Path +from unittest.mock import patch + +from signaloid.benchmarking.automation.check_traced_values_printed import ( + find_unprinted_values, + main, +) + +_TABLE = "TracingTable" + +_UX_A = "Ux0400000000000000AAAA" +_UX_B = "Ux0400000000000000BBBB" + + +def _make_tracing_db(path: str, values: Sequence[str]) -> None: + """Write a tracing DB holding one traced row per entry in *values*.""" + with sqlite3.connect(path) as conn: + conn.execute( + f'CREATE TABLE "{_TABLE}" (' + "Expression_DeclarationFileName TEXT, " + "Expression_Name TEXT, " + "Expression_DeclarationLineNumber INTEGER, " + "Dist_Value TEXT)" + ) + for index, value in enumerate(values): + conn.execute( + f'INSERT INTO "{_TABLE}" VALUES (?, ?, ?, ?)', + ("main.c", f"outputVariables[{index}]", 48, value), + ) + conn.commit() + + +class TestCheckTracedValuesPrinted(unittest.TestCase): + def setUp(self) -> None: + tmp_dir = tempfile.TemporaryDirectory() + self.addCleanup(tmp_dir.cleanup) + self.tmp = Path(tmp_dir.name) + + def _db(self, name: str, values: Sequence[str]) -> str: + path = str(self.tmp / name) + _make_tracing_db(path, values) + return path + + def _stdout(self, name: str, *ux_strings: str) -> str: + path = self.tmp / name + body = "".join(f" value: 1.5{ux}\n" for ux in ux_strings) + path.write_text(f"seed: 1024\n{body}", encoding="utf-8") + return str(path) + + def test_every_recorded_value_printed(self) -> None: + unprinted, recorded = find_unprinted_values( + self._db("t.db", [_UX_A, _UX_B]), + self._stdout("run.out", _UX_A, _UX_B), + _TABLE, + ) + self.assertEqual(unprinted, []) + self.assertEqual(recorded, 2) + + def test_recorded_value_missing_from_stdout(self) -> None: + unprinted, recorded = find_unprinted_values( + self._db("t.db", [_UX_A, _UX_B]), + self._stdout("run.out", _UX_A), + _TABLE, + ) + self.assertEqual(recorded, 2) + self.assertEqual(len(unprinted), 1) + value, identity = unprinted[0] + self.assertEqual(value, _UX_B) + self.assertEqual(identity, ("main.c", "outputVariables[1]", 48)) + + def test_print_order_and_extras_do_not_matter(self) -> None: + # stdout prints the recorded values in the other order, plus a value + # that was never traced. The check is containment, not equality. + unprinted, recorded = find_unprinted_values( + self._db("t.db", [_UX_A]), + self._stdout("run.out", _UX_B, _UX_A), + _TABLE, + ) + self.assertEqual(unprinted, []) + self.assertEqual(recorded, 1) + + def test_repeated_recordings_count_once(self) -> None: + # The same value written twice is one distinct value to cross-check. + unprinted, recorded = find_unprinted_values( + self._db("t.db", [_UX_A, _UX_A]), + self._stdout("run.out", _UX_A), + _TABLE, + ) + self.assertEqual(unprinted, []) + self.assertEqual(recorded, 1) + + def test_main_returns_zero_when_all_printed(self) -> None: + argv = [self._db("t.db", [_UX_A]), self._stdout("run.out", _UX_A)] + self.assertEqual(_run_main(argv), 0) + + def test_main_returns_one_when_value_unprinted(self) -> None: + argv = [self._db("t.db", [_UX_A]), self._stdout("run.out", _UX_B)] + self.assertEqual(_run_main(argv), 1) + + def test_main_returns_one_when_nothing_recorded(self) -> None: + argv = [self._db("t.db", []), self._stdout("run.out", _UX_A)] + self.assertEqual(_run_main(argv), 1) + + def test_main_returns_two_on_missing_db(self) -> None: + missing = str(self.tmp / "does-not-exist.db") + argv = [missing, self._stdout("run.out", _UX_A)] + self.assertEqual(_run_main(argv), 2) + + +def _run_main(argv: list[str]) -> int: + """Invoke ``main`` with a patched ``sys.argv`` and return its exit code.""" + with patch("sys.argv", ["check_traced_values_printed", *argv]): + return main() + + +if __name__ == "__main__": + unittest.main() diff --git a/src/signaloid/benchmarking/automation/compare_tracing_ux_strings.py b/src/signaloid/benchmarking/automation/compare_tracing_ux_strings.py index d3900a2..ba64044 100644 --- a/src/signaloid/benchmarking/automation/compare_tracing_ux_strings.py +++ b/src/signaloid/benchmarking/automation/compare_tracing_ux_strings.py @@ -17,169 +17,133 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER # DEALINGS IN THE SOFTWARE. - """ -Compare the Ux strings produced by two tracing runs of the same application. +Compare the Ux strings two builds of the same application print to stdout. + +Optimisation must not change the values the +uncertainty machinery computes, so the two builds' Ux strings are expected to +be byte-for-byte identical. + +The values are read from each run's **stdout**, not from a tracing database. +A tracing DB only exists when the ``opt`` pass is given ``--enable-tracing``, +and the verification build is deliberately compiled without it. The SDK forces +``OPTFLAGS`` back to ``-O0`` whenever tracing is on, which would defeat the +point of building at ``-O2``. -The benchmarking tracing pass compiles the application at ``-O0`` (the -``OPTFLAGS`` default in ``Makefile.pro``) so the ``addDistValueTrace`` -``file:line`` directives resolve against unoptimised debug info. Real -deployments compile at ``-O2``. Optimisation must not change the values the -uncertainty machinery computes, so the Ux strings from the ``-O0`` and ``-O2`` -builds are expected to be byte-for-byte identical. This module loads the final -(last-written) Ux string for each traced expression from two tracing DBs and -reports any expression whose Ux string differs or is present in only one build. +Ux strings are compared in the order printed. Everything else on stdout is +ignored, which matters because ordinary output lines carry per-build paths +(the stats DB filename, for one) that legitimately differ between the two runs. Invoked from the bash tracing layer (``get-timings.sh``) as:: python3 -m signaloid.benchmarking.automation.compare_tracing_ux_strings \ - [--table TABLE] [--config SUFFIX] \ + [--config SUFFIX] \ [--baseline-label O0] [--candidate-label O2] -Exit status is ``0`` when the two builds produce identical Ux strings and -non-zero when they differ or cannot be compared. The caller treats a non-zero -status as a warning and continues. +Exit status is ``0`` when the two builds produced identical Ux strings and +non-zero when they differ, when neither printed any, or when the output could +not be read. The caller treats a non-zero status as a warning and continues. """ import argparse -import sqlite3 +import re import sys -from contextlib import closing - -from signaloid.benchmarking.config import EquivMC - -# Table holding the per-execution emulator metadata, joined to the tracing -# table on Execution_ID = Execution_Info_Table_ID (see merge_tracing_dbs). -_EXECUTION_INFO_TABLE = "Emulator_Execution_Info" - -# Columns that together identify a single traced expression under one emulator -# configuration. Two rows sharing these values are writes to the same logical -# distributional value. The last such write is the final Ux string. This -# mirrors the grouping keys _load_uxhw uses when picking the last write. -_IDENTITY_COLUMNS = ( - "Expression_DeclarationFileName", - "Expression_Subprogram", - "Expression_Name", - "Expression_DeclarationLineNumber", - "UR_Type", - "UR_Order", - "UR_Order_CoreLibrary", - "CorrelationTracking_Status", -) - - -def _load_final_ux_strings(db_path: str, table: str) -> dict[tuple[object, ...], str]: - """ - Load the final Ux string for each traced expression from a tracing DB. - Joins *table* to ``Emulator_Execution_Info`` on the execution foreign key, - orders by ``rowid`` (insertion order), and keeps the last write per - identity group. A program can write a value, jump back, and overwrite it, - so the last write (not the highest PC / assignment index) is the final - value — matching ``_load_uxhw``'s ``.last()`` semantics. +# A printed uncertain value renders as `Ux` followed by the hex encoding of its +# representation. The leading type byte varies by representation (Athens, Mercury, +# ...), so the pattern must not pin it to a particular value. +_UX_STRING_PATTERN = re.compile(r"Ux[0-9A-Fa-f]+") + +# Cap on how much of a differing Ux string to print. A single Athens-16 value +# is several hundred characters, and a systematic difference would otherwise +# flood the build log. +_REPORTED_MISMATCHES = 5 +_REPORTED_PREFIX_LENGTH = 80 + + +def load_ux_strings(path: str) -> list[str]: + """ + Read every Ux string printed by one run, in the order it was printed. Args: - db_path: Path to the tracing SQLite database. - table: Name of the traced-values table (e.g. ``TracingTable``). + path: Path to the captured stdout of a single application run. Returns: - Mapping from the identity tuple (``_IDENTITY_COLUMNS`` order) to the - last-written ``Dist_Value`` for that expression. + The Ux strings found, in print order. Non-Ux output is ignored. """ - identity_select = ", ".join(f't."{c}"' for c in _IDENTITY_COLUMNS[:4]) - exec_select = ", ".join(f'e."{c}"' for c in _IDENTITY_COLUMNS[4:]) - query = ( - f"SELECT {identity_select}, {exec_select}, t.Dist_Value " - f'FROM "{table}" t ' - f'JOIN "{_EXECUTION_INFO_TABLE}" e ' - f"ON e.Execution_ID = t.Execution_Info_Table_ID " - f"ORDER BY t.rowid" - ) - final: dict[tuple[object, ...], str] = {} - with closing(sqlite3.connect(db_path)) as connection: - for row in connection.execute(query): - key = tuple(row[: len(_IDENTITY_COLUMNS)]) - # Insertion order is preserved by ORDER BY rowid, so overwriting - # here leaves the last write as the final value. - final[key] = row[len(_IDENTITY_COLUMNS)] - return final + with open(path, encoding="utf-8", errors="replace") as stream: + return _UX_STRING_PATTERN.findall(stream.read()) class ComparisonResult: - """Outcome of comparing two tracing DBs' Ux strings.""" + """Outcome of comparing two runs' printed Ux strings.""" def __init__( self, *, matched: int, - mismatches: list[tuple[tuple[object, ...], str, str]], - only_in_baseline: list[tuple[object, ...]], - only_in_candidate: list[tuple[object, ...]], + mismatches: list[tuple[int, str, str]], + baseline_count: int, + candidate_count: int, ) -> None: self.matched = matched self.mismatches = mismatches - self.only_in_baseline = only_in_baseline - self.only_in_candidate = only_in_candidate + self.baseline_count = baseline_count + self.candidate_count = candidate_count @property def is_identical(self) -> bool: - """True when every expression matched and none was missing on a side.""" - return ( - not self.mismatches - and not self.only_in_baseline - and not self.only_in_candidate - ) + """True when both runs printed the same Ux strings in the same order.""" + return not self.mismatches and self.baseline_count == self.candidate_count + + @property + def is_empty(self) -> bool: + """ + True when neither run printed a single Ux string. + + :attr:`is_identical` is vacuously true in that case, because there is + nothing to mismatch and the two counts are equally zero. Callers must + check this first, or a run that printed nothing reads as a pass. + """ + return self.is_identical and self.matched == 0 -def compare_ux_strings( - baseline_db: str, candidate_db: str, table: str -) -> ComparisonResult: +def compare_ux_strings(baseline_stdout: str, candidate_stdout: str) -> ComparisonResult: """ - Compare the final Ux strings of two tracing DBs for the same application. + Compare the Ux strings printed by two builds of the same application. Args: - baseline_db: Path to the baseline (``-O0``) tracing DB. - candidate_db: Path to the candidate (``-O2``) tracing DB. - table: Name of the traced-values table in both DBs. + baseline_stdout: Captured stdout of the baseline (``-O0``) run. + candidate_stdout: Captured stdout of the candidate (``-O2``) run. Returns: - A :class:`ComparisonResult` describing matches, byte-level mismatches, - and expressions present in only one of the two builds. + A :class:`ComparisonResult` describing how many values matched and + which positions differed. """ - baseline = _load_final_ux_strings(baseline_db, table) - candidate = _load_final_ux_strings(candidate_db, table) + baseline = load_ux_strings(baseline_stdout) + candidate = load_ux_strings(candidate_stdout) matched = 0 - mismatches: list[tuple[tuple[object, ...], str, str]] = [] - for key, baseline_value in baseline.items(): - if key not in candidate: - continue - if candidate[key] == baseline_value: + mismatches: list[tuple[int, str, str]] = [] + for index, (baseline_value, candidate_value) in enumerate(zip(baseline, candidate)): + if baseline_value == candidate_value: matched += 1 else: - mismatches.append((key, baseline_value, candidate[key])) - - only_in_baseline = [key for key in baseline if key not in candidate] - only_in_candidate = [key for key in candidate if key not in baseline] + mismatches.append((index, baseline_value, candidate_value)) return ComparisonResult( matched=matched, mismatches=mismatches, - only_in_baseline=only_in_baseline, - only_in_candidate=only_in_candidate, + baseline_count=len(baseline), + candidate_count=len(candidate), ) -def _format_key(key: tuple[object, ...]) -> str: - """Render an identity tuple as ``expr @ file:line [UR_Type/UR_Order/...]``.""" - fields = dict(zip(_IDENTITY_COLUMNS, key)) - return ( - f'{fields["Expression_Name"]} @ ' - f'{fields["Expression_DeclarationFileName"]}:' - f'{fields["Expression_DeclarationLineNumber"]} ' - f'[{fields["UR_Type"]}/{fields["UR_Order"]}/' - f'{fields["CorrelationTracking_Status"]}]' - ) +def _abbreviate(value: str) -> str: + """Shorten a Ux string for reporting, marking it when truncated.""" + if len(value) <= _REPORTED_PREFIX_LENGTH: + return value + return f"{value[:_REPORTED_PREFIX_LENGTH]}... ({len(value)} chars)" def _report( @@ -191,54 +155,61 @@ def _report( ) -> None: """Print a human-readable summary of *result* to stdout.""" scope = f" for config '{config}'" if config else "" + + if result.is_empty: + print( + f"WARNING: ux-string check{scope}: neither the {baseline_label} " + f"nor the {candidate_label} build printed any Ux string, so " + f"nothing was verified. Check that the application prints its " + f"uncertain values." + ) + return + if result.is_identical: print( - f"ux-string check{scope}: OK — {result.matched} traced " - f"expression(s) identical between {baseline_label} and " + f"ux-string check{scope}: OK — {result.matched} printed Ux " + f"string(s) identical between {baseline_label} and " f"{candidate_label} builds." ) return print( f"WARNING: ux-string check{scope}: {baseline_label} and " - f"{candidate_label} builds produced different Ux strings " + f"{candidate_label} builds printed different Ux strings " f"({result.matched} identical, {len(result.mismatches)} differing, " - f"{len(result.only_in_baseline)} only in {baseline_label}, " - f"{len(result.only_in_candidate)} only in {candidate_label})." + f"{result.baseline_count} printed by {baseline_label}, " + f"{result.candidate_count} by {candidate_label})." ) - for key, baseline_value, candidate_value in result.mismatches: - print(f" DIFF {_format_key(key)}") - print(f" {baseline_label}: {baseline_value}") - print(f" {candidate_label}: {candidate_value}") - for key in result.only_in_baseline: - print(f" ONLY IN {baseline_label}: {_format_key(key)}") - for key in result.only_in_candidate: - print(f" ONLY IN {candidate_label}: {_format_key(key)}") + for index, baseline_value, candidate_value in result.mismatches[ + :_REPORTED_MISMATCHES + ]: + print(f" DIFF at printed value #{index}") + print(f" {baseline_label}: {_abbreviate(baseline_value)}") + print(f" {candidate_label}: {_abbreviate(candidate_value)}") + remaining = len(result.mismatches) - _REPORTED_MISMATCHES + if remaining > 0: + print(f" ... and {remaining} further differing value(s)") def main() -> int: """ - Parse arguments, compare the two tracing DBs, and report the result. + Parse arguments, compare the two runs' stdout, and report the result. Returns: - ``0`` when the two builds produced identical Ux strings, ``1`` when - they differed, and ``2`` when the comparison could not be performed - (e.g. a DB was missing or had an incompatible schema). The bash caller - treats any non-zero status as a warning and continues. + ``0`` when the two builds printed identical Ux strings, ``1`` when + they differed or when neither printed any, and ``2`` when the + comparison could not be performed (e.g. a stdout file was missing). + The bash caller treats any non-zero status as a warning and continues. """ parser = argparse.ArgumentParser( description=( - "Compare the final Ux strings of two tracing DBs built at " - "different optimisation levels, warning on any byte-level difference." + "Compare the Ux strings printed by two builds of the same " + "application at different optimisation levels, warning on any " + "byte-level difference." ), ) - parser.add_argument("baseline_db", help="Baseline (e.g. -O0) tracing DB.") - parser.add_argument("candidate_db", help="Candidate (e.g. -O2) tracing DB.") - parser.add_argument( - "--table", - default=EquivMC.TRACING_TABLE, - help=f"Traced-values table name (default: {EquivMC.TRACING_TABLE}).", - ) + parser.add_argument("baseline_stdout", help="Captured stdout of the -O0 run.") + parser.add_argument("candidate_stdout", help="Captured stdout of the -O2 run.") parser.add_argument( "--baseline-label", default="O0", @@ -257,11 +228,11 @@ def main() -> int: args = parser.parse_args() try: - result = compare_ux_strings(args.baseline_db, args.candidate_db, args.table) - except (OSError, sqlite3.Error) as exc: + result = compare_ux_strings(args.baseline_stdout, args.candidate_stdout) + except OSError as exc: print( f"WARNING: ux-string check could not compare " - f"{args.baseline_db} and {args.candidate_db}: {exc}", + f"{args.baseline_stdout} and {args.candidate_stdout}: {exc}", file=sys.stderr, ) return 2 @@ -272,7 +243,7 @@ def main() -> int: candidate_label=args.candidate_label, config=args.config, ) - return 0 if result.is_identical else 1 + return 0 if result.is_identical and not result.is_empty else 1 if __name__ == "__main__": diff --git a/src/signaloid/benchmarking/automation/compare_tracing_ux_strings_test.py b/src/signaloid/benchmarking/automation/compare_tracing_ux_strings_test.py index 3263f82..b0b3802 100644 --- a/src/signaloid/benchmarking/automation/compare_tracing_ux_strings_test.py +++ b/src/signaloid/benchmarking/automation/compare_tracing_ux_strings_test.py @@ -17,68 +17,35 @@ # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING # FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER # DEALINGS IN THE SOFTWARE. - -import sqlite3 import tempfile import unittest -from collections.abc import Mapping, Sequence from pathlib import Path +from unittest.mock import patch from signaloid.benchmarking.automation.compare_tracing_ux_strings import ( compare_ux_strings, main, ) -_TABLE = "TracingTable" +# Shortened stand-ins for real Ux strings, which run to several hundred hex +# characters. Only the `Ux` prefix and the hex body matter to the comparator. +_UX_A = "Ux0400000000000000AAAA" +_UX_B = "Ux0400000000000000BBBB" -def _make_tracing_db(path: str, rows: Sequence[Mapping[str, object]]) -> None: +def _stdout_with(*ux_strings: str) -> str: """ - Write a minimal tracing DB with the columns the comparator reads. + Render application stdout that prints *ux_strings* among ordinary output. - Each entry in *rows* becomes one ``TracingTable`` write plus its - ``Emulator_Execution_Info`` row, sharing ``Execution_ID = 1`` so all - writes belong to one emulator configuration. Rows are inserted in list - order, so a later row overwrites an earlier one with the same identity - (exercising the last-write-wins grouping). + Mirrors the real shape: a printed uncertain value appears inline, directly + after its decimal rendering, surrounded by plain text that the comparator + must ignore. """ - with sqlite3.connect(path) as conn: - conn.execute( - "CREATE TABLE Emulator_Execution_Info (" - "Execution_ID INTEGER PRIMARY KEY AUTOINCREMENT, " - "UR_Type TEXT, UR_Order INTEGER, UR_Order_CoreLibrary INTEGER, " - "CorrelationTracking_Status TEXT)" - ) - conn.execute( - "INSERT INTO Emulator_Execution_Info " - "(Execution_ID, UR_Type, UR_Order, UR_Order_CoreLibrary, " - "CorrelationTracking_Status) VALUES (1, 'Athens', 64, 64, 'OFF')" - ) - conn.execute( - f'CREATE TABLE "{_TABLE}" (' - "Expression_DeclarationFileName TEXT, " - "Expression_Subprogram TEXT, " - "Expression_Name TEXT, " - "Expression_DeclarationLineNumber INTEGER, " - "Execution_Info_Table_ID INTEGER, " - "Dist_Value TEXT)" - ) - for row in rows: - conn.execute( - f'INSERT INTO "{_TABLE}" ' - "(Expression_DeclarationFileName, Expression_Subprogram, " - "Expression_Name, Expression_DeclarationLineNumber, " - "Execution_Info_Table_ID, Dist_Value) " - "VALUES (?, ?, ?, ?, 1, ?)", - ( - row.get("file", "main.c"), - row.get("subprogram", "main"), - row["name"], - row.get("line", 10), - row["dist_value"], - ), - ) - conn.commit() + lines = ["Core library random seed: 1024"] + for index, ux_string in enumerate(ux_strings): + lines.append(f" output {index}: 3.14159{ux_string} units") + lines.append("CPU time used: 0.123 seconds") + return "\n".join(lines) + "\n" class TestCompareUxStrings(unittest.TestCase): @@ -87,88 +54,105 @@ def setUp(self) -> None: self.addCleanup(tmp_dir.cleanup) self.tmp = Path(tmp_dir.name) - def _db(self, name: str, rows: Sequence[Mapping[str, object]]) -> str: - path = str(self.tmp / name) - _make_tracing_db(path, rows) - return path + def _stdout(self, name: str, *ux_strings: str) -> str: + path = self.tmp / name + path.write_text(_stdout_with(*ux_strings), encoding="utf-8") + return str(path) def test_identical_ux_strings_match(self) -> None: - rows = [ - {"name": "a", "dist_value": "Ux04ffff"}, - {"name": "b", "dist_value": "Ux04aaaa"}, - ] result = compare_ux_strings( - self._db("o0.db", rows), self._db("o2.db", rows), _TABLE + self._stdout("o0.out", _UX_A, _UX_B), + self._stdout("o2.out", _UX_A, _UX_B), ) self.assertTrue(result.is_identical) self.assertEqual(result.matched, 2) self.assertEqual(result.mismatches, []) def test_differing_ux_string_is_reported(self) -> None: - o0 = self._db("o0.db", [{"name": "a", "dist_value": "Ux04ffff"}]) - o2 = self._db("o2.db", [{"name": "a", "dist_value": "Ux04fffe"}]) - result = compare_ux_strings(o0, o2, _TABLE) + result = compare_ux_strings( + self._stdout("o0.out", _UX_A), + self._stdout("o2.out", _UX_B), + ) self.assertFalse(result.is_identical) self.assertEqual(result.matched, 0) self.assertEqual(len(result.mismatches), 1) - _key, baseline_value, candidate_value = result.mismatches[0] - self.assertEqual(baseline_value, "Ux04ffff") - self.assertEqual(candidate_value, "Ux04fffe") - - def test_last_write_wins_per_expression(self) -> None: - # Both DBs' final write for `a` is the same, even though an earlier - # write differs. The comparison must use the last write only. - o0 = self._db( - "o0.db", - [ - {"name": "a", "dist_value": "Ux04early"}, - {"name": "a", "dist_value": "Ux04final"}, - ], + index, baseline_value, candidate_value = result.mismatches[0] + self.assertEqual(index, 0) + self.assertEqual(baseline_value, _UX_A) + self.assertEqual(candidate_value, _UX_B) + + def test_print_order_is_significant(self) -> None: + # Same multiset of values, printed in the other order. The comparison + # is positional, so this must be reported rather than matched. + result = compare_ux_strings( + self._stdout("o0.out", _UX_A, _UX_B), + self._stdout("o2.out", _UX_B, _UX_A), ) - o2 = self._db( - "o2.db", - [{"name": "a", "dist_value": "Ux04final"}], + self.assertFalse(result.is_identical) + self.assertEqual(len(result.mismatches), 2) + + def test_surrounding_output_is_ignored(self) -> None: + # The two runs write different stats-DB paths and timings, which must + # not register as a difference. + baseline = self.tmp / "o0.out" + baseline.write_text( + f"ExecutionStatistics DB Name is /tmp/a-O0.db\nv: 1.0{_UX_A}\n", + encoding="utf-8", ) - result = compare_ux_strings(o0, o2, _TABLE) + candidate = self.tmp / "o2.out" + candidate.write_text( + f"ExecutionStatistics DB Name is /tmp/b-O2.db\nv: 1.0{_UX_A}\n", + encoding="utf-8", + ) + result = compare_ux_strings(str(baseline), str(candidate)) self.assertTrue(result.is_identical) self.assertEqual(result.matched, 1) - def test_expression_only_in_one_build(self) -> None: - o0 = self._db( - "o0.db", - [ - {"name": "a", "dist_value": "Ux04aaaa"}, - {"name": "b", "dist_value": "Ux04bbbb"}, - ], + def test_extra_value_printed_by_one_build(self) -> None: + result = compare_ux_strings( + self._stdout("o0.out", _UX_A, _UX_B), + self._stdout("o2.out", _UX_A), ) - o2 = self._db("o2.db", [{"name": "a", "dist_value": "Ux04aaaa"}]) - result = compare_ux_strings(o0, o2, _TABLE) self.assertFalse(result.is_identical) self.assertEqual(result.matched, 1) - self.assertEqual(len(result.only_in_baseline), 1) - self.assertEqual(result.only_in_baseline[0][2], "b") # Expression_Name - self.assertEqual(result.only_in_candidate, []) + self.assertEqual(result.baseline_count, 2) + self.assertEqual(result.candidate_count, 1) + + def test_both_builds_empty_is_not_a_pass(self) -> None: + """A run that printed no Ux string must not report as verified.""" + result = compare_ux_strings(self._stdout("o0.out"), self._stdout("o2.out")) + # Vacuously identical: nothing mismatched and both counts are zero. + self.assertTrue(result.is_identical) + self.assertEqual(result.matched, 0) + self.assertTrue(result.is_empty) + + def test_populated_comparison_is_not_empty(self) -> None: + result = compare_ux_strings( + self._stdout("o0.out", _UX_A), self._stdout("o2.out", _UX_A) + ) + self.assertFalse(result.is_empty) + self.assertTrue(result.is_identical) def test_main_returns_zero_when_identical(self) -> None: - rows = [{"name": "a", "dist_value": "Ux04aaaa"}] - argv = [self._db("o0.db", rows), self._db("o2.db", rows), "--table", _TABLE] + argv = [self._stdout("o0.out", _UX_A), self._stdout("o2.out", _UX_A)] self.assertEqual(_run_main(argv), 0) def test_main_returns_one_when_differing(self) -> None: - o0 = self._db("o0.db", [{"name": "a", "dist_value": "Ux04aaaa"}]) - o2 = self._db("o2.db", [{"name": "a", "dist_value": "Ux04bbbb"}]) - self.assertEqual(_run_main([o0, o2, "--table", _TABLE]), 1) + argv = [self._stdout("o0.out", _UX_A), self._stdout("o2.out", _UX_B)] + self.assertEqual(_run_main(argv), 1) - def test_main_returns_two_on_missing_db(self) -> None: - o0 = self._db("o0.db", [{"name": "a", "dist_value": "Ux04aaaa"}]) - missing = str(self.tmp / "does-not-exist.db") - self.assertEqual(_run_main([o0, missing, "--table", _TABLE]), 2) + def test_main_returns_one_when_neither_build_printed(self) -> None: + argv = [self._stdout("o0.out"), self._stdout("o2.out")] + self.assertEqual(_run_main(argv), 1) + + def test_main_returns_two_on_missing_stdout(self) -> None: + baseline = self._stdout("o0.out", _UX_A) + missing = str(self.tmp / "does-not-exist.out") + self.assertEqual(_run_main([baseline, missing]), 2) def _run_main(argv: list[str]) -> int: """Invoke ``main`` with a patched ``sys.argv`` and return its exit code.""" - from unittest.mock import patch - with patch("sys.argv", ["compare_tracing_ux_strings", *argv]): return main() diff --git a/src/signaloid/benchmarking/benchmark_timing/get-timings.sh b/src/signaloid/benchmarking/benchmark_timing/get-timings.sh index 63e4466..34a133d 100644 --- a/src/signaloid/benchmarking/benchmark_timing/get-timings.sh +++ b/src/signaloid/benchmarking/benchmark_timing/get-timings.sh @@ -525,17 +525,20 @@ run_uxhw_tracing() { local tracing_dbs=() local tracing_configs=() - # -O2 verification: the tracing build uses -O0 (the OPTFLAGS default in - # Makefile.pro) so the addDistValueTrace file:line directives resolve - # against unoptimised debug info, but real deployments compile at -O2. # Optimisation must not change the values the uncertainty machinery # computes, so we build a parallel -O2 binary per config and later check - # (warn-only) that its Ux strings byte-match the -O0 ones. TRACING_VERIFY_OPTFLAGS - # overrides the level compared against; -gdwarf-4 is kept so tracing still resolves. - local verify_optflags="${TRACING_VERIFY_OPTFLAGS:-"-O2 -gdwarf-4"}" + # (warn-only) that its Ux strings byte-match the -O0 ones. + local verify_optflags="${TRACING_VERIFY_OPTFLAGS:-"-O2 -gdwarf-4 -fno-vectorize -fno-slp-vectorize"}" + # ENABLE_TRACING for each of the two builds. The tracing build sets ON so + # the SDK writes its per-config tracing DB. The verification build leaves it + # empty: the SDK forces OPTFLAGS back to -O0 when tracing is on, and it gates + # the flag on a non-empty value, so OFF would still trace. With no tracing DB + # of its own, this build's Ux strings are read from stdout instead. + local tracing_build_enable_tracing="ON" + local verify_build_enable_tracing="" local verify_binaries=() - local verify_dbs=() - local verify_baseline_dbs=() + local verify_stdouts=() + local verify_baseline_stdouts=() local verify_configs=() # Configs whose -O2 build or run failed: skipped for comparison and # reported (as failing) in the verification summary below. @@ -566,7 +569,7 @@ run_uxhw_tracing() { CORRELATION_TRACKING="$CORRELATION_TRACKING_TYPE" M_CONFIG_FILE="$per_config_m" TARGET_ARCH="$TARGET_ARCH" - ENABLE_TRACING=ON + ENABLE_TRACING="$tracing_build_enable_tracing" ENABLE_UNCERTAIN_TYPE_MODIFIER="$ENABLE_UNCERTAIN_TYPE_MODIFIER" STATS_DB_FILENAME="$per_config_db" STATS_DB_TABLENAME="Emulator_Execution_Info" @@ -597,7 +600,7 @@ run_uxhw_tracing() { CORRELATION_TRACKING="$CORRELATION_TRACKING_TYPE" M_CONFIG_FILE="$verify_m" TARGET_ARCH="$TARGET_ARCH" - ENABLE_TRACING=ON + ENABLE_TRACING="$verify_build_enable_tracing" ENABLE_UNCERTAIN_TYPE_MODIFIER="$ENABLE_UNCERTAIN_TYPE_MODIFIER" STATS_DB_FILENAME="$verify_db" STATS_DB_TABLENAME="Emulator_Execution_Info" @@ -607,8 +610,8 @@ run_uxhw_tracing() { if uxhw_make "${verify_args[@]}" && [[ -f "$PROGRAM" ]]; then mv "$PROGRAM" "$verify_binary_name" verify_binaries+=("$verify_binary_name") - verify_dbs+=("$verify_db") - verify_baseline_dbs+=("$per_config_db") + verify_stdouts+=("$APPLICATION_PATH/src/$verify_binary_name.stdout") + verify_baseline_stdouts+=("$APPLICATION_PATH/src/$binary_name.stdout") verify_configs+=("$suffix") else warn "WARNING: verification build failed (OPTFLAGS='$verify_optflags') for config '$suffix'; skipping its Ux-string check." @@ -673,20 +676,33 @@ run_uxhw_tracing() { if ! wait "${verify_pids[$i]}"; then warn "WARNING: -O2 verification run failed for config '${verify_configs[$i]}'; skipping its Ux-string check." verify_failed_configs+=("${verify_configs[$i]} (run failed)") - verify_dbs[$i]="" + verify_stdouts[$i]="" fi done cd "$APPLICATION_PATH/src" - # Phase 2.5: Verify the -O2 Ux strings byte-match the -O0 baseline. This is - # warn-only (guarded with `|| true`) and must run before the merge below, - # which consumes (deletes) the per-config baseline DBs. - for i in "${!verify_dbs[@]}"; do - [[ -z "${verify_dbs[$i]}" ]] && continue + # Cross-check that every Ux string the tracing run recorded in its DB was + # also printed by that same run. The -O2 check below compares stdout on + # both sides, which is only sound while the SDK prints the bytes it stores; + # this is what would catch that drifting. Warn-only, and must run before + # the merge below, which consumes the per-config DBs. + for i in "${!tracing_dbs[@]}"; do + PYTHONPATH="$PACKAGE_IMPORT_ROOT${PYTHONPATH:+:$PYTHONPATH}" \ + "$BENCHMARKING_PYTHON" -m signaloid.benchmarking.automation.check_traced_values_printed \ + "${tracing_dbs[$i]}" "$APPLICATION_PATH/src/${tracing_binaries[$i]}.stdout" \ + --config "${tracing_configs[$i]}" || true + done + + # Verify the -O2 Ux strings byte-match the -O0 baseline. Both + # sides are read from the runs' stdout, since the -O2 build has no tracing + # DB. This is warn-only (guarded with `|| true`) and must run before the + # cleanup below, which deletes the captured stdout. + for i in "${!verify_stdouts[@]}"; do + [[ -z "${verify_stdouts[$i]}" ]] && continue PYTHONPATH="$PACKAGE_IMPORT_ROOT${PYTHONPATH:+:$PYTHONPATH}" \ "$BENCHMARKING_PYTHON" -m signaloid.benchmarking.automation.compare_tracing_ux_strings \ - "${verify_baseline_dbs[$i]}" "${verify_dbs[$i]}" \ + "${verify_baseline_stdouts[$i]}" "${verify_stdouts[$i]}" \ --baseline-label O0 --candidate-label O2 --config "${verify_configs[$i]}" || true done