mirror of
https://github.com/agent-substrate/substrate.git
synced 2026-10-02 03:24:42 +08:00
main
15
Commits
| Author | SHA1 | Message | Date | |
|---|---|---|---|---|
 Krisztian F
|
945e44a5ec |
(ateapi): report worker occupancy by actor slots in ate.worker.state (#1854)
Part of #1664, implements #1799. ## Changes - `ate.worker.state` now has `idle`, `partial`, `at_capacity` and `unschedulable`. `assigned` is removed. - ateapi picks the state by comparing allocated actor slots with capacity, the same check the scheduler makes. - Draining workers and workers with no reported capacity are `unschedulable`. This wins over occupancy, so the sum over the states is still the pool size. - Every known pool reports all four states, set to 0 when empty. - Updated the registry, `docs/observability.md` and the autoscaled-workerpool demo (`assigned` -> `at_capacity`). ## Open questions - Are we fine with `unschedulable` as a fourth state? cc. @JeffLuoo Every new worker starts with capacity 0, so `at_capacity` would make an HPA on it scale up on its own scale-up. - This breaks queries on `ate_worker_state="assigned"`. Should be still fine. - The demo HPA is only right while each worker holds one actor. Pool utilization needs slot counts, which needs a new instrument (#1664). - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
f75e626485 |
(chore): Write both copies of an actor lifecycle event from one call (#1771)
An actor lifecycle record went to stdout and to OTLP in two separate calls. The attributes were shared, but the severity was not, so the slog level sat at the call site and the OTel severity sat on the `Event`. Nothing made a caller write both copies either, so a new record could reach stdout only and no test would notice. Since this PR `actorevent.Log` now writes both copies. The level comes from `Event.Severity`, so it is stored once. The OTLP only `Emit` and the exported body constants are gone, so the dual write is the only way out of the package. Also normalizes `ate.actor.operation.name` on the crash event, which the state change event already did. Fixes #1744 Testing - Unit tests for the level mapping, the dual write, and the registry check. - End to end on a fresh kind cluster. Both event names arrive with the right severity (9 and 17), the right attributes, and trace context on the record fields. The stdout copies match record for record. - [x] Tests pass - [ ] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
5f7c690108 |
(feat): Actor lifecycle events over otlp (#1658)
## What this does ateapi writes a record every time an actor changes state. Until now those records only went to the pod's stdout, and nothing reads stdout. This sends the same records to a collector as OTLP log events. Actor name and uid cannot be metric labels (too many values), and traces are sampled at 1%. So these records are the only way to answer "what state is this actor in, and since when". ## Changes - `serverboot.InitLogging` sets up a LoggerProvider, next to the existing tracer and meter ones. - New `internal/actorevent` package builds the log records. - ateapi emits at the two places that already write the stdout records. - Two event names: `ate.actor.state_changed` and `ate.actor.crashed`. - Both names are registered in `docs/metrics/registry/events.yaml`, so `make verify` checks them. - kind gets a logs pipeline and a count connector. The e2e suite reads the counts back. - Docs updated. `otel-collector.md` said substrate has no LoggerProvider, which is no longer true. ## Opt-in `OTEL_LOGS_EXPORTER` defaults to `none`. Only the kind overlay sets it to `otlp`. The base ConfigMap is untouched, so no deployed environment changes when this merges. ## Notes on the design - **No slog bridge.** Only two call sites emit these records, so emitting twice costs two lines. A bridge would also send every ateapi log over the wire, could not set the event name, and would loop, because SDK export errors are logged through slog. - **Batching processor, not the simple one.** These records sit on the actor resume path. A processor that exports inside the emit call would add a blocking gRPC call there, so a slow collector would become control plane latency. - **Two event names, not one per state.** `ate.actor.state` already says which transition happened. A crash gets its own name because it carries two extra attributes and a higher severity. - **Both copies are kept on purpose.** No collector in this repo reads pod stdout, so nothing is duplicated today. `kubectl logs` keeps working. If a filelog agent is ever added, drop one of the two. The escape hatch is written down in `docs/metrics/substrate.yaml`. ## Dependencies Adds `otel/log`, `otel/sdk/log` and `otlploggrpc`, all pinned at v0.20.0. That is the release that matches the pinned `otel v1.44.0`. v0.21.0 would pull the core modules to v1.45.0, which this change does not need. The logs API has a v1.47.0 release candidate upstream, so it is on its way to stable. ## Testing - Unit tests for the exporter resolver, the record builder, and both ateapi emit sites. - The record builder test checks the attribute set matches what the event name declares, in both directions. - The ateapi tests check the OTLP record carries the same attributes as the stdout record. - Ran end to end on kind. Records arrive with the right event name, severity, attributes, and with trace context on the record's own fields rather than as attributes. - Checked the off state too. With `OTEL_LOGS_EXPORTER` removed, the collector receives no log records and stdout is unchanged. - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
1f22af8701 |
Record actor state changes from ateapi (#1638)
# Record actor state changes from ateapi
ateapi now writes a log record every time an actor changes state.
## Before
Nothing tells you what state an actor is in. Metrics can't carry actor
identity, and the control plane samples traces at 10%, so most
transitions leave nothing behind at all. If you want to know whether an
agent is running, paused or suspended, there's nowhere to look.
## After
One filter:
```text
ate.actor.uid="8f2a1c4e6b0d47f1" AND ate.actor.state!=""
```
Last record wins. That's the state it's in now, and the timestamp is
when it got there.
The record:
```json
{
"time": "…",
"level": "INFO",
"msg": "Actor state changed",
"ate.atespace": "ate-demo-counter",
"ate.actor.name": "counter-1",
"ate.actor.uid": "8f2a…",
"ate.template.atespace": "ate-demo-counter",
"ate.template.name": "counter",
"ate.actor.operation.name": "suspend",
"ate.actor.state": "suspended"
}
```
## The two new keys
`ate.actor.state` is the `ateapipb.ActorState` values lowercased, so the
log wording and the state machine can't drift apart.
`ate.actor.operation.name` says what caused the change. The state on its
own doesn't tell you: an actor lands in `suspended` from a suspend and
`paused` from a pause, and only one of those gives the worker back.
`Actor crashed` picks up the same state key. A crash is a state change
too, and it's the one an actor can reach without any operation
finishing.
## Notes for review
**Why ateapi.** It owns the state machine. It also sees transitions that
never reach a worker, like deleting an actor that was already suspended,
or a resume that fails in the scheduler.
**It can't log a state the store never had.** The record goes out after
the store commit, and every state commit has a version precondition, so
a losing writer in a concurrent update writes nothing.
- [x] Tests pass
- [x] Appropriate changes to documentation are included in the PR
|
||
|
Krisztian F
|
645be8957c |
(otel): split infra vs. workload faults (#1445)
`ate.failure.reason` only ever named infrastructure faults, and the crash log didn't say which actor crashed. This PR adds the following: - **`ate.failure.domain`** (`infrastructure` / `workload` / `unknown`) is available next to every `ate.failure.reason`. It's a strict function of the reason so it costs no series, but it's *emitted* rather than derived downstream, so a component ahead of ateapi can report a reason this build rejects, which collapses to `UNKNOWN`, and a consumer matching on reason names would file every one of those as infra. `UNKNOWN` now reports `unknown`, not `infrastructure`. - **`Actor crashed`** record from ateapi, with full identity including the uid, via a helper both crash sites share. It sits under the same guard as the counter so the two can't disagree on how many crashes happened. The counter is barred from carrying actor identity, so this record is the only way to attribute a crash to one agent. - **`WORKLOAD_NOT_READY`** on the readyz deadline, as the first workload-domain reason. Deadline branch only: a cancellation is ateom draining, not the actor failing. Tested locally: ``` desc = WORKLOAD_NOT_READY: readyz for "counter" never returned 200 within 5s ``` - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
85d404a823 |
(atelet): make the restore timing log a joinable per-actor latency record (#1364)
Restore timing breakdown is the only unsampled per-actor latency record
we emit, and since traces are head-sampled at 1% on the data plane, and
actor identity is not available from metric labels on purpose.
This adds this to logs:
Before:
```json
{"msg":"Restore timing breakdown",
"actor":{"type":"*ateapipb.Actor","atespace":"demo","name":"counter-1"},
"download":310000000,"oci_unpack":50000000,"ateom_restore":60000000,"total":420000000}
```
After:
```json
{"msg":"Restore timing breakdown",
"ate.atespace":"ate-demo-counter-substrate","ate.actor.name":"join-probe",
"ate.actor.uid":"3a5b4e86-1a77-4da7-84c4-c0993d9c83ec",
"ate.template.atespace":"ate-demo-counter-substrate","ate.template.name":"counter",
"ate.snapshot.scope":"full","ate.snapshot.kind":"golden","ate.sandbox.class":"gvisor",
"ate.actor.restore.duration.volume_mount":0.000004583,
"ate.actor.restore.duration.manifest_fetch":0.006111636,
"ate.actor.restore.duration.sandbox_assets":0.000098958,
"ate.actor.restore.duration.download":0.025386544,
"ate.actor.restore.duration.oci_unpack":0.000954919,
"ate.actor.restore.duration.ateom_restore":0.147448298,
"ate.actor.restore.duration.total":0.181189689,
"trace_id":"c9d7ea9a5f90a5eb4399bfa0b966d5ac","span_id":"89280ba761137c8e"}
```
The duration keys are the `ate.actor.restore.duration` instrument's name
plus an `ate.snapshot.phase` value, so a log key and the histogram it
mirrors are literally the same identifier in source, which is also why
they're seconds.
Also adds `ateattr.ActorLogAttrs`, the component-log twin of
`ActorLogLabels`, held to the same key set by a test.
Verified on kind:
- the ateom Actor restoring record for the same actor carries the
identical `ate.actor.uid` and `trace_id`, this was impossible before
- `ate_actor_restore_duration_seconds_sum{phase="total"} = 0.181189689`,
matching the log to the nanosecond
- induced a download failure by deleting a snapshot object: record sets
`ate.failure.reason:` `FAILED_GET_EXTERNAL_OBJECT` and correctly omitted
`ateom_restore`; the metric for the same restore shows the same six
phases
- [x] Tests pass
- [x] Appropriate changes to documentation are included in the PR
|
||
|
Krisztian F
|
39df566dfa |
(otel): atelet and ateom telemetry now says which node it came from (#1363)
We want to be able to answer questions like: - image cache hit ratio per node - cold starts got slower on one node but nothing we emit says which node anything is on, this PR fixes this. Verified on a local kind cluster, where both atelet and ateom-gvisor now show `k8s_node_name` on `target_info`, including ateom's, which arrives through the OTLP relay. - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
c3c6876985 |
(chore): consolidate logging to ateattr (#1035)
Actor logs used `ate.dev/actor_*` while spans and metrics use `ate.*` registry in internal/ateattr. This PR makes ateattr the single source of truth for everything telemetry-related. - Renamed the six actor log labels onto the registry: - `ate.atespace`, `ate.actor.name`, `ate.actor.uid`, `ate.template.namespace`, `ate.template.name`, `ate.actor.container.name` - Logs join traces now. Records set `trace_id`, `span_id` and `trace_flags`, so you can go from Actor restored to the resume that caused it. Our own lines only, not an actor's stdout: one goroutine forwards a whole container stream and can't know which request produced a given line. Per line correlation comes with #853. - Actors can't fake platform labels. They already couldn't overwrite ours, but they could invent new ones like `ate.tenant` that look platform issued downstream. Anything under `ate.` from an actor is now dropped. - Fixed the asymmetry that was actually left: actor supplied label values weren't stringified, and one non string value makes Cloud Logging discard the labels for that whole entry. - Note: the actor_uid bullet in the issue is stale, #841 fixed it earlier. Lifecycle records still set five labels rather than six, on purpose as they're about the actor, so no container produced them. Fixes #886 - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR --------- Signed-off-by: krisztianfekete <git@krisztianfekete.org> |
||
|
Krisztian F
|
0dbe1523e4 |
feat(otel): add cold start metrics (#776)
This PR implements the last two metrics from #433. Right now, we can see that a resume was slow but not where. `ate.actor.lifecycle.operation.duration` covers the whole ateapi operation, and `atenet.router.route.duration` covers the edge, but everything between ateapi-atelet-actors is one block that contains fetching the manifest, downloading the snapshot, unpack the OCI image, call to ateom. We have `rpc.server.call.duration` that gives us the atelet restore total time, but template, kind, and scope labels are missing, so today we cannot really pinpoint why/where we have a regressions in latency. In this PR I am adding per-phase histograms, here's an example of what we can know after these changes: ```console ateom_restore 522 ms ############################### download 8.9 ms # manifest_fetch 3.2 ms oci_unpack 2.6 ms --------------------------------------------------------- total 535 ms ``` It also fixes a gap #683 opened where a `data_on_golden` resume was labeled identically to a plain one on the lifecycle histogram. Things folks might want to argue with: - total as a phase value. Partly duplicates `rpc.server.call.duration`, but that one has no domain labels and gRPC-specifc. We can drop it, but it's an inferior operational UX, so I'd rather have it here. - Phases overlap, they are not a partition of total, because download runs concurrently with the asset fetch and unpack. I called this out in the metric description. Do not sum across phases. - New `ate.snapshot.scope` key rather than a new `ate.snapshot.kind` value for `data_on_golden`. A new value would collapse local and external into one bucket, which is the biggest latency difference there is. This does add a label to the already shipped lifecycle histogram. Verified on kind, and all e2e suites pass, and the emitted series cover every kind (golden, latest, local) on both metrics with no unknown values. - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
c155efd1ac |
feat(otel): onboard atecontroller to the OTLP path (#754)
atecontroller had no OTel at all. Dev-mode zap logger, and its controller-runtime metrics were only available on a :8080 that we don't scrape. After this PR, logs go through the shared slog handler (plus a `--log-level` flag to match the other binaries), and controller-runtime's Prometheus registry is bridged onto the OTLP reader so the reconcile/workqueue metrics actually reach the collector. Filtering these out is a pipeline responsibility. Also added otelgrpc to the ateapi client, which was untraced. This unblocks #564 the workperpool metrics, cc @Angelawork, @JeffLuoo: there's a working `MeterProvider` to use for `ate.workerpool.desired_workers`/`ready_workers`. Couple of things to mention for review: -`InitMetricsPushOnly`, not `InitMetrics`, even though we do serve :8080. That port is controller-runtime's own private registry, not the global one `serverboot.metricsMux` serves, so a pull reader there would collect into something we never expose. - Bridge is pinned to v0.68.0 to match otelgrpc. Wanted to go to v0.70.0, but that requires otel/sdk/metric 1.45.0 and pulls the whole SDK up with it (406 vendor files instead of 81). Happy to do that bump separately. - zap/zapr fall out of go.mod since atecontroller was the last importer. - I included an OTel collector image bump from the early 2024 (!) one to latest, which was breaking exposing native histograms - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
6f2b2178c1 |
feat(otel): add actor lifecycle + scheduler duration metrics (#514)
This PR is the second slice of the platform-metrics split (#433). It adds two duration histograms emitted by ateapi: - `ate.actor.lifecycle.operation.duration`: create/resume/suspend/pause/delete, labeled by operation, template, pool, sandbox class, and (on resume) snapshot kind - I'd like to use this for user-facing latency for e.g. showing when suspended actors can serve requests again. The existing `rpc.server.call.duration` metric covers this, but the meaningful dimensions are missing, so it's not really actionable. Extending its labels with extra, domain-specific labels is an OTel anti-pattern, hence the new metric. - `ate.scheduler.assignment.duration`: worker-assignment step, labeled by outcome (assigned / no_free_worker / error) and pool - I'd like to use this to alert on no free worker situation, and have proper SLOs via various percentiles for assigning latencies. There's no RPC around this, so it's not something existing RPC metrics cover. Tested e2e on a local kind cluste where: both metrics reach the otel-system collector with the expected labels (resume shows `snapshot_kind=golden`, scheduler shows `outcome=assigned`, no `error.type` on success). - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
15eecd02c9 |
Define a production-ready default tracing policy (#711)
Today everything outside ateapi hardcodes `ParentBased(NeverSample)`, and setting `OTEL_TRACES_SAMPLER` does nothing because an explicit sampler silences the SDK's env handling. This makes troubleshooting production issues impossible via traces. This PR gives every component a sane default and makes the standard OTel env vars work: - Control plane (ateapi, atelet, ateom) defaults to `parentbased_traceidratio` 0.1, the router (data plane root) to 0.01, per the discussion on #584. - `OTEL_TRACES_SAMPLER` / `OTEL_TRACES_SAMPLER_ARG` override any of this without a rebuild. Invalid values keep the component default and log a warning instead of inheriting the SDK's fall-open-to-100% behavior. - Envoy's `RandomSampling` is derived from the router's resolved policy, so the two root decisions cannot drift. - kubectl-ate without `--trace` no longer installs a tracer provider at all: the old `NeverSample` provider injected `sampled=0`, which pinned every parent based sampler downstream and would have defeated the server side ratios. `--trace` still forces a full end to end trace. - ate-controller propagates the two env vars to the ateom worker pods it creates, same as the metric export vars. - kind pins ateapi to `parentbased_always_on`, so the local Jaeger flow keeps showing every API call. - The agentgateway integration follows what we have above. its `randomSampling` changes from `true` to `0.01` to match the data plane default, though as static config it does not follow `OTEL_TRACES_SAMPLER` overrides, so the two need adjusting together. Verified on a kind cluster e2e manually. It resolved samplers logged at startup, a `--trace` resume produced one trace across ateapi, atelet, and ateom, an unsampled CLI call got picked up server side, Envoy continued a sampled traceparent while sampling 0 of 30 parentless requests at the 1% default, and an invalid env value fell back to the component default. Gating who may use `--trace` stays a separate follow-up (and a discussion), and the more sophisticaed tracing policies belongs in a collector, not in substrate. Fixes #584 cc. @git286 - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
acf5c12df4 |
(otel): onboard ateom to the OTLP metrics path (#562)
This PR wires `ateom` into the OTLP push path so it can emit metrics, and unblock unblocking https://github.com/agent-substrate/substrate/issues/550 - serverboot: new InitMetricsPushOnly (OTLP periodic reader, no Prometheus pull surface) for binaries that run no metrics HTTP server - ateom-gvisor + ateom-microvm call it, so the existing otelgrpc server handler now feeds `rpc.server.*` to the collector - atecontroller propagates its `OTEL_EXPORTER_OTLP_ENDPOINT` + `OTEL_RESOURCE_ATTRIBUTES` into the ateom worker pods - fixes ateom telemetry not reaching the collector - e2e: metrics suite asserts an `ateom` service reaches the collector cc. @git286 - [x] Tests pass - [ ] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
163bcf4aa8 |
feat(otel): add ate.workerpool.workers metric with e2e suite (#492)
Part of the preferred split of #433, please check that out if you need wider context. This PR adds `ate.workerpool.workers` metric end to end so we have coverage for workers by pool / state / sandbox class, emitted by ateapi. Comes with the few attribute keys it actually uses, unit tests, and an e2e suite that drives an actor lifecycle and checks the metric (plus the two existing platform metrics) actually lands in the collector. - [x] Tests pass - [x] Appropriate changes to documentation are included in the PR |
||
|
Krisztian F
|
3377b3fb59 |
feat(otel): set ate.* actor telemetry identity on ateapi spans (#412)
This PR sets consistent, namespaced actor-identity set on the spans we
already emit:
- `ate.atespace`, `ate.actor.id`, `ate.actor.template.{name,namespace}`,
`ate.actor.version`
- ateapi: the RPC server span for create/resume/suspend/pause/delete
We do this, so platform traces are queryable by actor, atespace, and
template. Cross-hop correlation and per-tenant/per-template filtering,
all on traces (not TSDB labels, as discussed in #174). This is a
general, workload-neutral telemetry identity plumbing. We could add
gen_ai specific stuff on top of this later.
This is a resume:
<img width="1913" height="1010" alt="image"
src="https://github.com/user-attachments/assets/876cf689-a8ec-4f37-b035-3b9b1de87d59"
/>
**Notes:**
- Left as it was on purpose: metric attribute names and the stdout log
labels (`ate.dev/*`), but we should probably do this as well. Maybe in
this PR?
- Bikeshed is welcomed on the `ate.*` spelling before merge, renaming
span attrs later is painful.
- [x] Tests pass
- [x] Appropriate changes to documentation are included in the PR
|