Validate task messages

CHANGES.md

@@ -72,6 +72,9 @@ exporting environment variables.
 [#3614](https://github.com/cylc/cylc-flow/pull/3614) - Ensure the suite always
 restarts using the same time zone as the last `cylc run`.
 
+[#3788](https://github.com/cylc/cylc-flow/pull/3788) - Task messages are now
+validated.
+
 -------------------------------------------------------------------------------
 ## __cylc-8.0a2 (2020-07-03)__
 

cylc/flow/__init__.py

@@ -23,6 +23,15 @@
 LOG = logging.getLogger(CYLC_LOG)
 LOG.addHandler(logging.NullHandler())  # Start with a null handler
 
+LOG_LEVELS = {
+    "INFO": logging.INFO,
+    "NORMAL": logging.INFO,
+    "WARNING": logging.WARNING,
+    "ERROR": logging.ERROR,
+    "CRITICAL": logging.CRITICAL,
+    "DEBUG": logging.DEBUG,
+}
+
 # Used widely with data element ID (internally and externally),
 # scope may widen further with internal and CLI adoption.
 ID_DELIM = '|'

cylc/flow/config.py

@@ -70,7 +70,8 @@
 from cylc.flow.task_id import TaskID
 from cylc.flow.task_outputs import TASK_OUTPUT_SUCCEEDED
 from cylc.flow.task_trigger import TaskTrigger, Dependency
-from cylc.flow.unicode_rules import XtriggerNameValidator
+from cylc.flow.unicode_rules import (
+    XtriggerNameValidator, MessageTriggerValidator)
 from cylc.flow.wallclock import (
     get_current_time_string, set_utc_mode, get_utc_mode)
 from cylc.flow.xtrigger_mgr import XtriggerManager
@@ -1603,10 +1604,9 @@ def generate_edges(self, lexpr, orig_lexpr, left_nodes, right, seq,
                 if suicide:
                     continue
                 if orig_lexpr != lexpr:
-                    LOG.error("%s => %s" % (orig_lexpr, right))
+                    LOG.error(f"{orig_lexpr} => {right}")
                 raise SuiteConfigError(
-                    "self-edge detected: %s => %s" % (
-                        left, right))
+                    f"self-edge detected: {left} => {right}")
             self.edges[seq].add((left, right, suicide, conditional))
 
     def generate_taskdefs(self, orig_expr, left_nodes, right, seq, suicide):
@@ -1661,6 +1661,13 @@ def generate_taskdefs(self, orig_expr, left_nodes, right, seq, suicide):
 
             # Record custom message outputs.
             for item in self.cfg['runtime'][name]['outputs'].items():
+                output, task_message = item
+                valid, msg = MessageTriggerValidator.validate(task_message)
+                if not valid:
+                    raise SuiteConfigError(
+                        f'Invalid task message "[runtime][{name}][outputs]'
+                        f'{output} = {task_message}" - {msg}'
+                    )
                 taskdef.outputs.add(item)
 
     def generate_triggers(self, lexpression, left_nodes, right, seq,
@@ -1693,7 +1700,7 @@ def generate_triggers(self, lexpression, left_nodes, right, seq,
 
             # Qualifier.
             outputs = self.cfg['runtime'][name]['outputs']
-            if outputs and output in outputs:
+            if outputs and (output in outputs):
                 # Qualifier is a task message.
                 qualifier = outputs[output]
             elif output:

cylc/flow/scripts/cylc_message.py

@@ -53,7 +53,7 @@
 environments - you do not need to write their actual values in task scripting.
 
 Each message can be prefixed with a severity level using the syntax 'SEVERITY:
-MESSAGE'.
+MESSAGE' (colons cannot be used unless such a prefix is provided).
 
 The default message severity is INFO. The --severity=SEVERITY option can be
 used to set the default severity level for all unprefixed messages.
@@ -111,7 +111,7 @@ def main(parser, options, *args):
     # Read messages from STDIN
     if '-' in message_strs:
         current_message_str = ''
-        while True:  # Note: for line in sys.stdin: can hang
+        while True:  # Note: `for line in sys.stdin:` can hang
             message_str = sys.stdin.readline()
             if message_str.strip():
                 # non-empty line

cylc/flow/scripts/cylc_set_verbosity.py

@@ -22,28 +22,18 @@
 or above the chosen severity level will be logged; for example, if you
 choose WARNING, only warnings and critical messages will be logged."""
 
-from logging import CRITICAL, ERROR, WARNING, INFO, DEBUG
-
+from cylc.flow import LOG_LEVELS
 from cylc.flow.option_parsers import CylcOptionParser as COP
 from cylc.flow.network.client import SuiteRuntimeClient
 from cylc.flow.terminal import cli_function
 
-LOGGING_LVL_OF = {
-    "INFO": INFO,
-    "NORMAL": INFO,
-    "WARNING": WARNING,
-    "ERROR": ERROR,
-    "CRITICAL": CRITICAL,
-    "DEBUG": DEBUG,
-}
-
 
 def get_option_parser():
     parser = COP(
         __doc__, comms=True,
         argdoc=[
             ('REG', 'Suite name'),
-            ('LEVEL', ', '.join(LOGGING_LVL_OF.keys()))
+            ('LEVEL', ', '.join(LOG_LEVELS.keys()))
         ]
     )
 
@@ -53,7 +43,7 @@ def get_option_parser():
 @cli_function(get_option_parser)
 def main(parser, options, suite, severity_str):
     try:
-        severity = LOGGING_LVL_OF[severity_str]
+        severity = LOG_LEVELS[severity_str]
     except KeyError:
         parser.error("Illegal logging level, %s" % severity_str)
 

cylc/flow/task_events_mgr.py

@@ -26,15 +26,15 @@
 """
 
 from collections import namedtuple
-from logging import getLevelName, CRITICAL, ERROR, WARNING, INFO, DEBUG
+from logging import getLevelName, INFO, DEBUG
 import os
 from shlex import quote
 import shlex
 from time import time
 
 from cylc.flow.parsec.config import ItemNotFoundError
 
-from cylc.flow import LOG
+from cylc.flow import LOG, LOG_LEVELS
 from cylc.flow.cfgspec.glbl_cfg import glbl_cfg
 from cylc.flow.hostuserutil import get_host, get_user
 from cylc.flow.pathutil import (
@@ -124,14 +124,6 @@ class TaskEventsManager():
     FLAG_POLLED = "(polled)"
     FLAG_POLLED_IGNORED = "(polled-ignored)"
     KEY_EXECUTE_TIME_LIMIT = 'execution_time_limit'
-    LEVELS = {
-        "INFO": INFO,
-        "NORMAL": INFO,
-        "WARNING": WARNING,
-        "ERROR": ERROR,
-        "CRITICAL": CRITICAL,
-        "DEBUG": DEBUG,
-    }
     NON_UNIQUE_EVENTS = ('warning', 'critical', 'custom')
 
     def __init__(self, suite, proc_pool, suite_db_mgr,
@@ -454,7 +446,7 @@ def process_message(
             LOG.debug(
                 '[%s] status=%s: unhandled: %s',
                 itask, itask.state.status, message)
-            if severity in [CRITICAL, ERROR, WARNING, INFO, DEBUG]:
+            if severity in LOG_LEVELS.values():
                 severity = getLevelName(severity)
             self._db_events_insert(
                 itask, ("message %s" % str(severity).lower()), message)
@@ -501,7 +493,7 @@ def _process_message_check(
                 timestamp, submit_num, itask.flow_label)
             return False
         LOG.log(
-            self.LEVELS.get(severity, INFO), logfmt, itask, itask.state, flag,
+            LOG_LEVELS.get(severity, INFO), logfmt, itask, itask.state, flag,
             message, timestamp, submit_num, itask.flow_label)
         return True
 

cylc/flow/unicode_rules.py

@@ -17,14 +17,15 @@
 """Module for unicode restrictions"""
 
 import re
+from cylc.flow import LOG_LEVELS
 
 
 ENGLISH_REGEX_MAP = {
     r'\w': 'alphanumeric',
     r'a-zA-Z0-9': 'latin letters and numbers',
-    r'\-': '-',
-    r'\.': '.',
-    r'\/': '/'
+    r'\-': '``-``',
+    r'\.': '``.``',
+    r'\/': '``/``'
 }
 
 
@@ -38,10 +39,12 @@ def regex_chars_to_text(chars):
         ['-', '.', '/']
         >>> regex_chars_to_text([r'\w'])
         ['alphanumeric']
+        >>> regex_chars_to_text(['not_in_map'])
+        ['not_in_map']
 
     """
     return [
-        ENGLISH_REGEX_MAP.get(char, char)
+        ENGLISH_REGEX_MAP.get(char, f'``{char}``')
         for char in chars
     ]
 
@@ -71,7 +74,7 @@ def allowed_characters(*chars):
     Example:
         >>> regex, message = allowed_characters('a', 'b', 'c')
         >>> message
-        'can only contain: a, b, c'
+        'can only contain: ``a``, ``b``, ``c``'
         >>> bool(regex.match('abc'))
         True
         >>> bool(regex.match('def'))
@@ -90,7 +93,7 @@ def not_starts_with(*chars):
     Example:
         >>> regex, message = not_starts_with('a', 'b', 'c')
         >>> message
-        'can not start with: a, b, c'
+        'can not start with: ``a``, ``b``, ``c``'
         >>> bool(regex.match('def'))
         True
         >>> bool(regex.match('adef'))
@@ -103,6 +106,29 @@ def not_starts_with(*chars):
     )
 
 
+def not_contains_colon_unless_starts_with(*chars):
+    """Restrict use of colons.
+
+    Example:
+        >>> regex, message = not_contain_colon_unless_starts_with(
+                'INFO', 'WARNING')
+        >>> message
+        'cannot contain a colon unless starts with: ``INFO``, ``WARNING``'
+        >>> bool(regex.match('Foo: bar'))
+        False
+        >>> bool(regex.match('INFO: Foo: bar'))
+        True
+        >>> bool(regex.match('Foo bar'))
+        True
+
+    """
+    return (
+        re.compile(r'(^(%s):|^[^:]*$)' % '|'.join(chars)),
+        ('cannot contain a colon unless starts with: '
+         f'{", ".join(regex_chars_to_text(chars))}')
+    )
+
+
 class UnicodeRuleChecker():
 
     RULES = []
@@ -151,3 +177,11 @@ class XtriggerNameValidator(UnicodeRuleChecker):
     RULES = [
         allowed_characters(r'a-zA-Z0-9', '_')
     ]
+
+
+class MessageTriggerValidator(UnicodeRuleChecker):
+    """The rules for valid custom output message trigger contents:"""
+
+    RULES = [
+        not_contains_colon_unless_starts_with(*LOG_LEVELS.keys())
+    ]

tests/unit/test_suite_files.py

@@ -175,7 +175,7 @@ def get_register_test_cases():
          None,  # expected symlink
          None,  # expected return value
          SuiteServiceFileError,  # expected exception
-         "can not start with: ., -"  # expected part of exception message
+         "can not start with: ``.``, ``-``"  # expected part of exception msg
          )
     ]
 

tests/unit/test_unicode_rules.py

@@ -0,0 +1,39 @@
+# THIS FILE IS PART OF THE CYLC SUITE 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
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+"""Test validation of unicode rules and similar."""
+
+from cylc.flow.unicode_rules import MessageTriggerValidator
+
+
+def test_task_message_validation():
+    """Test that `[runtime][<task>][outputs]<output> = msg` messages validate
+    correctly."""
+    tests = [
+        ('Chronon Field Regulator', True),
+        # Cannot have colon unless first part of message is logging
+        # severity level:
+        ('Time machine location: Bradbury Swimming Pool', False),
+        # but after that colons are okay:
+        ('INFO: Time machine location: Bradbury Swimming Pool', True),
+        # simply poor form:
+        ('Foo:', False),
+        (':Foo', False),
+        ('::group::', False)
+    ]
+    for task_message, expected in tests:
+        valid, _ = MessageTriggerValidator.validate(task_message)
+        assert valid is expected