Stop traceback when ParsecError occurs during config load on workflow run

CHANGES.md

@@ -36,6 +36,10 @@ ones in. -->
 [#4777](https://github.com/cylc/cylc-flow/pull/4777) -
 Reinstate the Cylc 7 template variables for xtriggers with deprecation warnings.
 
+[#4720](https://github.com/cylc/cylc-flow/pull/4720) - Fix traceback in
+workflow logs when starting or reloading a workflow with an illegal item
+(e.g. typo) in the config.
+
 -------------------------------------------------------------------------------
 ## __cylc-8.0rc2 (<span actions:bind='release-date'>Released 2022-03-23</span>)__
 

cylc/flow/config.py

@@ -177,7 +177,6 @@ def __init__(
         fpath: Union[Path, str],
         options: 'Values',
         template_vars: Optional[Mapping[str, Any]] = None,
-        is_reload: bool = False,
         output_fname: Optional[str] = None,
         xtrigger_mgr: Optional[XtriggerManager] = None,
         mem_log_func: Optional[Callable[[str], None]] = None,

cylc/flow/parsec/exceptions.py

@@ -27,6 +27,11 @@
 class ParsecError(Exception):
     """Generic exception for Parsec errors."""
 
+    schd_expected: bool = False
+    """Set this flag to True on the exception if it is anticipated during
+    Cylc Scheduler run (apart from loading of config we do not expect
+    ParsecErrors during runtime)."""
+
 
 class ItemNotFoundError(ParsecError, KeyError):
     """Error raised for missing configuration items."""

cylc/flow/parsec/fileparse.py

@@ -458,17 +458,15 @@ def read_and_proc(fpath, template_vars=None, viewcfg=None, opts=None):
 def hashbang_and_plugin_templating_clash(
     templating: str, flines: List[str]
 ) -> Optional[str]:
-    """Check whether plugin set template engine and #!hashbang line match.
+    """Return file's hashbang/shebang, but raise TemplateVarLanguageClash
+    if plugin-set template engine and hashbang do not match.
 
     Args:
-        templating (str): [description]
-        flines (List[str]): [description]
-
-    Raises:
-        TemplateVarLanguageClash
+        templating: Template engine set by a plugin.
+        flines: The lines of text from file.
 
     Returns:
-        str: the hashbang, in lower case, to allow for users using any of
+        The hashbang, in lower case, to allow for users using any of
         ['empy', 'EmPy', 'EMPY'], or similar in other templating languages.
 
     Examples:
@@ -486,20 +484,19 @@ def hashbang_and_plugin_templating_clash(
                 ...
             cylc.flow.parsec.exceptions.TemplateVarLanguageClash: ...
     """
+    hashbang: Optional[str] = None
     # Get hashbang if possible:
-    if flines and re.match(r'^#!(.*)\s*', flines[0]):
-        hashbang = re.findall(r'^#!(.*)\s*', flines[0])[0].lower()
-    else:
-        hashbang = None
-
+    if flines:
+        match = re.match(r'^#!(\S+)', flines[0])
+        if match:
+            hashbang = match[1].lower()
     if (
         hashbang and templating
         and templating != 'template variables'
         and hashbang != templating
     ):
         raise TemplateVarLanguageClash(
-            "Plugins set templating engine = "
-            f"{templating}"
+            f"A plugin set the templating engine to {templating}"
             f" which does not match {flines[0]} set in flow.cylc."
         )
     return hashbang

cylc/flow/parsec/validate.py

@@ -30,7 +30,7 @@
 from metomi.isodatetime.data import Duration, TimePoint, Calendar
 from metomi.isodatetime.dumpers import TimePointDumper
 from metomi.isodatetime.parsers import TimePointParser, DurationParser
-from metomi.isodatetime.exceptions import IsodatetimeError
+from metomi.isodatetime.exceptions import IsodatetimeError, ISO8601SyntaxError
 
 from cylc.flow.parsec.exceptions import (
     ListValueError, IllegalValueError, IllegalItemError)
@@ -260,8 +260,8 @@ def coerce_float(cls, value, keys):
             return None
         try:
             return float(value)
-        except ValueError:
-            raise IllegalValueError('float', keys, value)
+        except ValueError as exc:
+            raise IllegalValueError('float', keys, value, exc=exc)
 
     @classmethod
     def coerce_float_list(cls, value, keys):
@@ -289,8 +289,8 @@ def coerce_int(cls, value, keys):
             return None
         try:
             return int(value)
-        except ValueError:
-            raise IllegalValueError('int', keys, value)
+        except ValueError as exc:
+            raise IllegalValueError('int', keys, value, exc=exc)
 
     @classmethod
     def coerce_int_list(cls, value, keys):
@@ -783,12 +783,17 @@ def coerce_cycle_point(cls, value, keys):
                 else:
                     parser.parse(value)
                 return value
-            except IsodatetimeError:
-                raise IllegalValueError("cycle point", keys, value)
+            except IsodatetimeError as exc:
+                raise IllegalValueError('cycle point', keys, value, exc=exc)
         try:
             TimePointParser().parse(value)
-        except IsodatetimeError:
-            raise IllegalValueError('cycle point', keys, value)
+        except IsodatetimeError as exc:
+            if isinstance(exc, ISO8601SyntaxError):
+                # Don't know cycling mode yet, so override ISO8601-specific msg
+                details = {'msg': "Invalid cycle point"}
+            else:
+                details = {'exc': exc}
+            raise IllegalValueError('cycle point', keys, value, **details)
         return value
 
     @classmethod
@@ -827,8 +832,10 @@ def coerce_cycle_point_format(cls, value, keys):
         if '%' in value:
             try:
                 TimePointDumper().strftime(test_timepoint, value)
-            except IsodatetimeError:
-                raise IllegalValueError('cycle point format', keys, value)
+            except IsodatetimeError as exc:
+                raise IllegalValueError(
+                    'cycle point format', keys, value, exc=exc
+                )
             return value
         if 'X' in value:
             for i in range(1, 101):
@@ -842,8 +849,8 @@ def coerce_cycle_point_format(cls, value, keys):
         dumper = TimePointDumper()
         try:
             dumper.dump(test_timepoint, value)
-        except IsodatetimeError:
-            raise IllegalValueError('cycle point format', keys, value)
+        except IsodatetimeError as exc:
+            raise IllegalValueError('cycle point format', keys, value, exc=exc)
         return value
 
     @classmethod
@@ -874,9 +881,10 @@ def coerce_cycle_point_time_zone(cls, value, keys):
         parser = TimePointParser(allow_only_basic=True)
         try:
             parser.parse(test_timepoint_string)
-        except ValueError:  # not IsodatetimeError as too specific
+        except ValueError as exc:  # not IsodatetimeError as too specific
             raise IllegalValueError(
-                'cycle point time zone format', keys, value)
+                'cycle point time zone format', keys, value, exc=exc
+            )
         return value
 
     @classmethod
@@ -894,8 +902,8 @@ def coerce_interval(cls, value, keys):
             return None
         try:
             interval = DurationParser().parse(value)
-        except IsodatetimeError:
-            raise IllegalValueError("ISO 8601 interval", keys, value)
+        except IsodatetimeError as exc:
+            raise IllegalValueError("ISO 8601 interval", keys, value, exc=exc)
         days, seconds = interval.get_days_and_seconds()
         return DurationFloat(
             days * Calendar.default().SECONDS_IN_DAY + seconds)

cylc/flow/scheduler.py

@@ -52,7 +52,11 @@
 from cylc.flow.id import Tokens
 from cylc.flow.flow_mgr import FlowMgr
 from cylc.flow.exceptions import (
-    CommandFailedError, CyclingError, CylcError, UserInputError
+    CommandFailedError,
+    CyclingError,
+    CylcConfigError,
+    CylcError,
+    UserInputError,
 )
 import cylc.flow.flags
 from cylc.flow.host_select import select_workflow_host
@@ -72,7 +76,7 @@
 from cylc.flow.network.schema import WorkflowStopMode
 from cylc.flow.network.server import WorkflowRuntimeServer
 from cylc.flow.option_parsers import verbosity_to_env
-from cylc.flow.parsec.exceptions import TemplateVarLanguageClash
+from cylc.flow.parsec.exceptions import ParsecError
 from cylc.flow.parsec.OrderedDict import DictTree
 from cylc.flow.parsec.validate import DurationFloat
 from cylc.flow.pathutil import (
@@ -125,12 +129,10 @@
 
 class SchedulerStop(CylcError):
     """Scheduler normal stop."""
-    pass
 
 
 class SchedulerError(CylcError):
     """Scheduler expected error stop."""
-    pass
 
 
 @dataclass
@@ -441,7 +443,12 @@ async def configure(self):
                 pri_dao.close()
 
         self.profiler.log_memory("scheduler.py: before load_flow_file")
-        self.load_flow_file()
+        try:
+            self.load_flow_file()
+        except ParsecError as exc:
+            # Mark this exc as expected (see docstring for .schd_expected):
+            exc.schd_expected = True
+            raise exc
         self.profiler.log_memory("scheduler.py: after load_flow_file")
 
         self.workflow_db_mgr.on_workflow_start(self.is_restart)
@@ -833,7 +840,7 @@ def get_command_method(self, command_name: str) -> Callable:
         """Return a command processing method or raise AttributeError."""
         return getattr(self, f'command_{command_name}')
 
-    def queue_command(self, command, kwargs):
+    def queue_command(self, command: str, kwargs: dict) -> None:
         self.command_queue.put((
             command,
             tuple(kwargs.values()), {}
@@ -863,7 +870,7 @@ def process_command_queue(self) -> None:
             except SchedulerStop:
                 LOG.info(f"Command succeeded: {cmdstr}")
                 raise
-            except (CommandFailedError, Exception) as exc:
+            except Exception as exc:
                 # Don't let a bad command bring the workflow down.
                 if (
                     cylc.flow.flags.verbosity > 1 or
@@ -1025,7 +1032,10 @@ def command_reload_workflow(self):
         pri_dao = self.workflow_db_mgr.get_pri_dao()
         pri_dao.select_workflow_params(self._load_workflow_params)
 
-        self.load_flow_file(is_reload=True)
+        try:
+            self.load_flow_file(is_reload=True)
+        except (ParsecError, CylcConfigError) as exc:
+            raise CommandFailedError(f"{type(exc).__name__}: {exc}")
         self.broadcast_mgr.linearized_ancestors = (
             self.config.get_linearized_ancestors())
         self.pool.set_do_reload(self.config)
@@ -1107,7 +1117,6 @@ def load_flow_file(self, is_reload=False):
             self.flow_file,
             self.options,
             self.template_vars,
-            is_reload=is_reload,
             xtrigger_mgr=self.xtrigger_mgr,
             mem_log_func=self.profiler.log_memory,
             output_fname=os.path.join(
@@ -1123,6 +1132,7 @@ def load_flow_file(self, is_reload=False):
             self.config.cfg['scheduler'],
             glbl_cfg().get(['scheduler'])
         )
+
         self.flow_file_update_time = time()
         # Dump the loaded flow.cylc file for future reference.
         time_str = get_current_time_string(
@@ -1699,12 +1709,15 @@ async def _shutdown(self, reason: Exception) -> None:
             if self.auto_restart_mode != AutoRestartMode.RESTART_NORMAL:
                 self.resume_workflow(quiet=True)
         elif isinstance(reason, SchedulerError):
-            LOG.error(f'Workflow shutting down - {reason}')
-        elif isinstance(reason, (CylcError, TemplateVarLanguageClash)):
+            LOG.error(f"Workflow shutting down - {reason}")
+        elif isinstance(reason, CylcError) or (
+            isinstance(reason, ParsecError) and reason.schd_expected
+        ):
             LOG.error(
-                "Workflow shutting down - "
-                f"{reason.__class__.__name__}: {reason}")
+                f"Workflow shutting down - {type(reason).__name__}: {reason}"
+            )
             if cylc.flow.flags.verbosity > 1:
+                # Print traceback
                 LOG.exception(reason)
         else:
             LOG.exception(reason)
@@ -1741,6 +1754,7 @@ async def _shutdown(self, reason: Exception) -> None:
                 [(b'shutdown', str(reason).encode('utf-8'))]
             )
             self.publisher.stop()
+            self.publisher = None
         if self.curve_auth:
             self.curve_auth.stop()  # stop the authentication thread
 
@@ -1771,6 +1785,10 @@ async def _shutdown(self, reason: Exception) -> None:
             except OSError as exc:
                 LOG.warning(f"failed to remove workflow contact file: {fname}")
                 LOG.exception(exc)
+            else:
+                # Useful to identify that this Scheduler has shut down
+                # properly (e.g. in tests):
+                self.contact_data = None
             if self.task_job_mgr:
                 self.task_job_mgr.task_remote_mgr.remote_tidy()
 

cylc/flow/scripts/diff.py

@@ -157,8 +157,7 @@ def main(parser: COP, options: 'Values', workflow_id1: str, workflow_id2: str):
     ).cfg
     print(f"Parsing {workflow_id_2} ({workflow_file_2_})")
     config2 = WorkflowConfig(
-        workflow_id_2, workflow_file_2_, options, template_vars,
-        is_reload=True
+        workflow_id_2, workflow_file_2_, options, template_vars
     ).cfg
 
     if config1 == config2:

tests/conftest.py

@@ -85,13 +85,16 @@ def log_filter():
         level: Filter out records if they aren't at this logging level.
         contains: Filter out records if this string is not in the message.
         regex: Filter out records if the message doesn't match this regex.
+        exact_match: Filter out records if the message does not exactly match
+            this string.
     """
     def _log_filter(
         log: pytest.LogCaptureFixture,
         name: Optional[str] = None,
         level: Optional[int] = None,
         contains: Optional[str] = None,
-        regex: Optional[str] = None
+        regex: Optional[str] = None,
+        exact_match: Optional[str] = None,
     ) -> List[Tuple[str, int, str]]:
         return [
             (log_name, log_level, log_message)
@@ -100,6 +103,7 @@ def _log_filter(
             and (level is None or level == log_level)
             and (contains is None or contains in log_message)
             and (regex is None or re.match(regex, log_message))
+            and (exact_match is None or exact_match == log_message)
         ]
     return _log_filter
 

tests/functional/validate/14-fail-old-syntax-3.t

@@ -1,7 +1,7 @@
 #!/usr/bin/env bash
 # THIS FILE IS PART OF THE CYLC WORKFLOW ENGINE.
 # Copyright (C) NIWA & British Crown (Met Office) & Contributors.
-# 
+#
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU General Public License as published by
 # the Free Software Foundation, either version 3 of the License, or
@@ -25,7 +25,7 @@ install_workflow "${TEST_NAME_BASE}" "${TEST_NAME_BASE}"
 TEST_NAME=${TEST_NAME_BASE}
 run_fail "${TEST_NAME}" cylc validate "${WORKFLOW_NAME}"
 cmp_ok "${TEST_NAME}.stderr" <<__END__
-IllegalValueError: (type=ISO 8601 interval) [runtime][root][events]execution timeout = 3
+IllegalValueError: (type=ISO 8601 interval) [runtime][root][events]execution timeout = 3 - (Invalid ISO 8601 duration representation: 3)
 __END__
 #-------------------------------------------------------------------------------
 purge