benchmarking: actor telemetry for the sweperf workload

[Nishanth Kotla (Nishanth29)]

benchmarking: actor telemetry for the sweperf workload

What this does

Adds the suspend/resume and task-execution timings from the telemetry proposal to the sweperf boomer workload, and deploys the remaining four sweperf actor templates.

New locust rows

row	what it measures
ResumeToFirstExec	resume RPC start until the first exec lands in the actor
TaskCEL	server-side execution time for one sweperf task (4 cycles)
CycleCEL	server-side execution time for one cycle
TaskWallClock	client wall clock for one task, excluding think time
<rpc>_rtt	client round trip for each control-plane RPC

The four derived rows are recorded under the actor method, the _rtt rows under grpc.

We keep both the client RTT and the server-side elapsed for every control-plane RPC so the network and queueing overhead stays visible separately. The existing ResumeActor / SuspendActor rows keep the server-side elapsed from the response trailer.

Templates

deploy.sh now renders all five templates instead of just astropy. The four new ones are copies of the astropy template with their own image and task id.

Documentation

benchmarking/README.md had no sweperf section, so this adds one listing every row the workload emits, matching the existing DurDir section.

Testing

go test -race ./internal/benchmarking/boomer/... plus a 3 minute run per workload on a real cluster. astropy and sphinx both finish with 0 failures and all expected rows present. Spot checked that TaskCEL is about 4x CycleCEL, that ResumeToFirstExec is at least the resume RPC, and that every _rtt is at least its server-side counterpart. Also ran sympy at 2 user / 2 worker and 4 user / 2 worker together with #1725; all rows were present in both.

• Tests pass
• Appropriate changes to documentation are included in the PR

[Nishanth Kotla (Nishanth29)]

cc Max Smythe (@maxsmythe), Haowei Cai (Roy) (@roycaihw) - ptal:)

[Mauricio Poppe (mauriciopoppe)]

Could we make the units (Ms / (ms)) explicit on the derived duration metrics here and in stats.jsonl, and also spell out what CEL stands for on first use?

In Locust's UI (stats.csv), response times are implicitly in milliseconds (locust_request_duration_milliseconds). However, once runner.py (stats_to_jsonl) exports these rows to stats.jsonl, the Prometheus metric name is stripped and the keys become unitless ({"metric": "actor_ResumeToFirstExec", "measurements": {"p50": "1610", ...}}). Meanwhile, in #1725 (server_telemetry.py), the server_summary row written to the exact same stats.jsonl file uses explicit unit suffixes in seconds (restore_p50_s, restore_mean_s, checkpoint_p50_s, checkpoint_mb_s).

Keeping bare method names for the gRPC RPCs (CreateActor, ResumeActor, SuspendActor, DeleteActor) makes sense since those are protobuf method names, but the synthetic duration metrics (ResumeToFirstExec, CycleCEL, TaskCEL, TaskWallClock, <rpc>_rtt) are durations rather than endpoint names.

Suggestions:

1. Rename the synthetic duration metrics to include Ms (matching ExecutionDurationMs and server.elapsed_ms): ResumeToFirstExecMs, CycleCELMs (or CycleExecDurationMs), TaskCELMs (or TaskExecDurationMs), TaskWallClockMs, and <rpc>_rtt_ms.
2. Define CEL in this section and note that all reported metrics are in milliseconds.
3. Clarify the description of Workload_Cycle_<n>: since /execute returns 202 Accepted and httpJSONCall wraps validate (pollJobCompletion), Workload_Cycle_<n> measures POST /execute plus the entire /status polling loop until job completion, rather than a single HTTP round trip.

[Nishanth Kotla (Nishanth29)]

SG, will update the README.

[Mauricio Poppe (mauriciopoppe)]

Same unit naming comment here: since these four rows (ResumeToFirstExec, CycleCEL, TaskCEL, TaskWallClock) and name+"_rtt" (line 446/449) represent synthetic duration measurements rather than RPC method names, can we suffix them with Ms (ResumeToFirstExecMs, CycleCELMs, TaskCELMs, TaskWallClockMs, <rpc>_rtt_ms) so they are self-describing in stats.jsonl alongside #1725's _s server summary metrics?

[Nishanth Kotla (Nishanth29)]

I'd prefer to keep these without Ms. Every Locust row is in ms, including ResumeActor, Workload_Cycle_N and the glutton/durdir rows, so suffixing only these would make the names inconsistent, and _rtt should stay paired with its RPC row.

like the _s keys in #1725 are there because that row comes from Prometheus in seconds, not from Locust. I'll call out the ms units in the README instead. is that fine?

[Mauricio Poppe (mauriciopoppe)]

