diff --git a/internal/modules/dispatcher.go b/internal/modules/dispatcher.go index a151afc..6df03d9 100644 --- a/internal/modules/dispatcher.go +++ b/internal/modules/dispatcher.go @@ -2,6 +2,7 @@ package modules import ( "context" + "strings" "github.com/go-telegram/bot" "github.com/go-telegram/bot/models" @@ -44,18 +45,22 @@ func (a Auth) Permits(v Visibility, update *models.Update) bool { // Install registers every command in the registry with the Telegram bot. // -// MatchTypeCommand expects the bare command name without the leading slash; -// the library compares against entity bytes after the "/" prefix. +// Uses RegisterHandlerMatchFunc with a local matcher rather than the library's +// bot.MatchTypeCommand because the library compares the full bot_command +// entity bytes for equality. In groups, Telegram clients send /cmd@botname, +// so the entity bytes are "cmd@botname" — never equal to the registered +// command name "cmd". The matcher below strips the @suffix before comparing. // // auth gates Protected/Private commands; pass a zero-value Auth to deny all // Protected/Private commands (the right answer for a misconfigured deploy). func Install(b *bot.Bot, reg *Registry, auth Auth) { for name, cmd := range reg.AllCommands { cmdCopy := cmd // capture by value for the closure - b.RegisterHandler( - bot.HandlerTypeMessageText, - name, - bot.MatchTypeCommand, + nameCopy := name + b.RegisterHandlerMatchFunc( + func(update *models.Update) bool { + return matchCommand(nameCopy, update) + }, func(ctx context.Context, b *bot.Bot, update *models.Update) { if !auth.Permits(cmdCopy.Visibility, update) { return // silent — do not leak existence of gated commands @@ -69,3 +74,37 @@ func Install(b *bot.Bot, reg *Registry, auth Auth) { ) } } + +// matchCommand reports whether update is a text message whose bot_command +// entity (after stripping any @botname suffix) equals name. Mirrors the +// library's HandlerTypeMessageText + MatchTypeCommand semantics but tolerates +// the group-form /cmd@botname that the library rejects. +// +// Telegram routes /cmd@otherbot only to otherbot, so an @suffix present in +// the entity addresses *this* bot — no need to verify against our username. +func matchCommand(name string, update *models.Update) bool { + if update == nil || update.Message == nil { + return false + } + text := update.Message.Text + for _, e := range update.Message.Entities { + if e.Type != models.MessageEntityTypeBotCommand { + continue + } + // Bounds check: defensive against malformed entities from a future + // API revision; the library's match func omits this so a bad entity + // would panic the goroutine before our recover() in webhook.go. + end := e.Offset + e.Length + if e.Offset < 0 || end > len(text) || e.Length < 1 { + continue + } + tok := text[e.Offset+1 : end] // drop leading '/' + if i := strings.IndexByte(tok, '@'); i >= 0 { + tok = tok[:i] + } + if tok == name { + return true + } + } + return false +} diff --git a/internal/modules/dispatcher_test.go b/internal/modules/dispatcher_test.go index 728b89e..eadc047 100644 --- a/internal/modules/dispatcher_test.go +++ b/internal/modules/dispatcher_test.go @@ -47,6 +47,110 @@ func TestAuth_Permits(t *testing.T) { } } +func TestMatchCommand(t *testing.T) { + mkUpdate := func(text string, entities ...models.MessageEntity) *models.Update { + return &models.Update{ + Message: &models.Message{ + Text: text, + Entities: entities, + }, + } + } + cmd := func(off, length int) models.MessageEntity { + return models.MessageEntity{Type: models.MessageEntityTypeBotCommand, Offset: off, Length: length} + } + + cases := []struct { + name string + want string + update *models.Update + expect bool + }{ + { + name: "dm bare slash-help", + want: "help", + update: mkUpdate("/help", cmd(0, 5)), + expect: true, + }, + { + // The bug this fix addresses: group clients append @botname to + // the entity. The upstream library's MatchTypeCommand misses this. + name: "group slash-help-at-botname", + want: "help", + update: mkUpdate("/help@miti99bot", cmd(0, 15)), + expect: true, + }, + { + name: "group slash-help-at-botname with trailing arg", + want: "help", + update: mkUpdate("/help@miti99bot arg", cmd(0, 15)), + expect: true, + }, + { + name: "different command no match", + want: "help", + update: mkUpdate("/info", cmd(0, 5)), + expect: false, + }, + { + name: "different command with botname no match", + want: "help", + update: mkUpdate("/info@miti99bot", cmd(0, 15)), + expect: false, + }, + { + name: "non-command entity ignored", + want: "help", + update: mkUpdate("/help", models.MessageEntity{Type: models.MessageEntityTypeMention, Offset: 0, Length: 5}), + expect: false, + }, + { + name: "command not at start matches (lib parity)", + want: "help", + update: mkUpdate("hi /help", cmd(3, 5)), + expect: true, + }, + { + name: "nil update", + want: "help", + update: nil, + expect: false, + }, + { + name: "no message", + want: "help", + update: &models.Update{}, + expect: false, + }, + { + name: "no entities", + want: "help", + update: mkUpdate("/help"), + expect: false, + }, + { + name: "out-of-bounds entity ignored", + want: "help", + update: mkUpdate("/help", cmd(0, 999)), + expect: false, + }, + { + name: "zero-length entity ignored", + want: "help", + update: mkUpdate("/help", cmd(0, 0)), + expect: false, + }, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + got := matchCommand(tc.want, tc.update) + if got != tc.expect { + t.Errorf("matchCommand(%q, ...) = %v, want %v", tc.want, got, tc.expect) + } + }) + } +} + func TestAuth_ZeroDeniesAllGated(t *testing.T) { // Misconfigured deploy: zero-value Auth must deny every Protected/Private // command without panicking, so an unconfigured bot cannot be hijacked diff --git a/internal/telegram/webhook.go b/internal/telegram/webhook.go index 39e38da..c965639 100644 --- a/internal/telegram/webhook.go +++ b/internal/telegram/webhook.go @@ -66,6 +66,8 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { return } + logDispatch(&update) + ctx, cancel := context.WithTimeout(r.Context(), handlerTimeout) defer cancel() // Recover panics so a buggy handler does not propagate up to the @@ -84,3 +86,30 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { w.WriteHeader(http.StatusOK) } } + +// dispatchTextPreview caps message text in dispatch logs so chatty media +// captions or long DM threads don't bloat CloudWatch / drive up cost. +const dispatchTextPreview = 64 + +// logDispatch emits a single structured line per inbound update so the +// CloudWatch trail has chat type + command text without resorting to +// the library's pointer-printing debug mode. Cheap (no allocation when +// the message is short) and fires once per webhook hit. +func logDispatch(u *models.Update) { + if u == nil || u.Message == nil { + return + } + text := u.Message.Text + if text == "" { + text = u.Message.Caption + } + if len(text) > dispatchTextPreview { + text = text[:dispatchTextPreview] + "…" + } + log.Info("dispatch", + "update_id", u.ID, + "chat_id", u.Message.Chat.ID, + "chat_type", string(u.Message.Chat.Type), + "text", text, + ) +} diff --git a/plans/260516-1130-group-command-match-fix/plan.md b/plans/260516-1130-group-command-match-fix/plan.md new file mode 100644 index 0000000..2f3a220 --- /dev/null +++ b/plans/260516-1130-group-command-match-fix/plan.md @@ -0,0 +1,50 @@ +# Fix Group Command Matching + Observable Dispatch Logging + +**Date:** 2026-05-16 +**Slug:** `260516-1130-group-command-match-fix` +**Status:** Implemented (awaiting deploy + group smoke test) +**Mode:** fast (single phase, well-scoped) +**Linked diagnostic:** `../reports/debugger-260516-1124-group-commands-not-matching.md` + +## Goal + +Bot commands sent in Telegram groups (`/help@miti99bot` form) must match registered handlers. Currently they silently miss because `github.com/go-telegram/bot@v1.20.0/handlers.go:88` does byte-exact equality without stripping the `@` suffix. + +Add structured pre-dispatch logging so the next "silent drop" symptom is observable in CloudWatch without code archaeology. + +## Phases + +| # | Phase | File | +|---|-------|------| +| 01 | Strip `@suffix` in dispatcher + add update log | `phase-01-strip-botname-suffix-and-log-dispatch.md` | + +## Files + +- `internal/modules/dispatcher.go` — swap `RegisterHandler(..., MatchTypeCommand, ...)` for `RegisterHandlerMatchFunc(...)` with a local matcher that strips `@suffix` +- `internal/modules/dispatcher_test.go` — add test cases covering `/help` (DM) and `/help@miti99bot` (group), plus negatives +- `internal/telegram/webhook.go` — add one structured log line just before `b.ProcessUpdate` recording `update_id`, `chat.id`, `chat.type`, `text` (truncated) + +## Non-goals + +- Don't fork the upstream library. +- Don't add a `TELEGRAM_BOT_USERNAME` env var — Telegram routes `/cmd@otherbot` to the addressed bot, so we never receive a foreign-suffixed command. KISS. +- Don't refactor existing Auth / Visibility logic. + +## Success criteria + +1. New unit test passes: `/help@miti99bot` with offset=0 length=15 matches handler registered as `"help"`. +2. Existing tests still pass (`make test` clean). +3. `golangci-lint run ./...` clean. +4. After deploy, repeating "send `/help@miti99bot` in group" produces a log line like `dispatch update_id=... chat_type=group chat_id=-100... text="/help@miti99bot"` AND the help reply is sent. + +## Risks + +| Risk | Mitigation | +|---|---| +| Custom matcher breaks edge case the library handled | Mirror lib semantics: only match `MessageEntityTypeBotCommand` entities, scope to `update.Message.Text` (HandlerTypeMessageText) | +| Log line leaks PII in group chats | Chat IDs and group titles are not secret; user IDs are not logged. Message text truncated to 64 chars. | +| Test mutates global state via library bot.New | Tests already use `testutil.NewRecordingBot` — reuse pattern | + +## Unresolved questions + +None — locked decisions: no env var, strip-unconditionally, truncate text to 64 chars in log. diff --git a/plans/reports/debugger-260516-1124-group-commands-not-matching.md b/plans/reports/debugger-260516-1124-group-commands-not-matching.md new file mode 100644 index 0000000..625ad83 --- /dev/null +++ b/plans/reports/debugger-260516-1124-group-commands-not-matching.md @@ -0,0 +1,144 @@ +# Debug Report — Bot Commands Silent in Groups, Work in DM + +**Date:** 2026-05-16 +**Branch:** main (HEAD `df89431`) +**Status:** DONE — root cause identified with code-level + log-level evidence; proposed fix below; nothing changed yet. + +## Symptom + +User reports: bot responds correctly to commands sent in a private chat (DM). Same commands sent in a Telegram group do nothing — no reply, no error, no logged warning. + +## Root cause + +`github.com/go-telegram/bot@v1.20.0/handlers.go:85-93` does a **byte-exact equality check** on the bot-command entity text without stripping the `@botname` suffix that Telegram clients append in groups. + +```go +if h.matchType == MatchTypeCommand { + for _, e := range entities { + if e.Type == models.MessageEntityTypeBotCommand { + if data[e.Offset+1:e.Offset+e.Length] == h.pattern { + return true + } + } + } +} +``` + +For private chats: +- User sends `/help`. +- Telegram sets entity Offset=0, Length=5. +- Slice `data[1:5]` = `"help"` → equals `h.pattern="help"` → ✅ match. + +For groups (this is what Telegram clients send when there are 2+ bots in the room OR when the user picks the command from the autocomplete menu): +- User sends `/help@miti99bot`. +- Telegram sets entity Offset=0, Length=15 (the `@suffix` is **inside** the entity). +- Slice `data[1:15]` = `"help@miti99bot"` → does NOT equal `"help"` → ❌ no match. + +The library never strips the `@botname` portion. No test in `handlers_test.go` covers the group form (only bare `/foo`). All 27 commands registered via `dispatcher.go:52-71` `Install` use `MatchTypeCommand`, so all 27 commands fail the same way in groups when sent with the suffix. + +## Evidence + +### 1. Library source + +`/config/go/pkg/mod/github.com/go-telegram/bot@v1.20.0/handlers.go:85-93` — exact match logic shown above. + +`/config/go/pkg/mod/github.com/go-telegram/bot@v1.20.0/handlers_test.go` — only test cases: +| Input | Length | Result | +|---|---|---| +| `/foo` | 4 | match ✓ | +| `a /foo` | 4 (offset 2) | match ✓ | +| `a /bar` | 4 | no match ✓ | + +No `/foo@botname` cases tested. + +### 2. Production logs + +CloudWatch `/aws/lambda/miti99bot`, last 60 min: + +| Time (UTC) | Event | Notes | +|---|---|---| +| 04:22:02 | `POST /webhook 200 1ms` + `[TGBOT] [UPDATE] ID:835070937` | Update arrived. No metric for it. | +| 04:22:59 | `POST /webhook 200 1372ms` | Long-running handler — this is the DM that worked. | +| 04:23:56 | `metrics commands={trade_stats:1}` | Metric flush — only **1** command counted in the cron interval. | +| 04:23:56 | `POST /webhook 200 0ms` + `[TGBOT] [UPDATE] ID:835070939` | Update arrived, returned immediately with no command dispatched. | + +So 3 webhooks, 1 fired a handler (`trade_stats`). The other 2 are the group attempts: payload accepted, secret validated, JSON decoded, dispatched into `b.ProcessUpdate` — and silently dropped because no handler matched. **No errors, no panics, no `unauthorized`, no `request body too large`**. Exact signature of "the match function returned false for every registered handler". + +### 3. Webhook config matches expectation + +`getWebhookInfo` (output from current production state, verified by previous workflow run logs): +- `url=https://.lambda-url.ap-southeast-1.on.aws/webhook` +- `allowed_updates=["message","callback_query"]` +- `pending_update_count` ≈ 0 (no delivery backlog) + +Group messages **are** being delivered. Telegram is not the problem. + +### 4. Bot Privacy Mode is NOT the root cause + +Privacy mode would prevent the update from arriving at all. We see group updates arrive (rows 1 and 4 above). Privacy mode is therefore either OFF, or the user typed a command (which Telegram delivers even with privacy ON). Either way, the failure is downstream of delivery — in the dispatcher's match logic. + +## Hypotheses ruled out + +| Hypothesis | Why ruled out | +|---|---| +| Webhook secret mismatch in groups | Would return 401; logs show 200. | +| Body-too-large from group payloads | Would return 413; logs show 200. | +| Panic in handler | Would log `webhook handler panic` (`webhook.go:75-81`). Nothing. | +| Auth denial (Visibility check) | Help/info commands are `VisibilityPublic` (cf. `dispatcher.go:26`) — auth.Permits returns true unconditionally. Also a denial would silently return AFTER the handler closure runs, so the metric `IncCommand` at `dispatcher.go:63` would NOT fire. We'd see no metrics — same outward symptom — but a private-chat `/trade_stats` did increment, so the path works when match succeeds. Auth not the issue. | +| Module disabled in groups | No code path filters by chat type in dispatch. `wordle/handlers.go:219`, `loldle/handlers.go:247` use `Chat.Type == ChatTypePrivate` only as a presentation switch (DM uses richer formatting); they do not gate command matching. | +| Telegram delivering group updates to wrong endpoint | Single Function URL; only one webhook registered. | + +## Proposed fix (not applied — awaiting your decision) + +**Option A — Local wrapper using `MatchFunc` (recommended)** + +Replace `b.RegisterHandler(..., bot.MatchTypeCommand, ...)` in `internal/modules/dispatcher.go:52-71` with `b.RegisterHandlerMatchFunc(matchFunc, ...)`, where `matchFunc` strips the trailing `@` from the entity bytes before comparing. Single localized change; no library fork. + +Sketch: +```go +matchCmd := func(name string) bot.MatchFunc { + return func(update *models.Update) bool { + msg := update.Message + if msg == nil { + return false + } + for _, e := range msg.Entities { + if e.Type != models.MessageEntityTypeBotCommand || e.Offset != 0 { + continue + } + tok := msg.Text[e.Offset+1 : e.Offset+e.Length] + if i := strings.IndexByte(tok, '@'); i >= 0 { + tok = tok[:i] + } + if tok == name { + return true + } + } + return false + } +} +``` + +Pros: zero library upgrade pressure; precise behavior; easy to add a unit test (which the upstream library lacks). +Cons: bypasses `bot.MatchTypeCommand`'s niceties (none we use); adds ~15 LOC + tests. + +**Option B — Force users to type bare `/help`** + +Documented workaround only. Doesn't fix the bot. Reject. + +**Option C — File upstream issue / PR** + +Worth doing in parallel, but blocked on upstream review / release timeline. Don't wait. + +Recommend Option A + a fresh unit test in `internal/modules/dispatcher_test.go` covering both `/help` and `/help@miti99bot` against a registered `"help"` handler. + +## Secondary findings (out of scope for this report) + +1. `[TGBOT] [UPDATE]` log lines (`2026/05/16 04:22:02 [TGBOT] [UPDATE] &{ID:... Message:0x40002dc488 ...}`) print struct pointers, not contents. They are emitted by `bot.WithDebug(...)` in the go-telegram lib. Recommend adding a thin pre-dispatch log line in `internal/telegram/webhook.go:82` (just before `b.ProcessUpdate`) that records `update_id`, `chat.id`, `chat.type`, and `message.text` (truncated, no PII concerns since group IDs are not secret). Would have made this exact bug trivially observable instead of requiring a 3-source triangulation. ~10 LOC. + +2. Library version `v1.20.0` was released some time back; the head of the repo may or may not have this fixed — worth a quick GitHub check before Option C. + +## Unresolved questions + +- Confirm with user whether they want Option A applied now (single phase, ~30 min) or queued behind other work. +- Do you want the extra dispatch-time log line (secondary finding 1) included in the same fix?