don't warn on hello

Do not put log messages into format string
and enable INFO level when bot is started
via main() as it happens with systemd.

CHANGELOG.md

@@ -0,0 +1,22 @@
+# Changelog for chatmail deployment 
+
+## unreleased
+
+### Changes since March 15th, 2024
+
+- Fix various tests to pass again with "cmdeploy test". 
+  ([#245](https://github.com/deltachat/chatmail/pull/245),
+  [#242](https://github.com/deltachat/chatmail/pull/242)
+
+- Ensure lets-encrypt certificates are reloaded after renewal 
+  ([#244]) https://github.com/deltachat/chatmail/pull/244
+
+- Persist tokens to avoid iOS users loosing push-notifications when the
+  chatmail metadata service is restarted (happens regularly during deploys)
+  ([#238](https://github.com/deltachat/chatmail/pull/239)
+
+- Fix failing sieve-script compile errors on incoming messages
+  ([#237](https://github.com/deltachat/chatmail/pull/239)
+
+- Fix quota reporting after expunging of old mails
+  ([#233](https://github.com/deltachat/chatmail/pull/239)

chatmaild/src/chatmaild/doveauth.py

@@ -17,6 +17,10 @@ from .config import read_config, Config
 NOCREATE_FILE = "/etc/chatmail-nocreate"
 
 
+class UnknownCommand(ValueError):
+    """dictproxy handler received an unkown command"""
+
+
 def encrypt_password(password: str):
     # https://doc.dovecot.org/configuration_manual/authentication/password_schemes/
     passhash = crypt.crypt(password, crypt.METHOD_SHA512)
@@ -127,8 +131,12 @@ def split_and_unescape(s):
 
 
 def handle_dovecot_request(msg, db, config: Config):
+    # see https://doc.dovecot.org/3.0/developer_manual/design/dict_protocol/
     short_command = msg[0]
-    if short_command == "L":  # LOOKUP
+    if short_command == "H":  # HELLO
+        # we don't do any checking on versions and just return
+        return
+    elif short_command == "L":  # LOOKUP
         parts = msg[1:].split("\t")
 
         # Dovecot <2.3.17 has only one part,
@@ -159,7 +167,7 @@ def handle_dovecot_request(msg, db, config: Config):
                     reply_command = "N"
         json_res = json.dumps(res) if res else ""
         return f"{reply_command}{json_res}\n"
-    return None
+    raise UnknownCommand(msg)
 
 
 def handle_dovecot_protocol(rfile, wfile, db: Database, config: Config):
@@ -167,12 +175,14 @@ def handle_dovecot_protocol(rfile, wfile, db: Database, config: Config):
         msg = rfile.readline().strip().decode()
         if not msg:
             break
-        res = handle_dovecot_request(msg, db, config)
-        if res:
-            wfile.write(res.encode("ascii"))
-            wfile.flush()
+        try:
+            res = handle_dovecot_request(msg, db, config)
+        except UnknownCommand:
+            logging.warning("unknown command: %r", msg)
         else:
-            logging.warning("request had no answer: %r", msg)
+            if res:
+                wfile.write(res.encode("ascii"))
+                wfile.flush()
 
 
 class ThreadedUnixStreamServer(ThreadingMixIn, UnixStreamServer):

chatmaild/src/chatmaild/echo.py

@@ -18,14 +18,14 @@ hooks = events.HookCollection()
 @hooks.on(events.RawEvent)
 def log_event(event):
     if event.kind == EventType.INFO:
-        logging.info(event.msg)
+        logging.info("%s", event.msg)
     elif event.kind == EventType.WARNING:
-        logging.warning(event.msg)
+        logging.warning("%s", event.msg)
 
 
 @hooks.on(events.RawEvent(EventType.ERROR))
 def log_error(event):
-    logging.error(event.msg)
+    logging.error("%s", event.msg)
 
 
 @hooks.on(events.MemberListChanged)
@@ -48,6 +48,9 @@ def on_group_name_changed(event):
 @hooks.on(events.NewMessage(func=lambda e: not e.command))
 def echo(event):
     snapshot = event.message_snapshot
+    if snapshot.is_info:
+        # Ignore info messages
+        return
     if snapshot.text or snapshot.file:
         snapshot.chat.send_message(text=snapshot.text, file=snapshot.file)
 
@@ -59,6 +62,7 @@ def help_command(event):
 
 
 def main():
+    logging.basicConfig(level=logging.INFO)
     path = os.environ.get("PATH")
     venv_path = sys.argv[0].strip("echobot")
     os.environ["PATH"] = path + ":" + venv_path
@@ -80,5 +84,4 @@ def main():
 
 
 if __name__ == "__main__":
-    logging.basicConfig(level=logging.INFO)
     main()

chatmaild/src/chatmaild/tests/test_doveauth.py

@@ -75,6 +75,14 @@ def test_handle_dovecot_request(db, example_config):
     assert userdata["password"].startswith("{SHA512-CRYPT}")
 
 
+def test_handle_dovecot_protocol_hello_is_skipped(db, example_config, caplog):
+    rfile = io.BytesIO(b"H3\t2\t0\t\tauth\n")
+    wfile = io.BytesIO()
+    handle_dovecot_protocol(rfile, wfile, db, example_config)
+    assert wfile.getvalue() == b""
+    assert not caplog.messages
+
+
 def test_handle_dovecot_protocol(db, example_config):
     rfile = io.BytesIO(
         b"H3\t2\t0\t\tauth\nLshared/userdb/foobar@chat.example.org\tfoobar@chat.example.org\n"

cmdeploy/src/cmdeploy/__init__.py

@@ -350,9 +350,7 @@ def _configure_dovecot(config: Config, debug: bool = False) -> bool:
     need_restart |= lua_push_notification_script.changed
 
     sieve_script = files.put(
-        src=importlib.resources.files(__package__).joinpath(
-            "dovecot/default.sieve"
-        ),
+        src=importlib.resources.files(__package__).joinpath("dovecot/default.sieve"),
         dest="/etc/dovecot/default.sieve",
         user="root",
         group="root",
@@ -361,10 +359,8 @@ def _configure_dovecot(config: Config, debug: bool = False) -> bool:
     need_restart |= sieve_script.changed
     if sieve_script.changed:
         server.shell(
-            name=f"compile sieve script",
-            commands=[
-                f"/usr/bin/sievec /etc/dovecot/default.sieve"
-            ],
+            name="compile sieve script",
+            commands=["/usr/bin/sievec /etc/dovecot/default.sieve"],
         )
 
     files.template(
@@ -457,7 +453,9 @@ def check_config(config):
         blocked_words = "merlinux schmieder testrun.org".split()
         for key in config.__dict__:
             value = config.__dict__[key]
-            if key.startswith("privacy") and any(x in str(value) for x in blocked_words):
+            if key.startswith("privacy") and any(
+                x in str(value) for x in blocked_words
+            ):
                 raise ValueError(
                     f"please set your own privacy contacts/addresses in {config._inipath}"
                 )

cmdeploy/src/cmdeploy/acmetool/acmetool.cron

@@ -1,4 +1,4 @@
 SHELL=/bin/sh
 PATH=/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin
 MAILTO=root
-20 16 * * * root /usr/bin/acmetool --batch reconcile
+20 16 * * * root /usr/bin/acmetool --batch reconcile && systemctl reload dovecot && systemctl reload postfix

cmdeploy/src/cmdeploy/dns.py

@@ -5,8 +5,6 @@ import importlib
 import subprocess
 import datetime
 
-from typing import Optional
-
 
 class DNS:
     def __init__(self, out, mail_domain):

cmdeploy/src/cmdeploy/tests/online/test_2_deltachat.py

@@ -63,7 +63,7 @@ class TestEndToEndDeltaChat:
 
         addr = ac2.get_config("addr").lower()
         saved_ok = 0
-        for line in remote.iter_output("journalctl -f -u dovecot"):
+        for line in remote.iter_output("journalctl -n0 -f -u dovecot"):
             if addr not in line:
                 # print(line)
                 continue
@@ -75,7 +75,7 @@ class TestEndToEndDeltaChat:
                         )
                     lp.indent("good, message sending failed because quota was exceeded")
                     return
-            if "saved mail to inbox" in line:
+            if "stored mail into mailbox 'inbox'" in line or "saved mail to inbox" in line:
                 saved_ok += 1
                 print(f"{saved_ok}: {line}")
                 if saved_ok >= num_to_send:
@@ -112,7 +112,7 @@ class TestEndToEndDeltaChat:
         lp.sec("ac1 sends a message and ac2 marks it as seen")
         chat = ac1.create_chat(ac2)
         msg = chat.send_text("hi")
-        m = ac2.wait_next_incoming_message()
+        m = ac2._evtracker.wait_next_incoming_message()
         m.mark_seen()
         # we can only indirectly wait for mark-seen to cause an smtp-error
         lp.sec("try to wait for markseen to complete and check error states")
@@ -132,7 +132,7 @@ def test_hide_senders_ip_address(cmfactory):
     chat = cmfactory.get_accepted_chat(user1, user2)
 
     chat.send_text("testing submission header cleanup")
-    user2.wait_next_incoming_message()
+    user2._evtracker.wait_next_incoming_message()
     user2.direct_imap.select_folder("Inbox")
     msg = user2.direct_imap.get_all_messages()[0]
     assert public_ip not in msg.obj.as_string()
@@ -146,5 +146,5 @@ def test_echobot(cmfactory, chatmail_config, lp):
     text = "hi, I hope you text me back"
     chat.send_text(text)
     lp.sec("Wait for reply from echobot")
-    reply = ac.wait_next_incoming_message()
+    reply = ac._evtracker.wait_next_incoming_message()
     assert reply.text == text