From ec0765cf950994d460ef34c189d82ac6289e7ce5 Mon Sep 17 00:00:00 2001 From: Calvin Pieters Date: Sun, 16 Aug 2026 21:06:52 +0300 Subject: [PATCH 1/3] Stop timedelta_from_str() from zeroing every restored TS guess execution time timedelta_from_str() claimed to invert str(datetime.timedelta) but implemented a '1hr2m3s' grammar instead. Every group in that regex was optional, so the pattern also matched the empty string: any input in the real str(timedelta) form matched zero characters and the function returned timedelta(0). TSGuess.from_dict() is the only caller, and it feeds it exactly that form - TSGuess.as_dict() writes str(self.execution_time), and the gcn, goflow, kinbot and rits scripts all write str(datetime.datetime.now() - t0). So every TS guess's execution time silently became zero on restart. ARC's own restart fixture arc/testing/restart/5_TS1/restart.yml stores '0:00:05.357294' for seven heuristics guesses, all of which restored as zero. TS guess cost per method is a reported benchmark quantity, so this corrupted data rather than only a log line. Both grammars are kept. Nothing in the repository or its history produces or persists the '1hr2m3s' form - the regex arrived with the function in bd168da3 and never had a producer - but the two grammars are disjoint (one uses colons, the other letters), so accepting both costs nothing and avoids silently removing behaviour from a public helper in arc/common.py. The str(timedelta) grammar is tried first and is anchored at both ends, which is what stops the empty match. Unparseable input now returns None with a logged warning rather than raising. The caller assigns the result straight to TSGuess.execution_time, where None is already a first-class value - as_dict() guards it with `is not None` and scheduler.py str()s it - whereas raising would abort restart of an otherwise valid project. That is not hypothetical: arc/testing/restart/2_restart_rate/ restart.yml persists a legacy execution_time of '0', which no duration grammar accepts. The warning is what keeps the failure visible; returning a plausible-looking zero is what hid this bug. An exact zero stays distinguishable from a parse failure: '0:00:00' parses to timedelta(0), unparseable input yields None. The existing test asserted only isinstance(result, datetime.timedelta), which timedelta(0) satisfies, so it passed forever while enshrining the bug. It now asserts parsed values, and a round-trip test covers sub-second, multi-day, zero and negative durations. Two rendering helpers are added here as well, for the TS guess report that the following commit rewrites as a table. format_table() sizes each column to its own widest entry, header or cell, and supports a multi-line header so a units line can sit under a title. It validates its inputs and raises InputError for a ragged row, an alignment character other than '<', '>' and '^', and a non-string cell, rather than letting those surface as a TypeError or a ValueError from inside the renderer; a column whose multi-line header is empty and which has no rows now renders at width zero instead of raising from max() on an empty sequence. Its docstring states that widths are counted in characters, which is the contract a caller needs in order to know that alignment holds for single-width text; no display-width measurement is implemented, because the only cell that could carry a full-width or combining character is Status, built from tsg.errors, which is ASCII as an ESS emits it. format_duration() reports a duration in the largest unit it fills, to one decimal place ('3.4 s', '47.2 m', '13.1 h', '2.1 d'). Most TS guesses finish in seconds and per-method guess cost is a reported benchmark metric, so the report has to resolve a 3.4 s heuristics guess from an 18.1 s AutoTST one, which a whole-minute format cannot. One decimal place in a self-naming unit keeps that resolution and spans seconds to days while staying short enough to sit in a column without a unit line of its own. The unit loop covers the three bounded units and days are the terminal return after it, rather than a fourth entry whose limit is a None sentinel: the sentinel entry always matched, so the function could only return from inside the loop even though it is annotated `-> str`, which is what CodeQL's py/mixed-returns flags. Structuring it as "three bounded units, then days as the unbounded fallback" removes the implicit fall-through without leaving a line after the loop that can never execute. time_lapse() is corrected in the same file. It computes its day count with divmod() on a float, so `str(d)` rendered it as '1.0' and the function returned '1.0 days, 06:00:00' - which matches neither the "D HH:MM:SS" format its own docstring claims nor Python's own str(timedelta). Formatting the count with '.0f' makes it a whole number. Sub-day output is untouched. This also removes an inconsistency inside the module this commit restructures: arc/common.py now holds one duration parser, and timedelta_from_str(), newly anchored, rejected the day form that time_lapse() produced. Nothing feeds one into the other today, so the defect was latent, which is also why no test caught it - there was no coverage above 24 hours at all. There is now, and it asserts the round trip through timedelta_from_str() as well as the rendered string. Searched arc/common.py, arc/plotter.py and the rest of arc/ for an existing column, table or padding helper (def .*(pad|align|column|width|table|format), ljust/rjust/center, tabulate/PrettyTable, "max(len(") and for a duration formatter (time_lapse, timedelta_from_str, convert_to_hours). No table helper exists; the only comparable code is the Arkane thermo table in arc/statmech/arkane.py, which hand-rolls its widths inline. Rather than add a second copy of that, the renderer goes in arc/common.py, which is where the duration formatter belongs too. arkane.py is left alone because converting it would change thermo log output this change is not otherwise concerned with; it is the obvious next caller. format_duration() does not carry a duration grammar of its own. It delegates the string case to timedelta_from_str(), so the module holds exactly one parser for the str(timedelta) form and the two cannot drift apart - which they already had: a parser written privately against the broken timedelta_from_str() allowed no sign on the days field and so failed on '-1 day, 23:59:59', which timedelta_from_str() reads. Delegating is only correct once timedelta_from_str() is fixed; against the old implementation every colon-form duration would have rendered as '0.0 s'. The contract seam is preserved in both directions. timedelta_from_str() returns None for unparseable input and format_duration() returns '' for it, so the composition still yields ''. An exact zero stays distinguishable from a failure: '0:00:00' renders '0.0 s', garbage renders ''. Negative durations now parse, where the private regex rejected them outright, and format_duration() still reports them as '' - a negative guess duration is not worth displaying, and that was the behaviour before. An empty or blank string is treated as an absent duration and short-circuits before the parser, so a missing execution time does not log a parse warning once per report row; a non-blank string that is genuinely malformed still warns, which is the signal worth keeping. --- arc/common.py | 133 ++++++++++++++++++++++++++++++++++---- arc/common_test.py | 156 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 276 insertions(+), 13 deletions(-) diff --git a/arc/common.py b/arc/common.py index f406bd511b..2377ca0fcf 100644 --- a/arc/common.py +++ b/arc/common.py @@ -305,6 +305,66 @@ def log_footer(execution_time: str, logger.log(level, f'ARC execution terminated on {time.asctime()}') +def format_table(headers: Sequence[str | Sequence[str]], + rows: Sequence[Sequence[str]], + alignments: str | None = None, + separator: str = ' ', + rule_char: str = '-', + ) -> list[str]: + """ + Format a table as a list of lines with aligned columns. + + Each column is exactly as wide as its widest entry, considering both its header and its cells. + Widths are counted in characters, so the columns line up for single-width text. + A header may be given as a sequence of strings to render it on several lines, e.g., a title + line and a units line; shorter headers are padded with blank lines at the bottom, placing every + header's first string on the first line. Trailing whitespace is stripped from every line. + + Args: + headers (Sequence[str | Sequence[str]]): The column headers, each a string, + or a sequence of strings for a multi-line header. + rows (Sequence[Sequence[str]]): The table rows, each a sequence of one cell string per column. + alignments (str, optional): One alignment character ('<', '>' or '^') per column. + Columns are left-aligned if not given. + separator (str, optional): The string separating two adjacent columns. + rule_char (str, optional): The character to draw the rule under the header with, + an empty string to omit the rule. + + Returns: list[str] + The rendered lines: the header line(s), a rule, and one line per row. + + Raises: + InputError: If a row, or the alignments, does not have exactly one entry per column, + if an alignment character is not one of '<', '>' and '^', + or if a cell is not a string. + """ + headers = [(header,) if isinstance(header, str) else tuple(header) for header in headers] + alignments = alignments if alignments is not None else '<' * len(headers) + if len(alignments) != len(headers): + raise InputError(f'Expected {len(headers)} alignment characters, got {len(alignments)}: {alignments}') + if any(alignment not in '<>^' for alignment in alignments): + raise InputError(f'Alignment characters must each be one of "<", ">" and "^", got {alignments}') + for row in rows: + if len(row) != len(headers): + raise InputError(f'Expected {len(headers)} cells per row, got {len(row)}: {row}') + if any(not isinstance(cell, str) for cell in row): + raise InputError(f'Table cells must be strings, got {row}') + header_height = max((len(header) for header in headers), default=0) + headers = [header + ('',) * (header_height - len(header)) for header in headers] + widths = [max([len(line) for line in header] + [len(row[i]) for row in rows] + [0]) + for i, header in enumerate(headers)] + + def render(cells: Sequence[str]) -> str: + """Render one line of cells, padded to the column widths and stripped of trailing space.""" + return separator.join(f'{cell:{alignment}{width}}' + for cell, alignment, width in zip(cells, alignments, widths)).rstrip() + + lines = [render([header[i] for header in headers]) for i in range(header_height)] + if rule_char: + lines.append(render([rule_char * width for width in widths])) + return lines + [render(row) for row in rows] + + def get_git_commit(path: str | None = None) -> tuple[str, str]: """ Get the recent git commit to be logged. @@ -1368,12 +1428,44 @@ def time_lapse(t0) -> str: h, m = divmod(m, 60) d, h = divmod(h, 24) if d > 0: - d = str(d) + ' days, ' + d = f'{d:.0f} days, ' else: d = '' return f'{d}{h:02.0f}:{m:02.0f}:{s:02.0f}' +def format_duration(duration: 'datetime.timedelta | str | None') -> str: + """ + Format a duration briefly, in the largest unit it fills, e.g. '3.4 s', '47.2 m', '13.1 h', '2.1 d'. + + Seconds ('s') are used below a minute, minutes ('m') below an hour, hours ('h') below a day, + and days ('d') beyond that. The value is given to one decimal place and is followed by a space + and the symbol of its unit. A duration of exactly zero is reported as '0.0 s'. A negative + duration, and a value that cannot be read as a duration, are reported as an empty string. + + A string duration is read by :func:`timedelta_from_str`, so both accept the same grammars. + An empty or blank string is treated as an absent duration and is not reported as unreadable. + + Args: + duration (datetime.timedelta, str, optional): The duration, either a timedelta object + or its ``str()`` representation, + e.g. '2 days, 3:04:05.678'. + + Returns: str + The brief representation of the duration. + """ + if isinstance(duration, str): + duration = timedelta_from_str(duration) if duration.strip() else None + if not isinstance(duration, datetime.timedelta) or duration.total_seconds() < 0: + return '' + seconds = duration.total_seconds() + for limit, divisor, unit in ((60, 1, 's'), (60, 60, 'm'), (24, 3600, 'h')): + value = seconds / divisor + if round(value, 1) < limit: + return f'{value:.1f} {unit}' + return f'{seconds / 86400:.1f} d' + + def estimate_orca_mem_cpu_requirement(num_heavy_atoms: int, server: str = '', consider_server_limits: bool = False, @@ -1715,26 +1807,41 @@ def get_close_tuple(key_1: tuple[float | str, ...], raise ValueError(f'Could not locate a key close to {key_1} within the tolerance {tolerance} in the given keys list.') -def timedelta_from_str(time_str: str): +TIMEDELTA_STR_REGEX = re.compile(r'^(?:(?P[-+]?\d+)\s+days?,\s*)?' + r'(?P\d{1,2}):(?P\d{2}):(?P\d{2})' + r'(?:\.(?P\d{1,6}))?$') +TIMEDELTA_COMPACT_REGEX = re.compile(r'^(?:(?P\d+)hr)?(?:(?P\d+)m)?(?:(?P\d+)s)?$') + + +def timedelta_from_str(time_str: str) -> datetime.timedelta | None: """ - Get a datetime.timedelta object from its str() representation + Get a datetime.timedelta object from its string representation. + + Two grammars are accepted. The primary one is the ``str(datetime.timedelta)`` representation, + e.g., '0:00:03.420000', '2 days, 3:00:00', or '-1 day, 23:59:59', which is the form ARC persists + in restart.yml and output.yml. The secondary one is a compact 'hr'/'m'/'s' form, e.g., '1hr2m3s' + or '45s', in which at least one of the three components must be present. Args: time_str (str): The string representation of a datetime.timedelta object. Returns: - datetime.timedelta: The corresponding timedelta object. + datetime.timedelta | None: The corresponding timedelta object, + or ``None`` if ``time_str`` does not represent a duration. """ - regex = re.compile(r'((?P\d+?)hr)?((?P\d+?)m)?((?P\d+?)s)?') - - parts = regex.match(time_str) - if not parts: - return - parts = parts.groupdict() + if not isinstance(time_str, str) or not time_str.strip(): + logger.warning(f'Could not interpret {time_str!r} as a time delta, returning None.') + return None + match = TIMEDELTA_STR_REGEX.match(time_str.strip()) + if match is None: + match = TIMEDELTA_COMPACT_REGEX.match(time_str.strip()) + if match is None or not any(match.groupdict().values()): + logger.warning(f'Could not interpret {time_str!r} as a time delta, returning None.') + return None time_params = {} - for (name, param) in parts.items(): - if param: - time_params[name] = int(param) + for name, param in match.groupdict().items(): + if param is not None: + time_params[name] = int(param.ljust(6, '0')) if name == 'microseconds' else int(param) return datetime.timedelta(**time_params) diff --git a/arc/common_test.py b/arc/common_test.py index b4b6832faa..f571b743dc 100644 --- a/arc/common_test.py +++ b/arc/common_test.py @@ -147,6 +147,127 @@ def test_time_lapse(self): lap = common.time_lapse(t0) self.assertEqual(lap, '00:00:02') + def test_time_lapse_beyond_a_day(self): + """Test that time_lapse() gives a whole number of days and stays readable by timedelta_from_str()""" + now = time.time() + self.assertEqual(common.time_lapse(now - 30 * 3600), '1 days, 06:00:00') + self.assertEqual(common.time_lapse(now - 3 * 86400), '3 days, 00:00:00') + self.assertEqual(common.time_lapse(now - (400 * 86400 + 1)), '400 days, 00:00:01') + for seconds in [6 * 3600, 23 * 3600 + 59 * 60 + 59, 30 * 3600, 3 * 86400, 400 * 86400 + 1]: + lap = common.time_lapse(now - seconds) + self.assertEqual(common.timedelta_from_str(lap), datetime.timedelta(seconds=seconds), + msg=f'time_lapse() gave {lap!r}, which does not read back as {seconds} s') + + def test_format_duration(self): + """Test the format_duration() function""" + self.assertEqual(common.format_duration(datetime.timedelta(0)), '0.0 s') + self.assertEqual(common.format_duration(datetime.timedelta(seconds=3.42)), '3.4 s') + self.assertEqual(common.format_duration(datetime.timedelta(minutes=7)), '7.0 m') + self.assertEqual(common.format_duration(datetime.timedelta(hours=13, minutes=7)), '13.1 h') + self.assertEqual(common.format_duration(datetime.timedelta(days=2, hours=3)), '2.1 d') + self.assertEqual(common.format_duration(datetime.timedelta(days=140, hours=1)), '140.0 d') + + def test_format_duration_keeps_sub_minute_timings_distinct(self): + """Test that the sub-minute TS guess timings of a real run render to three distinct strings""" + rendered = [common.format_duration(datetime.timedelta(seconds=seconds)) + for seconds in [3.4, 16.8, 18.1]] + self.assertEqual(rendered, ['3.4 s', '16.8 s', '18.1 s']) + self.assertEqual(len(set(rendered)), 3) + + def test_format_duration_unit_boundaries(self): + """Test that format_duration() steps up a unit rather than reporting a full unit's worth of the smaller""" + self.assertEqual(common.format_duration(datetime.timedelta(seconds=59.9)), '59.9 s') + self.assertEqual(common.format_duration(datetime.timedelta(seconds=59.99)), '1.0 m') + self.assertEqual(common.format_duration(datetime.timedelta(seconds=60)), '1.0 m') + self.assertEqual(common.format_duration(datetime.timedelta(minutes=59.99)), '1.0 h') + self.assertEqual(common.format_duration(datetime.timedelta(hours=23.99)), '1.0 d') + + def test_format_duration_spans_seconds_to_days(self): + """Test that format_duration() gives one decimal place and a unit symbol across its whole range""" + rendered = [common.format_duration(datetime.timedelta(seconds=seconds)) + for seconds in [0, 0.05, 3.4, 59.9, 60, 3599, 3600, 86399, 86400, 12096000, 864000000]] + self.assertEqual(rendered, ['0.0 s', '0.1 s', '3.4 s', '59.9 s', '1.0 m', '1.0 h', '1.0 h', + '1.0 d', '1.0 d', '140.0 d', '10000.0 d']) + for cell in rendered: + self.assertRegex(cell, r'^\d+\.\d [smhd]$') + + def test_format_duration_from_str(self): + """Test that format_duration() accepts the str() representation of a timedelta""" + for delta in [datetime.timedelta(seconds=3.42), + datetime.timedelta(hours=13, minutes=7, seconds=6.5), + datetime.timedelta(days=1, seconds=12), + datetime.timedelta(days=2, hours=3)]: + self.assertEqual(common.format_duration(str(delta)), common.format_duration(delta)) + + def test_format_duration_uninterpretable(self): + """Test that format_duration() reports an absent or negative duration as an empty string""" + for duration in [None, '', 'not a duration', 24, datetime.timedelta(seconds=-1)]: + self.assertEqual(common.format_duration(duration), '') + + def test_format_duration_reads_a_string_exactly_as_timedelta_from_str_does(self): + """Test that format_duration() and timedelta_from_str() agree on every duration string""" + for time_str in ['0:00:00', '0:00:00.500000', '0:00:03.4', '0:00:03.420000', '0:00:16.8', '0:00:18.1', + '0:17:05', '13:07:06.500000', '1 day, 0:00:00', '2 days, 3:00:00', '400 days, 0:00:01', + '-1 day, 23:59:59', '-3 days, 5:00:00', '1hr2m3s', '45s', + '', ' ', 'not a duration', '3:04', 'None']: + self.assertEqual(common.format_duration(time_str), + common.format_duration(common.timedelta_from_str(time_str)), + msg=f'{time_str!r} is read differently by the two entry points') + self.assertEqual([common.format_duration(time_str) for time_str in ['0:00:03.4', '0:00:16.8', '0:00:18.1']], + ['3.4 s', '16.8 s', '18.1 s']) + self.assertEqual(common.format_duration('0:00:00'), '0.0 s') + self.assertEqual(common.format_duration('0:00:00.500000'), '0.5 s') + self.assertEqual(common.format_duration('2 days, 3:00:00'), '2.1 d') + self.assertEqual(common.format_duration('-1 day, 23:59:59'), '') + self.assertEqual(common.timedelta_from_str('-1 day, 23:59:59'), datetime.timedelta(seconds=-1)) + self.assertEqual(common.format_duration('not a duration'), '') + + def test_format_duration_does_not_warn_for_an_absent_duration(self): + """Test that format_duration() reports an absent duration quietly, without a parse warning""" + with self.assertNoLogs('arc', level='WARNING'): + for duration in [None, '', ' ', datetime.timedelta(seconds=-1)]: + self.assertEqual(common.format_duration(duration), '') + + def test_format_table(self): + """Test the format_table() function""" + table = common.format_table(headers=['Label', ('H298', '(kJ/mol)')], + rows=[['CH4', '-74.60'], ['a longer label', '1.00']], + alignments='<>', + ) + self.assertEqual(table, ['Label H298', + ' (kJ/mol)', + '-------------- --------', + 'CH4 -74.60', + 'a longer label 1.00']) + + def test_format_table_column_widths(self): + """Test that format_table() sizes each column to its widest entry, header or cell""" + table = common.format_table(headers=['A', 'BBBBB'], rows=[['CCC', 'D']], separator='|', rule_char='') + self.assertEqual(table, ['A |BBBBB', 'CCC|D']) + + def test_format_table_no_rows(self): + """Test that format_table() renders the header alone when there are no rows""" + self.assertEqual(common.format_table(headers=['A', 'BB'], rows=[]), ['A BB', '- --']) + + def test_format_table_raises_on_a_ragged_row(self): + """Test that format_table() rejects a row or an alignment string that does not match the headers""" + with self.assertRaises(InputError): + common.format_table(headers=['A', 'B'], rows=[['1']]) + with self.assertRaises(InputError): + common.format_table(headers=['A', 'B'], rows=[['1', '2']], alignments='<') + + def test_format_table_raises_input_error_on_a_bad_cell_or_alignment(self): + """Test that format_table() reports a non-string cell or an unknown alignment as an InputError""" + for row in [[None, '2'], [1, '2'], [['1'], '2']]: + with self.assertRaises(InputError): + common.format_table(headers=['A', 'B'], rows=[row]) + with self.assertRaises(InputError): + common.format_table(headers=['A', 'B'], rows=[['1', '2']], alignments=' Date: Sun, 16 Aug 2026 21:06:52 +0300 Subject: [PATCH 2/3] Report the successful TS guesses as a table The per-guess lines logged by determine_most_likely_ts_conformer() were prose with embedded labels, and they did not line up: three of the four fields ahead of the free-text tail were rendered at their natural width. The method string is 7-24 characters, longer still when a clustered guess adds an "(also: ...)" suffix; the execution time varies; and the index format spec hard-coded a width of 2, so an index of 100 or more shifted the whole line. Only the relative energy was padded, at a fixed width of 8 that was both wider than the data needs and able to overflow. The block is now a table with a header, a rule, and one row per guess: TS Guess, Method, Rel. Energy (kJ/mol), Guess Time, Img Freq (cm-1), and Status. Each column is sized to its own widest entry, computed over the guesses that are actually reported, i.e. those that pass the "success and energy is not None" filter, so a guess that is filtered out cannot leave a permanently over-wide column. Sizing them needs the rendered cells before the first line is emitted, so the guesses are collected in the existing loop, which already mutates tsg.energy into a relative energy, and logged in a second pass. The whole table is emitted before any structure is drawn. plotter.draw_3d() opens with an unconditional logger.debug('not drawing 3D!'), so drawing each guess right after its own row put that line between the rows and destroyed the alignment whenever ARC runs at DEBUG - and verbose is a documented user-facing ARC input, persisted to the restart dict when it is not INFO, so DEBUG is a supported mode rather than a developer-only one. Splitting the loop keeps the table contiguous. The draws themselves are unchanged: one per reported guess, in row order, still with method='draw_3d', because for a TS only draw_3d() may be used - show_sticks() infers connectivity and gets it wrong for a structure with partial bonds. The guess time cell comes from format_duration(), which reports the duration in the largest unit it fills to one decimal place. Most TS guesses finish in seconds and per-method guess cost is a reported benchmark metric, so the column has to resolve a 3.4 s heuristics guess from an 18.1 s AutoTST one; the previous code truncated str(tsg.execution_time) at one decimal place, which was legible only because it happened to be sub-minute, and a whole-minute format would collapse every row of a real block to one value. The Status column carries tsg.errors, which was previously appended to the end of the prose line, and is added only when a reported guess actually has an error: errors are recorded exclusively on guesses with success False (see the loop at the end of troubleshoot_ess), which this block filters out, so the column would otherwise always be blank. The imaginary frequencies, previously spelled out mid-sentence, are now just the Img Freq column. The relative-energy conversion is also made idempotent, which is a pre-existing defect this commit fixes rather than one it introduces - the same subtraction, with the same asymmetry, is on main. e_min is the lowest energy of ANY guess, successful or not, but `tsg.energy -= e_min` was applied only to the successful ones. A second invocation for the same label therefore saw a set in which the successful guesses already held relative energies while the unsuccessful ones still held absolute ones; if the global minimum sat on an unsuccessful guess, e_min stayed at that absolute value and every successful energy shifted again. Measured on main, for guesses at +10 and +20 that succeeded and one at -100 that did not: [110.0, 120.0, -100.0] after the first call, [210.0, 220.0, -100.0] after the second. Repeat invocation is reachable from switch_ts() and from two call sites in arc/job/pipe/pipe_coordinator.py. The subtraction is now applied to every guess that has an energy. This keeps the reference point exactly where it was - the lowest energy of any guess - so no energy reported on a first invocation changes, which matters because those numbers are physical and feed the selection. It also makes the set minimum exactly zero, so a second invocation subtracts zero and is a no-op. Computing e_min over only the successful guesses would have been idempotent too, but it moves the reference point whenever the global minimum sits on an unsuccessful guess, and so changes reported energies; that was rejected for exactly that reason. The values newly mutated are the energies of unsuccessful guesses. Two things read them. plotter.save_conformers_file() takes the energies of all guesses and re-baselines them against their own minimum, so a uniform offset leaves its output unchanged; it was previously handed a mixture of relative and absolute values, and now receives one consistent baseline. TSGuess.almost_equal_tsgs() compares two energies with isclose(abs_tol=0.1), a difference, which a uniform offset also leaves unchanged. as_dict() persists the energy, so a restart now restores an already-relative set whose minimum is zero, on which the conversion is again a no-op. --- arc/scheduler.py | 40 +++++--- arc/scheduler_test.py | 219 ++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 246 insertions(+), 13 deletions(-) diff --git a/arc/scheduler.py b/arc/scheduler.py index 3c27829cf5..82150aa80d 100644 --- a/arc/scheduler.py +++ b/arc/scheduler.py @@ -20,6 +20,8 @@ from arc.checks.common import get_i_from_job_name, is_conformer_job, sum_time_delta from arc.checks.ts import check_imaginary_frequencies, check_ts, check_irc_species_and_rxn from arc.common import (extremum_list, + format_duration, + format_table, get_angle_in_180_range, get_logger, get_number_with_ordinal_indicator, @@ -2460,6 +2462,7 @@ def determine_most_likely_ts_conformer(self, label: str): # Reset e_min to the lowest value regardless of other criteria (imaginary frequencies, IRC, normal modes). if tsg.energy is not None and (e_min is None or tsg.energy < e_min): e_min = tsg.energy + reported_tsgs = list() for tsg in self.species_dict[label].ts_guesses: if tsg.index == selected_i: self.species_dict[label].chosen_ts = selected_i @@ -2470,23 +2473,34 @@ def determine_most_likely_ts_conformer(self, label: str): self.species_dict[label].ts_guesses_exhausted = False if getattr(tsg, 'log_path', None): self.output[label]['paths']['neb'] = tsg.log_path - if tsg.success and tsg.energy is not None: # guess method and ts_level opt were both successful + if tsg.energy is not None: tsg.energy -= e_min - im_freqs = f', imaginary frequencies {tsg.imaginary_freqs}' if tsg.imaginary_freqs is not None else '' - execution_time = str(tsg.execution_time) - execution_time = execution_time[:execution_time.index('.') + 2] \ - if '.' in execution_time else execution_time - aux = f' {tsg.errors}.' if tsg.errors else '.' + if tsg.success and tsg.energy is not None: # guess method and ts_level opt were both successful methods_str = tsg.method if tsg.method_sources and len(tsg.method_sources) > 1: methods_str += f' (also: {", ".join(m for m in tsg.method_sources if m != tsg.method)})' - logger.info(f'TS guess {tsg.index:2} for {label}. ' - f'Method: {methods_str}, ' - f'relative energy: {tsg.energy:8.2f} kJ/mol, ' - f'guess ex time: {execution_time}{im_freqs}' - f'{aux}') - # for TSs, only use `draw_3d()`, not `show_sticks()` which gets connectivity wrong: - plotter.draw_structure(xyz=tsg.initial_xyz, method='draw_3d') + reported_tsgs.append((tsg, [str(tsg.index), + methods_str, + f'{tsg.energy:.2f}', + format_duration(tsg.execution_time), + ', '.join(f'{freq:.1f}' for freq in tsg.imaginary_freqs) + if tsg.imaginary_freqs is not None else ''])) + headers = ['TS Guess', 'Method', ('Rel. Energy', '(kJ/mol)'), + 'Guess Time', ('Img Freq', '(cm-1)')] + alignments = '><>>>' + if any(tsg.errors for tsg, _ in reported_tsgs): + headers.append('Status') + alignments += '<' + for tsg, row in reported_tsgs: + row.append(tsg.errors) + table = format_table(headers=headers, + rows=[row for _, row in reported_tsgs], + alignments=alignments, + ) + for line in table: + logger.info(line) + for tsg, _ in reported_tsgs: + plotter.draw_structure(xyz=tsg.initial_xyz, method='draw_3d') logger.info('\n') if self.species_dict[label].chosen_ts is None: raise SpeciesError(f'Could not pair most stable conformer {selected_i} of {label} to a respective ' diff --git a/arc/scheduler_test.py b/arc/scheduler_test.py index 05ab83dc41..b14d8a2ea4 100644 --- a/arc/scheduler_test.py +++ b/arc/scheduler_test.py @@ -7,8 +7,10 @@ import unittest from unittest.mock import MagicMock, patch +import datetime import os import shutil +from contextlib import nullcontext from types import SimpleNamespace @@ -2267,5 +2269,222 @@ def test_apply_adaptive_reaction_levels_label_collision(self): self.build_scheduler(rxn, r + p + [collider], 'adaptive_collision') +class TestSchedulerTSGuessReportAlignment(unittest.TestCase): + """ + Contains unit tests for the column alignment of the successful TS guess block reported by + Scheduler.determine_most_likely_ts_conformer(). + """ + + TITLES = ['TS Guess', 'Method', 'Rel. Energy', 'Guess Time', 'Img Freq'] + + @staticmethod + def make_ts_guess(index, method, method_sources, energy, execution_time, + success=True, errors='', imaginary_freqs=None): + """Return a TSGuess with the given reporting attributes and a geometry unique to its index.""" + tsg = TSGuess(index=index, + method=method, + energy=energy, + execution_time=execution_time, + xyz={'symbols': ('H', 'H'), 'isotopes': (1, 1), + 'coords': ((0.0, 0.0, 0.0), (0.0, 0.0, 0.74 + 0.01 * index))}, + ) + tsg.method_sources = method_sources + tsg.success = success + tsg.errors = errors + tsg.imaginary_freqs = imaginary_freqs if imaginary_freqs is not None else [-500.0 - index] + tsg.opt_xyz = tsg.initial_xyz + return tsg + + def build_scheduler(self, ts_guesses): + """Return a Scheduler holding a TS species carrying the given guesses.""" + ts = ARCSpecies(label='TS0', is_ts=True) + ts.ts_guesses = ts_guesses + scheduler = Scheduler.__new__(Scheduler) + scheduler.species_dict = {'TS0': ts} + scheduler.output = {'TS0': {'paths': dict()}} + scheduler.project_directory = '' + scheduler.ts_guess_level = None + return scheduler + + def invoke(self, scheduler, level='INFO', draw=False): + """Run the TS guess selection once and return the lines emitted after the guess block header.""" + with nullcontext() if draw else patch('arc.scheduler.plotter.draw_structure'), \ + patch('arc.scheduler.plotter.save_conformers_file'): + with self.assertLogs('arc', level=level) as cm: + scheduler.determine_most_likely_ts_conformer(label='TS0') + messages = [record.getMessage() for record in cm.records] + start = next(i for i, message in enumerate(messages) if 'Geometry *guesses*' in message) + return [message for message in messages[start + 1:] if message.strip()] + + def report(self, ts_guesses): + """Run the TS guess selection on the given guesses and return the emitted table lines.""" + return self.invoke(self.build_scheduler(ts_guesses)) + + def column_spans(self, lines): + """Return the (start, stop) offset of each column, read off the rule line of the given table.""" + rules = [line for line in lines if line and set(line) <= set('- ')] + self.assertTrue(rules, msg='the reported block has no rule line, so it is not a table:\n' + '\n'.join(lines)) + rule = rules[0] + spans, start = list(), None + for i, char in enumerate(rule + ' '): + if char == '-' and start is None: + start = i + elif char != '-' and start is not None: + spans.append((start, i)) + start = None + return spans + + def assert_tabulated(self, lines, n_rows, titles=None): + """Assert that the given lines form a table whose cells stay inside their own columns.""" + titles = titles if titles is not None else self.TITLES + spans = self.column_spans(lines) + rendered = '\n'.join(lines) + self.assertEqual(len(spans), len(titles), msg=f'expected {len(titles)} columns in:\n{rendered}') + title_line = lines[0] + for title, (start, stop) in zip(titles, spans): + self.assertIn(title, title_line[start:stop], msg=f'{title!r} is not in its own column in:\n{rendered}') + for line in lines: + padded = line.ljust(spans[-1][1]) + for start, stop in spans: + if start: + self.assertEqual(padded[start - 1], ' ', + msg=f'a cell bleeds into the column at offset {start} in:\n{rendered}') + self.assertEqual(''.join(padded[start:stop] for start, stop in spans).replace(' ', ''), + line.replace(' ', ''), + msg=f'a character falls outside every column in:\n{rendered}') + self.assertEqual(len(self.column_cells(lines, 0)), n_rows, msg=f'expected {n_rows} rows in:\n{rendered}') + + def column_cells(self, lines, column): + """Return the stripped cells of the given column, for the data rows only.""" + spans = self.column_spans(lines) + rule_index = next(i for i, line in enumerate(lines) if line and set(line) <= set('- ')) + start, stop = spans[column] + return [line.ljust(stop)[start:stop].strip() for line in lines[rule_index + 1:]] + + def test_columns_align_across_mixed_methods_and_indices(self): + """Test that the table holds given mixed method name lengths and 1-, 2- and 3-digit indices.""" + lines = self.report([ + self.make_ts_guess(0, 'heuristics', ['heuristics', 'crest'], -50.0, datetime.timedelta(seconds=3.42)), + self.make_ts_guess(36, 'autotst', ['autotst'], -48.27, datetime.timedelta(seconds=18.15)), + self.make_ts_guess(136, 'gcn', ['gcn'], 1234.5, datetime.timedelta(hours=13, minutes=7, seconds=6.5)), + ]) + self.assert_tabulated(lines, n_rows=3) + self.assertEqual(self.column_cells(lines, 0), ['0', '36', '136']) + self.assertEqual(self.column_cells(lines, 1), ['heuristics (also: crest)', 'autotst', 'gcn']) + self.assertEqual(self.column_cells(lines, 2), ['0.00', '1.73', '1284.50']) + + def test_a_status_column_is_added_only_when_a_reported_guess_has_an_error(self): + """Test that the status column appears given an error on a reported guess, and is omitted otherwise.""" + lines = self.report([ + self.make_ts_guess(1, 'kinbot', ['kinbot'], 0.0, datetime.timedelta(seconds=1.5), errors='some error'), + self.make_ts_guess(2, 'xtb_gsm', ['xtb_gsm', 'gcn', 'autotst'], 7.5, datetime.timedelta(days=2, hours=3)), + ]) + self.assert_tabulated(lines, n_rows=2, titles=self.TITLES + ['Status']) + self.assertEqual(self.column_cells(lines, 5), ['some error', '']) + lines = self.report([ + self.make_ts_guess(1, 'kinbot', ['kinbot'], 0.0, datetime.timedelta(seconds=1.5)), + self.make_ts_guess(2, 'xtb_gsm', ['xtb_gsm', 'gcn', 'autotst'], 7.5, datetime.timedelta(days=2, hours=3)), + ]) + self.assert_tabulated(lines, n_rows=2) + self.assertNotIn('Status', '\n'.join(lines)) + + def test_the_guess_time_column_spans_seconds_to_days(self): + """Test that the guess time column reports each duration in the largest unit it fills.""" + lines = self.report([ + self.make_ts_guess(1, 'heuristics', ['heuristics'], 0.0, datetime.timedelta(seconds=3.42)), + self.make_ts_guess(2, 'autotst', ['autotst'], 1.0, datetime.timedelta(hours=13, minutes=7, seconds=6.5)), + self.make_ts_guess(3, 'kinbot', ['kinbot'], 2.0, datetime.timedelta(days=2, hours=3)), + ]) + self.assert_tabulated(lines, n_rows=3) + self.assertEqual(self.column_cells(lines, 3), ['3.4 s', '13.1 h', '2.1 d']) + + def test_sub_minute_guess_times_stay_distinct(self): + """Test that the sub-minute guess timings of a real run do not collapse into one cell.""" + lines = self.report([ + self.make_ts_guess(1, 'heuristics', ['heuristics'], 0.0, datetime.timedelta(seconds=3.4)), + self.make_ts_guess(2, 'gcn', ['gcn'], 1.0, datetime.timedelta(seconds=16.8)), + self.make_ts_guess(3, 'autotst', ['autotst'], 2.0, datetime.timedelta(seconds=18.1)), + ]) + cells = self.column_cells(lines, 3) + self.assertEqual(len(set(cells)), 3, msg=f'the guess times collapsed into {set(cells)} in:\n' + + '\n'.join(lines)) + self.assertEqual(cells, ['3.4 s', '16.8 s', '18.1 s']) + + def test_the_imaginary_frequency_column(self): + """Test that the imaginary frequency column lists the frequencies and is blank when there are none.""" + lines = self.report([ + self.make_ts_guess(1, 'heuristics', ['heuristics'], 0.0, datetime.timedelta(seconds=1), + imaginary_freqs=[-1204.53]), + self.make_ts_guess(2, 'autotst', ['autotst'], 1.0, datetime.timedelta(seconds=1), + imaginary_freqs=[-209.4, -109.9]), + ]) + self.assert_tabulated(lines, n_rows=2) + self.assertEqual(self.column_cells(lines, 4), ['-1204.5', '-209.4, -109.9']) + + def test_column_widths_ignore_unreported_guesses(self): + """Test that a guess which is not reported does not widen the columns of the guesses that are.""" + def reported_guesses(): + return [self.make_ts_guess(3, 'heuristics', ['heuristics'], 0.0, datetime.timedelta(seconds=2.5)), + self.make_ts_guess(4, 'autotst', ['autotst'], 3.5, datetime.timedelta(seconds=4.5))] + omitted = self.make_ts_guess(1234, 'user guess', ['user guess', 'heuristics', 'autotst', 'gcn'], + 9.5, datetime.timedelta(days=5), success=False, errors='a very long error') + narrow = self.report(reported_guesses()) + wide = self.report(reported_guesses() + [omitted]) + self.assert_tabulated(narrow, n_rows=2) + self.assert_tabulated(wide, n_rows=2) + self.assertEqual(narrow, wide) + self.assertNotIn('a very long error', '\n'.join(wide)) + + def test_no_line_interrupts_the_table_at_debug_verbosity(self): + """Test that the per-guess draw does not emit a line between the rule and the last table row""" + scheduler = self.build_scheduler([ + self.make_ts_guess(0, 'heuristics', ['heuristics'], -50.0, datetime.timedelta(seconds=3.42)), + self.make_ts_guess(1, 'autotst', ['autotst'], -48.0, datetime.timedelta(seconds=18.15)), + ]) + lines = self.invoke(scheduler, level='DEBUG', draw=True) + rule_index = next(i for i, line in enumerate(lines) if line and set(line) <= set('- ')) + table = lines[:rule_index + 3] + self.assert_tabulated(table, n_rows=2) + self.assertEqual(self.column_cells(table, 0), ['0', '1'], + msg='a non-table line was emitted between the table rows:\n' + '\n'.join(lines)) + self.assertIn('not drawing 3D!', lines, + msg='the structures were not drawn, so this test cannot detect an interruption') + self.assertGreater(lines.index('not drawing 3D!'), rule_index + 2) + + def test_every_reported_guess_is_drawn_once_in_row_order(self): + """Test that the structures are drawn once per reported row, in the order of the rows""" + guesses = [self.make_ts_guess(0, 'heuristics', ['heuristics'], -50.0, datetime.timedelta(seconds=3.42)), + self.make_ts_guess(1, 'autotst', ['autotst'], -48.0, datetime.timedelta(seconds=18.15)), + self.make_ts_guess(2, 'gcn', ['gcn'], None, datetime.timedelta(seconds=1), success=False)] + scheduler = self.build_scheduler(guesses) + with patch('arc.scheduler.plotter.draw_structure') as draw_structure, \ + patch('arc.scheduler.plotter.save_conformers_file'): + scheduler.determine_most_likely_ts_conformer(label='TS0') + self.assertEqual([call.kwargs['xyz'] for call in draw_structure.call_args_list], + [guesses[0].initial_xyz, guesses[1].initial_xyz]) + + def test_the_reported_energies_are_relative_to_the_lowest_energy_of_any_guess(self): + """Test that an unsuccessful guess holding the lowest energy is still the reference point""" + lines = self.report([ + self.make_ts_guess(1, 'heuristics', ['heuristics'], 10.0, datetime.timedelta(seconds=1)), + self.make_ts_guess(2, 'autotst', ['autotst'], 20.0, datetime.timedelta(seconds=2)), + self.make_ts_guess(3, 'kinbot', ['kinbot'], -100.0, datetime.timedelta(seconds=3), success=False), + ]) + self.assertEqual(self.column_cells(lines, 2), ['110.00', '120.00']) + + def test_a_repeat_invocation_reports_the_same_energies(self): + """Test that invoking the selection twice for one label does not shift the reported energies""" + scheduler = self.build_scheduler([ + self.make_ts_guess(1, 'heuristics', ['heuristics'], 10.0, datetime.timedelta(seconds=1)), + self.make_ts_guess(2, 'autotst', ['autotst'], 20.0, datetime.timedelta(seconds=2)), + self.make_ts_guess(3, 'kinbot', ['kinbot'], -100.0, datetime.timedelta(seconds=3), success=False), + ]) + first = self.invoke(scheduler) + second = self.invoke(scheduler) + self.assertEqual(self.column_cells(first, 2), ['110.00', '120.00']) + self.assertEqual(self.column_cells(second, 2), self.column_cells(first, 2)) + self.assertEqual([tsg.energy for tsg in scheduler.species_dict['TS0'].ts_guesses], [110.0, 120.0, 0.0]) + + if __name__ == '__main__': unittest.main(testRunner=unittest.TextTestRunner(verbosity=2)) From 870ac3d319a673b08f8cf2292a7e5ef1601a592d Mon Sep 17 00:00:00 2001 From: Calvin Pieters Date: Sun, 16 Aug 2026 21:06:52 +0300 Subject: [PATCH 3/3] Do not parse a TS guess execution time that is about to be discarded TSGuess.from_dict() parsed ts_dict['execution_time'] near the top and then, for a 'user guess' method, overwrote the result with timedelta(seconds=0) at the bottom. Now that an unparseable duration is reported rather than silently read as zero, that ordering makes ARC warn about values it throws away: loading arc/testing/restart/2_restart_rate/restart.yml, whose four TS guesses are all 'user guess' entries carrying a legacy execution_time of '0', emitted three "Could not interpret '0' as a time delta" warnings per restart for a field whose restored value cannot depend on it. The method is now resolved before the execution time, and the execution time is not parsed at all when the method is a user guess, since the later branch is the authority on that value. Nothing else moves, and the warning is untouched for every guess whose execution time is actually kept - an unparseable duration on a kinbot or heuristics guess is a real loss of benchmark data and still says so. TSGuess.as_dict() writes str(self.execution_time) and from_dict() reads it back, so that pair is the path on which every TS guess's execution time was silently reset to zero on restart. Nothing tested the pair itself: the parser had a unit test that asserted only isinstance(result, datetime.timedelta), which timedelta(0) satisfies, so the defect survived a green suite. The new TestTSGuess cases round-trip a sub-second duration, a multi-day one and an exact zero through as_dict()/from_dict() and assert the restored value equals the original, load the restart fixture and assert it produces no warning, and assert that a non-user-guess entry with the same unparseable value still warns. That pins the behaviour at the level a restart actually exercises rather than at the level of the regex. --- arc/species/species.py | 5 +++-- arc/species/species_test.py | 34 ++++++++++++++++++++++++++++++++++ 2 files changed, 37 insertions(+), 2 deletions(-) diff --git a/arc/species/species.py b/arc/species/species.py index 7bc636ce25..e20b490f86 100644 --- a/arc/species/species.py +++ b/arc/species/species.py @@ -2669,10 +2669,11 @@ def from_dict(self, ts_dict: dict): self.success = ts_dict['success'] if 'success' in ts_dict else None self.energy = ts_dict['energy'] if 'energy' in ts_dict else None self.cluster = ts_dict['cluster'] if 'cluster' in ts_dict else None - self.execution_time = timedelta_from_str(ts_dict['execution_time']) if 'execution_time' in ts_dict \ + self.method = ts_dict['method'].lower() if 'method' in ts_dict else 'user guess' + self.execution_time = None if 'user guess' in self.method \ + else timedelta_from_str(ts_dict['execution_time']) if 'execution_time' in ts_dict \ and isinstance(ts_dict['execution_time'], str) \ else ts_dict['execution_time'] if 'execution_time' in ts_dict else None - self.method = ts_dict['method'].lower() if 'method' in ts_dict else 'user guess' if 'method_sources' in ts_dict and isinstance(ts_dict['method_sources'], list): self.method_sources = self._normalize_method_sources(ts_dict['method_sources']) else: diff --git a/arc/species/species_test.py b/arc/species/species_test.py index 1abac6ca85..dce65aef4d 100644 --- a/arc/species/species_test.py +++ b/arc/species/species_test.py @@ -15,6 +15,7 @@ ARC_TESTING_PATH, almost_equal_coords_lists, check_that_all_entries_are_in_list, + read_yaml_file, save_yaml_file, ) from arc.species.converter import check_xyz_dict @@ -3618,6 +3619,39 @@ def test_from_dict(self): self.assertEqual(list(ts_dict_for_report.keys()), ['method', 'method_sources', 'method_index', 'success', 'index', 'conformer_index', 'initial_xyz', 'opt_xyz']) + def test_execution_time_survives_the_dict_round_trip(self): + """Test that a non-zero execution time is not zeroed by an as_dict()/from_dict() restart round trip""" + for execution_time in [datetime.timedelta(seconds=3, microseconds=420000), + datetime.timedelta(days=2, hours=3), + datetime.timedelta(0), + ]: + tsg = TSGuess(method='KinBot', family='H_Abstraction', xyz=self.xyz_3, success=True) + tsg.execution_time = execution_time + tsg_dict = tsg.as_dict() + self.assertEqual(tsg_dict['execution_time'], str(execution_time)) + restored = TSGuess(ts_dict=tsg_dict) + self.assertEqual(restored.execution_time, execution_time, + msg=f'execution time {str(execution_time)!r} was not preserved by the round trip') + + def test_a_user_guess_execution_time_is_overwritten_without_being_parsed(self): + """Test that restoring a user guess does not warn about an execution time it then discards""" + restart_path = os.path.join(ARC_PATH, 'arc', 'testing', 'restart', '2_restart_rate', 'restart.yml') + ts_dicts = [ts_dict for spc_dict in read_yaml_file(restart_path)['species'] + for ts_dict in spc_dict.get('ts_guesses') or list()] + self.assertTrue(any(ts_dict.get('execution_time') == '0' for ts_dict in ts_dicts), + msg='the fixture no longer holds an unparseable execution time, so this test is vacuous') + with self.assertNoLogs('arc', level='WARNING'): + restored = [TSGuess(ts_dict=ts_dict) for ts_dict in ts_dicts] + for tsg in restored: + self.assertIn('user guess', tsg.method) + self.assertEqual(tsg.execution_time, datetime.timedelta(0)) + + def test_an_unparseable_execution_time_still_warns_when_it_is_kept(self): + """Test that an unparseable execution time of a guess that keeps it is still reported""" + with self.assertLogs('arc', level='WARNING'): + tsg = TSGuess(ts_dict={'method': 'kinbot', 'execution_time': '0', 'initial_xyz': self.xyz_3}) + self.assertIsNone(tsg.execution_time) + def test_process_xyz(self): """Test the process_xyz() method""" # path