Log Telegram outages once in plain words

[onechat] / telegram.go

package main

import (
        "bytes"
        "context"
        "encoding/json"
        "errors"
        "fmt"
        "io"
        "log"
        "net/http"
        "os"
        "path/filepath"
        "strings"
        "sync"
        "time"
        "unicode/utf8"
)

const (
        // telegramAPIURL is the Telegram Bot API service.
        telegramAPIURL = "https://api.telegram.org"

        // telegramConfigFileName is the bot config in the data directory. The
        // daemon runs the bot only when the file exists.
        telegramConfigFileName = "telegram.json"

        // telegramOffsetFileName is the update offset of the bot in the agent
        // directory.
        telegramOffsetFileName = "telegram-offset.json"

        // telegramSource is the source of the user messages from Telegram.
        telegramSource = "telegram"

        // telegramMessageUnits is the most UTF-16 code units of one Telegram
        // message.
        telegramMessageUnits = 4096

        // telegramRichBytes is the most bytes of the Markdown of one rich
        // message. The Bot API allows 32768 characters of rendered text, and
        // the Markdown of a text has at least as many bytes as the text has
        // characters.
        telegramRichBytes = 32768

        // telegramTypingInterval is how often the bot shows the typing action
        // while a turn runs. Telegram shows the action for about five seconds.
        telegramTypingInterval = 4 * time.Second

        // telegramTextOnly is the answer to a message that is not text.
        telegramTextOnly = "Only text messages are supported."
)

// loadTelegramConfig reads telegram.json in dir. It returns false when the file
// does not exist. An error never holds the token.
func loadTelegramConfig(dir string) (TelegramConfig, bool, error) {
        path := filepath.Join(dir, telegramConfigFileName)
        info, err := os.Stat(path)
        if errors.Is(err, os.ErrNotExist) {
                return TelegramConfig{}, false, nil
        }

        if err != nil {
                return TelegramConfig{}, false, fmt.Errorf("read bot config: %w", err)
        }

        if info.Mode().Perm()&0o077 != 0 {
                return TelegramConfig{}, false, fmt.Errorf("%s holds the bot token, so its mode must be 0600", telegramConfigFileName)
        }

        data, err := os.ReadFile(path)
        if err != nil {
                return TelegramConfig{}, false, fmt.Errorf("read bot config: %w", err)
        }

        var config TelegramConfig
        decoder := json.NewDecoder(bytes.NewReader(data))
        decoder.DisallowUnknownFields()
        err = decoder.Decode(&config)
        if err == nil && !errors.Is(decoder.Decode(&struct{}{}), io.EOF) {
                err = errors.New("data after the JSON object")
        }

        if err != nil {
                return TelegramConfig{}, false, fmt.Errorf("%s is not valid JSON with the fields token and owner", telegramConfigFileName)
        }

        err = config.validate()
        if err != nil {
                return TelegramConfig{}, false, fmt.Errorf("%s: %w", telegramConfigFileName, err)
        }

        return config, true, nil
}

// newTelegramBot returns the bot of owner on api. The offset file is at
// offsetPath, and logger gets the failures. No log line holds the text of a
// message.
func newTelegramBot(api *TelegramAPI, owner int64, offsetPath string, logger *log.Logger) *TelegramBot {
        return &TelegramBot{
                api:        api,
                owner:      owner,
                offsetPath: offsetPath,
                logger:     logger,
                minWait:    time.Second,
                maxWait:    time.Minute,
                ready:      make(chan struct{}, 1),
        }
}

// TelegramConfig holds the settings of telegram.json: the bot token and the
// user ID of the owner. The token is a secret, so the file must have mode 0600.
type TelegramConfig struct {
        Token string `json:"token"`
        Owner int64  `json:"owner"`
}

