Say in grants' log how long each first-view page took (issue 1966, recovery)

The wants page failed 226 times on a call's bound with nothing in the log to
show how far from it the answer was.

Claude-Session: https://claude.ai/code/session_01NcbgfFfQ4Z9UE5jK32PmE5

modules/mesh-grants/cmd/mesh-grants/main.go

@@ -28,6 +28,7 @@ import (
 	"os/signal"
 	"strings"
 	"syscall"
+	"time"
 
 	"github.com/nats-io/nats.go"
 	"github.com/nats-io/nats.go/jetstream"
@@ -117,7 +118,7 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro
 	// followed on the owners' views families, which the hearing below hands them.
 	sayCond := sayVia(ctx, js, account.Module)
 	fv := grants.NewViews(func(tool string) func(context.Context, string) (views.Answer, error) {
-		return views.AskVia(grants.Unwrapped(conn.Call), tool)
+		return grants.TimedAsk(tool, views.AskVia(grants.Unwrapped(conn.Call), tool), time.Now, logger.Printf)
 	}, sayCond, f.Wake, logger.Printf)
 	fv.Rest, fv.Watching = bus, bus
 	byState := map[string]*views.Follower{}

modules/mesh-grants/grants_test.go

@@ -3905,6 +3905,28 @@ func TestGrants(t *testing.T) {
 			t.Errorf("the kept tool runner was not said: %+v", last)
 		}
 	})
+
+	// Each first view's page says in the log how long it took (issue 1966: the wants page outgrew the call's bound unseen).
+	t.Run("a first view's page says how long it took", func(t *testing.T) {
+		at := time.Date(2026, 11, 8, 22, 0, 0, 0, time.UTC)
+		now := func() time.Time { at = at.Add(1500 * time.Millisecond); return at }
+		for _, row := range []struct {
+			name string
+			err  error
+			want string
+		}{
+			{"answered", nil, `the first view mesh-delivery-assigner.wants, the page after "", took 1.5s: 2 keys at revision 9, next ""`},
+			{"failed", errors.New("context deadline exceeded"), `the first view mesh-delivery-assigner.wants, the page after "", failed after 1.5s: context deadline exceeded`},
+		} {
+			var lines []string
+			ask := grants.TimedAsk(grants.ReadWants, func(context.Context, string) (views.Answer, error) {
+				return views.Answer{Revision: 9, Values: map[string]json.RawMessage{"a": nil, "b": nil}}, row.err
+			}, now, func(f string, a ...any) { lines = append(lines, fmt.Sprintf(f, a...)) })
+			if _, err := ask(context.Background(), ""); !errors.Is(err, row.err) || len(lines) != 1 || !strings.Contains(lines[0], row.want) {
+				t.Errorf("%s: said %q (%v), want %q", row.name, lines, err, row.want)
+			}
+		}
+	})
 }
 
 // fakeObjects is the part's object bucket of sealed lists.

modules/mesh-grants/internal/grants/firstviews.go

@@ -479,6 +479,26 @@ func (p *Part) AskFirstViewAgain(caller, state, why string, record func(what, wh
 		"says": "the part's process asks it once more at this ask; grants_first_views shows its answer"}, nil
 }
 
+// TimedAsk is ask, saying in the log how long each page took and how many keys it brought, or after how long it failed:
+// a first view that never answers (issue 1966: the wants page outgrew the call's bound) shows how far from its bound it is.
+func TimedAsk(tool string, ask func(context.Context, string) (views.Answer, error), now func() time.Time,
+	logf func(string, ...any)) func(context.Context, string) (views.Answer, error) {
+	return func(ctx context.Context, after string) (views.Answer, error) {
+		start := now()
+		a, err := ask(ctx, after)
+		took := now().Sub(start).Round(time.Millisecond)
+		switch {
+		case logf == nil:
+		case err != nil:
+			logf("[mesh-grants] the first view %s, the page after %q, failed after %s: %v", tool, after, took, err)
+		default:
+			logf("[mesh-grants] the first view %s, the page after %q, took %s: %d keys at revision %d, next %q", tool, after, took,
+				len(a.Values), a.Revision, a.Next)
+		}
+		return a, err
+	}
+}
+
 // Unwrapped is a call whose answer is read as the tool's own text where the runtime wraps it as content (unwrap), as
 // a first view's answer is decoded (views.AskVia).
 func Unwrapped(call func(key string, body any) (json.RawMessage, error)) func(key string, body any) (json.RawMessage, error) {