carlos / platform Public

Clone
git clone https://amadan.net/carlos/platform

Plain git — no account needed to clone.

Download

Download this file

1package console
2
3import (
4 "context"
5 "encoding/json"
6 "errors"
7 "fmt"
8 "io"
9 "net/http"
10 "sync/atomic"
11 "testing"
12 "time"
13
14 "github.com/carlosframework/platform/internal/objstore"
15 "github.com/carlosframework/platform/internal/release"
16)
17
18// statusArmed is enqueueArmed plus a handle on the engine, because every test
19// here has to stage what the object's tag says.
20func statusArmed(t *testing.T, code string) (*consoleFixture, *objstore.MemScanner, string, string) {
21 t.Helper()
22 fx, _, token, _ := storeArmed(t, code)
23 grantStore(t, fx, token)
24 requestScanning(t, fx, token, false)
25 sc := objstore.NewMemScanner()
26 fx.srv.cfg.StoreScanner = sc
27 enableDeploymentScanning(t, fx)
28 fx.srv.cfg.StoreOperators = []string{"alice@keymail.dev"}
29 if s, o := postJSON(t, scanURL(fx, "titogo")+"/grant", map[string]any{}, token); s != http.StatusOK {
30 t.Fatalf("scan grant = %d %v", s, o)
31 }
32 rec, _, err := objstore.Get(context.Background(), fx.rel, release.OpsAccount, "titogo")
33 if err != nil || rec == nil || rec.Provisioned == nil {
34 t.Fatalf("no provisioned record to read a bucket from: %v", err)
35 }
36 return fx, sc, appToken(t, fx, "titobot"), rec.Provisioned.Bucket
37}
38
39// getStatus asks the door about one key and decodes the answer.
40func getStatus(t *testing.T, fx *consoleFixture, tok, query string) (int, map[string]any) {
41 t.Helper()
42 status, _, body := rawReq(t, http.MethodGet, enqueueURL(fx, "titogo")+"?"+query, tok, "")
43 out := map[string]any{}
44 if body != "" {
45 if err := json.Unmarshal([]byte(body), &out); err != nil {
46 t.Fatalf("decode %q: %v", body, err)
47 }
48 }
49 return status, out
50}
51
52// getStatusSafe is getStatus for a NON-TEST goroutine. rawReq calls t.Fatal on
53// a transport error, and FailNow from any goroutine but the test's own is
54// undefined behaviour that go vet's testinggoroutine check exists to catch.
55func getStatusSafe(fx *consoleFixture, tok, query string) (map[string]any, error) {
56 req, err := http.NewRequest(http.MethodGet, enqueueURL(fx, "titogo")+"?"+query, nil)
57 if err != nil {
58 return nil, err
59 }
60 req.Header.Set("Authorization", "Bearer "+tok)
61 resp, err := http.DefaultClient.Do(req)
62 if err != nil {
63 return nil, err
64 }
65 defer resp.Body.Close()
66 raw, err := io.ReadAll(resp.Body)
67 if err != nil {
68 return nil, err
69 }
70 out := map[string]any{}
71 if len(raw) > 0 {
72 if err := json.Unmarshal(raw, &out); err != nil {
73 return nil, fmt.Errorf("decode %q: %w", raw, err)
74 }
75 }
76 return out, nil
77}
78
79// seedObject puts an object in the engine's world and returns its version, so
80// a test can stage a tag or a result against the same bytes.
81func seedObject(sc *objstore.MemScanner, bucket, key, etag string) string {
82 mod := time.Now().Truncate(time.Second)
83 sc.PutObject(bucket, key, etag, mod, 10)
84 return objstore.ScanObject{Key: key, ETag: etag, Modified: mod, Size: 10}.Version()
85}
86
87// TestStatusDoorReadsTagThenResultObject pins the ORDER, which is the whole of
88// §5.2's read rule: the object's own tag is the more recent and more
89// authoritative answer, and a result object exists only because a tag could
90// not be written.
91func TestStatusDoorReadsTagThenResultObject(t *testing.T) {
92 ctx := context.Background()
93 fx, sc, tok, bucket := statusArmed(t, "code-status-order")
94
95 // (a) a tag and nothing else.
96 vTagged := seedObject(sc, bucket, "uploads/tagged.pdf", "etag-t")
97 sc.Put(bucket, "uploads/tagged.pdf", vTagged, objstore.VerdictClean)
98 if status, out := getStatus(t, fx, tok, "key=uploads/tagged.pdf"); status != http.StatusOK || out["state"] != "clean" {
99 t.Fatalf("tagged = %d %v, want 200 clean", status, out)
100 }
101
102 // (b) a result object and no tag.
103 vResult := seedObject(sc, bucket, "uploads/untaggable.pdf", "etag-u")
104 if err := objstore.WriteScanResult(ctx, fx.rel, release.OpsAccount, "titogo", &objstore.ScanResult{
105 Key: "uploads/untaggable.pdf", Verdict: "infected", Version: vResult,
106 Engine: "clamav", Signature: "Eicar-Test", At: time.Now().UTC(),
107 }); err != nil {
108 t.Fatal(err)
109 }
110 status, out := getStatus(t, fx, tok, "key=uploads/untaggable.pdf")
111 if status != http.StatusOK || out["state"] != "infected" {
112 t.Fatalf("result-object read = %d %v, want 200 infected", status, out)
113 }
114 if out["engine"] != "clamav" || out["signature"] != "Eicar-Test" {
115 t.Errorf("provenance missing from a result-object answer: %v", out)
116 }
117 // The app must be told the verdict is NOT on the object: an infected
118 // object answered this way is not covered by the enforcement Deny, which
119 // matches on a tag that is not there.
120 if out["recorded"] != false {
121 t.Errorf("recorded = %#v, want JSON false — the app cannot tell this verdict is not enforceable", out["recorded"])
122 }
123
124 // (c) BOTH, disagreeing. The tag wins.
125 vBoth := seedObject(sc, bucket, "uploads/both.pdf", "etag-b")
126 sc.Put(bucket, "uploads/both.pdf", vBoth, objstore.VerdictClean)
127 if err := objstore.WriteScanResult(ctx, fx.rel, release.OpsAccount, "titogo", &objstore.ScanResult{
128 Key: "uploads/both.pdf", Verdict: "infected", Version: vBoth,
129 Engine: "clamav", At: time.Now().UTC(),
130 }); err != nil {
131 t.Fatal(err)
132 }
133 if status, out := getStatus(t, fx, tok, "key=uploads/both.pdf"); out["state"] != "clean" {
134 t.Fatalf("with both present = %d %v, want the TAG's answer (clean)", status, out)
135 }
136}
137
138// TestStatusDoorRefusesStaleResultObject is the laundering bug as a
139// correctness bug: v1 was judged, v2 was uploaded over it, and the recorded
140// answer is about bytes that are no longer there.
141func TestStatusDoorRefusesStaleResultObject(t *testing.T) {
142 ctx := context.Background()
143 fx, sc, tok, bucket := statusArmed(t, "code-status-stale")
144
145 if err := objstore.WriteScanResult(ctx, fx.rel, release.OpsAccount, "titogo", &objstore.ScanResult{
146 Key: "uploads/x.pdf", Verdict: "clean", Version: "etag-v1@2020-01-01T00:00:00Z",
147 Engine: "clamav", At: time.Now().UTC(),
148 }); err != nil {
149 t.Fatal(err)
150 }
151 // The object now holds DIFFERENT bytes.
152 seedObject(sc, bucket, "uploads/x.pdf", "etag-v2")
153
154 status, out := getStatus(t, fx, tok, "key=uploads/x.pdf")
155 if status != http.StatusOK {
156 t.Fatalf("status = %d %v", status, out)
157 }
158 if out["state"] != "pending" {
159 t.Fatalf("state = %v, want pending — a verdict about replaced bytes is not an answer about this object", out["state"])
160 }
161}
162
163// TestStatusDoorReportsFailedAndDenied: as themselves, never as pending.
164//
165// The landed TAG READER maps both back to unknown so the sweep retries them,
166// which is right as retry policy and wrong as an answer to a question. If this
167// door applied that rule, a failed scan would read as pending forever — the
168// drain deletes the item as handled, and nothing changes the answer until a
169// sweep happens to re-fail it.
170func TestStatusDoorReportsFailedAndDenied(t *testing.T) {
171 fx, sc, tok, bucket := statusArmed(t, "code-status-fd")
172
173 v := seedObject(sc, bucket, "uploads/failed.pdf", "etag-f")
174 sc.Put(bucket, "uploads/failed.pdf", v, objstore.VerdictFailed)
175 if _, out := getStatus(t, fx, tok, "key=uploads/failed.pdf"); out["state"] != "failed" {
176 t.Errorf("state = %v, want failed", out["state"])
177 }
178
179 seedObject(sc, bucket, "uploads/denied.pdf", "etag-d")
180 sc.DenyHead(bucket, "uploads/denied.pdf")
181 if _, out := getStatus(t, fx, tok, "key=uploads/denied.pdf"); out["state"] != "denied" {
182 t.Errorf("state = %v, want denied", out["state"])
183 }
184
185 // And skipped is not clean. An app treating it as success reproduces the
186 // dishonesty the two-number rule exists to prevent.
187 vs := seedObject(sc, bucket, "uploads/huge.bin", "etag-h")
188 sc.Put(bucket, "uploads/huge.bin", vs, objstore.VerdictSkipped)
189 if _, out := getStatus(t, fx, tok, "key=uploads/huge.bin"); out["state"] != "skipped" {
190 t.Errorf("state = %v, want skipped", out["state"])
191 }
192}
193
194// TestStatusDoorGoneForMissingObject: an object that is not there is `gone`,
195// which is distinct from both `pending` and `clean`.
196func TestStatusDoorGoneForMissingObject(t *testing.T) {
197 fx, _, tok, _ := statusArmed(t, "code-status-gone")
198
199 status, out := getStatus(t, fx, tok, "key=uploads/never-existed.pdf")
200 if status != http.StatusOK || out["state"] != "gone" {
201 t.Fatalf("missing object = %d %v, want 200 gone", status, out)
202 }
203}
204
205// TestStatusDoorPendingForAnUnjudgedObject is the positive control for
206// everything above: without it, a door that answered `pending` to absolutely
207// everything would pass the stale test and the long-poll tests.
208func TestStatusDoorPendingForAnUnjudgedObject(t *testing.T) {
209 fx, sc, tok, bucket := statusArmed(t, "code-status-pending")
210 seedObject(sc, bucket, "uploads/new.pdf", "etag-n")
211
212 if _, out := getStatus(t, fx, tok, "key=uploads/new.pdf"); out["state"] != "pending" {
213 t.Fatalf("state = %v, want pending", out["state"])
214 }
215}
216
217// TestStatusDoorSharesTheConsentChain: the same table the enqueue door reads,
218// so the two doors cannot answer one refusal differently — a disagreement is
219// itself something an app could conclude from.
220func TestStatusDoorSharesTheConsentChain(t *testing.T) {
221 fx, _, member, _ := storeArmed(t, "code-status-consent")
222 grantStore(t, fx, member)
223 fx.srv.cfg.StoreScanner = objstore.NewMemScanner()
224 enableDeploymentScanning(t, fx)
225 tok := appToken(t, fx, "bot")
226
227 // ARMED TO FAIL ON ANY READ. MemScanner counts Scans, not Status calls, so
228 // "no bytes were read" cannot be asserted by counting — but an engine that
229 // errors on Status turns any read into a 502, which a 409 proves did not
230 // happen. That is what makes this a test of ORDER and not just of wording.
231 sc := fx.srv.cfg.StoreScanner.(*objstore.MemScanner)
232 sc.Fail("Status", errors.New("the engine must not have been consulted"))
233
234 status, out := getStatus(t, fx, tok, "key=uploads/x.pdf")
235 if status != http.StatusConflict || out["reason"] != "not_requested" {
236 t.Fatalf("status door = %d %v, want the enqueue door's 409 not_requested", status, out)
237 }
238 if out["state"] != "unavailable" {
239 t.Errorf("state = %v, want unavailable", out["state"])
240 }
241
242 // And the reversible refusal, which is a different status code — one row
243 // proved nothing about the mapping being shared, only about one entry.
244 requestScanning(t, fx, member, false)
245 fx.srv.cfg.StoreOperators = []string{"alice@keymail.dev"}
246 if s, o := postJSON(t, scanURL(fx, "titogo")+"/grant", map[string]any{}, member); s != http.StatusOK {
247 t.Fatalf("scan grant = %d %v", s, o)
248 }
249 setDeploymentScanning(t, fx, false)
250 status, out = getStatus(t, fx, tok, "key=uploads/x.pdf")
251 if status != http.StatusServiceUnavailable || out["reason"] != "disabled" {
252 t.Fatalf("disabled = %d %v, want 503 disabled", status, out)
253 }
254}
255
256// TestStatusDoorNeedsAKey and rejects a malformed wait.
257func TestStatusDoorArgumentErrors(t *testing.T) {
258 fx, _, tok, _ := statusArmed(t, "code-status-args")
259
260 if status, _ := getStatus(t, fx, tok, ""); status != http.StatusBadRequest {
261 t.Errorf("no key = %d, want 400", status)
262 }
263 if status, _ := getStatus(t, fx, tok, "key=uploads/x.pdf&wait=soon"); status != http.StatusBadRequest {
264 t.Errorf("malformed wait = %d, want 400", status)
265 }
266 if status, _ := getStatus(t, fx, tok, "key=uploads/x.pdf&wait=-5s"); status != http.StatusBadRequest {
267 t.Errorf("negative wait = %d, want 400", status)
268 }
269}
270
271// TestScanWaitForClamps: an over-long wait is the client asking for the
272// longest it can have, not an error to special-case.
273func TestScanWaitForClamps(t *testing.T) {
274 for _, tc := range []struct {
275 in string
276 want time.Duration
277 bad bool
278 }{
279 {in: "", want: 0},
280 {in: "5s", want: 5 * time.Second},
281 {in: "30s", want: scanWaitMax},
282 {in: "5m", want: scanWaitMax},
283 {in: "24h", want: scanWaitMax},
284 {in: "soon", bad: true},
285 {in: "-1s", bad: true},
286 } {
287 got, err := scanWaitFor(tc.in)
288 if tc.bad {
289 if err == nil {
290 t.Errorf("scanWaitFor(%q) = %v, want an error", tc.in, got)
291 }
292 continue
293 }
294 if err != nil {
295 t.Errorf("scanWaitFor(%q): %v", tc.in, err)
296 continue
297 }
298 if got != tc.want {
299 t.Errorf("scanWaitFor(%q) = %v, want %v", tc.in, got, tc.want)
300 }
301 }
302}
303
304// TestLongPollWakesOnDrain: a request parked on `wait` returns as soon as the
305// drain records a verdict, rather than sitting out its window.
306//
307// The wait is long and the assertion is that the answer arrives EARLY, which
308// is the only formulation that fails if the wake is never delivered — a test
309// that merely checked the final answer would pass against a door that always
310// slept the full duration.
311func TestLongPollWakesOnDrain(t *testing.T) {
312 ctx := context.Background()
313 fx, sc, tok, bucket := statusArmed(t, "code-status-poll")
314 seedObject(sc, bucket, "uploads/x.pdf", "etag-x")
315 if _, err := objstore.Enqueue(ctx, fx.rel, fx.srv.scanQueue, release.OpsAccount, "titogo",
316 &objstore.QueueItem{Key: "uploads/x.pdf", By: "test"}, time.Now()); err != nil {
317 t.Fatal(err)
318 }
319
320 type reply struct {
321 out map[string]any
322 took time.Duration
323 state string
324 }
325 done := make(chan reply, 1)
326 errs := make(chan error, 1)
327 go func() {
328 start := time.Now()
329 out, err := getStatusSafe(fx, tok, "key=uploads/x.pdf&wait=25s")
330 if err != nil {
331 errs <- err
332 return
333 }
334 st, _ := out["state"].(string)
335 done <- reply{out: out, took: time.Since(start), state: st}
336 }()
337
338 // Give the request time to park before the drain runs, so the wake is
339 // what returns it rather than the first read.
340 time.Sleep(150 * time.Millisecond)
341 if err := fx.srv.scanDrainTick(ctx); err != nil {
342 t.Fatal(err)
343 }
344
345 select {
346 case got := <-done:
347 if got.state != "clean" {
348 t.Fatalf("state = %v (%v), want clean", got.state, got.out)
349 }
350 if got.took > 20*time.Second {
351 t.Errorf("took %v against a 25s wait — it sat out the window rather than being woken", got.took)
352 }
353 case err := <-errs:
354 t.Fatalf("long-poll request: %v", err)
355 case <-time.After(20 * time.Second):
356 t.Fatal("the parked request was never woken by the drain")
357 }
358}
359
360// TestLongPollReturnsPendingWhenNothingHappens: the window is a ceiling, not a
361// promise, and it must end.
362func TestLongPollReturnsPendingWhenNothingHappens(t *testing.T) {
363 fx, sc, tok, bucket := statusArmed(t, "code-status-timeout")
364 seedObject(sc, bucket, "uploads/quiet.pdf", "etag-q")
365
366 start := time.Now()
367 status, out := getStatus(t, fx, tok, "key=uploads/quiet.pdf&wait=300ms")
368 if status != http.StatusOK || out["state"] != "pending" {
369 t.Fatalf("quiet wait = %d %v, want 200 pending", status, out)
370 }
371 if took := time.Since(start); took < 250*time.Millisecond {
372 t.Errorf("returned after %v — it did not wait the window it was given", took)
373 }
374}
375
376// TestLongPollCapsWaiters covers BOTH caps, and the per-app one is not implied
377// by the global one: without it a single tenant fills the global budget and
378// every other tenant's wait degrades to polling.
379func TestLongPollCapsWaiters(t *testing.T) {
380 fx, _, _, _ := statusArmed(t, "code-status-caps")
381
382 // Per app: one app's own keys, up to its cap and then no further.
383 ref := objstore.AppRef{Account: release.OpsAccount, App: "titogo"}
384 var release1 []func()
385 for i := 0; i < scanWaitersPerApp; i++ {
386 _, rel, ok := fx.srv.scanWait(ref, string(rune('a'+i%26))+"/x")
387 if !ok {
388 t.Fatalf("refused waiter %d, below the per-app cap of %d", i, scanWaitersPerApp)
389 }
390 release1 = append(release1, rel)
391 }
392 if _, _, ok := fx.srv.scanWait(ref, "one/too/many"); ok {
393 t.Errorf("parked a waiter past the per-app cap of %d", scanWaitersPerApp)
394 }
395 // A DIFFERENT app is unaffected — which is the whole point of the per-app
396 // cap existing beside the global one.
397 other := objstore.AppRef{Account: release.OpsAccount, App: "otherapp"}
398 if _, rel, ok := fx.srv.scanWait(other, "x"); !ok {
399 t.Errorf("one app at its cap blocked another app entirely")
400 } else {
401 rel()
402 }
403 for _, rel := range release1 {
404 rel()
405 }
406 // Releasing gives the capacity back rather than burning it.
407 if _, rel, ok := fx.srv.scanWait(ref, "after/release"); !ok {
408 t.Error("capacity was not returned when the waiters were released")
409 } else {
410 rel()
411 }
412
413 // Global: enough distinct apps that no per-app cap is ever reached.
414 var release2 []func()
415 for i := 0; ; i++ {
416 app := "app" + string(rune('A'+i%26)) + string(rune('A'+(i/26)%26))
417 r := objstore.AppRef{Account: release.OpsAccount, App: app}
418 ch, rel, ok := fx.srv.scanWait(r, "k")
419 if !ok {
420 break
421 }
422 _ = ch
423 release2 = append(release2, rel)
424 if i > scanWaitersGlobal+8 {
425 t.Fatalf("parked %d waiters with a global cap of %d", i, scanWaitersGlobal)
426 }
427 }
428 if len(release2) != scanWaitersGlobal {
429 t.Errorf("global cap admitted %d waiters, want %d", len(release2), scanWaitersGlobal)
430 }
431 for _, rel := range release2 {
432 rel()
433 }
434}
435
436// TestReleaseIsIdempotent: the door defers the release and a caller may call it
437// early. A second call that decremented again would leak capacity downwards
438// until the console stopped parking anything at all.
439func TestReleaseIsIdempotent(t *testing.T) {
440 fx, _, _, _ := statusArmed(t, "code-status-idem")
441 ref := objstore.AppRef{Account: release.OpsAccount, App: "titogo"}
442
443 _, rel, ok := fx.srv.scanWait(ref, "k")
444 if !ok {
445 t.Fatal("idle console refused a waiter")
446 }
447 rel()
448 rel()
449 rel()
450
451 fx.srv.scanWaits.mu.Lock()
452 total := fx.srv.scanWaits.total
453 fx.srv.scanWaits.mu.Unlock()
454 if total != 0 {
455 t.Errorf("total = %d after releasing one waiter three times, want 0", total)
456 }
457}
458
459// TestStatusDoorAnswersWhenTheWaitCapIsFull: over the cap nothing is refused.
460// The read still happens and still answers truthfully; only the waiting is
461// skipped, so a full console degrades to polling rather than to errors.
462func TestStatusDoorAnswersWhenTheWaitCapIsFull(t *testing.T) {
463 fx, sc, tok, bucket := statusArmed(t, "code-status-full")
464 // PENDING, not clean. The first version staged a CLEAN object, so the door
465 // answered on its first read and returned before the wait mattered at all
466 // — it passed against a door that ignored the caps entirely AND against
467 // one that parked forever when refused. The object has to be one the door
468 // would WANT to wait for.
469 seedObject(sc, bucket, "uploads/x.pdf", "etag-x")
470
471 ref := objstore.AppRef{Account: release.OpsAccount, App: "titogo"}
472 var rels []func()
473 for i := 0; i < scanWaitersPerApp; i++ {
474 if _, rel, ok := fx.srv.scanWait(ref, "filler/"+string(rune('a'+i%26))); ok {
475 rels = append(rels, rel)
476 }
477 }
478 defer func() {
479 for _, rel := range rels {
480 rel()
481 }
482 }()
483
484 start := time.Now()
485 status, out := getStatus(t, fx, tok, "key=uploads/x.pdf&wait=10s")
486 if status != http.StatusOK || out["state"] != "pending" {
487 t.Fatalf("over the cap = %d %v, want the truthful 200 pending", status, out)
488 }
489 if took := time.Since(start); took > 3*time.Second {
490 t.Fatalf("took %v against a 10s wait — a request that cannot park must answer at once, not park anyway", took)
491 }
492
493 // THE CONTROL, without which "answered immediately" proves nothing: under
494 // the cap, the same request on the same pending object waits.
495 for _, rel := range rels {
496 rel()
497 }
498 rels = nil
499 start = time.Now()
500 if _, out := getStatus(t, fx, tok, "key=uploads/x.pdf&wait=400ms"); out["state"] != "pending" {
501 t.Fatalf("under the cap = %v, want pending", out)
502 }
503 if took := time.Since(start); took < 350*time.Millisecond {
504 t.Errorf("under the cap it returned after %v — it did not park, so the test above says nothing", took)
505 }
506}
507
508// TestLongPollSurvivesADrainDuringItsFirstRead runs a whole drain INSIDE the
509// door's first Status call and requires a prompt, correct answer.
510//
511// WHAT IT DOES NOT PROVE, stated because the obvious reading of it is wrong: it
512// does not pin the register-before-read ORDER. That was the intent, and a
513// mutation that moves registration after the first read SURVIVES it. The
514// reason is that the hook fires at the top of Status, so by the time the read
515// returns the drain has already tagged the object and the door answers "clean"
516// from the read itself — in both orderings, without the wake mattering at all.
517//
518// The ordering therefore remains unasserted, and the comment on the door says
519// so. What this does pin is that a drain landing mid-read cannot make the door
520// lose the answer or hang, which is worth having on its own.
521func TestLongPollSurvivesADrainDuringItsFirstRead(t *testing.T) {
522 ctx := context.Background()
523 fx, sc, tok, bucket := statusArmed(t, "code-status-order2")
524 seedObject(sc, bucket, "uploads/x.pdf", "etag-x")
525 if _, err := objstore.Enqueue(ctx, fx.rel, fx.srv.scanQueue, release.OpsAccount, "titogo",
526 &objstore.QueueItem{Key: "uploads/x.pdf", By: "test"}, time.Now()); err != nil {
527 t.Fatal(err)
528 }
529
530 // FIRE ONCE, and with a compare-and-swap rather than sync.Once: the drain
531 // this hook starts calls Status itself, so the hook re-enters — and
532 // Once.Do is not reentrant, it DEADLOCKS the second caller against the
533 // first. A CAS lets the inner call see "already fired" and return.
534 var fired atomic.Bool
535 sc.OnStatus(func() {
536 if !fired.CompareAndSwap(false, true) {
537 return
538 }
539 if err := fx.srv.scanDrainTick(ctx); err != nil {
540 t.Errorf("drain inside the door's read: %v", err)
541 }
542 })
543
544 start := time.Now()
545 status, out := getStatus(t, fx, tok, "key=uploads/x.pdf&wait=20s")
546 took := time.Since(start)
547 if status != http.StatusOK {
548 t.Fatalf("status = %d %v", status, out)
549 }
550 if out["state"] != "clean" {
551 t.Fatalf("state = %v, want clean — the drain ran during the first read", out["state"])
552 }
553 if took > 15*time.Second {
554 t.Errorf("took %v against a 20s wait — a drain during the read must not cost the whole window", took)
555 }
556}
557