github.com/anthropics/anthropic-sdk-go@v1.70.1/lib/environments/worker_test.go (about) 1 package environments 2 3 import ( 4 "bytes" 5 "context" 6 "encoding/json" 7 "errors" 8 "log/slog" 9 "net/http" 10 "os" 11 "strings" 12 "sync" 13 "sync/atomic" 14 "testing" 15 "time" 16 17 "github.com/anthropics/anthropic-sdk-go" 18 "github.com/anthropics/anthropic-sdk-go/option" 19 "github.com/anthropics/anthropic-sdk-go/tools/agenttoolset" 20 "github.com/stretchr/testify/require" 21 ) 22 23 func TestEnvironmentWorker_CancelledCtxReturnsNil(t *testing.T) { 24 server := newFakeWorkServer(t) 25 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 26 EnvironmentID: "env_1", 27 EnvironmentKey: "envkey", 28 Logger: silentLogger, 29 }) 30 ctx, cancel := context.WithCancel(context.Background()) 31 cancel() 32 require.NoError(t, worker.Run(ctx), "a cancelled ctx is normal termination, not an error") 33 } 34 35 func TestEnvironmentWorker_DefaultWorkdirSnapshotsCwd(t *testing.T) { 36 server := newFakeWorkServer(t) 37 38 wd, err := os.Getwd() 39 require.NoError(t, err) 40 41 // An empty Workdir is snapshotted to the cwd at construction, not left as 42 // a lazily-resolved ".". This mirrors the TS/Python helpers and keeps the 43 // session workdir stable across a later os.Chdir. 44 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 45 EnvironmentID: "env_1", 46 EnvironmentKey: "envkey", 47 Logger: silentLogger, 48 }) 49 require.Equal(t, wd, worker.opts.Workdir) 50 require.NotEqual(t, ".", worker.opts.Workdir) 51 52 // An explicit Workdir is honored as-is. 53 explicit := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 54 EnvironmentID: "env_1", 55 EnvironmentKey: "envkey", 56 Workdir: "/some/explicit/dir", 57 Logger: silentLogger, 58 }) 59 require.Equal(t, "/some/explicit/dir", explicit.opts.Workdir) 60 } 61 62 // The deprecated UnrestrictedPaths option fails both entry points before any 63 // request is sent, with an error callers can match. 64 func TestEnvironmentWorker_UnrestrictedPathsIsRejected(t *testing.T) { 65 server := newFakeWorkServer(t) 66 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 67 EnvironmentID: "env_1", 68 EnvironmentKey: "envkey", 69 UnrestrictedPaths: true, 70 Logger: silentLogger, 71 }) 72 require.ErrorIs(t, worker.Run(context.Background()), agenttoolset.ErrUnrestrictedPathsUnsupported) 73 require.ErrorIs(t, worker.HandleItem(context.Background(), HandleItemOptions{ 74 WorkID: "work_1", 75 EnvironmentID: "env_1", 76 SessionID: "sesn_1", 77 EnvironmentKey: "envkey", 78 }), agenttoolset.ErrUnrestrictedPathsUnsupported) 79 require.Empty(t, server.Calls()) 80 } 81 82 // A MemorySyncInterval below the floor fails both entry points the same way. 83 func TestEnvironmentWorker_AShortMemorySyncIntervalIsRejected(t *testing.T) { 84 server := newFakeWorkServer(t) 85 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 86 EnvironmentID: "env_1", 87 EnvironmentKey: "envkey", 88 MemorySyncInterval: time.Second, 89 Logger: silentLogger, 90 }) 91 require.ErrorIs(t, worker.Run(context.Background()), ErrMemorySyncIntervalTooShort) 92 require.ErrorIs(t, worker.HandleItem(context.Background(), HandleItemOptions{ 93 WorkID: "work_1", 94 EnvironmentID: "env_1", 95 SessionID: "sesn_1", 96 EnvironmentKey: "envkey", 97 }), ErrMemorySyncIntervalTooShort) 98 require.Empty(t, server.Calls()) 99 } 100 101 func TestEnvironmentWorker_RequiresEnvironmentID(t *testing.T) { 102 server := newFakeWorkServer(t) 103 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 104 EnvironmentKey: "envkey", 105 Logger: silentLogger, 106 }) 107 // The underlying WorkPoller surfaces the missing-id error on the first poll. 108 require.Error(t, worker.Run(context.Background())) 109 } 110 111 // The queue hands the worker a health check instead of a session. There is 112 // no session to look up or serve, but the item must still be stopped so the 113 // queue gets it back. 114 func TestEnvironmentWorker_SkipsNonSessionItem(t *testing.T) { 115 server := newFakeWorkServer(t) 116 scriptWorkServer(t, server, workJSON("work_1", "env_1", "healthcheck")) 117 server.HandleSessionGet = func(w http.ResponseWriter, _ *http.Request) { 118 t.Error("no session must be fetched for a health check") 119 http.Error(w, "not found", http.StatusNotFound) 120 } 121 server.HandleStream = func(w http.ResponseWriter, _ *http.Request) { 122 t.Error("no session must be served for a health check") 123 http.Error(w, "not found", http.StatusNotFound) 124 } 125 ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) 126 defer cancel() 127 // End the run once the item was stopped. 128 var stops atomic.Int32 129 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 130 w.WriteHeader(http.StatusNoContent) 131 stops.Add(1) 132 cancel() 133 } 134 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 135 EnvironmentID: "env_1", 136 EnvironmentKey: "env_key", 137 Workdir: t.TempDir(), 138 Logger: silentLogger, 139 }) 140 141 require.NoError(t, worker.Run(ctx)) 142 143 require.Equal(t, int32(1), stops.Load()) 144 } 145 146 // customHeaderName/customHeaderValue stand in for a caller-supplied 147 // proxy/routing header that must reach every request the self-hosted runner 148 // issues when threaded through EnvironmentWorkerOptions.RequestOptions. 149 const ( 150 customHeaderName = "X-Custom-Proxy" 151 customHeaderValue = "proxy-token-xyz" 152 ) 153 154 // assertCustomHeaderEverywhere asserts that every recorded call carries the 155 // caller's custom header, authenticates with the environment key, AND does 156 // NOT leak the parent client's X-Api-Key. The third assertion is what closes 157 // the regression window the original #854 review missed: a future change 158 // that drops WithHeaderDel("X-Api-Key") from the worker side of the auth 159 // recipe (heartbeat, force-stop, runner stream/list/send, skill-setup 160 // session lookup) flips this assertion immediately, just as the poller-side 161 // assertion at poller_test.go:307-315 does for poll/ack/stop. 162 func assertCustomHeaderEverywhere(t *testing.T, calls []recordedCall) { 163 t.Helper() 164 require.NotEmpty(t, calls, "expected the worker to issue at least one request") 165 for _, c := range calls { 166 t.Run(c.method+" "+c.path, func(t *testing.T) { 167 require.Equal(t, customHeaderValue, c.header.Get(customHeaderName), 168 "caller-supplied custom header must reach %s %s", c.method, c.path) 169 require.Equal(t, "Bearer env_key", c.auth, 170 "environment-key auth must still win on %s %s", c.method, c.path) 171 require.Empty(t, c.apiKey, 172 "%s %s must not leak the parent client's X-Api-Key alongside the bearer", c.method, c.path) 173 }) 174 } 175 } 176 177 // TestWorkPoller_ThreadsCustomRequestOptions covers the poller leg: a custom 178 // header supplied via WorkPollerOptions.RequestOptions must appear on 179 // Poll/Ack/Stop. 180 func TestWorkPoller_ThreadsCustomRequestOptions(t *testing.T) { 181 server := newFakeWorkServer(t) 182 work := workJSON("work_1", "env_1", "session") 183 184 pollCount := 0 185 server.HandlePoll = func(w http.ResponseWriter, _ *http.Request) { 186 pollCount++ 187 w.Header().Set("Content-Type", "application/json") 188 if pollCount == 1 { 189 _, _ = w.Write([]byte(work)) 190 } else { 191 w.WriteHeader(http.StatusNoContent) 192 } 193 } 194 server.HandleAck = func(w http.ResponseWriter, _ *http.Request) { 195 w.Header().Set("Content-Type", "application/json") 196 _, _ = w.Write([]byte(work)) 197 } 198 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 199 w.WriteHeader(http.StatusNoContent) 200 } 201 202 ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) 203 defer cancel() 204 205 p := NewWorkPoller(ctx, server.Client(), WorkPollerOptions{ 206 EnvironmentID: "env_1", 207 EnvironmentKey: "env_key", 208 WorkerID: "test-worker", 209 RequestOptions: []option.RequestOption{option.WithHeader(customHeaderName, customHeaderValue)}, 210 Logger: silentLogger, 211 }) 212 213 require.True(t, p.Next(), "first Next() must yield the scripted work") 214 require.NoError(t, p.Close()) 215 216 calls := server.Calls() 217 require.Len(t, calls, 3, "expected poll + ack + stop") 218 assertCustomHeaderEverywhere(t, calls) 219 } 220 221 // TestEnvironmentWorker_ThreadsCustomRequestOptions covers the per-session 222 // leg: a custom header supplied via EnvironmentWorkerOptions.RequestOptions 223 // must reach the session lookup, the lease heartbeat, the SessionToolRunner's 224 // stream/list, and the force-stop on exit. 225 func TestEnvironmentWorker_ThreadsCustomRequestOptions(t *testing.T) { 226 server := newFakeWorkServer(t) 227 228 // Gate the stream's terminate event on the heartbeat having fired, so the 229 // heartbeat is deterministically observed before the session ends and the 230 // per-session context is cancelled — no timing-based flakiness. 231 heartbeatSeen := make(chan struct{}) 232 var heartbeatOnce sync.Once 233 234 server.HandleSessionGet = func(w http.ResponseWriter, _ *http.Request) { 235 // No skills -> SetupSkills issues no requests of its own. 236 w.Header().Set("Content-Type", "application/json") 237 _, _ = w.Write([]byte(`{"agent":{"skills":[]}}`)) 238 } 239 server.HandleHeartbeat = func(w http.ResponseWriter, _ *http.Request) { 240 heartbeatOnce.Do(func() { close(heartbeatSeen) }) 241 w.Header().Set("Content-Type", "application/json") 242 _, _ = w.Write([]byte(`{"last_heartbeat":"2026-05-11T12:00:00Z","lease_extended":true,"state":"active","ttl_seconds":30,"type":"work_heartbeat"}`)) 243 } 244 server.HandleList = func(w http.ResponseWriter, _ *http.Request) { 245 w.Header().Set("Content-Type", "application/json") 246 _, _ = w.Write([]byte(`{"data":[],"first_id":null,"has_more":false,"last_id":null}`)) 247 } 248 server.HandleStream = func(w http.ResponseWriter, r *http.Request) { 249 w.Header().Set("Content-Type", "text/event-stream") 250 flusher, ok := w.(http.Flusher) 251 require.True(t, ok, "stream response writer must support flushing") 252 w.WriteHeader(http.StatusOK) 253 flusher.Flush() 254 // Wait for at least one heartbeat before terminating the session. 255 select { 256 case <-heartbeatSeen: 257 case <-r.Context().Done(): 258 return 259 case <-time.After(5 * time.Second): 260 t.Error("heartbeat was never observed before stream terminate") 261 } 262 _, _ = w.Write([]byte("event: session.status_terminated\n" + 263 `data: {"type":"session.status_terminated","id":"evt_term","processed_at":"2026-05-11T12:00:00Z"}` + 264 "\n\n")) 265 flusher.Flush() 266 } 267 server.HandleSend = func(w http.ResponseWriter, _ *http.Request) { 268 // No tool_use fires, so Send should never be called. 269 t.Error("Send must not be called when no tool_use event arrives") 270 w.WriteHeader(http.StatusOK) 271 } 272 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 273 w.WriteHeader(http.StatusNoContent) 274 } 275 276 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 277 EnvironmentID: "env_1", 278 EnvironmentKey: "env_key", 279 Workdir: t.TempDir(), 280 RequestOptions: []option.RequestOption{option.WithHeader(customHeaderName, customHeaderValue)}, 281 Logger: silentLogger, 282 }) 283 284 ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) 285 defer cancel() 286 287 require.NoError(t, worker.HandleItem(ctx, HandleItemOptions{ 288 WorkID: "work_1", 289 EnvironmentID: "env_1", 290 SessionID: "sesn_test", 291 }), "a terminated session is benign and HandleItem should return nil") 292 293 calls := server.Calls() 294 assertCustomHeaderEverywhere(t, calls) 295 296 // Sanity-check that the calls we expect to carry the header actually 297 // happened — otherwise the assertion above could pass vacuously. 298 want := map[string]bool{ 299 "sessions/sesn_test": false, // skill-setup session lookup 300 "work/work_1/heartbeat": false, // lease heartbeat 301 "sessions/sesn_test/events/stream": false, // runner stream 302 "work/work_1/stop": false, // force-stop on exit 303 } 304 for _, c := range calls { 305 for suffix := range want { 306 if strings.HasSuffix(c.path, suffix) { 307 want[suffix] = true 308 } 309 } 310 } 311 for suffix, seen := range want { 312 require.True(t, seen, "expected a request to %q but none was recorded", suffix) 313 } 314 } 315 316 // TestEnvironmentWorker_LeaseTTLBoundsSendRetryWindow pins the wiring from 317 // the lease heartbeat to the runner (internal/sendwindow on the session ctx): 318 // the server-reported ttl_seconds becomes the runner's tool-result send retry 319 // window, so a send that keeps failing 320 // transiently is abandoned once the lease TTL has passed rather than after 321 // the runner's standalone 5m default. 322 func TestEnvironmentWorker_LeaseTTLBoundsSendRetryWindow(t *testing.T) { 323 server := newFakeWorkServer(t) 324 325 server.HandleSessionGet = func(w http.ResponseWriter, _ *http.Request) { 326 w.Header().Set("Content-Type", "application/json") 327 _, _ = w.Write([]byte(`{"agent":{"skills":[]}}`)) 328 } 329 server.HandleHeartbeat = func(w http.ResponseWriter, _ *http.Request) { 330 w.Header().Set("Content-Type", "application/json") 331 _, _ = w.Write([]byte(`{"last_heartbeat":"2026-05-11T12:00:00Z","lease_extended":true,"state":"active","ttl_seconds":1,"type":"work_heartbeat"}`)) 332 } 333 server.HandleList = func(w http.ResponseWriter, _ *http.Request) { 334 w.Header().Set("Content-Type", "application/json") 335 _, _ = w.Write([]byte(`{"data":[],"first_id":null,"has_more":false,"last_id":null}`)) 336 } 337 var firstSend, lastSend atomic.Int64 // unix nanos 338 server.HandleSend = func(w http.ResponseWriter, _ *http.Request) { 339 now := time.Now().UnixNano() 340 firstSend.CompareAndSwap(0, now) 341 lastSend.Store(now) 342 http.Error(w, "unavailable", http.StatusServiceUnavailable) 343 } 344 server.HandleStream = func(w http.ResponseWriter, r *http.Request) { 345 w.Header().Set("Content-Type", "text/event-stream") 346 flusher, ok := w.(http.Flusher) 347 require.True(t, ok, "stream response writer must support flushing") 348 w.WriteHeader(http.StatusOK) 349 _, _ = w.Write([]byte("event: agent.tool_use\n" + 350 `data: {"type":"agent.tool_use","id":"evt_1","name":"echo","input":{},"processed_at":"2026-05-11T12:00:00Z"}` + 351 "\n\n")) 352 flusher.Flush() 353 // Keep the session open well past the 1s lease TTL so only the send 354 // retry window — not session termination — can end the retries. 355 select { 356 case <-time.After(3 * time.Second): 357 case <-r.Context().Done(): 358 return 359 } 360 _, _ = w.Write([]byte("event: session.status_terminated\n" + 361 `data: {"type":"session.status_terminated","id":"evt_term","processed_at":"2026-05-11T12:00:00Z"}` + 362 "\n\n")) 363 flusher.Flush() 364 } 365 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 366 w.WriteHeader(http.StatusNoContent) 367 } 368 369 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 370 EnvironmentID: "env_1", 371 EnvironmentKey: "env_key", 372 Workdir: t.TempDir(), 373 Tools: []anthropic.BetaTool{echoTool{}}, 374 Logger: silentLogger, 375 }) 376 377 ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second) 378 defer cancel() 379 require.NoError(t, worker.HandleItem(ctx, HandleItemOptions{ 380 WorkID: "work_1", 381 EnvironmentID: "env_1", 382 SessionID: "sesn_test", 383 })) 384 385 first, last := firstSend.Load(), lastSend.Load() 386 require.NotZero(t, first, "the send should have been attempted") 387 require.Greater(t, last, first, "the send should have been retried") 388 require.Less(t, time.Duration(last-first), 1500*time.Millisecond, 389 "retries must stop once the 1s lease TTL has passed; under the 5m default they would continue until the session terminated ~3s later") 390 } 391 392 // echoTool is a minimal anthropic.BetaTool for driving the runner inside the 393 // worker composition. 394 type echoTool struct{} 395 396 func (echoTool) Name() string { return "echo" } 397 func (echoTool) Description() string { return "echo" } 398 func (echoTool) InputSchema() anthropic.BetaToolInputSchemaParam { 399 return anthropic.BetaToolInputSchemaParam{Properties: map[string]any{}} 400 } 401 func (echoTool) Execute(context.Context, json.RawMessage) ([]anthropic.BetaToolResultBlockParamContentUnion, error) { 402 return []anthropic.BetaToolResultBlockParamContentUnion{{OfText: &anthropic.BetaTextBlockParam{Text: "ok"}}}, nil 403 } 404 405 // TestEnvironmentWorker_HeartbeatStartsBeforeSkillSetup pins the invariant 406 // that the lease heartbeat is running before the session lookup that feeds 407 // skill setup completes. The poller acks the item when it 408 // yields, so any gap between ack and the first heartbeat is a window where 409 // the control plane can reclaim the lease — and the lookup plus a per-skill 410 // download/extract can take longer than the lease 411 // TTL on a slow network or a large bundle. 412 // 413 // The test enforces this by making HandleSessionGet block until at least 414 // one heartbeat has fired. If the heartbeat goroutine is started AFTER 415 // skill setup returns (the pre-fix shape), no heartbeat ever fires and 416 // HandleSessionGet blocks until the outer ctx times out — HandleItem then 417 // returns the wrapped ctx error rather than nil. With the fix, the 418 // heartbeat goroutine is started before the lookup, the channel closes 419 // while the session lookup is in flight, and the session 420 // completes normally. 421 func TestEnvironmentWorker_HeartbeatStartsBeforeSkillSetup(t *testing.T) { 422 server := newFakeWorkServer(t) 423 424 heartbeatSeen := make(chan struct{}) 425 var heartbeatOnce sync.Once 426 427 server.HandleHeartbeat = func(w http.ResponseWriter, _ *http.Request) { 428 heartbeatOnce.Do(func() { close(heartbeatSeen) }) 429 w.Header().Set("Content-Type", "application/json") 430 _, _ = w.Write([]byte(`{"last_heartbeat":"2026-05-11T12:00:00Z","lease_extended":true,"state":"active","ttl_seconds":30,"type":"work_heartbeat"}`)) 431 } 432 server.HandleSessionGet = func(w http.ResponseWriter, r *http.Request) { 433 // Block the session-get until a heartbeat has been observed. This is 434 // what proves the heartbeat starts BEFORE skill setup finishes — if 435 // it didn't, this handler would block forever (the heartbeat 436 // goroutine never starts) and the outer context would time out. 437 select { 438 case <-heartbeatSeen: 439 case <-r.Context().Done(): 440 return 441 case <-time.After(5 * time.Second): 442 t.Error("heartbeat did not fire while the session lookup was in flight") 443 return 444 } 445 w.Header().Set("Content-Type", "application/json") 446 _, _ = w.Write([]byte(`{"agent":{"skills":[]}}`)) 447 } 448 server.HandleList = func(w http.ResponseWriter, _ *http.Request) { 449 w.Header().Set("Content-Type", "application/json") 450 _, _ = w.Write([]byte(`{"data":[],"first_id":null,"has_more":false,"last_id":null}`)) 451 } 452 server.HandleStream = func(w http.ResponseWriter, _ *http.Request) { 453 w.Header().Set("Content-Type", "text/event-stream") 454 flusher, ok := w.(http.Flusher) 455 require.True(t, ok, "stream response writer must support flushing") 456 w.WriteHeader(http.StatusOK) 457 flusher.Flush() 458 _, _ = w.Write([]byte("event: session.status_terminated\n" + 459 `data: {"type":"session.status_terminated","id":"evt_term","processed_at":"2026-05-11T12:00:00Z"}` + 460 "\n\n")) 461 flusher.Flush() 462 } 463 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 464 w.WriteHeader(http.StatusNoContent) 465 } 466 467 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 468 EnvironmentID: "env_1", 469 EnvironmentKey: "env_key", 470 Workdir: t.TempDir(), 471 Logger: silentLogger, 472 }) 473 474 ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) 475 defer cancel() 476 477 require.NoError(t, worker.HandleItem(ctx, HandleItemOptions{ 478 WorkID: "work_1", 479 EnvironmentID: "env_1", 480 SessionID: "sesn_test", 481 }), "HandleItem must complete normally; if the heartbeat never starts, HandleSessionGet blocks until ctx timeout and HandleItem returns a wrapped ctx error") 482 } 483 484 // TestEnvironmentWorker_HeartbeatPerRequestTimeoutAndStalenessCeiling pins 485 // two related guarantees about runHeartbeat: 486 // 487 // 1. No per-request timeout — Heartbeat inherits the SDK's ~10-minute 488 // default, so one slow/hung call outlives the entire lease window. 489 // 2. No staleness ceiling — a run of transient errors retries forever while 490 // the lease silently expires server-side; the worker keeps executing 491 // tools against a session another worker may also have claimed. 492 // 493 // The fixes interact: each Heartbeat is sent with WithRequestTimeout(interval) 494 // (so hung calls fail fast), and the transient-error branch bails when 495 // time.Since(lastSuccess) > ttl (so a run of fast-failing or fast-cancelled 496 // beats also terminates the heartbeat goroutine within a bounded window). 497 // 498 // This test scripts a server that returns one successful beat with a short 499 // TTL (2 s — shrinks interval to 1 s and ttl to 2 s) and then hangs every 500 // subsequent heartbeat. With the fixes, each hung beat is cancelled at the 501 // 1 s request timeout, and the staleness check fires once we're past the 502 // 2 s TTL since the last success — so the heartbeat goroutine cancels 503 // sessCtx, the runner exits with ctx.Canceled, and HandleItem returns the 504 // wrapped ctx error well within the 15 s outer ctx. 505 // 506 // Without the per-request-timeout fix, beat 2 would block on the hung 507 // handler for the full SDK default (10 min) — only one heartbeat call would 508 // land, and HandleItem would only return when the outer ctx times out. 509 // Without the staleness-ceiling fix (even with the request timeout) the 510 // goroutine would log transient failures forever; sessCtx would never be 511 // cancelled by the heartbeat. 512 func TestEnvironmentWorker_HeartbeatPerRequestTimeoutAndStalenessCeiling(t *testing.T) { 513 server := newFakeWorkServer(t) 514 515 var heartbeatCalls atomic.Int32 516 server.HandleHeartbeat = func(w http.ResponseWriter, r *http.Request) { 517 n := heartbeatCalls.Add(1) 518 if n == 1 { 519 // First beat succeeds with a tight TTL so the test runs fast: 520 // ttl becomes 2 s and interval shrinks to 1 s. 521 w.Header().Set("Content-Type", "application/json") 522 _, _ = w.Write([]byte(shortTTLHeartbeat)) 523 return 524 } 525 // Every subsequent beat hangs. With the per-request-timeout fix the 526 // client cancels at interval (1 s); the handler's request context 527 // fires and the handler returns. Without the fix, this would block 528 // for the SDK default (~10 min). 529 select { 530 case <-r.Context().Done(): 531 return 532 case <-time.After(20 * time.Second): 533 t.Error("hung heartbeat was never cancelled — per-request timeout did not fire") 534 } 535 } 536 537 scriptOpenSession(t, server) 538 elapsed := timeHandleItem(t, server, silentLogger) 539 540 // With the fix, the staleness ceiling fires once the 2 s ttl has 541 // elapsed since the first (and only) successful beat, terminating 542 // HandleItem in roughly that window. 8 s is comfortably below the 15 s 543 // outer ctx, so a regression where only the outer ctx terminates the 544 // run fails this check. 545 require.Less(t, elapsed, 8*time.Second, "HandleItem ran too long — staleness ceiling didn't terminate the heartbeat (got %s)", elapsed) 546 547 // At least 2 heartbeat calls must have landed: the first success and at 548 // least one timeout-cancelled retry. Without the per-request-timeout 549 // fix, the second call would still be blocked on the SDK's ~10 min 550 // default when HandleItem returns (via the outer ctx), so the count 551 // would be 1. 552 require.GreaterOrEqual(t, heartbeatCalls.Load(), int32(2), "expected at least 2 heartbeats; got %d — per-request timeout likely missing", heartbeatCalls.Load()) 553 } 554 555 // A 409 on heartbeat is transient: the session survives the first one, the 556 // beat is retried at the current interval, and only the staleness ceiling — 557 // no successful heartbeat within ttl — cancels the session. 558 func TestEnvironmentWorker_Heartbeat409IsRetriedUntilStalenessCeiling(t *testing.T) { 559 server := newFakeWorkServer(t) 560 561 var heartbeatCalls atomic.Int32 562 server.HandleHeartbeat = func(w http.ResponseWriter, _ *http.Request) { 563 if heartbeatCalls.Add(1) == 1 { 564 w.Header().Set("Content-Type", "application/json") 565 _, _ = w.Write([]byte(shortTTLHeartbeat)) 566 return 567 } 568 writeAPIError(w, http.StatusConflict) 569 } 570 scriptOpenSession(t, server) 571 572 var logs lockedBuffer 573 elapsed := timeHandleItem(t, server, slog.New(slog.NewTextHandler(&logs, nil))) 574 575 require.Less(t, elapsed, 8*time.Second, "the staleness ceiling must end the session once ttl passes without a successful heartbeat (got %s)", elapsed) 576 require.GreaterOrEqual(t, heartbeatCalls.Load(), int32(3), "a 409 must be retried at the beat interval, not end heartbeating") 577 out := logs.String() 578 require.Contains(t, out, "transient heartbeat failure") 579 require.Contains(t, out, "heartbeat staleness ceiling exceeded") 580 require.NotContains(t, out, "permanent heartbeat failure", "a 409 must never take the permanent-failure path") 581 } 582 583 func TestEnvironmentWorker_Heartbeat401CancelsImmediately(t *testing.T) { 584 server := newFakeWorkServer(t) 585 586 var heartbeatCalls atomic.Int32 587 server.HandleHeartbeat = func(w http.ResponseWriter, _ *http.Request) { 588 heartbeatCalls.Add(1) 589 writeAPIError(w, http.StatusUnauthorized) 590 } 591 scriptOpenSession(t, server) 592 593 var logs lockedBuffer 594 elapsed := timeHandleItem(t, server, slog.New(slog.NewTextHandler(&logs, nil))) 595 596 require.Less(t, elapsed, 5*time.Second, "a permanent heartbeat failure must cancel the session at once (got %s)", elapsed) 597 require.Equal(t, int32(1), heartbeatCalls.Load(), "a 401 must not be retried") 598 require.Contains(t, logs.String(), "permanent heartbeat failure") 599 } 600 601 // shortTTLHeartbeat is a successful heartbeat body whose 2 s TTL shrinks the 602 // worker's beat interval to 1 s and its staleness ceiling to 2 s. 603 const shortTTLHeartbeat = `{"last_heartbeat":"2026-05-11T12:00:00Z","lease_extended":true,"state":"active","ttl_seconds":2,"type":"work_heartbeat"}` 604 605 // scriptOpenSession scripts a skill-less session whose event stream stays 606 // open until the per-session context is cancelled, so only the heartbeat 607 // loop (or the outer deadline) can end HandleItem. 608 func scriptOpenSession(t *testing.T, server *fakeWorkServer) { 609 t.Helper() 610 server.HandleSessionGet = func(w http.ResponseWriter, _ *http.Request) { 611 w.Header().Set("Content-Type", "application/json") 612 _, _ = w.Write([]byte(`{"agent":{"skills":[]}}`)) 613 } 614 server.HandleList = func(w http.ResponseWriter, _ *http.Request) { 615 w.Header().Set("Content-Type", "application/json") 616 _, _ = w.Write([]byte(`{"data":[],"first_id":null,"has_more":false,"last_id":null}`)) 617 } 618 server.HandleStream = func(w http.ResponseWriter, r *http.Request) { 619 w.Header().Set("Content-Type", "text/event-stream") 620 flusher, ok := w.(http.Flusher) 621 require.True(t, ok) 622 w.WriteHeader(http.StatusOK) 623 flusher.Flush() 624 <-r.Context().Done() 625 } 626 server.HandleStop = func(w http.ResponseWriter, _ *http.Request) { 627 w.WriteHeader(http.StatusNoContent) 628 } 629 } 630 631 // timeHandleItem serves one work item against server and returns how long 632 // HandleItem took. The 15 s outer deadline is deliberately generous so a run 633 // that only the deadline ended is distinguishable from one the heartbeat loop 634 // ended; callers assert an upper bound well below it. HandleItem's return 635 // value is ignored: a heartbeat-driven cancel is normal termination (nil). 636 func timeHandleItem(t *testing.T, server *fakeWorkServer, logger *slog.Logger) time.Duration { 637 t.Helper() 638 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 639 EnvironmentID: "env_1", 640 EnvironmentKey: "env_key", 641 Workdir: t.TempDir(), 642 Logger: logger, 643 }) 644 ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second) 645 defer cancel() 646 647 start := time.Now() 648 _ = worker.HandleItem(ctx, HandleItemOptions{ 649 WorkID: "work_1", 650 EnvironmentID: "env_1", 651 SessionID: "sesn_test", 652 }) 653 return time.Since(start) 654 } 655 656 // lockedBuffer is an io.Writer safe for the concurrent writes slog issues 657 // from the worker's goroutines. 658 type lockedBuffer struct { 659 mu sync.Mutex 660 buf bytes.Buffer 661 } 662 663 func (b *lockedBuffer) Write(p []byte) (int, error) { 664 b.mu.Lock() 665 defer b.mu.Unlock() 666 return b.buf.Write(p) 667 } 668 669 func (b *lockedBuffer) String() string { 670 b.mu.Lock() 671 defer b.mu.Unlock() 672 return b.buf.String() 673 } 674 675 // leaseLostBody is the 412 the control plane answers a heartbeat with once the 676 // item's lease was cleared (re-queued) or is held by another worker. 677 const leaseLostBody = `{"type":"error","error":{"type":"invalid_request_error","message":"Heartbeat precondition failed: expected hb-1, actual was NULL","details":{"error_code":"heartbeat_precondition_failed","error_visibility":"user_facing","current_state":{"state":"queued","last_heartbeat":null,"lease_updated_at":null,"lease_extended":false,"ttl_seconds":120}}}}` 678 679 // callsEndingIn returns the recorded calls whose path ends in suffix, in order. 680 func callsEndingIn(calls []recordedCall, suffix string) []recordedCall { 681 var out []recordedCall 682 for _, c := range calls { 683 if strings.HasSuffix(c.path, suffix) { 684 out = append(out, c) 685 } 686 } 687 return out 688 } 689 690 // runItemEndedByHeartbeat runs one worker pass over work_1 whose session never 691 // completes on its own: every heartbeat is held until the event stream is open 692 // and then answered by answerHeartbeat (beat counts from 1), so the heartbeat 693 // alone decides how the item ends; the second poll ends the run. 694 func runItemEndedByHeartbeat(t *testing.T, answerHeartbeat func(w http.ResponseWriter, beat int)) (*fakeWorkServer, string) { 695 t.Helper() 696 server := newFakeWorkServer(t) 697 work := workJSON("work_1", "env_1", "session") 698 ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) 699 defer cancel() 700 701 var polls atomic.Int32 702 server.HandlePoll = func(w http.ResponseWriter, r *http.Request) { 703 if polls.Add(1) == 1 { 704 w.Header().Set("Content-Type", "application/json") 705 _, _ = w.Write([]byte(work)) 706 return 707 } 708 cancel() 709 <-r.Context().Done() 710 } 711 server.HandleAck = func(w http.ResponseWriter, _ *http.Request) { 712 w.Header().Set("Content-Type", "application/json") 713 _, _ = w.Write([]byte(work)) 714 } 715 scriptOpenSession(t, server) 716 serving := make(chan struct{}) 717 var servingOnce sync.Once 718 server.HandleStream = func(w http.ResponseWriter, r *http.Request) { 719 w.Header().Set("Content-Type", "text/event-stream") 720 flusher, ok := w.(http.Flusher) 721 require.True(t, ok, "stream response writer must support flushing") 722 w.WriteHeader(http.StatusOK) 723 flusher.Flush() 724 servingOnce.Do(func() { close(serving) }) 725 <-r.Context().Done() 726 } 727 var beats atomic.Int32 728 server.HandleHeartbeat = func(w http.ResponseWriter, r *http.Request) { 729 n := beats.Add(1) 730 select { 731 case <-serving: 732 case <-r.Context().Done(): 733 return 734 case <-time.After(5 * time.Second): 735 t.Error("the event stream never opened while a heartbeat was waiting") 736 return 737 } 738 answerHeartbeat(w, int(n)) 739 } 740 741 var logs lockedBuffer 742 worker := NewEnvironmentWorker(server.Client(), EnvironmentWorkerOptions{ 743 EnvironmentID: "env_1", 744 EnvironmentKey: "env_key", 745 WorkerID: "test-worker", 746 Workdir: t.TempDir(), 747 Logger: slog.New(slog.NewTextHandler(&logs, nil)), 748 }) 749 require.NoError(t, worker.Run(ctx)) 750 751 require.NotEmpty(t, callsEndingIn(server.Calls(), "/sessions/sesn_test/events/stream"), "the runner must have served the session") 752 require.EqualValues(t, 2, polls.Load(), "Run must go back to polling after the item ends") 753 return server, logs.String() 754 } 755 756 // A 412 on the heartbeat means the server cleared this worker's lease 757 // (re-queued the item, or another worker holds it). The run ends, no stop of 758 // any kind is posted — that would take the item from its new holder — and the 759 // worker goes back to polling. 760 func TestEnvironmentWorker_Heartbeat412ReleasesItemWithoutStoppingIt(t *testing.T) { 761 server, logs := runItemEndedByHeartbeat(t, func(w http.ResponseWriter, _ int) { 762 w.Header().Set("Content-Type", "application/json") 763 w.WriteHeader(http.StatusPreconditionFailed) 764 _, _ = w.Write([]byte(leaseLostBody)) 765 }) 766 767 calls := server.Calls() 768 require.Len(t, callsEndingIn(calls, "/heartbeat"), 1) 769 require.Empty(t, callsEndingIn(calls, "/stop"), "a lost item must not be stopped by the worker or its poller") 770 require.Contains(t, logs, `level=ERROR msg="lease lost: heartbeat precondition failed" work_id=work_1 session_id=sesn_test server_state=queued server_ttl_seconds=120 server_last_heartbeat=<nil>`) 771 require.Contains(t, logs, `level=INFO msg="lease lost; released without stopping it" work_id=work_1 session_id=sesn_test`) 772 require.Equal(t, 1, strings.Count(logs, "lease lost; released without stopping it")) 773 for _, stem := range []string{"force-stop on exit failed", "session lookup failed", "session tool runner exited with error"} { 774 require.NotContains(t, logs, stem) 775 } 776 } 777 778 // A heartbeat reporting state "stopped" ends the run and the item is still 779 // force-stopped on the way out — only a lost lease skips that — and that 780 // force-stop is the item's only stop in a full Run. 781 func TestEnvironmentWorker_ControlPlaneStopStillForceStops(t *testing.T) { 782 server, logs := runItemEndedByHeartbeat(t, func(w http.ResponseWriter, _ int) { 783 w.Header().Set("Content-Type", "application/json") 784 _, _ = w.Write([]byte(`{"last_heartbeat":"2026-05-11T12:00:00Z","lease_extended":true,"state":"stopped","ttl_seconds":30,"type":"work_heartbeat"}`)) 785 }) 786 787 require.Contains(t, logs, `msg="heartbeat reports shutdown" work_id=work_1 session_id=sesn_test state=stopped`) 788 stops := callsEndingIn(server.Calls(), "/stop") 789 require.Len(t, stops, 1, "the exit-path force-stop must be the item's only stop") 790 require.Contains(t, stops[0].path, "work/work_1/stop") 791 require.Contains(t, stops[0].body, `"force":true`) 792 require.Equal(t, "Bearer env_key", stops[0].auth) 793 require.NotContains(t, logs, "without stopping it") 794 } 795 796 // Transient heartbeat failures lasting past the lease TTL mean another worker 797 // may hold the item by now, so it is released without a force-stop. 798 func TestEnvironmentWorker_LeaseAssumedLostReleasesItemWithoutStoppingIt(t *testing.T) { 799 start := time.Now() 800 server, logs := runItemEndedByHeartbeat(t, func(w http.ResponseWriter, beat int) { 801 if beat == 1 { 802 w.Header().Set("Content-Type", "application/json") 803 _, _ = w.Write([]byte(shortTTLHeartbeat)) 804 return 805 } 806 writeAPIError(w, http.StatusServiceUnavailable) 807 }) 808 809 require.Less(t, time.Since(start), 8*time.Second) 810 require.GreaterOrEqual(t, len(callsEndingIn(server.Calls(), "/heartbeat")), 2) 811 require.Contains(t, logs, "heartbeat staleness ceiling exceeded; lease presumed expired") 812 require.Empty(t, callsEndingIn(server.Calls(), "/stop")) 813 require.Equal(t, 1, strings.Count(logs, `msg="lease lost; released without stopping it" work_id=work_1 session_id=sesn_test`)) 814 } 815 816 // Only the two reasons where the item now belongs to someone else read as 817 // lost; every other reason, and no reason at all, keeps the force-stop. 818 func TestLeaseLostClassification(t *testing.T) { 819 tests := []struct { 820 description string 821 reason leaseEndReason 822 lost bool 823 }{ 824 {"a 412 hands the item to the queue or another worker", leaseLost, true}, 825 {"a full TTL without a successful heartbeat is treated the same way", leaseAssumedLost, true}, 826 {"a control-plane stop still force-stops", leaseControlPlaneStop, false}, 827 {"a rejected heartbeat still force-stops", leaseHeartbeatRejected, false}, 828 {"the run finishing first still force-stops", leaseRunnerDone, false}, 829 {"a lease that never ended still force-stops", leaseHeld, false}, 830 } 831 for _, tc := range tests { 832 t.Run(tc.description, func(t *testing.T) { 833 require.Equal(t, tc.lost, tc.reason.lost()) 834 }) 835 } 836 } 837 838 // The 412 log line reads the server's view of the lease from the error body; a 839 // body without one, or an error that never reached the API, yields nil so the 840 // fields log as <nil> rather than breaking the heartbeat path. 841 func TestServerLeaseState(t *testing.T) { 842 apiError := func(body string) error { 843 apiErr := &anthropic.Error{StatusCode: http.StatusPreconditionFailed} 844 require.NoError(t, apiErr.UnmarshalJSON([]byte(body))) 845 return apiErr 846 } 847 require.Equal(t, map[string]any{ 848 "state": "queued", 849 "last_heartbeat": nil, 850 "lease_updated_at": nil, 851 "lease_extended": false, 852 "ttl_seconds": float64(120), 853 }, serverLeaseState(apiError(leaseLostBody))) 854 require.Nil(t, serverLeaseState(apiError(`{"type":"error","error":{"type":"api_error","message":"unavailable"}}`))) 855 require.Nil(t, serverLeaseState(errors.New("connection reset"))) 856 require.Nil(t, serverLeaseState(nil)) 857 }