// validate makes sure that the token has the form of a bot token and that the
// owner is a user ID. The token goes into a URL path, so it can only hold the
// characters of a bot token.
func (c TelegramConfig) validate() error {
        id, secret, found := strings.Cut(c.Token, ":")
        if !found || id == "" || secret == "" || strings.Trim(id, "0123456789") != "" || strings.Trim(secret, "0123456789abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ_-") != "" {
                return errors.New("token does not have the form of a bot token from BotFather")
        }

        if c.Owner <= 0 {
                return errors.New("owner must be the numeric Telegram user ID of the owner")
        }

        return nil
}

// TelegramBot connects the private chat of the owner with the agent. It polls
// the Bot API for new messages and sends each text message of the owner to the
// agent. It ignores every other update. Its sender sends the replies, the
// errors, the notices of the bot, and the user messages of the other clients to
// the chat, and shows the typing action while a turn runs. Only the replies
// have a format: their Markdown goes as rich messages, which Telegram renders
// itself, and as message entities only when Telegram refuses a rich message.
// The rest is plain text. Tool calls do not go to the chat.
//
// The offset file holds the ID of the next update. It moves past an update
// only after the message of the update is durable in the log, so a restart
// does not lose a message. A crash between the flush and the offset write
// makes Telegram send the update again, and the message repeats once.
//
// A failed Bot API call waits and tries again, from minWait up to maxWait, or
// as long as the Bot API asks. It never stops the agent. A TelegramOutage logs
// the first failure and the end of each run of failures, and the retries
// between them log nothing.
type TelegramBot struct {
        api        *TelegramAPI
        owner      int64
        offsetPath string
        logger     *log.Logger
        minWait    time.Duration
        maxWait    time.Duration

        mutex sync.Mutex
        queue []Event
        ready chan struct{}
}

// Notify queues event for the chat. It never blocks, so a slow network does not
// stop the agent. The WhatsApp batches and the runs of the schedules do not go
// to the chat: the reply of the agent tells the user what needs the user.
func (b *TelegramBot) Notify(event Event) {
        switch event.Kind {
        case "busy", "idle", "reply", "error", "notice", "subagent":
        case "work":
                if event.Source == whatsappSource || event.Source == scheduleSource {
                        return
                }
        case "user":
                if event.Source == telegramSource {
                        return
                }
        default:
                return
        }

        b.mutex.Lock()
        b.queue = append(b.queue, event)
        b.mutex.Unlock()

        select {
        case b.ready <- struct{}{}:
        default:
        }
}

// Run polls for the messages of the owner and sends the queued events to the
// chat until ctx ends. It returns an error only when a message or the offset
// cannot be written, because then the bot would lose or repeat messages.
func (b *TelegramBot) Run(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp) error {
        ctx, cancel := context.WithCancel(ctx)
        defer cancel()

        var sender sync.WaitGroup
        sender.Add(1)
        go func() {
                defer sender.Done()

                b.send(ctx)
        }()

        err := b.poll(ctx, l, whatsapp)
        cancel()
        sender.Wait()

        return err
}

// send sends each queued event to the chat in order until ctx ends. While a
// turn runs, it shows the typing action every telegramTypingInterval and after
// each message, because a message ends the action.
func (b *TelegramBot) send(ctx context.Context) {
        ticker := time.NewTicker(telegramTypingInterval)
        defer ticker.Stop()

        busy := false
        for ctx.Err() == nil {
                event, found := b.next()
                if !found {
                        select {
                        case <-b.ready:
                        case <-ticker.C:
                                if busy {
                                        b.typing(ctx)
                                }
                        case <-ctx.Done():
                        }

                        continue
                }

                switch event.Kind {
                case "busy":
                        busy = true
                        b.typing(ctx)
                        ticker.Reset(telegramTypingInterval)
                case "idle":
                        busy = false
                default:
                        b.post(ctx, event)

                        if busy {
                                b.typing(ctx)
                        }
                }
        }
}

