From a8ed67a0a34f34d4e4f72489eb012223964698c7 Mon Sep 17 00:00:00 2001 From: tiennm99 Date: Sat, 16 May 2026 13:35:00 +0700 Subject: [PATCH] refactor: audit-driven hygiene pass across modules and infra MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Concurrency - lolschedule: serialize subscriber Get→mutate→Put via state.subscribersMu; the single-slot list was previously losing writes under concurrent /lolschedule_subscribe. - trading: PriceClient memoises its default *http.Client so /trade_stats reuses TLS connections across held tickers. Observability - server/log_middleware: defer the req log line and recover panics so a panicking cron handler still emits the structured req entry CloudWatch filters on for 5xx alerting. - server/router (cron): inner recover with cron-name context captures the panicking job before the middleware's safety net does. - telegram/webhook: rune-safe truncation in dispatch logs — Vietnamese, Korean, and emoji previews no longer ship as garbled bytes. - lolschedule/api_client: same rune-safe fix for error-body log truncation. - telegram/webhook: gate the post-recover WriteHeader(200) so a panicking handler that already touched w doesn't trigger superfluous-WriteHeader. Correctness - twentyq: clearGame error during solved-relaunch is logged instead of silently swallowed (was a permanent deadlock vector on KV failure). - misc /mstats: KV read failure replies "Could not load stats. Try again later." to the user instead of returning into the dispatcher; matches the pattern other modules use. - migrate_cf_data trading-audit-dump: surface f.Close error so a truncated JSONL never passes silently as a complete audit dump. Operator ergonomics - migrate_cf_data (all 4 subcommands): signal.NotifyContext for SIGINT / SIGTERM. Ctrl-C mid-Scan now propagates cleanly instead of leaving a half-converted DynamoDB table. - ai/ratelimit: doc the Lambda-recycle memory bound to match keylock.Map so a future reviewer doesn't re-flag the unbounded map. I/O-changing (user-approved) - lolschedule daily push auto-prunes subscribers whose Telegram error matches a terminal marker (blocked / deactivated / chat gone). Transient errors keep the chat on the list. Subscribe message updated to mention the auto-cleanup. - twentyq seed pool grown 50 → 178; repeat-collision threshold moves from ~9 plays to ~17 (birthday paradox). - util /info flipped Public → Protected — chat/thread/sender IDs are no longer enumerable by every group member. - cmd/server WriteTimeout 6min → 75s (cron 60s + 15s slack). No-op on Lambda; matters only for local non-Lambda runs. - webhook + cron rejection paths drop response bodies (no fingerprintable text for internet scanners hitting the public Function URL). Status codes preserved for CloudWatch metrics; structured log lines carry the rejection reason for operator triage. Tests added: TestTruncateRunes, TestRunDailyPush_PrunesDeadSubscribers, TestIsTerminalSendError, TestInfo_DeniedToNonOwner, TestInfo_DeniedToChannelMessageNoFrom, plus owner-allowed counterparts. --- cmd/migrate_cf_data/convert_value.go | 11 ++- cmd/migrate_cf_data/main.go | 28 ++++++- cmd/server/main.go | 9 ++- internal/ai/ratelimit.go | 6 ++ internal/modules/lolschedule/api_client.go | 14 +++- internal/modules/lolschedule/cron.go | 70 +++++++++++++++++ internal/modules/lolschedule/cron_test.go | 87 +++++++++++++++++++-- internal/modules/lolschedule/handlers.go | 12 ++- internal/modules/lolschedule/subscribers.go | 8 ++ internal/modules/misc/misc.go | 6 +- internal/modules/trading/prices.go | 13 ++- internal/modules/twentyq/handlers.go | 8 +- internal/modules/twentyq/seeds.go | 55 +++++++++++-- internal/modules/util/handlers_test.go | 28 ++++--- internal/modules/util/info.go | 9 ++- internal/server/log_middleware.go | 39 +++++++-- internal/server/router.go | 45 ++++++++--- internal/telegram/webhook.go | 46 +++++++++-- internal/telegram/webhook_test.go | 18 +++++ 19 files changed, 451 insertions(+), 61 deletions(-) diff --git a/cmd/migrate_cf_data/convert_value.go b/cmd/migrate_cf_data/convert_value.go index ccba2dd..e6d824a 100644 --- a/cmd/migrate_cf_data/convert_value.go +++ b/cmd/migrate_cf_data/convert_value.go @@ -17,6 +17,14 @@ import ( "github.com/aws/aws-sdk-go-v2/service/dynamodb/types" ) +// signalContext is defined in main.go and gives every subcommand a SIGINT / +// SIGTERM-cancellable context — Ctrl-C mid-scan now propagates as a clean +// context error instead of leaving a half-converted table. +// +// (signature mirrors signal.NotifyContext for documentation purposes; no +// re-declaration here, just a pointer for future readers.) + + func runConvertValueToString(args []string) error { fs := flag.NewFlagSet("convert-value-to-string", flag.ExitOnError) table := fs.String("table", "", "target DynamoDB table (required)") @@ -28,7 +36,8 @@ func runConvertValueToString(args []string) error { return fmt.Errorf("--table is required") } - ctx := context.Background() + ctx, cancel := signalContext() + defer cancel() cfg, err := awsconfig.LoadDefaultConfig(ctx) if err != nil { return fmt.Errorf("aws config: %w", err) diff --git a/cmd/migrate_cf_data/main.go b/cmd/migrate_cf_data/main.go index e5c59e1..f4a8460 100644 --- a/cmd/migrate_cf_data/main.go +++ b/cmd/migrate_cf_data/main.go @@ -37,12 +37,21 @@ import ( "flag" "fmt" "os" + "os/signal" + "syscall" awsconfig "github.com/aws/aws-sdk-go-v2/config" "github.com/aws/aws-sdk-go-v2/service/dynamodb" "github.com/tiennm99/miti99bot/internal/migration" ) +// signalContext returns a context cancelled on Ctrl-C / SIGTERM. Used by every +// subcommand so a mid-scan abort leaves a clean error trail instead of a +// half-converted table the operator has to reason about. +func signalContext() (context.Context, context.CancelFunc) { + return signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) +} + func main() { if len(os.Args) < 2 { usage() @@ -86,7 +95,8 @@ func runInventory(args []string) error { if err != nil { return err } - ctx := context.Background() + ctx, cancel := signalContext() + defer cancel() keys, err := kv.ListKeys(ctx) if err != nil { return fmt.Errorf("list keys: %w", err) @@ -128,7 +138,8 @@ func runKVImport(args []string) error { if err != nil { return err } - ctx := context.Background() + ctx, cancel := signalContext() + defer cancel() var writer *migration.DynamoDBWriter if !*dryRun { cfg, err := awsconfig.LoadDefaultConfig(ctx) @@ -186,7 +197,9 @@ func runTradingAuditDump(args []string) error { if err != nil { return err } - rows, err := d1.Query(context.Background(), + ctx, cancel := signalContext() + defer cancel() + rows, err := d1.Query(ctx, "SELECT id, user_id, symbol, side, qty, price_vnd, ts FROM trading_trades ORDER BY id", nil) if err != nil { return fmt.Errorf("d1 query: %w", err) @@ -195,13 +208,20 @@ func runTradingAuditDump(args []string) error { if err != nil { return err } - defer func() { _ = f.Close() }() + // Surface Close's error: an audit JSONL that fails to flush is silently + // truncated otherwise. Encode succeeding doesn't guarantee fsync — if + // the final Close hits ENOSPC the operator must see it (this file is + // evidence; a partial dump is worse than no dump). enc := json.NewEncoder(f) for _, r := range rows { if err := enc.Encode(r); err != nil { + _ = f.Close() return err } } + if err := f.Close(); err != nil { + return fmt.Errorf("close audit dump: %w", err) + } fmt.Printf("Wrote %d rows to %s\n", len(rows), *out) return nil } diff --git a/cmd/server/main.go b/cmd/server/main.go index 410b3fc..135353d 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -136,9 +136,12 @@ func main() { Handler: handler, ReadHeaderTimeout: 10 * time.Second, ReadTimeout: 30 * time.Second, - // 6 min accommodates /cron/{name}; the webhook handler enforces a - // tighter per-update ctx timeout internally. - WriteTimeout: 6 * time.Minute, + // 75s = cron handler cap (60s, internal/server/timeouts.go) plus a + // 15s margin for response serialization. On Lambda the 30s function + // timeout supersedes this; the tighter ceiling matters only for + // local non-Lambda runs where a 6-minute slow-loris write was the + // previous (over-generous) bound. + WriteTimeout: 75 * time.Second, IdleTimeout: 120 * time.Second, } diff --git a/internal/ai/ratelimit.go b/internal/ai/ratelimit.go index 9a32c18..e957e14 100644 --- a/internal/ai/ratelimit.go +++ b/internal/ai/ratelimit.go @@ -16,6 +16,12 @@ import ( // Why we don't enforce daily caps here: x/time/rate is a token bucket, not // a fixed-window counter. Per-day caps need a different abstraction; if we // hit RPD limits in practice we'll add a DynamoDB-backed counter. +// +// Memory bound: the buckets map is never evicted. Each entry costs ~120 B. +// On Lambda the container recycles every ~hour, so the map size is bounded +// by "distinct subjects within one container lifetime" — small enough to +// not justify an LRU. Same rationale as keylock.Map; if either ever runs +// outside Lambda for long-lived processes, both will need eviction. type PerUserLimiter struct { mu sync.Mutex buckets map[string]*rate.Limiter diff --git a/internal/modules/lolschedule/api_client.go b/internal/modules/lolschedule/api_client.go index 7cf39f0..1ed15af 100644 --- a/internal/modules/lolschedule/api_client.go +++ b/internal/modules/lolschedule/api_client.go @@ -20,6 +20,7 @@ import ( "net/http" "net/url" "time" + "unicode/utf8" "github.com/tiennm99/miti99bot/internal/log" "github.com/tiennm99/miti99bot/internal/storage" @@ -259,13 +260,20 @@ func (c *Client) GetEventsCached(ctx context.Context, kv storage.KVStore, from, return nil, fetchErr } -// truncate clips a string to maxLen runes with "..." if cut. Keeps the log -// output bounded — lolesports occasionally returns multi-MB error pages. +// truncate clips a string to a rune-boundary prefix whose byte length is +// <= maxLen, appending "..." if cut. Keeps log output bounded — lolesports +// occasionally returns multi-MB error pages, and team/player names mix in +// Korean/Chinese characters that a raw byte slice would split mid-codepoint +// (producing replacement glyphs in CloudWatch). func truncate(s string, maxLen int) string { if len(s) <= maxLen { return s } - return s[:maxLen] + "..." + cut := maxLen + for cut > 0 && !utf8.RuneStart(s[cut]) { + cut-- + } + return s[:cut] + "..." } // ErrEmptyResult is reserved for explicit "no events" scenarios where the diff --git a/internal/modules/lolschedule/cron.go b/internal/modules/lolschedule/cron.go index a7ca0dd..a66461e 100644 --- a/internal/modules/lolschedule/cron.go +++ b/internal/modules/lolschedule/cron.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "strings" "time" "github.com/go-telegram/bot" @@ -13,6 +14,40 @@ import ( "github.com/tiennm99/miti99bot/internal/modules" ) +// terminalSendErrorMarkers are substrings of Telegram API errors that mean the +// chat will never accept messages again (blocked, deactivated, kicked, chat +// gone). Detecting these lets the daily-push handler prune the subscriber +// list so dead chats stop consuming the 30-msg/s global budget. +// +// String matching is fragile by nature, but the bot library surfaces these +// directly in err.Error() and Telegram has used the same wording for years. +// The false-negative path (we miss a new wording, dead chat lingers) is +// strictly safer than the false-positive path (we wrongly prune a live chat). +var terminalSendErrorMarkers = []string{ + "bot was blocked by the user", + "user is deactivated", + "bot is not a member", + "chat not found", + "group chat was upgraded", + "have no rights to send", + "chat was deleted", +} + +// isTerminalSendError reports whether err indicates the chat is permanently +// unreachable. Used by runDailyPush to drive auto-unsubscription. +func isTerminalSendError(err error) bool { + if err == nil { + return false + } + msg := err.Error() + for _, m := range terminalSendErrorMarkers { + if strings.Contains(msg, m) { + return true + } + } + return false +} + // dailyPushCronName is the cron route segment + EventBridge schedule key. // Must match the regex in internal/server/router.go (^[a-z0-9_]{1,32}$). const dailyPushCronName = "lolschedule_daily_push" @@ -80,6 +115,7 @@ func runDailyPush(ctx context.Context, s *state, sender messageSender) error { throttle := len(subs) > telegramRateLimitThreshold var sent, failed int + var deadChats []int64 for i, chatID := range subs { if throttle && i > 0 { select { @@ -95,14 +131,48 @@ func runDailyPush(ctx context.Context, s *state, sender messageSender) error { }); err != nil { log.Warn("lolschedule daily push send failed", "chat", chatID, "err", err) failed++ + if isTerminalSendError(err) { + deadChats = append(deadChats, chatID) + } continue } sent++ } + + // Best-effort prune. Failure here just leaves the dead chats in the list + // for tomorrow's push — same behaviour as before this code existed, so + // strictly an improvement even when the writes fail. + pruned := pruneDeadSubscribers(ctx, s, deadChats) + log.Info("lolschedule daily push complete", "subscribers", len(subs), "sent", sent, "failed", failed, + "pruned", pruned, "throttled", throttle) return nil } + +// pruneDeadSubscribers removes chatIDs flagged as permanently unreachable. +// Serializes through state.subscribersMu so a concurrent /subscribe handler +// doesn't lose its write. Returns the number actually removed (idempotent if +// a subscriber unsubscribed between the failed send and this call). +func pruneDeadSubscribers(ctx context.Context, s *state, deadChats []int64) int { + if len(deadChats) == 0 { + return 0 + } + s.subscribersMu.Lock() + defer s.subscribersMu.Unlock() + removed := 0 + for _, chatID := range deadChats { + ok, err := removeSubscriber(ctx, s.kv, chatID) + if err != nil { + log.Warn("lolschedule prune dead subscriber failed", "chat", chatID, "err", err) + continue + } + if ok { + removed++ + } + } + return removed +} diff --git a/internal/modules/lolschedule/cron_test.go b/internal/modules/lolschedule/cron_test.go index febf988..526f617 100644 --- a/internal/modules/lolschedule/cron_test.go +++ b/internal/modules/lolschedule/cron_test.go @@ -14,19 +14,28 @@ import ( "github.com/tiennm99/miti99bot/internal/storage" ) -// fakeSender records every SendMessage call. errOn returns an error for the -// configured chat IDs; all others succeed. +// fakeSender records every SendMessage call. errOn returns a transient +// failure for the configured chat IDs; terminalErrOn returns a +// permanent-failure message string the dead-subscriber pruner recognises. +// All others succeed. type fakeSender struct { - mu sync.Mutex - calls []bot.SendMessageParams - errOn map[int64]bool + mu sync.Mutex + calls []bot.SendMessageParams + errOn map[int64]bool + terminalErrOn map[int64]bool } func (f *fakeSender) SendMessage(_ context.Context, p *bot.SendMessageParams) (*models.Message, error) { f.mu.Lock() defer f.mu.Unlock() f.calls = append(f.calls, *p) - if id, ok := p.ChatID.(int64); ok && f.errOn[id] { + id, ok := p.ChatID.(int64) + if ok && f.terminalErrOn[id] { + // String shape that isTerminalSendError matches; verifies the marker + // list works against a realistic Telegram error message. + return nil, errors.New("Forbidden: bot was blocked by the user") + } + if ok && f.errOn[id] { return nil, errors.New("fakeSender: induced failure for chat " + chatIDString(id)) } return &models.Message{}, nil @@ -138,6 +147,72 @@ func TestRunDailyPush_PartialFailureContinues(t *testing.T) { } } +// TestRunDailyPush_PrunesDeadSubscribers locks in the auto-cleanup of chats +// that have permanently blocked the bot. Recoverable (transient) errors +// MUST NOT trigger removal — only terminal Telegram errors do. +func TestRunDailyPush_PrunesDeadSubscribers(t *testing.T) { + s := newTestState(t) + seedFreshCache(t, s.kv, nil) + + chatIDs := []int64{100, 200, 300, 400} + for _, id := range chatIDs { + if _, err := addSubscriber(context.Background(), s.kv, id); err != nil { + t.Fatalf("addSubscriber %d: %v", id, err) + } + } + + sender := &fakeSender{ + // 200 hit a transient failure → keep on list. 400 is permanently blocked + // → prune from list. + errOn: map[int64]bool{200: true}, + terminalErrOn: map[int64]bool{400: true}, + } + if err := runDailyPush(context.Background(), s, sender); err != nil { + t.Fatalf("runDailyPush: %v", err) + } + + remaining, err := listSubscribers(context.Background(), s.kv) + if err != nil { + t.Fatalf("listSubscribers: %v", err) + } + want := []int64{100, 200, 300} // 400 removed; 200 retained despite transient error + if len(remaining) != len(want) { + t.Fatalf("subscribers after prune: got %v, want %v", remaining, want) + } + for i, id := range want { + if remaining[i] != id { + t.Errorf("subscriber[%d]: got %d, want %d", i, remaining[i], id) + } + } +} + +func TestIsTerminalSendError(t *testing.T) { + terminals := []string{ + "Forbidden: bot was blocked by the user", + "Forbidden: user is deactivated", + "Bad Request: chat not found", + "Bad Request: group chat was upgraded to a supergroup chat", + } + for _, msg := range terminals { + if !isTerminalSendError(errors.New(msg)) { + t.Errorf("isTerminalSendError(%q) = false, want true", msg) + } + } + transients := []string{ + "connection reset by peer", + "Too Many Requests: retry after 30", + "context deadline exceeded", + } + for _, msg := range transients { + if isTerminalSendError(errors.New(msg)) { + t.Errorf("isTerminalSendError(%q) = true, want false (transient)", msg) + } + } + if isTerminalSendError(nil) { + t.Error("isTerminalSendError(nil) = true, want false") + } +} + func TestDailyPushHandler_NilBot_ReturnsError(t *testing.T) { s := newTestState(t) deps := modules.Deps{KV: s.kv} // Bot intentionally nil diff --git a/internal/modules/lolschedule/handlers.go b/internal/modules/lolschedule/handlers.go index d2e1349..9828710 100644 --- a/internal/modules/lolschedule/handlers.go +++ b/internal/modules/lolschedule/handlers.go @@ -2,6 +2,7 @@ package lolschedule import ( "context" + "sync" "time" "github.com/go-telegram/bot" @@ -19,6 +20,10 @@ type state struct { // nowFn allows tests to inject a deterministic clock. Production code // uses time.Now via the default zero-value. nowFn func() time.Time + // subscribersMu serializes Get→mutate→Put on the single subscribers KV + // slot. Two concurrent /lolschedule_subscribe calls in the same + // millisecond would otherwise race and drop one append. + subscribersMu sync.Mutex } func (s *state) now() time.Time { @@ -92,13 +97,16 @@ func (s *state) handleSubscribe(ctx context.Context, b *bot.Bot, update *models. if msg == nil { return nil } + s.subscribersMu.Lock() + defer s.subscribersMu.Unlock() added, err := addSubscriber(ctx, s.kv, msg.Chat.ID) if err != nil { return err } if added { return chathelper.Reply(ctx, b, msg, - "✅ Subscribed. You'll get today's LoL schedule at 08:00 ICT (push activates with the cron rollout).") + "✅ Subscribed. You'll get today's LoL schedule at 08:00 ICT.\n"+ + "If you block the bot, you'll be auto-unsubscribed on the next push.") } return chathelper.Reply(ctx, b, msg, "Already subscribed.") } @@ -109,6 +117,8 @@ func (s *state) handleUnsubscribe(ctx context.Context, b *bot.Bot, update *model if msg == nil { return nil } + s.subscribersMu.Lock() + defer s.subscribersMu.Unlock() removed, err := removeSubscriber(ctx, s.kv, msg.Chat.ID) if err != nil { return err diff --git a/internal/modules/lolschedule/subscribers.go b/internal/modules/lolschedule/subscribers.go index 9521a14..5406ddb 100644 --- a/internal/modules/lolschedule/subscribers.go +++ b/internal/modules/lolschedule/subscribers.go @@ -30,6 +30,11 @@ func listSubscribers(ctx context.Context, kv storage.KVStore) ([]int64, error) { // addSubscriber appends chatID if absent. Returns true on first-add, false // when already subscribed (idempotent). +// +// Concurrency: the list lives in a single KV slot, so a concurrent +// Get→mutate→Put from two chats subscribing in the same millisecond would +// drop one write. Callers MUST serialize through state.subscribersMu (or an +// equivalent module-scoped lock) before calling this. func addSubscriber(ctx context.Context, kv storage.KVStore, chatID int64) (bool, error) { ids, err := listSubscribers(ctx, kv) if err != nil { @@ -49,6 +54,9 @@ func addSubscriber(ctx context.Context, kv storage.KVStore, chatID int64) (bool, // removeSubscriber drops chatID from the list. Returns true when removed, // false when chatID wasn't present (idempotent). +// +// Concurrency: same single-slot Get→mutate→Put as addSubscriber; callers +// must hold state.subscribersMu. func removeSubscriber(ctx context.Context, kv storage.KVStore, chatID int64) (bool, error) { ids, err := listSubscribers(ctx, kv) if err != nil { diff --git a/internal/modules/misc/misc.go b/internal/modules/misc/misc.go index 095ae6a..1b48e66 100644 --- a/internal/modules/misc/misc.go +++ b/internal/modules/misc/misc.go @@ -76,7 +76,11 @@ func mstatsCommand(deps modules.Deps) modules.Command { text = fmt.Sprintf("last ping: %s", time.UnixMilli(last.At).UTC().Format(time.RFC3339)) case err != nil && !errors.Is(err, storage.ErrNotFound): - return fmt.Errorf("misc /mstats: %w", err) + // User-visible reply mirrors how trading/wordle/loldle handle + // transient KV failures — returning the error here would leave + // the user with no reply at all. + log.Error("kv get failed", "module", "misc", "command", "mstats", "key", lastPingKey, "err", err) + text = "Could not load stats. Try again later." } return chathelper.Reply(ctx, b, update.Message, text) }, diff --git a/internal/modules/trading/prices.go b/internal/modules/trading/prices.go index 70de4d9..00e2e67 100644 --- a/internal/modules/trading/prices.go +++ b/internal/modules/trading/prices.go @@ -7,6 +7,7 @@ import ( "fmt" "net/http" "net/url" + "sync" "time" ) @@ -26,13 +27,23 @@ const kbsHTTPTimeout = 10 * time.Second type PriceClient struct { HTTP *http.Client URL string + + // defaultClient memoises the zero-value HTTP fallback so the transport's + // connection pool survives across FetchPrice calls — /trade_stats fans + // out per held ticker, and a fresh client per call means a fresh TLS + // handshake per ticker. + defaultOnce sync.Once + defaultClient *http.Client } func (c *PriceClient) httpClient() *http.Client { if c.HTTP != nil { return c.HTTP } - return &http.Client{Timeout: kbsHTTPTimeout} + c.defaultOnce.Do(func() { + c.defaultClient = &http.Client{Timeout: kbsHTTPTimeout} + }) + return c.defaultClient } func (c *PriceClient) baseURL() string { diff --git a/internal/modules/twentyq/handlers.go b/internal/modules/twentyq/handlers.go index 7596e26..d1ebbcb 100644 --- a/internal/modules/twentyq/handlers.go +++ b/internal/modules/twentyq/handlers.go @@ -93,7 +93,13 @@ func (s *state) handleTwentyq(ctx context.Context, b *bot.Bot, update *models.Up } // Solved-but-lingering rounds → start fresh transparently (JS-parity). if game != nil && game.Solved { - _ = clearGame(ctx, s.kv, subject) + // Best-effort delete: a hard failure here means the solved-state + // branch re-enters every call and the user is stuck. Log but keep + // going — the fresh-round write below will overwrite the slot + // regardless. + if err := clearGame(ctx, s.kv, subject); err != nil { + log.Warn("twentyq clearGame on solved-relaunch failed", "subject", subject, "err", err) + } game = nil } diff --git a/internal/modules/twentyq/seeds.go b/internal/modules/twentyq/seeds.go index 3f942f6..bf93b22 100644 --- a/internal/modules/twentyq/seeds.go +++ b/internal/modules/twentyq/seeds.go @@ -1,18 +1,57 @@ package twentyq -// seeds is the JS-parity seed list. Add nouns here — the LLM derives category -// + initial hint per round so no metadata table is needed. +// seeds is the seed pool. The LLM derives category + initial hint per round +// so no metadata table is needed. Keep entries: +// - single concrete nouns (no abstractions, no proper nouns, no plurals) +// - distinguishable to a player with general knowledge +// - ASCII-only so prompt-engineered locale traps don't bias the model +// +// Pool size matters because random selection is uniform without exclusion — +// at N=50 a power user sees a repeat within ~9 plays (birthday paradox); at +// N=200 the same threshold moves to ~17. This list is deliberately wide +// across categories to reduce thematic clustering when the model picks hints. var seeds = []string{ // instruments "guitar", "piano", "drum", "violin", "flute", "trumpet", "organ", "harmonica", - // animals - "elephant", "dolphin", "eagle", "kangaroo", "octopus", "penguin", "tiger", "horse", "snake", "owl", + "saxophone", "cello", "accordion", "banjo", "xylophone", "clarinet", "tambourine", + "harp", "ukulele", "bagpipes", + // animals — land + "elephant", "kangaroo", "tiger", "horse", "snake", "owl", "wolf", "rabbit", + "giraffe", "hedgehog", "rhinoceros", "panda", "cheetah", "gorilla", "raccoon", + "squirrel", "platypus", "bat", "armadillo", "sloth", + // animals — sea + air + "dolphin", "eagle", "octopus", "penguin", "shark", "whale", "starfish", "crab", + "jellyfish", "lobster", "parrot", "hummingbird", "flamingo", "ostrich", "seahorse", // food - "pizza", "sushi", "burger", "ramen", "taco", "pho", "curry", "salad", "chocolate", "cheese", + "pizza", "sushi", "burger", "ramen", "taco", "pho", "curry", "salad", + "chocolate", "cheese", "pancake", "waffle", "donut", "croissant", "dumpling", + "sandwich", "lasagna", "popcorn", "kimchi", "biryani", + // fruits + vegetables + "banana", "pineapple", "watermelon", "strawberry", "mango", "avocado", "coconut", + "pomegranate", "broccoli", "carrot", "cucumber", "pumpkin", "garlic", "onion", // vehicles - "bicycle", "car", "airplane", "boat", "train", "motorcycle", "helicopter", "submarine", - // sports + "bicycle", "car", "airplane", "boat", "train", "motorcycle", "helicopter", + "submarine", "tractor", "skateboard", "scooter", "rocket", "ambulance", "bulldozer", + // sports + games "soccer", "basketball", "tennis", "swimming", "boxing", "golf", "chess", "skiing", + "badminton", "cricket", "rugby", "bowling", "surfing", "archery", "fencing", // household items - "refrigerator", "microwave", "vacuum", "toaster", "kettle", "blender", "lamp", "sofa", "mirror", "broom", + "refrigerator", "microwave", "vacuum", "toaster", "kettle", "blender", "lamp", + "sofa", "mirror", "broom", "umbrella", "scissors", "telephone", "clock", + "hammer", "screwdriver", "ladder", "candle", "flashlight", + // nature + places + "mountain", "volcano", "desert", "glacier", "waterfall", "island", "forest", + "beach", "cave", "river", + // space + "telescope", "asteroid", "comet", "satellite", "galaxy", + // occupations + "firefighter", "astronaut", "chef", "carpenter", "librarian", "dentist", + "photographer", "scientist", "lifeguard", "magician", + // tools + tech + "camera", "compass", "binoculars", "keyboard", "headphones", + "microscope", "printer", "stapler", + // clothing + "sweater", "sneakers", "scarf", "helmet", "gloves", "raincoat", + // drinks + "coffee", "tea", "lemonade", "smoothie", } diff --git a/internal/modules/util/handlers_test.go b/internal/modules/util/handlers_test.go index 2735d71..ff11877 100644 --- a/internal/modules/util/handlers_test.go +++ b/internal/modules/util/handlers_test.go @@ -28,8 +28,9 @@ func installUtil(t *testing.T, ownerID int64) *testutil.RecordingBot { return rb } -func TestInfo_PrivateChat(t *testing.T) { - rb := installUtil(t, 0) +func TestInfo_PrivateChat_OwnerAllowed(t *testing.T) { + // /info is Protected — sender must be the bot owner to get a reply. + rb := installUtil(t, 42) rb.Bot.ProcessUpdate(context.Background(), testutil.NewPrivateMessage(42, "/info")) got := rb.LastSent().Text() @@ -40,8 +41,8 @@ func TestInfo_PrivateChat(t *testing.T) { } } -func TestInfo_GroupChat(t *testing.T) { - rb := installUtil(t, 0) +func TestInfo_GroupChat_OwnerAllowed(t *testing.T) { + rb := installUtil(t, 7) rb.Bot.ProcessUpdate(context.Background(), testutil.NewGroupMessage(-100, 7, "/info")) got := rb.LastSent().Text() @@ -52,13 +53,22 @@ func TestInfo_GroupChat(t *testing.T) { } } -func TestInfo_ChannelMessageNoFrom(t *testing.T) { +func TestInfo_DeniedToNonOwner(t *testing.T) { + // Non-admin sender → Protected denies silently (no reply, no leak of + // the command's existence). + rb := installUtil(t, 999) + rb.Bot.ProcessUpdate(context.Background(), testutil.NewGroupMessage(-100, 7, "/info")) + if calls := rb.Sent(); len(calls) != 0 { + t.Errorf("non-owner /info replied: %+v", calls) + } +} + +func TestInfo_DeniedToChannelMessageNoFrom(t *testing.T) { + // Channel posts have no From. Protected denies (no sender to check). rb := installUtil(t, 0) rb.Bot.ProcessUpdate(context.Background(), testutil.NewChannelMessage(-200, "/info")) - - got := rb.LastSent().Text() - if !strings.Contains(got, "sender id: n/a") { - t.Errorf("info channel reply missing 'sender id: n/a'; got %q", got) + if calls := rb.Sent(); len(calls) != 0 { + t.Errorf("channel-post /info replied: %+v", calls) } } diff --git a/internal/modules/util/info.go b/internal/modules/util/info.go index aa41382..6c5b3b5 100644 --- a/internal/modules/util/info.go +++ b/internal/modules/util/info.go @@ -15,8 +15,13 @@ import ( // IDs, with "n/a" fallbacks. Used to debug bot routing in groups + topics. func infoCommand() modules.Command { return modules.Command{ - Name: "info", - Visibility: modules.VisibilityPublic, + Name: "info", + // Protected (not Public) because the response exposes internal + // routing IDs — chat id, thread id, sender id. Useful for admins + // debugging group/topic routing; not something every group member + // should be able to enumerate. Non-admins see no response at all + // (Visibility denies are silent — see dispatcher.go:31). + Visibility: modules.VisibilityProtected, Description: "Show chat id, thread id, and sender id (debug helper)", Handler: func(ctx context.Context, b *bot.Bot, update *models.Update) error { msg := update.Message diff --git a/internal/server/log_middleware.go b/internal/server/log_middleware.go index 6d1a564..cc3216f 100644 --- a/internal/server/log_middleware.go +++ b/internal/server/log_middleware.go @@ -2,6 +2,7 @@ package server import ( "net/http" + "runtime/debug" "time" "github.com/tiennm99/miti99bot/internal/log" @@ -36,16 +37,42 @@ func (r *statusRecorder) effectiveStatus() int { // // CloudWatch Logs filters on `jsonPayload.msg=req AND jsonPayload.status>=500` // for 5xx-rate alerting. Mirrors the JS source's index.js shape. +// +// The req line is emitted from a deferred closure so a panic in a downstream +// handler still produces an observable log entry — without this, a cron +// panic would disappear silently (http.Server does its own recover but never +// runs middleware again on the way out). func LogRequests(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { start := time.Now() rec := &statusRecorder{ResponseWriter: w} + defer func() { + rec.status = recoverPanicStatus(recover(), rec.status) + log.Info("req", + "method", r.Method, + "path", r.URL.Path, + "status", rec.effectiveStatus(), + "ms", time.Since(start).Milliseconds(), + ) + }() next.ServeHTTP(rec, r) - log.Info("req", - "method", r.Method, - "path", r.URL.Path, - "status", rec.effectiveStatus(), - "ms", time.Since(start).Milliseconds(), - ) }) } + +// recoverPanicStatus folds a recovered panic into the status to log: returns +// 500 if a panic was recovered (and re-panics nothing — http.Server will +// terminate the connection cleanly while the deferred req log still runs), +// otherwise returns the original status untouched. +// +// Re-panicking would lose the deferred log line in some recover-order edge +// cases; absorbing the panic here matches the webhook handler's posture of +// "log the failure, keep the goroutine clean". +func recoverPanicStatus(rec any, currentStatus int) int { + if rec == nil { + return currentStatus + } + log.Error("middleware recovered panic", + "panic", rec, + "stack", string(debug.Stack())) + return http.StatusInternalServerError +} diff --git a/internal/server/router.go b/internal/server/router.go index 5a15455..1f31bf9 100644 --- a/internal/server/router.go +++ b/internal/server/router.go @@ -6,6 +6,7 @@ import ( "errors" "net/http" "regexp" + "runtime/debug" "strings" "github.com/go-telegram/bot" @@ -57,23 +58,31 @@ func cronHandler(reg *modules.Registry, secret string) http.HandlerFunc { secretBytes := []byte(secret) cronDisabled := secret == "" return func(w http.ResponseWriter, r *http.Request) { + // Rejection paths use bare status codes (no response body) so a + // scanner hitting /cron/ can't fingerprint the route from the + // response text. Status codes remain distinct for CloudWatch + // metric filters; structured log lines carry the reason for + // operator triage. if cronDisabled { - http.NotFound(w, r) + w.WriteHeader(http.StatusNotFound) return } if r.Method != http.MethodPost { - http.Error(w, "method not allowed", http.StatusMethodNotAllowed) + log.Warn("cron rejected", "reason", "method", "method", r.Method) + w.WriteHeader(http.StatusMethodNotAllowed) return } got := []byte(r.Header.Get(cronAuthHeader)) if subtle.ConstantTimeCompare(got, secretBytes) != 1 { - http.Error(w, "unauthorized", http.StatusUnauthorized) + log.Warn("cron rejected", "reason", "secret_mismatch") + w.WriteHeader(http.StatusUnauthorized) return } name := strings.TrimPrefix(r.URL.Path, "/cron/") if !cronNameRe.MatchString(name) { - http.NotFound(w, r) + log.Warn("cron rejected", "reason", "bad_name", "name", name) + w.WriteHeader(http.StatusNotFound) return } @@ -81,13 +90,31 @@ func cronHandler(reg *modules.Registry, secret string) http.HandlerFunc { ctx, cancel := context.WithTimeout(r.Context(), defaultCronTimeout) defer cancel() - if err := modules.DispatchScheduled(ctx, name, reg); err != nil { - if errors.Is(err, modules.ErrCronNotFound) { - http.NotFound(w, r) + // Recover panics with cron-name context BEFORE the LogRequests + // middleware's safety-net recover sees them — otherwise CloudWatch + // would just show "middleware recovered panic" with no clue which + // scheduled job blew up. EventBridge sees 500 either way. + var dispatchErr error + func() { + defer func() { + if rec := recover(); rec != nil { + log.Error("cron handler panic", + "route", "/cron", + "name", name, + "panic", rec, + "stack", string(debug.Stack())) + dispatchErr = errors.New("cron handler panicked") + } + }() + dispatchErr = modules.DispatchScheduled(ctx, name, reg) + }() + if dispatchErr != nil { + if errors.Is(dispatchErr, modules.ErrCronNotFound) { + w.WriteHeader(http.StatusNotFound) return } - log.Error("cron failed", "route", "/cron", "name", name, "err", err) - http.Error(w, "cron failed", http.StatusInternalServerError) + log.Error("cron failed", "route", "/cron", "name", name, "err", dispatchErr) + w.WriteHeader(http.StatusInternalServerError) return } w.WriteHeader(http.StatusOK) diff --git a/internal/telegram/webhook.go b/internal/telegram/webhook.go index c965639..536316b 100644 --- a/internal/telegram/webhook.go +++ b/internal/telegram/webhook.go @@ -8,6 +8,7 @@ import ( "net/http" "runtime/debug" "time" + "unicode/utf8" "github.com/go-telegram/bot" "github.com/go-telegram/bot/models" @@ -41,13 +42,20 @@ const handlerTimeout = 10 * time.Second func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { secretBytes := []byte(secret) return func(w http.ResponseWriter, r *http.Request) { + // Rejection paths use bare status codes (no response body) so internet + // scanners hitting the public Function URL can't fingerprint this as a + // Telegram webhook from the response text. CloudWatch metric filters + // still see the distinct status codes (401 / 405 / 413 / 400), and the + // structured log lines below carry the *reason* for operator triage. if r.Method != http.MethodPost { - http.Error(w, "method not allowed", http.StatusMethodNotAllowed) + log.Warn("webhook rejected", "reason", "method", "method", r.Method) + w.WriteHeader(http.StatusMethodNotAllowed) return } got := []byte(r.Header.Get(secretTokenHeader)) if subtle.ConstantTimeCompare(got, secretBytes) != 1 { - http.Error(w, "unauthorized", http.StatusUnauthorized) + log.Warn("webhook rejected", "reason", "secret_mismatch") + w.WriteHeader(http.StatusUnauthorized) return } @@ -59,10 +67,12 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { // distinguish "body too big" from generic malformed JSON. var maxBytesErr *http.MaxBytesError if errors.As(err, &maxBytesErr) { - http.Error(w, "request body too large", http.StatusRequestEntityTooLarge) + log.Warn("webhook rejected", "reason", "body_too_large") + w.WriteHeader(http.StatusRequestEntityTooLarge) return } - http.Error(w, "bad request", http.StatusBadRequest) + log.Warn("webhook rejected", "reason", "bad_json", "err", err) + w.WriteHeader(http.StatusBadRequest) return } @@ -73,9 +83,11 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { // Recover panics so a buggy handler does not propagate up to the // http.Server (which would close the response mid-write and trigger // Telegram's 24-hour retry loop on the same poisoned update). + panicked := false func() { defer func() { if rec := recover(); rec != nil { + panicked = true log.Error("webhook handler panic", "panic", rec, "stack", string(debug.Stack())) @@ -83,7 +95,14 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { }() b.ProcessUpdate(ctx, &update) }() - w.WriteHeader(http.StatusOK) + // Suppress the trailing 200 if a panic occurred: a poisoned handler + // may have already written headers/body, and a second WriteHeader + // here emits `superfluous response.WriteHeader` noise. The + // LogRequests middleware will mark this as 500 from its own recover + // path; we just stay quiet here. + if !panicked { + w.WriteHeader(http.StatusOK) + } } } @@ -91,6 +110,21 @@ func WebhookHandler(b *bot.Bot, secret string) http.HandlerFunc { // captions or long DM threads don't bloat CloudWatch / drive up cost. const dispatchTextPreview = 64 +// truncateRunes returns the longest prefix of s whose UTF-8 byte length is +// <= maxBytes AND that ends on a rune boundary. Byte-slicing alone would +// split a multi-byte rune (Vietnamese, emoji, CJK), producing invalid UTF-8 +// in the log line that downstream JSON encoders replace with U+FFFD. +func truncateRunes(s string, maxBytes int) string { + if len(s) <= maxBytes { + return s + } + cut := maxBytes + for cut > 0 && !utf8.RuneStart(s[cut]) { + cut-- + } + return s[:cut] +} + // 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 @@ -104,7 +138,7 @@ func logDispatch(u *models.Update) { text = u.Message.Caption } if len(text) > dispatchTextPreview { - text = text[:dispatchTextPreview] + "…" + text = truncateRunes(text, dispatchTextPreview) + "…" } log.Info("dispatch", "update_id", u.ID, diff --git a/internal/telegram/webhook_test.go b/internal/telegram/webhook_test.go index 72da1eb..864b643 100644 --- a/internal/telegram/webhook_test.go +++ b/internal/telegram/webhook_test.go @@ -112,6 +112,24 @@ func TestWebhookHandler_AcceptsValidUpdate(t *testing.T) { } } +func TestTruncateRunes_KeepsUTF8Valid(t *testing.T) { + // Single-byte (ASCII): output must equal a byte slice when boundary aligns. + if got := truncateRunes("hello world", 5); got != "hello" { + t.Errorf("ascii: got %q, want %q", got, "hello") + } + // Multi-byte (Vietnamese): max=5 bytes, "ầ" is 3 bytes ("\xe1\xba\xa7"). + // "h" (1) + "ầ" (3) = 4 bytes; next rune would push to 7. truncate at 5 + // would land mid-rune; the helper must walk back to byte 4 so the slice + // ends on a rune boundary and the result decodes cleanly. + if got := truncateRunes("hầuhầuhầu", 5); got != "hầu" { + t.Errorf("vietnamese: got %q (len %d), want %q (len %d)", got, len(got), "hầu", len("hầu")) + } + // Length-below-cap path: pass through unchanged. + if got := truncateRunes("abc", 10); got != "abc" { + t.Errorf("short: got %q, want %q", got, "abc") + } +} + // panicUpdate matches the panicHandler registered below by /panic command. const panicUpdate = `{"update_id":2,"message":{"message_id":1,"date":1,"chat":{"id":1,"type":"private"},"from":{"id":1,"is_bot":false,"first_name":"x"},"text":"/panic","entities":[{"type":"bot_command","offset":0,"length":6}]}}`