feat: add tool to analyze deferred queue

It prints all destinations with the number of recipients
and all the reasons. Operator can then try
to fix the problems for destinations,
e.g. by manually adding reverse proxy
addresses to /etc/hosts for failing domains
or routing IP addresses to another interface.

.github/workflows/ci.yaml

@@ -57,8 +57,9 @@ jobs:
 
   lxc-test:
     name: LXC deploy and test
-    uses: chatmail/cmlxc/.github/workflows/lxc-test.yml@v0.10.0
+    uses: chatmail/cmlxc/.github/workflows/lxc-test.yml@v0.13.5
     with:
+      cmlxc_version: v0.13.5
       cmlxc_commands: |
         cmlxc init 
         # single cmdeploy relay test

chatmaild/pyproject.toml

@@ -24,6 +24,7 @@ chatmail-metadata = "chatmaild.metadata:main"
 chatmail-expire = "chatmaild.expire:daily_expire_main"
 chatmail-quota-expire = "chatmaild.expire:quota_expire_main"
 chatmail-fsreport = "chatmaild.fsreport:main"
+chatmail-deferred = "chatmaild.deferred:main"
 lastlogin = "chatmaild.lastlogin:main"
 turnserver = "chatmaild.turnserver:main"
 

chatmaild/src/chatmaild/deferred.py

@@ -0,0 +1,39 @@
+"""
+Analyze deferred mails and print most common failing destinations.
+
+Example:
+
+    python -m chatmaild.deferred
+"""
+
+import json
+import subprocess
+from collections import Counter, defaultdict
+
+
+def main():
+    p = subprocess.Popen(["postqueue", "-j"], text=True, stdout=subprocess.PIPE)
+    domain_reasons = defaultdict(Counter)
+    domain_total = Counter()
+
+    for line in p.stdout:
+        item = json.loads(line)
+        if item["queue_name"] != "deferred":
+            continue
+
+        for recipient in item["recipients"]:
+            _, domain = recipient["address"].rsplit("@", 1)
+            reason = recipient["delay_reason"].removeprefix(
+                "host 127.0.0.1[127.0.0.1] said: "
+            )
+            domain_total[domain] += 1
+            domain_reasons[domain][reason] += 1
+
+    for domain, total in reversed(domain_total.most_common()):
+        print(f"{domain} ({total} recipients)")
+        for reason, count in domain_reasons[domain].most_common():
+            print(f"  {count}: {reason}")
+
+
+if __name__ == "__main__":
+    main()

chatmaild/src/chatmaild/metadata.py

@@ -70,6 +70,9 @@ class Metadata:
                 # Some tokens have expired, remove them.
                 with self._modify_tokens(addr) as _tokens:
                     pass
+        elif isinstance(tokens, list):
+            with self._modify_tokens(addr) as tokens:
+                token_list = list(tokens.keys())
         else:
             token_list = []
         return token_list

chatmaild/src/chatmaild/tests/test_metadata.py

@@ -372,3 +372,14 @@ def test_iroh_relay(dictproxy):
     dictproxy.iroh_relay = "https://example.org/"
     dictproxy.loop_forever(rfile, wfile)
     assert wfile.getvalue() == b"Ohttps://example.org/\n"
+
+
+def test_legacy_token_migration(metadata, testaddr):
+    with metadata.get_metadata_dict(testaddr).modify() as data:
+        data[metadata.DEVICETOKEN_KEY] = ["oldtoken1", "oldtoken2"]
+
+    assert metadata.get_tokens_for_addr(testaddr) == ["oldtoken1", "oldtoken2"]
+    mdict = metadata.get_metadata_dict(testaddr).read()
+    tokens = mdict[metadata.DEVICETOKEN_KEY]
+    assert isinstance(tokens, dict)
+    assert "oldtoken1" in tokens and "oldtoken2" in tokens

cmdeploy/src/cmdeploy/nginx/nginx.conf.j2

