mirror of
https://github.com/kuhyx/signal-bot.git
synced 2026-11-10 20:27:17 +01:00
Krzysztof kuhy Rudnicki
50f6a587c2
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
49 lines
1.7 KiB
Python
49 lines
1.7 KiB
Python
# 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)
|