Trace a rotation's credential writes and compositions, record the bindings a composition carries, drop SchemaReachOf, and re-pin mesh-sdk to e45bdc0891bb (issue 1945)

cmd/mesh-controller/composed_live.go

@@ -70,6 +70,9 @@ func composeModules(ctx context.Context, open *stores, nodes []string) (map[stri
 			continue
 		}
 		at.sign, at.policy = sign, policy
+		if composeTrace != nil {
+			traceInput(ctx, open, node)
+		}
 		declared, err := composeSend(ctx, open, node)
 		if err != nil {
 			errs = append(errs, fmt.Errorf("%s: %w", node, err))
@@ -93,11 +96,20 @@ func composeModules(ctx context.Context, open *stores, nodes []string) (map[stri
 			fmt.Printf("compositions: %s's %s compose with the node's own: no fingerprint of the new form names them\n",
 				node, strings.Join(moved, ", "))
 		}
+		if composeTrace != nil {
+			traceComposed(ctx, at, node, comps)
+		}
 		wrote, err := writeNodeCompositions(ctx, at, comps)
 		if len(wrote) > 0 {
 			out[node] = wrote
 			fmt.Printf("compositions: %s: wrote %s\n", node, strings.Join(wrote, ", "))
 		}
+		// And where a data-keeping provision bound each consumer: what the next resolution keeps it at (novox/hq ADR 0232).
+		if len(declared.Bindings) > 0 {
+			if err := open.inventory.RecordBindings(ctx, node, declared.Bindings); err != nil {
+				errs = append(errs, fmt.Errorf("%s: where its consumers are bound to their data: %w", node, err))
+			}
+		}
 		if err != nil {
 			errs = append(errs, fmt.Errorf("%s: %w", node, err))
 		}

cmd/mesh-controller/composed_served_integration_test.go

@@ -11,6 +11,7 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
+	"sync"
 	"testing"
 	"time"
 
@@ -434,6 +435,28 @@ func TestServedADoneKeyIsComposedAndGranted(t *testing.T) {
 // composition keeps its own, and nothing is sent.
 func TestServedARotationRewritesOnlyTheCompositionsThatUseIt(t *testing.T) {
 	m := aServedMesh(t)
+	// Everything that writes or discards a credential row, and what composing each node saw and decided, in order, with the
+	// callers: one failure shows the cause (issue 1945).
+	var traceMu sync.Mutex
+	var trace []string
+	note := func(line string) {
+		traceMu.Lock()
+		defer traceMu.Unlock()
+		trace = append(trace, time.Now().Format("15:04:05.000")+" "+line)
+	}
+	inventory.SecretTrace = func(op, what string) { note("secret " + op + ": " + what) }
+	composeTrace = func(line string) { note("compose " + line) }
+	t.Cleanup(func() { inventory.SecretTrace, composeTrace = nil, nil })
+	traced := func() string {
+		traceMu.Lock()
+		defer traceMu.Unlock()
+		return strings.Join(trace, "\n    ")
+	}
+	defer func() {
+		if t.Failed() {
+			t.Logf("TRACE\n    %s", traced())
+		}
+	}()
 	before := map[string]map[string]uint64{"anchor": m.revisions(t, "anchor"), "laptop": m.revisions(t, "laptop")}
 	holders, _ := m.open.inventory.HoldersOf(t.Context(), "postgres-database", "")
 	var waited uint64
@@ -485,8 +508,8 @@ func TestServedARotationRewritesOnlyTheCompositionsThatUseIt(t *testing.T) {
 			}
 		}
 		diag := fmt.Sprintf("state %+v %v; compose now %v sealed %v; %s %v", state, serr, derr, sealed, credentials, ierr)
-		t.Fatalf("the board's composition did not move within a minute after the rotation; LINES %s; holders before %+v, after %+v; DIAG %s; %s",
-			strings.Join(strings.Fields(said), " "), holders, after, diag, m.whatIsThere(t, "laptop"))
+		t.Fatalf("the board's composition did not move within a minute after the rotation; TRACE\n    %s\nLINES %s; holders before %+v, after %+v; DIAG %s; %s",
+			traced(), strings.Join(strings.Fields(said), " "), holders, after, diag, m.whatIsThere(t, "laptop"))
 	}
 	moved := map[string]bool{}
 	for node, was := range before {

cmd/mesh-controller/composed_trace.go

@@ -0,0 +1,51 @@
+package main
+
+import (
+	"context"
+	"fmt"
+	"sort"
+
+	sdkdelivery "git.novox.be/novox/mesh-sdk/go/delivery"
+)
+
+// composeTrace, when set, is told what composing a node saw and decided: the Input's credential state before it composes, and for
+// each module the digest it composed against the digest already written. A test sets it to read why a composition did or did not
+// move; the controller never does.
+var composeTrace func(string)
+
+// traceInput says what the node's composition will read of the pair credentials: those no row holds (would-make) and those held.
+func traceInput(ctx context.Context, open *stores, node string) {
+	in, err := inputFor(ctx, open)
+	if err != nil {
+		composeTrace(fmt.Sprintf("%s: the Input cannot be read: %v", node, err))
+		return
+	}
+	composeTrace(fmt.Sprintf("%s: before composing, would make %+v; credentials held %+v", node, in.wouldMake, in.Credentials))
+}
+
+// traceComposed says, per composition of a node, the digest composed now against the one written.
+func traceComposed(ctx context.Context, at composedPlace, node string, comps map[string]sdkdelivery.Composed) {
+	keys := make([]string, 0, len(comps))
+	for k := range comps {
+		keys = append(keys, k)
+	}
+	sort.Strings(keys)
+	for _, key := range keys {
+		now, err := sdkdelivery.ComposedDigestOf(comps[key])
+		if err != nil {
+			composeTrace(fmt.Sprintf("%s: %s: no digest: %v", node, key, err))
+			continue
+		}
+		written := "none"
+		if e, err := at.digests.Get(ctx, key); err == nil {
+			if v, err := sdkdelivery.DecodeComposedDigest(e.Value()); err == nil {
+				written = v.Digest
+			}
+		}
+		same := "CHANGED"
+		if written == now {
+			same = "same"
+		}
+		composeTrace(fmt.Sprintf("%s: %s: composed %.19s, written %.19s: %s", node, key, now, written, same))
+	}
+}