diff --git a/cmd/mavend/ecosystem.go b/cmd/mavend/ecosystem.go
index c249fcc..a7c36d8 100644
--- a/cmd/mavend/ecosystem.go
+++ b/cmd/mavend/ecosystem.go
@@ -45,6 +45,12 @@ const mavenRequester = "maven"
// setEcosystemHeaders stamps the version, requester, auth and correlation
// headers common to every outgoing ecosystem request. token may be empty,
// which means the transport itself is trusted (loopback or unix socket).
+//
+// The correlation ID is read from the context and never minted here. Minting
+// one per request sent the far side an ID that existed nowhere on this side,
+// and gave a single multi-hop action as many unrelated IDs as it made calls.
+// Callers that start an action assign the ID once (handleHexisAct,
+// handlePraxisAct, resolveEntityReference) and every hop inherits it.
func setEcosystemHeaders(req *http.Request, ctx context.Context, versionHeader, token string) {
req.Header.Set("Content-Type", "application/json")
req.Header.Set(versionHeader, ecosystemAPIVersion)
@@ -53,13 +59,9 @@ func setEcosystemHeaders(req *http.Request, ctx context.Context, versionHeader,
if token != "" {
req.Header.Set("Authorization", "Bearer "+token)
}
- id := correlationIDFromCtx(ctx)
- if id == "" {
- // A call made outside a traced action still gets an ID, so the far
- // side's log line can be matched to this one request.
- id = newCorrelationID()
+ if id := correlationIDFromCtx(ctx); id != "" {
+ req.Header.Set("X-Correlation-ID", id)
}
- req.Header.Set("X-Correlation-ID", id)
}
// ecosystemError is the typed failure every ecosystem client returns, so
@@ -202,16 +204,16 @@ func (c *nexusClient) Resolve(ctx context.Context, query string, types []string)
func (c *nexusClient) Health(ctx context.Context) error {
req, err := http.NewRequestWithContext(ctx, http.MethodGet, c.baseURL+"/health", nil)
if err != nil {
- return err
+ return &ecosystemError{Service: "nexus", Op: "health", Err: err}
}
setEcosystemHeaders(req, ctx, "X-Nexus-Version", c.token)
resp, err := c.httpClient.Do(req)
if err != nil {
- return err
+ return &ecosystemError{Service: "nexus", Op: "health", Err: err}
}
resp.Body.Close()
if resp.StatusCode != 200 {
- return fmt.Errorf("nexus health: %s", http.StatusText(resp.StatusCode))
+ return httpError("nexus", "health", resp.StatusCode)
}
return nil
}
@@ -237,8 +239,11 @@ func (c *praxisClient) withToken(token string) *praxisClient {
return c
}
-// getJSON performs a GET and decodes the JSON body into out.
-func (c *praxisClient) getJSON(ctx context.Context, path string, out any) error {
+// getJSON performs a GET and decodes the JSON body into out. op is the logical
+// operation name for errors and traces: the path carries the query string, and
+// after entity scoping that means an entity id in every log line built from the
+// error, next to a trace that redacts far less than that.
+func (c *praxisClient) getJSON(ctx context.Context, op, path string, out any) error {
req, err := http.NewRequestWithContext(ctx, http.MethodGet, c.baseURL+path, nil)
if err != nil {
return err
@@ -246,21 +251,21 @@ func (c *praxisClient) getJSON(ctx context.Context, path string, out any) error
setEcosystemHeaders(req, ctx, "X-Praxis-Version", c.token)
resp, err := c.httpClient.Do(req)
if err != nil {
- return &ecosystemError{Service: "praxis", Op: path, Err: err}
+ return &ecosystemError{Service: "praxis", Op: op, Err: err}
}
defer resp.Body.Close()
if resp.StatusCode != 200 {
- return httpError("praxis", path, resp.StatusCode)
+ return httpError("praxis", op, resp.StatusCode)
}
if err := json.NewDecoder(resp.Body).Decode(out); err != nil {
- return &ecosystemError{Service: "praxis", Op: path, Status: resp.StatusCode, Err: err}
+ return &ecosystemError{Service: "praxis", Op: op, Status: resp.StatusCode, Err: err}
}
return nil
}
func (c *praxisClient) ListAttention(ctx context.Context, limit int) ([]map[string]any, error) {
var out []map[string]any
- err := c.getJSON(ctx, fmt.Sprintf("/api/v1/tools/attention?limit=%d", limit), &out)
+ err := c.getJSON(ctx, "attention", fmt.Sprintf("/api/v1/tools/attention?limit=%d", limit), &out)
return out, err
}
@@ -270,13 +275,14 @@ func (c *praxisClient) ListAttention(ctx context.Context, limit int) ([]map[stri
// instead of filtering the unscoped list client-side.
func (c *praxisClient) ListAttentionForEntity(ctx context.Context, entityID string, limit int) ([]map[string]any, error) {
var out []map[string]any
- err := c.getJSON(ctx, fmt.Sprintf("/api/v1/tools/attention?limit=%d&entity_id=%s", limit, url.QueryEscape(entityID)), &out)
+ err := c.getJSON(ctx, "attention_for_entity",
+ fmt.Sprintf("/api/v1/tools/attention?limit=%d&entity_id=%s", limit, url.QueryEscape(entityID)), &out)
return out, err
}
func (c *praxisClient) ListChanges(ctx context.Context, limit int) ([]map[string]any, error) {
var out []map[string]any
- err := c.getJSON(ctx, fmt.Sprintf("/api/v1/tools/changes?limit=%d", limit), &out)
+ err := c.getJSON(ctx, "changes", fmt.Sprintf("/api/v1/tools/changes?limit=%d", limit), &out)
return out, err
}
@@ -302,24 +308,32 @@ type praxisItem struct {
// postItemAction posts {"item_id": id} to a Praxis tools lifecycle endpoint
// and decodes the resulting item. Shared by Surface/Acknowledge/Resolve/Ignore.
-func (c *praxisClient) postItemAction(ctx context.Context, path, itemID string) (*praxisItem, error) {
- body, _ := json.Marshal(map[string]any{"item_id": itemID})
+func (c *praxisClient) postItemAction(ctx context.Context, op, path, itemID string) (*praxisItem, error) {
+ return c.postJSON(ctx, op, path, map[string]any{"item_id": itemID})
+}
+
+// postJSON posts a body to a Praxis lifecycle endpoint and decodes the item.
+// Every failure is a *ecosystemError, including the transport and decode ones:
+// these are the paths that mutate remote state, and the question worth
+// answering afterwards is whether the call never left or was refused.
+func (c *praxisClient) postJSON(ctx context.Context, op, path string, payload map[string]any) (*praxisItem, error) {
+ body, _ := json.Marshal(payload)
req, err := http.NewRequestWithContext(ctx, http.MethodPost, c.baseURL+path, bytes.NewReader(body))
if err != nil {
- return nil, err
+ return nil, &ecosystemError{Service: "praxis", Op: op, Err: err}
}
setEcosystemHeaders(req, ctx, "X-Praxis-Version", c.token)
resp, err := c.httpClient.Do(req)
if err != nil {
- return nil, err
+ return nil, &ecosystemError{Service: "praxis", Op: op, Err: err}
}
defer resp.Body.Close()
if resp.StatusCode != 200 {
- return nil, httpError("praxis", path, resp.StatusCode)
+ return nil, httpError("praxis", op, resp.StatusCode)
}
var out praxisItem
if err := json.NewDecoder(resp.Body).Decode(&out); err != nil {
- return nil, fmt.Errorf("decode: %w", err)
+ return nil, &ecosystemError{Service: "praxis", Op: op, Status: resp.StatusCode, Err: err}
}
return &out, nil
}
@@ -328,46 +342,28 @@ func (c *praxisClient) postItemAction(ctx context.Context, path, itemID string)
// ECOSYSTEM-SPEC.md §2.3). Callers that read attention aloud must call this, never
// Acknowledge, so "I mentioned it" stays distinguishable from "you told me you saw it".
func (c *praxisClient) Surface(ctx context.Context, itemID string) (*praxisItem, error) {
- return c.postItemAction(ctx, "/api/v1/tools/surface", itemID)
+ return c.postItemAction(ctx, "surface", "/api/v1/tools/surface", itemID)
}
func (c *praxisClient) Acknowledge(ctx context.Context, itemID string) (*praxisItem, error) {
- return c.postItemAction(ctx, "/api/v1/tools/acknowledge", itemID)
+ return c.postItemAction(ctx, "acknowledge", "/api/v1/tools/acknowledge", itemID)
}
func (c *praxisClient) Resolve(ctx context.Context, itemID string) (*praxisItem, error) {
- return c.postItemAction(ctx, "/api/v1/tools/resolve", itemID)
+ return c.postItemAction(ctx, "resolve", "/api/v1/tools/resolve", itemID)
}
func (c *praxisClient) Ignore(ctx context.Context, itemID string) (*praxisItem, error) {
- return c.postItemAction(ctx, "/api/v1/tools/ignore", itemID)
+ return c.postItemAction(ctx, "ignore", "/api/v1/tools/ignore", itemID)
}
func (c *praxisClient) Pin(ctx context.Context, itemID string, pinned bool) (*praxisItem, error) {
- body, _ := json.Marshal(map[string]any{"item_id": itemID, "pinned": pinned})
- req, err := http.NewRequestWithContext(ctx, http.MethodPost, c.baseURL+"/api/v1/tools/pin", bytes.NewReader(body))
- if err != nil {
- return nil, err
- }
- setEcosystemHeaders(req, ctx, "X-Praxis-Version", c.token)
- resp, err := c.httpClient.Do(req)
- if err != nil {
- return nil, err
- }
- defer resp.Body.Close()
- if resp.StatusCode != 200 {
- return nil, httpError("praxis", "pin", resp.StatusCode)
- }
- var out praxisItem
- if err := json.NewDecoder(resp.Body).Decode(&out); err != nil {
- return nil, fmt.Errorf("decode: %w", err)
- }
- return &out, nil
+ return c.postJSON(ctx, "pin", "/api/v1/tools/pin", map[string]any{"item_id": itemID, "pinned": pinned})
}
func (c *praxisClient) GetItem(ctx context.Context, itemID string) (*praxisItem, error) {
var out praxisItem
- err := c.getJSON(ctx, "/api/v1/tools/items/"+itemID, &out)
+ err := c.getJSON(ctx, "get_item", "/api/v1/tools/items/"+itemID, &out)
if err != nil {
return nil, err
}
@@ -376,7 +372,7 @@ func (c *praxisClient) GetItem(ctx context.Context, itemID string) (*praxisItem,
func (c *praxisClient) Search(ctx context.Context, query string, limit int) ([]praxisItem, error) {
var out []praxisItem
- err := c.getJSON(ctx, fmt.Sprintf("/api/v1/tools/search?q=%s&limit=%d", url.QueryEscape(query), limit), &out)
+ err := c.getJSON(ctx, "search", fmt.Sprintf("/api/v1/tools/search?q=%s&limit=%d", url.QueryEscape(query), limit), &out)
return out, err
}
@@ -400,14 +396,18 @@ func wireEcosystem(cfg *config.Config) *ecosystemWiring {
// Hexis capability service
if cfg.Hexis != nil && cfg.Hexis.URL != "" {
- w.hexis = hexisclient.New(cfg.Hexis.URL)
if cfg.Hexis.Token != "" {
- // Upstream hexis grew Client.WithToken, but the copy vendored
- // here predates it, so the token cannot be sent yet. Say so
- // loudly rather than pretending the call is authenticated.
- log.Printf("ecosystem: hexis token configured but the vendored hexis client cannot send it — re-vendor github.com/kami/hexis to enable bearer auth")
+ // Upstream hexis grew Client.WithToken, but the copy vendored here
+ // predates it, so the token cannot be sent. Hexis is the only one
+ // of the three that executes anything, and configuring auth on the
+ // executing service is not a best-effort request: refuse to wire it
+ // rather than execute unauthenticated for weeks behind one boot-time
+ // log line.
+ log.Printf("ecosystem: hexis token configured but the vendored hexis client cannot send it — hexis stays disabled; re-vendor github.com/kami/hexis to enable bearer auth")
+ } else {
+ w.hexis = hexisclient.New(cfg.Hexis.URL)
+ log.Printf("ecosystem: hexis at %s", cfg.Hexis.URL)
}
- log.Printf("ecosystem: hexis at %s", cfg.Hexis.URL)
} else {
log.Printf("ecosystem: hexis not configured")
}
@@ -439,7 +439,19 @@ func (w *ecosystemWiring) resolveEntityReference(ctx context.Context, text strin
log.Printf("ecosystem: nexus resolve error: %v", err)
return "", "", nil, err
}
- if result.Status == "resolved" && result.Entity != nil {
+ if result.Status == "resolved" {
+ // "resolved" with nothing to resolve to is a contract violation, not a
+ // miss. Treating it as "no such entity" let the caller fall straight
+ // through to the local executor with his verb intact, which is a
+ // dependency failure reaching execution.
+ if result.Entity == nil || result.Entity.ID == "" {
+ err := &ecosystemError{
+ Service: "nexus", Op: "resolve", Status: 200,
+ Err: errors.New("resolved status with no entity"),
+ }
+ log.Printf("ecosystem: %v", err)
+ return "", "", nil, err
+ }
return result.Entity.ID, result.Entity.DisplayName, nil, nil
}
if result.Status == "ambiguous" {
@@ -459,6 +471,11 @@ func (w *ecosystemWiring) resolveEntityReference(ctx context.Context, text strin
// healthy and genuinely has nothing registered for this entity. Callers must
// not conflate the two: a dependency failure must not silently read as "no
// capabilities" and fall through to unrelated local execution.
+//
+// The vendored Hexis client stamps a correlation header on Execute only, so
+// discovery and execution cannot be joined on the Hexis side. Maven's own
+// traces still share one ID for both hops; the gap is on the far side and
+// closes when the client is re-vendored.
func (w *ecosystemWiring) discoverCapabilities(ctx context.Context, entityID string) ([]hexisclient.Capability, error) {
if w == nil || w.hexis == nil || entityID == "" {
return nil, nil
diff --git a/cmd/mavend/ecosystem_acts.go b/cmd/mavend/ecosystem_acts.go
index b0a513d..867685d 100644
--- a/cmd/mavend/ecosystem_acts.go
+++ b/cmd/mavend/ecosystem_acts.go
@@ -2,7 +2,6 @@ package main
import (
"context"
- "encoding/json"
"errors"
"fmt"
"log"
@@ -10,8 +9,8 @@ import (
"time"
hexisclient "github.com/kami/hexis/pkg/client"
- "github.com/kami/maven/internal/ipc"
"github.com/kami/maven/internal/router"
+ "github.com/kami/maven/internal/store"
)
// praxisCapability is one arm of the Praxis act dispatch. This is an interface
@@ -84,6 +83,12 @@ func (h *reactiveHandler) handlePraxisAct(ctx context.Context, dec router.Decisi
if h.ecosystem == nil || h.ecosystem.praxis == nil {
return ""
}
+ // Every hop of this action shares one correlation ID, assigned here, so a
+ // digest that calls attention once and surface N times reads as one turn
+ // on the Praxis side instead of N+1 unrelated request ids.
+ if correlationIDFromCtx(ctx) == "" {
+ ctx = withCorrelationID(ctx, newCorrelationID())
+ }
px := h.ecosystem.praxis
for _, capability := range praxisCapabilities {
for _, alias := range capability.aliases() {
@@ -114,11 +119,14 @@ func (a praxisItemAction) handle(ctx context.Context, h *reactiveHandler, px *pr
if id == "" {
return a.ask
}
+ started := h.now()
if err := a.call(ctx, px, id); err != nil {
log.Printf("ecosystem: praxis %s %s: %v", a.op, id, err)
+ h.recordEcosystemTrace(ctx, "praxis", a.op, traceStatusForError(err), started,
+ mergeFields(traceErrorFields(err), map[string]any{"item_id": id}))
return a.failure
}
- h.recordPraxisTrace(ctx, a.op, map[string]any{"item_id": id})
+ h.recordPraxisTrace(ctx, a.op, started, map[string]any{"item_id": id})
return a.success
}
@@ -130,15 +138,18 @@ func (listAttentionCapability) aliases() []string {
}
func (listAttentionCapability) handle(ctx context.Context, h *reactiveHandler, px *praxisClient, _ router.Decision) string {
+ started := h.now()
items, err := px.ListAttention(ctx, 20)
if err != nil {
log.Printf("ecosystem: praxis attention: %v", err)
+ h.recordEcosystemTrace(ctx, "praxis", "list_attention", traceStatusForError(err),
+ started, traceErrorFields(err))
return "не могу сейчас узнать, что требует внимания."
}
if len(items) == 0 {
return "ничего не требует внимания."
}
- h.recordPraxisTrace(ctx, "list_attention", map[string]any{"count": len(items)})
+ h.recordPraxisTrace(ctx, "list_attention", started, map[string]any{"count": len(items)})
var parts []string
for _, item := range items {
title, _ := item["title"].(string)
@@ -175,15 +186,18 @@ func (listChangesCapability) aliases() []string {
}
func (listChangesCapability) handle(ctx context.Context, h *reactiveHandler, px *praxisClient, _ router.Decision) string {
+ started := h.now()
changes, err := px.ListChanges(ctx, 20)
if err != nil {
log.Printf("ecosystem: praxis changes: %v", err)
+ h.recordEcosystemTrace(ctx, "praxis", "list_changes", traceStatusForError(err),
+ started, traceErrorFields(err))
return "не могу сейчас узнать об изменениях."
}
if len(changes) == 0 {
return "нет изменений."
}
- h.recordPraxisTrace(ctx, "list_changes", map[string]any{"count": len(changes)})
+ h.recordPraxisTrace(ctx, "list_changes", started, map[string]any{"count": len(changes)})
var parts []string
for _, c := range changes {
title, _ := c["title"].(string)
@@ -204,8 +218,10 @@ func (listChangesCapability) handle(ctx context.Context, h *reactiveHandler, px
// gets one answer across both stores.
type entityAttentionCapability struct{}
+// aliases are matched against Slots.Fn, which carries a function slot from the
+// act grammar and never free Russian, so only grammar names belong here.
func (entityAttentionCapability) aliases() []string {
- return []string{"entity_attention", "что с", "как дела у", "статус"}
+ return []string{"entity_attention", "entity_status"}
}
func (entityAttentionCapability) handle(ctx context.Context, h *reactiveHandler, px *praxisClient, dec router.Decision) string {
@@ -222,9 +238,18 @@ func (entityAttentionCapability) handle(ctx context.Context, h *reactiveHandler,
return "не могу связать это с сущностью — Nexus не настроен."
}
+ started := h.now()
entityID, displayName, ambiguous, err := h.ecosystem.resolveEntityReference(ctx, subject, nil)
if err != nil {
- log.Printf("ecosystem: entity attention resolve %q: %v", subject, err)
+ // The subject is his words, so the log gets the same redaction the
+ // trace gets. A trace that stores a rune count next to a log line
+ // storing the runes is not redacted at all.
+ log.Printf("ecosystem: entity attention resolve %s: %v", redactSubject(subject), err)
+ h.recordEcosystemTrace(ctx, "nexus", "resolve", traceStatusForError(err), started,
+ mergeFields(traceErrorFields(err), map[string]any{"subject": redactSubject(subject)}))
+ if unauthorizedEcosystemError(err) {
+ return "экосистема отклоняет доступ, проверь токен."
+ }
return "экосистема недоступна, попробуй ещё раз."
}
if len(ambiguous) > 0 {
@@ -237,12 +262,26 @@ func (entityAttentionCapability) handle(ctx context.Context, h *reactiveHandler,
displayName = subject
}
+ queried := h.now()
items, err := px.ListAttentionForEntity(ctx, entityID, 20)
if err != nil {
log.Printf("ecosystem: praxis attention for %s: %v", entityID, err)
+ h.recordEcosystemTrace(ctx, "praxis", "entity_attention", traceStatusForError(err),
+ queried, mergeFields(traceErrorFields(err), map[string]any{"entity_id": entityID}))
return "не могу сейчас узнать, что требует внимания по «" + displayName + "»."
}
- h.recordPraxisTrace(ctx, "entity_attention", map[string]any{
+ items, scoped := scopedToEntity(items, entityID)
+ if !scoped {
+ // A Praxis old enough to ignore an unknown query parameter answers the
+ // scoped question with the unscoped list. Reading that back as "по
+ // «X»: ..." is the exact fabrication the entity ref exists to prevent,
+ // so refuse the answer instead of relabelling someone else's items.
+ log.Printf("ecosystem: praxis returned unscoped items for %s, refusing to answer", entityID)
+ h.recordEcosystemTrace(ctx, "praxis", "entity_attention", traceFailed, queried,
+ map[string]any{"entity_id": entityID, "class": "unscoped_response"})
+ return "не могу сейчас узнать, что требует внимания по «" + displayName + "»."
+ }
+ h.recordPraxisTrace(ctx, "entity_attention", queried, map[string]any{
"entity_id": entityID, "count": len(items),
})
@@ -269,6 +308,40 @@ func (entityAttentionCapability) handle(ctx context.Context, h *reactiveHandler,
return "по «" + displayName + "»: " + strings.Join(parts, "; ")
}
+// scopedToEntity drops items that carry an entity_id other than the one asked
+// about, and reports whether the response can be trusted as scoped at all. An
+// item without an entity_id is kept only when at least one sibling carries the
+// matching id: a whole page with no entity_id is a Praxis that ignored the
+// scope, not a page of untagged items.
+func scopedToEntity(items []map[string]any, entityID string) ([]map[string]any, bool) {
+ if len(items) == 0 {
+ return items, true
+ }
+ var kept []map[string]any
+ var sawMatch, sawMismatch bool
+ for _, item := range items {
+ id, _ := item["entity_id"].(string)
+ switch {
+ case id == entityID:
+ sawMatch = true
+ kept = append(kept, item)
+ case id != "":
+ sawMismatch = true
+ default:
+ kept = append(kept, item)
+ }
+ }
+ if sawMatch {
+ return kept, true
+ }
+ if sawMismatch {
+ // Some items were tagged and none matched: the far side answered about
+ // other entities, so nothing here belongs to this one.
+ return nil, true
+ }
+ return nil, false
+}
+
// localFactsForEntity summarises Maven's own facts already resolved to this
// canonical entity. Empty when the store is unavailable or nothing matched —
// entity-scoped memory is an enrichment of the answer, never a precondition.
@@ -276,11 +349,18 @@ func (h *reactiveHandler) localFactsForEntity(ctx context.Context, entityID stri
if h.dataStore == nil || entityID == "" {
return ""
}
- facts, err := h.dataStore.FactsByEntity(ctx, entityID, 3)
+ const spoken = 3
+ // One over the spoken limit, so a truncation can be named rather than
+ // passed off as everything she knows.
+ facts, err := h.dataStore.FactsByEntity(ctx, entityID, spoken+1)
if err != nil {
log.Printf("ecosystem: facts by entity %s: %v", entityID, err)
return ""
}
+ more := false
+ if len(facts) > spoken {
+ facts, more = facts[:spoken], true
+ }
var parts []string
for _, f := range facts {
if f.Value != "" {
@@ -290,7 +370,11 @@ func (h *reactiveHandler) localFactsForEntity(ctx context.Context, entityID stri
if len(parts) == 0 {
return ""
}
- return "я помню: " + strings.Join(parts, ", ")
+ out := "я помню: " + strings.Join(parts, ", ")
+ if more {
+ out += ", и это не всё"
+ }
+ return out
}
// mergeFields overlays b onto a and returns a.
@@ -301,30 +385,11 @@ func mergeFields(a, b map[string]any) map[string]any {
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.
-func (h *reactiveHandler) recordPraxisTrace(ctx context.Context, operation string, details map[string]any) {
- now := h.now()
- value := operation
- if len(details) > 0 {
- if b, err := json.Marshal(details); err == nil {
- value = operation + " " + string(b)
- }
- }
- // 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: "env",
- Key: "praxis:" + operation,
- Value: value,
- Source: "praxis:trace",
- Confidence: 1.0,
- }); err != nil {
- log.Printf("ecosystem: record praxis trace %s: %v", operation, err)
- }
+// recordPraxisTrace — records a completed Praxis call. Thin wrapper over
+// recordEcosystemTrace so every ecosystem hop lands in one table with one
+// shape.
+func (h *reactiveHandler) recordPraxisTrace(ctx context.Context, operation string, started time.Time, details map[string]any) {
+ h.recordEcosystemTrace(ctx, "praxis", operation, traceOK, started, details)
}
// traceStatus classifies an ecosystem call for the trace record. Kept coarse
@@ -332,12 +397,25 @@ func (h *reactiveHandler) recordPraxisTrace(ctx context.Context, operation strin
// it take", not to re-derive the error.
const (
traceOK = "ok"
- traceFailed = "failed"
+ traceFailed = "failed" // the call never got an answer
traceRefused = "refused" // the far side answered, and said no
traceAmbig = "ambiguous"
traceNotFound = "not_found"
+ tracePending = "pending" // deliberately not done yet, awaiting a confirm
)
+// traceStatusForError distinguishes "I could not reach it" from "it answered
+// and refused". Both degrade the same way for him and not at all the same way
+// for whoever reads the trace: one is a network or a dead service, the other
+// is a token, a version or a rejected argument.
+func traceStatusForError(err error) string {
+ var ee *ecosystemError
+ if errors.As(err, &ee) && !ee.Unreachable() {
+ return traceRefused
+ }
+ return traceFailed
+}
+
// 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.
@@ -347,38 +425,55 @@ func redactSubject(s string) string {
// 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.
+// stitches the hops together. It is written for every outcome, not only
+// success — an unrecorded failure is exactly the hop you need when something
+// went wrong at 3am.
+//
+// Traces go to their own store table, never to facts. One act turn produces
+// three or four of them, at machine rate, while facts arrive at human rate:
+// sharing the table meant the habit profile's 2000-row window, memeval's
+// prompt snapshot and the /dash and /history pages all filled with traces and
+// stopped seeing his actual facts.
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 h.dataStore == nil {
+ return
}
- if id := correlationIDFromCtx(ctx); id != "" {
- details["correlation_id"] = id
+ tr := store.EcosystemTrace{
+ Ts: h.now(),
+ Service: service,
+ Operation: op,
+ Status: status,
+ DurationMs: h.now().Sub(started).Milliseconds(),
+ CorrelationID: correlationIDFromCtx(ctx),
+ Fields: map[string]any{},
}
for k, v := range fields {
- details[k] = v
+ switch k {
+ case "causation_id":
+ tr.CausationID, _ = v.(string)
+ case "http_status":
+ if n, ok := v.(int); ok {
+ tr.HTTPStatus = n
+ continue
+ }
+ tr.Fields[k] = v
+ default:
+ tr.Fields[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 {
+ if _, err := h.dataStore.WriteEcosystemTrace(ctx, tr); err != nil {
log.Printf("ecosystem: record trace %s:%s: %v", service, op, err)
}
}
+// unauthorizedEcosystemError reports a credential the far side rejected. It
+// gets its own reply: a missing or wrong token looks exactly like an outage to
+// him, and "try again" is advice that will never work.
+func unauthorizedEcosystemError(err error) bool {
+ var ee *ecosystemError
+ return errors.As(err, &ee) && ee.Unauthorized()
+}
+
// 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 {
@@ -422,8 +517,11 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
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,
+ h.recordEcosystemTrace(ctx, "nexus", "resolve", traceStatusForError(err), started,
mergeFields(traceErrorFields(err), map[string]any{"subject": redactSubject(dec.Slots.Text)}))
+ if unauthorizedEcosystemError(err) {
+ return "экосистема отклоняет доступ, проверь токен."
+ }
// 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
@@ -449,8 +547,11 @@ func (h *reactiveHandler) handleHexisAct(ctx context.Context, dec router.Decisio
discovered := h.now()
caps, err := h.ecosystem.discoverCapabilities(ctx, entityID)
if err != nil {
- h.recordEcosystemTrace(ctx, "hexis", "capabilities", traceFailed, discovered,
+ h.recordEcosystemTrace(ctx, "hexis", "capabilities", traceStatusForError(err), discovered,
mergeFields(traceErrorFields(err), map[string]any{"entity_id": entityID}))
+ if unauthorizedEcosystemError(err) {
+ return "экосистема отклоняет доступ, проверь токен."
+ }
return "экосистема недоступна, попробуй ещё раз."
}
h.recordEcosystemTrace(ctx, "hexis", "capabilities", traceOK, discovered,
@@ -499,7 +600,7 @@ 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(),
+ h.recordEcosystemTrace(ctx, "hexis", "confirmation", tracePending, started,
map[string]any{"entity_id": entityID, "capability": matched.Name})
return "выполнить «" + matched.Name + "» для " + displayName + "? скажи «да» или «нет»."
}
@@ -517,20 +618,17 @@ func (h *reactiveHandler) execHexis(ctx context.Context, capID, capName, entityI
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,
+ h.recordEcosystemTrace(traced, "hexis", "execute", traceStatusForError(err), started,
mergeFields(traceErrorFields(err), map[string]any{
"entity_id": entityID, "capability": capName, "causation_id": causationID,
}))
return "не получилось выполнить команду для " + displayName + "."
}
+ // One record per hop: the second write this used to make said the same
+ // thing under a different key, in a different shape.
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,
- "capability": capName,
- "correlation_id": correlationID,
+ "entity_id": entityID, "entity_name": displayName,
+ "capability": capName, "causation_id": causationID,
})
return "команда выполнена для " + displayName + "."
}
diff --git a/cmd/mavend/ecosystem_degraded_test.go b/cmd/mavend/ecosystem_degraded_test.go
index 16211c7..383959e 100644
--- a/cmd/mavend/ecosystem_degraded_test.go
+++ b/cmd/mavend/ecosystem_degraded_test.go
@@ -2,7 +2,6 @@ package main
import (
"context"
- "net/http"
"strings"
"testing"
"time"
@@ -30,7 +29,7 @@ import (
func ecoHandler(t *testing.T, nexus, praxis, hexis *fakeServer) *reactiveHandler {
t.Helper()
st := newTestStore(t)
- clock := newFakeClock(time.Date(2026, 8, 1, 9, 0, 0, 0, time.UTC))
+ clock := newTickingClock(time.Date(2026, 8, 1, 9, 0, 0, 0, time.UTC), time.Millisecond)
w := &ecosystemWiring{}
if nexus != nil {
w.nexus = newNexusClient(nexus.URL)
@@ -49,31 +48,43 @@ func ecoHandler(t *testing.T, nexus, praxis, hexis *fakeServer) *reactiveHandler
}
}
-func traceFacts(t *testing.T, h *reactiveHandler) []store.Fact {
+// traces reads the ecosystem trace table. Traces live there and not in facts,
+// so a bounded reader of facts never fills up with machine-rate rows.
+func traces(t *testing.T, h *reactiveHandler) []store.EcosystemTrace {
t.Helper()
- facts, err := h.dataStore.RecentFacts(context.Background(), 50)
+ out, err := h.dataStore.RecentEcosystemTraces(context.Background(), 100)
if err != nil {
- t.Fatalf("read facts: %v", err)
+ t.Fatalf("read traces: %v", err)
}
- var out []store.Fact
- for _, f := range facts {
- if f.Source == "praxis:trace" {
- out = append(out, f)
+ return out
+}
+
+// tracesFor returns the traces recorded for one service+operation.
+func tracesFor(t *testing.T, h *reactiveHandler, service, op string) []store.EcosystemTrace {
+ t.Helper()
+ var out []store.EcosystemTrace
+ for _, tr := range traces(t, h) {
+ if tr.Service == service && tr.Operation == op {
+ out = append(out, tr)
}
}
return out
}
+// restartCaps is a read-only capability. Restarting a service is a mutation,
+// so the read-only one this suite runs through the happy paths is named for
+// what it is; the mutating restart lives in the confirmation tests.
func restartCaps() string {
return fixtureHexisCapabilities(map[string]any{
- "id": "cap_restart", "name": "restart", "read_only": true,
+ "id": "cap_status", "name": "restart status", "read_only": true,
})
}
-// TestEcosystem_OutagesAreIndependent: Praxis being down must not disable the
-// Nexus+Hexis action path, and vice versa. A shared "ecosystem is broken"
-// mode would take away working capability for no reason.
-func TestEcosystem_OutagesAreIndependent(t *testing.T) {
+// TestEcosystem_OutagesLeaveNoSharedFailureState: the two act paths share a
+// handler, a store and a clock, so what is worth asserting is that a failure
+// on one leaves nothing behind that degrades the other. Faulting one disjoint
+// call graph and exercising the other only tests the call graph.
+func TestEcosystem_OutagesLeaveNoSharedFailureState(t *testing.T) {
ctx := context.Background()
nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
praxis := newFakePraxis(t, fixturePraxisAttentionItems(map[string]any{
@@ -82,17 +93,112 @@ func TestEcosystem_OutagesAreIndependent(t *testing.T) {
hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
h := ecoHandler(t, nexus, praxis, hexis)
- praxis.SetFault(503)
- if reply := h.handleHexisAct(ctx, actDec("muzick indexer")); !strings.Contains(reply, "выполнена") {
- t.Fatalf("praxis outage must not block the hexis path, got %q", reply)
+ // A Nexus outage during a Hexis act writes a failure trace, and a shared
+ // store is the one thing the Praxis path could inherit it through.
+ nexus.SetFault(503)
+ if reply := h.handleHexisAct(ctx, actDec("muzick indexer")); strings.Contains(reply, "выполнена") {
+ t.Fatalf("nexus outage must not report success, got %q", reply)
+ }
+ if len(tracesFor(t, h, "nexus", "resolve")) == 0 {
+ t.Fatal("the failed resolve must be recorded")
}
- praxis.SetFault(0)
- hexis.SetFault(503)
- nexus.SetFault(503)
+ nexus.SetFault(0)
reply := h.handlePraxisAct(ctx, praxisActDec("list_attention"))
if !strings.Contains(reply, "disk almost full") {
- t.Fatalf("nexus/hexis outage must not block the praxis digest, got %q", reply)
+ t.Fatalf("a recorded nexus failure must not degrade the praxis digest, got %q", reply)
+ }
+ if got := tracesFor(t, h, "praxis", "list_attention"); len(got) != 1 || got[0].Status != traceOK {
+ t.Fatalf("the praxis digest must trace its own success, got %+v", got)
+ }
+
+ // And the reverse: a Praxis outage mid-session leaves the Hexis path whole.
+ praxis.SetFault(503)
+ if reply := h.handlePraxisAct(ctx, praxisActDec("list_attention")); strings.Contains(reply, "disk") {
+ t.Fatalf("praxis outage must not serve content, got %q", reply)
+ }
+ if reply := h.handleHexisAct(ctx, actDec("muzick indexer")); !strings.Contains(reply, "выполнена") {
+ t.Fatalf("a praxis outage must not block the hexis path, got %q", reply)
+ }
+}
+
+// TestEcosystem_OneEndpointDownDoesNotMuteTheService: real outages are usually
+// partial. Attention answering while surface is down must still deliver.
+func TestEcosystem_OneEndpointDownDoesNotMuteTheService(t *testing.T) {
+ ctx := context.Background()
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems(map[string]any{
+ "id": "item_1", "title": "disk almost full", "importance": 3.0,
+ }))
+ h := ecoHandler(t, nil, praxis, nil)
+
+ praxis.SetRouteFault("/api/v1/tools/surface", 503)
+ reply := h.handlePraxisAct(ctx, praxisActDec("list_attention"))
+ if !strings.Contains(reply, "disk almost full") {
+ t.Fatalf("a downed surface endpoint must not mute the digest, got %q", reply)
+ }
+ if praxis.Count("POST", "/api/v1/tools/surface") == 0 {
+ t.Fatal("expected the surface attempt")
+ }
+}
+
+// TestEcosystem_ResolvedWithoutEntityFailsClosed: the contract violation that
+// decodes cleanly. Nexus says "resolved" and delivers no entity; treating that
+// as "no such entity" put the user's verb through to the local executor.
+func TestEcosystem_ResolvedWithoutEntityFailsClosed(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolvedEmpty())
+ hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
+ h := ecoHandler(t, nexus, nil, hexis)
+
+ reply := h.handleHexisAct(ctx, actDec("muzick indexer"))
+ if reply == "" {
+ t.Fatal("a resolve with no entity must degrade, not fall through to local execution")
+ }
+ if strings.Contains(reply, "выполнена") {
+ t.Fatalf("a resolve with no entity must not report success, got %q", reply)
+ }
+ if hexis.Count("", "/api/v1") != 0 {
+ t.Fatal("hexis must not be contacted after a contract-violating resolve")
+ }
+}
+
+// TestEcosystem_RejectedCredentialSaysSo: 401 and 403 must not read as an
+// outage. "Try again" is advice that never works for a misconfigured token.
+func TestEcosystem_RejectedCredentialSaysSo(t *testing.T) {
+ ctx := context.Background()
+ for _, status := range []int{401, 403} {
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
+ hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
+ h := ecoHandler(t, nexus, nil, hexis)
+ nexus.SetFault(status)
+
+ reply := h.handleHexisAct(ctx, actDec("muzick indexer"))
+ if !strings.Contains(reply, "токен") {
+ t.Fatalf("http %d must read as a credential problem, got %q", status, reply)
+ }
+ tr := tracesFor(t, h, "nexus", "resolve")
+ if len(tr) != 1 || tr[0].Status != traceRefused || tr[0].HTTPStatus != status {
+ t.Fatalf("http %d must trace as refused with its status, got %+v", status, tr)
+ }
+ }
+}
+
+// TestEcosystem_MalformedPraxisBodyDegrades: Praxis has the same decode path
+// Nexus does, and a 200 carrying garbage there is a dependency failure too.
+func TestEcosystem_MalformedPraxisBodyDegrades(t *testing.T) {
+ ctx := context.Background()
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems(map[string]any{
+ "id": "item_1", "title": "disk almost full", "importance": 3.0,
+ }))
+ h := ecoHandler(t, nil, praxis, nil)
+
+ praxis.SetBody(`[{"title":`)
+ reply := h.handlePraxisAct(ctx, praxisActDec("list_attention"))
+ if reply == "" {
+ t.Fatal("a malformed praxis body must not answer with silence")
+ }
+ if strings.Contains(reply, "disk almost full") {
+ t.Fatalf("a malformed body must not produce content, got %q", reply)
}
}
@@ -168,13 +274,60 @@ func TestEcosystem_ExecutionFailureIsNotSuccess(t *testing.T) {
if reply == "" {
t.Fatal("failed execution must say something")
}
- for _, f := range traceFacts(t, h) {
- if strings.HasPrefix(f.Key, "praxis:hexis:") {
- t.Fatalf("failed execution must not write a success trace: %+v", f)
+ for _, tr := range tracesFor(t, h, "hexis", "execute") {
+ if tr.Status == traceOK {
+ t.Fatalf("failed execution must not write a success trace: %+v", tr)
}
}
}
+// TestEcosystem_SuccessfulActionWritesATrace is the positive half the failure
+// assertions above depend on: without it, "no success trace" passes with the
+// trace writer deleted. It was, for a while — both writers used a fact kind the
+// store's CHECK constraint rejects and the error was discarded.
+func TestEcosystem_SuccessfulActionWritesATrace(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
+ hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
+ h := ecoHandler(t, nexus, nil, hexis)
+
+ if reply := h.handleHexisAct(ctx, actDec("muzick indexer")); !strings.Contains(reply, "выполнена") {
+ t.Fatalf("setup: expected success, got %q", reply)
+ }
+ exec := tracesFor(t, h, "hexis", "execute")
+ if len(exec) != 1 || exec[0].Status != traceOK {
+ t.Fatalf("a successful execution must leave exactly one ok trace, got %+v", exec)
+ }
+ if exec[0].CorrelationID == "" {
+ t.Error("a trace with no correlation id cannot be stitched to anything")
+ }
+}
+
+// TestEcosystem_TracesStayOutOfFacts: traces are written at machine rate and
+// facts at human rate. One act turn used to write four fact rows, which pushed
+// his facts out of every bounded reader (the habit profile's window, memeval's
+// prompt, /dash, /history).
+func TestEcosystem_TracesStayOutOfFacts(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
+ hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
+ h := ecoHandler(t, nexus, nil, hexis)
+
+ if reply := h.handleHexisAct(ctx, actDec("muzick indexer")); !strings.Contains(reply, "выполнена") {
+ t.Fatalf("setup: expected success, got %q", reply)
+ }
+ if len(traces(t, h)) == 0 {
+ t.Fatal("setup: expected traces")
+ }
+ facts, err := h.dataStore.RecentFacts(ctx, 100)
+ if err != nil {
+ t.Fatalf("read facts: %v", err)
+ }
+ if len(facts) != 0 {
+ t.Fatalf("an ecosystem act must write no facts at all, got %+v", facts)
+ }
+}
+
// TestEcosystem_AmbiguousTargetBlocksExecution: ambiguity blocks mutation, and
// the clarification must name the candidates rather than pick one.
func TestEcosystem_AmbiguousTargetBlocksExecution(t *testing.T) {
@@ -245,12 +398,10 @@ func TestEcosystem_MutatingCapabilityWaitsForConfirmation(t *testing.T) {
// downgrades bookkeeping, not the answer.
func TestEcosystem_SurfaceFailureStillDelivers(t *testing.T) {
ctx := context.Background()
- praxis := newFakeServer(t, map[string]http.HandlerFunc{
- "GET /api/v1/tools/attention": jsonHandler(200, fixturePraxisAttentionItems(
- map[string]any{"id": "item_1", "title": "disk almost full", "importance": 3.0},
- )),
- "POST /api/v1/tools/surface": jsonHandler(500, `{"error":"boom"}`),
- })
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems(
+ map[string]any{"id": "item_1", "title": "disk almost full", "importance": 3.0},
+ ))
+ praxis.SetRouteFault("/api/v1/tools/surface", 500)
h := ecoHandler(t, nil, praxis, nil)
reply := h.handlePraxisAct(ctx, praxisActDec("list_attention"))
@@ -278,7 +429,7 @@ func TestEcosystem_TotalOutageSaysSoForEveryPath(t *testing.T) {
"hexis act": h.handleHexisAct(ctx, actDec("muzick indexer")),
"attention": h.handlePraxisAct(ctx, praxisActDec("list_attention")),
"changes": h.handlePraxisAct(ctx, praxisActDec("list_changes")),
- "acknowledge": h.handlePraxisAct(ctx, praxisActDec("acknowledge_item")),
+ "acknowledge": h.handlePraxisAct(ctx, praxisItemDec("acknowledge_item", "item_1")),
} {
if reply == "" {
t.Errorf("%s: total outage must not answer with silence", name)
@@ -287,8 +438,13 @@ func TestEcosystem_TotalOutageSaysSoForEveryPath(t *testing.T) {
t.Errorf("%s: total outage must not claim success: %q", name, reply)
}
}
- if len(traceFacts(t, h)) != 0 {
- t.Fatal("a total outage must not leave success traces behind")
+ for _, tr := range traces(t, h) {
+ if tr.Status == traceOK {
+ t.Fatalf("a total outage must not leave success traces behind: %+v", tr)
+ }
+ }
+ if len(tracesFor(t, h, "praxis", "acknowledge")) == 0 {
+ t.Fatal("the acknowledge arm must reach praxis and record the refusal")
}
}
diff --git a/cmd/mavend/ecosystem_harness_test.go b/cmd/mavend/ecosystem_harness_test.go
index 1c6e375..521d220 100644
--- a/cmd/mavend/ecosystem_harness_test.go
+++ b/cmd/mavend/ecosystem_harness_test.go
@@ -19,6 +19,13 @@ func praxisActDec(fn string) router.Decision {
return router.Decision{Intent: router.IntentAct, Slots: router.Slots{Fn: fn, HasFn: true}}
}
+// praxisItemDec is praxisActDec for the lifecycle verbs, which need an item id
+// in the value slot. Without one they answer "which item?" and never reach
+// Praxis at all, which makes them useless for testing a Praxis outage.
+func praxisItemDec(fn, itemID string) router.Decision {
+ return router.Decision{Intent: router.IntentAct, Slots: router.Slots{Fn: fn, HasFn: true, Value: itemID}}
+}
+
func newPraxisTestHandler(t *testing.T, praxis *fakeServer) *reactiveHandler {
t.Helper()
st := newTestStore(t)
diff --git a/cmd/mavend/ecosystem_test.go b/cmd/mavend/ecosystem_test.go
index b603560..4fc557f 100644
--- a/cmd/mavend/ecosystem_test.go
+++ b/cmd/mavend/ecosystem_test.go
@@ -59,8 +59,11 @@ func newHexisTestHandler(t *testing.T, resolveBody string, caps string) (*reacti
}, executed
}
-func actDec(text string) router.Decision {
- return router.Decision{Intent: router.IntentAct, Slots: router.Slots{Text: text, Fn: "restart", HasFn: true}}
+// actDec builds an act decision about subject. The verb is always "restart":
+// the argument is the utterance the entity is resolved from, never the verb,
+// so actDec("restart") reads as a verb and is not one.
+func actDec(subject string) router.Decision {
+ return router.Decision{Intent: router.IntentAct, Slots: router.Slots{Text: subject, Fn: "restart", HasFn: true}}
}
func TestHexisMutatingRequiresConfirm(t *testing.T) {
diff --git a/cmd/mavend/ecosystem_trace_test.go b/cmd/mavend/ecosystem_trace_test.go
index ee59d19..86d3b1c 100644
--- a/cmd/mavend/ecosystem_trace_test.go
+++ b/cmd/mavend/ecosystem_trace_test.go
@@ -2,7 +2,6 @@ package main
import (
"context"
- "encoding/json"
"strings"
"testing"
@@ -11,34 +10,12 @@ import (
// Versioning, authentication and tracing of ecosystem calls (Vikunja #273).
-func ecoTraces(t *testing.T, h *reactiveHandler) []map[string]any {
+func findTrace(t *testing.T, h *reactiveHandler, service, op string) *store.EcosystemTrace {
t.Helper()
- facts, err := h.dataStore.RecentFacts(context.Background(), 100)
- if err != nil {
- t.Fatalf("read facts: %v", err)
- }
- var out []map[string]any
- for _, f := range facts {
- if f.Source != "ecosystem:trace" {
- continue
- }
- i := strings.Index(f.Value, "{")
- if i < 0 {
- t.Fatalf("trace fact carries no detail object: %q", f.Value)
- }
- var d map[string]any
- if err := json.Unmarshal([]byte(f.Value[i:]), &d); err != nil {
- t.Fatalf("decode trace %q: %v", f.Value, err)
- }
- out = append(out, d)
- }
- return out
-}
-
-func findTrace(traces []map[string]any, service, op string) map[string]any {
- for _, d := range traces {
- if d["service"] == service && d["operation"] == op {
- return d
+ for _, tr := range traces(t, h) {
+ if tr.Service == service && tr.Operation == op {
+ found := tr
+ return &found
}
}
return nil
@@ -58,7 +35,9 @@ func TestEcosystemHeaders_VersionRequesterAndAuth(t *testing.T) {
if err != nil {
t.Fatalf("resolve: %v", err)
}
- if _, err := h.ecosystem.praxis.ListAttention(ctx, 5); err != nil {
+ // A bare client call carries whatever the caller assigned. Entry points
+ // assign the ID, the header layer only reads it, so mirror an action here.
+ if _, err := h.ecosystem.praxis.ListAttention(withCorrelationID(ctx, newCorrelationID()), 5); err != nil {
t.Fatalf("attention: %v", err)
}
@@ -167,31 +146,69 @@ func TestEcosystemTrace_SuccessfulActionTracesEveryHop(t *testing.T) {
t.Fatalf("setup: expected success, got %q", reply)
}
- traces := ecoTraces(t, h)
+ var chain string
for _, want := range [][2]string{{"nexus", "resolve"}, {"hexis", "capabilities"}, {"hexis", "execute"}} {
- d := findTrace(traces, want[0], want[1])
+ d := findTrace(t, h, want[0], want[1])
if d == nil {
- t.Fatalf("missing trace for %s %s, got %+v", want[0], want[1], traces)
+ t.Fatalf("missing trace for %s %s, got %+v", want[0], want[1], traces(t, h))
}
- if d["status"] != traceOK {
- t.Errorf("%s %s status = %v, want ok", want[0], want[1], d["status"])
+ if d.Status != traceOK {
+ t.Errorf("%s %s status = %v, want ok", want[0], want[1], d.Status)
}
- if _, ok := d["duration_ms"]; !ok {
- t.Errorf("%s %s trace has no timing", want[0], want[1])
- }
- if d["correlation_id"] == nil || d["correlation_id"] == "" {
+ if d.CorrelationID == "" {
t.Errorf("%s %s trace has no correlation id", want[0], want[1])
}
+ if want[1] != "execute" {
+ if chain == "" {
+ chain = d.CorrelationID
+ } else if d.CorrelationID != chain {
+ t.Errorf("%s %s left the correlation chain: %s != %s", want[0], want[1], d.CorrelationID, chain)
+ }
+ }
}
- exec := findTrace(traces, "hexis", "execute")
- if exec["causation_id"] == nil || exec["causation_id"] == "" {
+ exec := findTrace(t, h, "hexis", "execute")
+ if exec.CausationID == "" {
t.Error("execute trace must carry the causation id of the turn that caused it")
}
- if exec["correlation_id"] == exec["causation_id"] {
+ if exec.CorrelationID == exec.CausationID {
t.Error("execute correlation and causation must be distinguishable")
}
}
+// TestEcosystemTrace_OneCorrelationIDPerPraxisAction: a digest calls attention
+// once and surface once per item. All of it is one turn, so the far side must
+// see one ID and not N+1 unrelated ones.
+func TestEcosystemTrace_OneCorrelationIDPerPraxisAction(t *testing.T) {
+ ctx := context.Background()
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems(
+ map[string]any{"id": "item_1", "title": "disk almost full", "importance": 3.0},
+ map[string]any{"id": "item_2", "title": "backup is stale", "importance": 2.0},
+ ))
+ h := ecoHandler(t, nil, praxis, nil)
+
+ if reply := h.handlePraxisAct(ctx, praxisActDec("list_attention")); !strings.Contains(reply, "disk almost full") {
+ t.Fatalf("setup: expected the digest, got %q", reply)
+ }
+
+ reqs := praxis.Requests()
+ if len(reqs) < 3 {
+ t.Fatalf("expected attention plus one surface per item, got %d requests", len(reqs))
+ }
+ first := reqs[0].Header.Get("X-Correlation-ID")
+ if first == "" {
+ t.Fatal("every ecosystem request must carry a correlation id")
+ }
+ for _, r := range reqs {
+ if got := r.Header.Get("X-Correlation-ID"); got != first {
+ t.Fatalf("%s %s carried %q, want the action's id %q", r.Method, r.Path, got, first)
+ }
+ }
+ tr := findTrace(t, h, "praxis", "list_attention")
+ if tr == nil || tr.CorrelationID != first {
+ t.Fatalf("the trace must carry the id that was actually sent, got %+v", tr)
+ }
+}
+
// TestEcosystemTrace_FailuresAreTracedToo: the whole point of the change —
// a failed hop is exactly the one worth having recorded.
func TestEcosystemTrace_FailuresAreTracedToo(t *testing.T) {
@@ -203,18 +220,39 @@ func TestEcosystemTrace_FailuresAreTracedToo(t *testing.T) {
_ = h.handleHexisAct(ctx, actDec("muzick indexer"))
- d := findTrace(ecoTraces(t, h), "nexus", "resolve")
+ d := findTrace(t, h, "nexus", "resolve")
if d == nil {
t.Fatal("a failed resolve must still be traced")
}
- if d["status"] != traceFailed {
- t.Errorf("status = %v, want failed", d["status"])
+ if d.Status != traceRefused {
+ t.Errorf("status = %v, want refused: the far side answered", d.Status)
}
- if d["class"] != "unauthorized" {
- t.Errorf("class = %v, want unauthorized", d["class"])
+ if d.Fields["class"] != "unauthorized" {
+ t.Errorf("class = %v, want unauthorized", d.Fields["class"])
}
- if d["http_status"] != float64(401) {
- t.Errorf("http_status = %v, want 401", d["http_status"])
+ if d.HTTPStatus != 401 {
+ t.Errorf("http_status = %v, want 401", d.HTTPStatus)
+ }
+}
+
+// TestEcosystemTrace_UnreachableIsNotRefused: never got an answer and answered
+// with a refusal are different failures, and the trace must say which.
+func TestEcosystemTrace_UnreachableIsNotRefused(t *testing.T) {
+ ctx := context.Background()
+ h := ecoHandler(t, nil, nil, nil)
+ h.ecosystem.nexus = newNexusClient("http://127.0.0.1:1")
+
+ _ = h.handleHexisAct(ctx, actDec("muzick indexer"))
+
+ d := findTrace(t, h, "nexus", "resolve")
+ if d == nil {
+ t.Fatal("an unreachable resolve must still be traced")
+ }
+ if d.Status != traceFailed {
+ t.Errorf("status = %v, want failed", d.Status)
+ }
+ if d.Fields["class"] != "unreachable" {
+ t.Errorf("class = %v, want unreachable", d.Fields["class"])
}
}
@@ -227,28 +265,23 @@ func TestEcosystemTrace_RedactsTheUtterance(t *testing.T) {
_ = h.handleHexisAct(ctx, actDec("перезапусти кофемашину"))
- facts, err := h.dataStore.RecentFacts(ctx, 100)
- if err != nil {
- t.Fatalf("read facts: %v", err)
- }
- var traced []store.Fact
- for _, f := range facts {
- if f.Source == "ecosystem:trace" {
- traced = append(traced, f)
- }
- if strings.Contains(f.Value, "кофемашину") && f.Source == "ecosystem:trace" {
- t.Fatalf("trace leaked the utterance: %q", f.Value)
- }
- }
- if len(traced) == 0 {
+ recorded := traces(t, h)
+ if len(recorded) == 0 {
t.Fatal("expected a not_found resolve trace")
}
- d := findTrace(ecoTraces(t, h), "nexus", "resolve")
- if d["status"] != traceNotFound {
- t.Errorf("status = %v, want not_found", d["status"])
+ for _, tr := range recorded {
+ for k, v := range tr.Fields {
+ if s, ok := v.(string); ok && strings.Contains(s, "кофемашину") {
+ t.Fatalf("trace leaked the utterance in %s: %q", k, s)
+ }
+ }
}
- if d["subject"] != redactSubject("перезапусти кофемашину") {
- t.Errorf("subject = %v, want a redacted length", d["subject"])
+ d := findTrace(t, h, "nexus", "resolve")
+ if d.Status != traceNotFound {
+ t.Errorf("status = %v, want not_found", d.Status)
+ }
+ if d.Fields["subject"] != redactSubject("перезапусти кофемашину") {
+ t.Errorf("subject = %v, want a redacted length", d.Fields["subject"])
}
}
@@ -263,7 +296,7 @@ func TestEcosystemTrace_AmbiguityAndConfirmationAreRecorded(t *testing.T) {
hexis := newFakeHexis(t, restartCaps(), fixtureHexisExecuted("exec_1", "succeeded"))
h := ecoHandler(t, ambig, nil, hexis)
_ = h.handleHexisAct(ctx, actDec("muzick"))
- if d := findTrace(ecoTraces(t, h), "nexus", "resolve"); d == nil || d["status"] != traceAmbig {
+ if d := findTrace(t, h, "nexus", "resolve"); d == nil || d.Status != traceAmbig {
t.Fatalf("ambiguous resolve must be traced as such, got %+v", d)
}
@@ -271,7 +304,13 @@ func TestEcosystemTrace_AmbiguityAndConfirmationAreRecorded(t *testing.T) {
mutating := fixtureHexisCapabilities(map[string]any{"id": "cap_restart", "name": "restart", "read_only": false})
h2 := ecoHandler(t, nexus, nil, newFakeHexis(t, mutating, fixtureHexisExecuted("exec_1", "succeeded")))
_ = h2.handleHexisAct(ctx, actDec("restart"))
- if d := findTrace(ecoTraces(t, h2), "hexis", "confirmation"); d == nil || d["status"] != "pending" {
+ d := findTrace(t, h2, "hexis", "confirmation")
+ if d == nil || d.Status != tracePending {
t.Fatalf("a parked confirmation must be traced, got %+v", d)
}
+ // The confirmation hop is measured from the top of the action, not from
+ // the instant it is recorded, which was always zero.
+ if d.DurationMs == 0 {
+ t.Error("the confirmation trace must report the time the action took to get there")
+ }
}
diff --git a/cmd/mavend/entityrefs_test.go b/cmd/mavend/entityrefs_test.go
index 2f7d236..4a4877f 100644
--- a/cmd/mavend/entityrefs_test.go
+++ b/cmd/mavend/entityrefs_test.go
@@ -28,7 +28,7 @@ func entityAttentionDec(subject string) router.Decision {
func TestEntityAttention_ScopesPraxisByCanonicalID(t *testing.T) {
ctx := context.Background()
nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
- praxis := newFakePraxis(t, fixturePraxisAttentionItems(
+ praxis := newFakePraxis(t, fixturePraxisAttentionScoped("ent_muzick",
map[string]any{"id": "item_1", "title": "indexer queue is backing up", "importance": 3.0},
))
h := ecoHandler(t, nexus, praxis, nil)
@@ -76,6 +76,76 @@ func TestEntityAttention_FoldsInLocalFactsForSameEntity(t *testing.T) {
}
}
+// TestEntityAttention_UnscopedPraxisResponseIsRefused: a Praxis old enough to
+// ignore the entity_id parameter answers the scoped question with the whole
+// unscoped list. Relabelling those items "по «X»" is the same fabrication the
+// canonical ref exists to prevent, arriving through a different door.
+func TestEntityAttention_UnscopedPraxisResponseIsRefused(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems(
+ map[string]any{"id": "item_1", "title": "disk almost full", "importance": 3.0},
+ ))
+ h := ecoHandler(t, nexus, praxis, nil)
+
+ reply := h.handlePraxisAct(ctx, entityAttentionDec("muzick indexer"))
+ if strings.Contains(reply, "disk almost full") {
+ t.Fatalf("an unscoped response must not be read back as entity-scoped, got %q", reply)
+ }
+ if reply == "" {
+ t.Fatal("refusing the answer must still say something")
+ }
+ if praxis.Count("POST", "/api/v1/tools/surface") != 0 {
+ t.Error("items that were never spoken must not be surfaced")
+ }
+}
+
+// TestEntityAttention_ForeignItemsAreDropped: items tagged with another entity
+// are dropped rather than spoken under this entity's name.
+func TestEntityAttention_ForeignItemsAreDropped(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_muzick", "Muzick indexer", "service"))
+ mixed := []map[string]any{
+ {"id": "item_1", "title": "indexer queue is backing up", "importance": 3.0, "entity_id": "ent_muzick"},
+ {"id": "item_2", "title": "the kettle is descaling", "importance": 1.0, "entity_id": "ent_kettle"},
+ }
+ praxis := newFakePraxis(t, mustJSON(mixed))
+ h := ecoHandler(t, nexus, praxis, nil)
+
+ reply := h.handlePraxisAct(ctx, entityAttentionDec("muzick indexer"))
+ if !strings.Contains(reply, "indexer queue is backing up") {
+ t.Fatalf("the matching item must be spoken, got %q", reply)
+ }
+ if strings.Contains(reply, "kettle") {
+ t.Fatalf("another entity's item must not be spoken here, got %q", reply)
+ }
+}
+
+// TestEntityAttention_TruncationIsNamed: reading three of many remembered
+// facts must not be presented as everything she knows.
+func TestEntityAttention_TruncationIsNamed(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_espresso", "the espresso machine", "device"))
+ praxis := newFakePraxis(t, fixturePraxisAttentionItems())
+ h := ecoHandler(t, nexus, praxis, nil)
+
+ for i := 0; i < 5; i++ {
+ id, err := h.dataStore.WriteFactAboutSubject(ctx, time.Now(), store.KindEnv,
+ "note", "the espresso machine", "факт "+string(rune('а'+i)), "infer:pref", 0.8, sql.NullInt64{})
+ if err != nil {
+ t.Fatalf("WriteFactAboutSubject: %v", err)
+ }
+ if err := h.dataStore.ResolveFactEntity(ctx, id, "ent_espresso", store.ResolutionResolved); err != nil {
+ t.Fatalf("ResolveFactEntity: %v", err)
+ }
+ }
+
+ reply := h.handlePraxisAct(ctx, entityAttentionDec("the espresso machine"))
+ if !strings.Contains(reply, "и это не всё") {
+ t.Fatalf("a truncated recall must say it is truncated, got %q", reply)
+ }
+}
+
// TestEntityAttention_AmbiguousAsksInsteadOfGuessing.
func TestEntityAttention_AmbiguousAsksInsteadOfGuessing(t *testing.T) {
ctx := context.Background()
@@ -145,7 +215,7 @@ func TestEntityAttention_WithoutNexusSaysSo(t *testing.T) {
reply := h.handlePraxisAct(ctx, entityAttentionDec("muzick indexer"))
if strings.Contains(reply, "disk almost full") {
- t.Fatalf("unscoped items must not be passed off as entity-scoped, got %q", reply)
+ t.Fatalf("without nexus, items must not be passed off as entity-scoped, got %q", reply)
}
if praxis.Count("GET", "/api/v1/tools/attention") != 0 {
t.Fatal("no canonical ref means no scoped query at all")
@@ -211,3 +281,78 @@ func TestEnrichmentBackoff_GrowsAndIsCapped(t *testing.T) {
t.Fatalf("backoff must cap at an hour, got %v", enrichmentBackoff(50))
}
}
+
+// TestEnrichment_BackedOffFactsDoNotStallTheQueue: the pending queue is ordered
+// by id, so the oldest facts are pulled first whether or not they are eligible.
+// A batch of facts in backoff at the head must not hold every slot and stop
+// enrichment for everything younger.
+func TestEnrichment_BackedOffFactsDoNotStallTheQueue(t *testing.T) {
+ ctx := context.Background()
+ st := newTestStore(t)
+ total := 5
+ for i := 0; i < total; i++ {
+ if _, err := st.WriteFactAboutSubject(ctx, time.Now(), store.KindEnv, "likes",
+ "subject-"+string(rune('a'+i)), `"true"`, "infer:pref", 0.8, sql.NullInt64{}); err != nil {
+ t.Fatalf("WriteFactAboutSubject: %v", err)
+ }
+ }
+
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_x", "X", "service"))
+ clock := newFakeClock(time.Date(2026, 8, 1, 3, 0, 0, 0, time.UTC))
+ w := newFactEnrichmentWorker(st, stubEcosystem(nexus.URL, ""), time.Hour)
+ w.now = clock.Now
+ // A batch smaller than the queue, so with no scan the last fact never
+ // reaches the head while the first ones are backed off.
+ w.batch = total - 1
+
+ nexus.SetFault(503)
+ w.tick(ctx)
+ if got := nexus.Count("POST", "/api/v1/resolve"); got != total-1 {
+ t.Fatalf("expected the first batch attempted, got %d calls", got)
+ }
+
+ // Second tick with Nexus healthy: the backed-off head must be skipped and
+ // the fact behind it resolved, not the same batch pulled and dropped.
+ nexus.SetFault(0)
+ w.tick(ctx)
+ facts, err := st.FactsByEntity(ctx, "ent_x", 10)
+ if err != nil {
+ t.Fatalf("FactsByEntity: %v", err)
+ }
+ if len(facts) == 0 {
+ t.Fatal("a due fact behind a backed-off batch must still be resolved")
+ }
+}
+
+// TestEnrichment_StoreWriteFailureBacksOffToo: the one failure mode where the
+// resolve worked and the write did not must be paced like any other, not
+// retried at full rate forever.
+func TestEnrichment_StoreWriteFailureBacksOffToo(t *testing.T) {
+ ctx := context.Background()
+ nexus := newFakeNexus(t, fixtureNexusResolved("ent_espresso", "the espresso machine", "device"))
+ st := newTestStore(t)
+ if _, err := st.WriteFactAboutSubject(ctx, time.Now(), store.KindEnv, "likes",
+ "the espresso machine", `"true"`, "infer:pref", 0.8, sql.NullInt64{}); err != nil {
+ t.Fatalf("WriteFactAboutSubject: %v", err)
+ }
+ pending, err := st.PendingFactResolutions(ctx, 10)
+ if err != nil || len(pending) != 1 {
+ t.Fatalf("setup: pending = %+v, %v", pending, err)
+ }
+
+ clock := newFakeClock(time.Date(2026, 8, 1, 3, 0, 0, 0, time.UTC))
+ w := newFactEnrichmentWorker(st, stubEcosystem(nexus.URL, ""), time.Hour)
+ w.now = clock.Now
+
+ // Closing the store makes the resolution write fail while the Nexus call
+ // still succeeds — the split this path gets wrong.
+ if err := st.Close(); err != nil {
+ t.Fatalf("close store: %v", err)
+ }
+ if w.resolveOne(ctx, pending[0]) {
+ t.Fatal("a failed store write must not report success")
+ }
+ if w.due(pending[0].ID) {
+ t.Fatal("a failed store write must back the fact off like a failed resolve")
+ }
+}
diff --git a/cmd/mavend/factenrichment.go b/cmd/mavend/factenrichment.go
index a19ea55..835e630 100644
--- a/cmd/mavend/factenrichment.go
+++ b/cmd/mavend/factenrichment.go
@@ -35,9 +35,15 @@ type factEnrichmentWorker struct {
mu sync.Mutex
attempt map[int64]int // fact id → consecutive failures
nextTry map[int64]time.Time // fact id → earliest retry
- skipped int // facts held back by backoff on the last tick
}
+// enrichmentScanLimit bounds how deep a single tick (or status report) walks
+// the pending queue looking for facts whose backoff has elapsed. The queue is
+// ordered by id, so without a scan the oldest facts hold every batch slot
+// whether or not they are eligible, and one permanently failing fact stalls
+// every younger one behind it.
+const enrichmentScanLimit = 1000
+
// enrichmentBackoff is the wait before retrying a fact after n consecutive
// failures, capped so a long Nexus outage still retries about hourly.
func enrichmentBackoff(n int) time.Duration {
@@ -64,26 +70,39 @@ func newFactEnrichmentWorker(st *store.Store, eco *ecosystemWiring, interval tim
}
// enrichmentStatus is what the worker reports about its own health: how many
-// facts are waiting, how many are currently in backoff, and the worst retry
-// count seen. Degradation is reported, never hidden — a Nexus that has been
-// down all day must be visible as a backlog, not as facts that silently
-// never got tagged.
+// facts are waiting, how many of those are currently in backoff, and the worst
+// retry count among them. Degradation is reported, never hidden — a Nexus that
+// has been down all day must be visible as a backlog, not as facts that
+// silently never got tagged.
+//
+// All three numbers describe the same set of rows, the first
+// enrichmentScanLimit pending facts. Counting Pending over a thousand rows
+// while counting InBackoff over the twenty that reached the head of a batch
+// described two different populations under one struct.
type enrichmentStatus struct {
Pending int
InBackoff int
MaxAttempts int
+ Scanned int // rows the other three counts were taken over
}
func (w *factEnrichmentWorker) status(ctx context.Context) enrichmentStatus {
var st enrichmentStatus
- if pending, err := w.store.PendingFactResolutions(ctx, 1000); err == nil {
- st.Pending = len(pending)
+ pending, err := w.store.PendingFactResolutions(ctx, enrichmentScanLimit)
+ if err != nil {
+ log.Printf("factenrichment: status: %v", err)
+ return st
}
+ st.Pending = len(pending)
+ st.Scanned = len(pending)
w.mu.Lock()
defer w.mu.Unlock()
- st.InBackoff = w.skipped
- for _, n := range w.attempt {
- if n > st.MaxAttempts {
+ now := w.now()
+ for _, f := range pending {
+ if next, ok := w.nextTry[f.ID]; ok && now.Before(next) {
+ st.InBackoff++
+ }
+ if n := w.attempt[f.ID]; n > st.MaxAttempts {
st.MaxAttempts = n
}
}
@@ -112,27 +131,65 @@ func (w *factEnrichmentWorker) run(ctx context.Context) {
}
func (w *factEnrichmentWorker) tick(ctx context.Context) {
- pending, err := w.store.PendingFactResolutions(ctx, w.batch)
+ // Scan past the facts that are still in backoff instead of letting them
+ // occupy the batch. The queue is ordered by id, so the oldest facts are
+ // pulled first whether or not they are eligible: twenty facts Nexus keeps
+ // rejecting would otherwise hold every slot forever and enrichment would
+ // stop with no error and no log line, because a tick that skips everything
+ // fails nothing.
+ pending, err := w.store.PendingFactResolutions(ctx, enrichmentScanLimit)
if err != nil {
log.Printf("factenrichment: list pending: %v", err)
return
}
- skipped, failed := 0, 0
+ w.forgetDeparted(pending)
+ skipped, failed, attempted := 0, 0, 0
for _, f := range pending {
+ if attempted >= w.batch {
+ break
+ }
if !w.due(f.ID) {
skipped++
continue
}
+ attempted++
if !w.resolveOne(ctx, f) {
failed++
}
}
- w.mu.Lock()
- w.skipped = skipped
- w.mu.Unlock()
if failed > 0 {
log.Printf("factenrichment: %d/%d resolutions failed this tick, %d held in backoff",
- failed, len(pending), skipped)
+ failed, attempted, skipped)
+ }
+ // Report the backlog every tick, not only when something failed: the
+ // stalled state worth seeing is the one where nothing failed because
+ // nothing was attempted.
+ if st := w.status(ctx); st.Pending > 0 {
+ log.Printf("factenrichment: %d facts pending entity resolution, %d in backoff, worst attempt %d (scanned %d)",
+ st.Pending, st.InBackoff, st.MaxAttempts, st.Scanned)
+ }
+}
+
+// forgetDeparted drops retry state for facts that are no longer pending. A
+// fact can leave the queue without ever resolving here — voided, or resolved
+// by a later write — and its entries would otherwise live as long as the
+// process does.
+func (w *factEnrichmentWorker) forgetDeparted(pending []store.Fact) {
+ live := make(map[int64]struct{}, len(pending))
+ for _, f := range pending {
+ live[f.ID] = struct{}{}
+ }
+ w.mu.Lock()
+ defer w.mu.Unlock()
+ for id := range w.attempt {
+ if _, ok := live[id]; !ok {
+ delete(w.attempt, id)
+ }
+ }
+ for id := range w.nextTry {
+ if _, ok := live[id]; !ok {
+ delete(w.nextTry, id)
+ }
}
}
@@ -150,17 +207,11 @@ func (w *factEnrichmentWorker) resolveOne(ctx context.Context, f store.Fact) boo
entityID, _, ambiguous, err := w.eco.resolveEntityReference(ctx, f.Subject, nil)
if err != nil {
// Transient (Nexus unreachable) — leave pending, back off, retry later.
- log.Printf("factenrichment: resolve fact %d subject %q: %v", f.ID, f.Subject, err)
- w.mu.Lock()
- w.attempt[f.ID]++
- w.nextTry[f.ID] = w.now().Add(enrichmentBackoff(w.attempt[f.ID]))
- w.mu.Unlock()
+ // The subject is his words: log its length, the way the trace does.
+ log.Printf("factenrichment: resolve fact %d subject %s: %v", f.ID, redactSubject(f.Subject), err)
+ w.backOff(f.ID)
return false
}
- w.mu.Lock()
- delete(w.attempt, f.ID)
- delete(w.nextTry, f.ID)
- w.mu.Unlock()
state := store.ResolutionNotFound
switch {
case entityID != "":
@@ -169,8 +220,25 @@ func (w *factEnrichmentWorker) resolveOne(ctx context.Context, f store.Fact) boo
state = store.ResolutionAmbiguous
}
if err := w.store.ResolveFactEntity(ctx, f.ID, entityID, state); err != nil {
+ // A failed write leaves the fact pending exactly like a failed resolve
+ // does, so it gets the same pacing. Clearing the counters first meant
+ // this one path retried every tick, at full rate, with no ceiling.
log.Printf("factenrichment: record resolution for fact %d: %v", f.ID, err)
+ w.backOff(f.ID)
return false
}
+ w.mu.Lock()
+ delete(w.attempt, f.ID)
+ delete(w.nextTry, f.ID)
+ w.mu.Unlock()
return true
}
+
+// backOff records one more consecutive failure for a fact and pushes its next
+// attempt out accordingly.
+func (w *factEnrichmentWorker) backOff(id int64) {
+ w.mu.Lock()
+ defer w.mu.Unlock()
+ w.attempt[id]++
+ w.nextTry[id] = w.now().Add(enrichmentBackoff(w.attempt[id]))
+}
diff --git a/cmd/mavend/fakeecosystem_test.go b/cmd/mavend/fakeecosystem_test.go
index 108860f..707f6ab 100644
--- a/cmd/mavend/fakeecosystem_test.go
+++ b/cmd/mavend/fakeecosystem_test.go
@@ -27,11 +27,12 @@ type capturedRequest struct {
type fakeServer struct {
*httptest.Server
- mu sync.Mutex
- requests []capturedRequest
- fault int // non-zero: every request gets this HTTP status instead of routing
- garbage string // non-empty: returned 200 verbatim instead of routing (malformed-contract lever)
- delay time.Duration
+ mu sync.Mutex
+ requests []capturedRequest
+ fault int // non-zero: every request gets this HTTP status instead of routing
+ routeFaults map[string]int // path prefix → status, for one endpoint failing alone
+ garbage string // non-empty: returned 200 verbatim instead of routing (malformed-contract lever)
+ delay time.Duration
}
// newFakeServer starts a server dispatching to routes keyed by "METHOD
@@ -59,6 +60,14 @@ func newFakeServer(t *testing.T, routes map[string]http.HandlerFunc) *fakeServer
Header: r.Header.Clone(),
})
fault := fs.fault
+ if fault == 0 {
+ for prefix, status := range fs.routeFaults {
+ if hasPrefix(r.URL.Path, prefix) {
+ fault = status
+ break
+ }
+ }
+ }
garbage := fs.garbage
delay := fs.delay
fs.mu.Unlock()
@@ -114,6 +123,22 @@ func (fs *fakeServer) SetFault(status int) {
fs.fault = status
}
+// SetRouteFault fails one endpoint while the rest of the server stays healthy,
+// which is the shape most real outages take: attention answers and pin is
+// down. Pass 0 to clear that route. A server-wide SetFault still wins.
+func (fs *fakeServer) SetRouteFault(pathPrefix string, status int) {
+ fs.mu.Lock()
+ defer fs.mu.Unlock()
+ if fs.routeFaults == nil {
+ fs.routeFaults = map[string]int{}
+ }
+ if status == 0 {
+ delete(fs.routeFaults, pathPrefix)
+ return
+ }
+ fs.routeFaults[pathPrefix] = status
+}
+
// SetBody makes every subsequent request answer 200 with the given body,
// bypassing the route table. Used to serve a malformed or contract-violating
// payload where the transport itself is healthy. Pass "" to clear it.
@@ -198,6 +223,14 @@ func fixtureNexusResolvedFuture(entityID, displayName, entityType string) string
})
}
+// fixtureNexusResolvedEmpty is the contract violation that decodes cleanly:
+// Nexus claims a resolve and delivers no entity. It must not read as "no such
+// entity", which would let the caller fall through to local execution with the
+// user's verb intact.
+func fixtureNexusResolvedEmpty() string {
+ return `{"status":"resolved"}`
+}
+
func fixtureNexusNotFound() string {
return `{"status":"not_found"}`
}
@@ -225,6 +258,16 @@ func fixtureHexisExecutionFailed(id, message string) string {
return mustJSON(map[string]any{"id": id, "status": "failed", "error": message})
}
+// fixturePraxisAttentionScoped tags each item with an entity_id, which is what
+// a Praxis that understands the entity_id query parameter returns. A Praxis
+// that ignores it answers with untagged items from every entity.
+func fixturePraxisAttentionScoped(entityID string, items ...map[string]any) string {
+ for _, item := range items {
+ item["entity_id"] = entityID
+ }
+ return mustJSON(items)
+}
+
func fixturePraxisAttentionItems(items ...map[string]any) string {
return mustJSON(items)
}
@@ -243,18 +286,28 @@ func mustJSON(v any) string {
// (e.g. asserting age-based digest ordering without sleeping).
type fakeClock struct {
- mu sync.Mutex
- t time.Time
+ mu sync.Mutex
+ t time.Time
+ step time.Duration // advanced on every read, so elapsed time is measurable
}
func newFakeClock(start time.Time) *fakeClock {
return &fakeClock{t: start}
}
+// newTickingClock advances by step on every read. Durations measured across
+// hops are then non-zero without sleeping, which is what lets a test tell a
+// trace that measured something from one that measured nothing.
+func newTickingClock(start time.Time, step time.Duration) *fakeClock {
+ return &fakeClock{t: start, step: step}
+}
+
func (c *fakeClock) Now() time.Time {
c.mu.Lock()
defer c.mu.Unlock()
- return c.t
+ now := c.t
+ c.t = c.t.Add(c.step)
+ return now
}
func (c *fakeClock) Advance(d time.Duration) {
diff --git a/cmd/mavweb/ecosystem.go b/cmd/mavweb/ecosystem.go
index 7198853..77a329c 100644
--- a/cmd/mavweb/ecosystem.go
+++ b/cmd/mavweb/ecosystem.go
@@ -8,6 +8,8 @@ import (
"net/http"
"sync"
"time"
+
+ "github.com/kami/maven/internal/ipc"
)
// The three sibling services Maven coordinates are headless JSON APIs (no web UI
@@ -84,9 +86,13 @@ type ecoData struct {
Nexus ecoPanel[ecoEntity]
Praxis ecoPanel[ecoItem]
Hexis ecoPanel[ecoCap]
+ Calls ecoPanel[ipc.EcosystemTrace]
}
-func handleEcosystem(w http.ResponseWriter, r *http.Request, urls ecoURLs) {
+// handleEcosystem renders the three sibling panels plus Maven's own log of the
+// calls she made to them. The call log comes from core, not from the siblings:
+// it is what Maven saw, including the hops that never got an answer.
+func handleEcosystem(w http.ResponseWriter, r *http.Request, urls ecoURLs, core ipc.CoreAPI) {
ctx := r.Context()
var d ecoData
var wg sync.WaitGroup
@@ -102,6 +108,15 @@ func handleEcosystem(w http.ResponseWriter, r *http.Request, urls ecoURLs) {
go func() { defer wg.Done(); d.Hexis.Err = getEco(ctx, urls.hexis, "/api/v1/capabilities", &d.Hexis.Rows) }()
wg.Wait()
+ if core == nil {
+ d.Calls.Err = "not configured"
+ } else if rows, err := core.RecentEcosystemTraces(ctx, 50); err != nil {
+ log.Printf("ecosystem traces: %v", err)
+ d.Calls.Err = "core read failed"
+ } else {
+ d.Calls.Rows = rows
+ }
+
w.Header().Set("Content-Type", "text/html; charset=utf-8")
if err := ecosystemTmpl.Execute(w, d); err != nil {
log.Printf("ecosystem render: %v", err)
diff --git a/cmd/mavweb/ecosystem.html b/cmd/mavweb/ecosystem.html
index 1bce15f..719173e 100644
--- a/cmd/mavweb/ecosystem.html
+++ b/cmd/mavweb/ecosystem.html
@@ -41,11 +41,24 @@
{{end}}
+
+