Add contract tests for headers-only parsing of email messages

- Implement KeyConfirmationQueue.delete_expired_queue_items to delete items
older than a given number of hours.

- Introduce configuration parameter to specify maximum number of hours.  It
defaults to 1 hour.

- Update documentation to explain that we never assign ST_TO_BE_DELETED.

Makefile

@@ -1,5 +1,6 @@
 .POSIX:
 .PHONY: test e2etest unittest crontest daemontest pre-clean clean restore-keyhome
+.SUFFIXES: .gv .png
 
 #
 # On systems where Python 3.x binary has a different name, just
@@ -12,6 +13,8 @@
 #
 PYTHON = python
 
+GRAPHVIZ = dot
+
 #
 # SQLite database used during tests
 #
@@ -20,11 +23,21 @@ PYTHON = python
 #
 TEST_DB = test/lacre.db
 
+#
+# List of graph files
+#
+GRAPHS = doc/key-lifecycle.png
+
 #
 # Main goal to run all tests.
 #
 test: e2etest daemontest unittest crontest
 
+#
+# Build graphviz diagrams.
+#
+doc: ${GRAPHS}
+
 #
 # Run a set of end-to-end tests.
 #
@@ -82,3 +95,7 @@ test/logs:
 
 clean: pre-clean clean-db
 	rm -rfv test/tmp test/logs
+
+# Convert dot source to PNG image.
+.gv.png:
+	$(GRAPHVIZ) -Tpng $< > ${<:S/.gv/.png/}

doc/key-lifecycle.gv

@@ -0,0 +1,76 @@
+digraph key_lifecycle {
+    node [fontname="Helvetica,Arial,sans-serif" fontsize=12 shape=Mrecord]
+    edge [fontname="Helvetica,Arial,sans-serif" fontsize=10]
+
+    start [label="" shape=circle]
+    end [label="" shape=circle]
+
+    // An ASCII-armoured key is stored in lacre_keys table with:
+    //
+    // lacre_keys.confirm = <random string>
+    // lacre_keys.status  = 0 (default value)
+    submitted [label="Submitted"]
+
+    // User has confirmed their email.
+    //
+    // lacre_keys.confirm = ''
+    confirmed [label="Email confirmed" color=green4]
+
+    // The key has been imported into GnuPG keyring and an identity has been
+    // created in lacre_identities table.
+    //
+    // lacre_keys.status = 1
+    imported [label="Imported" color=green4]
+
+    // Any old key for this email has been deleted.
+    deleted [label="Previous key\ndeleted"]
+
+    // When a key expires, we only fail to encrypt at the moment.
+    //
+    // See https://git.disroot.org/Disroot/gpg-lacre/issues/148
+    expired [label="Expired" color=red]
+
+    // A key may end up being non-usable in several different ways and this is
+    // a catch-all node to represent them.
+    //
+    // - User hasn't confirmed their email.
+    // - Provided key's email didn't match the one provided in submission form.
+    rejected [label="Key not used,\nremoved from database" color=brown]
+
+    // User submits ASCII-armoured OpenPGP key.
+    start -> submitted [label="user action:\nkey submission" color=green4]
+
+    // The user has clicked the confirmation link.
+    //
+    // - lacre_keys.confirm = ''
+    submitted -> confirmed [label="user action:\nemail confirmation" color=green4]
+
+    // Enough time has passed since submission that we decide to drop the key
+    // from the queue.
+    submitted -> rejected [label="confirmation timed out\nno user action" color=brown]
+
+    // A confirmed key is imported:
+    // - import into GnuPG keyring;
+    // - mark key as accepted (lacre_keys.status = 1);
+    // - update identity database;
+    // - send notification.
+    confirmed -> imported [label="import\n[non-empty key]" color=green4]
+
+    // Empty key is imported.
+    //
+    // Effectively this means key removal and disabling encryption.
+    confirmed -> deleted [label="import\n[empty key]" color=green4]
+    deleted -> end
+
+    // XXX: Import of revokation keys isn't implemented yet.
+    confirmed -> deleted [label="import\n[revokation key]\n(not implemented)" color=gray fontcolor=gray]
+
+    // Key validation fails, the key is not imported.
+    confirmed -> rejected [label="invalid key" color=brown]
+
+    // We don't explicitly make keys expired, but when they expire GnuPG
+    // refuses to encrypt payloads.
+    imported -> expired [label="expiry" color=red fontcolor=red]
+
+    rejected -> end
+}

