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/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/tests/online/test_2_deltachat.py

@@ -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: