mesh-tools/node-tools/internal/console/empty_round_test.go

package console

import (
	"encoding/json"
	"fmt"
	"strings"
	"sync"
	"testing"
	"time"

	"github.com/novox/mesh-tools/node-tools/internal/announce"
	mt "github.com/novox/mesh-tools/node-tools/internal/meshtest"
)

// novox/hq issue 554, reproduced: the laptop's console heard every runtime, then a round in which
// nothing answered discovery in time — and every seat and module call was refused ("it answered
// discovery 2s ago, not now") for the five seconds that round was kept, again and again. Now a call
// is resolved against what the runtime announced last, says how old that is, and reaches the tool; the
// empty round is logged once, is not kept, and the next question asks again.
func TestACallAfterARoundThatHeardNothingUsesWhatWasHeardBefore(t *testing.T) {
	keptWas, patienceWas := IndexKept, announce.Patience
	IndexKept, announce.Patience = 0, 1200*time.Millisecond
	t.Cleanup(func() { IndexKept, announce.Patience = keptWas, patienceWas })
	mt.New(t)

	// The tools answer on their own connection; discovery is answered on another, which goes quiet.
	tools := connect(t, "node-tools", "laptop")
	stopTool, err := tools.HandleSubject("mesh.mod.slack.tool.slack_check.laptop", func(json.RawMessage) (any, error) {
		return map[string]any{"ok": true}, nil
	})
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(stopTool)
	stopSeat, err := tools.HandleSubject("mesh.seat.issue-tracker.tool.list", func(json.RawMessage) (any, error) {
		return map[string]any{"issues": []int{554}}, nil
	})
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(stopSeat)
	tools.Flush()
	endpoints := []announce.Endpoint{
		{Kind: announce.KindTool, Module: "slack", Tool: "slack_check", Node: "laptop", Subject: "mesh.mod.slack.tool.slack_check.laptop"},
		{Kind: announce.KindSeat, Module: "issue-tracker", Seat: "issue-tracker", Tool: "list", Scope: "mesh", Node: "laptop",
			Schema: json.RawMessage(`{}`), Subject: "mesh.seat.issue-tracker.tool.list"},
	}
	announcing := connect(t, "node-tools", "laptop")
	stopAnnounce, err := announce.Serve(announcing, announce.Service{Name: "node-tools", ID: "laptop",
		Metadata: map[string]string{"node": "laptop"}}, func() []announce.Endpoint { return endpoints })
	if err != nil {
		t.Fatal(err)
	}
	announcing.Flush()

	console := connect(t, "node-tools", "laptop-console")
	var mu sync.Mutex
	var logged []string
	console.Logf = func(f string, a ...any) {
		mu.Lock()
		defer mu.Unlock()
		logged = append(logged, fmt.Sprintf(f, a...))
	}
	said := func(words string) int {
		mu.Lock()
		defer mu.Unlock()
		n := 0
		for _, l := range logged {
			if strings.Contains(l, words) {
				n++
			}
		}
		return n
	}
	surface := NewSurface(console, "laptop.node-tools")
	up, err := Serve(surface, "127.0.0.1:0")
	if err != nil {
		t.Fatal(err)
	}
	defer up.Close()
	endpoint := "http://" + up.Address + "/mcp"

	if got, isErr := call(t, endpoint, "mesh_call", map[string]any{"address": "laptop/slack.slack_check"}); isErr || strings.Contains(got, "announced") {
		t.Fatalf("while discovery hears the runtime: %s", got)
	}

	// Discovery goes quiet: no PING arrives at all.
	stopAnnounce()
	announcing.Flush()
	for _, address := range []string{"laptop/slack.slack_check", "issue-tracker.list"} {
		got, isErr := call(t, endpoint, "mesh_call", map[string]any{"address": address})
		if isErr || !strings.Contains(got, "found from what node-tools on laptop announced") ||
			!strings.Contains(got, "ago: it did not answer the latest round of discovery") {
			t.Errorf("%s after a round that heard nothing: %s", address, got)
		}
	}
	if got, isErr := call(t, endpoint, "mesh_describe", map[string]any{"address": "issue-tracker.list"}); isErr || !strings.Contains(got, `"found"`) {
		t.Errorf("describe after a round that heard nothing: %s", got)
	}
	if n := said("discovery heard nothing at all"); n != 1 {
		t.Errorf("the empty round was logged %d time(s), want once: %v", n, logged)
	}
	// A runtime really gone: the call is sent on what it announced, and fails with the bus's own refusal,
	// saying where the address was found.
	stopTool()
	tools.Flush()
	if got, isErr := call(t, endpoint, "mesh_call", map[string]any{"address": "laptop/slack.slack_check"}); !isErr ||
		!strings.Contains(got, "nothing serves") || !strings.Contains(got, "found from what node-tools on laptop announced") {
		t.Errorf("a gone runtime's tool: %s", got)
	}
	surface.mu.Lock()
	kept := surface.idx != nil && !surface.idx.Discovery.Empty() && time.Since(surface.idxAt) < time.Second
	surface.mu.Unlock()
	if kept {
		t.Error("a round that heard nothing was kept as the answer")
	}

	// Discovery answers again: the calls are plain again, and that is logged once.
	stopAgain, err := announce.Serve(announcing, announce.Service{Name: "node-tools", ID: "laptop",
		Metadata: map[string]string{"node": "laptop"}}, func() []announce.Endpoint { return endpoints })
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(stopAgain)
	announcing.Flush()
	if got, isErr := call(t, endpoint, "mesh_call", map[string]any{"address": "issue-tracker.list"}); isErr || strings.Contains(got, "announced") {
		t.Errorf("once discovery hears the runtime again: %s", got)
	}
	if n := said("discovery hears every runtime again"); n != 1 {
		t.Errorf("the recovery was logged %d time(s): %v", n, logged)
	}
}

// An address known only from an earlier answer says how old it is; one heard fresh on its machine is
// plain, even where the same module is known only from an earlier answer on another.
func TestAnAddressKnownOnlyFromAnEarlierAnswerSaysHowOld(t *testing.T) {
	at := time.Now().Add(-20 * time.Second)
	x := &index{Modules: map[string]*moduleInfo{"slack": {Module: "slack", On: []string{"laptop"},
		Tools: []Tool{{Module: "slack", Name: "slack_check"}}}}, Recorded: map[string][]string{},
		Stale:     map[string]staleFrom{"mod:slack@laptop": {Runtime: "node-tools", Machine: "laptop", At: at}},
		Discovery: announce.Discovery{Pinged: 0}}
	got, err := resolve(x, "laptop/slack.slack_check")
	if err != nil || got.Stale == nil || !strings.Contains(got.Stale.say(), "announced 20s ago") {
		t.Fatalf("%+v %v", got, err)
	}
	// A module heard fresh on one machine and only earlier on another: the fresh one is plain.
	x.Modules["slack"].On = []string{"desk", "laptop"}
	if got, err := resolve(x, "desk/slack.slack_check"); err != nil || got.Stale != nil {
		t.Errorf("a fresh machine's module marked stale: %+v %v", got, err)
	}
}