X-Git-Url: https://git.giacomolli.uk/onechat/blobdiff_plain/de170709599e849c6b409d247b800dc68b0c7ab7..3cdbd017da9ae7a7045f4272f16d4b262fd01c79:/telegram_test.go?ds=sidebyside

diff --git a/telegram_test.go b/telegram_test.go
index cf46106..84f41c8 100644
--- a/telegram_test.go
+++ b/telegram_test.go
@@ -1,13 +1,15 @@
 package main
 
 import (
-	"log"
+	"context"
 	"net/http"
 	"os"
 	"path/filepath"
 	"slices"
+	"strconv"
 	"strings"
 	"testing"
+	"testing/synctest"
 	"time"
 
 	"github.com/stretchr/testify/require"
@@ -15,7 +17,7 @@ import (
 
 func TestOwnerTalksToTheAgentThroughTelegram(t *testing.T) {
 	server := newModelFake(t)
-	server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+	server.reply = func(w http.ResponseWriter, _ ModelFakeCall) {
 		modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("Hello from the agent.")}, 100, 0, 5))
 	}
 
@@ -75,7 +77,7 @@ func TestBotIgnoresEveryoneButTheOwner(t *testing.T) {
 	require.Empty(t, telegram.Sent())
 	require.NotContains(t, terminal.Output(), "secret")
 	require.NotContains(t, logs.String(), "secret")
-	require.Contains(t, logs.String(), "update ignored")
+	require.Contains(t, logs.String(), "<6>message ignored")
 }
 
 func TestBotAnswersThatOnlyTextIsSupported(t *testing.T) {
@@ -99,7 +101,7 @@ func TestStopFromTelegramInterruptsTheTurn(t *testing.T) {
 		close(release)
 	})
 
-	server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+	server.reply = func(_ http.ResponseWriter, _ ModelFakeCall) {
 		close(arrived)
 		<-release
 	}
@@ -127,11 +129,79 @@ func TestStopFromTelegramInterruptsTheTurn(t *testing.T) {
 	})
 
 	telegramWaitForSent(t, telegram, "Error: interrupted", "No turn runs.")
+
+	telegram.Add(TelegramUpdate{
+		UpdateID: 4,
+		Message:  telegramOwnerMessage(stopCommand + " BlueFox"),
+	})
+
+	telegramWaitForSent(t, telegram, "No turn runs.", "No subagent BlueFox runs.")
 }
 
-func TestBotStartsAtTheStoredOffset(t *testing.T) {
+func TestBotShowsOnlyTheStartAndTheEndOfASubagent(t *testing.T) {
+	telegram := newTelegramFake(t)
 	server := newModelFake(t)
 	server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+		last := subagentTestLastItem(call)
+		switch {
+		case subagentTestCall(call):
+			// The report comes after the reply of the turn of the spawn.
+			require.Eventually(t, func() bool {
+				return slices.Contains(telegram.Sent(), "Started.")
+			}, 10*time.Second, time.Millisecond)
+			modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("There are 3 files.")}, 100, 0, 5))
+		case last["type"] == "function_call_output":
+			modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("Started.")}, 100, 0, 5))
+		case strings.HasPrefix(subagentTestText(last), "["):
+			modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("It counted 3 files.")}, 100, 0, 5))
+		default:
+			modelWriteEvents(w, modelCompletedEvent([]any{modelFunctionCallItem("fc_1", "call_1", "spawn", `{"tasks":["Count the files."],"effort":null}`)}, 100, 0, 5))
+		}
+	}
+
+	bot, _ := telegramStartTestBot(t, telegram)
+	daemonStartTestWithBot(t, server, bot)
+	telegram.Add(TelegramUpdate{
+		UpdateID: 1,
+		Message:  telegramOwnerMessage("Count the files in a subagent."),
+	})
+
+	require.Eventually(t, func() bool {
+		return slices.Contains(telegram.Sent(), "It counted 3 files.")
+	}, 10*time.Second, time.Millisecond)
+
+	sent := telegram.Sent()
+	name := strings.TrimSuffix(strings.TrimPrefix(sent[0], "["), "] started")
+	require.True(t, subagentNameValid(name), sent[0])
+	require.Equal(t, []string{
+		"[" + name + "] started",
+		"Started.",
+		"[" + name + "] finished",
+		"It counted 3 files.",
+	}, sent)
+}
+
+func TestBotSkipsTheWorkOfWhatsAppAndTheSchedules(t *testing.T) {
+	bot := &TelegramBot{
+		ready: make(chan struct{}, 1),
+	}
+
+	bot.Notify(Event{
+		Kind:   "work",
+		Source: whatsappSource,
+		Text:   "[WhatsApp] Ana Souza",
+	})
+	bot.Notify(Event{
+		Kind:   "work",
+		Source: scheduleSource,
+		Text:   "[Schedule 1] Sunday 2026-11-08 20:05 -03:00, once",
+	})
+	require.Empty(t, bot.queue)
+}
+
+func TestBotStartsAtTheStoredOffset(t *testing.T) {
+	server := newModelFake(t)
+	server.reply = func(w http.ResponseWriter, _ ModelFakeCall) {
 		modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("ok")}, 100, 0, 5))
 	}
 
