Format short daemon events with slog

[onechat] / telegram_test.go

diff --git a/telegram_test.go b/telegram_test.go
index 5e50ec15755f1b8f3367a44f6120697dcddf6d9b..f1a76b66609b9fd357895edc951e3819ecedfb50 100644 (file)
--- a/telegram_test.go
+++ b/telegram_test.go
@@ -6,6 +6,7 @@ import (
        "os"
        "path/filepath"
        "slices"
        "os"
        "path/filepath"
        "slices"

+       "strconv"

        "strings"
        "testing"
        "time"
        "strings"
        "testing"
        "time"


@@ -15,7 +16,7 @@ import (
 
 func TestOwnerTalksToTheAgentThroughTelegram(t *testing.T) {
        server := newModelFake(t)
 
 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))
        }
 
                modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("Hello from the agent.")}, 100, 0, 5))
        }
 


@@ -75,7 +76,7 @@ func TestBotIgnoresEveryoneButTheOwner(t *testing.T) {
        require.Empty(t, telegram.Sent())
        require.NotContains(t, terminal.Output(), "secret")
        require.NotContains(t, logs.String(), "secret")
        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(), "message ignored")

 }
 
 func TestBotAnswersThatOnlyTextIsSupported(t *testing.T) {
 }
 
 func TestBotAnswersThatOnlyTextIsSupported(t *testing.T) {


@@ -99,7 +100,7 @@ func TestStopFromTelegramInterruptsTheTurn(t *testing.T) {
                close(release)
        })
 
                close(release)
        })
 

-       server.reply = func(w http.ResponseWriter, call ModelFakeCall) {
+       server.reply = func(_ http.ResponseWriter, _ ModelFakeCall) {

                close(arrived)
                <-release
        }
                close(arrived)
                <-release
        }


@@ -179,9 +180,27 @@ func TestBotShowsOnlyTheStartAndTheEndOfASubagent(t *testing.T) {
        }, sent)
 }
 
        }, 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)
 func TestBotStartsAtTheStoredOffset(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))
        }
 
                modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("ok")}, 100, 0, 5))
        }
 


@@ -204,7 +223,7 @@ func TestBotStartsAtTheStoredOffset(t *testing.T) {
        terminal.WaitFor(t, "[connected to OneChat]")
        telegramWaitForSent(t, telegram, "ok")
 
        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 {
        require.NotContains(t, terminal.Output(), "handled before the restart")
 
        require.Eventually(t, func() bool {


@@ -215,7 +234,7 @@ func TestBotStartsAtTheStoredOffset(t *testing.T) {
 
 func TestBotTriesAgainAfterFailures(t *testing.T) {
        server := newModelFake(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))
        }
 
                modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("ok")}, 100, 0, 5))
        }
 


@@ -247,8 +266,8 @@ func TestBotTriesAgainAfterFailures(t *testing.T) {
        })
 
        telegramWaitForSent(t, telegram, "ok")
        })
 
        telegramWaitForSent(t, telegram, "ok")

-       require.Contains(t, logs.String(), "answered 502")
-       require.Contains(t, logs.String(), "answered 429")
+       require.Contains(t, logs.String(), "502")
+       require.Contains(t, logs.String(), "429")

        require.NotContains(t, logs.String(), telegramTestToken)
 }
 
        require.NotContains(t, logs.String(), telegramTestToken)
 }
 


@@ -273,14 +292,16 @@ func TestDeliverTriesAgainAfterATimeout(t *testing.T) {
 
        require.Equal(t, []string{"hello"}, telegram.Sent())
        require.Len(t, telegram.Calls(), 2)
 
        require.Equal(t, []string{"hello"}, telegram.Sent())
        require.Len(t, telegram.Calls(), 2)

-       require.Contains(t, logs.String(), "no valid answer")
+       require.Contains(t, logs.String(), "send failed: no answer in 50ms (retry in 1ms)\n")
+       require.Contains(t, logs.String(), "send back after ")
+       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)
        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))
        }
 
                modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem(reply)}, 100, 0, 5))
        }
 


