Files
jellybit/internal/tgbot/bot.go
T
avandClaude Opus 4.8 f8fb4fabb3 Логирование: доменная граница ошибок + защита секретов в логах
Приём торрента через Telegram молча падал без записи в логах. Разобрали
цепочку и починили логирование/обработку ошибок по конвенции logging.md
(логирует граница домена один раз, транспорты — нет).

Доменная граница логирует исход:
- ingest.Ingest: сбой БД → ERROR, невалидный источник → DEBUG;
- команды воркера (Apply/Cancel/Retry/Refine/…) — единый чокпоинт logCmd
  (ERROR для инфраструктурного сбоя; DEBUG для conflict/not-ready/not-found),
  закрывает и Telegram-, и HTTP-путь; дублирующие ERROR-логи в tgbot сняты;
- внутренний логгер tgbotapi заведён в slog: сбои long-poll getUpdates
  больше не уходят в stdlib log мимо структурированных логов;
- тихое закрытие канала обновлений бота → ERROR.

Защита секретов (инвариант «секреты не в логи»):
- общий logging.SanitizeErr убирает URL из *url.Error;
- закрыты утечки токена бота (getMe на старте, getFile, Send/Request)
  и api_key TMDB (query-параметр, попадавший в *url.Error на ERROR);
- покрыто тестом internal/logging/sanitize_test.go.

Ревью двумя сабагентами (fable): инфраструктурные и доменные ошибки.
Отложено (не в scope этого коммита): обёртка ErrConflict в
Cancel/Defer/Retry и классификация 500→409/400, обновление docs/conventions.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-10 14:29:38 +03:00

473 lines
18 KiB
Go