@@ -154,7 +224,7 @@ func TestBotStartsAtTheStoredOffset(t *testing.T) {
 	terminal.WaitFor(t, "[connected to OneChat]")
 	telegramWaitForSent(t, telegram, "ok")
 
-	require.Equal(t, float64(10), telegram.Calls()[0].params["offset"])
+	require.InDelta(t, float64(10), telegram.Calls()[0].params["offset"], 0)
 	require.NotContains(t, terminal.Output(), "handled before the restart")
 
 	require.Eventually(t, func() bool {
@@ -165,7 +235,7 @@ func TestBotStartsAtTheStoredOffset(t *testing.T) {
 
 func TestBotTriesAgainAfterFailures(t *testing.T) {
 	server := newModelFake(t)
-	server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+	server.reply = func(w http.ResponseWriter, _ ModelFakeCall) {
 		modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("ok")}, 100, 0, 5))
 	}
 
@@ -197,40 +267,52 @@ func TestBotTriesAgainAfterFailures(t *testing.T) {
 	})
 
 	telegramWaitForSent(t, telegram, "ok")
-	require.Contains(t, logs.String(), "answered 502")
-	require.Contains(t, logs.String(), "answered 429")
+	require.Contains(t, logs.String(), "<4>receive failed retry=1s: 502")
+	require.Contains(t, logs.String(), "<6>receive back after=")
+	require.Contains(t, logs.String(), "<4>send failed retry=1s: 429")
+
+	// The bot logs the end of the outage after the send returns, so the line
+	// can come after the fake server has the message.
+	require.Eventually(t, func() bool {
+		return strings.Contains(logs.String(), "<6>send back after=")
+	}, 10*time.Second, time.Millisecond)
+
 	require.NotContains(t, logs.String(), telegramTestToken)
 }
 
 func TestDeliverTriesAgainAfterATimeout(t *testing.T) {
-	telegram := newTelegramFake(t)
-	stalls := 1
-	telegram.stall = func(call TelegramFakeCall) bool {
-		if call.method != "sendMessage" || stalls == 0 {
-			return false
-		}
+	synctest.Test(t, func(t *testing.T) {
+		telegram := newTelegramLocalFake(t)
+		stalls := 1
+		telegram.stall = func(call TelegramFakeCall) bool {
+			if call.method != "sendMessage" || stalls == 0 {
+				return false
+			}
 
-		stalls--
+			stalls--
 
-		return true
-	}
+			return true
+		}
 
-	bot, logs := telegramStartTestBot(t, telegram)
-	bot.api.sendTimeout = 50 * time.Millisecond
-	bot.deliver(t.Context(), TelegramPart{
-		text: "hello",
-	})
+		bot, logs := telegramStartTestBot(t, telegram)
+		bot.api.http.Transport = telegram
+		bot.deliver(t.Context(), TelegramPart{
+			text: "hello",
+		})
 
-	require.Equal(t, []string{"hello"}, telegram.Sent())
-	require.Len(t, telegram.Calls(), 2)
-	require.Contains(t, logs.String(), "no valid answer")
-	require.NotContains(t, logs.String(), telegramTestToken)
+		require.Equal(t, []string{"hello"}, telegram.Sent())
+		require.Len(t, telegram.Calls(), 2)
+		require.Contains(t, logs.String(), "<4>send failed retry=1s: no answer in 30s\n")
+		require.Contains(t, logs.String(), "<6>send back after=1s\n")
+		require.Equal(t, 2, strings.Count(logs.String(), "\n"))
+		require.NotContains(t, logs.String(), telegramTestToken)
+	})
 }
 
 func TestRepliesGoAsRichMessages(t *testing.T) {
 	reply := "**Done.** The table:\n\n| Name | Size |\n|:-----|-----:|\n| `a.go` | 10 |\n\n- one\n- two\n\n```go\nx := 1\n```"
 	server := newModelFake(t)
-	server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+	server.reply = func(w http.ResponseWriter, _ ModelFakeCall) {
 		modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem(reply)}, 100, 0, 5))
 	}
 
