mesh-controller/internal/link/calls_test.go

package link

import (
	"bytes"
	"context"
	"encoding/json"
	"errors"
	"fmt"
	"log"
	"strings"
	"sync"
	"testing"
	"time"
	"unicode"
)

// answers collects what a call answered, and fails a second answer: the bus permits one.
type answers struct {
	t    *testing.T
	mu   sync.Mutex
	got  [][]byte
	sent chan struct{}
}

func newAnswers(t *testing.T) *answers { return &answers{t: t, sent: make(chan struct{}, 4)} }

func (a *answers) respond(body []byte) error {
	a.mu.Lock()
	defer a.mu.Unlock()
	a.got = append(a.got, body)
	if len(a.got) > 1 {
		a.t.Errorf("a call was answered %d times; the bus refuses every answer after the first", len(a.got))
	}
	a.sent <- struct{}{}
	return nil
}

func (a *answers) only() map[string]any {
	a.mu.Lock()
	defer a.mu.Unlock()
	if len(a.got) != 1 {
		a.t.Fatalf("%d answers, want exactly one", len(a.got))
	}
	var out map[string]any
	if err := json.Unmarshal(a.got[0], &out); err != nil {
		a.t.Fatal(err)
	}
	return out
}

func shortWindow(t *testing.T, d time.Duration) {
	t.Helper()
	was := AnswerWithin
	AnswerWithin = d
	t.Cleanup(func() { AnswerWithin = was })
}

// A call that finishes in time answers in full, once, and is kept as answered.
func TestACallThatFinishesInTimeAnswersInFull(t *testing.T) {
	l, a := NewCallLog(), newAnswers(t)
	l.serveCall("mesh-controller", "status", nil, "_INBOX.x.1", func(context.Context, json.RawMessage) (any, error) {
		return "all well", nil
	}, a.respond, nil)
	if got := a.only()["result"]; got != "all well" {
		t.Fatalf("answered %v", got)
	}
	recent, _ := l.Recent()
	if len(recent) != 1 || recent[0].State != CallAnswered || string(recent[0].Args) != "{}" {
		t.Fatalf("kept %+v", recent)
	}
}

// **A call that outlasts AnswerWithin is answered that it is running, with its id** — before its
// caller gives up — and what it finally answered is kept under that id, not dropped (issue 265).
func TestACallThatOutlastsTheWindowSaysItIsRunningAndKeepsItsAnswer(t *testing.T) {
	shortWindow(t, 20*time.Millisecond)
	l, a := NewCallLog(), newAnswers(t)
	var logged bytes.Buffer
	release := make(chan struct{})
	finished := make(chan struct{})
	go func() {
		l.serveCall("mesh-controller", "push", json.RawMessage(`{"node":"anchor"}`), "_INBOX.x.2",
			func(context.Context, json.RawMessage) (any, error) {
				<-release
				return "anchor told", nil
			}, a.respond, log.New(&logged, "", 0))
		close(finished)
	}()
	<-a.sent
	got := a.only()["result"].(map[string]any)
	id, _ := got["call"].(string)
	if got["running"] != true || id == "" || !strings.Contains(got["output"].(string), id) {
		t.Fatalf("the running answer does not name its call: %v", got)
	}
	if c, _, _ := l.Get(id); c.State != CallRunning {
		t.Fatalf("while it runs it is kept as %q", c.State)
	}
	close(release)
	<-finished
	c, ok, _ := l.Get(id)
	if !ok || c.State != CallFinishedAfter || !strings.Contains(string(c.Answer), "anchor told") {
		t.Fatalf("its answer was not kept: %+v", c)
	}
	if !strings.Contains(logged.String(), id) {
		t.Errorf("finishing late was not said: %q", logged.String())
	}
}

// A handler that acknowledges is answered then, not when it ends: a push answers before it sends.
func TestAnAcknowledgedCallIsAnsweredBeforeItGoesOn(t *testing.T) {
	l, a := NewCallLog(), newAnswers(t)
	done := make(chan struct{})
	go func() {
		l.serveCall("mesh-controller", "push", nil, "_INBOX.x.3", func(ctx context.Context, _ json.RawMessage) (any, error) {
			Acknowledge(ctx)
			Acknowledge(ctx) // a second time is nothing
			select {
			case <-a.sent: // the caller was answered before the work goes on
			case <-time.After(5 * time.Second):
				t.Error("acknowledging did not answer the caller")
			}
			return "sent", nil
		}, a.respond, nil)
		close(done)
	}()
	<-done
	if got := a.only()["result"].(map[string]any); got["running"] != true {
		t.Fatalf("an acknowledged call answered %v", got)
	}
	if c := recentOf(l)[0]; c.State != CallFinishedAfter || !strings.Contains(string(c.Answer), "sent") {
		t.Fatalf("kept %+v", c)
	}
}