The comment on pollSuspended says SuspendActor returns before the worker is free, but in cmd/ateapi/internal/controlapi/workflow_suspend.go (ActorWorkflow.SuspendActor -> ensureSuspendedFinalized), SuspendActor synchronously checkpoints via atelet, detaches volumes, frees the worker (releaseWorker), and commits ACTOR_STATE_SUSPENDED with WorkerAssignment = nil before returning SuspendActorResponse.

Because SuspendActor is synchronous (and step() at line 579 calls u.suspend(ctx) without pollSuspended before the next cycle's u.resume(ctx)), is pollSuspended during startUser still needed, or should the comment be updated to reflect that it is just a bootstrap sanity check?

[Nishanth Kotla (Nishanth29)]

you're right...since SuspendActor is synchronous, pollSuspended isn't needed. I'll remove it and keep just the bootstrap suspend call.

[Mauricio Poppe (mauriciopoppe)]

If u.suspend(ctx) fails, u.loopFailed is never set to true (unlike u.resume(ctx) at line 556 and u.execute(...) at line 566). If SuspendActor fails on the final cycle of a task, recordTaskMetrics() will still record TaskWallClock and TaskCEL as a success.

Should u.suspend(ctx) return a bool (similar to u.resume(ctx)) and set u.loopFailed = true on error?

[Nishanth Kotla (Nishanth29)]

good catch, will do. I'll make suspend return a bool and set loopFailed on error, same as resume.

[Mauricio Poppe (mauriciopoppe)]

The docstring states:

a synchronous reply leaves ackAt zero and is skipped.

However, if /execute returns a synchronous reply (resp.JobID == "", so ackAt is zero) with a non-zero exit code (resp.ExitCode != 0 at line 745), execute() returns err != nil and ackAt.IsZero(). recordResumeToFirstExec then hits case err != nil: and records a ResumeToFirstExec failure using the entire synchronous command duration (time.Since(resumeStart)), even though the actor resume and HTTP routing succeeded.

To match the docstring, recordResumeToFirstExec should only record a failure when the initial HTTP request to /execute failed to get a valid response before ackAt could be determined, or skip recording when a synchronous reply ran and returned a command exit error.

[Nishanth Kotla (Nishanth29)]

true, this path only applies to the old synchronous replay.py. The current images always reply async, so it can't trigger, but I'll add the skip so the code matches the docstring.

[Mauricio Poppe (mauriciopoppe)]

pollJobCompletion polls /status?job_id=... on a fixed 200ms interval (retryInterval = 200 * time.Millisecond), and attempt == 0 fires immediately (~1ms after POST /execute returns 202 Accepted and spawns the background thread in replay.py).

While ResumeToFirstExec (captured at ackAt on line 740 before polling) and CycleCEL/TaskCEL (measured inside the container via time.perf_counter()) are unaffected, the fixed 200ms polling interval directly impacts three measurements:

1. Workload_Cycle_<n> quantization: httpJSONCall wraps validate (pollJobCompletion), so totalLatency (line 805) is quantized to multiples of 200ms + RTT. Any performance improvement smaller than 200ms (e.g., 50ms) that falls between the same poll ticks will show 0ms change.
2. TaskWallClock (u.loopWall) inflation: step() accumulates time.Since(resumeStart) across all 4 cycles, which includes pollJobCompletion on every cycle. A 200ms polling interval injects an average of +100ms per cycle (+400ms mean, up to +800ms max per 4-cycle task) of client sleep into TaskWallClock.
3. Server-side worker hold time: u.suspend(ctx) is not called until pollJobCompletion returns, so the actor remains in ACTOR_STATE_RUNNING holding a worker pod idle for up to 200ms at the end of every cycle.

Note that exponential backoff would make this quantization worse, because SWE-Perf chunks run for 500ms to several seconds; by the time a 1.2s chunk finishes, an exponential backoff schedule would be sleeping 640ms to 1,280ms between polls.

Two ways we could tighten this:

1. Long-polling on /status (preferred if we can update replay.py): Keep POST /execute returning 202 Accepted immediately so ackAt (ResumeToFirstExec) stays exact, and have GET /status?job_id=<id>&wait=1 block on a threading.Event in replay.py until finish_job() completes. That gives 0ms quantization error and 1 /status call per cycle.
2. Client-only improvements: Lower retryInterval from 200ms to 20ms–25ms (/status only reads an in-memory dict in replay.py), sleep once before attempt == 0 so we don't fire an immediate guaranteed-RUNNING poll right after 202 Accepted, and consider computing TaskWallClock without client polling sleep.

[Nishanth Kotla (Nishanth29)]

Yeah, makes sense. The 200ms interval was already there before this PR, but it does add up. Cross-checking with our latest 4u2w run, there's a ~115ms/cycle gap between Workload_Cycle and CycleCEL.

I'll lower it to 25ms and skip the immediate first poll here.

long-polling needs a replay.py change, so I can prolly follow up on that in the sweperf repo later.