feat: the bot can describe an envelope without quoting anybody

DOCS-signal-envelopes.md exists because this wire format is not obvious
and guessing at it has cost real bugs -- the sticker read off the wrong
nesting level, and 0.0.3's !gekon shipping green on an assumption nobody
had checked against the live API. The recurring cost is that answering
"what does a frame with an attachment actually look like?" needed a code
change, a restart, and somebody sending one at the right moment.

So at DEBUG the dispatcher now logs each frame's *shape*: keys and value
types, never values. Two fields keep their values because they are wire
format rather than anything a person said -- a MIME type and a groupInfo
type. A message body, a name, a number, a uuid, quoted text and a
sticker id all come out as "str". An album collapses to one element and
a count instead of printing the same dict twenty times.

Verified against a live frame: the body, the quoted text, the uuid and
the phone number do not survive, and contentType does.

This also had to fix DEBUG being unusable. LOG_LEVEL=DEBUG set the root
logger, which turns on httpx, httpcore and asyncio; the bot polls a
group listing every 30 seconds, so the one interesting line arrived
buried and journald started dropping. Libraries are now held at WARNING
whatever the bot is set to -- at INFO httpx was already emitting an
"HTTP Request: GET ... 200 OK" line every thirty seconds, forever.
Measured on the running unit: 17 library lines per minute down to 2.

Two bugs in that setup found by its own tests rather than by review:
basicConfig is a documented no-op once the root logger has a handler, so
the level silently did not apply under pytest; and the floor belongs at
INFO too, not only below it.

A self-send does not produce a capturable attachment envelope, by the
way -- signal-cli emits no syncMessage for a send made over the same
connection. Two probe images returned HTTP 201 and no frame came back,
so the inbound shape still needs a human to post one.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015d48t4qsQLBJnDwDeo2Nom

signal_bot/__main__.py

@@ -12,11 +12,10 @@ BIND_HOST/BIND_PORT whenever they live in .env -- which is where they live.
 
 from __future__ import annotations
 
-import logging
-
 import uvicorn
 
 from signal_bot.config_env import load_config
+from signal_bot.logging_setup import configure as configure_logging
 from signal_bot.portcheck import PortInUseError, assert_port_free
 
 
@@ -26,9 +25,7 @@ def main() -> None:
     # Before anything else: uvicorn only configures its own loggers, so
     # without this the bot's own log lines go to logging.lastResort and
     # anything below WARNING is thrown away.
-    logging.basicConfig(
-        level=config.log_level, format="%(asctime)s %(levelname)s %(name)s: %(message)s"
-    )
+    configure_logging(config.log_level)
     try:
         assert_port_free(config.bind_host, config.bind_port)
     except PortInUseError as exc:

signal_bot/dispatcher.py

@@ -10,6 +10,7 @@ from dataclasses import dataclass
 from typing import TYPE_CHECKING
 
 from signal_bot.counting import should_count, watched_group
+from signal_bot.envelope_shape import shape_of
 from signal_bot.models import parse_envelope
 from signal_bot.registry import CommandContext, CommandRegistry
 from signal_bot.stats.recorder import record_message
@@ -38,6 +39,10 @@ class Dispatcher:
 
     async def handle(self, frame: str) -> None:
         """Process one raw websocket frame end to end."""
+        # Keys and types only, never values -- see envelope_shape. This is
+        # how "what does a frame with an attachment look like?" gets answered
+        # without a code change and a lucky moment.
+        logger.debug("envelope shape: %s", shape_of(frame))
         message = parse_envelope(frame)
         if message is None:
             return

signal_bot/envelope_shape.py