package tgbot
import (
"context"
"errors"
"fmt"
"io"
"log/slog"
"net/http"
"strings"
"sync"
"time"
tgbotapi "github.com/go-telegram-bot-api/telegram-bot-api/v5"
"git.vakhrushev.me/av/jellybit/internal/ident"
"git.vakhrushev.me/av/jellybit/internal/ingest"
"git.vakhrushev.me/av/jellybit/internal/logging"
"git.vakhrushev.me/av/jellybit/internal/worker"
)
// teleAPI — нужная боту часть клиента Telegram (его реализует
// *tgbotapi.BotAPI; в тестах подменяется фейком).
type teleAPI interface {
Send(c tgbotapi.Chattable) (tgbotapi.Message, error)
Request(c tgbotapi.Chattable) (*tgbotapi.APIResponse, error)
GetUpdatesChan(config tgbotapi.UpdateConfig) tgbotapi.UpdatesChannel
StopReceivingUpdates()
// GetFileDirectURL — прямой URL файла Telegram по file_id (для скачивания
// присланного .torrent-документа).
GetFileDirectURL(fileID string) (string, error)
}
// Ingestor принимает загрузку (ingest.Service).
type Ingestor interface {
Ingest(ctx context.Context, req ingest.Request) (ingest.Result, error)
}
// Reviewer — операции ревью (worker.Worker).
type Reviewer interface {
ReviewData(ctx context.Context, id string) (*worker.ReviewData, error)
Apply(ctx context.Context, id string) error
Refine(ctx context.Context, id string, hint string) error
SetType(ctx context.Context, id string, mediaType string) error
Defer(ctx context.Context, id string) error
Cancel(ctx context.Context, id string) error
Retry(ctx context.Context, id string) error
Delete(ctx context.Context, id string) error
}
// Config — параметры бота.
type Config struct {
AllowedUserIDs []int64
WebBaseURL string // для deep-link «открыть в вебе» (опц.)
}
// Bot — Telegram-адаптер: приём загрузок и подтверждение раскладки.
type Bot struct {
api teleAPI
ingestor Ingestor
reviewer Reviewer
allowed map[int64]bool
webBase string
log *slog.Logger
mu sync.Mutex // защищает pending
pending map[int64]string // chatID → downloadID, ждущий подсказку
httpClient *http.Client // для скачивания .torrent-документов Telegram
}
// New собирает бота поверх клиента Telegram.
func New(client teleAPI, ing Ingestor, rev Reviewer, cfg Config, log *slog.Logger) *Bot {
allowed := make(map[int64]bool, len(cfg.AllowedUserIDs))
for _, id := range cfg.AllowedUserIDs {
allowed[id] = true
}
return &Bot{
api: client,
ingestor: ing,
reviewer: rev,
allowed: allowed,
webBase: strings.TrimRight(cfg.WebBaseURL, "/"),
log: log,
pending: map[int64]string{},
httpClient: &http.Client{Timeout: 30 * time.Second},
}
}
const pollTimeout = 30 // секунд long-poll
// Run крутит цикл обновлений до отмены ctx.
func (b *Bot) Run(ctx context.Context) {
b.log.Info("telegram bot started", "allowed_users", len(b.allowed))
cfg := tgbotapi.NewUpdate(0)
cfg.Timeout = pollTimeout
cfg.AllowedUpdates = []string{"message", "callback_query"}
updates := b.api.GetUpdatesChan(cfg)
defer b.api.StopReceivingUpdates()
for {
select {
case <-ctx.Done():
b.log.Info("telegram bot stopped")
return
case u, ok := <-updates:
if !ok {
// Канал закрыт не по нашей отмене (ctx ещё жив) — библиотека
// прекратила приём обновлений: иначе бот молча перестал бы
// реагировать без следа в логах.
if ctx.Err() == nil {
b.log.Error("telegram updates channel closed unexpectedly")
}
return
}
b.handleUpdate(ctx, u)
}
}
}
func (b *Bot) handleUpdate(ctx context.Context, u tgbotapi.Update) {
switch {
case u.Message != nil:
b.handleMessage(ctx, u.Message)
case u.CallbackQuery != nil:
b.handleCallback(ctx, u.CallbackQuery)
}
}
// --- Входящие сообщения ---
func (b *Bot) handleMessage(ctx context.Context, m *tgbotapi.Message) {
if m.From == nil || m.Chat == nil {
return
}
if !b.allowed[m.From.ID] {
b.log.Warn("telegram denied user", "user_id", m.From.ID, "username", m.From.UserName)
b.send(m.Chat.ID, "Доступ запрещён.", nil)
return
}
// Документ (.torrent) — до ветки pending/текста: у документа m.Text пуст,
// иначе pending-подсказка «съела» бы его как пустую строку. Контекст — из
// подписи (m.Caption).
if m.Document != nil {
b.handleDocument(ctx, m)
return
}
text := strings.TrimSpace(m.Text)
// Ждём подсказку для перераспознавания?
if id, ok := b.takePending(m.Chat.ID); ok && !strings.Contains(text, "magnet:") {
if err := b.reviewer.Refine(ctx, id, text); err != nil {
// Ошибку логирует доменная граница (worker.Refine); транспорт лишь
// показывает пользователю (logging.md: «транспорты не логируют»).
b.send(m.Chat.ID, opErr("Не удалось обработать подсказку", id), nil)
return
}
b.send(m.Chat.ID, "Подсказка принята, перераспознаю #"+id+"…", nil)
return
}
if text == "/start" || text == "/help" {
b.send(m.Chat.ID, helpText, nil)
return
}
source, context, ok := ParseMessage(text)
if !ok {
// Невалидный ввод — норма (пользователь получит отказ): DEBUG, чтобы
// при разборе «почему не приняло» отказ был виден в логах.
b.log.Debug("telegram source not recognized", "chat_id", m.Chat.ID)
b.send(m.Chat.ID, "Не вижу magnet-ссылки. Перешлите сообщение торрент-бота, пришлите magnet или .torrent-файл.", nil)
return
}
b.ingestAndReply(ctx, m.Chat.ID, ingest.Request{Source: source, Context: context})
}
// handleDocument принимает присланный .torrent-документ: проверяет тип/размер,
// скачивает байты через Bot API и подаёт в приём (подпись — контекстом).
func (b *Bot) handleDocument(ctx context.Context, m *tgbotapi.Message) {
doc := m.Document
if !isTorrentDoc(doc) {
b.log.Debug("telegram document rejected", "chat_id", m.Chat.ID, "reason", "not-torrent", "mime", doc.MimeType)
b.send(m.Chat.ID, "Это не .torrent-файл. Пришлите magnet-ссылку или .torrent.", nil)
return
}
if doc.FileSize > 0 && doc.FileSize > ingest.MaxTorrentSize {
b.log.Debug("telegram document rejected", "chat_id", m.Chat.ID, "reason", "too-large", "size", doc.FileSize)
b.send(m.Chat.ID, "Файл слишком большой для .torrent.", nil)
return
}
data, err := b.downloadFile(ctx, doc.FileID)
if err != nil {
b.log.Warn("telegram document download failed", "error", err)
b.send(m.Chat.ID, "Не удалось скачать файл из Telegram, попробуйте ещё раз.", nil)
return
}
b.ingestAndReply(ctx, m.Chat.ID, ingest.Request{
TorrentData: data,
TorrentName: doc.FileName, // фолбек для source_ref, если у раздачи нет имени
Context: m.Caption,
})
}
// isTorrentDoc — документ выглядит как .torrent (по mime или расширению).
func isTorrentDoc(doc *tgbotapi.Document) bool {
if doc == nil {
return false
}
if doc.MimeType == "application/x-bittorrent" {
return true
}
return strings.HasSuffix(strings.ToLower(doc.FileName), ".torrent")
}
// downloadFile скачивает файл Telegram по file_id (прямой URL + HTTP GET),
// ограничивая объём MaxTorrentSize.
//
// ВАЖНО: прямой URL файла Telegram содержит токен бота
// (…/file/bot<TOKEN>/<path>). Ошибки транспорта (*url.Error) встраивают этот
// URL в текст — их нельзя возвращать/логировать как есть. logging.SanitizeErr
// оставляет только первопричину без URL, чтобы токен не утёк в логи (см.
// logging.md). GetFileDirectURL тоже ходит в Bot API (…/bot<TOKEN>/getFile) —
// его ошибку санитизируем так же.
func (b *Bot) downloadFile(ctx context.Context, fileID string) ([]byte, error) {
fileURL, err := b.api.GetFileDirectURL(fileID)
if err != nil {
return nil, fmt.Errorf("file url: %w", logging.SanitizeErr(err))
}
req, err := http.NewRequestWithContext(ctx, http.MethodGet, fileURL, nil)
if err != nil {
return nil, fmt.Errorf("telegram file request: %w", logging.SanitizeErr(err))
}
resp, err := b.httpClient.Do(req)
if err != nil {
return nil, fmt.Errorf("telegram file GET: %w", logging.SanitizeErr(err))
}
defer func() { _ = resp.Body.Close() }()
if resp.StatusCode != http.StatusOK {
return nil, fmt.Errorf("telegram file GET: status %d", resp.StatusCode)
}
// LimitReader на 1 байт больше лимита — чтобы отличить «ровно лимит» от
// «больше лимита».
data, err := io.ReadAll(io.LimitReader(resp.Body, ingest.MaxTorrentSize+1))
if err != nil {
return nil, err
}
if len(data) > ingest.MaxTorrentSize {
return nil, fmt.Errorf("telegram file exceeds %d bytes", ingest.MaxTorrentSize)
}
return data, nil
}
// ingestAndReply принимает загрузку и отвечает пользователю единообразно для
// всех источников (текст/magnet и .torrent-документ).
func (b *Bot) ingestAndReply(ctx context.Context, chatID int64, req ingest.Request) {
res, err := b.ingestor.Ingest(ctx, req)
if err != nil {
// res.DownloadID непуст, если сбой после создания задачи (напр. qbit);
// при раннем разборе источника id ещё нет — даём дружелюбный текст без
// него (детали всё равно в логах на доменной границе).
b.send(chatID, opErr("Не удалось принять загрузку", res.DownloadID), nil)
return
}
msg := fmt.Sprintf("Принято #%s — добавляю в qBittorrent.", res.DownloadID)
if res.Deduplicated {
msg = fmt.Sprintf("Уже в работе #%s.", res.DownloadID)
}
b.send(chatID, msg+"\nПозову, когда нужно подтверждение.", nil)
}
const helpText = `jellybit-бот: пришлите magnet-ссылку, .torrent-файл или перешлите сообщение торрент-бота — поставлю на закачку.
Когда раздача скачается и потребуется подтверждение раскладки, позову кнопками.`
// --- Колбэки (кнопки) ---
func (b *Bot) handleCallback(ctx context.Context, cq *tgbotapi.CallbackQuery) {
if cq.From == nil || cq.Message == nil || cq.Message.Chat == nil {
return
}
if !b.allowed[cq.From.ID] {
b.answer(cq.ID, "Доступ запрещён")
return
}
action, id, val := parseCallback(cq.Data)
if id == "" {
// Пустой/невалидный id — в т.ч. старые числовые кнопки, оставшиеся в
// истории чата до перехода на ULID: отвечаем понятно, а не молчим.
b.answer(cq.ID, "Кнопка устарела — откройте задачу в вебе")
return
}
chatID := cq.Message.Chat.ID
msgID := cq.Message.MessageID
var note string
var err error
switch action {
case "apply":
err = b.reviewer.Apply(ctx, id)
note = "Применяю…"
case "defer":
err = b.reviewer.Defer(ctx, id)
note = "Отложено"
case "reject":
err = b.reviewer.Cancel(ctx, id)
note = "Отклонено"
case "retry":
err = b.reviewer.Retry(ctx, id)
note = "Повторяю…"
case "delete":
// Первый шаг: показываем подтверждение (необратимое действие — снос
// раздачи+файлов и хардлинков). Домен не трогаем, меняем клавиатуру.
b.answer(cq.ID, "")
b.editMarkup(chatID, msgID, b.deleteConfirmKeyboard(id))
return
case "delete_cancel":
// Отмена подтверждения — возвращаем обычную карточку.
b.answer(cq.ID, "Отменено")
b.refreshCard(ctx, chatID, msgID, id)
return
case "delete_confirm":
err = b.reviewer.Delete(ctx, id)
note = "Удаляю…"
case "type":
err = b.reviewer.SetType(ctx, id, val)
note = "Меняю тип…"
case "refine":
b.setPending(chatID, id)
b.answer(cq.ID, "Жду подсказку")
b.send(chatID, "Ответьте сообщением с подсказкой для #"+id+".", nil)
return
default:
b.answer(cq.ID, "")
return
}
if err != nil {
if errors.Is(err, worker.ErrNotReady) {
// Источник ещё качается — actionable причина, показываем конкретно.
b.answer(cq.ID, "Торрент ещё качается")
b.send(chatID, opErr("Торрент ещё качается — дождитесь докачки", id), nil)
return
}
// Ошибку логирует доменная граница (соответствующая команда worker);
// транспорт лишь переводит её в ответ пользователю (logging.md).
b.answer(cq.ID, "Ошибка")
b.send(chatID, opErr("Не удалось выполнить действие", id), nil)
return
}
b.answer(cq.ID, note)
b.refreshCard(ctx, chatID, msgID, id)
}
// refreshCard перечитывает задачу и обновляет карточку на месте.
func (b *Bot) refreshCard(ctx context.Context, chatID int64, msgID int, id string) {
rd, err := b.reviewer.ReviewData(ctx, id)
if err != nil {
b.log.Warn("telegram refresh card failed", "download_id", id, "error", err)
return
}
text, kb := b.renderCard(rd)
var edit tgbotapi.EditMessageTextConfig
if kb != nil {
edit = tgbotapi.NewEditMessageTextAndMarkup(chatID, msgID, text, *kb)
} else {
edit = tgbotapi.NewEditMessageText(chatID, msgID, text)
}
if _, err := b.api.Send(edit); err != nil {
b.log.Warn("telegram edit card failed", "download_id", id, "error", logging.SanitizeErr(err))
}
}
// --- Notifier (worker.Notifier) ---
// Notify шлёт карточку подтверждения/готовности всем доверенным пользователям.
func (b *Bot) Notify(ctx context.Context, downloadID string, event worker.NotifyEvent) {
rd, err := b.reviewer.ReviewData(ctx, downloadID)
if err != nil {
b.log.Warn("telegram notify review data", "download_id", downloadID, "error", err)
return
}
var text string
var kb *tgbotapi.InlineKeyboardMarkup
switch event {
case worker.EventDone:
text = b.renderDone(rd)
case worker.EventTargetMissing, worker.EventOrphaned:
text, kb = b.renderDesync(rd, event), b.webOnly(downloadID)
case worker.EventFailed:
text, kb = b.renderFailed(rd)
default:
text, kb = b.renderCard(rd)
}
for chatID := range b.allowed {
b.send(chatID, text, kb)
}
}
// --- Отправка/хелперы ---
func (b *Bot) send(chatID int64, text string, kb *tgbotapi.InlineKeyboardMarkup) {
msg := tgbotapi.NewMessage(chatID, text)
msg.DisableWebPagePreview = true
if kb != nil {
msg.ReplyMarkup = *kb
}
if _, err := b.api.Send(msg); err != nil {
b.log.Warn("telegram send failed", "chat_id", chatID, "error", logging.SanitizeErr(err))
}
}
func (b *Bot) answer(callbackID, text string) {
if _, err := b.api.Request(tgbotapi.NewCallback(callbackID, text)); err != nil {
b.log.Warn("telegram answer callback failed", "error", logging.SanitizeErr(err))
}
}
// editMarkup подменяет только клавиатуру сообщения на месте (текст не трогаем).
// Используется для шага подтверждения удаления.
func (b *Bot) editMarkup(chatID int64, msgID int, kb *tgbotapi.InlineKeyboardMarkup) {
if kb == nil {
return
}
if _, err := b.api.Send(tgbotapi.NewEditMessageReplyMarkup(chatID, msgID, *kb)); err != nil {
b.log.Warn("telegram edit markup failed", "chat_id", chatID, "error", logging.SanitizeErr(err))
}
}
func (b *Bot) setPending(chatID int64, id string) {
b.mu.Lock()
b.pending[chatID] = id
b.mu.Unlock()
}
func (b *Bot) takePending(chatID int64) (string, bool) {
b.mu.Lock()
defer b.mu.Unlock()
id, ok := b.pending[chatID]
if ok {
delete(b.pending, chatID)
}
return id, ok
}
// opErr — сообщение публичного канала Telegram по доменной ошибке: нейтральный
// текст + download_id для корреляции с логами (полная ошибка уже там, на
// доменной границе). Сырой err.Error() пользователю не показываем. Если id
// операции ещё нет (downloadID == "") — дружелюбный текст без ключа.
func opErr(msg string, downloadID string) string {
if downloadID != "" {
return fmt.Sprintf("%s (download_id=%s).", msg, downloadID)
}
return msg + "."
}
// parseCallback разбирает "action[:id[:value]]". id валидируется как ULID
// (входная граница); невалидный/устаревший (числовой) → пустая строка.
func parseCallback(data string) (action string, id string, value string) {
parts := strings.Split(data, ":")
action = parts[0]
if len(parts) > 1 {
id, _ = ident.Parse(parts[1])
}
if len(parts) > 2 {
value = parts[2]
}
return action, id, value
}