// **A refused answer is recorded against its call, in the mesh's words** — not only as the client
// library's line on standard error, which is all there was on 2026-10-05.
func TestARefusedAnswerIsKeptAgainstItsCall(t *testing.T) {
	l, a := NewCallLog(), newAnswers(t)
	reply := "_INBOX.laptop.node-tools.jJ4DRJFnZYvkPUBKYwUG5v.LNRyztuX"
	l.serveCall("mesh-controller", "push", nil, reply, func(context.Context, json.RawMessage) (any, error) {
		return "told", nil
	}, a.respond, nil)
	var logged bytes.Buffer
	refusal := errors.New(`nats: permissions violation: Permissions Violation for Publish to "` + reply + `" on connection [838]`)
	if !l.Refusal(refusal, log.New(&logged, "", 0)) {
		t.Fatal("the refusal of a kept call's answer was not recognised")
	}
	c := recentOf(l)[0]
	if c.Refused == "" || !strings.Contains(logged.String(), c.ID) {
		t.Fatalf("the refusal is not kept or not said: %+v / %q", c, logged.String())
	}
	other := errors.New(`nats: permissions violation: Permissions Violation for Publish to "mesh.node.x" on connection [1]`)
	if l.Refusal(other, nil) || l.Refusal(errors.New("nats: timeout"), nil) {
		t.Error("an unrelated error was taken for a refused answer")
	}
}

// What `calls` keeps of the arguments never carries settings or a secret.
func TestACallKeepsNoSettingsOrSecrets(t *testing.T) {
	got := string(kept(json.RawMessage(`{"module":"m","values":"{\"token\":\"s3cret\"}","secret":"s3cret"}`)))
	if strings.Contains(got, "s3cret") || !strings.Contains(got, `"module":"m"`) {
		t.Fatalf("kept %s", got)
	}
}

// A command line's own words may carry a setting's value or a secret, so only its first word is kept
// — as a mesh-cli line's is (novox/hq issue 397). Each case says the whole of what is kept, because
// what matters is as much what is left out as what is there.
func TestACallKeepsNoCommandLine(t *testing.T) {
	long := strings.Repeat("s3cret", 50) // one word, 300 bytes: a token, as far as this can tell
	for line, want := range map[string]string{
		`settings set notes 'the operator's own passphrase' --node laptop`: "settings (the rest given, not kept)",
		`settings set notes --values {"token":"s3cret"}`:                   "settings (the rest given, not kept)",
		// Parted by a tab or a newline, which the verb's splitter reads as this line's words too.
		"settings\tset\tnotes\tthe-operators-passphrase": "settings (the rest given, not kept)",
		"builds\n--limit 5": "builds (the rest given, not kept)",
		"builds\t--limit 5": "builds (the rest given, not kept)",
		// Its first word is kept, and the spaces before it are not part of it.
		`  node show laptop`: "node (the rest given, not kept)",
		// A command of one word is kept whole: there is nothing after it to withhold.
		`builds`: "builds",
		// One word is still capped, as every other string in a kept record is.
		long: long[:120] + "…",
	} {
		raw, err := json.Marshal(map[string]any{"command": line})
		if err != nil {
			t.Fatal(err)
		}
		var got struct{ Command string }
		if err := json.Unmarshal(kept(raw), &got); err != nil {
			t.Fatal(err)
		}
		if got.Command != want {
			t.Errorf("%q is kept as %q; want %q", line, got.Command, want)
		}
		// Whole words, so that "set" can be looked for although "settings" is kept, and "show" cannot
		// be found in a word such as "shown".
		for _, never := range []string{"set", "notes", "laptop", "show", "passphrase", "operators"} {
			for _, word := range strings.FieldsFunc(got.Command, func(r rune) bool { return !unicode.IsLetter(r) }) {
				if word == never {
					t.Errorf("%q is kept as %q: it carries the word %q", line, got.Command, never)
				}
			}
		}
	}

	// Not a string, so its first word cannot be taken: none of it is kept. The verb refuses such a
	// call, but the record is written before it judges it.
	raw, _ := json.Marshal(map[string]any{"command": []string{"settings", "set", "notes", "s3cret"}})
	if got := string(kept(raw)); strings.Contains(got, "s3cret") {
		t.Errorf("kept %s", got)
	}
}

