diff --git a/node-tools/internal/bus/caller.go b/node-tools/internal/bus/caller.go index 7222627..5a817bb 100644 --- a/node-tools/internal/bus/caller.go +++ b/node-tools/internal/bus/caller.go @@ -91,7 +91,11 @@ func calledPattern(subject string) string { // callerOn is the bus user a call names, from the subject it arrived on: its last token, under a pattern // calledPattern made. "" — said by the module as Unproven — for a call on the subject that names no caller. func callerOn(pattern, subject string) string { - if !strings.HasSuffix(pattern, ".*") { + // Only the `call` kind names a caller: a `tool` pattern ending in a wildcard (a node seat's verb on any + // machine) is never read as one. + parts := strings.SplitN(pattern, ".", 5) + if len(parts) != 5 || parts[0] != "mesh" || (parts[1] != "mod" && parts[1] != "seat") || parts[3] != CallKind || + !strings.HasSuffix(pattern, ".*") { return "" } dot := strings.LastIndex(subject, ".") @@ -107,9 +111,11 @@ type CalledHandler func(caller string, body json.RawMessage) (any, error) // callers is what a connection keeps of its caller-named calls: those in flight, by subject, so a refused // publish ends its call at once instead of after RequestTimeout. type callers struct { - mu sync.Mutex - next uint64 - pending map[string]map[uint64]context.CancelCauseFunc + mu sync.Mutex + // fellBack are the caller-named subjects already said to have reached nobody, so each is said once. + fellBack map[string]bool + next uint64 + pending map[string]map[uint64]context.CancelCauseFunc } // errCallRefused is the bus refusing a caller-named publish: this user is not granted it yet (the controller's @@ -176,6 +182,7 @@ func (c *Conn) askCalled(subject string, data []byte) (answered Answered, handin case errors.Is(context.Cause(ctx), errCallRefused): return Answered{}, false, true, nil case errors.Is(err, nats.ErrNoResponders): + c.saidFallBack(subject) return Answered{}, false, true, nil case errors.Is(err, context.DeadlineExceeded) || errors.Is(err, nats.ErrTimeout): return Answered{}, false, false, errors.New("timeout") @@ -185,3 +192,21 @@ func (c *Conn) askCalled(subject string, data []byte) (answered Answered, handin answered, handingOver, err = c.answerOf(subject, msg.Data) return answered, handingOver, false, err } + +// saidFallBack says, once per subject, that a caller-named call reached nobody and is asked on the subject that +// names no caller: a runtime or holder not yet serving it, or a grant that drifted, is seen in the log rather +// than read later as a quiet "unproven" (novox/hq issue 365; expected for the controller's seat until hq issue +// 464). +func (c *Conn) saidFallBack(subject string) { + c.calls.mu.Lock() + if c.calls.fellBack == nil { + c.calls.fellBack = map[string]bool{} + } + first := !c.calls.fellBack[subject] + c.calls.fellBack[subject] = true + c.calls.mu.Unlock() + if first { + c.Logf("[mesh-tools] nothing answers the caller-named %s; asked on the subject that names no caller, where "+ + "the module is told no caller (said once per subject; novox/hq issue 365)", subject) + } +} diff --git a/node-tools/internal/bus/caller_bus_test.go b/node-tools/internal/bus/caller_bus_test.go index 1ea2d6d..625c7fd 100644 --- a/node-tools/internal/bus/caller_bus_test.go +++ b/node-tools/internal/bus/caller_bus_test.go @@ -180,3 +180,39 @@ func TestAGrantedCallerIsHeardAsItselfAndCannotNameAnother(t *testing.T) { t.Errorf("heard %v; want the asker alone, as itself", got) } } + +// A fall-back for want of a responder on the caller-named subject is said, once per subject, so a runtime or +// grant that drifted behind is seen rather than read as a quiet "unproven". +func TestAFallBackForWantOfAResponderIsSaidOncePerSubject(t *testing.T) { + url := mt.URL(t) + // A runtime from before issue 365: the subject that names no caller, alone. + older, err := nats.Connect(url) + if err != nil { + t.Fatal(err) + } + defer older.Close() + if _, err := older.Subscribe("mesh.mod.ledger.tool.who", func(m *nats.Msg) { _ = m.Respond([]byte(`{"result":{}}`)) }); err != nil { + t.Fatal(err) + } + _ = older.Flush() + asker := dial(t, url, "node-tools", "shanks", "shanks.node-tools") + var mu sync.Mutex + var said []string + asker.Logf = func(f string, a ...any) { mu.Lock(); said = append(said, fmt.Sprintf(f, a...)); mu.Unlock() } + for i := 0; i < 3; i++ { + if _, err := asker.Ask("ledger.who", map[string]any{}, ""); err != nil { + t.Fatal(err) + } + } + mu.Lock() + defer mu.Unlock() + n := 0 + for _, s := range said { + if strings.Contains(s, "nothing answers the caller-named mesh.mod.ledger.call.who.shanks~node-tools") { + n++ + } + } + if n != 1 { + t.Errorf("the fall-back was said %d times, want once: %v", n, said) + } +} diff --git a/node-tools/internal/bus/caller_test.go b/node-tools/internal/bus/caller_test.go index 23e9356..5c4da68 100644 --- a/node-tools/internal/bus/caller_test.go +++ b/node-tools/internal/bus/caller_test.go @@ -56,3 +56,17 @@ func TestTheCallerIsTheLastTokenOfTheSubjectTheCallArrivedOn(t *testing.T) { } } } + +// Only a pattern of the `call` kind names a caller: a `tool` subscription with a wildcard last — a node seat's +// verb on any machine, say — never yields one, whatever token a call arrived with. +func TestAToolPatternNeverYieldsACaller(t *testing.T) { + for pattern, subject := range map[string]string{ + "mesh.mod.ledger.tool.who.*": "mesh.mod.ledger.tool.who.controller", + "mesh.seat.node-desk.tool.who.*": "mesh.seat.node-desk.tool.who.shanks~node-tools", + "mesh.mod.ledger.event.*": "mesh.mod.ledger.event.controller", + } { + if got := callerOn(pattern, subject); got != "" { + t.Errorf("%s on %s yielded caller %q", pattern, subject, got) + } + } +} diff --git a/node-tools/internal/runtime/caller_test.go b/node-tools/internal/runtime/caller_test.go index 2aa5da0..54ca2fe 100644 --- a/node-tools/internal/runtime/caller_test.go +++ b/node-tools/internal/runtime/caller_test.go @@ -27,7 +27,7 @@ func TestACallOnTheCallerNamedSubjectReachesTheModuleWithItsCaller(t *testing.T) if err != nil { t.Fatal(err) } - defer stop() + defer settled(stop) asker, err := bus.Connect(bus.Credential{URL: mt.URL(t), Module: "node-tools", Node: "shanks", User: "shanks.node-tools", Password: "unused"}) if err != nil { @@ -65,7 +65,7 @@ func TestTheSubjectThatNamesNoCallerStillWorksAndNamesNone(t *testing.T) { if err != nil { t.Fatal(err) } - defer stop() + defer settled(stop) old, err := nats.Connect(mt.URL(t)) if err != nil { t.Fatal(err) @@ -89,3 +89,11 @@ func TestTheSubjectThatNamesNoCallerStillWorksAndNamesNone(t *testing.T) { } } } + +// settled stops a runtime and waits for its bundle's exit to be handled: the launcher reads its restart pauses +// (launch.RestartFirst) as a bundle exits, and a later test in this package sets them, so a test that leaves its +// bundle exiting behind it races the next one. +func settled(stop func()) { + stop() + time.Sleep(500 * time.Millisecond) +}