// poll gets the updates from the stored offset on and handles each one, until
// ctx ends. Each update is handled to its end also when ctx ends during it, so
// a stop does not repeat its message.
func (b *TelegramBot) poll(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp) error {
        offset, err := telegramLoadOffset(b.offsetPath)
        if err != nil {
                return err
        }

        outage := &TelegramOutage{
                logger: b.logger,
                loss:   "cannot get messages from Telegram",
                back:   "messages from Telegram come again",
        }

        wait := b.minWait
        for ctx.Err() == nil {
                updates, err := b.api.GetUpdates(ctx, offset)
                if ctx.Err() != nil {
                        return nil
                }

                if err != nil {
                        _, asked := telegramRetryable(err)
                        wait = b.pause(ctx, outage, err, wait, asked)

                        continue
                }

                outage.End()
                wait = b.minWait
                for _, update := range updates {
                        if ctx.Err() != nil {
                                return nil
                        }

                        err = b.handle(context.WithoutCancel(ctx), l, whatsapp, update)
                        if err != nil {
                                return err
                        }

                        offset = update.UpdateID + 1
                        err = telegramSaveOffset(b.offsetPath, offset)
                        if err != nil {
                                return err
                        }
                }
        }

        return nil
}

// next removes the first queued event and returns it.
func (b *TelegramBot) next() (Event, bool) {
        b.mutex.Lock()
        defer b.mutex.Unlock()

        if len(b.queue) == 0 {
                return Event{}, false
        }

        event := b.queue[0]
        b.queue = b.queue[1:]

        return event, true
}

// typing shows the typing action once. A failure is not logged, because the
// next message or poll logs the state of the network.
func (b *TelegramBot) typing(ctx context.Context) {
        _ = b.api.SendTyping(ctx, b.owner)
}

// post sends event to the chat. A reply goes as rich messages of its Markdown,
// with each < and & outside code escaped by telegramEscapeTags and then split
// with telegramSplitRich, so that the length limit counts the escaped text.
// Every other event goes as plain text, split with telegramSplitMessage.
func (b *TelegramBot) post(ctx context.Context, event Event) {
        if event.Kind != "reply" {
                for _, text := range telegramSplitMessage(telegramText(event), telegramMessageUnits) {
                        b.deliver(ctx, TelegramPart{
                                text: text,
                        })
                }

                return
        }

        for _, markdown := range telegramSplitRich(telegramEscapeTags(event.Text), telegramRichBytes) {
                b.deliverRich(ctx, markdown)
        }
}

// pause gives err to outage and waits the longer of wait and asked, or until
// ctx ends. It returns the wait of the next failure: twice wait, up to maxWait.
func (b *TelegramBot) pause(ctx context.Context, outage *TelegramOutage, err error, wait, asked time.Duration) time.Duration {
        delay := max(wait, asked)
        outage.Fail(err, delay)

        timer := time.NewTimer(delay)
        defer timer.Stop()

        select {
        case <-timer.C:
        case <-ctx.Done():
        }

        return min(2*wait, b.maxWait)
}

// handle runs one update. A text message of the owner in the private chat goes
// to the agent, and handle returns when it is durable in the log. The line
// /stop interrupts the turn, the line /stop NAME stops the subagent NAME, and a
// line that starts with /whatsapp runs a WhatsApp command on whatsapp, whose
// answers go to the chat only. Any other message of the owner gets the answer
// that only text is supported. Every other update is ignored, and its content
// is not logged.
func (b *TelegramBot) handle(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp, update TelegramUpdate) error {
        message := update.Message
        if message == nil || message.Chat.Type != "private" || message.Chat.ID != b.owner || message.From == nil || message.From.ID != b.owner {
                b.logger.Print("a Telegram message is ignored, because it is not from the owner in the private chat")
                return nil
        }

        name, stop := stopSubagentName(message.Text)
        args, isWhatsApp := whatsappCommandArgs(message.Text)
        switch {
        case message.Text == "":
                b.notice(telegramTextOnly)
        case strings.TrimSpace(message.Text) == stopCommand:
                if !l.Interrupt() {
                        b.notice("No turn runs.")
                }
        case stop:
                found, err := l.StopSubagent(name)
                if err != nil {
                        return fmt.Errorf("stop subagent %s: %w", name, err)
                }

                if !found {
                        b.notice("No subagent " + name + " runs.")
                }
        case isWhatsApp:
                whatsapp.Command(args, b.notice)
        default:
                _, err := l.Submit(telegramSource, message.Text)
                if err != nil {
                        return err
                }

                err = l.Flush(ctx)
                if err != nil {
                        return fmt.Errorf("flush the message from Telegram: %w", err)
                }
        }

        return nil
}

