task_events_mgr: include event message with event emails

* Closes #5566
* Note, the event message is not stored in the database, so when events
  are restored from the DB on restart, the event message will default to
  the event name.

Author: oliver-sanders

changes.d/5769.feat.md

@@ -0,0 +1 @@
+Include task messages and workflow port as appropriate in emails configured by "mail events".

cylc/flow/id.py

@@ -163,6 +163,12 @@ def __eq__(self, other):
             for key in self._KEYS
         )
 
+    def __lt__(self, other):
+        return self.id < other.id
+
+    def __gt__(self, other):
+        return self.id > other.id
+
     def __ne__(self, other):
         if not isinstance(other, self.__class__):
             return True

cylc/flow/task_events_mgr.py

@@ -126,6 +126,13 @@ class EventKey(NamedTuple):
     """The task event."""
     event: str
 
+    """The task event message.
+
+    Warning: This information is not currently preserved in the DB so will be
+    lost on restart.
+    """
+    message: str
+
     """The job tokens."""
     tokens: 'Tokens'
 
@@ -897,7 +904,7 @@ def setup_event_handlers(self, itask, event, message):
             msg = message
         self._db_events_insert(itask, event, msg)
         self._setup_job_logs_retrieval(itask, event)
-        self._setup_event_mail(itask, event)
+        self._setup_event_mail(itask, event, message)
         self._setup_custom_event_handlers(itask, event, message)
 
     def _custom_handler_callback(
@@ -951,14 +958,18 @@ def _process_event_email(
                 subject = "[%d task events] %s" % (
                     len(id_keys), schd.workflow)
         cmd = ["mail", "-s", subject]
+
         # From: and To:
         cmd.append("-r")
         cmd.append(ctx.mail_from)
         cmd.append(ctx.mail_to)
+
         # STDIN for mail, tasks
         stdin_str = ""
         for id_key in sorted(id_keys):
-            stdin_str += f'{id_key.event}: {id_key.tokens.relative_id}\n'
+            stdin_str += f'job: {id_key.tokens.relative_id}\n'
+            stdin_str += f'event: {id_key.event}\n'
+            stdin_str += f'message: {id_key.message}\n\n'
 
         # STDIN for mail, event info + workflow detail
         stdin_str += "\n"
@@ -1491,6 +1502,7 @@ def _setup_job_logs_retrieval(self, itask, event) -> None:
         id_key = EventKey(
             self.HANDLER_JOB_LOGS_RETRIEVE,
             event,
+            event,
             itask.tokens.duplicate(job=itask.submit_num),
         )
         if id_key in self._event_timers:
@@ -1514,7 +1526,12 @@ def _setup_job_logs_retrieval(self, itask, event) -> None:
             )
         )
 
-    def _setup_event_mail(self, itask: 'TaskProxy', event: str) -> None:
+    def _setup_event_mail(
+        self,
+        itask: 'TaskProxy',
+        event: str,
+        message: str,
+    ) -> None:
         """Set up task event notification, by email."""
         if event not in self._get_events_conf(itask, "mail events", []):
             # event does not need to be processed
@@ -1523,6 +1540,7 @@ def _setup_event_mail(self, itask: 'TaskProxy', event: str) -> None:
         id_key = EventKey(
             self.HANDLER_MAIL,
             get_event_id(event, itask),
+            message,
             itask.tokens.duplicate(job=itask.submit_num),
         )
         if id_key in self._event_timers:
