refinements and fixes

CHANGELOG.md

@@ -5,6 +5,10 @@
 - Install dig on the server to resolve DNS records
   ([#267](https://github.com/deltachat/chatmail/pull/267))
 
+- preserve notification order and exponentially backoff with 
+  retries for tokens where we didn't get a successful return
+  ([#265](https://github.com/deltachat/chatmail/pull/263))
+
 - Run chatmail-metadata and doveauth as vmail
   ([#261](https://github.com/deltachat/chatmail/pull/261))
 

chatmaild/src/chatmaild/metadata.py

@@ -1,5 +1,4 @@
 from pathlib import Path
-from threading import Thread, Event
 from socketserver import (
     UnixStreamServer,
     StreamRequestHandler,
@@ -8,9 +7,9 @@ from socketserver import (
 import sys
 import logging
 import os
-import requests
 
 from .filedict import FileDict
+from .notifier import Notifier
 
 
 DICTPROXY_HELLO_CHAR = "H"
@@ -21,84 +20,49 @@ DICTPROXY_SET_CHAR = "S"
 DICTPROXY_COMMIT_TRANSACTION_CHAR = "C"
 DICTPROXY_TRANSACTION_CHARS = "BSC"
 
-# each SETMETADATA on this key appends to a list of unique device tokens
-# which only ever get removed if the upstream indicates the token is invalid
-METADATA_TOKEN_KEY = "devicetoken"
 
+class Metadata:
+    # each SETMETADATA on this key appends to a list of unique device tokens
+    # which only ever get removed if the upstream indicates the token is invalid
+    DEVICETOKEN_KEY = "devicetoken"
 
-class Notifier:
     def __init__(self, vmail_dir):
         self.vmail_dir = vmail_dir
-        self.notification_dir = vmail_dir / "pending_notifications"
-        if not self.notification_dir.exists():
-            self.notification_dir.mkdir()
-        self.message_arrived_event = Event()
 
     def get_metadata_dict(self, addr):
         return FileDict(self.vmail_dir / addr / "metadata.json")
 
-    def add_token(self, addr, token):
+    def add_token_to_addr(self, addr, token):
         with self.get_metadata_dict(addr).modify() as data:
-            tokens = data.get(METADATA_TOKEN_KEY)
-            if tokens is None:
-                data[METADATA_TOKEN_KEY] = [token]
-            elif token not in tokens:
+            tokens = data.setdefault(self.DEVICETOKEN_KEY, [])
+            if token not in tokens:
                 tokens.append(token)
 
-    def remove_token(self, addr, token):
+    def remove_token_from_addr(self, addr, token):
         with self.get_metadata_dict(addr).modify() as data:
-            tokens = data.get(METADATA_TOKEN_KEY, [])
-            try:
+            tokens = data.get(self.DEVICETOKEN_KEY, [])
+            if token in tokens:
                 tokens.remove(token)
-            except ValueError:
-                pass
 
-    def get_tokens(self, addr):
-        return self.get_metadata_dict(addr).read().get(METADATA_TOKEN_KEY, [])
-
-    def new_message_for_addr(self, addr):
-        self.notification_dir.joinpath(addr).touch()
-        self.message_arrived_event.set()
-
-    def thread_run_loop(self):
-        requests_session = requests.Session()
-        while 1:
-            self.message_arrived_event.wait()
-            self.message_arrived_event.clear()
-            self.thread_run_one(requests_session)
-
-    def thread_run_one(self, requests_session):
-        for addr_path in self.notification_dir.iterdir():
-            addr = addr_path.name
-            if "@" not in addr:
-                continue
-            for token in self.get_tokens(addr):
-                response = requests_session.post(
-                    "https://notifications.delta.chat/notify",
-                    data=token,
-                    timeout=60,
-                )
-                if response.status_code == 410:
-                    # 410 Gone status code
-                    # means the token is no longer valid.
-                    self.remove_token(addr, token)
-            addr_path.unlink()
+    def get_tokens_for_addr(self, addr):
+        mdict = self.get_metadata_dict(addr).read()
+        return mdict.get(self.DEVICETOKEN_KEY, [])
 
 
-def handle_dovecot_protocol(rfile, wfile, notifier):
+def handle_dovecot_protocol(rfile, wfile, notifier, metadata):
     transactions = {}
     while True:
         msg = rfile.readline().strip().decode()
         if not msg:
             break
 
-        res = handle_dovecot_request(msg, transactions, notifier)
+        res = handle_dovecot_request(msg, transactions, notifier, metadata)
         if res:
             wfile.write(res.encode("ascii"))
             wfile.flush()
 
 
-def handle_dovecot_request(msg, transactions, notifier):
+def handle_dovecot_request(msg, transactions, notifier, metadata):
     # see https://doc.dovecot.org/3.0/developer_manual/design/dict_protocol/
     short_command = msg[0]
     parts = msg[1:].split("\t")
@@ -108,8 +72,8 @@ def handle_dovecot_request(msg, transactions, notifier):
         if keyparts[0] == "priv":
             keyname = keyparts[2]
             addr = parts[1]
-            if keyname == METADATA_TOKEN_KEY:
-                res = " ".join(notifier.get_tokens(addr))
+            if keyname == metadata.DEVICETOKEN_KEY:
+                res = " ".join(metadata.get_tokens_for_addr(addr))
                 return f"O{res}\n"
         logging.warning("lookup ignored: %r", msg)
         return "N\n"
@@ -142,10 +106,10 @@ def handle_dovecot_request(msg, transactions, notifier):
         keyname = parts[1].split("/")
         value = parts[2] if len(parts) > 2 else ""
         addr = transactions[transaction_id]["addr"]
-        if keyname[0] == "priv" and keyname[2] == METADATA_TOKEN_KEY:
-            notifier.add_token(addr, value)
+        if keyname[0] == "priv" and keyname[2] == metadata.DEVICETOKEN_KEY:
+            metadata.add_token_to_addr(addr, value)
         elif keyname[0] == "priv" and keyname[2] == "messagenew":
-            notifier.new_message_for_addr(addr)
+            notifier.new_message_for_addr(addr, metadata)
         else:
             # Transaction failed.
             transactions[transaction_id]["res"] = "F\n"
@@ -159,17 +123,20 @@ def main():
     socket, vmail_dir = sys.argv[1:]
 
     vmail_dir = Path(vmail_dir)
-
     if not vmail_dir.exists():
         logging.error("vmail dir does not exist: %r", vmail_dir)
         return 1
 
-    notifier = Notifier(vmail_dir)
+    queue_dir = vmail_dir / "pending_notifications"
+    queue_dir.mkdir(exist_ok=True)
+    metadata = Metadata(vmail_dir)
+    notifier = Notifier(queue_dir)
+    notifier.start_notification_threads(metadata.remove_token_from_addr)
 
     class Handler(StreamRequestHandler):
         def handle(self):
             try:
-                handle_dovecot_protocol(self.rfile, self.wfile, notifier)
+                handle_dovecot_protocol(self.rfile, self.wfile, notifier, metadata)
             except Exception:
                 logging.exception("Exception in the dovecot dictproxy handler")
                 raise
@@ -179,15 +146,6 @@ def main():
     except FileNotFoundError:
         pass
 
-    # start notifier thread for signalling new messages to
-    # Delta Chat notification server
-
-    t = Thread(target=notifier.thread_run_loop)
-    t.setDaemon(True)
-    t.start()
-    # let notifier thread run once for any pending notifications from last run
-    notifier.message_arrived_event.set()
-
     with ThreadedUnixStreamServer(socket, Handler) as server:
         try:
             server.serve_forever()

chatmaild/src/chatmaild/notifier.py

@@ -0,0 +1,165 @@
+"""
+This modules provides notification machinery for transmitting device tokens to
+a central notification server which in turn contacts a phone provider's notification server
+to trigger Delta Chat apps to retrieve messages and provide instant notifications to users.
+
+The Notifier class arranges the queuing of tokens in separate PriorityQueues
+from which NotifyThreads take and transmit them via HTTPS
+to the `notifications.delta.chat` service.
+The current lack of proper HTTP/2-support in Python leads us
+to use multiple threads and connections to the Rust-implemented `notifications.delta.chat`
+which itself uses HTTP/2 and thus only a single connection to phone-notification providers.
+
+If a token fails to cause a successful notification
+it is moved to a retry-number specific PriorityQueue
+which handles all tokens that failed a particular number of times
+and which are scheduled for retry using exponential back-off timing.
+If a token notification would be scheduled more than DROP_DEADLINE seconds
+after its first attempt, it is dropped with a log error.
+
+Note that tokens are completely opaque to the notification machinery here
+and will in the future be encrypted foreclosing all ability to distinguish
+which device token ultimately goes to which phone-provider notification service,
+or to understand the relation of "device tokens" and chatmail addresses.
+The meaning and format of tokens is basically a matter of Delta-Chat Core and
+the `notification.delta.chat` service.
+"""
+
+import os
+import time
+import math
+import logging
+from uuid import uuid4
+from threading import Thread
+from pathlib import Path
+from queue import PriorityQueue
+from dataclasses import dataclass
+import requests
+
+
+@dataclass
+class PersistentQueueItem:
+    path: Path
+    addr: str
+    start_ts: int
+    token: str
+
+    def delete(self):
+        self.path.unlink(missing_ok=True)
+
+    @classmethod
+    def create(cls, queue_dir, addr, start_ts, token):
+        queue_id = uuid4().hex
+        start_ts = int(start_ts)
+        path = queue_dir.joinpath(queue_id)
+        tmp_path = path.with_name(path.name + ".tmp")
+        tmp_path.write_text(f"{addr}\n{start_ts}\n{token}")
+        os.rename(tmp_path, path)
+        return cls(path, addr, start_ts, token)
+
+    @classmethod
+    def read_from_path(cls, path):
+        addr, start_ts, token = path.read_text().split("\n", maxsplit=2)
+        return cls(path, addr, int(start_ts), token)
+
+    def __lt__(self, other):
+        return self.start_ts < other.start_ts
+
+
+class Notifier:
+    URL = "https://notifications.delta.chat/notify"
+    CONNECTION_TIMEOUT = 60.0  # seconds until http-request is given up
+    BASE_DELAY = 8.0  # base seconds for exponential back-off delay
+    DROP_DEADLINE = 5 * 60 * 60  #  drop notifications after 5 hours
+
+    def __init__(self, queue_dir):
+        self.queue_dir = queue_dir
+        max_tries = int(math.log(self.DROP_DEADLINE, self.BASE_DELAY)) + 1
+        self.retry_queues = [PriorityQueue() for _ in range(max_tries)]
+
+    def compute_delay(self, retry_num):
+        return 0 if retry_num == 0 else pow(self.BASE_DELAY, retry_num)
+
+    def new_message_for_addr(self, addr, metadata):
+        start_ts = int(time.time())
+        for token in metadata.get_tokens_for_addr(addr):
+            queue_item = PersistentQueueItem.create(
+                self.queue_dir, addr, start_ts, token
+            )
+            self.queue_for_retry(queue_item)
+
+    def requeue_persistent_queue_items(self):
+        for queue_path in self.queue_dir.iterdir():
+            if queue_path.name.endswith(".tmp"):
+                logging.warning("removing spurious queue item: %r", queue_path)
+                queue_path.unlink()
+                continue
+            queue_item = PersistentQueueItem.read_from_path(queue_path)
+            self.queue_for_retry(queue_item)
+
+    def queue_for_retry(self, queue_item, retry_num=0):
+        delay = self.compute_delay(retry_num)
+        when = int(time.time()) + delay
+        deadline = queue_item.start_ts + self.DROP_DEADLINE
+        if retry_num >= len(self.retry_queues) or when > deadline:
+            queue_item.delete()
+            logging.error("notification exceeded deadline: %r", queue_item.token)
+            return
+
+        self.retry_queues[retry_num].put((when, queue_item))
+
+    def start_notification_threads(self, remove_token_from_addr):
+        self.requeue_persistent_queue_items()
+        threads = {}
+        for retry_num in range(len(self.retry_queues)):
+            # use 4 threads for first-try tokens and less for subsequent tries
+            num_threads = 4 if retry_num == 0 else 2
+            threads[retry_num] = []
+            for _ in range(num_threads):
+                thread = NotifyThread(self, retry_num, remove_token_from_addr)
+                threads[retry_num].append(thread)
+                thread.start()
+        return threads
+
+
+class NotifyThread(Thread):
+    def __init__(self, notifier, retry_num, remove_token_from_addr):
+        super().__init__(daemon=True)
+        self.notifier = notifier
+        self.retry_num = retry_num
+        self.remove_token_from_addr = remove_token_from_addr
+
+    def stop(self):
+        self.notifier.retry_queues[self.retry_num].put((None, None))
+
+    def run(self):
+        requests_session = requests.Session()
+        while self.retry_one(requests_session):
+            pass
+
+    def retry_one(self, requests_session, sleep=time.sleep):
+        when, queue_item = self.notifier.retry_queues[self.retry_num].get()
+        if when is None:
+            return False
+        wait_time = when - int(time.time())
+        if wait_time > 0:
+            sleep(wait_time)
+        self.perform_request_to_notification_server(requests_session, queue_item)
+        return True
+
+    def perform_request_to_notification_server(self, requests_session, queue_item):
+        timeout = self.notifier.CONNECTION_TIMEOUT
+        token = queue_item.token
+        try:
+            res = requests_session.post(self.notifier.URL, data=token, timeout=timeout)
+        except requests.exceptions.RequestException as e:
+            res = e
+        else:
+            if res.status_code in (200, 410):
+                if res.status_code == 410:
+                    self.remove_token_from_addr(queue_item.addr, token)
+                queue_item.delete()
+                return
+
+        logging.warning("Notification request failed: %r", res)
+        self.notifier.queue_for_retry(queue_item, retry_num=self.retry_num + 1)

chatmaild/src/chatmaild/tests/test_metadata.py

@@ -1,18 +1,32 @@
 import io
 import pytest
+import requests
+import time
 
 from chatmaild.metadata import (
     handle_dovecot_request,
     handle_dovecot_protocol,
+    Metadata,
+)
+from chatmaild.notifier import (
     Notifier,
+    NotifyThread,
+    PersistentQueueItem,
 )
 
 
 @pytest.fixture
-def notifier(tmp_path):
+def notifier(metadata):
+    queue_dir = metadata.vmail_dir.joinpath("pending_notifications")
+    queue_dir.mkdir()
+    return Notifier(queue_dir)
+
+
+@pytest.fixture
+def metadata(tmp_path):
     vmail_dir = tmp_path.joinpath("vmaildir")
     vmail_dir.mkdir()
-    return Notifier(vmail_dir)
+    return Metadata(vmail_dir)
 
 
 @pytest.fixture
@@ -25,72 +39,100 @@ def testaddr2():
     return "user2@example.org"
 
 
-def test_notifier_persistence(tmp_path, testaddr, testaddr2):
-    notifier1 = Notifier(tmp_path)
-    notifier2 = Notifier(tmp_path)
-    assert not notifier1.get_tokens(testaddr)
-    assert not notifier2.get_tokens(testaddr)
-
-    notifier1.add_token(testaddr, "01234")
-    notifier1.add_token(testaddr2, "456")
-    assert notifier2.get_tokens(testaddr) == ["01234"]
-    assert notifier2.get_tokens(testaddr2) == ["456"]
-    notifier2.remove_token(testaddr, "01234")
-    assert not notifier1.get_tokens(testaddr)
-    assert notifier1.get_tokens(testaddr2) == ["456"]
+@pytest.fixture
+def token():
+    return "01234"
 
 
-def test_remove_nonexisting(tmp_path, testaddr):
-    notifier1 = Notifier(tmp_path)
-    notifier1.add_token(testaddr, "123")
-    notifier1.remove_token(testaddr, "1l23k1l2k3")
-    assert notifier1.get_tokens(testaddr) == ["123"]
+def get_mocked_requests(statuslist):
+    class ReqMock:
+        requests = []
+
+        def post(self, url, data, timeout):
+            self.requests.append((url, data, timeout))
+            res = statuslist.pop(0)
+            if isinstance(res, Exception):
+                raise res
+
+            class Result:
+                status_code = res
+
+            return Result()
+
+    return ReqMock()
 
 
-def test_notifier_delete_without_set(notifier, testaddr):
-    notifier.remove_token(testaddr, "123")
-    assert not notifier.get_tokens(testaddr)
+def test_metadata_persistence(tmp_path, testaddr, testaddr2):
+    metadata1 = Metadata(tmp_path)
+    metadata2 = Metadata(tmp_path)
+    assert not metadata1.get_tokens_for_addr(testaddr)
+    assert not metadata2.get_tokens_for_addr(testaddr)
+
+    metadata1.add_token_to_addr(testaddr, "01234")
+    metadata1.add_token_to_addr(testaddr2, "456")
+    assert metadata2.get_tokens_for_addr(testaddr) == ["01234"]
+    assert metadata2.get_tokens_for_addr(testaddr2) == ["456"]
+    metadata2.remove_token_from_addr(testaddr, "01234")
+    assert not metadata1.get_tokens_for_addr(testaddr)
+    assert metadata1.get_tokens_for_addr(testaddr2) == ["456"]
 
 
-def test_handle_dovecot_request_lookup_fails(notifier, testaddr):
-    res = handle_dovecot_request(f"Lpriv/123/chatmail\t{testaddr}", {}, notifier)
+def test_remove_nonexisting(metadata, tmp_path, testaddr):
+    metadata.add_token_to_addr(testaddr, "123")
+    metadata.remove_token_from_addr(testaddr, "1l23k1l2k3")
+    assert metadata.get_tokens_for_addr(testaddr) == ["123"]
+
+
+def test_notifier_remove_without_set(metadata, testaddr):
+    metadata.remove_token_from_addr(testaddr, "123")
+    assert not metadata.get_tokens_for_addr(testaddr)
+
+
+def test_handle_dovecot_request_lookup_fails(notifier, metadata, testaddr):
+    res = handle_dovecot_request(
+        f"Lpriv/123/chatmail\t{testaddr}", {}, notifier, metadata
+    )
     assert res == "N\n"
 
 
-def test_handle_dovecot_request_happy_path(notifier, testaddr):
+def test_handle_dovecot_request_happy_path(notifier, metadata, testaddr, token):
     transactions = {}
 
     # set device token in a transaction
     tx = "1111"
     msg = f"B{tx}\t{testaddr}"
-    res = handle_dovecot_request(msg, transactions, notifier)
-    assert not res and not notifier.get_tokens(testaddr)
+    res = handle_dovecot_request(msg, transactions, notifier, metadata)
+    assert not res and not metadata.get_tokens_for_addr(testaddr)
     assert transactions == {tx: dict(addr=testaddr, res="O\n")}
 
-    msg = f"S{tx}\tpriv/guid00/devicetoken\t01234"
-    res = handle_dovecot_request(msg, transactions, notifier)
+    msg = f"S{tx}\tpriv/guid00/devicetoken\t{token}"
+    res = handle_dovecot_request(msg, transactions, notifier, metadata)
     assert not res
     assert len(transactions) == 1
-    assert notifier.get_tokens(testaddr) == ["01234"]
+    assert metadata.get_tokens_for_addr(testaddr) == [token]
 
     msg = f"C{tx}"
-    res = handle_dovecot_request(msg, transactions, notifier)
+    res = handle_dovecot_request(msg, transactions, notifier, metadata)
     assert res == "O\n"
     assert len(transactions) == 0
-    assert notifier.get_tokens(testaddr) == ["01234"]
+    assert metadata.get_tokens_for_addr(testaddr) == [token]
 
     # trigger notification for incoming message
     tx2 = "2222"
-    assert handle_dovecot_request(f"B{tx2}\t{testaddr}", transactions, notifier) is None
+    assert (
+        handle_dovecot_request(f"B{tx2}\t{testaddr}", transactions, notifier, metadata)
+        is None
+    )
     msg = f"S{tx2}\tpriv/guid00/messagenew"
-    assert handle_dovecot_request(msg, transactions, notifier) is None
-    assert notifier.message_arrived_event.is_set()
-    assert handle_dovecot_request(f"C{tx2}", transactions, notifier) == "O\n"
+    assert handle_dovecot_request(msg, transactions, notifier, metadata) is None
+    queue_item = notifier.retry_queues[0].get()[1]
+    assert queue_item.token == token
+    assert handle_dovecot_request(f"C{tx2}", transactions, notifier, metadata) == "O\n"
     assert not transactions
-    assert notifier.notification_dir.joinpath(testaddr).exists()
+    assert queue_item.path.exists()
 
 
-def test_handle_dovecot_protocol_set_devicetoken(notifier):
+def test_handle_dovecot_protocol_set_devicetoken(metadata, notifier):
     rfile = io.BytesIO(
         b"\n".join(
             [
@@ -102,12 +144,12 @@ def test_handle_dovecot_protocol_set_devicetoken(notifier):
         )
     )
     wfile = io.BytesIO()
-    handle_dovecot_protocol(rfile, wfile, notifier)
+    handle_dovecot_protocol(rfile, wfile, notifier, metadata)
     assert wfile.getvalue() == b"O\n"
-    assert notifier.get_tokens("user@example.org") == ["01234"]
+    assert metadata.get_tokens_for_addr("user@example.org") == ["01234"]
 
 
-def test_handle_dovecot_protocol_set_get_devicetoken(notifier):
+def test_handle_dovecot_protocol_set_get_devicetoken(metadata, notifier):
     rfile = io.BytesIO(
         b"\n".join(
             [
@@ -119,19 +161,19 @@ def test_handle_dovecot_protocol_set_get_devicetoken(notifier):
         )
     )
     wfile = io.BytesIO()
-    handle_dovecot_protocol(rfile, wfile, notifier)
-    assert notifier.get_tokens("user@example.org") == ["01234"]
+    handle_dovecot_protocol(rfile, wfile, notifier, metadata)
+    assert metadata.get_tokens_for_addr("user@example.org") == ["01234"]
     assert wfile.getvalue() == b"O\n"
 
     rfile = io.BytesIO(
         b"\n".join([b"HELLO", b"Lpriv/0123/devicetoken\tuser@example.org"])
     )
     wfile = io.BytesIO()
-    handle_dovecot_protocol(rfile, wfile, notifier)
+    handle_dovecot_protocol(rfile, wfile, notifier, metadata)
     assert wfile.getvalue() == b"O01234\n"
 
 
-def test_handle_dovecot_protocol_iterate(notifier):
+def test_handle_dovecot_protocol_iterate(metadata, notifier):
     rfile = io.BytesIO(
         b"\n".join(
             [
@@ -141,90 +183,116 @@ def test_handle_dovecot_protocol_iterate(notifier):
         )
     )
     wfile = io.BytesIO()
-    handle_dovecot_protocol(rfile, wfile, notifier)
+    handle_dovecot_protocol(rfile, wfile, notifier, metadata)
     assert wfile.getvalue() == b"\n"
 
 
-def test_handle_dovecot_protocol_messagenew(notifier):
-    rfile = io.BytesIO(
-        b"\n".join(
-            [
-                b"HELLO",
-                b"Btx01\tuser@example.org",
-                b"Stx01\tpriv/guid00/messagenew",
-                b"Ctx01",
-            ]
-        )
-    )
-    wfile = io.BytesIO()
-    handle_dovecot_protocol(rfile, wfile, notifier)
-    assert wfile.getvalue() == b"O\n"
-    assert notifier.message_arrived_event.is_set()
-    assert notifier.notification_dir.joinpath("user@example.org").exists()
-
-
-def test_notifier_thread_run(notifier, testaddr):
-    requests = []
-
-    class ReqMock:
-        def post(self, url, data, timeout):
-            requests.append((url, data, timeout))
-
-            class Result:
-                status_code = 200
-
-            return Result()
-
-    notifier.add_token(testaddr, "01234")
-    notifier.new_message_for_addr(testaddr)
-    notifier.thread_run_one(ReqMock())
-    url, data, timeout = requests[0]
+def test_notifier_thread_deletes_persistent_file(metadata, notifier, testaddr):
+    reqmock = get_mocked_requests([200])
+    metadata.add_token_to_addr(testaddr, "01234")
+    notifier.new_message_for_addr(testaddr, metadata)
+    NotifyThread(notifier, 0, None).retry_one(reqmock)
+    url, data, timeout = reqmock.requests[0]
     assert data == "01234"
-    assert notifier.get_tokens(testaddr) == ["01234"]
+    assert metadata.get_tokens_for_addr(testaddr) == ["01234"]
+    notifier.requeue_persistent_queue_items()
+    assert notifier.retry_queues[0].qsize() == 0
 
 
-def test_multi_device_notifier(notifier, testaddr):
-    requests = []
+@pytest.mark.parametrize("status", [requests.exceptions.RequestException(), 404, 500])
+def test_notifier_thread_connection_failures(
+    metadata, notifier, testaddr, status, caplog
+):
+    """test that tokens keep getting retried until they are given up."""
+    metadata.add_token_to_addr(testaddr, "01234")
+    notifier.new_message_for_addr(testaddr, metadata)
+    notifier.NOTIFICATION_RETRY_DELAY = 5
+    max_tries = len(notifier.retry_queues)
+    for i in range(max_tries):
+        caplog.clear()
+        reqmock = get_mocked_requests([status])
+        sleep_calls = []
+        NotifyThread(notifier, i, None).retry_one(reqmock, sleep=sleep_calls.append)
+        assert notifier.retry_queues[i].qsize() == 0
+        assert "request failed" in caplog.records[0].msg
+        if i > 0:
+            assert len(sleep_calls) == 1
+        if i + 1 < max_tries:
+            assert notifier.retry_queues[i + 1].qsize() == 1
+            assert len(caplog.records) == 1
+        else:
+            assert len(caplog.records) == 2
+            assert "deadline" in caplog.records[1].msg
+    notifier.requeue_persistent_queue_items()
+    assert notifier.retry_queues[0].qsize() == 0
 
-    class ReqMock:
-        def post(self, url, data, timeout):
-            requests.append((url, data, timeout))
 
-            class Result:
-                status_code = 200
+def test_requeue_removes_tmp_files(notifier, metadata, testaddr, caplog):
+    metadata.add_token_to_addr(testaddr, "01234")
+    notifier.new_message_for_addr(testaddr, metadata)
+    p = notifier.queue_dir.joinpath("1203981203.tmp")
+    p.touch()
+    notifier2 = notifier.__class__(notifier.queue_dir)
+    notifier2.requeue_persistent_queue_items()
+    assert "spurious" in caplog.records[0].msg
+    assert not p.exists()
+    assert notifier2.retry_queues[0].qsize() == 1
+    when, queue_item = notifier2.retry_queues[0].get()
+    assert when <= int(time.time())
+    assert queue_item.addr == testaddr
 
-            return Result()
 
-    notifier.add_token(testaddr, "01234")
-    notifier.add_token(testaddr, "56789")
-    notifier.new_message_for_addr(testaddr)
-    notifier.thread_run_one(ReqMock())
-    url, data, timeout = requests[0]
+def test_start_and_stop_notification_threads(notifier, testaddr):
+    threads = notifier.start_notification_threads(None)
+    for retry_num, threadlist in threads.items():
+        for t in threadlist:
+            t.stop()
+            t.join()
+
+
+def test_multi_device_notifier(metadata, notifier, testaddr):
+    metadata.add_token_to_addr(testaddr, "01234")
+    metadata.add_token_to_addr(testaddr, "56789")
+    notifier.new_message_for_addr(testaddr, metadata)
+    reqmock = get_mocked_requests([200, 200])
+    NotifyThread(notifier, 0, None).retry_one(reqmock)
+    NotifyThread(notifier, 0, None).retry_one(reqmock)
+    assert notifier.retry_queues[0].qsize() == 0
+    assert notifier.retry_queues[1].qsize() == 0
+    url, data, timeout = reqmock.requests[0]
     assert data == "01234"
-    url, data, timeout = requests[1]
+    url, data, timeout = reqmock.requests[1]
     assert data == "56789"
-    assert notifier.get_tokens(testaddr) == ["01234", "56789"]
+    assert metadata.get_tokens_for_addr(testaddr) == ["01234", "56789"]
 
 
-def test_notifier_thread_run_gone_removes_token(notifier, testaddr):
-    requests = []
+def test_notifier_thread_run_gone_removes_token(metadata, notifier, testaddr):
+    metadata.add_token_to_addr(testaddr, "01234")
+    metadata.add_token_to_addr(testaddr, "45678")
+    notifier.new_message_for_addr(testaddr, metadata)
 
-    class ReqMock:
-        def post(self, url, data, timeout):
-            requests.append((url, data, timeout))
-
-            class Result:
-                status_code = 410 if data == "01234" else 200
-
-            return Result()
-
-    notifier.add_token(testaddr, "01234")
-    notifier.new_message_for_addr(testaddr)
-    assert notifier.get_tokens(testaddr) == ["01234"]
-    notifier.add_token(testaddr, "45678")
-    notifier.thread_run_one(ReqMock())
-    url, data, timeout = requests[0]
+    reqmock = get_mocked_requests([410, 200])
+    NotifyThread(notifier, 0, metadata.remove_token_from_addr).retry_one(reqmock)
+    NotifyThread(notifier, 0, None).retry_one(reqmock)
+    url, data, timeout = reqmock.requests[0]
     assert data == "01234"
-    url, data, timeout = requests[1]
+    url, data, timeout = reqmock.requests[1]
     assert data == "45678"
-    assert notifier.get_tokens(testaddr) == ["45678"]
+    assert metadata.get_tokens_for_addr(testaddr) == ["45678"]
+    assert notifier.retry_queues[0].qsize() == 0
+    assert notifier.retry_queues[1].qsize() == 0
+
+
+def test_persistent_queue_items(tmp_path, testaddr, token):
+    queue_item = PersistentQueueItem.create(tmp_path, testaddr, 432, token)
+    assert queue_item.addr == testaddr
+    assert queue_item.start_ts == 432
+    assert queue_item.token == token
+    item2 = PersistentQueueItem.read_from_path(queue_item.path)
+    assert item2.addr == testaddr
+    assert item2.start_ts == 432
+    assert item2.token == token
+    assert item2 == queue_item
+    item2.delete()
+    assert not item2.path.exists()
+    assert not queue_item < item2 and not item2 < queue_item