@@ -251,6 +333,7 @@ func TestRepliesGoAsRichMessages(t *testing.T) {
 	telegramWaitForSent(t, telegram, telegramTextOnly)
 
 	var sends []TelegramFakeCall
+
 	for _, call := range telegram.Calls() {
 		if call.method == "sendMessage" || call.method == "sendRichMessage" {
 			sends = append(sends, call)
@@ -294,6 +377,7 @@ func TestRichMessageFailures(t *testing.T) {
 		always  bool
 		methods []string
 		sent    []string
+		lines   int
 		logText string
 	}{
 		{
@@ -302,7 +386,8 @@ func TestRichMessageFailures(t *testing.T) {
 			always:  true,
 			methods: []string{"sendRichMessage", "sendMessage"},
 			sent:    []string{"a secret word"},
-			logText: "rich message refused",
+			lines:   1,
+			logText: "<4>reply sent with simple formatting",
 		},
 		{
 			name:    "unknown method sends the reply once with entities",
@@ -310,28 +395,32 @@ func TestRichMessageFailures(t *testing.T) {
 			always:  true,
 			methods: []string{"sendRichMessage", "sendMessage"},
 			sent:    []string{"a secret word"},
-			logText: "rich message refused",
+			lines:   1,
+			logText: "<4>reply sent with simple formatting",
 		},
 		{
 			name:    "rate limit tries the rich message again",
 			status:  http.StatusTooManyRequests,
 			methods: []string{"sendRichMessage", "sendRichMessage"},
 			sent:    []string{"a **secret** word"},
-			logText: "answered 429",
+			lines:   2,
+			logText: "<4>send failed retry=1s: 429",
 		},
 		{
 			name:    "server error tries the rich message again",
 			status:  http.StatusInternalServerError,
 			methods: []string{"sendRichMessage", "sendRichMessage"},
 			sent:    []string{"a **secret** word"},
-			logText: "answered 500",
+			lines:   2,
+			logText: "<4>send failed retry=1s: 500",
 		},
 		{
 			name:    "other refusal drops the reply",
 			status:  http.StatusForbidden,
 			always:  true,
 			methods: []string{"sendRichMessage"},
-			logText: "message dropped",
+			lines:   1,
+			logText: "<3>reply lost: 403",
 		},
 	}
 
@@ -356,14 +445,20 @@ func TestRichMessageFailures(t *testing.T) {
 			})
 
 			var methods []string
+
 			for _, call := range telegram.Calls() {
 				methods = append(methods, call.method)
 			}
 
 			require.Equal(t, tc.methods, methods)
 			require.Equal(t, tc.sent, telegram.Sent())
-			require.Equal(t, 1, strings.Count(logs.String(), "\n"))
+			require.Equal(t, tc.lines, strings.Count(logs.String(), "\n"))
 			require.Contains(t, logs.String(), tc.logText)
+
+			if tc.lines == 2 {
+				require.Contains(t, logs.String(), "<6>send back after=")
+			}
+
 			require.NotContains(t, logs.String(), telegramTestToken)
 			require.NotContains(t, logs.String(), "secret word")
 
@@ -398,12 +493,12 @@ func TestReplyTagsGoAsText(t *testing.T) {
 	}{
 		{
 			name: "rich message escapes the tag outside code",
-			sent: []string{"a \\<details> tag and `<b>`"},
+			sent: []string{"a &lt;details> &amp; tag and `<b>`"},
 		},
 		{
 			name:   "entity fallback shows the tag as written",
 			status: http.StatusBadRequest,
-			sent:   []string{"a <details> tag and <b>"},
+			sent:   []string{"a <details> & tag and <b>"},
 		},
 	}
 
@@ -421,7 +516,7 @@ func TestReplyTagsGoAsText(t *testing.T) {
 			bot, _ := telegramStartTestBot(t, telegram)
 			bot.post(t.Context(), Event{
 				Kind: "reply",
-				Text: "a <details> tag and `<b>`",
+				Text: "a <details> & tag and `<b>`",
 			})
 
 			require.Equal(t, tc.sent, telegram.Sent())
@@ -451,6 +546,51 @@ func TestLongReplySplitCountsTheEscapedTags(t *testing.T) {
 	}
 }
 
+func TestRefusedRichPartGoesWithTheTextAsWritten(t *testing.T) {
+	paragraph := "A <b> & c.\n\n"
+	reply := strings.Repeat(paragraph, telegramRichBytes/len(paragraph))
+
+	telegram := newTelegramFake(t)
+	refused := false
+	telegram.fail = func(call TelegramFakeCall) (int, string) {
+		if call.method != "sendRichMessage" || refused {
+			return 0, ""
+		}
+
+		refused = true
+
+		return http.StatusBadRequest, "Bad Request"
+	}
+
+	bot, _ := telegramStartTestBot(t, telegram)
+	bot.post(t.Context(), Event{
+		Kind: "reply",
+		Text: reply,
+	})
+
+	var fallback, rich []string
+
+	for _, call := range telegram.Calls() {
+		switch {
+		case !call.ok:
+		case call.method == "sendMessage":
+			fallback = append(fallback, call.params["text"].(string))
+		case call.method == "sendRichMessage":
+			rich = append(rich, call.params["rich_message"].(map[string]any)["markdown"].(string))
+		}
+	}
+
+	require.Greater(t, len(fallback), 1)
+	require.Len(t, rich, 1)
+	require.True(t, strings.HasPrefix(reply, strings.Join(fallback, "")), "fallback text is not the reply as written")
+
+	for _, text := range fallback {
+		require.LessOrEqual(t, telegramUTF16Units(text), telegramMessageUnits)
+	}
+
+	require.Equal(t, reply, strings.Join(fallback, "")+telegramUnescapeTags(rich[0]), "reply is not sent once and whole")
+}
+
 func TestRefusedEntitiesGoAgainAsPlainText(t *testing.T) {
 	telegram := newTelegramFake(t)
 	telegram.fail = func(call TelegramFakeCall) (int, string) {
@@ -474,11 +614,27 @@ func TestRefusedEntitiesGoAgainAsPlainText(t *testing.T) {
 	require.Nil(t, calls[1].params["entities"])
 	require.Equal(t, []string{"a secret word"}, telegram.Sent())
 	require.Equal(t, 1, strings.Count(logs.String(), "\n"))
-	require.Contains(t, logs.String(), "entities refused")
+	require.Contains(t, logs.String(), "<4>reply sent as plain text")
 	require.NotContains(t, logs.String(), telegramTestToken)
 	require.NotContains(t, logs.String(), "secret word")
 }
 
+func TestBotLogsALostPlainReplyAsAnError(t *testing.T) {
+	telegram := newTelegramFake(t)
+	telegram.fail = func(call TelegramFakeCall) (int, string) {
+		if call.method == "sendMessage" {
+			return http.StatusForbidden, "Forbidden"
+		}
+
+		return 0, ""
+	}
+
+	bot, logs := telegramStartTestBot(t, telegram)
+	bot.deliver(t.Context(), TelegramPart{text: "secret reply"})
+	require.Equal(t, "<3>reply lost: 403 Forbidden\n", logs.String())
+	require.Empty(t, telegram.Sent())
+}
+
 func TestBotLogsNoTokenWhenTheNetworkFails(t *testing.T) {
 	telegram := newTelegramFake(t)
 	telegram.Close()
@@ -487,11 +643,63 @@ func TestBotLogsNoTokenWhenTheNetworkFails(t *testing.T) {
 	daemonStartTestWithBot(t, newModelFake(t), bot)
 
 	require.Eventually(t, func() bool {
-		return strings.Count(logs.String(), "no valid answer") >= 2
+		return strings.Contains(logs.String(), "<4>receive failed retry=1s: no answer: ")
 	}, 10*time.Second, time.Millisecond)
 	require.NotContains(t, logs.String(), telegramTestToken)
 }
 
+func TestBotLogsAnOutageOnlyAtItsStartAndEnd(t *testing.T) {
+	synctest.Test(t, func(t *testing.T) {
+		telegram := newTelegramLocalFake(t)
+		failures := 5
+		telegram.fail = func(call TelegramFakeCall) (int, string) {
+			if call.method != "getUpdates" || failures == 0 {
+				return 0, ""
+			}
+
+			failures--
+
+			return http.StatusBadGateway, "Bad Gateway"
+		}
+
+		bot, logs := telegramStartTestBot(t, telegram)
+		bot.api.http.Transport = telegram
+		whatsapp, _, _ := whatsappStartTest(t, t.TempDir(), newTestClock())
+		loop, _ := newTestIdleTurnLoop(t, whatsapp)
+
+		telegram.Add(TelegramUpdate{
+			UpdateID: 1,
+			Message:  telegramOwnerMessage("a secret word"),
+		})
+
+		ctx, cancel := context.WithCancel(t.Context())
+		defer cancel()
+
+		done := make(chan error, 1)
+		go func() {
+			done <- bot.poll(ctx, loop, whatsapp)
+		}()
+
+		time.Sleep(31 * time.Second)
+		synctest.Wait()
+		require.Equal(t, 1, loop.memory.Len())
+
+		message, err := loop.memory.Message(0)
+		require.NoError(t, err)
+		require.Equal(t, "a secret word", message.Text)
+
+		lines := strings.Split(strings.TrimSuffix(logs.String(), "\n"), "\n")
+		require.Equal(t, []string{
+			"<4>receive failed retry=1s: 502 Bad Gateway",
+			"<6>receive back after=31s",
+		}, lines)
+		require.NotContains(t, logs.String(), "secret word")
+		require.NotContains(t, logs.String(), strconv.FormatInt(telegramTestOwner, 10))
+		cancel()
+		require.NoError(t, <-done)
+	})
+}
+
 func TestSplitMessage(t *testing.T) {
 	testCases := []struct {
 		name  string
@@ -629,6 +837,12 @@ func TestSplitRich(t *testing.T) {
 			limit:    3,
 			parts:    []string{"ab", "\u00e9c", "d"},
 		},
+		{
+			name:     "long line is not cut inside an entity",
+			markdown: "abc&amp;def",
+			limit:    6,
+			parts:    []string{"abc", "&amp;d", "ef"},
+		},
 	}
 
 	for _, tc := range testCases {
@@ -712,15 +926,12 @@ func TestLoadBotConfig(t *testing.T) {
 }
 
 // telegramStartTestBot returns a bot of telegramTestOwner on server, with its
-// offset file in a temporary directory and short waits, and the buffer of its
-// log.
+// offset file in a temporary directory and the buffer of its log.
 func telegramStartTestBot(t *testing.T, server *TelegramFake) (*TelegramBot, *SyncBuffer) {
 	t.Helper()
 
 	logs := &SyncBuffer{}
-	bot := newTelegramBot(newTelegramAPI(server.URL, telegramTestToken), telegramTestOwner, filepath.Join(t.TempDir(), telegramOffsetFileName), log.New(logs, "", 0))
-	bot.minWait = time.Millisecond
-	bot.maxWait = 10 * time.Millisecond
+	bot := newTelegramBot(newTelegramAPI(server.URL, telegramTestToken), telegramTestOwner, filepath.Join(t.TempDir(), telegramOffsetFileName), daemonTestLogger(logs))
 
 	return bot, logs
 }