Version, authenticate and fully trace ecosystem calls (#273)

Every Nexus and Praxis request now carries the contract version, an X-Requested-By identifying Maven, a correlation ID (generated per request when the call is not part of a traced action), and a bearer token when one is configured. Nexus/Praxis/Hexis config blocks grew an optional token field, env-expandable so the secret stays out of the committed config; the vendored hexis client predates bearer auth, so a configured Hexis token logs a loud warning instead of pretending to authenticate. Client failures are now a typed *ecosystemError carrying service, operation and HTTP status, classifying unauthorized, contract-mismatch and unreachable without matching on message text. Trace records are written for resolution, discovery, confirmation and execution — on failure as well as success — with status, duration, correlation and causation ids, HTTP status and failure class, and the utterance redacted to its length. Traces were never actually persisted before: both trace writers used fact kind "system", which the store's CHECK constraint rejects, and the error was discarded.
2026-08-01 06:57:52 +04:00
parent 08f3db318f
commit 927e46bca3
4 changed files with 523 additions and 24 deletions
@@ -3,9 +3,11 @@ package main
 import (
 	"context"
 	"encoding/json"
+	"errors"
 	"fmt"
 	"log"
 	"strings"
+	"time"

 	hexisclient "github.com/kami/hexis/pkg/client"
 	"github.com/kami/maven/internal/ipc"
@@ -291,6 +293,14 @@ func (h *reactiveHandler) localFactsForEntity(ctx context.Context, entityID stri
 	return "я помню: " + strings.Join(parts, ", ")
 }

+// mergeFields overlays b onto a and returns a.
+func mergeFields(a, b map[string]any) map[string]any {
+	for k, v := range b {
+		a[k] = v
+	}
+	return a
+}
+
 // recordPraxisTrace — writes a fact recording a cross-service ecosystem call.
 // The fact is stored with source "praxis:trace" so the proactive loop can
 // reference it and the dashboard can display recent ecosystem activity.
@@ -302,14 +312,94 @@ func (h *reactiveHandler) recordPraxisTrace(ctx context.Context, operation strin
 			value = operation + " " + string(b)
 		}
 	}
-	_, _ = h.api.WriteFact(ctx, ipc.WriteFactReq{
+	// Kind must be one of the store's allowed kinds ('self','env','config');
+	// "system" was silently rejected by the CHECK constraint, so no praxis
+	// trace was ever persisted.
+	if _, err := h.api.WriteFact(ctx, ipc.WriteFactReq{
 		Ts:         now,
-		Kind:       "system",
+		Kind:       "env",
 		Key:        "praxis:" + operation,
 		Value:      value,
 		Source:     "praxis:trace",
 		Confidence: 1.0,
-	})
+	}); err != nil {
+		log.Printf("ecosystem: record praxis trace %s: %v", operation, err)
+	}
+}
+
+// traceStatus classifies an ecosystem call for the trace record. Kept coarse
+// on purpose: a trace is read to answer "did this hop work, and how long did
+// it take", not to re-derive the error.
+const (
+	traceOK       = "ok"
+	traceFailed   = "failed"
+	traceRefused  = "refused" // the far side answered, and said no
+	traceAmbig    = "ambiguous"
+	traceNotFound = "not_found"
+)
+
+// redactSubject reduces a user utterance to something safe to persist in a
+// trace: its length only. Traces are diagnostics, and his words are not
+// diagnostics — the correlation ID is what ties a trace to the turn.
+func redactSubject(s string) string {
+	return fmt.Sprintf("<%d chars>", len([]rune(s)))
+}
+
+// recordEcosystemTrace writes one hop of a cross-service call: which service,
+// which operation, the outcome, how long it took, and the correlation ID that
+// stitches the hops together. Unlike recordPraxisTrace it is written for every
+// outcome, not only success — an unrecorded failure is exactly the hop you
+// need when something went wrong at 3am.
+func (h *reactiveHandler) recordEcosystemTrace(ctx context.Context, service, op, status string, started time.Time, fields map[string]any) {
+	details := map[string]any{
+		"service":     service,
+		"operation":   op,
+		"status":      status,
+		"duration_ms": h.now().Sub(started).Milliseconds(),
+	}
+	if id := correlationIDFromCtx(ctx); id != "" {
+		details["correlation_id"] = id
+	}
+	for k, v := range fields {
+		details[k] = v
+	}
+	value := service + ":" + op + " " + status
+	if b, err := json.Marshal(details); err == nil {
+		value = value + " " + string(b)
+	}
+	if _, err := h.api.WriteFact(ctx, ipc.WriteFactReq{
+		Ts:         h.now(),
+		Kind:       "env",
+		Key:        "ecosystem:" + service + ":" + op,
+		Value:      value,
+		Source:     "ecosystem:trace",
+		Confidence: 1.0,
+	}); err != nil {
+		log.Printf("ecosystem: record trace %s:%s: %v", service, op, err)
+	}
+}
+
+// traceErrorFields describes an ecosystemError for a trace without leaking the
+// payload: the HTTP status and the failure class, nothing else.
+func traceErrorFields(err error) map[string]any {
+	fields := map[string]any{}
+	var ee *ecosystemError
+	if errors.As(err, &ee) {
+		fields["http_status"] = ee.Status
+		switch {
+		case ee.Unauthorized():
+			fields["class"] = "unauthorized"
+		case ee.ContractMismatch():
+			fields["class"] = "contract_mismatch"
+		case ee.Unreachable():
+			fields["class"] = "unreachable"
+		default:
+			fields["class"] = "error"
+		}
+		return fields
+	}
+	fields["class"] = "error"
+	return fields
 }

 // handleHexisAct — resolves entity references through Nexus and executes