@@ -42,6 +42,9 @@ stream {
 }
 
 http {
+	# access_log setting is inherited by all server sections
+	access_log syslog:server=unix:/dev/log,facility=local7;
+
 {% if config.tls_cert_mode == "self" %}
 	limit_req_zone $binary_remote_addr zone=newaccount:10m rate=2r/s;
 {% endif %}
@@ -69,9 +72,7 @@ http {
 
 		index index.html index.htm;
 
-		server_name {{ config.mail_domain }} www.{{ config.mail_domain }} mta-sts.{{ config.mail_domain }};
-
-		access_log syslog:server=unix:/dev/log,facility=local7;
+		server_name {{ config.mail_domain }} mta-sts.{{ config.mail_domain }};
 
 		location /mxdeliv {
 		    proxy_pass http://127.0.0.1:{{ config.filtermail_http_port_incoming }};
@@ -143,7 +144,6 @@ http {
 		listen 127.0.0.1:8443 ssl;
 		server_name www.{{ config.mail_domain }};
 		return 301 $scheme://{{ config.mail_domain }}$request_uri;
-		access_log syslog:server=unix:/dev/log,facility=local7;
 	}
 
 	server {

cmdeploy/src/cmdeploy/remote/rdns.py

@@ -64,21 +64,25 @@ def get_dkim_entry(mail_domain, pre_command, dkim_selector):
     )
 
 
-def query_dns(typ, domain):
-    # Get autoritative nameserver from the SOA record.
-    soa_answers = [
+def get_authoritative_ns(domain):
+    ns_replies = [
         x.split()
         for x in shell(
-            f"dig -r -q {domain} -t SOA +noall +authority +answer", print=log_progress
+            f"dig -r -q {domain} -t NS +noall +authority +answer", print=log_progress
         ).split("\n")
     ]
-    soa = [a for a in soa_answers if len(a) >= 3 and a[3] == "SOA"]
-    if not soa:
+    filtered_replies = [a for a in ns_replies if len(a) >= 5 and a[3] == "NS"]
+    if not filtered_replies:
         return
-    ns = soa[0][4]
+    return filtered_replies[0][4]
+
+
+def query_dns(typ, domain):
+    ns = get_authoritative_ns(domain)
 
     # Query authoritative nameserver directly to bypass DNS cache.
-    res = shell(f"dig @{ns} -r -q {domain} -t {typ} +short", print=log_progress)
+    direct_ns = f"@{ns}" if ns else ""
+    res = shell(f"dig {direct_ns} -r -q {domain} -t {typ} +short", print=log_progress)
     return next((line for line in res.split("\n") if not line.startswith(";")), "")
 
 

cmdeploy/src/cmdeploy/tests/online/test_1_basic.py

@@ -281,3 +281,13 @@ def test_deployed_state(remote):
     # assert len(git_status) == len(remote_version)  # for some reason, we only get 11 lines from remote.iter_output()
     for i in range(len(remote_version)):
         assert git_status[i] == remote_version[i], "You have undeployed changes."
+
+
+def test_nginx_access_log_only_defined_once(sshdomain):
+    sshexec = get_sshexec(sshdomain)
+    conf = sshexec(
+        call=remote.rshell.shell,
+        kwargs=dict(command="nginx -T 2>/dev/null"),
+    )
+    access_logs = [l for l in conf.splitlines() if l.strip().startswith("access_log")]
+    assert len(access_logs) == 1, f"expected 1 access_log, found {len(access_logs)}: {access_logs}"

cmdeploy/src/cmdeploy/tests/test_dns.py

@@ -4,6 +4,7 @@ import pytest
 
 from cmdeploy import remote
 from cmdeploy.dns import check_full_zone, check_initial_remote_data, parse_zone_records
+from cmdeploy.remote.rdns import get_authoritative_ns
 
 
 @pytest.fixture
@@ -14,11 +15,15 @@ def mockdns_base(monkeypatch):
         if command.startswith("dig"):
             if command == "dig":
                 return "."
-            if "SOA" in command:
+            if "with.public.soa" in command and "NS" in command:
+                return "domain.with.public.soa. 2419 IN NS ns1.first-ns.de."
+            if "with.hidden.soa" in command and "NS" in command:
                 return (
-                    "delta.chat. 21600 IN SOA ns1.first-ns.de. dns.hetzner.com."
-                    " 2025102800 14400 1800 604800 3600"
+                    "domain.with.hidden.soa. 2137 IN NS ns1.desec.io.\n"
+                    "domain.with.hidden.soa. 2137 IN NS ns2.desec.org."
                 )
+            if "NS" in command:
+                return "delta.chat. 21600 IN NS ns1.first-ns.de."
             command_chunks = command.split()
             domain, typ = command_chunks[4], command_chunks[6]
             try:
@@ -125,6 +130,17 @@ class TestPerformInitialChecks:
         assert not l
 
 
+@pytest.mark.parametrize(
+    ("domain", "ns"),
+    [
+        ("domain.with.public.soa", "ns1.first-ns.de."),
+        ("domain.with.hidden.soa", "ns1.desec.io."),
+    ],
+)
+def test_get_authoritative_ns(domain, ns, mockdns):
+    assert get_authoritative_ns(domain) == ns
+
+
 def test_parse_zone_records():
     text = """
     ; This is a comment