// deliver sends part to the chat. When Telegram refuses a part with entities
// (HTTP 400), it sends the text of the part again once with no entities, so a
// reply is not lost to a bad entity. It tries again after each failure that a
// later try can fix, until ctx ends. It drops the part after any other failure.
func (b *TelegramBot) deliver(ctx context.Context, part TelegramPart) {
        outage := b.sendOutage()
        wait := b.minWait
        for {
                err := b.api.SendMessage(ctx, b.owner, part.text, part.entities)
                retry, asked := telegramRetryable(err)
                if !retry {
                        outage.End()
                }

                if err == nil || ctx.Err() != nil {
                        return
                }

                var answer *TelegramError
                if len(part.entities) > 0 && errors.As(err, &answer) && answer.Status == http.StatusBadRequest {
                        b.logger.Printf("a reply goes as plain text, because Telegram refused its formatting: %v", err)
                        part.entities = nil

                        continue
                }

                if !retry {
                        b.logger.Printf("a reply to Telegram is lost: %v", err)
                        return
                }

                wait = b.pause(ctx, outage, err, wait, asked)
        }
}

// deliverRich sends markdown, escaped with telegramEscapeTags, to the chat as a
// rich message. When the Bot API refuses it with HTTP 400 or 404, the message
// was not sent, so deliverRich sends the text of the part once with message
// entities, and the reply is not lost and does not repeat. Message entities
// read no HTML, so the fallback gets the Markdown of telegramUnescapeTags, as
// the model wrote it. It tries again after each failure that a later try can
// fix, until ctx ends. It drops the message after any other failure.
func (b *TelegramBot) deliverRich(ctx context.Context, markdown string) {
        outage := b.sendOutage()
        wait := b.minWait
        for {
                err := b.api.SendRichMessage(ctx, b.owner, markdown)
                retry, asked := telegramRetryable(err)
                if !retry {
                        outage.End()
                }

                if err == nil || ctx.Err() != nil {
                        return
                }

                if telegramRejected(err) {
                        b.logger.Printf("a reply goes with simpler formatting, because Telegram refused its full formatting: %v", err)
                        for _, part := range telegramReplyParts(telegramUnescapeTags(markdown)) {
                                b.deliver(ctx, part)
                        }

                        return
                }

                if !retry {
                        b.logger.Printf("a reply to Telegram is lost: %v", err)
                        return
                }

                wait = b.pause(ctx, outage, err, wait, asked)
        }
}

// sendOutage returns a new outage of the messages to the chat.
func (b *TelegramBot) sendOutage() *TelegramOutage {
        return &TelegramOutage{
                logger: b.logger,
                loss:   "cannot send replies to Telegram",
                back:   "replies go to Telegram again",
        }
}

// notice queues a short answer of the bot for the chat.
func (b *TelegramBot) notice(text string) {
        b.Notify(Event{
                Kind: "notice",
                Text: text,
        })
}

// TelegramOutage is one run of failures of a kind of Bot API call. The first
// failure logs loss, its cause, and the wait of the next try. The retries log
// nothing. The next answer of Telegram logs back and the length of the outage.
// loss and back say what the user loses and gets again.
type TelegramOutage struct {
        logger *log.Logger
        loss   string
        back   string
        start  time.Time
}