@@ -0,0 +1,60 @@
+# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
+"""Describing an envelope's *shape* without logging what anybody wrote.
+
+`DOCS-signal-envelopes.md` exists because the wire format is not obvious and
+guessing at it has cost this repo real bugs -- the sticker read off the wrong
+nesting level, and 0.0.3's `!gekon` shipping green on an assumption nobody had
+checked against the live API. The recurring problem is that answering "what
+does a frame with an attachment actually look like?" needed a code change, a
+restart, and somebody sending one at the right moment.
+
+So the bot can now say it itself, at DEBUG. What it emits is keys and value
+*types*, never values -- with a small allowlist for the handful of fields that
+are format, not content: a MIME type and a groupInfo type say nothing about
+anybody. Message bodies, names, numbers, uuids, quoted text and sticker ids
+are all reduced to their type.
+
+    LOG_LEVEL=DEBUG, then: journalctl --user -u signal-bot | grep 'envelope shape'
+"""
+
+from __future__ import annotations
+
+import json
+from typing import Final
+
+# Fields whose value is a wire-format fact rather than anything a person said.
+SAFE_VALUES: Final = frozenset({"contentType", "type"})
+
+
+def _describe(value: object, key: str = "") -> str:
+    """Render one value as its shape."""
+    if isinstance(value, dict):
+        inner = ", ".join(f"{k}: {_describe(v, k)}" for k, v in sorted(value.items()))
+        return "{" + inner + "}"
+    if isinstance(value, list):
+        if not value:
+            return "[]"
+        # One entry is enough to show the element shape; a photo album would
+        # otherwise print the same dict twenty times.
+        return f"[{_describe(value[0])} x{len(value)}]"
+    if key in SAFE_VALUES and isinstance(value, str):
+        return repr(value)
+    if value is None:
+        return "null"
+    return type(value).__name__
+
+
+def shape_of(raw: str | bytes) -> str:
+    """Describe a raw frame as keys and types, or say why it could not be.
+
+    Args:
+        raw: The JSON frame exactly as received.
+
+    Returns:
+        A one-line description safe to write to a log.
+    """
+    try:
+        decoded = json.loads(raw)
+    except json.JSONDecodeError, UnicodeDecodeError:
+        return "<unparseable>"
+    return _describe(decoded)

signal_bot/logging_setup.py

@@ -0,0 +1,41 @@
+# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
+"""Logging configuration, with the noisy libraries kept out of DEBUG.
+
+``LOG_LEVEL=DEBUG`` exists to answer questions about the bot -- which frame
+was ignored and why, what shape an envelope actually has. Setting the root
+logger to DEBUG also turns on httpx, httpcore and asyncio, which between them
+emit several lines per HTTP request. The bot polls a group listing every 30
+seconds, so the one line worth reading arrives buried in hundreds that are
+not, and journald rate-limiting then starts dropping messages.
+
+So the libraries are held at WARNING whatever the bot is set to. A warning
+from httpx is worth seeing; its per-request bookkeeping is not, at any level
+-- at INFO it was already emitting a "HTTP Request: GET ... 200 OK" line
+every thirty seconds, forever.
+"""
+
+from __future__ import annotations
+
+import logging
+from typing import Final
+
+FORMAT: Final = "%(asctime)s %(levelname)s %(name)s: %(message)s"
+# Every third-party logger that is chatty at DEBUG. httpcore is the worst
+# offender by an order of magnitude: it logs both ends of every connection.
+NOISY: Final = ("httpx", "httpcore", "asyncio", "websockets", "urllib3")
+NOISY_FLOOR: Final = logging.WARNING
+
+
+def configure(level: str) -> None:
+    """Send the bot's logs to stderr at ``level``, muting the noisy libraries.
+
+    Args:
+        level: A logging level name, already validated by config_env.
+    """
+    logging.basicConfig(level=level, format=FORMAT)
+    # Explicitly too: basicConfig is a documented no-op once the root logger
+    # already has a handler, which is the case under pytest and under some
+    # uvicorn arrangements. Without this the level silently does not apply.
+    logging.getLogger().setLevel(level)
+    for name in NOISY:
+        logging.getLogger(name).setLevel(NOISY_FLOOR)

tests/test_envelope_shape.py