lacre.conf.sample

@@ -133,6 +133,10 @@ pooling_mode = optimistic
 # made and closed after use, to avoid pool growth and connection rejections.
 #max_overflow = 10
 
+# Number of hours we will wait for the user to confirm their email.  Cron-job
+# will delete items older than this number of hours.  Default: 1h.
+#max_queue_hours = 1
+
 [enc_keymap]
 # You can find these by running the following command:
 #	gpg --list-keys --keyid-format long user@example.com

lacre/__init__.py

@@ -43,7 +43,9 @@ EX_CONFIG = 78
 def init_logging(config_filename):
     if config_filename is not None:
         logging.config.fileConfig(config_filename)
+        logging.captureWarnings(True)
         logging.info('Configured from %s', config_filename)
     else:
         logging.config.dictConfig(FAIL_OVER_LOGGING_CONFIG)
+        logging.captureWarnings(True)
         logging.warning('Lacre logging configuration missing, using syslog as default')

lacre/config.py

@@ -6,6 +6,7 @@ configuration.
 
 from enum import Enum, auto
 from configparser import RawConfigParser
+from collections import namedtuple
 
 import os
 
@@ -128,9 +129,11 @@ def validate_config(*, additional=None):
 # High level access to configuration.
 #
 
-def relay_params():
-    """Return a (HOST, PORT) tuple identifying the mail relay."""
-    return (cfg["relay"]["host"], int(cfg["relay"]["port"]))
+Host = namedtuple('Host', ['name', 'port'])
+
+def relay_params() -> Host:
+    """Return a Host named tuple identifying the mail relay."""
+    return Host(name = cfg["relay"]["host"], port = int(cfg["relay"]["port"]))
 
 
 def daemon_params():

lacre/daemon.py

@@ -40,7 +40,7 @@ class MailEncryptionProxy:
                 message = email.message_from_bytes(envelope.original_content, policy=SMTPUTF8)
 
                 if message.defects:
-                    LOG.warning("Issues found: %d; %s", len(message.defects), repr(message.defects))
+                    LOG.warning("Issues found: %s", repr(message.defects))
 
                 send = xport.SendFrom(envelope.mail_from)
                 for operation in gate.delivery_plan(envelope.rcpt_tos, message, keys):
@@ -48,22 +48,28 @@ class MailEncryptionProxy:
                     try:
                         new_message = operation.perform(message)
                         send(new_message, operation.recipients())
-                    except (EncryptionException, MailSerialisationException, UnicodeEncodeError):
-                        # If the message can't be encrypted, deliver cleartext.
-                        LOG.exception('Unable to encrypt message, delivering in cleartext')
-                        if not isinstance(operation, KeepIntact):
-                            self._send_unencrypted(operation, envelope, send)
-                        else:
-                            LOG.exception('Cannot perform: %s', operation)
-                            raise
+                    except (EncryptionException, MailSerialisationException) as e:
+                        # If the message can't be encrypted or serialised to a
+                        # stream of bytes, deliver original payload in
+                        # cleartext.
+                        LOG.error('Unable to encrypt message, delivering in cleartext: %s', e)
+                        self._send_unencrypted(operation, envelope, send)
+
+            except xport.TransientFailure:
+                LOG.info('Bouncing message')
+                return xport.RESULT_ABORT
+
+            except xport.PermanentFailure:
+                LOG.exception('Permanent failure')
+                return xport.RESULT_PERM_FAIL
 
             except:
-                LOG.exception('Unexpected exception caught, bouncing message')
-
                 if conf.should_log_headers():