@@ -320,10 +410,20 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
 		return ""
 	}

+	// Every hop of this action shares one correlation ID, assigned here so
+	// resolution and discovery are traceable even when execution never
+	// happens.
+	if correlationIDFromCtx(ctx) == "" {
+		ctx = withCorrelationID(ctx, newCorrelationID())
+	}
+
 	// Resolve the utterance text as an entity reference through Nexus. An
 	// ambiguous match must stop and clarify — never guess a mutation target.
+	started := h.now()
 	entityID, displayName, ambiguous, err := h.ecosystem.resolveEntityReference(ctx, dec.Slots.Text, nil)
 	if err != nil {
+		h.recordEcosystemTrace(ctx, "nexus", "resolve", traceFailed, started,
+			mergeFields(traceErrorFields(err), map[string]any{"subject": redactSubject(dec.Slots.Text)}))
 		// A genuine Nexus dependency failure, not "no such entity" — stop here
 		// and report degradation rather than silently falling through to the
 		// local command executor (ECOSYSTEM-SPEC.md: services degrade
@@ -331,19 +431,30 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
 		return "экосистема недоступна, попробуй ещё раз."
 	}
 	if len(ambiguous) > 0 {
+		h.recordEcosystemTrace(ctx, "nexus", "resolve", traceAmbig, started,
+			map[string]any{"candidates": len(ambiguous)})
 		return "уточни, что именно: " + strings.Join(ambiguous, ", ") + "?"
 	}
 	if entityID == "" {
+		h.recordEcosystemTrace(ctx, "nexus", "resolve", traceNotFound, started,
+			map[string]any{"subject": redactSubject(dec.Slots.Text)})
 		return ""
 	}
+	h.recordEcosystemTrace(ctx, "nexus", "resolve", traceOK, started,
+		map[string]any{"entity_id": entityID})

 	// Discover Hexis capabilities for this entity. A resolved entity with a
 	// genuine Hexis failure must not be treated as "no capabilities" and
 	// fall through to unrelated local execution.
+	discovered := h.now()
 	caps, err := h.ecosystem.discoverCapabilities(ctx, entityID)
 	if err != nil {
+		h.recordEcosystemTrace(ctx, "hexis", "capabilities", traceFailed, discovered,
+			mergeFields(traceErrorFields(err), map[string]any{"entity_id": entityID}))
 		return "экосистема недоступна, попробуй ещё раз."
 	}
+	h.recordEcosystemTrace(ctx, "hexis", "capabilities", traceOK, discovered,
+		map[string]any{"entity_id": entityID, "count": len(caps)})
 	if len(caps) == 0 {
 		return ""
 	}
@@ -388,6 +499,8 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
 			expiry:       h.now().Add(confirmTTL),
 		}
 		h.mu.Unlock()
+		h.recordEcosystemTrace(ctx, "hexis", "confirmation", "pending", h.now(),
+			map[string]any{"entity_id": entityID, "capability": matched.Name})
 		return "выполнить «" + matched.Name + "» для " + displayName + "? скажи «да» или «нет»."
 	}

@@ -398,11 +511,21 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
 // the correlation ID. It reports command success, never operational recovery
 // (Praxis observes recovery independently).
 func (h *reactiveHandler) execHexis(ctx context.Context, capID, capName, entityID, displayName string) string {
+	started := h.now()
+	causationID := correlationIDFromCtx(ctx)
 	correlationID, err := h.ecosystem.executeCapability(ctx, capID, entityID, nil)
+	traced := withCorrelationID(ctx, correlationID)
 	if err != nil {
 		log.Printf("ecosystem: hexis execute error (cor=%s): %v", correlationID, err)
+		h.recordEcosystemTrace(traced, "hexis", "execute", traceFailed, started,
+			mergeFields(traceErrorFields(err), map[string]any{
+				"entity_id": entityID, "capability": capName, "causation_id": causationID,
+			}))
 		return "не получилось выполнить команду для " + displayName + "."
 	}
+	h.recordEcosystemTrace(traced, "hexis", "execute", traceOK, started, map[string]any{
+		"entity_id": entityID, "capability": capName, "causation_id": causationID,
+	})
 	h.recordPraxisTrace(ctx, "hexis:"+capName, map[string]any{
 		"entity_id":      entityID,
 		"entity_name":    displayName,