Log refused actions and name the missed command-agent lookup

A refused action plan, decision, or execution returned its 409 to the
client and left no trace in the server journal, so every remote report
of "Docker / Podman command agent is not connected" stalled on greps
that could never match anything. Refusals now log one warn line with
the resource, capability, and reason code, and the Docker command-agent
resolver reports which lookup missed (stale enrollment token binding vs
agent-id/hostname session), carried as an optional diagnostic detail on
the readiness contract and in the refusal envelope.

Refs #1728
This commit is contained in:
rcourtman
2026-08-23 06:33:30 +01:00
parent c313a80daa
commit ea5c105ff2
10 changed files with 192 additions and 29 deletions
@@ -960,7 +960,12 @@ reconnect, substitute, or directly address an agent to make a stale container
action executable. Backend resource payloads and plan-action readiness are the
only supported lifecycle signal for that state. When a resource payload carries
typed `actionReadiness`, lifecycle surfaces may display the reason but must not
treat it as reconnect authority or an alternate command grant.
treat it as reconnect authority or an alternate command grant. The optional
`detail` such an entry may carry (naming the missed enrollment-token or
session lookup) and the server-side warn log every availability refusal now
writes are the same API-owned diagnosis surface: they add no agent-visible
transport, and no surface gains reconnect, rebind, or command authority from
reading them.
Assistant session rename through `PATCH /api/ai/sessions/{id}` follows that
same browser-safe history boundary. Lifecycle surfaces, MCP adapters, and
agents may display the updated title as human navigation metadata, but they
@@ -2463,7 +2463,11 @@ a new API state machine, queue contract, or verification-accounting field.
Resource payloads may expose the same executor-owned unavailable state as
`actionReadiness[]` entries with stable `name`, `available`, `reasonCode`,
and `reason` fields so browser and agent clients can explain disabled
actions without treating unavailable capabilities as executable.
actions without treating unavailable capabilities as executable. A readiness
entry may add an optional bounded `detail` naming the concrete lookup the
refusal was judged against (for example the stale enrollment token id, or
the agent-id / hostname session lookups that missed); `reason` stays the
stable operator-safe copy and clients must not branch on `detail` text.
Action approval decisions are API-owned as a separate non-execution
contract: `POST /api/actions/{id}/decision` may only record an
`approved` or `rejected` decision against a persisted `pending_approval`
@@ -4273,7 +4277,13 @@ canonical resource and then asks the optional executor-owned
`ExecuteUnderPolicy`, so an automatic broker cannot bypass it. A resource that
disappears remains `action_plan_drift`; an explicitly unavailable capability
returns HTTP `409` with shared code `action_execution_unavailable` and bounded
`resourceId`, `capabilityName`, `reasonCode`, and `reason` details. Pulse
`resourceId`, `capabilityName`, `reasonCode`, and `reason` details, plus an
optional `detail` when the executor supplies a lookup diagnostic. Every
availability refusal rendered through that shared envelope — plan, decision,
and execution alike — also writes one server-side warn log line naming the
resource, capability, reason code, and diagnostic, because a refusal that
reaches the client as a toast while the server journal stays empty is
undiagnosable from a remote bug report (#1728). Pulse
persists a terminal failed/no-effect audit and lifecycle event and publishes
the normal completion notification. Executors without either optional checker,
and checkers returning an empty readiness result, preserve the existing
@@ -384,6 +384,11 @@ no new persisted state: it is read from live Patrol runtime status at snapshot
time, not from the run history list or the run tally, records no run identity,
provider configuration, or blocked-reason text, and is likewise not recovery
coverage or storage-health proof.
Availability-refusal warn logs and the optional `actionReadiness` `detail`
emitted through the shared `internal/api/` action handlers are likewise
process-log observability only: they create no persisted state, no storage or
recovery signal, and no backup, restore, or storage-health proof.
First-party workflow starter activity recorded through shared `internal/api/`
handlers, including Pro activation entry-point telemetry for the same
operations-loop prompt, is likewise API/privacy/commercial activation evidence
@@ -907,7 +907,12 @@ cannot create a browser mutation.
`available=false`, a stable reason code such as
`command_agent_disconnected`, and operator-safe copy. Frontend consumers may
use that field to explain disabled controls, while `capabilities` remains
the executable action set.
the executable action set. The same readiness entry may carry an optional
`detail` naming which command-session lookup the refusal was judged against
(the immutable enrollment token binding versus the agent-id / hostname
session lookups); it is diagnostic copy for server logs and support
threads, `reason` remains the stable user-facing text, and consumers must
not branch on `detail` content.
Proxmox VM and LXC lifecycle actions are also part of that governed
resource contract. `resourceFromVM` and `resourceFromContainer` may advertise
`start` only for stopped guests and `shutdown`, `reboot`, and `stop` only
+30 -18
View File
@@ -16,6 +16,7 @@ import (
"github.com/rcourtman/pulse-go-rewrite/internal/api/resourceapi"
"github.com/rcourtman/pulse-go-rewrite/internal/mock"
unified "github.com/rcourtman/pulse-go-rewrite/internal/unifiedresources"
"github.com/rs/zerolog/log"
)
const maxActionPlanRequestBytes = 1 << 20
@@ -337,6 +338,32 @@ func (h *ResourceHandlers) HandleGetAction(w http.ResponseWriter, r *http.Reques
}
}
// writeActionExecutionUnavailable renders an availability refusal into the
// stable 409 contract and logs it. Refusals previously produced only a client
// toast while the server journal stayed empty, so remote reports of "command
// agent is not connected" were undiagnosable without source access (#1728).
func writeActionExecutionUnavailable(w http.ResponseWriter, refusal *actionlifecycle.AvailabilityRefusedError) {
reason := firstNonEmpty(refusal.Readiness.Reason, "action execution is unavailable")
details := map[string]string{
"resourceId": refusal.ResourceID,
"capabilityName": refusal.CapabilityName,
"reasonCode": refusal.Readiness.ReasonCode,
"reason": reason,
}
detail := strings.TrimSpace(refusal.Readiness.Detail)
if detail != "" {
details["detail"] = detail
}
log.Warn().
Str("resource_id", refusal.ResourceID).
Str("capability", refusal.CapabilityName).
Str("reason_code", refusal.Readiness.ReasonCode).
Str("reason", reason).
Str("detail", detail).
Msg("Action refused: capability is not currently executable")
writeJSONErrorWithDetails(w, http.StatusConflict, agentcapabilities.AgentErrCodeActionExecutionUnavailable, "Action execution is unavailable", details)
}
func writeActionPlanError(w http.ResponseWriter, err error) {
var validationErr *actionplanner.ValidationError
var notFound *actionlifecycle.ResourceNotFoundError
@@ -362,12 +389,7 @@ func writeActionPlanError(w http.ResponseWriter, err error) {
"resourceId": notFound.ResourceID,
})
case errors.As(err, &unavailable):
writeJSONErrorWithDetails(w, http.StatusConflict, agentcapabilities.AgentErrCodeActionExecutionUnavailable, "Action execution is unavailable", map[string]string{
"resourceId": unavailable.ResourceID,
"capabilityName": unavailable.CapabilityName,
"reasonCode": unavailable.Readiness.ReasonCode,
"reason": firstNonEmpty(unavailable.Readiness.Reason, "action execution is unavailable"),
})
writeActionExecutionUnavailable(w, unavailable)
case errors.Is(err, actionlifecycle.ErrRegistryUnavailable):
writeJSONError(w, http.StatusInternalServerError, "resource_registry_unavailable", sanitizeErrorForClient(err, "Resource registry unavailable"))
case errors.Is(err, actionlifecycle.ErrStoreUnavailable):
@@ -578,12 +600,7 @@ func writeActionReadinessError(w http.ResponseWriter, err error) bool {
var availabilityCheck *actionlifecycle.AvailabilityCheckError
switch {
case errors.As(err, &availability):
writeJSONErrorWithDetails(w, http.StatusConflict, agentcapabilities.AgentErrCodeActionExecutionUnavailable, "Action execution is unavailable", map[string]string{
"resourceId": availability.ResourceID,
"capabilityName": availability.CapabilityName,
"reasonCode": availability.Readiness.ReasonCode,
"reason": firstNonEmpty(availability.Readiness.Reason, "action execution is unavailable"),
})
writeActionExecutionUnavailable(w, availability)
case errors.Is(err, unified.ErrActionPlanDrift):
writeJSONError(w, http.StatusConflict, agentcapabilities.AgentErrCodeActionPlanDrift, "Action plan no longer matches the current resource contract; refresh the plan before continuing")
case errors.Is(err, unified.ErrActionEmergencyStop):
@@ -876,12 +893,7 @@ func writeActionExecuteError(w http.ResponseWriter, err error) {
case errors.Is(err, actionlifecycle.ErrExecutorUnavailable):
writeJSONError(w, http.StatusNotImplemented, agentcapabilities.AgentErrCodeActionExecutorUnavailable, "No action executor is configured for this API instance")
case errors.As(err, &availability):
writeJSONErrorWithDetails(w, http.StatusConflict, agentcapabilities.AgentErrCodeActionExecutionUnavailable, "Action execution is unavailable", map[string]string{
"resourceId": availability.ResourceID,
"capabilityName": availability.CapabilityName,
"reasonCode": availability.Readiness.ReasonCode,
"reason": firstNonEmpty(availability.Readiness.Reason, "action execution is unavailable"),
})
writeActionExecutionUnavailable(w, availability)
case errors.As(err, &persist):
writeActionExecutionPersistError(w, err)
case errors.As(err, &freshness):
+14
View File
@@ -21246,6 +21246,7 @@ func TestContract_ResourceActionReadinessPayloadShape(t *testing.T) {
Available: false,
ReasonCode: "command_agent_disconnected",
Reason: "Docker / Podman command agent is not connected.",
Detail: "no live command session for agent agent-1 or hostname docker-host",
},
},
})
@@ -21259,6 +21260,7 @@ func TestContract_ResourceActionReadinessPayloadShape(t *testing.T) {
`"available":false`,
`"reasonCode":"command_agent_disconnected"`,
`"reason":"Docker / Podman command agent is not connected."`,
`"detail":"no live command session for agent agent-1 or hostname docker-host"`,
} {
if !strings.Contains(body, want) {
t.Fatalf("resource action readiness payload missing %s: %s", want, body)
@@ -21267,6 +21269,18 @@ func TestContract_ResourceActionReadinessPayloadShape(t *testing.T) {
if strings.Contains(body, "InternalHandler") {
t.Fatalf("resource payload leaked internal action handler: %s", body)
}
bare, err := json.Marshal(unifiedresources.ResourceActionReadiness{
Name: "restart",
Available: false,
ReasonCode: "command_agent_disconnected",
Reason: "Docker / Podman command agent is not connected.",
})
if err != nil {
t.Fatalf("marshal readiness: %v", err)
}
if strings.Contains(string(bare), "detail") {
t.Fatalf("empty diagnostic detail must be omitted from the readiness payload: %s", bare)
}
}
func TestContract_ActionPreflightRefusalProjectsStableReadiness(t *testing.T) {
@@ -337,10 +337,12 @@ func (e dockerContainerActionExecutor) CheckActionAvailable(ctx context.Context,
if _, err := e.executableDockerContainerResource(ctx, resource, operation); err != nil {
return unavailableDockerActionReadiness(operation, dockerActionUnavailableReasonCode(err), dockerActionUnavailableReason(err))
}
if _, err := e.connectedDockerCommandAgentID(ctx, resource); err != nil {
return unavailableDockerActionReadiness(operation, "command_agent_disconnected", "Docker / Podman command agent is not connected.")
agentID, connectErr := e.connectedDockerCommandAgentID(ctx, resource)
if connectErr != nil {
readiness := unavailableDockerActionReadiness(operation, "command_agent_disconnected", "Docker / Podman command agent is not connected.")
readiness.Detail = connectErr.Error()
return readiness
}
agentID, _ := e.connectedDockerCommandAgentID(ctx, resource)
if liveAgentOperationReceiptVersion(ctx, e.agents, agentID) != operationreceipt.ProtocolVersion {
return unavailableDockerActionReadiness(operation, "operation_receipt_unsupported", "The Pulse agent on this host cannot run reviewed actions: it is on an older version, or its durable state directory is unavailable. Update the agent, or check the agent logs if it is already current, then retry.")
}
@@ -425,7 +427,7 @@ func (e dockerContainerActionExecutor) executableDockerContainerResource(_ conte
func (e dockerContainerActionExecutor) connectedDockerCommandAgentID(ctx context.Context, resource unified.Resource) (string, error) {
if e.agents == nil {
return "", fmt.Errorf("docker container command agent is not connected")
return "", fmt.Errorf("docker container command agent is not connected: no agent command server is configured")
}
if resource.Docker == nil {
return "", fmt.Errorf("docker resource metadata missing")
@@ -435,8 +437,8 @@ func (e dockerContainerActionExecutor) connectedDockerCommandAgentID(ctx context
}
// When telemetry names a token, it is the immutable session binding. Do
// not fall back to a different identity or hostname after rotation.
if strings.TrimSpace(resource.Docker.TokenID) != "" {
return "", fmt.Errorf("docker container command agent is not connected")
if tokenID := strings.TrimSpace(resource.Docker.TokenID); tokenID != "" {
return "", fmt.Errorf("docker container command agent is not connected: no live command session for enrollment token %s (agent %q, hostname %q); a token-named resource never falls back to identity or hostname lookup", tokenID, strings.TrimSpace(resource.Docker.AgentID), strings.TrimSpace(resource.Docker.Hostname))
}
if agentID := strings.TrimSpace(resource.Docker.AgentID); agentID != "" && isAgentCommandConnected(ctx, e.agents, agentID) {
return agentID, nil
@@ -447,7 +449,7 @@ func (e dockerContainerActionExecutor) connectedDockerCommandAgentID(ctx context
return agentID, nil
}
}
return "", fmt.Errorf("docker container command agent is not connected")
return "", fmt.Errorf("docker container command agent is not connected: no live command session for agent %q or hostname %q", strings.TrimSpace(resource.Docker.AgentID), strings.TrimSpace(resource.Docker.Hostname))
}
func unavailableDockerActionReadiness(operation, reasonCode, reason string) unified.ResourceActionReadiness {
@@ -671,3 +671,90 @@ func TestDockerContainerActionExecutorRefusesUpdateThroughLifecycleHandler(t *te
t.Fatalf("readiness = %+v, want fail-closed for wrong handler", readiness)
}
}
func TestDockerContainerActionAvailabilityDetailNamesMissedLookup(t *testing.T) {
now := time.Now().UTC()
request := unified.ActionRequest{
RequestID: "req-detail",
ResourceID: "app-container:api",
CapabilityName: "restart",
Reason: "operator requested restart",
RequestedBy: "operator",
}
resource := dockerContainerActionResource("app-container:api", "docker", "running", now)
h := newActionTestResourceHandlers(t, &config.Config{DataPath: t.TempDir()})
h.SetStateProvider(resourceUnifiedSeedProvider{
snapshot: models.StateSnapshot{LastUpdate: now},
resources: []unified.Resource{resource},
})
executor := newDockerContainerActionExecutor(h, &fakeDockerActionAgentCommander{
connected: map[string]bool{"agent-1": false},
}).(dockerContainerActionExecutor)
readiness := executor.CheckActionAvailable(context.Background(), request, resource)
if readiness.Available || readiness.ReasonCode != "command_agent_disconnected" ||
readiness.Reason != "Docker / Podman command agent is not connected." {
t.Fatalf("identity-fallback readiness = %#v, want disconnected agent", readiness)
}
if !strings.Contains(readiness.Detail, `agent "agent-1"`) {
t.Fatalf("identity-fallback detail = %q, want the missed agent identity named", readiness.Detail)
}
tokenResource := dockerContainerActionResource("app-container:api", "docker", "running", now)
tokenResource.Docker.TokenID = "rotated-token"
tokenResource.Docker.Hostname = "docker-host"
tokenExecutor := newDockerContainerActionExecutor(h, &scopedFakeDockerActionAgentCommander{
fakeDockerActionAgentCommander: &fakeDockerActionAgentCommander{
connected: map[string]bool{"agent-1": true},
},
tokenAgents: map[string]string{},
}).(dockerContainerActionExecutor)
readiness = tokenExecutor.CheckActionAvailable(context.Background(), request, tokenResource)
if readiness.Available || readiness.ReasonCode != "command_agent_disconnected" ||
readiness.Reason != "Docker / Podman command agent is not connected." {
t.Fatalf("token-named readiness = %#v, want disconnected agent", readiness)
}
if !strings.Contains(readiness.Detail, "rotated-token") ||
!strings.Contains(readiness.Detail, "never falls back") {
t.Fatalf("token-named detail = %q, want the stale token binding named", readiness.Detail)
}
}
func TestHandlePlanActionRefusalEnvelopeCarriesDetail(t *testing.T) {
now := time.Now().UTC()
h := newActionTestResourceHandlers(t, &config.Config{DataPath: t.TempDir()})
h.SetStateProvider(resourceUnifiedSeedProvider{
snapshot: models.StateSnapshot{LastUpdate: now},
resources: []unified.Resource{
dockerContainerActionResource("app-container:api", "docker", "running", now),
},
})
h.SetActionExecutor(newDockerContainerActionExecutor(h, &fakeDockerActionAgentCommander{
connected: map[string]bool{"agent-1": false},
}))
rec := httptest.NewRecorder()
req := httptest.NewRequest(http.MethodPost, "/api/actions/plan", bytes.NewBufferString(`{
"requestId":"req-refusal-detail",
"resourceId":"app-container:api",
"capabilityName":"restart",
"reason":"operator requested restart",
"requestedBy":"operator"
}`))
h.HandlePlanAction(rec, actionHandlerTestRequest(req, ""))
if rec.Code != http.StatusConflict {
t.Fatalf("plan status = %d, want %d, body=%s", rec.Code, http.StatusConflict, rec.Body.String())
}
var envelope struct {
Details map[string]string `json:"details"`
}
if err := json.Unmarshal(rec.Body.Bytes(), &envelope); err != nil {
t.Fatalf("decode refusal envelope: %v", err)
}
if !strings.Contains(envelope.Details["detail"], `agent "agent-1"`) {
t.Fatalf("envelope detail = %q, want the missed agent identity named", envelope.Details["detail"])
}
}
@@ -80,4 +80,8 @@ type ResourceActionReadiness struct {
Available bool `json:"available"`
ReasonCode string `json:"reasonCode,omitempty"`
Reason string `json:"reason,omitempty"`
// Detail names the concrete lookup or identity the refusal was judged
// against (which token, agent id, or hostname missed). It feeds server
// logs and error envelopes; Reason stays the stable user-facing copy.
Detail string `json:"detail,omitempty"`
}
+19
View File
@@ -875,3 +875,22 @@ func TestClonedResourcesPreservePlatformAdmission(t *testing.T) {
t.Fatalf("provider-owned host must not admit standalone after clone, got %+v", cloned)
}
}
func TestCloneResource_PreservesActionReadinessDetail(t *testing.T) {
original := &Resource{
ID: "app-container:api",
ActionReadiness: []ResourceActionReadiness{
{
Name: "restart",
Available: false,
ReasonCode: "command_agent_disconnected",
Reason: "Docker / Podman command agent is not connected.",
Detail: "no live command session for agent agent-1 or hostname docker-host",
},
},
}
cloned := cloneResource(original)
if len(cloned.ActionReadiness) != 1 || cloned.ActionReadiness[0] != original.ActionReadiness[0] {
t.Fatalf("clone dropped action readiness diagnostics: %#v", cloned.ActionReadiness)
}
}