andwati/zitadel
1
0
Fork 0
mirror of https://github.com/andwati/zitadel.git synced 2026-10-18 05:52:51 +00:00
Code Issues Packages Projects Releases Wiki Activity

docs(perf): v4.17.1 results and harness fixes (#12651)

Browse Source 
Publishes the v4.17.1 benchmark sweep and the harness fixes the sweep
uncovered.

## Results

All 11 published targets ran for 30 minutes each against a fixed
7-container deployment (vCPU 6 / 6 Gi, psql v17.4, US1 client and
server), at 600 VUs except where noted. Latencies are
`http_req_duration` over the test phase.

| target | VUs | iter/s | p50 | p95 | p99 | failed requests |
|:---|---:|---:|---:|---:|---:|:---|
| machine_pat_login | 600 | 3452 | 24.53ms | 872ms | 1.00s | 29 /
6,335,633 (0.00%) |
| user_info | 600 | 3217 | 29.32ms | 943ms | 1.13s | 66 / 5,800,788
(0.00%) |
| introspect | 600 | 2297 | 46.49ms | 1.16s | 1.36s | 1,400 / 4,159,863
(0.03%) |
| machine_jwt_profile_grant | 600 | 1076 | 85.34ms | 2.57s | 2.93s | 97
/ 1,986,156 (0.00%) |
| machine_client_credentials_login | 600 | 834 | 56.78ms | 1.74s | 2.42s
| 1,789 / 3,073,497 (0.05%) |
| add_session | 600 | 767 | 95.25ms | 3.53s | 4.15s | 1 / 1,416,546
(0.00%) |
| oidc_session | 600 | 326 | 77.47ms | 3.41s | 4.43s | 3 / 1,767,162
(0.00%) |
| otp_session | 600 | 84 | 47.80ms | 13.83s | 20.22s | 182 / 466,756
(0.03%) |
| password_session | 600 | 68 | 408.63ms | 20.00s | 24.05s | 1 / 253,280
(0.00%) |
| human_password_login | 600 | 49 | 146.67ms | 4.08s | 1m0s | 9,227 /
683,256 (1.35%) |
| manipulate_user | **200** | 19 | 304.58ms | 10.23s | 38.43s | 225 /
171,987 (0.13%) |

Against the goals:

- **#8352 is met.** `machine_jwt_profile_grant` reached **1076/s**
against the 1000/s goal, with p50 at 85ms.
- **#4424 is not met.** `human_password_login` runs at **49/s** against
a 1200/s goal.

The sweep ran with `improvedPerformance` enabled (`PROJECT_GRANT`,
`PROJECT`, `USER_GRANT`, `ORG_DOMAIN_VERIFIED`), captured from the
instance before the first target rather than assumed; the full flag set
is on every page.

## What the observability rows show

The containers were never the constraint. ZITADEL CPU sat at 9–50%
(p50), memory at 6–7% (p50, peaking at 16%) of 6 GiB, and instance count
was flat at 7 with no container startups in any window. Database CPU was
at **86–98% median on nine of eleven targets**. Any "ZITADEL achieves
N/s" figure that omits which resource ran out is true and misleading, so
the pages say.

The query breakdown then shows what the CPU numbers cannot: **advisory
lock wait is the single largest category of database time across the
sweep (91,857 s accumulated)**, ahead of event reads (64,805 s), event
push (26,411 s) and projection reads (14,625 s). The three locks are the
projection handler lock (`handler/v2/handler.go`), the eventstore read
barrier (`repository/sql/query.go`) and the shared lock every push takes
(`eventstore/v3/push.go`).

That is what sets the `flowchart outcome` on each page, and it is not
uniform:

- **Scale** on the seven targets where a resource genuinely ran out —
database CPU at 92–98% with 0% lock share.
- **Potential issues** on `human_password_login`, `password_session`,
`otp_session` and `manipulate_user`, where 45–74% of the top query time
is lock wait. `password_session` runs at 51% database CPU and 50%
container CPU and still only manages 68 iter/s; adding vCPU there buys
nothing.

Autovacuum is cleared as a contributor: 93.9% median DB CPU in buckets
containing a vacuum against 93.1% without, within noise. The new v4.17
eventstore autovacuum is barely triggered — `events2` is not in the top
twenty vacuumed tables.

## Harness fixes

Defects found during the sweep, all of which corrupted published numbers
or aborted runs:

1. **Colliding check names.** `updateHuman`, `lockUser` and `deleteUser`
all registered checks as `update user is status ok`, two of them
asserting `status === 201` against endpoints returning 200. k6
aggregates checks by name, so this produced a permanent, fictional 28%
failure rate. Each check now has its own name and accepts 2xx.
2. **User-creation read-after-write race**, in three variants, each
found after the previous fix. The read-back resolved `undefined` when
the projection was behind, surfacing much later as `Cannot read property
'0' of undefined`; then an unguarded `res.json()` turned every request
timeout into a killed iteration; then a *partial* read — a valid user
object with `loginNames` not yet projected — passed an `if (user)` guard
and failed identically. `readUserAfterCreate()` now guards status and
body before parsing, requires the field rather than the object, and
retries with backoff, rejecting with the user id and username.
3. **Metric cardinality.** Id-bearing URLs produced 800k+ time series
against k6's suggested 100k, driving k6 to 6.8 GB and an OOM mid-run.
All 16 such call sites now set a grouped `name` tag.
4. **`password_session` wrote its CSV to `otp_session`'s filename** in
the Makefile, silently overwriting the previous target's output.

The read-back race is not only a harness defect: at 600 VUs it measures
real load-induced projection lag, exceeding 25 s for login-name
projection and 100 s for the user projection, against instant reads on
an unloaded instance.

## Stable v2 user API

Four calls in `benchmark/src/user.ts` still went to `/v2beta/users` —
update, lock, delete and the machine read-back. They date from the
original load-test bootstrap in April 2024 (#7635), when the user
service was still v2beta, and were never moved when it was promoted;
they surfaced in this diff only because the read-after-write fix rewrote
the surrounding functions. All four are now on stable v2.

`updateHuman` is the one that changed shape: `PUT /v2beta/users/{id}` is
`UpdateHumanUser`, whose stable-v2 counterpart `PUT
/v2/users/human/{id}` is deprecated in the proto, so it now calls `PATCH
/v2/users/{id}` (`UpdateUser`) and `manipulate_user` nests the profile
under `human`. Both RPCs land on `command.ChangeUserHuman`, so the
measured work is unchanged. `lockUser`, `deleteUser` and the
`createMachine` read-back move over unchanged in method and payload.

No published result is affected: per-endpoint latencies come from custom
Trends, and `run-bench.sh` drops the `name` system tag, so no artefact
ever recorded a v2beta URL. The remaining `/management/v1` and
`/admin/v1` calls are left alone — migrating those changes which API
surface is benchmarked and would need a re-run.

## Timestamps

Pages reported `Test start` as a bare `HH:MM`, so a run could not be
correlated against monitoring the next day. Pages now carry the full UTC
date and time and a `Test end` row, both derived from the first and last
per-second row of `output.json`. `_template.mdx` is updated to match.

## Post-mortem

`benchmark/postmortems/2026-08-27-503-burst.md` records two bursts of
HTTP 503 `Service error -27` — an HTML page from the Google frontend,
not a ZITADEL error — on `manipulate_user` and `human_password_login`,
six hours apart. **The investigation is open**, and the note is explicit
about what is established (no container startups; the two bursts have
opposite server-side signatures), what is provisionally ruled out
(restart, panic), and what is not yet known. It is included because both
affected pages report the 503s as a separate population from the ZITADEL
failures beside them, and that split needs its evidence somewhere.

It also records two defects found by accident in the collected logs,
unrelated to the 503s: `sql: transaction has already been committed or
rolled back` (232 occurrences under load) and a missing i18n key,
`"unable to get user by id" not found in language "en"`.

## Notes for review

- **`manipulate_user` ran at 200 VUs, not 600, and the page says so.**
Throughput saturates near 100 VUs; at 600 the same target produced 4,283
failed requests for identical throughput against 225 at 200 VUs. Its
failure mode is degradation over sustained single-org churn —
per-operation p50 climbs 1.7x–6x between the first and last five minutes
of a run — not a concurrency threshold.
- **Two `Observed errors` rows are hand-corrected** and deliberately
differ from the generated text, on `manipulate_user` and
`human_password_login`. Both cases are one generated number covering two
unrelated failure populations; each page says it was corrected and why.
- Org deletion failing with a 500 (`V3-C8l3V`) after heavy user churn is
already tracked as #8510 and was hit repeatedly during cleanup.
- **The run/publish tooling is no longer part of this PR.** It moved to
a private repository, along with the cloud collection scripts, because
deployment identity does not belong here. What remains is the published
pages, the post-mortem findings and the harness fixes.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

---------

Co-authored-by: Claude Opus 5 (1M context) <[email protected]>
This commit is contained in:
Tim Möhlmann
2026-09-01 19:12:37 +00:00
committed by GitHub
co-authored by Claude Opus 5
parent 8de625dc48
commit 3be21ccbf0
44 changed files with 102762 additions and 141 deletions
Download Patch File Download Diff File Expand all files Collapse all files
benchmark/Makefile
+1 -1
View File
@@ -43,7 +43,7 @@ otp_session: ensure_key_pair ensure_modules bundle
.PHONY: password_session
password_session: ensure_key_pair ensure_modules bundle
${K6} run --summary-trend-stats "min,avg,max,p(50),p(95),p(99)" dist/password_session.js --vus ${VUS} --duration ${DURATION} --out csv=output/otp_session_${DATE}.csv
${K6} run --summary-trend-stats "min,avg,max,p(50),p(95),p(99)" dist/password_session.js --vus ${VUS} --duration ${DURATION} --out csv=output/password_session_${DATE}.csv
.PHONY: add_session
add_session: ensure_key_pair ensure_modules bundle
benchmark/postmortems/2026-08-27-503-burst.md
+186
View File
@@ -0,0 +1,186 @@
# Follow-up: the 503 bursts of 2026-08-27
Two bursts, six hours apart, on different targets, during the v4.17.1 benchmark sweep. Burst 1
was found first and most of this note was written about it; burst 2 is seven times larger and
is what makes the pair worth a post-mortem rather than a shrug.
Both are **HTTP 503 `Service error -27`** — an HTML page from the Google frontend, not a Zitadel
JSON error. They are recorded here because a page that reports them as a plain failure rate would
be attributing an infrastructure event to Zitadel, and the difference matters more than the
number does.
## Status as of 2026-08-28
The metric half of the investigation is done. The log half was run with broken filters and must
be repeated. **Nothing here is concluded.** The sections below are the chronological record and
this block is the summary.
### Established
- Two bursts on 2026-08-27, both 503 `Service error -27`. Burst 1: `manipulate_user`,
13:43:19–13:44:13, 150 requests. Burst 2: `human_password_login`, 19:37–19:44, 1,044 requests.
Both bounded, then silence.
- **No container startups in any of the eleven test windows.** The Cloud Run
`container/startup_latencies` metric returned empty distributions throughout, and instance
count was constant at 7.
- **The two bursts have different server-side signatures.** In burst 1's window there were
**zero** log entries at `severity>=WARNING`. In burst 2's there were **at least 200**, and that
200 was the query limit, reached within the first ~2 seconds of a 20-minute window.
- **The 2026-08-26 sweep produced no 503s at all**, on any of its eleven targets. Same instance,
same deployment, roughly 24 hours earlier.
### Ruled out, provisionally
- **Container restart or replacement.** This was the original working hypothesis, on the grounds
that a bounded burst followed by silence looks like something being replaced. The startup metric
does not support it: a replaced container starts, and a start would appear. Provisional only
because it rests on one metric being both correct and complete.
- **Panic and crash.** The stack traces in the collected logs are not crash dumps: they begin
`runtime/debug.Stack()` called from `zerrors.CreateZitadelError`, which is Zitadel's error type
capturing a stack when it is constructed. `recover_interceptor.go` appears because it is in the
call chain, not because it recovered anything. Combined with zero container startups, the
crash-and-restart family of explanations is firmly out.
### Open questions, in the order worth answering
1. **What do burst 2's errors actually say?** Still open after two attempts. The first failed on
`textPayload` filters against a service that logs structured JSON. The second fixed that and
then spent its whole 5,000-entry budget on the seven minutes of padding *before* the burst, at
a baseline rate of 800–1,300 errors/minute. Both failures were in the collection, not in the
data, and both produced output that looked like an answer.
2. **How many errors are there really?** 200 in two seconds, truncated. Over twenty minutes the
true figure could be in the thousands, and 1,044 client-observed 503s may be a small fraction
of what the server logged — or unrelated to it.
3. **Did the 503s reach Cloud Run at all?** The queries filtering on `httpRequest.status=503` came
back empty, which invites the reading "the frontend rejected them before they arrived". **Do
not accept that yet.** If request logging is not enabled on this service the query returns
nothing regardless. Establish the control first: confirm the service emits *any* `httpRequest`
entry, in any window. Only then is an empty result evidence.
4. **Why is burst 1 silent and burst 2 noisy?** Same HTTP symptom, opposite server-side signature.
Two causes wearing the same error page is at least as likely as one, and this note's earlier
framing — that the pair is the finding — assumed a single mechanism it had not established.
5. **Which container instances were involved?** The instance-id label rendered empty for every
entry. Unknown whether the label path is wrong for this service or the value is genuinely
unset. Check one known-good entry's full JSON before trusting any instance-level conclusion.
6. **What is `Service error -27`?** Used throughout this note as an identifier and nowhere
explained. It is a Google frontend string; if it names the layer that rejected the request, it
answers question 3 without any log query at all.
7. **Why only the 27th?** The 26 August sweep was clean. The instance's feature flags were changed
at **13:35:31Z on the 27th, eight minutes before burst 1**. That is close enough to be worth
checking and far too neat to trust: burst 2 came six hours later, so a one-off configuration
change does not cover both. Treat as a lead, not a cause.
8. **Does it recur?** Two bursts on one day and none the day before. Whether this reproduces is
unknown, and it determines whether this is worth an issue or a footnote.
Weak signal, recorded so it is not rediscovered as though it were new: both bursts fell on the two
targets that create users in bulk. With n=2 that is barely distinguishable from coincidence.
## Burst 1 — `manipulate_user` @ 200 VUs, 13:43:19–13:44:13
Run: `manipulate_user`, 200 VUs, 1800s, started 2026-08-27 13:41:09 UTC.
Feature flags: `improvedPerformance` = PROJECT_GRANT, PROJECT, USER_GRANT, ORG_DOMAIN_VERIFIED,
captured before the run; sequence 7, set 13:35:31Z.
29 errors surfaced as thrown k6 errors, all of them on user creation. The CSV shows the real
figure:
first 2026-08-27T13:43:19Z (CSV; k6 error lines showed 13:43:21)
last 2026-08-27T13:44:13Z (CSV; k6 error lines showed 13:43:57)
count 150 failed requests (29 surfaced as thrown errors on user creation)
window 55 seconds, ~2 minutes into the run
other error classes: 75 request timeouts, 14:08:48-14:11:02 - UNRELATED, see below
A bounded burst followed by silence. This is not the shape of a service under sustained load; it
is the shape of something being restarted or replaced — which is what made the absence of any
container startup in the metrics the surprise it was. It is also a different failure class from
every other failure seen during the sweep, all of which are application or harness level.
## Burst 2 — `human_password_login` @ 600 VUs, 19:37–19:44
Found after burst 1. It is the larger of the two by a wide margin:
| | burst 1 | burst 2 |
| --- | --- | --- |
| target | `manipulate_user` (200 VUs) | `human_password_login` (600 VUs) |
| window (UTC) | 13:43:19 – 13:44:13 | 19:37 – 19:44 |
| duration | 55 s | ~7 min |
| count | 150 | **1,044** |
| position in run | ~2 min in | ~13 min in |
| recurrence | none in the following 25 min | none after |
Same symptom, six hours and four intervening targets apart.
Note also what burst 2 is **not**: `human_password_login` reported 8,178 request timeouts spread
evenly across the whole run at 125–360/min. Those are Zitadel under load and are the number to
read. The 1,044 platform 503s are a separate population, and the page reports them separately. Do
not let the post-mortem collapse them back together.
## What the 2026-08-28 collection added — read the caveat before the findings
The log half of that collection was **partly invalid** and must be re-run. The filters matched
only `textPayload`, and Zitadel logs structured JSON, so every such term matched nothing and the
display column rendered blank even where entries existed. The corrected queries then hit a second
problem: at 800–1,300 errors per minute on this target, a window padded to 19:30–19:50 and ordered
ascending exhausted its 5,000-entry cap at **19:34:51**, before the burst began at 19:37.
Everything it retrieved is the ordinary pre-burst error rate.
What survives that caveat, because `severity>=WARNING` is payload-agnostic:
| | burst 1 (13:38–13:50) | burst 2 (19:30–19:50) |
| --- | --- | --- |
| entries at severity >= WARNING | **0** | **>= 200, truncated at the limit** |
| span of the 200 sampled | — | 19:30:00–19:30:0x, i.e. ~2 seconds |
**The two bursts do not have the same signature**, which contradicts the working assumption that
one mechanism produced both. Burst 1 produced no warnings or errors at all; burst 2 produced at
least 200 in the first two seconds of the window alone, so the true count over 20 minutes is
likely in the thousands. Their content is unknown — that is exactly what the broken filter cost.
From the metric side, which was not affected: no container startups in any window, and instance
count constant at 7.
Do not conclude "the frontend rejected the requests before Cloud Run saw them" from the empty
503 request logs. See open question 3: without the control, that query cannot distinguish an
infrastructure finding from a disabled log.
### Two unrelated defects, found by accident
The baseline error mix under 600 VUs is worth recording independently of the burst: 2,901 bare
`context canceled`, 1,239 `QUERY-AWx52 Errors.Query.SQLStatement` (parent: context canceled), 232
`LOG-ii6Pi` with parent `sql: transaction has already been committed or rolled back`, and 66
occurrences of a missing i18n key, `"unable to get user by id" not found in language "en"`.
`context canceled` is a consequence of the client giving up, not a cause. But **`sql: transaction
has already been committed or rolled back` is a genuine defect** — code using a transaction after
it has finished — and the missing translation key is a smaller one. Neither is related to the
503s; both should not be lost.
## Why it matters for the page
If this was a container restart, the failures are a deployment event and must be reported as such
rather than as a Zitadel failure rate. If there was a panic, that is a defect and worth an issue
of its own. Either way the page states what happened; an unexplained 503 burst rendered as a plain
failure count would be true and misleading, which is the worst combination available.
## Addendum: the two populations in burst 1's run
The full status breakdown, taken while the CSV still existed, shows the run contained **two
unrelated failure populations**, separated by 25 minutes of clean traffic:
error_code reqs first_utc last_utc
1503 150 2026-08-27 13:43:19 2026-08-27 13:44:13 <- infrastructure
1050 75 2026-08-27 14:08:48 2026-08-27 14:11:02 <- the known wall
Only the first population is the subject of this note. The second is the documented
degradation-over-sustained-churn behaviour described on the `manipulate_user` page, and is
expected.
The burst was also larger than the k6 error lines suggested: 150 failed requests, of which only 29
surfaced as thrown errors (user creation). The other 121 hit update, lock and delete, where a
failed check does not throw. This is why failure counts are taken from the CSV and not from
`grep -c level=error` on the log, which gave 29.
---
The Cloud Shell queries used for the collection, and the identity of the deployment they run
against, are not in this repository.
benchmark/src/app.ts
+2
View File
@@ -19,6 +19,7 @@ export function createAPI(name: string, projectId: string, org: Org, accessToken
authMethodType: 'API_AUTH_METHOD_TYPE_PRIVATE_KEY_JWT',
}),
{
tags: { name: '/management/v1/projects/{projectId}/apps/api' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -51,6 +52,7 @@ export function createAppKey(appId: string, projectId: string, org: Org, accessT
type: 'KEY_TYPE_JSON',
}),
{
tags: { name: '/management/v1/projects/{projectId}/apps/{appId}/keys' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
benchmark/src/oidc.ts
+2
View File
@@ -172,6 +172,7 @@ export async function token(request: TokenRequest): Promise<Tokens> {
const authRequestByIDTrend = new Trend('oidc_auth_request_by_id_duration', true);
export async function authRequestByID(id: string, tokens: any): Promise<Response> {
const response = http.get(url(`/v2/oidc/auth_requests/${id}`), {
tags: { name: '/v2/oidc/auth_requests/{id}' },
headers: {
Authorization: `Bearer ${tokens.accessToken}`,
},
@@ -195,6 +196,7 @@ export async function finalizeAuthRequest(id: string, session: any, tokens: any)
},
}),
{
tags: { name: '/v2/oidc/auth_requests/{id}' },
headers: {
Authorization: `Bearer ${tokens.accessToken}`,
'Content-Type': 'application/json',
benchmark/src/pool.ts
+1 -1
View File
@@ -5,7 +5,7 @@
*/
export async function mapPool<T, R>(
items: T[],
concurrency: number,
concurrency: number,
fn: (item: T, index: number) => Promise<R>,
): Promise<R[]> {
if (items.length === 0) {
benchmark/src/session.ts
+1
View File
@@ -40,6 +40,7 @@ export function setSession(id: string, session: any, accessToken: string, challe
};
return new Promise((resolve, reject) => {
let response = http.asyncRequest('PATCH', url(`/v2/sessions/${id}`), JSON.stringify(body), {
tags: { name: '/v2/sessions/{id}' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
benchmark/src/use_cases/manipulate_user.ts
+9 -17
View File
@@ -2,7 +2,6 @@ import { loginByUsernamePassword } from '../login_ui';
import { createOrg, removeOrg } from '../org';
import { createHuman, updateHuman, lockUser, deleteUser, User } from '../user';
import { Config } from '../config';
import { check } from 'k6';
export async function setup() {
const tokens = loginByUsernamePassword(Config.admin as User);
@@ -16,29 +15,22 @@ export async function setup() {
export default async function (data: any) {
const human = await createHuman(`vu-${__VU}-${new Date(Date.now()).getTime()}`, data.org, data.tokens.accessToken);
const updateRes = await updateHuman(
// updateHuman/lockUser/deleteUser each register their own check; repeating them
// here would double count, and k6 aggregates checks by name.
await updateHuman(
{
profile: {
nickName: `${new Date(Date.now()).toISOString()}`,
human: {
profile: {
nickName: `${new Date(Date.now()).toISOString()}`,
},
},
},
human.userId,
data.org,
data.tokens.accessToken,
);
check(updateRes, {
'update user is status ok': (r) => r.status >= 200 && r.status < 300,
});
const lockRes = await lockUser(human.userId, data.org, data.tokens.accessToken);
check(lockRes, {
'lock user is status ok': (r) => r.status >= 200 && r.status < 300,
});
const deleteRes = await deleteUser(human.userId, data.org, data.tokens.accessToken);
check(deleteRes, {
'delete user is status ok': (r) => r.status >= 200 && r.status < 300,
});
await lockUser(human.userId, data.org, data.tokens.accessToken);
await deleteUser(human.userId, data.org, data.tokens.accessToken);
}
export function teardown(data: any) {
benchmark/src/user.ts
+186 -95
View File
@@ -3,6 +3,7 @@ import { Org } from './org';
import http, { RefinedResponse } from 'k6/http';
import url from './url';
import { check } from 'k6';
import { setTimeout } from 'k6/timers';
import { Metadata } from './metadata';
export type User = {
@@ -15,64 +16,149 @@ export interface Human extends User {
loginNames: string[];
}
const createHumanTrend = new Trend('user_create_human_duration', true);
export function createHuman(username: string, org: Org, accessToken: string): Promise<Human> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest(
'POST',
url('/v2/users/human'),
JSON.stringify({
username: username,
organization: {
orgId: org.organizationId,
},
profile: {
givenName: 'Gigi',
familyName: 'Zitizen',
},
email: {
email: `${username}@zitadel.com`,
isVerified: true,
},
password: {
password: 'Password1!',
changeRequired: false,
},
}),
{
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
// A user is created by a write, but its login names can only be read back from the
// query side. Under load that projection can lag behind the write, and the read
// then returns no user at all. Retry briefly rather than resolving undefined, which
// surfaces much later as "Cannot read property '0' of undefined" while mapping
// login names, hiding the real cause.
// Diagnostics from the last attempt, so an exhausted retry loop can say *why* it gave
// up rather than only that it did. Two failures on 2026-08-27 burned 30 attempts each
// and reported nothing more useful than "not readable", which cost a whole cycle.
export type ReadUserResult = { user?: any; lastStatus: number; lastBody: string; attempts: number };
// Backoff that yields to the event loop. `sleep()` would not: k6 documents that it "blocks VU
// execution and prevents promises from resolving and event handlers from running", and the same
// is true of the synchronous `http.get`. That matters here and nowhere else in this file, because
// this is the one helper called from inside a `.then()` callback while up to MaxVUs sibling
// creations are still in flight -- blocking serialises every one of them behind this loop.
function delay(ms: number): Promise<void> {
return new Promise((resolve) => setTimeout(resolve, ms));
}
async function readUserAfterCreate(path: string, userId: string, org: Org, accessToken: string): Promise<ReadUserResult> {
let lastStatus = -1;
let lastBody = '';
let attempt = 0;
for (attempt = 0; attempt < 60; attempt++) {
const res = await http.asyncRequest('GET', url(`${path}/${userId}`), null, {
tags: { name: `${path}/{userId}` },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
});
// A timed-out request has status 0 and a null body. Calling res.json() on that
// throws "GoError: the body is null" and kills the iteration instead of consuming
// a retry, which is exactly the failure this retry loop exists to absorb.
if (res.status >= 200 && res.status < 300 && res.body) {
const user = res.json('user') as any;
// The user record can come back before its login names have been projected.
// Accepting a merely-truthy user here returns a partial record, and every
// caller immediately does loginNames[0] on it -- so this must wait for the
// field itself, not just for the object. Observed at 600 VUs on
// human_password_login, 2026-08-27: ten retries available, none consumed.
if (user && Array.isArray(user.loginNames) && user.loginNames.length > 0) {
// A loop that only reports itself when it gives up says nothing about how close it
// came, which is how the budget below got guessed at three times before it was
// measured once. Deliberately a log line and not a Trend: a Trend recorded here
// reaches output.json for manipulate_user, where this runs inside the measured
// iteration, and moving a published series to observe it would defeat the point.
if (attempt > 0) {
console.warn(
`read-back retried: user ${userId} readable after ${attempt + 1} attempts, previous status ${lastStatus}`,
);
}
return { user, lastStatus: res.status, lastBody: '', attempts: attempt + 1 };
}
}
lastStatus = res.status;
lastBody = (res.body ? String(res.body) : '<null body>').slice(0, 200);
// ~100s of waiting in total (backoff rises to 2s and stays there). Sized against a
// measured behaviour, not a guess: unloaded, login names are present on the *first*
// GET, but a burst of MaxVUs concurrent creations queues them behind the projection
// handler advisory lock -- the largest single database cost in the whole v4.17.1 sweep.
//
// Two things measured on 2026-08-31 that this budget cannot fix, recorded so the next
// person does not widen it a fourth time:
//
// Retries are never consumed successfully. Across every run that day the warn above
// fired zero times -- each user either had its login names on the *first* GET or never
// had them at all. The read-back is bimodal, so the budget only sets how long we wait
// before reporting a failure, not how many succeed.
//
// And some of those failures are permanent. In one 200-VU run all 200 creates returned
// 2xx and, ten minutes later, the query side was still missing zitizen-6 entirely and
// zitizen-7/-24/-25 had no login names. Widening the budget to ~220s changed nothing
// except how long it took to give up, which is why it was reverted to this.
//
// Note also that serialising this loop used to grant an accidental grace period: user N
// was not asked until users 0..N-1 had finished, so a late user got the queue's time for
// free. Awaiting concurrently aligns every deadline on the same instant. That is correct
// and strictly less forgiving, and it is a real effect -- it was simply not the cause of
// the failures above, which were loss rather than lag.
await delay(Math.min(100 * (attempt + 1), 2000));
}
return { user: undefined, lastStatus, lastBody, attempts: attempt };
}
const createHumanTrend = new Trend('user_create_human_duration', true);
export async function createHuman(username: string, org: Org, accessToken: string): Promise<Human> {
const res = await http.asyncRequest(
'POST',
url('/v2/users/human'),
JSON.stringify({
username: username,
organization: {
orgId: org.organizationId,
},
profile: {
givenName: 'Gigi',
familyName: 'Zitizen',
},
email: {
email: `${username}@zitadel.com`,
isVerified: true,
},
password: {
password: 'Password1!',
changeRequired: false,
},
}),
{
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
},
);
if (
!check(res, {
'create user is status ok': (r) => r.status >= 200 && r.status < 300,
})
) {
throw new Error(`unable to create user(username: ${username}) status: ${res.status} body: ${res.body}`);
}
createHumanTrend.add(res.timings.duration);
const userId = res.json('userId') as string;
const read = await readUserAfterCreate('/v2/users', userId, org, accessToken);
if (!read.user) {
throw new Error(
`user ${userId} not readable with login names after create ` +
`(username: ${username}, attempts: ${read.attempts}, last status: ${read.lastStatus}, ` +
`last body: ${read.lastBody})`,
);
response
.then((res) => {
check(res, {
'create user is status ok': (r) => r.status >= 200 && r.status < 300,
}) || reject(`unable to create user(username: ${username}) status: ${res.status} body: ${res.body}`);
createHumanTrend.add(res.timings.duration);
const user = http.get(url(`/v2/users/${res.json('userId')!}`), {
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
});
resolve(user.json('user')! as unknown as Human);
})
.catch((reason) => {
reject(reason);
});
});
}
return read.user as unknown as Human;
}
const setEmailOTPOnHumanTrend = new Trend('set_human_email_otp_duration', true);
export async function setEmailOTPOnHuman(user: User, org: Org, accessToken: string): Promise<void> {
const response = await http.asyncRequest('POST', url(`/v2/users/${user.userId}/otp_email`), null, {
tags: { name: '/v2/users/{userId}/otp_email' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -95,7 +181,8 @@ export function updateHuman(
accessToken: string,
): Promise<RefinedResponse<any>> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('PUT', url(`/v2beta/users/${userId}`), JSON.stringify(payload), {
let response = http.asyncRequest('PATCH', url(`/v2/users/${userId}`), JSON.stringify(payload), {
tags: { name: '/v2/users/{userId}' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -106,7 +193,7 @@ export function updateHuman(
response
.then((res) => {
check(res, {
'update user is status ok': (r) => r.status === 201,
'update user is status ok': (r) => r.status >= 200 && r.status < 300,
});
updateHumanTrend.add(res.timings.duration);
resolve(res);
@@ -122,46 +209,44 @@ export interface Machine extends User {
}
const createMachineTrend = new Trend('user_create_machine_duration', true);
export function createMachine(username: string, org: Org, accessToken: string): Promise<Machine> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest(
'POST',
url('/management/v1/users/machine'),
JSON.stringify({
userName: username,
name: username,
// bearer
access_token_type: 0,
}),
{
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
export async function createMachine(username: string, org: Org, accessToken: string): Promise<Machine> {
const res = await http.asyncRequest(
'POST',
url('/management/v1/users/machine'),
JSON.stringify({
userName: username,
name: username,
// bearer
access_token_type: 0,
}),
{
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
},
);
if (
!check(res, {
'create user is status ok': (r) => r.status >= 200 && r.status < 300,
})
) {
throw new Error(`unable to create user(username: ${username}) status: ${res.status} body: ${res.body}`);
}
createMachineTrend.add(res.timings.duration);
const userId = res.json('userId') as string;
const read = await readUserAfterCreate('/v2/users', userId, org, accessToken);
if (!read.user) {
throw new Error(
`user ${userId} not readable with login names after create ` +
`(username: ${username}, attempts: ${read.attempts}, last status: ${read.lastStatus}, ` +
`last body: ${read.lastBody})`,
);
response
.then((res) => {
check(res, {
'create user is status ok': (r) => r.status >= 200 && r.status < 300,
}) || reject(`unable to create user(username: ${username}) status: ${res.status} body: ${res.body}`);
createMachineTrend.add(res.timings.duration);
const user = http.get(url(`/v2beta/users/${res.json('userId')!}`), {
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
'x-zitadel-orgid': org.organizationId,
},
});
resolve(user.json('user')! as unknown as Machine);
})
.catch((reason) => {
reject(reason);
});
});
}
return read.user as unknown as Machine;
}
export type MachinePat = {
@@ -172,6 +257,7 @@ const addMachinePatTrend = new Trend('user_add_machine_pat_duration', true);
export function addMachinePat(userId: string, org: Org, accessToken: string): Promise<MachinePat> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('POST', url(`/management/v1/users/${userId}/pats`), null, {
tags: { name: '/management/v1/users/{userId}/pats' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -198,6 +284,7 @@ const addMachineSecretTrend = new Trend('user_add_machine_secret_duration', true
export function addMachineSecret(userId: string, org: Org, accessToken: string): Promise<MachineSecret> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('PUT', url(`/management/v1/users/${userId}/secret`), null, {
tags: { name: '/management/v1/users/{userId}/secret' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -232,6 +319,7 @@ export function addMachineKey(userId: string, org: Org, accessToken: string, pub
publicKey: publicKey,
}),
{
tags: { name: '/management/v1/users/{userId}/keys' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -253,7 +341,8 @@ export function addMachineKey(userId: string, org: Org, accessToken: string, pub
const lockUserTrend = new Trend('lock_user_duration', true);
export function lockUser(userId: string, org: Org, accessToken: string): Promise<RefinedResponse<any>> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('POST', url(`/v2beta/users/${userId}/lock`), null, {
let response = http.asyncRequest('POST', url(`/v2/users/${userId}/lock`), null, {
tags: { name: '/v2/users/{userId}/lock' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -264,7 +353,7 @@ export function lockUser(userId: string, org: Org, accessToken: string): Promise
response
.then((res) => {
check(res, {
'update user is status ok': (r) => r.status >= 200 && r.status < 300,
'lock user is status ok': (r) => r.status >= 200 && r.status < 300,
});
lockUserTrend.add(res.timings.duration);
resolve(res);
@@ -278,7 +367,8 @@ export function lockUser(userId: string, org: Org, accessToken: string): Promise
const deleteUserTrend = new Trend('delete_user_duration', true);
export function deleteUser(userId: string, org: Org, accessToken: string): Promise<RefinedResponse<any>> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('DELETE', url(`/v2beta/users/${userId}`), null, {
let response = http.asyncRequest('DELETE', url(`/v2/users/${userId}`), null, {
tags: { name: '/v2/users/{userId}' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
@@ -289,7 +379,7 @@ export function deleteUser(userId: string, org: Org, accessToken: string): Promi
response
.then((res) => {
check(res, {
'update user is status ok': (r) => r.status === 201,
'delete user is status ok': (r) => r.status >= 200 && r.status < 300,
});
deleteUserTrend.add(res.timings.duration);
resolve(res);
@@ -304,6 +394,7 @@ const setUserMetadataTrend = new Trend('set_user_metadata_duration', true);
export function setUserMetadata(metadata: Metadata[], userId: string, accessToken: string): Promise<RefinedResponse<any>> {
return new Promise((resolve, reject) => {
let response = http.asyncRequest('POST', url(`/v2/users/${userId}/metadata`), JSON.stringify({ metadata: metadata }), {
tags: { name: '/v2/users/{userId}/metadata' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',
benchmark/src/user_grant.ts
+1
View File
@@ -26,6 +26,7 @@ export async function addUserGrant(
roleKeys: roles,
}),
{
tags: { name: '/management/v1/users/{userId}/grants' },
headers: {
authorization: `Bearer ${accessToken}`,
'Content-Type': 'application/json',