Added logging to built-in sender classes

CHANGELOG.md

@@ -3,6 +3,7 @@ v0.2.0 (in development)
 - Require the `port` field of `SMTPSender` to be non-negative
 - Mark `Sender` as `runtime_checkable` and export it
 - Gave the `outgoing` command `--section` and `--no-section` options
+- Added logging to built-in sender classes
 
 v0.1.0 (2021-03-06)
 -------------------

docs/changelog.rst

@@ -9,6 +9,7 @@ v0.2.0 (in development)
 - Mark `Sender` as ``runtime_checkable`` and export it
 - Gave the :command:`outgoing` command ``--section`` and ``--no-section``
   options
+- Added logging to built-in sender classes
 
 v0.1.0 (2021-03-06)
 -------------------

src/outgoing/senders/command.py

@@ -1,10 +1,13 @@
 from email.message import EmailMessage
+import logging
 import subprocess
 from typing import List, Optional, Union
 from pydantic import Field
 from ..config import Path
 from ..util import OpenClosable
 
+log = logging.getLogger(__name__)
+
 
 class CommandSender(OpenClosable):
     configpath: Optional[Path] = None
@@ -19,6 +22,11 @@ def close(self) -> None:
         pass
 
     def send(self, msg: EmailMessage) -> None:
+        log.info(
+            "Sending e-mail %r via command %r",
+            msg.get("Subject", "<NO SUBJECT>"),
+            self.command,
+        )
         subprocess.run(
             self.command,
             shell=isinstance(self.command, str),

src/outgoing/senders/mailboxes.py

@@ -1,5 +1,6 @@
 from abc import abstractmethod
 from email.message import EmailMessage
+import logging
 import mailbox
 from typing import List, Optional, TypeVar, Union
 from pydantic import PrivateAttr
@@ -8,6 +9,8 @@
 
 T = TypeVar("T", bound="MailboxSender")
 
+log = logging.getLogger(__name__)
+
 
 class MailboxSender(OpenClosable):  # ABC inherited from OpenClosable
     _mbox: Optional[mailbox.Mailbox] = PrivateAttr(None)
@@ -16,20 +19,31 @@ class MailboxSender(OpenClosable):  # ABC inherited from OpenClosable
     def _makebox(self) -> mailbox.Mailbox:
         ...
 
+    @abstractmethod
+    def _describe(self) -> str:
+        ...
+
     def open(self) -> None:
+        log.debug("Opening %s", self._describe())
         self._mbox = self._makebox()
         self._mbox.lock()
 
     def close(self) -> None:
         if self._mbox is None:
             raise ValueError("Mailbox is not open")
+        log.debug("Closing %s", self._describe())
         self._mbox.unlock()
         self._mbox.close()
         self._mbox = None
 
     def send(self, msg: EmailMessage) -> None:
         with self:
             assert self._mbox is not None
+            log.info(
+                "Adding e-mail %r to %s",
+                msg.get("Subject", "<NO SUBJECT>"),
+                self._describe(),
+            )
             self._mbox.add(msg)
 
 
@@ -40,6 +54,9 @@ class MboxSender(MailboxSender):
     def _makebox(self) -> mailbox.mbox:
         return mailbox.mbox(self.path)
 
+    def _describe(self) -> str:
+        return f"mbox at {self.path}"
+
 
 class MaildirSender(MailboxSender):
     configpath: Optional[Path] = None
@@ -55,6 +72,13 @@ def _makebox(self) -> mailbox.Maildir:
                 box = box.add_folder(self.folder)
         return box
 
+    def _describe(self) -> str:
+        if self.folder is None:
+            folder = "root folder"
+        else:
+            folder = f"folder {self.folder!r}"
+        return f"Maildir at {self.path}, {folder}"
+
 
 class MHSender(MailboxSender):
     configpath: Optional[Path] = None
@@ -76,6 +100,15 @@ def _makebox(self) -> mailbox.MH:
                     box = box.add_folder(f)
         return box
 
+    def _describe(self) -> str:
+        if self.folder is None:
+            folder = "root folder"
+        elif isinstance(self.folder, str):
+            folder = f"folder {self.folder!r}"
+        else:
+            folder = "folder " + "/".join(map(repr, self.folder))
+        return f"MH mailbox at {self.path}, {folder}"
+
 
 class MMDFSender(MailboxSender):
     configpath: Optional[Path] = None
@@ -84,10 +117,16 @@ class MMDFSender(MailboxSender):
     def _makebox(self) -> mailbox.MMDF:
         return mailbox.MMDF(self.path)
 
+    def _describe(self) -> str:
+        return f"MMDF mailbox at {self.path}"
+
 
 class BabylSender(MailboxSender):
     configpath: Optional[Path] = None
     path: Path
 
     def _makebox(self) -> mailbox.Babyl:
         return mailbox.Babyl(self.path)
+
+    def _describe(self) -> str:
+        return f"Babyl mailbox at {self.path}"

src/outgoing/senders/null.py

@@ -1,17 +1,20 @@
 from email.message import EmailMessage
+import logging
 from typing import Optional
 from ..config import Path
 from ..util import OpenClosable
 
+log = logging.getLogger(__name__)
+
 
 class NullSender(OpenClosable):
     configpath: Optional[Path] = None
 
     def open(self) -> None:
-        ...
+        pass
 
     def close(self) -> None:
-        ...
+        pass
 
     def send(self, msg: EmailMessage) -> None:
-        ...
+        log.info("Discarding e-mail %r", msg.get("Subject", "<NO SUBJECT>"))

src/outgoing/senders/smtp.py

@@ -1,4 +1,5 @@
 from email.message import EmailMessage
+import logging
 import smtplib
 import sys
 from typing import Any, Dict, Optional
@@ -13,6 +14,8 @@
 
 STARTTLS = "starttls"
 
+log = logging.getLogger(__name__)
+
 
 class SMTPSender(NetrcConfig, OpenClosable):
     ssl: Literal[False, True, "starttls"] = False
@@ -38,22 +41,32 @@ def open(self) -> None:
         # We need to pass the host & port to the constructor instead of calling
         # connect() later due to <https://bugs.python.org/issue36094>.
         if self.ssl is True:
+            log.debug(
+                "Connecting to SMTP server at %s, port %d, using TLS",
+                self.host,
+                self.port,
+            )
             self._client = smtplib.SMTP_SSL(self.host, self.port)
         else:
+            log.debug("Connecting to SMTP server at %s, port %d", self.host, self.port)
             self._client = smtplib.SMTP(self.host, self.port)
         if self.ssl == STARTTLS:
+            log.debug("Enabling STARTTLS")
             self._client.starttls()
         if self.username is not None:
             assert self.password is not None
+            log.debug("Logging in as %r", self.username)
             self._client.login(self.username, self.password.get_secret_value())
 
     def close(self) -> None:
         if self._client is None:
             raise ValueError("SMTPSender is not open")
+        log.debug("Closing connection to %s", self.host)
         self._client.quit()
         self._client = None
 
     def send(self, msg: EmailMessage) -> None:
         with self:
             assert self._client is not None
+            log.info("Sending e-mail %r via SMTP", msg.get("Subject", "<NO SUBJECT>"))
             self._client.send_message(msg)

test/test_senders/test_babyl.py

@@ -1,4 +1,5 @@
 from email.message import EmailMessage
+import logging
 from mailbox import Babyl
 from pathlib import Path
 from mailbits import email2dict
@@ -26,8 +27,12 @@ def test_babyl_construct(monkeypatch: pytest.MonkeyPatch, tmp_path: Path) -> Non
 
 
 def test_babyl_send_new_path(
-    monkeypatch: pytest.MonkeyPatch, test_email1: EmailMessage, tmp_path: Path
+    caplog: pytest.LogCaptureFixture,
+    monkeypatch: pytest.MonkeyPatch,
+    test_email1: EmailMessage,
+    tmp_path: Path,
 ) -> None:
+    caplog.set_level(logging.DEBUG, logger="outgoing")
     monkeypatch.chdir(tmp_path)
     sender = from_dict(
         {
@@ -45,6 +50,24 @@ def test_babyl_send_new_path(
     inbox.close()
     assert len(msgs) == 1
     assert email2dict(test_email1) == email2dict(msgs[0])
+    assert caplog.record_tuples == [
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Opening Babyl mailbox at {tmp_path/'inbox'}",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.INFO,
+            f"Adding e-mail {test_email1['Subject']!r} to Babyl mailbox at"
+            f" {tmp_path/'inbox'}",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Closing Babyl mailbox at {tmp_path/'inbox'}",
+        ),
+    ]
 
 
 def test_babyl_send_extant_path(

test/test_senders/test_command.py

@@ -1,4 +1,5 @@
 from email.message import EmailMessage
+import logging
 from pathlib import Path
 import subprocess
 from typing import List, Union
@@ -40,12 +41,14 @@ def test_command_construct(command: Union[str, List[str]], tmp_path: Path) -> No
     ],
 )
 def test_command_send(
+    caplog: pytest.LogCaptureFixture,
     command: Union[str, List[str]],
     shell: bool,
     mocker: MockerFixture,
     test_email1: EmailMessage,
     tmp_path: Path,
 ) -> None:
+    caplog.set_level(logging.DEBUG, logger="outgoing")
     m = mocker.patch("subprocess.run")
     sender = from_dict(
         {"method": "command", "command": command}, configpath=tmp_path / "foo.toml"
@@ -61,6 +64,13 @@ def test_command_send(
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
     )
+    assert caplog.record_tuples == [
+        (
+            "outgoing.senders.command",
+            logging.INFO,
+            f"Sending e-mail {test_email1['Subject']!r} via command {command!r}",
+        )
+    ]
 
 
 @pytest.mark.parametrize(

test/test_senders/test_maildir.py

@@ -1,4 +1,5 @@
 from email.message import EmailMessage
+import logging
 from mailbox import Maildir
 from operator import itemgetter
 from pathlib import Path
@@ -33,8 +34,12 @@ def test_maildir_construct(
 
 
 def test_maildir_send_no_folder_new_path(
-    monkeypatch: pytest.MonkeyPatch, test_email1: EmailMessage, tmp_path: Path
+    caplog: pytest.LogCaptureFixture,
+    monkeypatch: pytest.MonkeyPatch,
+    test_email1: EmailMessage,
+    tmp_path: Path,
 ) -> None:
+    caplog.set_level(logging.DEBUG, logger="outgoing")
     monkeypatch.chdir(tmp_path)
     sender = from_dict(
         {
@@ -51,11 +56,33 @@ def test_maildir_send_no_folder_new_path(
     msgs = list(inbox)
     assert len(msgs) == 1
     assert email2dict(test_email1) == email2dict(msgs[0])
+    assert caplog.record_tuples == [
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Opening Maildir at {tmp_path/'inbox'}, root folder",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.INFO,
+            f"Adding e-mail {test_email1['Subject']!r} to Maildir at"
+            f" {tmp_path/'inbox'}, root folder",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Closing Maildir at {tmp_path/'inbox'}, root folder",
+        ),
+    ]
 
 
 def test_maildir_send_folder_new_path(
-    monkeypatch: pytest.MonkeyPatch, test_email1: EmailMessage, tmp_path: Path
+    caplog: pytest.LogCaptureFixture,
+    monkeypatch: pytest.MonkeyPatch,
+    test_email1: EmailMessage,
+    tmp_path: Path,
 ) -> None:
+    caplog.set_level(logging.DEBUG, logger="outgoing")
     monkeypatch.chdir(tmp_path)
     sender = from_dict(
         {
@@ -73,6 +100,24 @@ def test_maildir_send_folder_new_path(
     msgs = list(work)
     assert len(msgs) == 1
     assert email2dict(test_email1) == email2dict(msgs[0])
+    assert caplog.record_tuples == [
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Opening Maildir at {tmp_path/'inbox'}, folder 'work'",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.INFO,
+            f"Adding e-mail {test_email1['Subject']!r} to Maildir at"
+            f" {tmp_path/'inbox'}, folder 'work'",
+        ),
+        (
+            "outgoing.senders.mailboxes",
+            logging.DEBUG,
+            f"Closing Maildir at {tmp_path/'inbox'}, folder 'work'",
+        ),
+    ]
 
 
 def test_maildir_send_no_folder_extant_path(