Skip to content

Commit d10fa0e

Browse files
JeffLuooJeffLuoo
committed
docs: keep the troubleshooting guides thin
The guides copied label taxonomies and flag defaults inline. A copy goes out of date without a signal, and one already had: the guide said that ate.imagecache.requests reports _OTHER for each status that is not 401, 403 or 429, but the registry and internal/imagecache/metrics.go also pass 404, 500, 502, 503 and 504 through as literal values. Give the guides one job. They own the decision tree: which query to run, how to read the result, and where to go next. The registry owns the definitions. Drop the value tables for ate.snapshot.kind, ate.failure.reason, ate.scheduling.constraint and the parking outcome, and link to the registry group instead. Drop the --parked-request-max default and link to request-parking.md, which owns the flag. Drop the histogram bucket ceilings and the two sample measurements, which the surrounding argument does not need. The phase, reason and outcome tables that remain hold routing and not definitions. Fix two drifts on the way: three guides said "three reasons" for an empty query where the README lists four, and capacity-is-full.md said "two states" above a three-row table.
1 parent 3b10d38 commit d10fa0e

4 files changed

Lines changed: 80 additions & 65 deletions

File tree

‎docs/troubleshooting/README.md‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,12 @@ The instruments and their labels are defined in
2121
is the source of truth. [`docs/observability.md`](../observability.md)
2222
describes logs, metrics, and traces as a whole.
2323

24+
**These guides own the decision tree. The registry owns the definitions.** A
25+
guide tells you which query to run, how to read the result, and where to go
26+
next. It does not repeat the permitted values of a label, or the default of a
27+
flag. For those, open the registry, or the document that owns the flag. A copy
28+
in a guide goes out of date without a signal.
29+
2430
## The two paths
2531

2632
Substrate has two paths, and the first question is always which one is slow.

‎docs/troubleshooting/capacity-is-full.md‎

Lines changed: 9 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ An actor must hold a worker to run. When each worker is assigned, a new resume
77
cannot start. The router parks the request, and then it returns
88
`503 no free workers available`.
99

10-
Two different states look the same at the edge:
10+
Three different states look the same at the edge:
1111

1212
| State | What it means | Where to see it |
1313
|---|---|---|
@@ -24,7 +24,7 @@ the pools of different namespaces into one series.
2424