// Only the newest KeptCalls are kept.
func TestTheLogKeepsTheNewest(t *testing.T) {
	l := NewCallLog()
	for i := 0; i < KeptCalls+5; i++ {
		l.begin("s", "v", nil, "")
	}
	recent, _ := l.Recent()
	if len(recent) != KeptCalls || !strings.HasSuffix(recent[0].ID, "-105") || !strings.HasSuffix(recent[KeptCalls-1].ID, "-6") {
		t.Fatalf("kept %d, newest %s, oldest %s", len(recent), recent[0].ID, recent[len(recent)-1].ID)
	}
}

func recentOf(l *CallLog) []Call {
	out, _ := l.Recent()
	return out
}

// A call refused because its controller is handing over says so in a mark as well as in words, so the
// caller asks once more without parsing a sentence (novox/hq issue 289).
func TestAHandoverRefusalIsMarkedRetryable(t *testing.T) {
	l, a := NewCallLog(), newAnswers(t)
	l.serveCall("mesh-controller", "rotate", nil, "_INBOX.x.9", func(context.Context, json.RawMessage) (any, error) {
		return nil, fmt.Errorf("%w: stopping", ErrHandingOver)
	}, a.respond, nil)
	got := a.only()
	if got["retry"] != RetryHandingOver || !strings.Contains(fmt.Sprint(got["error"]), "handing over") {
		t.Fatalf("answered %v", got)
	}

	l, a = NewCallLog(), newAnswers(t)
	l.serveCall("mesh-controller", "rotate", nil, "_INBOX.x.10", func(context.Context, json.RawMessage) (any, error) {
		return nil, errors.New("refused for its own reason")
	}, a.respond, nil)
	if _, marked := a.only()["retry"]; marked {
		t.Fatal("an ordinary refusal was marked to be asked again")
	}
}

// **A join token is shown to its caller and kept nowhere** (novox/hq ADR 0169): `calls` answers anyone
// who may call the seat, and a token is the one-time right to become a machine of the mesh.
func TestAJoinTokenIsShownToItsCallerAndNotKept(t *testing.T) {
	l, a := NewCallLog(), newAnswers(t)
	l.woken = make(chan struct{}, 1) // queued for the keeper, and nothing takes them: read below
	l.serveCall("mesh-controller", "token", json.RawMessage(`{"new":"laptop"}`), "_INBOX.x.1",
		func(context.Context, json.RawMessage) (any, error) { return "token for laptop: s3cret-join", nil },
		a.respond, nil)
	if got, _ := a.only()["result"].(string); !strings.Contains(got, "s3cret-join") {
		t.Fatalf("its caller was not shown the token: %v", got)
	}
	recent, _ := l.Recent()
	if len(recent) != 1 || strings.Contains(string(recent[0].Answer), "s3cret-join") {
		t.Fatalf("the token was kept in memory: %+v", recent)
	}
	for _, c := range l.queued.take() {
		if strings.Contains(string(c.Answer), "s3cret-join") {
			t.Fatalf("the token was sent to be kept on the bus: %s", c.Answer)
		}
	}
}

// A verb whose handler panics answers an error, and the controller serves the next call (review of
// novox/hq issue 327: read verbs are answered in the serving process now).

// Sweep 2026-10-30 (issue 774): a burst of calls never loses a record while the keeper is slow: each call waits once,
// with its latest state, and every call of a burst far over the old queue of 256 is kept with its last state.
func TestABurstOfCallsIsKeptWithEachCallsLastState(t *testing.T) {
	var q callQueue
	for i := range 2000 {
		id := fmt.Sprintf("call-%d", i)
		if !q.put(Call{ID: id, State: CallRunning}) || !q.put(Call{ID: id, State: CallAnswered}) {
			t.Fatalf("%s was refused by a queue of %d", id, callQueueBound)
		}
	}
	got := q.take()
	if len(got) != 2000 {
		t.Fatalf("%d calls wait, want 2000", len(got))
	}
	for i, c := range got {
		if c.ID != fmt.Sprintf("call-%d", i) || c.State != CallAnswered {
			t.Fatalf("call %d waits as %+v", i, c)
		}
	}
	if len(q.take()) != 0 {
		t.Fatal("taken calls wait again")
	}
	for i := range callQueueBound {
		q.put(Call{ID: fmt.Sprint(i)})
	}
	if q.put(Call{ID: "one too many"}) {
		t.Fatal("the queue grew past its bound")
	}
}