// Fail logs the start of an outage with err and delay, unless an outage runs.
func (o *TelegramOutage) Fail(err error, delay time.Duration) {
        if !o.start.IsZero() {
                return
        }

        o.start = time.Now()
        o.logger.Printf("%s: %v (next try in %s)", o.loss, err, durationText(delay))
}

// End logs the end of the outage that runs, with its length.
func (o *TelegramOutage) End() {
        if o.start.IsZero() {
                return
        }

        o.logger.Printf("%s, after %s", o.back, durationText(time.Since(o.start)))
        o.start = time.Time{}
}

// TelegramPart is the text of one message to the chat, at most
// telegramMessageUnits long, and its entities.
type TelegramPart struct {
        text     string
        entities []TelegramEntity
}

// TelegramOffsetFile is the content of the offset file.
type TelegramOffsetFile struct {
        Offset int64 `json:"offset"`
}

// telegramLoadOffset reads the update offset at path. A missing file gives 0,
// which asks for every update that Telegram keeps.
func telegramLoadOffset(path string) (int64, error) {
        data, err := os.ReadFile(path)
        if errors.Is(err, os.ErrNotExist) {
                return 0, nil
        }

        if err != nil {
                return 0, fmt.Errorf("read update offset: %w", err)
        }

        var file TelegramOffsetFile
        err = json.Unmarshal(data, &file)
        if err != nil {
                return 0, fmt.Errorf("%s: %w", path, err)
        }

        return file.Offset, nil
}

// telegramSaveOffset replaces the update offset at path.
func telegramSaveOffset(path string, offset int64) error {
        data, err := json.Marshal(TelegramOffsetFile{
                Offset: offset,
        })
        if err != nil {
                return fmt.Errorf("encode update offset: %w", err)
        }

        err = writeFileAtomic(path, append(data, '\n'))
        if err != nil {
                return fmt.Errorf("write update offset: %w", err)
        }

        return nil
}

// telegramSplitMessage cuts text into parts of at most limit UTF-16 code units,
// the unit of the Telegram message limit. It cuts after the last line break or
// space of a part when one is in its second half, and else at the limit. It
// never cuts a character.
func telegramSplitMessage(text string, limit int) []string {
        var parts []string
        for {
                end := telegramPrefixEnd(text, limit)
                if end == len(text) {
                        return append(parts, text)
                }

                cut := strings.LastIndexByte(text[:end], '\n') + 1
                if cut <= end/2 {
                        cut = strings.LastIndexByte(text[:end], ' ') + 1
                }

                if cut <= end/2 {
                        cut = end
                }

                parts = append(parts, text[:cut])
                text = text[cut:]
        }
}

// telegramText returns the text of event for the chat. A user message of
// another client has its source as a mark. A subagent shows only its start and
// how its run ended, because the reply of the agent carries the content of the
// report.
func telegramText(event Event) string {
        switch event.Kind {
        case "user":
                return "[" + event.Source + "] " + event.Text
        case "subagent":
                return "[" + event.Text + "] started"
        case "work":
                return "[" + event.Source + "] " + event.Status
        case "error":
                return "Error: " + event.Text
        default:
                return event.Text
        }
}

// telegramSplitRich cuts the Markdown of a reply into parts of at most limit
// bytes. It cuts after a blank line outside a code block, so a table, a code
// block, or a paragraph stays whole. When no such cut fits in a part, it cuts
// after the last line break outside a code block, then after the last line
// break in a code block, which it closes at the end of the part and opens again
// in the next part with the same fence line. A line longer than limit is cut at
// the limit, or before an & in the four bytes before the limit, so that it does
// not cut an entity of telegramEscapeTags. It never cuts a character.
func telegramSplitRich(markdown string, limit int) []string {
        var parts []string
        for len(markdown) > limit {
                cut, fence, opening := telegramRichCut(markdown, limit)
                if fence == "" {
                        parts = append(parts, markdown[:cut])
                        markdown = markdown[cut:]

                        continue
                }

                parts = append(parts, markdown[:cut]+fence+"\n")
                markdown = opening + "\n" + markdown[cut:]
        }

        return append(parts, markdown)
}