@@ -0,0 +1,78 @@
+# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
+"""Describing a frame's shape without logging what anybody wrote."""
+
+from __future__ import annotations
+
+import json
+
+from signal_bot.envelope_shape import shape_of
+from tests.conftest import WATCHED_GROUP, envelope
+
+PRIVATE_BODY = "the actual message body"
+
+
+def test_values_are_replaced_by_their_types() -> None:
+    """The whole point: a log line that cannot leak a message."""
+    shape = shape_of(envelope(text=PRIVATE_BODY))
+    assert PRIVATE_BODY not in shape
+    assert "message: str" in shape
+
+
+def test_names_numbers_and_uuids_do_not_survive() -> None:
+    shape = shape_of(envelope(text="hi", sender=("b1c2d3e4-0000", "kuhy")))
+    assert "b1c2d3e4" not in shape
+    assert "kuhy" not in shape
+    assert "+15555550123" not in shape
+
+
+def test_quoted_text_does_not_survive() -> None:
+    shape = shape_of(envelope(text="hi", extra="quote"))
+    assert "..." not in shape
+    assert "quote: {author: str, id: int, text: str}" in shape
+
+
+def test_the_group_id_is_a_type_but_its_kind_is_a_value() -> None:
+    """DELIVER vs UPDATE is wire format; the id identifies a conversation."""
+    shape = shape_of(envelope(text="hi"))
+    assert WATCHED_GROUP not in shape
+    assert "groupId: str" in shape
+    assert "type: 'DELIVER'" in shape
+
+
+def test_attachment_content_types_are_kept() -> None:
+    """The one thing this exists to answer, so it must survive redaction."""
+    shape = shape_of(envelope(text=None, attachments=("image/jpeg", "video/mp4")))
+    assert "contentType: 'image/jpeg'" in shape
+    assert "x2]" in shape
+
+
+def test_an_album_is_summarised_not_repeated() -> None:
+    shape = shape_of(envelope(text=None, attachments=("image/jpeg",) * 20))
+    assert "x20]" in shape
+    assert shape.count("contentType") == 1
+
+
+def test_an_empty_list_is_shown_as_empty() -> None:
+    assert shape_of(json.dumps({"envelope": {"members": []}})) == "{envelope: {members: []}}"
+
+
+def test_null_is_distinguished_from_absent() -> None:
+    """A caption-less photo may send message: null rather than omitting it."""
+    assert "message: null" in shape_of(json.dumps({"envelope": {"message": None}}))
+
+
+def test_numbers_and_booleans_show_their_type() -> None:
+    frame = json.dumps({"envelope": {"timestamp": 1, "urgent": True, "score": 1.5}})
+    assert shape_of(frame) == "{envelope: {score: float, timestamp: int, urgent: bool}}"
+
+
+def test_an_unparseable_frame_says_so() -> None:
+    assert shape_of("not json") == "<unparseable>"
+    assert shape_of(b"\xff\xfe") == "<unparseable>"
+
+
+def test_keys_are_sorted_so_two_frames_compare() -> None:
+    """Same shape, different key order, identical description."""
+    first = json.dumps({"envelope": {"b": 1, "a": "x"}})
+    second = json.dumps({"envelope": {"a": "x", "b": 1}})
+    assert shape_of(first) == shape_of(second)

tests/test_logging_setup.py

@@ -0,0 +1,48 @@
+# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
+"""DEBUG that stays readable: the bot's own loggers, not its libraries'."""
+
+from __future__ import annotations
+
+import logging
+
+import pytest
+
+from signal_bot.logging_setup import NOISY, NOISY_FLOOR, configure
+
+
+@pytest.fixture(autouse=True)
+def _restore_levels() -> None:
+    """Put every logger this module touches back, so tests stay independent."""
+    root = logging.getLogger().level
+    before = {name: logging.getLogger(name).level for name in NOISY}
+    yield
+    logging.getLogger().setLevel(root)
+    for name, level in before.items():
+        logging.getLogger(name).setLevel(level)
+
+
+def test_the_bots_own_level_is_what_was_asked_for() -> None:
+    configure("DEBUG")
+    assert logging.getLogger("signal_bot.dispatcher").getEffectiveLevel() == logging.DEBUG
+
+
+def test_debug_does_not_turn_on_the_noisy_libraries() -> None:
+    """httpcore logs both ends of every connection, every 30 seconds."""
+    configure("DEBUG")
+    for name in NOISY:
+        assert logging.getLogger(name).level == NOISY_FLOOR
+
+
+def test_the_floor_applies_at_info_too() -> None:
+    """httpx logged one "HTTP Request" line per listing poll, at INFO."""
+    logging.getLogger("httpx").setLevel(logging.NOTSET)
+    configure("INFO")
+    assert logging.getLogger("httpx").level == NOISY_FLOOR
+    assert logging.getLogger("signal_bot").getEffectiveLevel() == logging.INFO
+
+
+def test_warnings_from_a_noisy_library_still_get_through() -> None:
+    """The floor is a floor, not a gag: a real httpx warning is worth seeing."""
+    configure("DEBUG")
+    assert logging.getLogger("httpx").isEnabledFor(logging.WARNING)
+    assert not logging.getLogger("httpx").isEnabledFor(logging.INFO)