mesh-tools/node-tools/internal/runtime/events_test.go

package runtime

import (
	"fmt"
	"os"
	"path/filepath"
	"strings"
	"sync"
	"testing"
	"time"

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

// A logger safe to write from the runtime's goroutines.
type lines struct {
	mu sync.Mutex
	l  []string
}

func (s *lines) logf(format string, args ...any) {
	s.mu.Lock()
	defer s.mu.Unlock()
	s.l = append(s.l, strings.TrimSpace(sprintf(format, args...)))
}

func (s *lines) all() string {
	s.mu.Lock()
	defer s.mu.Unlock()
	return strings.Join(s.l, "\n")
}

func sprintf(format string, args ...any) string { return fmtSprintf(format, args...) }

func countLines(t *testing.T, path, want string) int {
	t.Helper()
	b, _ := os.ReadFile(path)
	n := 0
	for _, l := range strings.Split(string(b), "\n") {
		if l == want {
			n++
		}
	}
	return n
}

// novox/hq ADR 0198: a module's long-running code is launched by the node's runtime, and the runtime
// is its bus — it binds the module's own consumer, hands each event to the bundle, and acknowledges it
// only when the bundle has taken it; one the bundle failed or died on is offered again.
func TestTheRuntimeHandsAModulesEventsToItsBundleAndAcknowledgesThemOnlyWhenTaken(t *testing.T) {
	mesh := mt.New(t)
	restore := bus.NakDelay
	bus.NakDelay = 300 * time.Millisecond
	t.Cleanup(func() { bus.NakDelay = restore })
	firstPause := launch.RestartFirst
	launch.RestartFirst = 100 * time.Millisecond
	t.Cleanup(func() { launch.RestartFirst = firstPause })

	mesh.Issue(t, mt.MembershipOf("watcher", "anchor", false, nil))
	mesh.Issue(t, mt.MembershipOf("beta", "anchor", true, nil))
	// The controller's consumer for the module, as its own runtime bound it: anchor_watcher on EVENTS.
	mesh.Consumer(t, "anchor", "watcher", []string{"mesh.mod.alpha.event.>"}, 2*time.Second)

	nodeTools := connect(t, "node-tools", "anchor")
	asker := connect(t, "console", "workstation")
	dir := t.TempDir()
	log := filepath.Join(dir, "watch.log")
	said := &lines{}
	stop, err := Run(nodeTools, []Served{
		{Module: "watcher", Entrypoints: []string{mt.Fixture("watcher.serve.mjs")}},
		{Module: "beta", Entrypoints: []string{mt.Fixture("many-beta.serve.mjs")}},
	}, map[string]map[string]string{"watcher": {"WATCH_LOG": log}}, said.logf)
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(stop)
	if !strings.Contains(said.all(), "watcher's events arrive on its consumer anchor_watcher") {
		t.Fatalf("the module's consumer was not bound:\n%s", said.all())
	}

	// Handled once, acknowledged once.
	mesh.Emit(t, "mesh.mod.alpha.event.happened", map[string]any{"n": 1})
	mt.Until(t, func() error {
		if countLines(t, log, "handled 1") != 1 {
			return errorf("event 1 not handled yet")
		}
		return nil
	})
	// The handler fails the first time: not acknowledged, offered again, then handled.
	mesh.Emit(t, "mesh.mod.alpha.event.happened", map[string]any{"n": 2, "fail": true})
	// The bundle dies on the first offer: not acknowledged, the bundle is started again and the
	// event is offered again once its ack wait has passed.
	mesh.Emit(t, "mesh.mod.alpha.event.happened", map[string]any{"n": 3, "die": true})
	deadline := time.Now().Add(20 * time.Second)
	for time.Now().Before(deadline) {
		if countLines(t, log, "handled 2") == 1 && countLines(t, log, "handled 3") == 1 {
			break
		}
		time.Sleep(200 * time.Millisecond)
	}
	if countLines(t, log, "handled 2") != 1 || countLines(t, log, "handled 3") != 1 {
		b, _ := os.ReadFile(log)
		t.Fatalf("a failed or interrupted event was not offered again and handled once:\n%s\nruntime:\n%s", b, said.all())
	}
	if countLines(t, log, "started") < 2 {
		t.Errorf("the bundle that died was not started again: %s", said.all())
	}
	mt.Until(t, func() error {
		ack, notYet := mesh.Pending(t, "anchor", "watcher")
		if ack != 0 || notYet != 0 {
			return errorf("still pending: %d unacknowledged, %d undelivered", ack, notYet)
		}
		return nil
	})
	if countLines(t, log, "handled 1") != 1 {
		t.Errorf("event 1 was handled more than once")
	}

	// A tool asks another module's tool through the runtime, as the module.
	got, err := call(t, asker, "watcher.relay@anchor", map[string]any{})
	if err != nil {
		t.Fatal(err)
	}
	same(t, got, `{"beta":3}`)
}

// A long-running bundle that exits is started again, without waiting for a call (ADR 0198).
func TestALongRunningBundleThatExitsIsStartedAgain(t *testing.T) {
	mesh := mt.New(t)
	firstPause := launch.RestartFirst
	launch.RestartFirst = 100 * time.Millisecond
	t.Cleanup(func() { launch.RestartFirst = firstPause })
	mesh.Issue(t, mt.MembershipOf("flaky", "anchor", false, nil))
	nodeTools := connect(t, "node-tools", "anchor")
	log := filepath.Join(t.TempDir(), "flaky.log")
	said := &lines{}
	stop, err := Run(nodeTools, []Served{{Module: "flaky", Entrypoints: []string{mt.Fixture("flaky.serve.mjs")}}},
		map[string]map[string]string{"flaky": {"FLAKY_LOG": log}}, said.logf)
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(stop)
	mt.Until(t, func() error {
		if countLines(t, log, "started") < 3 {
			return errorf("started %d time(s)", countLines(t, log, "started"))
		}
		return nil
	})
	if !strings.Contains(said.all(), "flaky's bundle exited (3)") || !strings.Contains(said.all(), "started again in") {
		t.Errorf("the restart was not said:\n%s", said.all())
	}
}

func fmtSprintf(format string, args ...any) string { return fmt.Sprintf(format, args...) }
func errorf(format string, args ...any) error      { return fmt.Errorf(format, args...) }