-                    LOG.error('Erroneous message headers: %s', self._beginning(envelope))
+                    LOG.exception('Unexpected exception caught, bouncing message. Erroneous message headers: %s', self._beginning(envelope))
+                else:
+                    LOG.exception('Unexpected exception caught, bouncing message')
 
-                return xport.RESULT_ERRORR
+                return xport.RESULT_ABORT
 
         return xport.RESULT_OK
 
@@ -80,9 +86,6 @@ class MailEncryptionProxy:
         end = min(limit, 2560)
         return e.original_content[0:end]
 
-    def _seconds_between(self, start_ms, end_ms) -> float:
-        return (end_ms - start_ms) * 1000
-
 
 def _init_controller(keys: kcache.KeyRing, max_body_bytes=None, tout: float = 5):
     proxy = MailEncryptionProxy(keys)
@@ -90,7 +93,10 @@ def _init_controller(keys: kcache.KeyRing, max_body_bytes=None, tout: float = 5)
     LOG.info(f"Initialising a mail Controller at {host}:{port}")
     return Controller(proxy, hostname=host, port=port,
                       ready_timeout=tout,
-                      data_size_limit=max_body_bytes)
+                      data_size_limit=max_body_bytes,
+                      # Do not decode data into str as we only operate on raw
+                      # data available via Envelope.original_content.
+                      decode_data=False)
 
 
 def _validate_config():

lacre/dbschema.py

@@ -16,7 +16,8 @@ import sqlalchemy
 # Values for lacre_keys.status column:
 # - ST_DEFAULT: initial state;
 # - ST_IMPORTED: key has been successfully processed by cron job;
-# - ST_TO_BE_DELETED: key can be deleted.
+# - ST_TO_BE_DELETED: key can be deleted.  We only have checks for this value
+#   but never assign it, so this is a candidate for removal.
 ST_DEFAULT, ST_IMPORTED, ST_TO_BE_DELETED = range(3)
 
 # lacre_keys.confirmed is set to an empty string when a key is confirmed by the user.

lacre/keymgmt.py

@@ -0,0 +1,16 @@
+"""Key management utilities."""
+
+from datetime import datetime, timedelta
+
+from lacre.config import get_item
+
+
+def calculate_expiry_date(now: datetime) -> datetime:
+    """Calculate date-time of key queue item expiry.
+
+    Given current timestamp and configuration item
+    [database]max_queue_hours, return a date-time object that should be
+    older than any key in our confirmation queue.  If a key is older
+    than this threshold, we should remove it."""
+    max_hours = get_item('database', 'max_queue_hours', 1)
+    return now - timedelta(hours=max_hours)

lacre/mailop.py

@@ -131,7 +131,7 @@ class KeepIntact(MailOperation):
         """Return MESSAGE unmodified."""
         try:
             return message.as_bytes(policy=SMTPUTF8)
-        except IndexError as e:
+        except (IndexError, UnicodeEncodeError, ValueError) as e:
             raise MailSerialisationException(e)
 
     def __repr__(self):

lacre/notify.py

@@ -45,8 +45,8 @@ def notify(mailsubject, messagefile, recipients = None):
     msg.attach(MIMEText(markdown.markdown(mailbody), 'html'))
 
     if conf.config_item_set('relay', 'host') and conf.config_item_set('relay', 'enc_port'):
-        (host, port) = conf.relay_params()
-        smtp = smtplib.SMTP(host, port)
+        host = conf.relay_params()
+        smtp = smtplib.SMTP(host.name, host.port)
         _authenticate_maybe(smtp)
         LOG.info('Delivering notification: %s', recipients)
         smtp.sendmail(conf.get_item('cron', 'notification_email'), recipients, msg.as_string())

lacre/repositories.py

@@ -1,5 +1,7 @@
 """Lacre identity and key repositories."""
 
+from datetime import datetime, timedelta
+
 from sqlalchemy import create_engine, select, delete, and_, func
 from sqlalchemy.exc import OperationalError
 import logging
@@ -171,6 +173,21 @@ class KeyConfirmationQueue:
         with self._engine.connect() as conn:
             return [e for e in conn.execute(seldel)]
 