2525
Each step gives the query in two forms. Refer to
2626
[the naming rules](README.md#the-names-on-your-backend) for which form your
27-
backend needs, and for the three reasons a query can return nothing.
27+
backend needs, and for the reasons a query can return nothing.
2828

2929
---
3030

@@ -120,11 +120,9 @@ histogram_quantile(0.5, sum by(le, "ate.scheduling.constraint") (
120120
rate({__name__="ate.scheduler.eligible_workers_bucket"}[5m])))
121121
```
122122

123-
| `ate.scheduling.constraint` | Meaning |
124-
|---|---|
125-
| `none` | The request has no constraint. |
126-
| `selector` | A label selector of an actor or a template applies. |
127-
| `required_nodes` | The request is pinned to specific node VMs. |
123+
The `registry.ate.scheduler` group of
124+
[the registry](../metrics/registry/metrics.yaml) says what each value of
125+
`ate.scheduling.constraint` is.
128126

129127
**The value of this key does not tell you the cause.** An ActorTemplate with a
130128
`workerSelector` makes each of its requests `selector`, thus you never see
@@ -157,11 +155,11 @@ sum by("ate.scheduler.outcome") (
157155
rate({__name__="ate.scheduler.assignment.duration_count"}[5m]))
158156
```
159157

160-
| Outcome | Meaning |
158+
| Outcome | Go to |
161159
|---|---|
162-
| `assigned` | The scheduler took a worker. |
163-
| `no_free_worker` | No free worker was available. This shows the capacity. It is not a failure, thus it has no `error.type` key and it names no pool. |
164-
| `error` | The attempt failed. Only this outcome has an `error.type` key. |
160+
| `assigned` | The scheduler took a worker. If the users still get a 503 error, go to step 5. |
161+
| `no_free_worker` | This is capacity pressure and not a failure. Go to step 2 and to step 6. |
162+
| `error` | The query below. Only this outcome has an `error.type` key. |
165163

166164
**Prometheus**
167165

‎docs/troubleshooting/requests-are-slow.md‎

Lines changed: 17 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@ and it does not include the response.
2323
| Yes | Small | In the code of the actor, or in the network. Read the logs of the actor. |
2424
| No | Large | Somebody waited, but not this client. For example, an operator did a resume. |
2525

26-
Three different faults give a 503 error to the client:
26+
Four outcomes reach the client, and three of them are a 503 error:
2727

2828
| What the client sees | Label | Cause |
2929
|---|---|---|
@@ -41,7 +41,7 @@ activations.
4141

4242
Each step gives the query in two forms. Refer to
4343
[the naming rules](README.md#the-names-on-your-backend) for which form your
44-
backend needs, and for the three reasons a query can return nothing.
44+
backend needs, and for the reasons a query can return nothing.
4545

4646
---
4747

@@ -73,6 +73,12 @@ sum by("ate.router.outcome") (
7373
`ok` on this metric means only that the router found an endpoint. It does not
7474
mean that the client got an answer.
7575

76+
The table above holds the outcomes that send you to a different step. The
77+
router has more, and the `registry.ate.router` group of
78+
[the registry](../metrics/registry/metrics.yaml) lists each one. An outcome
79+
that is not in the table names its own cause; read it there and then go to
80+
step 4.
81+
7682
## Step 2. Divide the warm route from the resume
7783

7884
**Keep both `ate.router.outcome` and `ate.router.resume` in the `by()` clause.**
@@ -81,9 +87,9 @@ reports `none` for a request that stopped before it reached a resume state. The
8187
outcome is what separates the two readings, thus the query must group by both.
8288

8389
Keep the resume key for a second reason: if you remove it, the aggregation adds
84-
the warm route to the activation, and one distribution then holds both
85-
milliseconds and seconds. On this data the warm route is 23 ms and the
86-
activation is 488 ms, thus a merged number describes neither.
90+
the warm route to the activation. A warm route is milliseconds and an
91+
activation is hundreds of milliseconds or more, thus one distribution then
92+
holds both and the merged number describes neither.
8793

8894
**Prometheus**
8995

@@ -133,20 +139,15 @@ histogram_quantile(0.95, sum by(le, outcome) (
133139
rate({__name__="atenet.router.parking.wait.duration_bucket"}[5m])))
134140
```
135141

136-
* `parking.active` near the configured maximum (`--parked-request-max`,
137-
default 1024) means that the parking area is almost full.
142+
* `parking.active` near the configured maximum means that the parking area is
143+
almost full. `--parked-request-max` sets it. Refer to
144+
[request-parking.md](../request-parking.md) for the flag and its default.
138145
* `parking.rejected` above zero means that the router refuses requests at the
139146
edge. Make the pool larger, or make the parking area larger.
140147
* The `outcome` label on the wait histogram does not start with `ate.`. This is
141-
a known exception in `docs/metrics/substrate.yaml`.
142-
143-
| `outcome` | Meaning |
144-
|---|---|
145-
| `served` | The resume was correct and the router sent the request. |
146-
| `budget_exhausted` | The park budget ended. The fleet stayed full. |
147-
| `timeout` | The time limit of the request ended. |
148-
| `canceled` | The client disconnected. |
149-
| `error` | The resume failed. |
148+
a known exception in `docs/metrics/substrate.yaml`. Its permitted values are
149+
in the `registry.ate.deviation` group of
150+
[the registry](../metrics/registry/metrics.yaml).
150151

151152
A value of `budget_exhausted` below the full budget is normal. The budget is
152153
per flight. A request that joins a flight late shares the remaining budget.

‎docs/troubleshooting/resumes-are-slow.md‎

Lines changed: 48 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -18,14 +18,11 @@ Two states give a resume, and their cost is not the same:
1818
| Paused | On the node VM, and the resume prefers that node | Low. No download. |
1919
| Suspended | In object storage (GCS or S3) | High. A download and an unpack. |
2020

21-
`ate.snapshot.kind` tells you which snapshot the resume read:
22-
23-
| Value | Meaning |
24-
|---|---|
25-
| `local` | A snapshot on the node. A pause wrote it. |
26-
| `latest` | The durable snapshot of the actor. |
27-
| `golden` | The image of the ActorTemplate. This is the first activation of a new actor. |
28-
| `boot` | A start from nothing. A boot is not a restore, thus this value never occurs on the atelet histograms. |
21+
`ate.snapshot.kind` tells you which snapshot the resume read. The permitted
22+
values and their meaning are in the `registry.ate.snapshot` group of
23+
[the registry](../metrics/registry/metrics.yaml). One of them changes what you
24+
can query: a `boot` is a start from nothing, thus it is not a restore and the
25+
atelet restore histogram has no data for it.
2926

3027
Two instruments measure a resume. They do not measure the same part:
3128

@@ -44,7 +41,7 @@ zero.
4441

4542
Each step gives the query in two forms. Refer to
4643
[the naming rules](README.md#the-names-on-your-backend) for which form your
47-
backend needs, and for the three reasons a query can return nothing.
44+
backend needs, and for the reasons a query can return nothing.
4845

4946
---
5047

@@ -81,11 +78,11 @@ histogram_quantile(0.95, sum by(le) (
8178
* The router number is much larger — the time went to the queue or to the
8279
scheduler. Go to step 5.
8380

84-
**A quantile at the last bucket is saturated.** The lifecycle histogram of
85-
ateapi stops at 30 s. The restore histogram of atelet stops at 60 s. A value at
86-
or near the end of the range means only that the true value is somewhere above
87-
the buckets, thus the two instruments cannot be compared there. Read the mean
88-
instead, as step 2 does.
81+
**A quantile at the last bucket is saturated.** The two instruments do not use
82+
the same buckets, and the lifecycle histogram of ateapi ends before the restore
83+
histogram of atelet. A value at or near the end of either range means only that
84+
the true value is somewhere above the buckets, thus the two cannot be compared
85+
there. Read the mean instead, as step 2 does.
8986
* The restore query is empty but resumes occur — the resumes are boots. Confirm
9087
it:
9188

@@ -148,14 +145,16 @@ sum by("ate.snapshot.phase") (
148145
increase({__name__="ate.actor.restore.duration_count","ate.failure.reason"=""}[30m]))
149146
```
150147

151-
| Phase | What is slow | Go to |
152-
|---|---|---|
153-
| `volume_mount` | The volumes of the actor. | The logs of atelet. |
154-
| `manifest_fetch` | The read of the snapshot manifest. | Step 3. |
155-
| `download` | Object storage. | Step 3. |
156-
| `oci_unpack` | The node, or the image cache missed. | Step 4. |
157-
| `sandbox_assets` | The sandbox assets on the node. | Step 4. |
158-
| `ateom_restore` | The sandbox runtime. | The logs of ateom. |
148+
The `registry.ate.snapshot` group of
149+
[the registry](../metrics/registry/metrics.yaml) says what each phase covers.
150+
The slowest phase says where to go next:
151+
152+
| Phase | Go to |
153+
|---|---|
154+
| `volume_mount` | The logs of atelet. |
155+
| `manifest_fetch`, `download` | Step 3. |
156+
| `oci_unpack`, `sandbox_assets` | Step 4. |
157+
| `ateom_restore` | The logs of ateom. |
159158

160159
If the filtered numbers are small but the unfiltered numbers are large, the
161160
subject is not the speed of the phase. It is the failures. Go to step 6.
@@ -204,21 +203,32 @@ A miss adds a pull and an unpack to each resume.
204203
```promql
205204
sum by (ate_imagecache_outcome) (
206205
rate(ate_imagecache_requests_total[5m]))
206+
207+
sum by (error_type) (
208+
rate(ate_imagecache_requests_total{
209+
ate_imagecache_outcome="error"}[5m]))
207210
```
208211

209212
**Cloud Monitoring / GMP**
210213

211214
```promql
212215
sum by("ate.imagecache.outcome") (
213216
rate({__name__="ate.imagecache.requests"}[5m]))
217+
218+
sum by("error.type") (
219+
rate({__name__="ate.imagecache.requests",
220+
"ate.imagecache.outcome"="error"}[5m]))
214221
```
215222

216-
Calculate the hit ratio as `hit / (hit + miss)`. Keep `error`, `cancelled` and
217-
`timeout` out of the denominator.
223+
Calculate the hit ratio as `hit / (hit + miss)`. Keep the outcomes that are not
224+
a lookup result out of the denominator. The
225+
`registry.ate.imagecache` group of
226+
[the registry](../metrics/registry/metrics.yaml) lists them.
218227

219-
If the outcome is `error`, `error.type` holds the HTTP status of the registry.
220-
The value `401` or `403` is a credential fault. The value `429` is a rate
221-
limit. Each other status reports `_OTHER`.
228+
Only the `error` outcome carries `error.type`, which holds the HTTP status that
229+
the registry of the image returned. Group by it to divide a credential fault
230+
from a rate limit from a fault of the registry. The permitted values are on
231+
`metric.ate.imagecache.requests` in the same file.
222232

223233
## Step 5. Examine the control plane
224234

@@ -290,18 +300,18 @@ sum by("ate.snapshot.phase", "ate.failure.reason") (
290300
"ate.failure.reason"!=""}[5m]))
291301
```
292302

293-
| Reason | Cause |
303+
The `registry.ate.failure` group of
304+
[the registry](../metrics/registry/metrics.yaml) says what each reason means.
305+
The reason says which component to examine next:
306+
307+
| Reason | Examine |
294308
|---|---|
295-
| `FAILED_GET_EXTERNAL_OBJECT` | The storage backend has a fault. |
296-
| `TERMINAL_FILE_SYSTEM_ERROR` | A permanent fault on the node. Usually the disks are full. |
297-
| `LOCAL_SNAPSHOT_GONE` | The node no longer has the local snapshot. |
298-
| `INVALID_SANDBOX_ASSET` | A sandbox asset is absent or bad. |
299-
| `INVALID_CHECKPOINT_RESULT` | ateom returned a checkpoint that is not valid. |
300-
| `INVALID_CONTAINER_CONFIG` | The ActorTemplate is not correct. |
301-
| `INVALID_OBJECT_URL` | The URL of the snapshot object is bad. |
302-
| `FAILED_SAVE_SNAPSHOT` | atelet could not write the snapshot. |
303-
| `WORKER_POD_GONE`, `WORKER_REASSIGNED`, `CORRUPTED_ASSIGNMENT` | A control plane fault. Examine ateapi. |
304-
| `UNKNOWN` | An infrastructure failure with no reason. Read the logs of atelet. |
309+
| `FAILED_GET_EXTERNAL_OBJECT`, `INVALID_OBJECT_URL` | The storage backend, and the URL of the snapshot object. |
310+
| `TERMINAL_FILE_SYSTEM_ERROR`, `LOCAL_SNAPSHOT_GONE`, `INVALID_SANDBOX_ASSET` | The node. Read the logs of atelet. |
311+
| `INVALID_CHECKPOINT_RESULT`, `FAILED_SAVE_SNAPSHOT` | The suspend path. A bad checkpoint makes the next resume fail. |
312+
| `INVALID_CONTAINER_CONFIG` | The ActorTemplate. |
313+
| `WORKER_POD_GONE`, `WORKER_REASSIGNED`, `CORRUPTED_ASSIGNMENT` | The control plane. Examine ateapi. |
314+
| `UNKNOWN` | Nothing else. The reason is absent, thus read the logs of atelet. |
305315

306316
A slow resume and a failed suspend are related. A suspend that fails leaves no
307317
good snapshot for the next resume. Read the crash counter, which uses the same

0 commit comments

Comments
 (0)