@@ -301,6 +322,7 @@ func TestRepliesGoAsRichMessages(t *testing.T) {
        telegramWaitForSent(t, telegram, telegramTextOnly)
 
        var sends []TelegramFakeCall
        telegramWaitForSent(t, telegram, telegramTextOnly)
 
        var sends []TelegramFakeCall

+

        for _, call := range telegram.Calls() {
                if call.method == "sendMessage" || call.method == "sendRichMessage" {
                        sends = append(sends, call)
        for _, call := range telegram.Calls() {
                if call.method == "sendMessage" || call.method == "sendRichMessage" {
                        sends = append(sends, call)


@@ -344,6 +366,7 @@ func TestRichMessageFailures(t *testing.T) {
                always  bool
                methods []string
                sent    []string
                always  bool
                methods []string
                sent    []string

+               lines   int

                logText string
        }{
                {
                logText string
        }{
                {


@@ -352,7 +375,8 @@ func TestRichMessageFailures(t *testing.T) {
                        always:  true,
                        methods: []string{"sendRichMessage", "sendMessage"},
                        sent:    []string{"a secret word"},
                        always:  true,
                        methods: []string{"sendRichMessage", "sendMessage"},
                        sent:    []string{"a secret word"},

-                       logText: "rich message refused",
+                       lines:   1,
+                       logText: "reply sent with simple formatting",

                },
                {
                        name:    "unknown method sends the reply once with entities",
                },
                {
                        name:    "unknown method sends the reply once with entities",


@@ -360,28 +384,32 @@ func TestRichMessageFailures(t *testing.T) {
                        always:  true,
                        methods: []string{"sendRichMessage", "sendMessage"},
                        sent:    []string{"a secret word"},
                        always:  true,
                        methods: []string{"sendRichMessage", "sendMessage"},
                        sent:    []string{"a secret word"},

-                       logText: "rich message refused",
+                       lines:   1,
+                       logText: "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"},
                },
                {
                        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: "send failed: 429",

                },
                {
                        name:    "server error tries the rich message again",
                        status:  http.StatusInternalServerError,
                        methods: []string{"sendRichMessage", "sendRichMessage"},
                        sent:    []string{"a **secret** word"},
                },
                {
                        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: "send failed: 500",

                },
                {
                        name:    "other refusal drops the reply",
                        status:  http.StatusForbidden,
                        always:  true,
                        methods: []string{"sendRichMessage"},
                },
                {
                        name:    "other refusal drops the reply",
                        status:  http.StatusForbidden,
                        always:  true,
                        methods: []string{"sendRichMessage"},

-                       logText: "message dropped",
+                       lines:   1,
+                       logText: "reply lost: 403",

                },
        }
 
                },
        }
 


@@ -406,13 +434,14 @@ func TestRichMessageFailures(t *testing.T) {
                        })
 
                        var methods []string
                        })
 
                        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())
                        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)
                        require.NotContains(t, logs.String(), telegramTestToken)
                        require.NotContains(t, logs.String(), "secret word")
                        require.Contains(t, logs.String(), tc.logText)
                        require.NotContains(t, logs.String(), telegramTestToken)
                        require.NotContains(t, logs.String(), "secret word")


@@ -524,6 +553,7 @@ func TestRefusedRichPartGoesWithTheTextAsWritten(t *testing.T) {
        })
 
        var fallback, rich []string
        })
 
        var fallback, rich []string

+

        for _, call := range telegram.Calls() {
                switch {
                case !call.ok:
        for _, call := range telegram.Calls() {
                switch {
                case !call.ok:


@@ -542,7 +572,7 @@ func TestRefusedRichPartGoesWithTheTextAsWritten(t *testing.T) {
                require.LessOrEqual(t, telegramUTF16Units(text), telegramMessageUnits)
        }
 
                require.LessOrEqual(t, telegramUTF16Units(text), telegramMessageUnits)
        }
 

-       require.True(t, reply == strings.Join(fallback, "")+telegramUnescapeTags(rich[0]), "reply is not sent once and whole")
+       require.Equal(t, reply, strings.Join(fallback, "")+telegramUnescapeTags(rich[0]), "reply is not sent once and whole")

 }
 
 func TestRefusedEntitiesGoAgainAsPlainText(t *testing.T) {
 }
 
 func TestRefusedEntitiesGoAgainAsPlainText(t *testing.T) {


@@ -568,7 +598,7 @@ 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.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(), "reply sent as plain text")

        require.NotContains(t, logs.String(), telegramTestToken)
        require.NotContains(t, logs.String(), "secret word")
 }
        require.NotContains(t, logs.String(), telegramTestToken)
        require.NotContains(t, logs.String(), "secret word")
 }


@@ -581,11 +611,47 @@ func TestBotLogsNoTokenWhenTheNetworkFails(t *testing.T) {
        daemonStartTestWithBot(t, newModelFake(t), bot)
 
        require.Eventually(t, func() bool {
        daemonStartTestWithBot(t, newModelFake(t), bot)
 
        require.Eventually(t, func() bool {

-               return strings.Count(logs.String(), "no valid answer") >= 2
+               return strings.Contains(logs.String(), "receive failed: no answer: ")

        }, 10*time.Second, time.Millisecond)
        require.NotContains(t, logs.String(), telegramTestToken)
 }
 
        }, 10*time.Second, time.Millisecond)
        require.NotContains(t, logs.String(), telegramTestToken)
 }
 

+func TestBotLogsAnOutageOnlyAtItsStartAndEnd(t *testing.T) {
+       server := newModelFake(t)
+       server.reply = func(w http.ResponseWriter, _ ModelFakeCall) {
+               modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("ok")}, 100, 0, 5))
+       }
+
+       telegram := newTelegramFake(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)
+       daemonStartTestWithBot(t, server, bot)
+
+       telegram.Add(TelegramUpdate{
+               UpdateID: 1,
+               Message:  telegramOwnerMessage("a secret word"),
+       })
+
+       telegramWaitForSent(t, telegram, "ok")
+
+       lines := strings.Split(strings.TrimSuffix(logs.String(), "\n"), "\n")
+       require.Len(t, lines, 2)
+       require.Equal(t, "receive failed: 502 Bad Gateway (retry in 1ms)", lines[0])
+       require.Regexp(t, `^receive back after [0-9]+m?s$`, lines[1])
+       require.NotContains(t, logs.String(), "secret word")
+       require.NotContains(t, logs.String(), strconv.FormatInt(telegramTestOwner, 10))
+}
+

 func TestSplitMessage(t *testing.T) {
        testCases := []struct {
                name  string
 func TestSplitMessage(t *testing.T) {
        testCases := []struct {
                name  string