+    def delete_expired_queue_items(self, older_than: datetime):
+        """Remove keys that have been in queue before `older_than`."""
+        delq = delete(self._keys) \
+            .where(
+                and_(
+                     self._keys.c.time < older_than,
+                     # We only want to delete keys that haven't been confirmed.
+                     self._keys.c.confirm != db.CO_CONFIRMED
+                   )
+                )
+        LOG.debug('Deleting queue items older than %s: %s', repr(older_than), delq)
+
+        with self._engine.connect() as conn:
+            conn.execute(delq)
+
     def delete_keys(self, row_id, /, email=None):
         """Remove key from the database."""
         if email is not None:

lacre/transport.py

@@ -5,12 +5,19 @@ import logging
 from typing import AnyStr, List
 
 import lacre.config as conf
+from lacre.mailop import MailSerialisationException
 
 # Mail status constants.
 #
 # These are the only values that our mail handler is allowed to return.
 RESULT_OK = '250 OK'
-RESULT_ERROR = '500 Could not process your message'
+RESULT_TRANS_FAIL = '451 Aborted: error in processing'
+RESULT_PERM_FAIL = '554 Transaction failed'
+
+# See RFC 5321, section 4.2.1 "Reply Code Severities and Theory" for more
+# information on SMTP reply codes.
+RESP_TRANSIENT_NEG = 4
+RESP_PERMANENT_NEG = 5
 
 LOG = logging.getLogger(__name__)
 
@@ -34,7 +41,7 @@ def send_msg(message: AnyStr, recipients: List[str]):
     if recipients:
         LOG.info(f"Sending email to: {recipients!r}")
         relay = conf.relay_params()
-        smtp = smtplib.SMTP(relay[0], relay[1])
+        smtp = smtplib.SMTP(relay.name, relay.port)
         if conf.flag_enabled('relay', 'starttls'):
             smtp.starttls()
         smtp.sendmail(from_addr, recipients, message)
@@ -42,6 +49,19 @@ def send_msg(message: AnyStr, recipients: List[str]):
         LOG.info("No recipient found")
 
 
+class TransientFailure(BaseException):
+    """Signals a transient delivery failure (4xx SMTP reply).
+
+    Message should be bounced and re-sent later.
+    """
+    pass
+
+
+class PermanentFailure(BaseException):
+    """Signals a permanent delivery failure (5xx SMTP reply)."""
+    pass
+
+
 class SendFrom:
     """A class wrapping the transport process."""
 
@@ -63,9 +83,28 @@ class SendFrom:
 
         LOG.info("Sending email to: %s", recipients)
         relay = conf.relay_params()
-        smtp = smtplib.SMTP(relay[0], relay[1])
+        smtp = smtplib.SMTP(relay.name, relay.port)
 
         if conf.flag_enabled('relay', 'starttls'):
             smtp.starttls()
 
-        smtp.sendmail(self._from_addr, recipients, message)
+        try:
+            smtp.sendmail(self._from_addr, recipients, message)
+        except smtplib.SMTPResponseException as re:
+            resp_class = self._get_class(re.smtp_code)
+
+            if resp_class == RESP_TRANSIENT_NEG:
+                LOG.warning('Transient delivery failure: %s', re)
+                raise TransientFailure()
+            elif resp_class == RESP_PERMANENT_NEG:
+                LOG.error('Permanent delivery failure: %s', re)
+                raise PermanentFailure()
+        except smtplib.SMTPException as err:
+            LOG.error('Failed to deliver message: %s', err)
+            raise PermanentFailure()
+        except UnicodeEncodeError as uee:
+            LOG.error('Failed to deliver for non-SMTP reason', uee)
+            raise MailSerialisationException(uee)
+
+    def _get_class(self, resp_code):
+        return int(resp_code / 100)

requirements.txt

@@ -1,5 +1,5 @@
 aiosmtpd==1.4.2
-SQLAlchemy==1.4.32
+SQLAlchemy==2.0.29
 Markdown==3.4.1
 M2Crypto==0.38.0
 requests==2.27.1

test/modules/test_contracts.py

