X-Git-Url: https://git.giacomolli.uk/onechat/blobdiff_plain/d008b46cbfc6348255e9b9a1fc009f0e4bd6aa2a..522d7fd117285e4e4ce3ea5ec9b5a1722521b681:/telegram.go?ds=inline

diff --git a/telegram.go b/telegram.go
index e77ea69..2a9345a 100644
--- a/telegram.go
+++ b/telegram.go
@@ -73,8 +73,10 @@ func loadTelegramConfig(dir string) (TelegramConfig, bool, error) {
 	}
 
 	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")
@@ -145,7 +147,9 @@ func (c TelegramConfig) validate() error {
 // 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.
+// 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
@@ -178,6 +182,7 @@ func (b *TelegramBot) Notify(event Event) {
 	}
 
 	b.mutex.Lock()
+
 	b.queue = append(b.queue, event)
 	b.mutex.Unlock()
 
@@ -195,7 +200,9 @@ func (b *TelegramBot) Run(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp)
 	defer cancel()
 
 	var sender sync.WaitGroup
+
 	sender.Add(1)
+
 	go func() {
 		defer sender.Done()
 
@@ -203,6 +210,7 @@ func (b *TelegramBot) Run(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp)
 	}()
 
 	err := b.poll(ctx, l, whatsapp)
+
 	cancel()
 	sender.Wait()
 
@@ -235,6 +243,7 @@ func (b *TelegramBot) send(ctx context.Context) {
 		switch event.Kind {
 		case "busy":
 			busy = true
+
 			b.typing(ctx)
 			ticker.Reset(telegramTypingInterval)
 		case "idle":
@@ -258,6 +267,12 @@ func (b *TelegramBot) poll(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp)
 		return err
 	}
 
+	outage := &TelegramOutage{
+		logger: b.logger,
+		loss:   "receive failed",
+		back:   "receive back",
+	}
+
 	wait := b.minWait
 	for ctx.Err() == nil {
 		updates, err := b.api.GetUpdates(ctx, offset)
@@ -267,11 +282,13 @@ func (b *TelegramBot) poll(ctx context.Context, l *TurnLoop, whatsapp *WhatsApp)
 
 		if err != nil {
 			_, asked := telegramRetryable(err)
-			wait = b.pause(ctx, err, wait, asked)
+			wait = b.pause(ctx, outage, err, wait, asked)
 
 			continue
 		}
 
+		outage.End()
+
 		wait = b.minWait
 		for _, update := range updates {
 			if ctx.Err() != nil {
@@ -335,11 +352,11 @@ func (b *TelegramBot) post(ctx context.Context, event Event) {
 	}
 }
 
-// pause logs err 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, err error, wait, asked time.Duration) time.Duration {
+// 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)
-	b.logger.Printf("%v (next try in %s)", err, delay)
+	outage.Fail(err, delay)
 
 	timer := time.NewTimer(delay)
 	defer timer.Stop()
@@ -362,7 +379,8 @@ func (b *TelegramBot) pause(ctx context.Context, err error, wait, asked time.Dur
 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("update ignored: not a message of the owner in the private chat")
+		b.logger.Print("message ignored: not from the owner")
+
 		return nil
 	}
 
@@ -406,28 +424,36 @@ func (b *TelegramBot) handle(ctx context.Context, l *TurnLoop, whatsapp *WhatsAp
 // 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("entities refused, the message goes again as plain text: %v", err)
+			b.logger.Printf("reply sent as plain text: %v", err)
+
 			part.entities = nil
 
 			continue
 		}
 
-		retry, asked := telegramRetryable(err)
 		if !retry {
-			b.logger.Printf("message dropped: %v", err)
+			b.logger.Printf("reply lost: %v", err)
+
 			return
 		}
 
-		wait = b.pause(ctx, err, wait, asked)
+		wait = b.pause(ctx, outage, err, wait, asked)
 	}
 }
 
@@ -439,15 +465,22 @@ func (b *TelegramBot) deliver(ctx context.Context, part TelegramPart) {
 // 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("rich message refused, the reply goes with entities: %v", err)
+			b.logger.Printf("reply sent with simple formatting: %v", err)
+
 			for _, part := range telegramReplyParts(telegramUnescapeTags(markdown)) {
 				b.deliver(ctx, part)
 			}
@@ -455,13 +488,22 @@ func (b *TelegramBot) deliverRich(ctx context.Context, markdown string) {
 			return
 		}
 
-		retry, asked := telegramRetryable(err)
 		if !retry {
-			b.logger.Printf("message dropped: %v", err)
+			b.logger.Printf("reply lost: %v", err)
+
 			return
 		}
 
-		wait = b.pause(ctx, err, wait, asked)
+		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:   "send failed",
+		back:   "send back",
 	}
 }
 
@@ -473,6 +515,38 @@ func (b *TelegramBot) notice(text string) {
 	})
 }
 
+// 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 (retry 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 {
@@ -498,6 +572,7 @@ func telegramLoadOffset(path string) (int64, error) {
 	}
 
 	var file TelegramOffsetFile
+
 	err = json.Unmarshal(data, &file)
 	if err != nil {
 		return 0, fmt.Errorf("%s: %w", path, err)
@@ -529,6 +604,7 @@ func telegramSaveOffset(path string, offset int64) error {
 // never cuts a character.
 func telegramSplitMessage(text string, limit int) []string {
 	var parts []string
+
 	for {
 		end := telegramPrefixEnd(text, limit)
 		if end == len(text) {
@@ -578,6 +654,7 @@ func telegramText(event Event) string {
 // 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 == "" {
@@ -633,7 +710,9 @@ func telegramPrefixEnd(text string, limit int) int {
 // 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 {
@@ -692,10 +771,13 @@ func telegramRichCut(markdown string, limit int) (int, string, string) {
 // 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)