From 71531f871e1228f6ddfbea999b89da720b232800 Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 17:48:22 +0000 Subject: [PATCH 1/7] controlplane: the storage sweep stops between steps on shutdown A sweep in flight when the server closes logged one error per remaining step, each a context canceled; the steps after a cancelled one are skipped. --- internal/controlplane/node_gc.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/internal/controlplane/node_gc.go b/internal/controlplane/node_gc.go index 22ffd902..3723e34f 100644 --- a/internal/controlplane/node_gc.go +++ b/internal/controlplane/node_gc.go @@ -113,7 +113,13 @@ func (s *Server) runNodeGCLoop() { // grow. func (s *Server) gcStorage(now time.Time) { s.gcExpiredNodes(now) + if s.ctx.Err() != nil { + return + } s.gcEnrollmentRecords(now) + if s.ctx.Err() != nil { + return + } s.pruneCatalog(now) } From 8d67450821edf5f7cb236540650023525974faa4 Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 17:48:23 +0000 Subject: [PATCH 2/7] controlplane: the key rotation deadline lives in the store, not in the process uptime The rotation loop ticked once per --key-rotation-interval from the process start and asked the store for the window on each tick. A control plane that never lived a full interval therefore never rotated: bananas redeploys on every merge to main and had not rotated since 2026-10-09, with rotation_lock.next_rotation_at five days in the past, and a control plane that crash-loops or is drained daily would behave the same. Init now schedules the first rotation one interval from the first start when the store has no deadline (ScheduleKeyRotationIfUnset), and the loop checks the store's deadline at a tenth of the interval, at most once a minute. The deadline is shared by the replicas and kept across restarts; a rotation that fell due while no replica was up happens on the first check after a start. The claim stays the single UPDATE that lets exactly one replica rotate per window. agentmesh_control_plane_next_key_rotation_timestamp_seconds exports the deadline, so a rotation that is not happening is a value in the past on a dashboard instead of a psql query. --- internal/controlplane/key_rotation_test.go | 97 ++++++++++++++++ internal/controlplane/metrics.go | 17 ++- internal/controlplane/metrics_test.go | 1 + internal/controlplane/server.go | 113 ++++++++++++------- internal/storage/sql_store.go | 25 ++++ internal/storage/sql_store_test.go | 47 ++++++++ internal/storage/storage.go | 9 ++ site/content/docs/reference/control-plane.md | 7 ++ 8 files changed, 273 insertions(+), 43 deletions(-) create mode 100644 internal/controlplane/key_rotation_test.go diff --git a/internal/controlplane/key_rotation_test.go b/internal/controlplane/key_rotation_test.go new file mode 100644 index 00000000..efb6fd4c --- /dev/null +++ b/internal/controlplane/key_rotation_test.go @@ -0,0 +1,97 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package controlplane + +import ( + "context" + "testing" + "time" +) + +func TestKeyRotationCheckInterval(t *testing.T) { + for _, tc := range []struct { + interval, want time.Duration + }{ + {24 * time.Hour, time.Minute}, + {time.Hour, time.Minute}, + {5 * time.Minute, 30 * time.Second}, + {2 * time.Second, 200 * time.Millisecond}, + } { + if got := keyRotationCheckInterval(tc.interval); got != tc.want { + t.Errorf("keyRotationCheckInterval(%s) = %s, want %s", tc.interval, got, tc.want) + } + } +} + +// The deadline is the store's, not the process's: a rotation that was due +// while no replica was up happens on the first check after a start, and a +// replica that restarts before the deadline does not push it back. +func TestRotateKeysIfDueFollowsTheStoredDeadline(t *testing.T) { + store := newMetricsTestStore(t) + ctx := context.Background() + interval := 24 * time.Hour + issuer, _ := startCustomMockOIDC(t) + srv, err := NewServer(Options{ + DriverName: "sqlite", DataSourceName: "unused", OIDCIssuer: issuer, + KeyRotationInterval: interval, + }, store) + if err != nil { + t.Fatal(err) + } + defer func() { _ = srv.Close() }() + if err := srv.Init(); err != nil { + t.Fatal(err) + } + keys := func() int { + t.Helper() + ks, err := store.GetAllValidKeys(ctx) + if err != nil { + t.Fatal(err) + } + return len(ks) + } + if got := keys(); got != 1 { + t.Fatalf("after Init the keyring holds %d keys, want 1", got) + } + + // Init scheduled the first rotation an interval from now; the loop it + // started checks every minute, these checks are direct. + next, err := store.NextKeyRotation(ctx) + if err != nil { + t.Fatal(err) + } + if next.IsZero() || time.Until(next) < interval-time.Minute { + t.Fatalf("first rotation scheduled at %s, want about %s from now", next, interval) + } + + srv.rotateKeysIfDue(time.Now()) + if got := keys(); got != 1 { + t.Fatalf("a check before the deadline rotated: %d keys", got) + } + + // Five days later, as after a week of restarts that never reached a tick. + late := next.Add(5 * 24 * time.Hour) + srv.rotateKeysIfDue(late) + if got := keys(); got != 2 { + t.Fatalf("a check past the deadline did not rotate: %d keys, want 2", got) + } + if next, _ = store.NextKeyRotation(ctx); !next.Equal(late.Add(interval).Truncate(time.Millisecond)) { + t.Fatalf("deadline after the late rotation = %s, want %s", next, late.Add(interval)) + } + srv.rotateKeysIfDue(late.Add(time.Minute)) + if got := keys(); got != 2 { + t.Fatalf("a check right after a rotation rotated again: %d keys", got) + } +} diff --git a/internal/controlplane/metrics.go b/internal/controlplane/metrics.go index 29adf675..22a8483b 100644 --- a/internal/controlplane/metrics.go +++ b/internal/controlplane/metrics.go @@ -113,6 +113,9 @@ type meshSnapshot struct { // the retiring one stops verifying; zero when there is none. signingKeys int retiringKeyExpiry time.Time + // nextKeyRotation is when the store says the next rotation is due; a + // value in the past is a rotation no replica has performed. + nextKeyRotation time.Time // storageRows is the row count of every table the control plane keeps // bounded; a table that grows past its retention is a reaper that // stopped working. @@ -145,6 +148,7 @@ type meshStateCollector struct { meshPeersDesc *prometheus.Desc signingKeysDesc *prometheus.Desc retiringKeyDesc *prometheus.Desc + nextRotationDesc *prometheus.Desc storageRowsDesc *prometheus.Desc scrapeOKDesc *prometheus.Desc scrapeSampleDesc *prometheus.Desc @@ -200,6 +204,10 @@ func newMeshStateCollector(store storage.Store) *meshStateCollector { "agentmesh_control_plane_retiring_key_expiry_timestamp_seconds", "Unix time the retiring signing key stops verifying; absent when no rotation is in its grace period", nil, nil), + nextRotationDesc: prometheus.NewDesc( + "agentmesh_control_plane_next_key_rotation_timestamp_seconds", + "Unix time the next signing key rotation is due; in the past when it is overdue", + nil, nil), storageRowsDesc: prometheus.NewDesc( "agentmesh_control_plane_storage_rows", "Rows in a control plane store table", @@ -219,7 +227,7 @@ func (c *meshStateCollector) Describe(ch chan<- *prometheus.Desc) { for _, d := range []*prometheus.Desc{ c.nodesDesc, c.usersDesc, c.requestsDesc, c.tokensDesc, c.routersDesc, c.routerPeersDesc, c.routerDHTDesc, c.routerLeaseDesc, c.meshPeersDesc, - c.signingKeysDesc, c.retiringKeyDesc, c.storageRowsDesc, c.scrapeOKDesc, c.scrapeSampleDesc, + c.signingKeysDesc, c.retiringKeyDesc, c.nextRotationDesc, c.storageRowsDesc, c.scrapeOKDesc, c.scrapeSampleDesc, } { ch <- d } @@ -266,6 +274,9 @@ func (c *meshStateCollector) Collect(ch chan<- prometheus.Metric) { if !s.retiringKeyExpiry.IsZero() { ch <- prometheus.MustNewConstMetric(c.retiringKeyDesc, prometheus.GaugeValue, float64(s.retiringKeyExpiry.Unix())) } + if !s.nextKeyRotation.IsZero() { + ch <- prometheus.MustNewConstMetric(c.nextRotationDesc, prometheus.GaugeValue, float64(s.nextKeyRotation.Unix())) + } for table, n := range s.storageRows { ch <- prometheus.MustNewConstMetric(c.storageRowsDesc, prometheus.GaugeValue, float64(n), table) } @@ -351,6 +362,10 @@ func readMeshSnapshot(ctx context.Context, store storage.Store, now time.Time) ( if err != nil { return snap, err } + snap.nextKeyRotation, err = store.NextKeyRotation(ctx) + if err != nil { + return snap, err + } return snap, nil } diff --git a/internal/controlplane/metrics_test.go b/internal/controlplane/metrics_test.go index 099d97d7..d066d760 100644 --- a/internal/controlplane/metrics_test.go +++ b/internal/controlplane/metrics_test.go @@ -344,6 +344,7 @@ func TestMetricsEndpointServesMeshStateAndRuntime(t *testing.T) { "agentmesh_control_plane_routers_active 0", "agentmesh_control_plane_mesh_connected_peers 0", `agentmesh_control_plane_storage_rows{table="nodes"} 0`, + "agentmesh_control_plane_next_key_rotation_timestamp_seconds ", `agentmesh_control_plane_storage_rows{table="enrollment_requests"} 0`, "agentmesh_control_plane_catalog_entries ", `agentmesh_control_plane_storage_rows_deleted_total{table="routers"} `, diff --git a/internal/controlplane/server.go b/internal/controlplane/server.go index a535d4ea..9b4537a4 100644 --- a/internal/controlplane/server.go +++ b/internal/controlplane/server.go @@ -300,6 +300,19 @@ func (s *Server) Init() error { } else if err != nil { return fmt.Errorf("failed to query initial keyring status: %w", err) } + // The rotation deadline lives in the store, shared by the replicas and + // kept across restarts; a store that never had one gets its first an + // interval from now. + if interval := s.config.KeyRotationInterval; interval > 0 { + first := time.Now().Add(interval) + scheduled, err := s.store.ScheduleKeyRotationIfUnset(ctx, first) + if err != nil { + return fmt.Errorf("failed to schedule the first key rotation: %w", err) + } + if scheduled { + logger.Infof("First key rotation scheduled at %s", first.UTC().Format(time.RFC3339)) + } + } // Bootstrap Policy is now disabled; starting default closed. @@ -514,64 +527,80 @@ func (s *Server) getProviders() map[string]*oidc.Provider { return pCopy } +// keyRotationCheckInterval is how often a replica asks the store whether a +// rotation is due: a tenth of the interval, at most once a minute. The +// deadline itself lives in the store, so a replica that restarts more often +// than the interval still rotates on time. +func keyRotationCheckInterval(interval time.Duration) time.Duration { + return min(time.Minute, interval/10) +} + +// runKeyRotationLoop rotates the signing keys when the deadline the store +// holds (set by Init, advanced by each rotation) has passed. The check runs +// well within the interval, so a control plane that restarts more often +// than it rotates still rotates on time instead of never. func (s *Server) runKeyRotationLoop() { defer s.wg.Done() - if s.config.KeyRotationInterval <= 0 { + interval := s.config.KeyRotationInterval + if interval <= 0 { return } - ticker := time.NewTicker(s.config.KeyRotationInterval) + ticker := time.NewTicker(keyRotationCheckInterval(interval)) defer ticker.Stop() for { select { case <-ticker.C: - // Replicas share one DB but tick independently; only the replica - // that wins this claim may rotate for the current window. - now := time.Now() - claimed, err := s.store.ClaimKeyRotation(s.ctx, now, s.config.KeyRotationInterval) - if err != nil { - logger.Errorf("Failed to claim key rotation window: %v", err) - continue - } - if !claimed { - logger.Debug("Skipping key rotation: another replica already claimed this window") - continue - } - - logger.Info("Rotating Biscuit signing keys...") - newPub, newPriv, err := ed25519.GenerateKey(rand.Reader) - if err != nil { - logger.Errorf("Failed to generate key pair for rotation: %v", err) - // Give up the window so a retry isn't stuck waiting a full interval. - if relErr := s.store.ReleaseKeyRotationClaim(s.ctx, now, s.config.KeyRotationInterval); relErr != nil { - logger.Errorf("Failed to release key rotation claim: %v", relErr) - } - continue - } - err = s.store.RotateKeys(s.ctx, newPriv, newPub, s.config.KeyGracePeriod) - if err != nil { - logger.Errorf("Failed to rotate keyring: %v", err) - // Same as above: don't let a failed rotation strand the mesh - // on unrotated keys until the next full interval. - if relErr := s.store.ReleaseKeyRotationClaim(s.ctx, now, s.config.KeyRotationInterval); relErr != nil { - logger.Errorf("Failed to release key rotation claim: %v", relErr) - } - } else { - logger.Infof("Key rotation committed. New current public key: %s", hex.EncodeToString(newPub)) - if _, oidcErr := s.RotateOIDCKey(s.config.KeyGracePeriod); oidcErr != nil { - logger.Warnf("Failed to rotate OIDC signing key: %v", oidcErr) - } - if err := s.getMeshAdapter().PublishEvent(s.ctx, api.MeshEvent_KEY_ROTATION, "", newPub); err != nil { - logger.Warnf("Failed to publish KEY_ROTATION event to mesh: %v", err) - } - } + s.rotateKeysIfDue(time.Now()) case <-s.ctx.Done(): return } } } +// rotateKeysIfDue claims the rotation window and rotates when it is due. +// Replicas share one store and check independently; only the one that wins +// the claim rotates for this window. +func (s *Server) rotateKeysIfDue(now time.Time) { + interval := s.config.KeyRotationInterval + claimed, err := s.store.ClaimKeyRotation(s.ctx, now, interval) + if err != nil { + logger.Errorf("Failed to claim key rotation window: %v", err) + return + } + if !claimed { + return + } + + logger.Info("Rotating Biscuit signing keys...") + newPub, newPriv, err := ed25519.GenerateKey(rand.Reader) + if err != nil { + logger.Errorf("Failed to generate key pair for rotation: %v", err) + // Give up the window so a retry isn't stuck waiting a full interval. + if relErr := s.store.ReleaseKeyRotationClaim(s.ctx, now, interval); relErr != nil { + logger.Errorf("Failed to release key rotation claim: %v", relErr) + } + return + } + if err := s.store.RotateKeys(s.ctx, newPriv, newPub, s.config.KeyGracePeriod); err != nil { + logger.Errorf("Failed to rotate keyring: %v", err) + // Same as above: don't let a failed rotation strand the mesh + // on unrotated keys until the next full interval. + if relErr := s.store.ReleaseKeyRotationClaim(s.ctx, now, interval); relErr != nil { + logger.Errorf("Failed to release key rotation claim: %v", relErr) + } + return + } + logger.Infof("Key rotation committed. New current public key: %s; next rotation at %s", hex.EncodeToString(newPub), now.Add(interval).UTC().Format(time.RFC3339)) + if _, oidcErr := s.RotateOIDCKey(s.config.KeyGracePeriod); oidcErr != nil { + logger.Warnf("Failed to rotate OIDC signing key: %v", oidcErr) + } + if err := s.getMeshAdapter().PublishEvent(s.ctx, api.MeshEvent_KEY_ROTATION, "", newPub); err != nil { + logger.Warnf("Failed to publish KEY_ROTATION event to mesh: %v", err) + } +} + // HandleHealthz HTTP GET `/healthz` func (s *Server) HandleHealthz(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodGet { diff --git a/internal/storage/sql_store.go b/internal/storage/sql_store.go index 6ca97f52..f7e75157 100644 --- a/internal/storage/sql_store.go +++ b/internal/storage/sql_store.go @@ -857,6 +857,31 @@ func (s *SQLStore) ReleaseKeyRotationClaim(ctx context.Context, now time.Time, i return err } +// ScheduleKeyRotationIfUnset implements Store. +func (s *SQLStore) ScheduleKeyRotationIfUnset(ctx context.Context, at time.Time) (bool, error) { + res, err := s.db.ExecContext(ctx, s.rebind(`UPDATE rotation_lock SET next_rotation_at = ? WHERE id = 1 AND next_rotation_at = 0`), at.UnixMilli()) + if err != nil { + return false, err + } + n, err := res.RowsAffected() + if err != nil { + return false, err + } + return n == 1, nil +} + +// NextKeyRotation implements Store. +func (s *SQLStore) NextKeyRotation(ctx context.Context) (time.Time, error) { + var ms int64 + if err := s.db.QueryRowContext(ctx, `SELECT next_rotation_at FROM rotation_lock WHERE id = 1`).Scan(&ms); err != nil { + return time.Time{}, err + } + if ms == 0 { + return time.Time{}, nil + } + return time.UnixMilli(ms), nil +} + // RotateKeys implements Store. func (s *SQLStore) RotateKeys(ctx context.Context, newPriv ed25519.PrivateKey, newPub ed25519.PublicKey, gracePeriod time.Duration) error { tx, err := s.db.BeginTx(ctx, nil) diff --git a/internal/storage/sql_store_test.go b/internal/storage/sql_store_test.go index 1158a029..7ffd234b 100644 --- a/internal/storage/sql_store_test.go +++ b/internal/storage/sql_store_test.go @@ -225,6 +225,53 @@ func TestClaimKeyRotation(t *testing.T) { } } +func TestScheduleKeyRotationIfUnset(t *testing.T) { + store := newTestStore(t) + defer func() { _ = store.Close() }() + ctx := context.Background() + t0 := time.Now().Truncate(time.Millisecond) + interval := 24 * time.Hour + + next, err := store.NextKeyRotation(ctx) + if err != nil { + t.Fatal(err) + } + if !next.IsZero() { + t.Fatalf("fresh store has a rotation deadline %s, want none", next) + } + + // The first replica to start schedules; a replica starting later, or + // the same one restarting, leaves the deadline alone. + scheduled, err := store.ScheduleKeyRotationIfUnset(ctx, t0.Add(interval)) + if err != nil { + t.Fatal(err) + } + if !scheduled { + t.Fatal("first schedule on a fresh store was not applied") + } + scheduled, err = store.ScheduleKeyRotationIfUnset(ctx, t0.Add(time.Hour)) + if err != nil { + t.Fatal(err) + } + if scheduled { + t.Fatal("a second schedule replaced the deadline; want it kept") + } + if next, _ = store.NextKeyRotation(ctx); !next.Equal(t0.Add(interval)) { + t.Fatalf("deadline = %s, want %s", next, t0.Add(interval)) + } + + // Not due before the deadline, due at it; a claim moves it one interval on. + if claimed, _ := store.ClaimKeyRotation(ctx, t0.Add(interval-time.Second), interval); claimed { + t.Fatal("claim before the deadline succeeded") + } + if claimed, _ := store.ClaimKeyRotation(ctx, t0.Add(interval), interval); !claimed { + t.Fatal("claim at the deadline failed") + } + if next, _ = store.NextKeyRotation(ctx); !next.Equal(t0.Add(2 * interval)) { + t.Fatalf("deadline after the claim = %s, want %s", next, t0.Add(2*interval)) + } +} + func TestReleaseKeyRotationClaim(t *testing.T) { store := newTestStore(t) defer func() { _ = store.Close() }() diff --git a/internal/storage/storage.go b/internal/storage/storage.go index 52ad4730..ca9095a1 100644 --- a/internal/storage/storage.go +++ b/internal/storage/storage.go @@ -248,6 +248,15 @@ type Store interface { // the rotation that followed a successful claim failed. ReleaseKeyRotationClaim(ctx context.Context, now time.Time, interval time.Duration) error + // ScheduleKeyRotationIfUnset sets the first rotation deadline of a store + // that never had one, and reports whether it did. A store that already + // carries a deadline, due or not, is left as it is. + ScheduleKeyRotationIfUnset(ctx context.Context, at time.Time) (bool, error) + + // NextKeyRotation is the deadline ClaimKeyRotation will honour: the + // instant the next rotation is due, zero when none was ever scheduled. + NextKeyRotation(ctx context.Context) (time.Time, error) + // SaveInitialKey sets the initial key pair if no keys exist yet. SaveInitialKey(ctx context.Context, priv ed25519.PrivateKey, pub ed25519.PublicKey) error diff --git a/site/content/docs/reference/control-plane.md b/site/content/docs/reference/control-plane.md index b0d0d50f..c35086d3 100644 --- a/site/content/docs/reference/control-plane.md +++ b/site/content/docs/reference/control-plane.md @@ -149,6 +149,13 @@ with `403`). The console uses these routes. - **Bans propagate in two ways.** `/info` lists banned peer IDs for nodes and routers that start or restart. A signed mesh event reaches the ones that are already running. +- **The rotation deadline is in the database.** The first rotation is due + one `--key-rotation-interval` after the first start, each rotation sets + the next, and every replica checks the deadline at least once a minute. + A control plane that restarts more often than it rotates still rotates on + time, and one that was down when a rotation was due rotates on its first + check. `agentmesh_control_plane_next_key_rotation_timestamp_seconds` is + the deadline; a value in the past is a rotation that is not happening. - **Node records are garbage-collected.** A node whose session has expired is deleted after `--node-retention`. A node enrolled with a bootstrap token has no session; its record is deleted once it has not refreshed its From f40c9f35456c26d3fe1e40c92c550e9bb0bf6dbc Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 18:33:21 +0000 Subject: [PATCH 3/7] node, bench: /readyz tells the truth on every listener; a member binds no loopback port The sidecar's /readyz answered 200 from the moment the process was up, on the socket and on TCP, while the metrics listener's /readyz waited for an authenticated, connected router. A probe or a harness reading the sidecar learned nothing. Both listeners now give the same answer, and a node without an identity yet is not ready. agentmesh-bench gave member i the loopback port 20000+i for /readyz. On ladder 17 the minions' ephemeral range covered those ports, the kernel handed some of them to other members' libp2p listeners, and 4% of the fleet died at start with "address already in use". The bench now reads readiness over the member's Unix socket, as it already does for discovery and the first call, and passes no --metrics-addr: a fleet of any size binds no loopback port. --metrics-base-port is gone with it. The bench's fake node refuses any --metrics-addr or --bind-addr, so a member that binds a port again fails every bench test; the sidecar test pins 503 then 200 on both listeners as a router is authenticated. --- cmd/agentmesh-bench/main.go | 1 - internal/bench/join.go | 66 ++++++++++------------ internal/bench/join_test.go | 55 +++++------------- internal/node/sidecar.go | 22 ++++++-- internal/node/sidecar_auth_test.go | 77 ++++++++++++++++++++++++++ internal/node/sidecar_test.go | 3 +- tests/integration/member_burst_test.go | 25 --------- tests/scale/member-journey.sh | 13 ++--- 8 files changed, 144 insertions(+), 118 deletions(-) diff --git a/cmd/agentmesh-bench/main.go b/cmd/agentmesh-bench/main.go index 3968e77b..01b69d1a 100644 --- a/cmd/agentmesh-bench/main.go +++ b/cmd/agentmesh-bench/main.go @@ -282,7 +282,6 @@ func newJoinCmd() *cobra.Command { flags.DurationVar(&opts.CallTimeout, "call-timeout", 120*time.Second, "Bound on one member's discovery and first call, from readiness") flags.DurationVar(&opts.Hold, "hold", 0, "Keep the fleet resident this long after the journeys end, sampling readiness; 0 tears it down at once") flags.DurationVar(&opts.SampleInterval, "sample-interval", 10*time.Second, "How often each resident member's readiness is read during --hold") - flags.IntVar(&opts.MetricsBasePort, "metrics-base-port", 20000, "Member i serves /readyz on 127.0.0.1:(port+i)") flags.StringArrayVar(&opts.NodeArgs, "node-arg", nil, "Extra argument for every agentmesh-node, repeatable (e.g. --node-arg=--insecure-control-plane)") flags.StringVar(&marker, "resident-marker", "", "File to create once the fleet is resident and the hold has begun") flags.StringArrayVar(&scrape, "scrape", nil, "Metrics endpoint to record before and after the run, repeatable") diff --git a/internal/bench/join.go b/internal/bench/join.go index 91eceb64..ac7904eb 100644 --- a/internal/bench/join.go +++ b/internal/bench/join.go @@ -93,10 +93,6 @@ type JoinOptions struct { // SampleInterval is how often each resident member is read during Hold. SampleInterval time.Duration - // MetricsBasePort is the first of Count consecutive loopback ports; - // member i serves /readyz on MetricsBasePort+i. - MetricsBasePort int - // NodeArgs are appended to every member's command line as given. NodeArgs []string @@ -208,6 +204,7 @@ const ( // and one that takes a minute is not asked a thousand times. readyPollMin = 50 * time.Millisecond readyPollMax = 500 * time.Millisecond + readyTimeout = 2 * time.Second callRetryInterval = 5 * time.Second requestTimeout = 30 * time.Second teardownGrace = 10 * time.Second @@ -222,17 +219,19 @@ const ( const mcpInitialize = `{"jsonrpc":"2.0","id":1,"method":"initialize","params":{"protocolVersion":"2025-06-18","capabilities":{},"clientInfo":{"name":"agentmesh-bench","version":"0"}}}` type member struct { - index int - dir string - socket string - metricsAddr string - readyz string - logPath string - cmd *exec.Cmd - logFile *os.File - started time.Time - exited chan struct{} - exitErr error + index int + dir string + socket string + // client speaks to the member over its Unix socket: readiness, discovery + // and the first call. A member binds no loopback port, so a fleet of any + // size cannot collide with the kernel's ephemeral range. + client *http.Client + logPath string + cmd *exec.Cmd + logFile *os.File + started time.Time + exited chan struct{} + exitErr error readyAt time.Time calledAt time.Time @@ -364,9 +363,6 @@ func (o *JoinOptions) setDefaults() { if o.SampleInterval <= 0 { o.SampleInterval = 10 * time.Second } - if o.MetricsBasePort <= 0 { - o.MetricsBasePort = 20000 - } } func (o *JoinOptions) logf(format string, args ...any) { @@ -378,14 +374,13 @@ func (o *JoinOptions) logf(format string, args ...any) { func newMember(opts JoinOptions, i int) *member { dir := filepath.Join(opts.Dir, fmt.Sprintf("member-%04d", i)) - metricsAddr := fmt.Sprintf("127.0.0.1:%d", opts.MetricsBasePort+i) + socket := filepath.Join(dir, "node.sock") return &member{ - index: i, - dir: dir, - socket: filepath.Join(dir, "node.sock"), - metricsAddr: metricsAddr, - readyz: "http://" + metricsAddr + "/readyz", - logPath: filepath.Join(dir, "node.log"), + index: i, + dir: dir, + socket: socket, + client: unixClient(socket), + logPath: filepath.Join(dir, "node.log"), } } @@ -407,7 +402,6 @@ func (m *member) start(opts JoinOptions) error { "--data-dir", m.dir, "--socket-path", m.socket, "--bind-addr=", - "--metrics-addr", m.metricsAddr, "--listen", "/ip4/0.0.0.0/tcp/0", "--listen", "/ip4/0.0.0.0/udp/0/quic-v1", } @@ -456,11 +450,10 @@ func journey(ctx context.Context, opts JoinOptions, m *member) { // waitReady polls the member's /readyz, which answers 200 only once the node // holds an authenticated connection to a router. func (m *member) waitReady(ctx context.Context, timeout time.Duration) error { - client := &http.Client{Timeout: 2 * time.Second} deadline := time.Now().Add(timeout) interval := readyPollMin for { - if isReady(ctx, client, m.readyz) { + if m.isReady(ctx) { m.readyAt = time.Now() return nil } @@ -481,12 +474,14 @@ func (m *member) waitReady(ctx context.Context, timeout time.Duration) error { } } -func isReady(ctx context.Context, client *http.Client, url string) bool { - req, err := http.NewRequestWithContext(ctx, http.MethodGet, url, nil) +func (m *member) isReady(ctx context.Context) bool { + ctx, cancel := context.WithTimeout(ctx, readyTimeout) + defer cancel() + req, err := http.NewRequestWithContext(ctx, http.MethodGet, "http://localhost/readyz", nil) if err != nil { return false } - resp, err := client.Do(req) + resp, err := m.client.Do(req) if err != nil { return false } @@ -500,7 +495,7 @@ func isReady(ctx context.Context, client *http.Client, url string) bool { // deadline: a provider record can name a peer a rollout just replaced, and a // member that joined seconds ago has a thin routing table. func (m *member) firstCall(ctx context.Context, opts JoinOptions) error { - client := unixClient(m.socket) + client := m.client defer client.CloseIdleConnections() deadline := m.readyAt.Add(opts.CallTimeout) lastErr := "none discovered" @@ -691,12 +686,11 @@ func hold(ctx context.Context, opts JoinOptions, members []*member) *HoldReport report := &HoldReport{} var outages []time.Duration - client := &http.Client{Timeout: 2 * time.Second} start := time.Now() end := start.Add(opts.Hold) for { now := time.Now() - ready := sampleReady(ctx, client, members) + ready := sampleReady(ctx, members) count := 0 for i, m := range members { if ready[i] { @@ -759,7 +753,7 @@ func hold(ctx context.Context, opts JoinOptions, members []*member) *HoldReport } // sampleReady reads every member's /readyz, a bounded number at a time. -func sampleReady(ctx context.Context, client *http.Client, members []*member) []bool { +func sampleReady(ctx context.Context, members []*member) []bool { ready := make([]bool, len(members)) sem := make(chan struct{}, sampleConcurrency) var wg sync.WaitGroup @@ -772,7 +766,7 @@ func sampleReady(ctx context.Context, client *http.Client, members []*member) [] go func() { defer wg.Done() defer func() { <-sem }() - ready[i] = isReady(ctx, client, m.readyz) + ready[i] = m.isReady(ctx) }() } wg.Wait() diff --git a/internal/bench/join_test.go b/internal/bench/join_test.go index 1ee3306a..1191efb1 100644 --- a/internal/bench/join_test.go +++ b/internal/bench/join_test.go @@ -31,8 +31,11 @@ import ( // The members RunJoin starts are whatever binary it is pointed at. Here that // is this test binary again, re-entered through TestMain as a node that -// answers /readyz and the two sidecar routes the journey uses, with its -// behaviour set through the environment the children inherit. +// answers /readyz and the two sidecar routes the journey uses on its Unix +// socket, with its behaviour set through the environment the children +// inherit. Like the real node it binds no loopback port unless told to, and +// it refuses to be told: a fleet of a thousand on one host collided with the +// kernel's ephemeral range when every member had one. func TestMain(m *testing.M) { if os.Getenv("AGENTMESH_BENCH_FAKE_NODE") == "1" { @@ -42,11 +45,14 @@ func TestMain(m *testing.M) { } func fakeNode(args []string) int { - var metricsAddr, socket, tokenPath string + var socket, tokenPath string for i := 0; i < len(args)-1; i++ { switch args[i] { - case "--metrics-addr": - metricsAddr = args[i+1] + case "--metrics-addr", "--bind-addr": + if args[i+1] != "" { + fmt.Fprintln(os.Stderr, "fake node: a member must not bind a loopback port:", args[i], args[i+1]) + return 4 + } case "--socket-path": socket = args[i+1] case "--bootstrap-token-path": @@ -78,15 +84,14 @@ func fakeNode(args []string) int { return true } - metrics := http.NewServeMux() - metrics.HandleFunc("/readyz", func(w http.ResponseWriter, _ *http.Request) { + sidecar := http.NewServeMux() + sidecar.HandleFunc("/readyz", func(w http.ResponseWriter, _ *http.Request) { if !ready() { http.Error(w, "not ready", http.StatusServiceUnavailable) return } w.WriteHeader(http.StatusOK) }) - sidecar := http.NewServeMux() sidecar.HandleFunc("/mesh/service/discover", func(w http.ResponseWriter, _ *http.Request) { var out []map[string]string for _, p := range providers { @@ -104,17 +109,11 @@ func fakeNode(args []string) int { _, _ = fmt.Fprint(w, `{"jsonrpc":"2.0","id":1,"result":{"protocolVersion":"2025-06-18","serverInfo":{"name":"fake","version":"0"}}}`) }) - tcp, err := net.Listen("tcp", metricsAddr) - if err != nil { - fmt.Fprintln(os.Stderr, "fake node:", err) - return 1 - } unix, err := net.Listen("unix", socket) if err != nil { fmt.Fprintln(os.Stderr, "fake node:", err) return 1 } - go func() { _ = http.Serve(tcp, metrics) }() //nolint:gosec // a test double go func() { _ = http.Serve(unix, sidecar) }() //nolint:gosec // a test double stop := make(chan os.Signal, 1) signal.Notify(stop, syscall.SIGTERM, os.Interrupt) @@ -152,37 +151,9 @@ func fakeFleet(t *testing.T, count int, env map[string]string) JoinOptions { ControlPlane: "http://127.0.0.1:1", BootstrapTokenPath: token, Service: "everything", - MetricsBasePort: freePortBase(t, count), } } -// freePortBase finds count consecutive free loopback ports. -func freePortBase(t *testing.T, count int) int { - t.Helper() - for attempt := 0; attempt < 20; attempt++ { - l, err := net.Listen("tcp", "127.0.0.1:0") - if err != nil { - t.Fatal(err) - } - base := l.Addr().(*net.TCPAddr).Port - _ = l.Close() - free := true - for i := 1; i < count; i++ { - probe, err := net.Listen("tcp", fmt.Sprintf("127.0.0.1:%d", base+i)) - if err != nil { - free = false - break - } - _ = probe.Close() - } - if free { - return base - } - } - t.Fatal("no run of free ports") - return 0 -} - func TestRunJoinTimesEachStageAndRetriesStaleProviders(t *testing.T) { // A provider record that names a peer which does not answer is the // normal state of a mesh just after a rollout. The journey has to get diff --git a/internal/node/sidecar.go b/internal/node/sidecar.go index 79f3fd7b..00ba4b40 100644 --- a/internal/node/sidecar.go +++ b/internal/node/sidecar.go @@ -47,7 +47,7 @@ func StartSidecarServer(node *AgentMeshNode, addr, socketPath, token, certFile, // Public endpoints mux.HandleFunc("/healthz", handleHealthz) - mux.HandleFunc("/readyz", handleReadyz) + mux.HandleFunc("/readyz", handleReadyzFor(node)) mux.HandleFunc("/.well-known/oauth-protected-resource", func(w http.ResponseWriter, r *http.Request) { handleOAuthProtectedResource(node, w, r) }) @@ -315,7 +315,7 @@ func StartUnauthSidecarServer(controlPlaneURL, addr, socketPath, certFile, keyFi // Public endpoints mux.HandleFunc("/healthz", handleHealthz) - mux.HandleFunc("/readyz", handleReadyz) + mux.HandleFunc("/readyz", handleReadyzFor(nil)) // Mount Unauthenticated MCP handler mcpHandler := NewUnauthenticatedMCPHandler(controlPlaneURL) @@ -383,10 +383,20 @@ func handleHealthz(w http.ResponseWriter, r *http.Request) { } } -func handleReadyz(w http.ResponseWriter, r *http.Request) { - w.WriteHeader(http.StatusOK) - if _, err := w.Write([]byte("OK")); err != nil { - logger.Errorf("Failed to write response: %v", err) +// handleReadyzFor answers 200 only once the node holds an authenticated +// connection to a router, the same answer the metrics listener gives, so a +// probe or a harness reading either listener learns the same thing. A node +// without an identity yet (nil) is not ready. +func handleReadyzFor(node *AgentMeshNode) http.HandlerFunc { + return func(w http.ResponseWriter, _ *http.Request) { + if node == nil || node.debugReady() != nil || !node.IsConnected() { + http.Error(w, "not connected to the mesh", http.StatusServiceUnavailable) + return + } + w.WriteHeader(http.StatusOK) + if _, err := w.Write([]byte("OK")); err != nil { + logger.Errorf("Failed to write response: %v", err) + } } } diff --git a/internal/node/sidecar_auth_test.go b/internal/node/sidecar_auth_test.go index b3346524..34405b53 100644 --- a/internal/node/sidecar_auth_test.go +++ b/internal/node/sidecar_auth_test.go @@ -19,6 +19,9 @@ import ( "path/filepath" "testing" "time" + + "github.com/libp2p/go-libp2p" + "github.com/libp2p/go-libp2p/core/peer" ) // TestConstantTimeEqual is a correctness check, not a timing one: a timing @@ -57,6 +60,80 @@ func TestConstantTimeEqual(t *testing.T) { } } +// TestSidecarReadyzFollowsTheMeshConnection pins that the sidecar's /readyz +// says what the metrics listener's does: 503 until the node holds an +// authenticated, connected router, then 200, on the socket and on TCP. A +// harness that reads readiness over the socket, as agentmesh-bench does so +// that a member binds no loopback port, learns the same thing a kubelet +// probing the metrics port would. +func TestSidecarReadyzFollowsTheMeshConnection(t *testing.T) { + store, err := NewStore(t.TempDir()) + if err != nil { + t.Fatal(err) + } + defer func() { _ = store.Close() }() + host, err := libp2p.New(libp2p.ListenAddrStrings("/ip4/127.0.0.1/tcp/0")) + if err != nil { + t.Fatal(err) + } + defer func() { _ = host.Close() }() + node := &AgentMeshNode{ + Host: host, + Store: store, + BiscuitTimeout: 500 * time.Millisecond, + services: NewServiceRegistry(&fakeDHT{}, 0), + } + node.Directory = &routerDirectory{host: host, routers: node.attachedRouters, addrs: host.Addrs} + socketPath := filepath.Join(t.TempDir(), "agentmesh.sock") + srv, err := StartSidecarServer(node, "127.0.0.1:0", socketPath, "test-token", "", "", "") + if err != nil { + t.Fatalf("failed to start sidecar server: %v", err) + } + defer func() { _ = srv.Close() }() + socket := waitForSocket(t, socketPath) + tcp := &http.Client{Timeout: 2 * time.Second} + + readyz := func(t *testing.T, client *http.Client, url string) int { + t.Helper() + resp, err := client.Get(url) + if err != nil { + t.Fatalf("GET %s: %v", url, err) + } + defer func() { _ = resp.Body.Close() }() + return resp.StatusCode + } + for name, url := range map[string]string{"socket": "http://localhost/readyz", "tcp": "http://" + node.BoundHTTPAddr + "/readyz"} { + client := socket + if name == "tcp" { + client = tcp + } + if code := readyz(t, client, url); code != http.StatusServiceUnavailable { + t.Errorf("%s /readyz = %d with no authenticated router, want 503", name, code) + } + } + + routerHost, err := libp2p.New(libp2p.ListenAddrStrings("/ip4/127.0.0.1/tcp/0")) + if err != nil { + t.Fatal(err) + } + defer func() { _ = routerHost.Close() }() + if err := host.Connect(t.Context(), peer.AddrInfo{ID: routerHost.ID(), Addrs: routerHost.Addrs()}); err != nil { + t.Fatal(err) + } + node.mu.Lock() + node.authenticatedRouters = map[peer.ID]bool{routerHost.ID(): true} + node.mu.Unlock() + for name, url := range map[string]string{"socket": "http://localhost/readyz", "tcp": "http://" + node.BoundHTTPAddr + "/readyz"} { + client := socket + if name == "tcp" { + client = tcp + } + if code := readyz(t, client, url); code != http.StatusOK { + t.Errorf("%s /readyz = %d once a router is authenticated and connected, want 200", name, code) + } + } +} + // TestMetricsGatedOnTCPButNotOnTheSocket pins where the metrics endpoint sits in // the sidecar's trust model. Its labels carry peer IDs and per-peer request // counts, and the TCP listener is reachable by any local process, so it is diff --git a/internal/node/sidecar_test.go b/internal/node/sidecar_test.go index 17b55e8a..0f25ea78 100644 --- a/internal/node/sidecar_test.go +++ b/internal/node/sidecar_test.go @@ -399,7 +399,8 @@ func TestSidecarServerAuthEnforcement(t *testing.T) { needsToken bool }{ {"healthz is public", "GET", "/healthz", http.StatusOK, false}, - {"readyz is public", "GET", "/readyz", http.StatusOK, false}, + // Public, and honest: this node holds no router, so it is not ready. + {"readyz is public", "GET", "/readyz", http.StatusServiceUnavailable, false}, // Liveness says nothing; metrics name peers and count their traffic. {"metrics is protected", "GET", "/metrics", http.StatusUnauthorized, false}, // Services are declared in configuration only: the former runtime diff --git a/tests/integration/member_burst_test.go b/tests/integration/member_burst_test.go index e5940169..d1a590bb 100644 --- a/tests/integration/member_burst_test.go +++ b/tests/integration/member_burst_test.go @@ -16,7 +16,6 @@ package integration_test import ( "context" - "fmt" "net" "net/http/httptest" "os" @@ -92,7 +91,6 @@ func TestMemberBurstJoinsConcurrently(t *testing.T) { Service: "everything", ReadyTimeout: 30 * time.Second, CallTimeout: 30 * time.Second, - MetricsBasePort: reservePortBlock(t, members), NodeArgs: []string{"--allow-loopback"}, Log: testLogWriter{t}, }) @@ -134,29 +132,6 @@ func TestMemberBurstJoinsConcurrently(t *testing.T) { members, report.ReadyMs.P50, report.ReadyMs.P95, report.JourneyMs.P50, report.JourneyMs.P95, report.JourneyMs.Max, report.CallAttempts) } -// reservePortBlock finds n consecutive free loopback ports in the reserved -// range and returns the first. -func reservePortBlock(t *testing.T, n int) int { - t.Helper() - for range 50 { - base := getFreePort(t) - free := true - for i := 1; i < n; i++ { - l, err := net.Listen("tcp", fmt.Sprintf("127.0.0.1:%d", base+i)) - if err != nil { - free = false - break - } - _ = l.Close() - } - if free { - return base - } - } - t.Fatalf("no run of %d free ports", n) - return 0 -} - // logTail returns the last part of a log file, for a failure message. func logTail(path string) string { data, err := os.ReadFile(path) // #nosec G304 -- a log the test wrote diff --git a/tests/scale/member-journey.sh b/tests/scale/member-journey.sh index 2c67d100..ee38e309 100755 --- a/tests/scale/member-journey.sh +++ b/tests/scale/member-journey.sh @@ -259,16 +259,15 @@ summarize() { # a backgrounded function is a subshell, and a signal to it would not reach # the run inside. JOIN_CMD=() -join_cmd() { # phase count base-port extra... - local phase="$1" count="$2" base="$3" a - shift 3 +join_cmd() { # phase count extra... + local phase="$1" count="$2" a + shift 2 JOIN_CMD=("$AGENTMESH_BENCH" join --node-bin "$AGENTMESH_NODE" --control-plane "$CONTROL_PLANE" --bootstrap-token-path "$BOOTSTRAP_TOKEN_PATH" --service "$SERVICE" --count "$count" - --metrics-base-port "$base" --dir "$OUT/$phase" --label "phase=$phase" --label "count=$count" --label "burst=$COUNT" --label "host=$(hostname)" --out "$OUT/$phase.json") @@ -288,7 +287,7 @@ rm -f "$OUT/resident" snapshot before event burst-start log "burst: ${COUNT} members at ${RAMP}/s, then holding ${HOLD}" -join_cmd burst "$COUNT" 20000 --ramp "$RAMP" --hold "$HOLD" --resident-marker "$OUT/resident" +join_cmd burst "$COUNT" --ramp "$RAMP" --hold "$HOLD" --resident-marker "$OUT/resident" "${JOIN_CMD[@]}" 2> "$OUT/burst.log" & JOIN_PID=$! while [[ ! -f "$OUT/resident" ]]; do @@ -309,7 +308,7 @@ PY if (( LATE > 0 )); then event late-start log "late: ${LATE} members join the populated mesh" - join_cmd late "$LATE" 30000 + join_cmd late "$LATE" "${JOIN_CMD[@]}" 2> "$OUT/late.log" || log "late phase did not run cleanly; see $OUT/late.log" event late-end fi @@ -326,7 +325,7 @@ if (( ROLLOUT )); then # timer; a long bound here measures that wait instead of hiding it. event late-after-rollout-start log "late: ${LATE} members join behind the rollout" - join_cmd late-after-rollout "$LATE" 31000 --ready-timeout 600s + join_cmd late-after-rollout "$LATE" --ready-timeout 600s "${JOIN_CMD[@]}" 2> "$OUT/late-after-rollout.log" \ || log "late-after-rollout phase did not run cleanly; see $OUT/late-after-rollout.log" event late-after-rollout-end From 20ea68356da318c6044213aeccc9581c55cc8f81 Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 18:43:28 +0000 Subject: [PATCH 4/7] controlplane, storage: the metrics snapshot counts enrollment requests instead of listing them The mesh state snapshot, read every 30s, listed every enrollment request with its public key and biscuit to count them by status. Within the retention a busy mesh holds one row per enrollment, tens of thousands, and on ladder 17 the snapshot missed its 5s budget once at full load. CountEnrollmentRequests is one GROUP BY, as CountNodes is for nodes; the admin view keeps the list. --- internal/controlplane/metrics.go | 8 +++-- internal/storage/round_trip_test.go | 47 +++++++++++++++++++++++++++++ internal/storage/sql_store.go | 20 ++++++++++++ internal/storage/storage.go | 3 ++ 4 files changed, 75 insertions(+), 3 deletions(-) diff --git a/internal/controlplane/metrics.go b/internal/controlplane/metrics.go index 22a8483b..47d382dd 100644 --- a/internal/controlplane/metrics.go +++ b/internal/controlplane/metrics.go @@ -323,12 +323,14 @@ func readMeshSnapshot(ctx context.Context, store storage.Store, now time.Time) ( } snap.users = len(users) - reqs, err := store.ListEnrollmentRequests(ctx) + // A count, not a list: the table holds one row per enrollment within the + // retention, tens of thousands on a busy mesh, and this runs every 30s. + requests, err := store.CountEnrollmentRequests(ctx) if err != nil { return snap, err } - for _, r := range reqs { - snap.enrollmentRequests[enrollmentStatusLabel(r.Status)]++ + for status, n := range requests { + snap.enrollmentRequests[enrollmentStatusLabel(status)] += int(n) } tokens, err := store.ListBootstrapTokens(ctx) diff --git a/internal/storage/round_trip_test.go b/internal/storage/round_trip_test.go index 721fd46f..7a0512e9 100644 --- a/internal/storage/round_trip_test.go +++ b/internal/storage/round_trip_test.go @@ -17,6 +17,7 @@ package storage import ( "context" "errors" + "fmt" "reflect" "slices" "strconv" @@ -388,6 +389,52 @@ func TestDeleteStaleEnrollmentRecords(t *testing.T) { } } +func TestCountEnrollmentRequestsByStatus(t *testing.T) { + store := newTestStore(t) + ctx := context.Background() + now := time.Now() + if err := store.SaveBootstrapToken(ctx, &BootstrapToken{ID: "tok", TokenHash: "hash", Role: api.RoleNode, MaxUsages: 10, CreatedAt: now, ExpiresAt: now.Add(time.Hour)}); err != nil { + t.Fatal(err) + } + for i, status := range []api.EnrollmentStatus{ + api.EnrollmentStatus_ENROLLMENT_STATUS_PENDING, + api.EnrollmentStatus_ENROLLMENT_STATUS_APPROVED, + api.EnrollmentStatus_ENROLLMENT_STATUS_APPROVED, + api.EnrollmentStatus_ENROLLMENT_STATUS_REJECTED, + } { + if err := store.CreateEnrollmentRequest(ctx, &EnrollmentRequest{ + ID: fmt.Sprintf("req-%d", i), PeerID: fmt.Sprintf("peer-%d", i), PublicKey: []byte("pub"), TokenID: "tok", Status: status, CreatedAt: now, + }); err != nil { + t.Fatal(err) + } + } + counts, err := store.CountEnrollmentRequests(ctx) + if err != nil { + t.Fatalf("CountEnrollmentRequests: %v", err) + } + want := map[api.EnrollmentStatus]int64{ + api.EnrollmentStatus_ENROLLMENT_STATUS_PENDING: 1, + api.EnrollmentStatus_ENROLLMENT_STATUS_APPROVED: 2, + api.EnrollmentStatus_ENROLLMENT_STATUS_REJECTED: 1, + } + if len(counts) != len(want) { + t.Fatalf("counts = %v, want %v", counts, want) + } + for status, n := range want { + if counts[status] != n { + t.Errorf("%s = %d, want %d", status, counts[status], n) + } + } + // The list and the count agree, so the admin view and the gauge do. + list, err := store.ListEnrollmentRequests(ctx) + if err != nil { + t.Fatal(err) + } + if len(list) != 4 { + t.Errorf("ListEnrollmentRequests returned %d, want 4", len(list)) + } +} + func TestDeleteExpiredRouterLeases(t *testing.T) { store := newTestStore(t) ctx := context.Background() diff --git a/internal/storage/sql_store.go b/internal/storage/sql_store.go index f7e75157..6a266743 100644 --- a/internal/storage/sql_store.go +++ b/internal/storage/sql_store.go @@ -1965,6 +1965,26 @@ func (s *SQLStore) CountNodes(ctx context.Context, now time.Time) ([]NodeCount, return counts, rows.Err() } +// CountEnrollmentRequests implements Store. +func (s *SQLStore) CountEnrollmentRequests(ctx context.Context) (map[api.EnrollmentStatus]int64, error) { + rows, err := s.db.QueryContext(ctx, `SELECT status, COUNT(*) FROM enrollment_requests GROUP BY status`) + if err != nil { + return nil, fmt.Errorf("failed to count enrollment requests: %w", err) + } + defer func() { _ = rows.Close() }() + + counts := make(map[api.EnrollmentStatus]int64) + for rows.Next() { + var status int32 + var n int64 + if err := rows.Scan(&status, &n); err != nil { + return nil, fmt.Errorf("failed to scan enrollment request count: %w", err) + } + counts[api.EnrollmentStatus(status)] = n + } + return counts, rows.Err() +} + // ListBootstrapTokens retrieves all bootstrap tokens. func (s *SQLStore) ListBootstrapTokens(ctx context.Context) ([]BootstrapToken, error) { query := s.rebind(`SELECT id, token_hash, role, owner_id, max_usages, usages_count, description, created_at, expires_at, revoked_at, autonomous_recovery, ephemeral FROM bootstrap_tokens ORDER BY created_at DESC`) diff --git a/internal/storage/storage.go b/internal/storage/storage.go index ca9095a1..b6724ced 100644 --- a/internal/storage/storage.go +++ b/internal/storage/storage.go @@ -377,6 +377,9 @@ type Store interface { // CountNodes counts every enrolled node by role and by its state at now. CountNodes(ctx context.Context, now time.Time) ([]NodeCount, error) + // CountEnrollmentRequests counts the enrollment requests by status. + CountEnrollmentRequests(ctx context.Context) (map[api.EnrollmentStatus]int64, error) + // DeleteExpiredNodes removes enrolled nodes whose session expired before // the given time and that are not banned, returning how many went. A // lapsed session already refuses every refresh, so the row only records From ab4922125c3745c04ae17fabd7b2fc2b8b8b6733 Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 19:09:04 +0000 Subject: [PATCH 5/7] node: a router that refuses a refreshed credential is asked again before it is dropped After a key rotation a node refreshes its credential, now signed by the new key, and shows it to every router it holds a session with. A router that has not synced the new key yet refuses it. The node dropped the router from its authenticated set and left the re-handshake to the connection monitor, a minute later by default: a minute with no router, during which its API answered 503 "not connected to the mesh" to every call. TestKeyRotationIntegration, with a 2s interval and a 500ms router sync, hit that window in about half its runs. A refused re-admission is retried after 500ms, 1s and 2s, which is longer than a router takes to learn a key from the rotation event or its sync, and the router is dropped only after that. The integration test prints the node log when the final call fails, so the next failure can be read instead of reproduced. --- internal/node/node.go | 44 +++++++-- internal/node/readmit_test.go | 145 +++++++++++++++++++++++++++++ tests/integration/rotation_test.go | 2 +- 3 files changed, 181 insertions(+), 10 deletions(-) create mode 100644 internal/node/readmit_test.go diff --git a/internal/node/node.go b/internal/node/node.go index 34128de9..8be81b97 100644 --- a/internal/node/node.go +++ b/internal/node/node.go @@ -1302,13 +1302,19 @@ func (n *AgentMeshNode) authenticateRouterSession(ctx context.Context, router pe return nil } +// readmitRetryDelays spaces the retries of a re-admission a router refused. +// A credential refreshed right after a key rotation is signed by a key the +// router may not have synced yet; it has within a few seconds, so the node +// asks again instead of waiting a monitor interval with no router. +var readmitRetryDelays = []time.Duration{500 * time.Millisecond, time.Second, 2 * time.Second} + // readmitRouters presents the current credential to every router this node // holds an authenticated session with. A router admits a peer until the // biscuit it was shown expires, whatever the connection does, so a refreshed // credential must be shown on the live session or relay circuits to this -// node are refused once the old one lapses. A router that refuses is -// dropped from the authenticated set; the connection monitor then dials and -// handshakes afresh. +// node are refused once the old one lapses. A router that still refuses +// after the retries is dropped from the authenticated set; the connection +// monitor then dials and handshakes afresh. func (n *AgentMeshNode) readmitRouters(ctx context.Context) { if n.Host == nil { return @@ -1318,16 +1324,36 @@ func (n *AgentMeshNode) readmitRouters(ctx context.Context) { return } for _, router := range n.authenticatedRouterIDs() { + n.readmitRouter(ctx, router, biscuitBytes) + } +} + +func (n *AgentMeshNode) readmitRouter(ctx context.Context, router peer.ID, biscuitBytes []byte) { + var err error + for attempt := 0; ; attempt++ { routerCtx, cancel := context.WithTimeout(ctx, n.config.RouterConnectTimeout) - err := n.authenticateRouterSession(routerCtx, router, biscuitBytes) + err = n.authenticateRouterSession(routerCtx, router, biscuitBytes) cancel() - if err != nil { - logger.Warnf("[AuthN] Router %s did not accept the refreshed credential; the connection monitor will re-handshake: %v", router, err) - n.mu.Lock() - delete(n.authenticatedRouters, router) - n.mu.Unlock() + if err == nil { + if attempt > 0 { + logger.Infow("[AuthN] Router accepted the refreshed credential on retry", "router", router, "attempt", attempt+1) + } + return + } + if attempt >= len(readmitRetryDelays) { + break + } + logger.Warnw("[AuthN] Router did not accept the refreshed credential; retrying", "router", router, "attempt", attempt+1, "retry_in", readmitRetryDelays[attempt], "error", err) + select { + case <-ctx.Done(): + return + case <-time.After(readmitRetryDelays[attempt]): } } + logger.Warnw("[AuthN] Router did not accept the refreshed credential; the connection monitor will re-handshake", "router", router, "attempts", len(readmitRetryDelays)+1, "error", err) + n.mu.Lock() + delete(n.authenticatedRouters, router) + n.mu.Unlock() } func (n *AgentMeshNode) performRouterAuthHandshake(s network.Stream, biscuitBytes []byte, expectedRouter peer.ID) (bool, error) { diff --git a/internal/node/readmit_test.go b/internal/node/readmit_test.go new file mode 100644 index 00000000..8f55fa59 --- /dev/null +++ b/internal/node/readmit_test.go @@ -0,0 +1,145 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package node + +import ( + "context" + "crypto/ed25519" + "sync/atomic" + "testing" + "time" + + "github.com/eclipse-biscuit/biscuit-go/v2" + "github.com/libp2p/go-libp2p" + "github.com/libp2p/go-libp2p/core/host" + "github.com/libp2p/go-libp2p/core/network" + "github.com/libp2p/go-libp2p/core/peer" + "github.com/libp2p/go-msgio" + "google.golang.org/protobuf/proto" + + "github.com/google/agentmesh/api" +) + +// A router that refuses the first handshakes, as one does when a node shows a +// credential under a key the router has not synced yet, then accepts. +func startRefusingRouter(t *testing.T, cpPriv ed25519.PrivateKey, refusals int32) (host.Host, *atomic.Int32) { + t.Helper() + h, err := libp2p.New(libp2p.ListenAddrStrings("/ip4/127.0.0.1/tcp/0")) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = h.Close() }) + builder := biscuit.NewBuilder(cpPriv) + for _, f := range []biscuit.Fact{ + {Predicate: biscuit.Predicate{Name: api.FactNode, IDs: []biscuit.Term{biscuit.String(h.ID().String())}}}, + {Predicate: biscuit.Predicate{Name: api.FactRole, IDs: []biscuit.Term{biscuit.String(api.RoleRouter)}}}, + {Predicate: biscuit.Predicate{Name: api.FactExpiration, IDs: []biscuit.Term{biscuit.Date(time.Now().Add(24 * time.Hour))}}}, + api.MarkerFact(api.FactTargetUnrestricted), + } { + if err := builder.AddAuthorityFact(f); err != nil { + t.Fatal(err) + } + } + tok, err := builder.Build() + if err != nil { + t.Fatal(err) + } + routerBiscuit, err := tok.Serialize() + if err != nil { + t.Fatal(err) + } + var handshakes atomic.Int32 + h.SetStreamHandler(api.AuthProtocolID, func(s network.Stream) { + defer func() { _ = s.Close() }() + reader := msgio.NewVarintReaderSize(s, 1024*64) + msg, err := reader.ReadMsg() + if err != nil { + return + } + reader.ReleaseMsg(msg) + resp := &api.AuthResponse{Success: true, Biscuit: routerBiscuit} + if handshakes.Add(1) <= refusals { + resp = &api.AuthResponse{Success: false, Error: "no valid key found for verification"} + } + data, err := proto.Marshal(resp) + if err != nil { + return + } + _ = msgio.NewVarintWriter(s).WriteMsg(data) + }) + return h, &handshakes +} + +// newReadmitTestNode is a node holding an authenticated session with router, +// connected to it, with a refreshed credential to show. +func newReadmitTestNode(t *testing.T, cpPub ed25519.PublicKey, router host.Host) *AgentMeshNode { + t.Helper() + h, err := libp2p.New(libp2p.ListenAddrStrings("/ip4/127.0.0.1/tcp/0")) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = h.Close() }) + if err := h.Connect(t.Context(), peer.AddrInfo{ID: router.ID(), Addrs: router.Addrs()}); err != nil { + t.Fatal(err) + } + n := &AgentMeshNode{ + Host: h, + BiscuitTimeout: 2 * time.Second, + authenticatedRouters: map[peer.ID]bool{router.ID(): true}, + trustedKeys: []TrustedKey{{Key: cpPub, ReceivedAt: time.Now()}}, + } + n.config.RouterConnectTimeout = 2 * time.Second + n.cachedIdentity.Store([]byte("refreshed-credential")) + return n +} + +// TestReadmitRetriesARouterThatHasNotSyncedTheNewKey pins the window after a +// key rotation: the node refreshes under the new key and shows it to its +// routers at once; a router that has not synced the key yet refuses. The +// node asks again within seconds and keeps the session, instead of dropping +// the router and serving 503 until the connection monitor's next minute. +func TestReadmitRetriesARouterThatHasNotSyncedTheNewKey(t *testing.T) { + cpPub, cpPriv, _ := ed25519.GenerateKey(nil) + router, handshakes := startRefusingRouter(t, cpPriv, 2) + n := newReadmitTestNode(t, cpPub, router) + + start := time.Now() + n.readmitRouters(t.Context()) + if got := handshakes.Load(); got != 3 { + t.Fatalf("router saw %d handshakes, want 3: two refusals and the one that succeeded", got) + } + if !n.IsConnected() { + t.Fatal("the router accepted the third handshake, but the node dropped it from the authenticated set") + } + if elapsed := time.Since(start); elapsed > 4*time.Second { + t.Errorf("re-admission took %s; the retries should fit in a few seconds", elapsed) + } +} + +// A router that keeps refusing is dropped after the retries, so the monitor +// dials and handshakes afresh, as before. +func TestReadmitDropsARouterThatKeepsRefusing(t *testing.T) { + cpPub, cpPriv, _ := ed25519.GenerateKey(nil) + router, handshakes := startRefusingRouter(t, cpPriv, 100) + n := newReadmitTestNode(t, cpPub, router) + + n.readmitRouters(context.Background()) + if got, want := handshakes.Load(), int32(len(readmitRetryDelays)+1); got != want { + t.Fatalf("router saw %d handshakes, want %d", got, want) + } + if n.IsConnected() { + t.Fatal("a router that refused every handshake is still in the authenticated set") + } +} diff --git a/tests/integration/rotation_test.go b/tests/integration/rotation_test.go index 59c4344b..7c62fe2c 100644 --- a/tests/integration/rotation_test.go +++ b/tests/integration/rotation_test.go @@ -211,7 +211,7 @@ roles: "-args", "{}", ) if err != nil { - t.Fatalf("failed to query node: %v\nstdout: %s\nstderr: %s", err, stdout, stderr) + t.Fatalf("failed to query node: %v\nstdout: %s\nstderr: %s\n--- node.log ---\n%s", err, stdout, stderr, readLog(t, nodeLogPath)) } if !strings.Contains(stdout, "attached_routers") { t.Fatalf("unexpected node response: %s", stdout) From 87771ef78e980991ab5ffc974b1433902dffa4b7 Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 19:13:50 +0000 Subject: [PATCH 6/7] scale: a dropped ssh session does not end the ladder's hold The hold ran while pgrep over ssh found agentmesh-bench on the first minion, so one IAP tunnel failure read as the run having ended: ladder 17's 90-minute hold was cut at 35. Exit 1 from pgrep ends the hold; any other exit is logged and checked again a minute later. --- tests/scale/member-ladder.sh | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/tests/scale/member-ladder.sh b/tests/scale/member-ladder.sh index 3b13057f..6d43a7db 100755 --- a/tests/scale/member-ladder.sh +++ b/tests/scale/member-ladder.sh @@ -237,5 +237,14 @@ for step in "${STEPS[@]}"; do done log "ladder complete: ${resident} members resident; holding until Ctrl-C or ${HOLD}" -# Stay until the first minion's hold ends or the operator interrupts. -while rssh "${STARTED_MINIONS[0]}" "pgrep -x agentmesh-bench >/dev/null"; do sleep 60; done +# Stay until the first minion's hold ends or the operator interrupts. The +# check tells "the run ended" (pgrep exits 1) from "ssh did not get through" +# (255): an IAP tunnel drops now and then, and a dropped session must not +# end a hold that carries thousands of members. +while :; do + rc=0 + rssh "${STARTED_MINIONS[0]}" "pgrep -x agentmesh-bench >/dev/null" || rc=$? + if [[ $rc -eq 1 ]]; then break; fi + if [[ $rc -ne 0 ]]; then log "could not reach ${STARTED_MINIONS[0]} to check the hold (ssh exit ${rc}); checking again"; fi + sleep 60 +done From 05c614c45b576bac40cc80d20ba037530d45596b Mon Sep 17 00:00:00 2001 From: Antonio Ojea Date: Thu, 15 Oct 2026 19:45:38 +0000 Subject: [PATCH 7/7] storage: a node enrolled without a last-seen instant is seen now TestUserStatusAndTenancy failed in CI with "expected 1 node for User A, got: 0". The test, like fifteen others in the package, enrolls a node with no EnrolledAt; the store wrote the zero time, and the storage sweep that runs when the server starts read it as a bootstrap member silent for two thousand years and collected it, when its goroutine won the race against the test's insert. An unset EnrolledAt is recorded as now. A receiver treats an unset instant as invalid, never as the epoch; every handler sets it, and a row written without one is a member seen at the write. Twelve runs of the test pinned to one CPU pass. Review: the rotation tests check every error they used to discard. --- internal/controlplane/key_rotation_test.go | 6 ++++- internal/storage/round_trip_test.go | 28 ++++++++++++++++++++++ internal/storage/sql_store.go | 3 +++ internal/storage/sql_store_test.go | 24 +++++++++++++++---- internal/storage/storage.go | 4 +++- 5 files changed, 59 insertions(+), 6 deletions(-) diff --git a/internal/controlplane/key_rotation_test.go b/internal/controlplane/key_rotation_test.go index efb6fd4c..6a7bc723 100644 --- a/internal/controlplane/key_rotation_test.go +++ b/internal/controlplane/key_rotation_test.go @@ -87,7 +87,11 @@ func TestRotateKeysIfDueFollowsTheStoredDeadline(t *testing.T) { if got := keys(); got != 2 { t.Fatalf("a check past the deadline did not rotate: %d keys, want 2", got) } - if next, _ = store.NextKeyRotation(ctx); !next.Equal(late.Add(interval).Truncate(time.Millisecond)) { + next, err = store.NextKeyRotation(ctx) + if err != nil { + t.Fatal(err) + } + if !next.Equal(late.Add(interval).Truncate(time.Millisecond)) { t.Fatalf("deadline after the late rotation = %s, want %s", next, late.Add(interval)) } srv.rotateKeysIfDue(late.Add(time.Minute)) diff --git a/internal/storage/round_trip_test.go b/internal/storage/round_trip_test.go index 7a0512e9..25b2d812 100644 --- a/internal/storage/round_trip_test.go +++ b/internal/storage/round_trip_test.go @@ -435,6 +435,34 @@ func TestCountEnrollmentRequestsByStatus(t *testing.T) { } } +// A node written without a last-seen instant is seen now, not at the zero +// time: the silent-member sweep would otherwise collect it on the control +// plane's first sweep, which raced with every test that enrolled a node +// this way (TestUserStatusAndTenancy failed so in CI). +func TestEnrollNodeWithoutEnrolledAtIsSeenNow(t *testing.T) { + store := newTestStore(t) + ctx := context.Background() + before := time.Now().Add(-time.Second) + node := &EnrolledNode{PeerID: "fresh", PublicKey: []byte("pub"), Biscuit: []byte("b"), Role: api.RoleNode} + if err := store.EnrollNode(ctx, node); err != nil { + t.Fatal(err) + } + got, err := store.GetNode(ctx, "fresh") + if err != nil { + t.Fatal(err) + } + if got.EnrolledAt.Before(before) { + t.Fatalf("EnrolledAt = %s, want about now", got.EnrolledAt) + } + regular, ephemeral, err := store.DeleteSilentBootstrapNodes(ctx, time.Now().Add(-30*24*time.Hour), time.Now().Add(-time.Hour)) + if err != nil { + t.Fatal(err) + } + if regular != 0 || ephemeral != 0 { + t.Fatalf("the sweep deleted regular=%d ephemeral=%d rows; a node enrolled now is not silent", regular, ephemeral) + } +} + func TestDeleteExpiredRouterLeases(t *testing.T) { store := newTestStore(t) ctx := context.Background() diff --git a/internal/storage/sql_store.go b/internal/storage/sql_store.go index 6a266743..266e7dd1 100644 --- a/internal/storage/sql_store.go +++ b/internal/storage/sql_store.go @@ -927,6 +927,9 @@ func (s *SQLStore) EnrollNode(ctx context.Context, node *EnrolledNode) error { if err != nil { return fmt.Errorf("failed to marshal labels: %w", err) } + if node.EnrolledAt.IsZero() { + node.EnrolledAt = time.Now() + } var query string if s.isPostgres() { diff --git a/internal/storage/sql_store_test.go b/internal/storage/sql_store_test.go index 7ffd234b..31040ddf 100644 --- a/internal/storage/sql_store_test.go +++ b/internal/storage/sql_store_test.go @@ -256,18 +256,34 @@ func TestScheduleKeyRotationIfUnset(t *testing.T) { if scheduled { t.Fatal("a second schedule replaced the deadline; want it kept") } - if next, _ = store.NextKeyRotation(ctx); !next.Equal(t0.Add(interval)) { + next, err = store.NextKeyRotation(ctx) + if err != nil { + t.Fatal(err) + } + if !next.Equal(t0.Add(interval)) { t.Fatalf("deadline = %s, want %s", next, t0.Add(interval)) } // Not due before the deadline, due at it; a claim moves it one interval on. - if claimed, _ := store.ClaimKeyRotation(ctx, t0.Add(interval-time.Second), interval); claimed { + claimed, err := store.ClaimKeyRotation(ctx, t0.Add(interval-time.Second), interval) + if err != nil { + t.Fatal(err) + } + if claimed { t.Fatal("claim before the deadline succeeded") } - if claimed, _ := store.ClaimKeyRotation(ctx, t0.Add(interval), interval); !claimed { + claimed, err = store.ClaimKeyRotation(ctx, t0.Add(interval), interval) + if err != nil { + t.Fatal(err) + } + if !claimed { t.Fatal("claim at the deadline failed") } - if next, _ = store.NextKeyRotation(ctx); !next.Equal(t0.Add(2 * interval)) { + next, err = store.NextKeyRotation(ctx) + if err != nil { + t.Fatal(err) + } + if !next.Equal(t0.Add(2 * interval)) { t.Fatalf("deadline after the claim = %s, want %s", next, t0.Add(2*interval)) } } diff --git a/internal/storage/storage.go b/internal/storage/storage.go index b6724ced..80ccb070 100644 --- a/internal/storage/storage.go +++ b/internal/storage/storage.go @@ -269,7 +269,9 @@ type Store interface { // ListUsers retrieves all registered users. ListUsers(ctx context.Context) ([]User, error) - // EnrollNode registers or updates a node enrollment. + // EnrollNode registers or updates a node enrollment. EnrolledAt is when + // the member was last seen; unset, it is recorded as now, never as the + // zero time, which the silent-member sweep would read as decades ago. EnrollNode(ctx context.Context, node *EnrolledNode) error // GetNode retrieves node enrollment details.