diff --git a/cmd/atelet/metrics.go b/cmd/atelet/metrics.go index ed31bad2f5..84f8ff835d 100644 --- a/cmd/atelet/metrics.go +++ b/cmd/atelet/metrics.go @@ -166,8 +166,9 @@ func restoreSnapshotKind(directLocal bool, rec *sandboxAssetsRecord) string { return ateattr.SnapshotKindLatest } -// checkpointSnapshotKind classifies which snapshot a checkpoint writes: a pause -// writes the node-local one, and a suspend writes a durable latest snapshot. +// checkpointSnapshotKind classifies which snapshot a checkpoint writes: an +// asynchronous suspend writes the node-local one, and a synchronous suspend +// writes a durable latest snapshot. func checkpointSnapshotKind(req *ateletpb.CheckpointRequest) string { if req.GetUploadConfig().GetMode() == ateletpb.UploadMode_UPLOAD_MODE_DEFERRED { return ateattr.SnapshotKindLocal diff --git a/docs/metrics/registry/metrics.yaml b/docs/metrics/registry/metrics.yaml index 0fe9265ae9..2ebfcd56ce 100644 --- a/docs/metrics/registry/metrics.yaml +++ b/docs/metrics/registry/metrics.yaml @@ -104,14 +104,14 @@ groups: stability: development value: suspending brief: > - ateapi is writing a snapshot: durable for a suspend, - node-local for a pause. + ateapi is writing a snapshot: node-local for an asynchronous + suspend, durable for a synchronous suspend. - id: suspended stability: development value: suspended brief: > - The actor holds no worker. Its latest snapshot is durable, or - node-local after a pause. + The actor holds no worker. Its latest snapshot is durable, + node-local, or both. - id: crashed stability: development value: crashed @@ -298,7 +298,10 @@ groups: - id: local stability: development value: local - brief: A snapshot on the node. A pause writes it. + brief: > + The copy on the node. An asynchronous suspend writes it. A + resume reads it while the node still has it, after either kind + of suspend and whether or not the upload has finished. - id: latest stability: development value: latest diff --git a/docs/observability.md b/docs/observability.md index ff8fd79ac6..9b3342d2ab 100644 --- a/docs/observability.md +++ b/docs/observability.md @@ -14,7 +14,7 @@ To make underlying infrastructure transitions transparent, Agent Substrate estab * `ate.template.atespace`: The atespace of the actor's ActorTemplate (e.g., `ate-demo-counter`). * `ate.actor.container.name`: The name of the container within the actor that produced the log line (e.g., `counter`), so a multi-container actor's logs can be demultiplexed by container. Absent on the synthetic lifecycle records (`Actor starting`, `Actor restored`, …): those are about the actor, so no container produced them. The `runsc create`, `start`, and `restore` CLI output and the pause container's stdio are wrapped under `_pause`. This does not capture sentry or gofer output, which runsc directs to `/dev/null` when debug logging is disabled. -Currently, Agent Substrate automatically wraps container output and injects these metadata labels into **container logs**. For metrics and distributed tracing, Agent Substrate provides foundational system telemetry and on-demand request tracing, with roadmap plans to fully integrate actor-level correlation. +Currently, Agent Substrate automatically wraps container output and injects these metadata labels into **container logs**. For metrics and distributed tracing, Agent Substrate provides foundational system telemetry and head-sampled request tracing (10% by default, 1% at the router), with roadmap plans to fully integrate actor-level correlation. `ate.*` is reserved for Substrate. An actor's own log lines pass through untouched except for keys in that namespace, which are dropped before the record is written, so nothing a workload emits can be read as platform-issued attribution. @@ -41,7 +41,7 @@ If an actor is suspended or not assigned to a worker pod, the CLI informs you im ```bash $ kubectl ate logs actor test -a demo -Error: actor test is not currently running on any worker pod +Error: actor demo/test is not currently running on any worker pod ``` #### Example 2: Default Clean JSON Lines Output @@ -77,7 +77,7 @@ kubectl ate logs actor -a -c To view the pause container's runsc diagnostics explicitly: ```bash -kubectl ate logs actors -a -c _pause +kubectl ate logs actor -a -c _pause ``` `--source` selects a class of lines instead of a container. `containers` shows application container output with the lifecycle events removed; `_pause` remains excluded unless selected with `-c _pause`. `lifecycle` shows only the lifecycle events, which is the quickest way to see how often an actor has been suspended and restored on its current worker (a migration moves the actor to another pod, whose log holds none of the earlier workers' events): @@ -193,7 +193,7 @@ Creating an actor counts as a change. A new actor is born suspended, so it gets "trace_id":"4bf92f…","span_id":"00f067…","trace_flags":"01"} ``` -The counter carries no actor identity, so this record is the only way to attribute a crash to one agent. The decision-point line that precedes it (`Setting Actor to crashed due to error`) carries only `ate.atespace` and `ate.actor.name`: it is written before the Actor is loaded, so no uid exists yet. +The counter carries no actor identity, so this record is the only way to attribute a crash to one agent. The decision-point line that precedes it (`Setting Actor to crashed due to Atelet error`) carries only `ate.atespace` and `ate.actor.name`: it is written before the Actor is loaded, so no uid exists yet. ateworker-gvisor's `Sandbox has no processes left while the actor is hosted` is a WARN written when a running actor's gVisor sandbox has died: the sentry crashed, was killed, or was OOM-killed. The ateworker's usage sweep finds it, so it shows up within one sweep (`--usage-sample-interval`, a minute by default), once per activation. `ate.sandbox.oom_kills` is the cgroup's `oom_kill` count, so a non-zero value points at the kernel OOM killer: @@ -285,7 +285,7 @@ Agent Substrate emits foundational OpenTelemetry system and server metrics to mo | `ate.workerpool.ready_workers` | atecontroller | up/down counter | number of worker pods currently ready for a WorkerPool, from `status.readyReplicas` (labels `ate.workerpool.namespace`, `ate.workerpool.name`) | | `ate.workerpool.workers` | ateapi | up/down counter | live worker count per pool, split by state (`idle`/`partial`/`at_capacity`/`unschedulable`) and sandbox class to provide fleet capacity and saturation at a glance | -| `ate.actor.lifecycle.operation.duration` | ateapi | histogram | how long each actor operation (create/resume/suspend/delete/revert; a pause is labeled suspend) takes and whether it failed (`error.type` present = failure, absent = success); labeled by operation, template, pool (`ate.workerpool.namespace` + `ate.workerpool.name`), sandbox class, snapshot kind on resume, and snapshot fidelity on resume and suspend; already-running resume no-ops are not recorded so the histogram tracks actual activations, not router traffic | +| `ate.actor.lifecycle.operation.duration` | ateapi | histogram | how long each actor operation (create/resume/suspend/delete/revert) takes and whether it failed (`error.type` present = failure, absent = success); labeled by operation, template, pool (`ate.workerpool.namespace` + `ate.workerpool.name`), sandbox class, snapshot kind on resume, and snapshot fidelity on resume and suspend; already-running resume no-ops are not recorded so the histogram tracks actual activations, not router traffic | | `ate.scheduler.assignment.duration` | ateapi | histogram | time of one attempt to assign a worker to an actor, with one record for each resume (ateapi retries an attempt that loses a race for a worker and records only the last attempt), with the outcome (`assigned` / `no_capacity` / `error`), the assigned pool (`ate.workerpool.namespace` + `ate.workerpool.name`) and sandbox class to catch scheduling latency and capacity starvation problems | | `ate.actor.restore.duration` | atelet | histogram | how long each phase of a restore takes on the worker node, which is where cold-start latency actually goes once ateapi hands off (labels `ate.snapshot.phase`, `ate.snapshot.kind`, `ate.snapshot.fidelity`, `ate.template.atespace`, `ate.template.name`, `ate.sandbox.class`) | | `ate.actor.checkpoint.duration` | atelet | histogram | the same phase breakdown for writing a snapshot, so a slow suspend can be attributed to ateworker or to the upload (same labels as the restore histogram) | @@ -323,7 +323,7 @@ For the `ate.filecache.*` instruments, one series per cache under `ate.filecache **No keys** means the operation has no pool. The actor-centric instruments omit the pair, so a crash before the actor reached a worker, or the `no_capacity` outcome, names no pool. No instrument sends the pair with both keys empty. The three snapshot labels are orthogonal and mean the same thing on every histogram that carries them: -* `ate.snapshot.kind`: which snapshot the operation reads or writes. `local` (node-local, written by a pause), `latest` (a durable snapshot, including a template's golden snapshot), or `boot` (from scratch, so it never appears on the atelet histograms). +* `ate.snapshot.kind`: which snapshot the operation reads or writes. `local` (the copy on the node: an asynchronous suspend writes it, and a resume reads it while the node still has it, whether or not its upload to durable storage has finished. A synchronous suspend is `latest`, but it also keeps a copy on the node, so the resume after it can be `local`), `latest` (a durable snapshot, including a template's golden snapshot), or `boot` (from scratch, so it never appears on the atelet histograms). * `ate.snapshot.fidelity`: what state it holds. `volumes`, `rootfs`, or `memory`. * `ate.snapshot.phase`: which step was timed. `volume_mount`, `manifest_fetch`, `sandbox_assets`, `download`, `oci_unpack`, `worker_restore` on restore; `sandbox_assets`, `worker_checkpoint`, `persist`, `cleanup` on checkpoint; `total` on both. @@ -354,12 +354,13 @@ weaver registry check -r docs/metrics/registry # the same command, direct **To add or change an instrument:** follow [Metrics Best Practices](dev/best-practices/metrics.md), which covers the instrument choice, the labels, the Go, the test, and the registry entry; then change `metrics.yaml` and run the script. -Two files, and not one: +Four files, and not one: | File | Content | Who reads it | |---|---|---| | `docs/metrics/registry/manifest.yaml` | The name and the schema URL of the registry. | Weaver | | `docs/metrics/registry/metrics.yaml` | The `groups`: each metric, each attribute. | Weaver | +| `docs/metrics/registry/events.yaml` | The [actor events](#the-same-records-over-otlp). | Weaver, `TestEventsMatchTheRegistry` | | `docs/metrics/substrate.yaml` | The rules of Substrate that Weaver cannot hold. | A person, an agent | Weaver permits only `groups` and `imports` at the top level of a registry file, and it refuses a file that has any other top-level key. Thus `substrate.yaml` is beside the registry directory and not in it. It records: @@ -386,7 +387,7 @@ A queue that has never processed an item bridges as an exponential histogram wit ### Scraping instead of pushing -ateapi, atelet, atenet-router and the credential provider also serve every instrument on their Prometheus `/metrics` endpoint. A cluster that scrapes those endpoints sets `OTEL_METRICS_EXPORTER=prometheus` on the components, so each series reaches the backend once. With `prometheus` the components install no OTLP metric reader and keep the Prometheus one; traces and logs are unaffected. `none` stops the push too. For now `/metrics` stays on for every value, including `otlp` and `none`. This is temporary until the probes move off `:9090`; `otlp` and `none` will then turn it off ([#2067](https://github.com/agent-substrate/substrate/issues/2067)). The variable takes a comma-separated list, with the same rules as `OTEL_LOGS_EXPORTER`. Unset is `otlp,prometheus`, or `otlp` alone on ateworker. `otlp` keeps the push, and `prometheus` or `none` stops it. ateworker serves no `/metrics`, so there `prometheus` is skipped as unknown with a warning, and the push stays on unless the variable is `none`. +ateapi, atelet, atenet-router and the credential provider also serve every instrument on their Prometheus `/metrics` endpoint. A cluster that scrapes those endpoints sets `OTEL_METRICS_EXPORTER=prometheus` on the components, so each series reaches the backend once. With `prometheus` the components install no OTLP metric reader and keep the Prometheus one; traces and logs are unaffected. `none` stops the push too. For now `/metrics` stays on for every value, including `otlp` and `none`. The health probes have moved to their own server on `:9091`, so `:9090` serves only `/metrics`; turning it off for `otlp` and `none` is tracked in [#2067](https://github.com/agent-substrate/substrate/issues/2067). The variable takes a comma-separated list, with the same rules as `OTEL_LOGS_EXPORTER`. Unset is `otlp,prometheus`, or `otlp` alone on ateworker. `otlp` keeps the push, and `prometheus` or `none` stops it. ateworker serves no `/metrics`, so there `prometheus` is skipped as unknown with a warning, and the push stays on unless the variable is `none`. `ate-controller` does not propagate its own value to the worker pods: ateworker serves no `/metrics`, and `none` would leave it exporting no metrics at all. To set the variable on ateworker, set `ATE_WORKER_OTEL_METRICS_EXPORTER` in `ate-otel-config` (or the controller's `--otel-metrics-exporter` flag). @@ -406,11 +407,13 @@ To explore metrics locally: 2. **Open the Prometheus UI** in your web browser: [http://localhost:9090](http://localhost:9090) -3. **Query metrics**: Run `up` to confirm each component is scraped (one series per target, value `1`), then explore the `rpc_*` series via the expression browser's autocomplete. **Status > Targets** lists the discovered pods. +3. **Query metrics**: Run `up` to confirm each scraped target is up (one series per target, value `1`), then explore the `rpc_*` series via the expression browser's autocomplete. **Status > Targets** lists the discovered pods. > **Note:** Storage is ephemeral (`emptyDir`), so metrics are lost when the Prometheus pod restarts. -> **Roadmap Note (Actor-Level Metrics):** A comprehensive metrics roadmap is under active development to support both system operators and workload analysis. Planned OpenTelemetry instrumentation focuses on control plane latency, state snapshot performance, fleet utilization density, and enriching metrics with standardized actor labels for seamless aggregation across pod transitions. +> **Note:** This Prometheus does not see every instrument. It scrapes the `/metrics` endpoint (`:9090`) of the pods annotated `prometheus.io/scrape`, which are `ate-api-server`, `atelet`, and `atenet-router`. From the collector it keeps only the `substrate_*` counts of the count connector and the collector's own `otelcol_*` counters ([`manifests/ate-install/kind/prometheus.yaml`](../manifests/ate-install/kind/prometheus.yaml)), so that the scraped services are not counted twice. The metrics that ateworker (including its `rpc.server.call.duration`) and atecontroller (`ate.workerpool.desired_workers`, `ate.workerpool.ready_workers`, and the bridged controller-runtime families) push over OTLP reach the collector but do not appear in this UI. The credential provider's metrics appear in neither: its pod carries no scrape annotation and does not read `ate-otel-config`, so its OTLP push goes to the SDK default `localhost:4317` and fails. + +> **Roadmap Note (Actor-Level Metrics):** The control plane latency, snapshot performance, and fleet utilization instruments above are in place. What remains is actor-level correlation: telemetry that an actor emits itself carries no Substrate-injected identity yet ([#853](https://github.com/agent-substrate/substrate/issues/853), [#761](https://github.com/agent-substrate/substrate/issues/761)). --- @@ -460,17 +463,17 @@ Telemetry is emitted the same way everywhere; only the backend differs between a | | Kind | GKE (Google Cloud) | |---|---|---| -| Path | service → in-cluster `opentelemetry-collector` | service → Google Managed Prometheus (GMP) | +| Path | service → in-cluster `opentelemetry-collector` | service → GKE managed OTel collector (`opentelemetry-collector.gke-managed-otel`) | | Metrics | collector Prometheus exporter on `:8889` | Google Cloud Monitoring | | Traces | Jaeger UI | Google Cloud Trace | | Logs | pod stdout; the [actor events](#the-same-records-over-otlp), ateapi's lifecycle records and the ateworkers' usage samples, also to the collector's `debug` exporter | pod stdout. No OTLP logs: `OTEL_LOGS_EXPORTER` is unset | | Dashboards | Not supported | Google Cloud Monitoring (see [Dashboards](#5-dashboards)) | -> In Kind, `ateapi`, `atelet`, `ate-controller`, and `atenet-router` are pointed at the in-cluster collector, and the controller propagates the endpoint to the worker pods it creates, so all component telemetry lands locally. +> In Kind, `ateapi`, `atelet`, `ate-controller`, `atenet-router`, and `atenet-egress` are pointed at the in-cluster collector, and the controller propagates the endpoint to the worker pods it creates, so the telemetry of these components and of the workers lands locally. The Kubernetes credential provider is the exception: it does not read the endpoint (see the [note on the Kind Prometheus](#2-metrics)). > -> Every component reads that endpoint from the shared `ate-otel-config` ConfigMap ([`manifests/ate-install/ate-otel-config.yaml`](../manifests/ate-install/ate-otel-config.yaml), with a Kind replacement of the same name under [`manifests/ate-install/kind/`](../manifests/ate-install/kind/ate-otel-config.yaml)). Editing it does not restart the pods that consume it — follow a change with `kubectl rollout restart`. +> Each of these components reads that endpoint from the shared `ate-otel-config` ConfigMap ([`manifests/ate-install/ate-otel-config.yaml`](../manifests/ate-install/ate-otel-config.yaml), with a Kind replacement of the same name under [`manifests/ate-install/kind/`](../manifests/ate-install/kind/ate-otel-config.yaml)). Editing it does not restart the pods that consume it — follow a change with `kubectl rollout restart`. > -> Workers don't read the ConfigMap at all — `ate-controller` copies the value into each worker pod at creation. A new endpoint reaches them only once the controller itself restarts, and that restart then rolls every WorkerPool Deployment, replacing the running workers along with the actors on them. +> Workers don't read the ConfigMap at all. They normally export through the [`atelet` relay](#the-ateworker-otlp-relay), which forwards to `atelet`'s own endpoint, so restarting `atelet` moves the relayed workers to a new endpoint. `ate-controller` also copies the value into each worker pod at creation, for the direct fallback. That copy changes only once the controller itself restarts, and that restart then rolls every WorkerPool Deployment, replacing the running workers along with the actors on them. ### The ateworker OTLP relay @@ -482,9 +485,9 @@ ateworker ──OTLP/gRPC over unix socket──► atelet relay ──OTLP/gRPC The socket sits in the `BasePath` hostPath already mounted into both, so nothing new is mounted. `atelet` is a DaemonSet, so every ateworker on a node shares one relay, and the many per-pod collector connections collapse into one per node. Four things motivate it: the worker pod runs untrusted agent code and will not need egress to the collector once direct fallback is phased out; the connection count drops; ateworker's own telemetry stays clear of the transparent egress redirect it installs for the actor; and `atelet` outlives the worker pod, so spans still queued at teardown are not lost with it. -The relay is best-effort. If the socket is absent when ateworker starts — `atelet` not up yet, `--otlp-relay-socket=""`, or no collector configured for the relay to forward to — ateworker logs it and exports directly to `OTEL_EXPORTER_OTLP_ENDPOINT`. Without that variable either, ateworker exports no traces, metrics, or logs, rather than dialing the SDK default `localhost:4317`, where no collector runs, and logs a warning per signal with `reason="no OTLP relay or endpoint"`. That fallback is decided once at startup, not per export, and is stamped on telemetry as the `ate.otlp.relay` resource attribute (`relay` vs `direct`). On an install that sets no endpoint for `ate-controller` to propagate, an ateworker that starts before its node's relay socket exists therefore exports nothing until the worker pod restarts. +The relay is best-effort. If the socket is absent when ateworker starts — `atelet` not up yet, `--otlp-relay-socket=""`, or no collector configured for the relay to forward to — ateworker logs it and exports directly to `OTEL_EXPORTER_OTLP_ENDPOINT` (or the per-signal `OTEL_EXPORTER_OTLP_{TRACES,METRICS,LOGS}_ENDPOINT`). `atelet` logs `Failed to create the OTLP relay` and starts no relay when its endpoint uses `https` (the relay forwards over plaintext gRPC and refuses to downgrade), when its per-signal endpoints or compression settings disagree (the relay carries every signal over one connection), or when its `OTEL_EXPORTER_OTLP_*_HEADERS` cannot be parsed. ateworker checks only that the socket file exists, so a socket left on the node by an earlier `atelet` still sends it to the relay: nothing serves the socket, and every export fails with `connection refused` instead of falling back. Without any endpoint either, ateworker exports no traces, metrics, or logs, rather than dialing the SDK default `localhost:4317`, where no collector runs, and logs a warning per signal with `reason="no OTLP relay or endpoint"`. That fallback is decided once at startup, not per export, and is stamped on telemetry as the `ate.otlp.relay` resource attribute (`relay` vs `direct`). On an install that sets no endpoint for `ate-controller` to propagate, an ateworker that starts before its node's relay socket exists therefore exports nothing until the worker pod restarts. -> **Note on Network Egress Lockdown:** Complete network policy lockdown of worker pod egress to the collector is planned as a Phase 2 milestone once the relay path is fully proven and direct fallback is deprecated. While the fallback path remains active, worker pods retain network egress to the collector and `ate-controller` continues to inject `OTEL_EXPORTER_OTLP_ENDPOINT`. +> **Note on Network Egress Lockdown:** Complete network policy lockdown of worker pod egress to the collector is planned as a Phase 2 milestone once the relay path is fully proven and direct fallback is deprecated. While the fallback path remains active, worker pods retain network egress to the collector and `ate-controller` continues to inject `OTEL_EXPORTER_OTLP_ENDPOINT` when it has one. For verified ateworker sources, the relay forwards each request verbatim rather than decoding and re-exporting, which is what keeps every ateworker its own service in Jaeger/GCP Trace instead of being absorbed into `atelet`'s. `ate-controller` injects `k8s.pod.name`, `k8s.namespace.name`, `k8s.pod.uid`, `k8s.node.name`, and `service.instance.id` directly into `OTEL_RESOURCE_ATTRIBUTES` via the Kubernetes Downward API, whether or not it has an endpoint to propagate; because the relay preserves resources verbatim, Kubernetes attributes remain intact even though the TCP connection to the collector originates from `atelet` rather than the worker pod IP (bypassing reliance on collector-side IP-based `k8sattributes` enrichment). @@ -520,7 +523,7 @@ An actor that already has a policy for other destinations keeps those rules and Three things to know when applying this: -* **It is per actor.** The policy is a resource under the actor, and nothing applies one by default today. Every actor that exports telemetry needs its own, created after the actor and before, or shortly after, it is resumed. A template-level default policy is proposed in [#1558](https://github.com/agent-substrate/substrate/pull/1558); the underlying ask is [#1430](https://github.com/agent-substrate/substrate/issues/1430). +* **It is per actor.** The policy is a resource under the actor, and nothing applies one by default today. Every actor that exports telemetry needs its own, created after the actor and before, or shortly after, it is resumed. A template-level default policy is requested in [#1430](https://github.com/agent-substrate/substrate/issues/1430). * **A running actor recovers slowly.** If the policy is created while the actor is already exporting and failing, the SDK's gRPC client is in reconnect backoff, the sandbox's DNS relay takes up to 5s to notice the policy, and the gateway caches the missing policy for `--egress-policy-cache-ttl` (10s by default). Expect the first successful export 45s to two minutes after the policy appears. An actor whose policy exists before it starts has no such delay. * **The collector sees the gateway, not the actor.** The TCP connection to the collector comes from the egress gateway pod, so a collector that enriches by source IP (the `k8sattributes` processor, which the GKE managed collector runs) labels the actor's spans and metrics with the gateway's `k8s.pod.name`, `k8s.deployment.name=atenet-egress`, and `k8s.namespace.name`. The actor's `service.name` and anything it puts in `OTEL_RESOURCE_ATTRIBUTES` survive. Set the actor's identity there yourself if you need it on the backend; the relay-based path that will do this for actors is tracked in [#853](https://github.com/agent-substrate/substrate/issues/853) and [#761](https://github.com/agent-substrate/substrate/issues/761).