@@ -186,6 +186,103 @@ class EmailParsingTest(unittest.TestCase):
         self.assertEqual(len(msg.defects), 0)
         self.assertRaises(IndexError, lambda: msg['Message-Id'])
 
+    def test_headersonly_text_plain(self):
+        rawmsg = b"From: alice@lacre.io\r\n" \
+          + b"To: bob@lacre.io\r\n" \
+          + b"Subject: Test message\r\n" \
+          + b"Content-Type: text/plain\r\n" \
+          + b"Content-Transfer-Encoding: base64\r\n" \
+          + b"Message-Id: <[yada-yada-yada@microsoft.com]>\r\n" \
+          + b"\r\n" \
+          + b"SGVsbG8sIFdvcmxkIQo=\r\n"
+
+        from email.parser import BytesHeaderParser
+        msg_headers_only = BytesHeaderParser(policy=SMTPUTF8).parsebytes(rawmsg)
+
+        self.assertEqual(msg_headers_only['From'], 'alice@lacre.io')
+        self.assertEqual(msg_headers_only.get_body().as_bytes(), rawmsg)
+        self.assertEqual(msg_headers_only.get_payload(), 'SGVsbG8sIFdvcmxkIQo=\r\n')
+
+    def test_headersonly_multipart_mixed(self):
+        rawmsg = b"From: eva@lacre.io\r\n" \
+          + b"Content-Type: multipart/mixed; boundary=XXXXXXXX\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX\r\n" \
+          + b"Content-Type: application/octet-stream\r\n" \
+          + b"Content-Transfer-Encoding: base64\r\n" \
+          + b"\r\n" \
+          + b"VGVzdCBtZXNzYWdlIGZyb20gQWxpY2UgdG8gQm9iLgo=\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX\r\n" \
+          + b"Content-Type: application/octet-stream\r\n" \
+          + b"Content-Transfer-Encoding: base64\r\n" \
+          + b"\r\n" \
+          + b"SGVsbG8sIFdvcmxkIQo=\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX--\r\n"
+
+        message_body = "--XXXXXXXX\r\n" \
+          + "Content-Type: application/octet-stream\r\n" \
+          + "Content-Transfer-Encoding: base64\r\n" \
+          + "\r\n" \
+          + "VGVzdCBtZXNzYWdlIGZyb20gQWxpY2UgdG8gQm9iLgo=\r\n" \
+          + "\r\n" \
+          + "--XXXXXXXX\r\n" \
+          + "Content-Type: application/octet-stream\r\n" \
+          + "Content-Transfer-Encoding: base64\r\n" \
+          + "\r\n" \
+          + "SGVsbG8sIFdvcmxkIQo=\r\n" \
+          + "\r\n" \
+          + "--XXXXXXXX--\r\n"
+
+        from email.parser import BytesHeaderParser
+        msg_headers_only = BytesHeaderParser(policy=SMTPUTF8).parsebytes(rawmsg)
+
+        self.assertEqual(msg_headers_only['From'], 'eva@lacre.io')
+        self.assertIsNone(msg_headers_only.get_body())
+        self.assertEqual(msg_headers_only.get_payload(), message_body)
+        self.assertRaises(KeyError, lambda: msg_headers_only.get_content())
+
+    def test_headersonly_multipart_alternative(self):
+        rawmsg = b"From: eva@lacre.io\r\n" \
+          + b"Content-Type: multipart/alternative; boundary=XXXXXXXX\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX\r\n" \
+          + b"Content-Type: application/octet-stream\r\n" \
+          + b"Content-Transfer-Encoding: base64\r\n" \
+          + b"\r\n" \
+          + b"VGVzdCBtZXNzYWdlIGZyb20gQWxpY2UgdG8gQm9iLgo=\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX\r\n" \
+          + b"Content-Type: application/octet-stream\r\n" \
+          + b"Content-Transfer-Encoding: base64\r\n" \
+          + b"\r\n" \
+          + b"SGVsbG8sIFdvcmxkIQo=\r\n" \
+          + b"\r\n" \
+          + b"--XXXXXXXX--\r\n"
+
+        message_body = "--XXXXXXXX\r\n" \
+          + "Content-Type: application/octet-stream\r\n" \
+          + "Content-Transfer-Encoding: base64\r\n" \
+          + "\r\n" \
+          + "VGVzdCBtZXNzYWdlIGZyb20gQWxpY2UgdG8gQm9iLgo=\r\n" \
+          + "\r\n" \
+          + "--XXXXXXXX\r\n" \
+          + "Content-Type: application/octet-stream\r\n" \
+          + "Content-Transfer-Encoding: base64\r\n" \
+          + "\r\n" \
+          + "SGVsbG8sIFdvcmxkIQo=\r\n" \
+          + "\r\n" \
+          + "--XXXXXXXX--\r\n"
+
+        from email.parser import BytesHeaderParser
+        msg_headers_only = BytesHeaderParser(policy=SMTPUTF8).parsebytes(rawmsg)
+
+        self.assertEqual(msg_headers_only['From'], 'eva@lacre.io')
+        self.assertIsNone(msg_headers_only.get_body())
+        self.assertEqual(msg_headers_only.get_payload(), message_body)
+        self.assertRaises(KeyError, lambda: msg_headers_only.get_content())
+
 
 class EmailTest(unittest.TestCase):
     def test_boundary_generated_after_as_string_call(self):

