mirror of
https://github.com/kuhyx/signal-bot.git
synced 2026-11-10 19:37:03 +01:00
One row per command attempt, not two aggregates written only on success. command_uses holds last-use only and daily_uses counts successes; both are rate-limiter state and both are written by store.record_use, which the dispatcher calls only when a handler returns cleanly. A gate refusal and a crash returned before it, so a command that failed every time looked exactly like one nobody ran, and nothing knew which command a counted message was. command_events now takes every attempt with its outcome, its duration and the item it served; upstream_calls takes every outbound request made while serving one. The two writes stay separate on purpose -- recording a refusal as a use is what slid the cooldown window forward every time somebody was told to wait -- and test_dispatcher_outcomes asserts last_used does not move. Backfilled from journald joined against message_events, with daily_uses filling the residual so the two sources cannot double-count. Two things were wrong on the first attempt and both were found by measuring rather than by reasoning: the window has to be symmetric, because sent_at_ms comes from the sender's phone and the journal stamp from this host (194 of 299 lines landed *before* their own message, by up to 3.2 s); and matching has to be a global closest-pair assignment, because per-row greedy cannot separate two commands seconds apart. Together those took the dropped rows from 137 to zero, and recovered 418 invocations back to 29 August. Also: !analityka in the group, twelve Polish lines, naming at most three people and only ones whose display name has been seen; an Analytics tab with Nivo charts; and continuous latency measurement, which answers the open question in DOCS-latency.md -- a text send is 235 ms and an image send about 2.2 s, so the upload really is where the time goes. EPHEMERAL_TABLES was doing two unrelated jobs and is now two tuples: what a schema bump rebuilds, and what leaving a group clears. daily_uses left the first (it is a backfill source now) and stayed in the second, and _drop_reshaped took over the repair a bump used to do for it. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01T4QTp3h5Q3MvfrwGV8xqPf
172 lines
5.5 KiB
Python
172 lines
5.5 KiB
Python
# Copyright (c) 2026 Krzysztof Rudnicki. MIT licence.
|
|
"""The outcomes that had no data at all before command_events.
|
|
|
|
Split out of ``test_dispatcher_recording`` so both stay under the 250-line
|
|
cap. This half is the one that matters most: a refusal and a crash are rows
|
|
now, and the *use* -- the write that feeds the cooldown -- must still not
|
|
move for either of them.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import datetime as dt
|
|
from typing import TYPE_CHECKING
|
|
|
|
import pytest
|
|
|
|
from signal_bot.analytics import probe
|
|
from signal_bot.decorators import cooldown, daily_limit
|
|
from signal_bot.registry import CommandRegistry
|
|
from tests.conftest import WATCHED_GROUP, envelope
|
|
from tests.test_dispatcher_recording import SENDER, build, calls, history
|
|
|
|
if TYPE_CHECKING:
|
|
from signal_bot.config import Config
|
|
from signal_bot.context import CommandContext
|
|
from signal_bot.discovery import GroupDirectory
|
|
from signal_bot.store import Store
|
|
from signal_bot.transport_fake import FakeTransport
|
|
|
|
NOW = dt.datetime(2026, 8, 29, 12, 0, tzinfo=dt.UTC)
|
|
|
|
|
|
@pytest.fixture
|
|
def ok_registry() -> CommandRegistry:
|
|
"""One command that succeeds and reports what it did on the way."""
|
|
|
|
async def handler(_ctx: CommandContext) -> None:
|
|
probe.note_upstream("api.example.test", 200, 40)
|
|
probe.note_send(120)
|
|
probe.note_item("Q42")
|
|
|
|
reg = CommandRegistry()
|
|
reg.register("cat", ["!cat"], handler, "kot")
|
|
return reg
|
|
|
|
|
|
async def test_a_refusal_does_not_move_the_cooldown(
|
|
config: Config,
|
|
directory: GroupDirectory,
|
|
store: Store,
|
|
transport: FakeTransport,
|
|
) -> None:
|
|
"""The invariant. A refused attempt is history, never a use.
|
|
|
|
If these two writes are ever merged, this fails and the bug it names
|
|
comes back: every "wait N seconds" reply would push the wait N seconds
|
|
further away, and waiting would never end.
|
|
"""
|
|
|
|
async def handler(_ctx: CommandContext) -> None:
|
|
pass
|
|
|
|
reg = CommandRegistry()
|
|
reg.register(
|
|
"cat",
|
|
["!cat"],
|
|
cooldown(3600.0, "poczekaj {seconds} {unit}")(handler),
|
|
"kot",
|
|
)
|
|
dispatcher = build(config, directory, reg, store, transport)
|
|
|
|
await dispatcher.handle(envelope(text="!cat", timestamp=1000))
|
|
first_use = store.last_used(WATCHED_GROUP, SENDER, "cat")
|
|
await dispatcher.handle(envelope(text="!cat", timestamp=2000))
|
|
|
|
outcomes = [row["outcome"] for row in history(store)]
|
|
assert outcomes == ["ok", "refused_cooldown"]
|
|
# The whole point: the second attempt is a row, and it moved nothing.
|
|
assert store.last_used(WATCHED_GROUP, SENDER, "cat") == first_use
|
|
assert store.uses_today(WATCHED_GROUP, SENDER, "cat", "2026-08-29") == 1
|
|
|
|
|
|
async def test_a_daily_refusal_names_its_own_gate(
|
|
config: Config,
|
|
directory: GroupDirectory,
|
|
store: Store,
|
|
transport: FakeTransport,
|
|
) -> None:
|
|
"""Which gate bit is the difference between "popular" and "mis-tuned"."""
|
|
|
|
async def handler(_ctx: CommandContext) -> None:
|
|
pass
|
|
|
|
reg = CommandRegistry()
|
|
reg.register(
|
|
"cat",
|
|
["!cat"],
|
|
daily_limit(1, "dosc na dzis")(handler),
|
|
"kot",
|
|
)
|
|
dispatcher = build(config, directory, reg, store, transport)
|
|
|
|
await dispatcher.handle(envelope(text="!cat", timestamp=1000))
|
|
await dispatcher.handle(envelope(text="!cat", timestamp=2000))
|
|
|
|
assert [row["outcome"] for row in history(store)] == ["ok", "refused_daily"]
|
|
|
|
|
|
async def test_a_crash_is_recorded_and_the_bot_survives_it(
|
|
config: Config,
|
|
directory: GroupDirectory,
|
|
store: Store,
|
|
transport: FakeTransport,
|
|
) -> None:
|
|
"""A command that fails every time used to look like one nobody ran."""
|
|
|
|
async def handler(_ctx: CommandContext) -> None:
|
|
raise ValueError
|
|
|
|
reg = CommandRegistry()
|
|
reg.register("cat", ["!cat"], handler, "kot")
|
|
dispatcher = build(config, directory, reg, store, transport)
|
|
|
|
await dispatcher.handle(envelope(text="!cat"))
|
|
|
|
(row,) = history(store)
|
|
assert row["outcome"] == "error"
|
|
# The class name, never the message: an exception's str() carries
|
|
# whatever it was processing, and here that is somebody's message.
|
|
assert row["error_class"] == "ValueError"
|
|
assert store.last_used(WATCHED_GROUP, SENDER, "cat") is None
|
|
|
|
|
|
async def test_recording_can_fail_without_taking_the_bot_down(
|
|
config: Config,
|
|
directory: GroupDirectory,
|
|
ok_registry: CommandRegistry,
|
|
store: Store,
|
|
transport: FakeTransport,
|
|
monkeypatch: pytest.MonkeyPatch,
|
|
) -> None:
|
|
"""A raise here would end the receive loop and the bot would go deaf.
|
|
|
|
Analytics are worth a great deal less than answering at all, so the
|
|
storage failure is logged and the use is still recorded.
|
|
"""
|
|
|
|
def explode(_event: object) -> None:
|
|
raise RuntimeError
|
|
|
|
monkeypatch.setattr(store.commands, "record", explode)
|
|
dispatcher = build(config, directory, ok_registry, store, transport)
|
|
|
|
await dispatcher.handle(envelope(text="!cat"))
|
|
|
|
assert store.last_used(WATCHED_GROUP, SENDER, "cat") == NOW.timestamp()
|
|
|
|
|
|
async def test_a_replayed_frame_is_recorded_once(
|
|
config: Config,
|
|
directory: GroupDirectory,
|
|
ok_registry: CommandRegistry,
|
|
store: Store,
|
|
transport: FakeTransport,
|
|
) -> None:
|
|
"""signal-cli replays undelivered frames when the bot reconnects."""
|
|
dispatcher = build(config, directory, ok_registry, store, transport)
|
|
for _ in range(3):
|
|
await dispatcher.handle(envelope(text="!cat", timestamp=5000))
|
|
assert len(history(store)) == 1
|
|
assert len(calls(store)) == 1
|