@@ -1571,6 +1589,7 @@ def _setup_custom_event_handlers(
             id_key = EventKey(
                 f'{self.HANDLER_CUSTOM}-{i:02d}',
                 get_event_id(event, itask),
+                message,
                 itask.tokens.duplicate(job=itask.submit_num),
             )
 

cylc/flow/task_pool.py

@@ -689,6 +689,9 @@ def load_db_task_action_timers(self, row_idx, row) -> None:
                 EventKey(
                     handler,
                     event,
+                    # NOTE: the event "message" is not preserved in the DB so
+                    # we use the event as a placeholder
+                    event,
                     tokens.duplicate(job=submit_num),
                 ),
                 TaskActionTimer(

tests/functional/events/09-task-event-mail.t

@@ -20,7 +20,7 @@
 if ! command -v mail 2>'/dev/null'; then
     skip_all '"mail" command not available'
 fi
-set_test_number 5
+set_test_number 6
 mock_smtpd_init
 OPT_SET=
 if [[ "${TEST_NAME_BASE}" == *-globalcfg ]]; then
@@ -49,17 +49,15 @@ run_ok "${TEST_NAME_BASE}-validate" \
 workflow_run_ok "${TEST_NAME_BASE}-run" \
     cylc play --reference-test --debug --no-detach ${OPT_SET} "${WORKFLOW_NAME}"
 
-contains_ok "${TEST_SMTPD_LOG}" <<__LOG__
-retry: 1/t1/01
-succeeded: 1/t1/02
-see: http://localhost/stuff/${USER}/${WORKFLOW_NAME}/
-__LOG__
+run_ok "${TEST_NAME_BASE}-grep-log-1" \
+    grep -Pizo 'job: 1/t1/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-grep-log-2" \
+    grep -Pizo 'job: 1/t1/02.*\n.*event: succeeded' "${TEST_SMTPD_LOG}"
 
-
-run_ok "${TEST_NAME_BASE}-grep-log" \
-    grep -qPizo "Subject: \[1/t1/01 retry\]\n? ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
-run_ok "${TEST_NAME_BASE}-grep-log" \
-    grep -qPizo "Subject: \[1/t1/02 succeeded\]\n? ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-grep-log-3" \
+    grep -Pizo "Subject: \[1/t1/01 retry\].*(\n)?.* ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-grep-log-4" \
+    grep -Pizo "Subject: \[1/t1/02 succeeded\].*(\n)?.* ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
 
 purge
 mock_smtpd_kill

tests/functional/events/29-task-event-mail-1.t

@@ -20,7 +20,7 @@
 if ! command -v mail 2>'/dev/null'; then
     skip_all '"mail" command not available'
 fi
-set_test_number 4
+set_test_number 5
 
 mock_smtpd_init
 create_test_global_config "
@@ -37,13 +37,15 @@ run_ok "${TEST_NAME_BASE}-validate" \
 workflow_run_ok "${TEST_NAME_BASE}-run" \
     cylc play --reference-test --debug --no-detach "$WORKFLOW_NAME"
 
-contains_ok "${TEST_SMTPD_LOG}" <<__LOG__
-retry: 1/t1/01
-see: http://localhost/stuff/${USER}/${WORKFLOW_NAME}/
-__LOG__
+run_ok "${TEST_NAME_BASE}-grep-log-1" \
+    grep -Pizo "job: 1/t1/01.*\n.*event: retry.*\n.*" "${TEST_SMTPD_LOG}"
 
-run_ok "${TEST_NAME_BASE}-grep-log" \
-    grep -qPizo "Subject: \[1/t1/01 retry\]\n? ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-grep-log-2" grep  \
+    "see: http://localhost/stuff/${USER}/${WORKFLOW_NAME}/" \
+    "${TEST_SMTPD_LOG}"
+
+run_ok "${TEST_NAME_BASE}-grep-log-2" \
+    grep -Pizo "Subject: \\[1/t1/01 retry\\].*(\n)?.*${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
 
 purge
 mock_smtpd_kill

tests/functional/events/30-task-event-mail-2.t

@@ -20,7 +20,7 @@
 if ! command -v mail 2>'/dev/null'; then
     skip_all '"mail" command not available'
 fi
-set_test_number 5
+set_test_number 20
 mock_smtpd_init
 OPT_SET=
 if [[ "${TEST_NAME_BASE}" == *-globalcfg ]]; then
@@ -49,22 +49,29 @@ run_ok "${TEST_NAME_BASE}-validate" \
 workflow_run_fail "${TEST_NAME_BASE}-run" \
     cylc play --reference-test --debug --no-detach ${OPT_SET} "${WORKFLOW_NAME}"
 
+# 1 - retry
+run_ok "${TEST_NAME_BASE}-t1-01" grep -Pizo 'job: 1/t1/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t2-01" grep -Pizo 'job: 1/t2/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t3-01" grep -Pizo 'job: 1/t3/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t4-01" grep -Pizo 'job: 1/t4/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t5-01" grep -Pizo 'job: 1/t5/01.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+
+# 2 - retry
+run_ok "${TEST_NAME_BASE}-t1-02" grep -Pizo 'job: 1/t1/02.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t2-02" grep -Pizo 'job: 1/t2/02.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t3-02" grep -Pizo 'job: 1/t3/02.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t4-02" grep -Pizo 'job: 1/t4/02.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t5-02" grep -Pizo 'job: 1/t5/02.*\n.*event: retry' "${TEST_SMTPD_LOG}"
+
+# 3 - fail
+run_ok "${TEST_NAME_BASE}-t1-03" grep -Pizo 'job: 1/t1/03.*\n.*event: failed' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t2-03" grep -Pizo 'job: 1/t2/03.*\n.*event: failed' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t3-03" grep -Pizo 'job: 1/t3/03.*\n.*event: failed' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t4-03" grep -Pizo 'job: 1/t4/03.*\n.*event: failed' "${TEST_SMTPD_LOG}"
+run_ok "${TEST_NAME_BASE}-t5-03" grep -Pizo 'job: 1/t5/03.*\n.*event: failed' "${TEST_SMTPD_LOG}"
+
+
 contains_ok "${TEST_SMTPD_LOG}" <<__LOG__
-retry: 1/t1/01
-retry: 1/t2/01
-retry: 1/t3/01
-retry: 1/t4/01
-retry: 1/t5/01
-retry: 1/t1/02
-retry: 1/t2/02
-retry: 1/t3/02
-retry: 1/t4/02
-retry: 1/t5/02
-failed: 1/t1/03
-failed: 1/t2/03
-failed: 1/t3/03
-failed: 1/t4/03
-failed: 1/t5/03
 see: http://localhost/stuff/${USER}/${WORKFLOW_NAME}/
 __LOG__
 
@@ -73,6 +80,6 @@ run_ok "${TEST_NAME_BASE}-grep-log" \
 run_ok "${TEST_NAME_BASE}-grep-log" \
     grep -qPizo "Subject: \[. tasks failed\]\n? ${WORKFLOW_NAME}" "${TEST_SMTPD_LOG}"
 
-    purge
+purge
 mock_smtpd_kill
 exit

tests/integration/events/test_task_events.py

@@ -51,7 +51,7 @@ async def test_mail_footer_template(
 
     # start the workflow and get it to send an email
     ctx = SimpleNamespace(mail_to=None, mail_from=None)
-    id_keys = [EventKey('none', 'failed', Tokens('//1/a'))]
+    id_keys = [EventKey('none', 'failed', 'failed', Tokens('//1/a'))]
     async with start(mod_one) as one_log:
         mod_one.task_events_mgr._process_event_email(mod_one, ctx, id_keys)
 
@@ -72,5 +72,32 @@ async def test_mail_footer_template(
     assert len(mail_calls) == 1
 
 
+async def test_event_email_body(
+    mod_one,
+    start,
+    capcall,
+):
+    """It should send an email with the event context."""
+    mail_calls = capcall(
+        'cylc.flow.task_events_mgr.TaskEventsManager._send_mail'
+    )
+
+    # start the workflow and get it to send an email
+    ctx = SimpleNamespace(mail_to=None, mail_from=None)
+    async with start(mod_one):
+        # send a custom task message with the warning severity level
+        id_keys = [EventKey('none', 'warning', 'warning message', Tokens('//1/a/01'))]
+        mod_one.task_events_mgr._process_event_email(mod_one, ctx, id_keys)
+
+    # test the email which would have been sent for this message
+    email_body = mail_calls[0][0][3]
+    assert 'event: warning'
+    assert 'job: 1/a/01' in email_body
+    assert 'message: warning message' in email_body
+    assert f'workflow: {mod_one.tokens["workflow"]}' in email_body
+    assert f'host: {mod_one.host}' in email_body
+    assert f'port: {mod_one.server.port}' in email_body
+    assert f'owner: {mod_one.owner}' in email_body
+
 # NOTE: we do not test custom event handlers here because these are tested
 # as a part of workflow validation (now also performed by cylc play)