test/modules/test_keymgmt.py

@@ -0,0 +1,10 @@
+import unittest
+
+import datetime
+import lacre.keymgmt as km
+
+class KeyManagementUtilitiesTest(unittest.TestCase):
+    def test_expiry_date_calculation(self):
+        ts = datetime.datetime(2024, 1, 1, 12, 0)
+        exp = km.calculate_expiry_date(ts)
+        self.assertEqual(exp, datetime.datetime(2024, 1, 1, 11, 0))

test/utils/relay.py

@@ -101,6 +101,8 @@ def _serve(port) -> bytes:
 
     logging.debug('Received %d bytes of data', len(message))
 
+    s.close()
+
     # Trim EOM marker as we're only interested in the message body.
     return message[:-len(EOM)]
 

webgate-cron.py

@@ -20,10 +20,12 @@
 #
 
 import sys
+from datetime import datetime
 import logging
 import lacre
 import lacre.config as conf
 from lacre.notify import notify
+from lacre.keymgmt import calculate_expiry_date
 
 # Read configuration from /etc/lacre.conf
 conf.load_config()
@@ -56,7 +58,7 @@ def import_key(key_dir, armored_key, key_id, email, key_queue, identities):
 
 def import_failed(key_id, email, key_queue):
     key_queue.delete_keys(key_id)
-    LOG.warning('Import confirmation failed: %s', email)
+    LOG.warning('Key confirmation failed: %s', email)
 
     if conf.flag_enabled('cron', 'send_email'):
         notify("PGP key registration failed", "registrationError.md", email)
@@ -64,17 +66,16 @@ def import_failed(key_id, email, key_queue):
 
 def delete_key(key_id, email, key_queue):
     # delete key so we don't continue processing it
-    LOG.debug('Empty key received, just deleting')
+    LOG.debug('Empty key received, deleting known key from: %s', email)
 
-    key_queue.delete_keys(row_id)
+    key_queue.delete_keys(key_id, email)
     if conf.flag_enabled('cron', 'send_email'):
         notify("PGP key deleted", "keyDeleted.md", email)
 
 
 def cleanup(key_dir, key_queue):
     """Delete keys and queue entries."""
-
-    LOG.info('Cleaning up after a round of key confirmation')
+    LOG.debug('Removing no longer needed keys from queue')
     for email, row_id in key_queue.fetch_keys_to_delete():
         LOG.debug('Removing key from keyring: %s', email)
         GnuPG.delete_key(key_dir, email)
@@ -84,6 +85,9 @@ def cleanup(key_dir, key_queue):
 
         LOG.info('Deleted key for: %s', email)
 
+    expiry_date = calculate_expiry_date(datetime.now())
+    key_queue.delete_expired_queue_items(expiry_date)
+
 
 _validate_config()