// telegramReplyParts returns the messages of the Markdown of a reply with
// message entities. A reply that has no text left after the conversion, such as
// an empty code block, goes as its Markdown.
func telegramReplyParts(markdown string) []TelegramPart {
        text, entities := telegramMarkdownEntities(markdown)
        if strings.TrimSpace(text) == "" {
                text, entities = markdown, nil
        }

        return telegramSplitEntities(text, entities, telegramMessageUnits)
}

// telegramPrefixEnd returns the byte length of the longest prefix of text with
// at most limit UTF-16 code units.
func telegramPrefixEnd(text string, limit int) int {
        units := 0
        for index, char := range text {
                size := 1
                if char > 0xFFFF {
                        size = 2
                }

                if units+size > limit {
                        return index
                }

                units += size
        }

        return len(text)
}

// telegramRichCut returns where telegramSplitRich cuts markdown, which is
// longer than limit. For a cut in a code block, it also returns the fence that
// closes the block and the line that opens it. Each part before a cut holds
// text other than space, and a cut in a code block leaves room for the fence,
// so each cut makes the rest shorter.
func telegramRichCut(markdown string, limit int) (int, string, string) {
        blank, line, code := 0, 0, 0
        var fence, opening, inFence, inOpening string
        for start := 0; start < limit; {
                end := strings.IndexByte(markdown[start:], '\n')
                if end < 0 || start+end+1 > limit {
                        break
                }

                end += start + 1
                text := strings.TrimRight(markdown[start:end], "\r\n")
                _, opens := telegramCodeFence(text)
                switch {
                case fence != "":
                        if telegramClosesFence(text, fence) {
                                fence = ""
                        } else if end > len(opening)+1 && end+len(fence)+1 <= limit {
                                code, inFence, inOpening = end, fence, opening
                        }
                case opens != "":
                        fence, opening = opens, text
                case strings.TrimSpace(markdown[:end]) == "":
                case strings.TrimSpace(text) == "":
                        blank = end
                }

                if fence == "" && strings.TrimSpace(markdown[:end]) != "" {
                        line = end
                }

                start = end
        }

        switch {
        case blank > 0:
                return blank, "", ""
        case line > 0:
                return line, "", ""
        case code > 0:
                return code, inFence, inOpening
        }

        cut := limit
        for !utf8.RuneStart(markdown[cut]) {
                cut--
        }

        start := max(cut-len("&amp;")+1, 0)
        entity := strings.LastIndexByte(markdown[start:cut], '&')
        if entity >= 0 && start+entity > 0 {
                cut = start + entity
        }

        return cut, "", ""
}

// telegramSplitEntities cuts text into parts with telegramSplitMessage, and
// gives each part the entities in it, with offsets from the start of the part.
// An entity that crosses a cut becomes one entity in each part.
func telegramSplitEntities(text string, entities []TelegramEntity, limit int) []TelegramPart {
        var parts []TelegramPart
        start := 0
        for _, part := range telegramSplitMessage(text, limit) {
                end := start + telegramUTF16Units(part)
                var kept []TelegramEntity
                for _, entity := range entities {
                        from := max(entity.Offset, start)
                        to := min(entity.Offset+entity.Length, end)
                        if to <= from {
                                continue
                        }

                        entity.Offset = from - start
                        entity.Length = to - from
                        kept = append(kept, entity)
                }

                parts = append(parts, TelegramPart{
                        text:     part,
                        entities: kept,
                })

                start = end
        }

        return parts
}