k8s.io/apiserver@v0.31.1/pkg/server/filters/priority-and-fairness_test.go (about) 1 /* 2 Copyright 2016 The Kubernetes Authors. 3 4 Licensed under the Apache License, Version 2.0 (the "License"); 5 you may not use this file except in compliance with the License. 6 You may obtain a copy of the License at 7 8 http://www.apache.org/licenses/LICENSE-2.0 9 10 Unless required by applicable law or agreed to in writing, software 11 distributed under the License is distributed on an "AS IS" BASIS, 12 WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 See the License for the specific language governing permissions and 14 limitations under the License. 15 */ 16 17 package filters 18 19 import ( 20 "context" 21 "fmt" 22 "net/http" 23 "net/http/httptest" 24 "net/url" 25 "os" 26 "reflect" 27 "strings" 28 "sync" 29 "testing" 30 "time" 31 32 flowcontrol "k8s.io/api/flowcontrol/v1" 33 metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" 34 "k8s.io/apimachinery/pkg/runtime" 35 "k8s.io/apimachinery/pkg/types" 36 "k8s.io/apimachinery/pkg/util/sets" 37 "k8s.io/apimachinery/pkg/util/wait" 38 "k8s.io/apiserver/pkg/apis/flowcontrol/bootstrap" 39 "k8s.io/apiserver/pkg/authentication/user" 40 apifilters "k8s.io/apiserver/pkg/endpoints/filters" 41 epmetrics "k8s.io/apiserver/pkg/endpoints/metrics" 42 apirequest "k8s.io/apiserver/pkg/endpoints/request" 43 "k8s.io/apiserver/pkg/server/mux" 44 utilflowcontrol "k8s.io/apiserver/pkg/util/flowcontrol" 45 fq "k8s.io/apiserver/pkg/util/flowcontrol/fairqueuing" 46 fcmetrics "k8s.io/apiserver/pkg/util/flowcontrol/metrics" 47 fcrequest "k8s.io/apiserver/pkg/util/flowcontrol/request" 48 "k8s.io/client-go/informers" 49 clientset "k8s.io/client-go/kubernetes" 50 "k8s.io/client-go/kubernetes/fake" 51 "k8s.io/component-base/metrics/legacyregistry" 52 "k8s.io/component-base/metrics/testutil" 53 "k8s.io/klog/v2" 54 clocktesting "k8s.io/utils/clock/testing" 55 "k8s.io/utils/ptr" 56 57 "github.com/google/go-cmp/cmp" 58 ) 59 60 func TestMain(m *testing.M) { 61 klog.InitFlags(nil) 62 os.Exit(m.Run()) 63 } 64 65 type mockDecision int 66 67 const ( 68 decisionNoQueuingExecute mockDecision = iota 69 decisionQueuingExecute 70 decisionCancelWait 71 decisionReject 72 decisionSkipFilter 73 ) 74 75 var defaultRequestWorkEstimator = func(req *http.Request, fsName, plName string) fcrequest.WorkEstimate { 76 return fcrequest.WorkEstimate{InitialSeats: 1} 77 } 78 79 type fakeApfFilter struct { 80 mockDecision mockDecision 81 postEnqueue func() 82 postDequeue func() 83 84 utilflowcontrol.WatchTracker 85 utilflowcontrol.MaxSeatsTracker 86 } 87 88 func (t fakeApfFilter) Handle(ctx context.Context, 89 requestDigest utilflowcontrol.RequestDigest, 90 noteFn func(fs *flowcontrol.FlowSchema, pl *flowcontrol.PriorityLevelConfiguration, flowDistinguisher string), 91 workEstimator func() fcrequest.WorkEstimate, 92 queueNoteFn fq.QueueNoteFn, 93 execFn func(), 94 ) { 95 if t.mockDecision == decisionSkipFilter { 96 panic("Handle should not be invoked") 97 } 98 noteFn(bootstrap.SuggestedFlowSchemaGlobalDefault, bootstrap.SuggestedPriorityLevelConfigurationGlobalDefault, requestDigest.User.GetName()) 99 switch t.mockDecision { 100 case decisionNoQueuingExecute: 101 execFn() 102 case decisionQueuingExecute: 103 queueNoteFn(true) 104 t.postEnqueue() 105 queueNoteFn(false) 106 t.postDequeue() 107 execFn() 108 case decisionCancelWait: 109 queueNoteFn(true) 110 t.postEnqueue() 111 queueNoteFn(false) 112 t.postDequeue() 113 case decisionReject: 114 return 115 } 116 } 117 118 func (t fakeApfFilter) Run(stopCh <-chan struct{}) error { 119 return nil 120 } 121 122 func (t fakeApfFilter) Install(c *mux.PathRecorderMux) { 123 } 124 125 func newApfServerWithSingleRequest(t *testing.T, decision mockDecision) *httptest.Server { 126 onExecuteFunc := func() { 127 if decision == decisionCancelWait { 128 t.Errorf("execute should not be invoked") 129 } 130 // atomicReadOnlyExecuting can be either 0 or 1 as we test one request at a time. 131 if decision != decisionSkipFilter && atomicReadOnlyExecuting != 1 { 132 t.Errorf("Wanted %d requests executing, got %d", 1, atomicReadOnlyExecuting) 133 } 134 } 135 postExecuteFunc := func() {} 136 // atomicReadOnlyWaiting can be either 0 or 1 as we test one request at a time. 137 postEnqueueFunc := func() { 138 if atomicReadOnlyWaiting != 1 { 139 t.Errorf("Wanted %d requests in queue, got %d", 1, atomicReadOnlyWaiting) 140 } 141 } 142 postDequeueFunc := func() { 143 if atomicReadOnlyWaiting != 0 { 144 t.Errorf("Wanted %d requests in queue, got %d", 0, atomicReadOnlyWaiting) 145 } 146 } 147 return newApfServerWithHooks(t, decision, onExecuteFunc, postExecuteFunc, postEnqueueFunc, postDequeueFunc) 148 } 149 150 func newApfServerWithHooks(t *testing.T, decision mockDecision, onExecute, postExecute, postEnqueue, postDequeue func()) *httptest.Server { 151 fakeFilter := fakeApfFilter{ 152 mockDecision: decision, 153 postEnqueue: postEnqueue, 154 postDequeue: postDequeue, 155 WatchTracker: utilflowcontrol.NewWatchTracker(), 156 MaxSeatsTracker: utilflowcontrol.NewMaxSeatsTracker(), 157 } 158 return newApfServerWithFilter(t, fakeFilter, time.Minute/4, onExecute, postExecute) 159 } 160 161 func newApfServerWithFilter(t *testing.T, flowControlFilter utilflowcontrol.Interface, defaultWaitLimit time.Duration, onExecute, postExecute func()) *httptest.Server { 162 epmetrics.Register() 163 fcmetrics.Register() 164 apfServer := httptest.NewServer(newApfHandlerWithFilter(t, flowControlFilter, defaultWaitLimit, onExecute, postExecute)) 165 return apfServer 166 } 167 168 func newApfHandlerWithFilter(t *testing.T, flowControlFilter utilflowcontrol.Interface, defaultWaitLimit time.Duration, onExecute, postExecute func()) http.Handler { 169 requestInfoFactory := &apirequest.RequestInfoFactory{APIPrefixes: sets.NewString("apis", "api"), GrouplessAPIPrefixes: sets.NewString("api")} 170 longRunningRequestCheck := BasicLongRunningRequestCheck(sets.NewString("watch"), sets.NewString("proxy")) 171 172 apfHandler := WithPriorityAndFairness(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 173 onExecute() 174 }), longRunningRequestCheck, flowControlFilter, defaultRequestWorkEstimator, defaultWaitLimit) 175 176 handler := apifilters.WithRequestInfo(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 177 r = r.WithContext(apirequest.WithUser(r.Context(), &user.DefaultInfo{ 178 Groups: []string{user.AllUnauthenticated}, 179 })) 180 apfHandler.ServeHTTP(w, r) 181 postExecute() 182 if atomicReadOnlyExecuting != 0 { 183 t.Errorf("Wanted %d requests executing, got %d", 0, atomicReadOnlyExecuting) 184 } 185 }), requestInfoFactory) 186 187 return handler 188 } 189 190 func TestApfSkipLongRunningRequest(t *testing.T) { 191 server := newApfServerWithSingleRequest(t, decisionSkipFilter) 192 defer server.Close() 193 194 ctx, cancel := context.WithCancel(context.Background()) 195 defer cancel() 196 StartPriorityAndFairnessWatermarkMaintenance(ctx.Done()) 197 198 // send a watch request to test skipping long running request 199 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/foos/foo/proxy", server.URL), http.StatusOK); err != nil { 200 // request should not be rejected 201 t.Error(err) 202 } 203 } 204 205 func TestApfRejectRequest(t *testing.T) { 206 server := newApfServerWithSingleRequest(t, decisionReject) 207 defer server.Close() 208 209 ctx, cancel := context.WithCancel(context.Background()) 210 defer cancel() 211 StartPriorityAndFairnessWatermarkMaintenance(ctx.Done()) 212 213 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default", server.URL), http.StatusTooManyRequests); err != nil { 214 t.Error(err) 215 } 216 217 checkForExpectedMetrics(t, []string{ 218 "apiserver_request_terminations_total", 219 "apiserver_request_total", 220 }) 221 } 222 223 func TestApfExemptRequest(t *testing.T) { 224 server := newApfServerWithSingleRequest(t, decisionNoQueuingExecute) 225 defer server.Close() 226 227 ctx, cancel := context.WithCancel(context.Background()) 228 defer cancel() 229 StartPriorityAndFairnessWatermarkMaintenance(ctx.Done()) 230 231 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default", server.URL), http.StatusOK); err != nil { 232 t.Error(err) 233 } 234 235 checkForExpectedMetrics(t, []string{ 236 "apiserver_current_inflight_requests", 237 "apiserver_flowcontrol_read_vs_write_current_requests", 238 }) 239 } 240 241 func TestApfExecuteRequest(t *testing.T) { 242 server := newApfServerWithSingleRequest(t, decisionQueuingExecute) 243 defer server.Close() 244 245 ctx, cancel := context.WithCancel(context.Background()) 246 defer cancel() 247 StartPriorityAndFairnessWatermarkMaintenance(ctx.Done()) 248 249 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default", server.URL), http.StatusOK); err != nil { 250 t.Error(err) 251 } 252 253 checkForExpectedMetrics(t, []string{ 254 "apiserver_current_inflight_requests", 255 "apiserver_current_inqueue_requests", 256 "apiserver_flowcontrol_read_vs_write_current_requests", 257 }) 258 } 259 260 func TestApfExecuteMultipleRequests(t *testing.T) { 261 concurrentRequests := 5 262 preStartExecute, postStartExecute := &sync.WaitGroup{}, &sync.WaitGroup{} 263 preEnqueue, postEnqueue := &sync.WaitGroup{}, &sync.WaitGroup{} 264 preDequeue, postDequeue := &sync.WaitGroup{}, &sync.WaitGroup{} 265 finishExecute := &sync.WaitGroup{} 266 for _, wg := range []*sync.WaitGroup{preStartExecute, postStartExecute, preEnqueue, postEnqueue, preDequeue, postDequeue, finishExecute} { 267 wg.Add(concurrentRequests) 268 } 269 270 onExecuteFunc := func() { 271 preStartExecute.Done() 272 preStartExecute.Wait() 273 if int(atomicReadOnlyExecuting) != concurrentRequests { 274 t.Errorf("Wanted %d requests executing, got %d", concurrentRequests, atomicReadOnlyExecuting) 275 } 276 postStartExecute.Done() 277 postStartExecute.Wait() 278 } 279 280 postEnqueueFunc := func() { 281 preEnqueue.Done() 282 preEnqueue.Wait() 283 if int(atomicReadOnlyWaiting) != concurrentRequests { 284 t.Errorf("Wanted %d requests in queue, got %d", 1, atomicReadOnlyWaiting) 285 286 } 287 postEnqueue.Done() 288 postEnqueue.Wait() 289 } 290 291 postDequeueFunc := func() { 292 preDequeue.Done() 293 preDequeue.Wait() 294 if atomicReadOnlyWaiting != 0 { 295 t.Errorf("Wanted %d requests in queue, got %d", 0, atomicReadOnlyWaiting) 296 } 297 postDequeue.Done() 298 postDequeue.Wait() 299 } 300 301 postExecuteFunc := func() { 302 finishExecute.Done() 303 finishExecute.Wait() 304 } 305 306 server := newApfServerWithHooks(t, decisionQueuingExecute, onExecuteFunc, postExecuteFunc, postEnqueueFunc, postDequeueFunc) 307 defer server.Close() 308 309 ctx, cancel := context.WithCancel(context.Background()) 310 defer cancel() 311 StartPriorityAndFairnessWatermarkMaintenance(ctx.Done()) 312 313 var wg sync.WaitGroup 314 wg.Add(concurrentRequests) 315 for i := 0; i < concurrentRequests; i++ { 316 go func() { 317 defer wg.Done() 318 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default", server.URL), http.StatusOK); err != nil { 319 t.Error(err) 320 } 321 }() 322 } 323 wg.Wait() 324 325 checkForExpectedMetrics(t, []string{ 326 "apiserver_current_inflight_requests", 327 "apiserver_current_inqueue_requests", 328 "apiserver_flowcontrol_read_vs_write_current_requests", 329 }) 330 } 331 332 func TestApfCancelWaitRequest(t *testing.T) { 333 server := newApfServerWithSingleRequest(t, decisionCancelWait) 334 defer server.Close() 335 336 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default", server.URL), http.StatusTooManyRequests); err != nil { 337 t.Error(err) 338 } 339 340 checkForExpectedMetrics(t, []string{ 341 "apiserver_current_inflight_requests", 342 "apiserver_request_terminations_total", 343 "apiserver_request_total", 344 }) 345 } 346 347 type fakeWatchApfFilter struct { 348 lock sync.Mutex 349 inflight int 350 capacity int 351 352 postExecutePanic bool 353 preExecutePanic bool 354 355 utilflowcontrol.WatchTracker 356 utilflowcontrol.MaxSeatsTracker 357 } 358 359 func newFakeWatchApfFilter(capacity int) *fakeWatchApfFilter { 360 return &fakeWatchApfFilter{ 361 capacity: capacity, 362 WatchTracker: utilflowcontrol.NewWatchTracker(), 363 MaxSeatsTracker: utilflowcontrol.NewMaxSeatsTracker(), 364 } 365 } 366 367 func (f *fakeWatchApfFilter) Handle(ctx context.Context, 368 requestDigest utilflowcontrol.RequestDigest, 369 noteFn func(fs *flowcontrol.FlowSchema, pl *flowcontrol.PriorityLevelConfiguration, flowDistinguisher string), 370 _ func() fcrequest.WorkEstimate, 371 _ fq.QueueNoteFn, 372 execFn func(), 373 ) { 374 noteFn(bootstrap.SuggestedFlowSchemaGlobalDefault, bootstrap.SuggestedPriorityLevelConfigurationGlobalDefault, requestDigest.User.GetName()) 375 canExecute := false 376 func() { 377 f.lock.Lock() 378 defer f.lock.Unlock() 379 if f.inflight < f.capacity { 380 f.inflight++ 381 canExecute = true 382 } 383 }() 384 if !canExecute { 385 return 386 } 387 388 if f.preExecutePanic { 389 panic("pre-exec-panic") 390 } 391 execFn() 392 if f.postExecutePanic { 393 panic("post-exec-panic") 394 } 395 396 f.lock.Lock() 397 defer f.lock.Unlock() 398 f.inflight-- 399 } 400 401 func (f *fakeWatchApfFilter) Run(stopCh <-chan struct{}) error { 402 return nil 403 } 404 405 func (t *fakeWatchApfFilter) Install(c *mux.PathRecorderMux) { 406 } 407 408 func (f *fakeWatchApfFilter) wait() error { 409 return wait.Poll(100*time.Millisecond, wait.ForeverTestTimeout, func() (bool, error) { 410 f.lock.Lock() 411 defer f.lock.Unlock() 412 return f.inflight == 0, nil 413 }) 414 } 415 416 func TestApfExecuteWatchRequestsWithInitializationSignal(t *testing.T) { 417 signalsLock := sync.Mutex{} 418 signals := []utilflowcontrol.InitializationSignal{} 419 sendSignals := func() { 420 signalsLock.Lock() 421 defer signalsLock.Unlock() 422 for i := range signals { 423 signals[i].Signal() 424 } 425 signals = signals[:0] 426 } 427 428 newInitializationSignal = func() utilflowcontrol.InitializationSignal { 429 signalsLock.Lock() 430 defer signalsLock.Unlock() 431 signal := utilflowcontrol.NewInitializationSignal() 432 signals = append(signals, signal) 433 return signal 434 } 435 defer func() { 436 newInitializationSignal = utilflowcontrol.NewInitializationSignal 437 }() 438 439 // We test if initialization after receiving initialization signal the 440 // new requests will be allowed to run by: 441 // - sending N requests that will occupy the whole capacity 442 // - sending initialiation signals for them 443 // - ensuring that number of inflight requests will get to zero 444 concurrentRequests := 5 445 firstRunning := sync.WaitGroup{} 446 firstRunning.Add(concurrentRequests) 447 allRunning := sync.WaitGroup{} 448 allRunning.Add(2 * concurrentRequests) 449 450 fakeFilter := newFakeWatchApfFilter(concurrentRequests) 451 452 onExecuteFunc := func() { 453 firstRunning.Done() 454 455 fakeFilter.wait() 456 457 allRunning.Done() 458 allRunning.Wait() 459 } 460 461 postExecuteFunc := func() {} 462 463 server := newApfServerWithFilter(t, fakeFilter, time.Minute/4, onExecuteFunc, postExecuteFunc) 464 defer server.Close() 465 466 var wg sync.WaitGroup 467 wg.Add(2 * concurrentRequests) 468 for i := 0; i < concurrentRequests; i++ { 469 go func() { 470 defer wg.Done() 471 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusOK); err != nil { 472 t.Error(err) 473 } 474 }() 475 } 476 477 firstRunning.Wait() 478 sendSignals() 479 fakeFilter.wait() 480 firstRunning.Add(concurrentRequests) 481 482 for i := 0; i < concurrentRequests; i++ { 483 go func() { 484 defer wg.Done() 485 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusOK); err != nil { 486 t.Error(err) 487 } 488 }() 489 } 490 firstRunning.Wait() 491 sendSignals() 492 wg.Wait() 493 } 494 495 func TestApfRejectWatchRequestsWithInitializationSignal(t *testing.T) { 496 fakeFilter := newFakeWatchApfFilter(0) 497 498 onExecuteFunc := func() { 499 t.Errorf("Request unexepectedly executing") 500 } 501 postExecuteFunc := func() {} 502 503 server := newApfServerWithFilter(t, fakeFilter, time.Minute/4, onExecuteFunc, postExecuteFunc) 504 defer server.Close() 505 506 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusTooManyRequests); err != nil { 507 t.Error(err) 508 } 509 } 510 511 func TestApfWatchPanic(t *testing.T) { 512 epmetrics.Register() 513 fcmetrics.Register() 514 515 fakeFilter := newFakeWatchApfFilter(1) 516 517 onExecuteFunc := func() { 518 panic("test panic") 519 } 520 postExecuteFunc := func() {} 521 522 apfHandler := newApfHandlerWithFilter(t, fakeFilter, time.Minute/4, onExecuteFunc, postExecuteFunc) 523 handler := func(w http.ResponseWriter, r *http.Request) { 524 defer func() { 525 if err := recover(); err == nil { 526 t.Errorf("expected panic, got %v", err) 527 } 528 }() 529 apfHandler.ServeHTTP(w, r) 530 } 531 server := httptest.NewServer(http.HandlerFunc(handler)) 532 defer server.Close() 533 534 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusOK); err != nil { 535 t.Errorf("unexpected error: %v", err) 536 } 537 } 538 539 func TestApfWatchHandlePanic(t *testing.T) { 540 epmetrics.Register() 541 fcmetrics.Register() 542 preExecutePanicingFilter := newFakeWatchApfFilter(1) 543 preExecutePanicingFilter.preExecutePanic = true 544 545 postExecutePanicingFilter := newFakeWatchApfFilter(1) 546 postExecutePanicingFilter.postExecutePanic = true 547 548 testCases := []struct { 549 name string 550 filter *fakeWatchApfFilter 551 }{ 552 { 553 name: "pre-execute panic", 554 filter: preExecutePanicingFilter, 555 }, 556 { 557 name: "post-execute panic", 558 filter: postExecutePanicingFilter, 559 }, 560 } 561 562 onExecuteFunc := func() { 563 time.Sleep(5 * time.Second) 564 } 565 postExecuteFunc := func() {} 566 567 for _, test := range testCases { 568 t.Run(test.name, func(t *testing.T) { 569 apfHandler := newApfHandlerWithFilter(t, test.filter, time.Minute/4, onExecuteFunc, postExecuteFunc) 570 handler := func(w http.ResponseWriter, r *http.Request) { 571 defer func() { 572 if err := recover(); err == nil { 573 t.Errorf("expected panic, got %v", err) 574 } 575 }() 576 apfHandler.ServeHTTP(w, r) 577 } 578 server := httptest.NewServer(http.HandlerFunc(handler)) 579 defer server.Close() 580 581 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusOK); err != nil { 582 t.Errorf("unexpected error: %v", err) 583 } 584 }) 585 } 586 } 587 588 // TestContextClosesOnRequestProcessed ensures that the request context is cancelled 589 // automatically even if the server doesn't cancel is explicitly. 590 // This is required to ensure we won't be leaking goroutines that wait for context 591 // cancelling (e.g. in queueset::StartRequest method). 592 // Even though in production we are not using httptest.Server, this logic is shared 593 // across these two. 594 func TestContextClosesOnRequestProcessed(t *testing.T) { 595 epmetrics.Register() 596 fcmetrics.Register() 597 wg := sync.WaitGroup{} 598 wg.Add(1) 599 handler := func(w http.ResponseWriter, r *http.Request) { 600 ctx := r.Context() 601 // asynchronously wait for context being closed 602 go func() { 603 <-ctx.Done() 604 wg.Done() 605 }() 606 } 607 server := httptest.NewServer(http.HandlerFunc(handler)) 608 defer server.Close() 609 610 if err := expectHTTPGet(fmt.Sprintf("%s/api/v1/namespaces/default/pods?watch=true", server.URL), http.StatusOK); err != nil { 611 t.Errorf("unexpected error: %v", err) 612 } 613 614 wg.Wait() 615 } 616 617 type fakeFilterRequestDigest struct { 618 *fakeApfFilter 619 requestDigestGot *utilflowcontrol.RequestDigest 620 workEstimateGot fcrequest.WorkEstimate 621 } 622 623 func (f *fakeFilterRequestDigest) Handle(ctx context.Context, 624 requestDigest utilflowcontrol.RequestDigest, 625 noteFn func(fs *flowcontrol.FlowSchema, pl *flowcontrol.PriorityLevelConfiguration, flowDistinguisher string), 626 workEstimator func() fcrequest.WorkEstimate, 627 _ fq.QueueNoteFn, _ func(), 628 ) { 629 f.requestDigestGot = &requestDigest 630 noteFn(bootstrap.MandatoryFlowSchemaCatchAll, bootstrap.MandatoryPriorityLevelConfigurationCatchAll, "") 631 f.workEstimateGot = workEstimator() 632 } 633 634 func TestApfWithRequestDigest(t *testing.T) { 635 epmetrics.Register() 636 fcmetrics.Register() 637 longRunningFunc := func(_ *http.Request, _ *apirequest.RequestInfo) bool { return false } 638 fakeFilter := &fakeFilterRequestDigest{} 639 640 reqDigestExpected := &utilflowcontrol.RequestDigest{ 641 RequestInfo: &apirequest.RequestInfo{Verb: "get"}, 642 User: &user.DefaultInfo{Name: "foo"}, 643 } 644 workExpected := fcrequest.WorkEstimate{ 645 InitialSeats: 5, 646 FinalSeats: 7, 647 AdditionalLatency: 3 * time.Second, 648 } 649 650 handler := WithPriorityAndFairness(http.HandlerFunc(func(_ http.ResponseWriter, req *http.Request) {}), 651 longRunningFunc, 652 fakeFilter, 653 func(_ *http.Request, _, _ string) fcrequest.WorkEstimate { return workExpected }, 654 time.Minute/4, 655 ) 656 657 w := httptest.NewRecorder() 658 req, err := http.NewRequest(http.MethodGet, "/bar", nil) 659 if err != nil { 660 t.Fatalf("Failed to create new http request - %v", err) 661 } 662 req = req.WithContext(apirequest.WithRequestInfo(req.Context(), reqDigestExpected.RequestInfo)) 663 req = req.WithContext(apirequest.WithUser(req.Context(), reqDigestExpected.User)) 664 665 handler.ServeHTTP(w, req) 666 667 if !reflect.DeepEqual(reqDigestExpected, fakeFilter.requestDigestGot) { 668 t.Errorf("Expected RequestDigest to match, diff: %s", cmp.Diff(reqDigestExpected, fakeFilter.requestDigestGot)) 669 } 670 if !reflect.DeepEqual(workExpected, fakeFilter.workEstimateGot) { 671 t.Errorf("Expected WorkEstimate to match, diff: %s", cmp.Diff(workExpected, fakeFilter.workEstimateGot)) 672 } 673 } 674 675 func TestPriorityAndFairnessWithPanicRecoveryAndTimeoutFilter(t *testing.T) { 676 epmetrics.Register() 677 fcmetrics.Register() 678 timeFmt := "15:04:05.999" 679 680 t.Run("priority level concurrency is set to 1, request handler panics, next request should not be rejected", func(t *testing.T) { 681 const ( 682 userName = "alice" 683 fsName = "test-fs" 684 plName = "test-pl" 685 serverConcurrency, plConcurrencyShares, plConcurrency = 1, 1, 1 686 ) 687 688 apfConfiguration := newConfiguration(fsName, plName, userName, plConcurrencyShares, 0) 689 stopCh := make(chan struct{}) 690 controller, controllerCompletedCh := startAPFController(t, stopCh, apfConfiguration, serverConcurrency, plName, plConcurrency) 691 692 headerMatcher := headerMatcher{} 693 // we will raise a panic for the first request. 694 firstRequestPathPanic, secondRequestPathShouldWork := "/request/panic-as-designed", "/request/should-succeed-as-expected" 695 firstHandlerDoneCh, secondHandlerDoneCh := make(chan struct{}), make(chan struct{}) 696 requestHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 697 headerMatcher.inspect(t, w, fsName, plName) 698 switch { 699 case r.URL.Path == firstRequestPathPanic: 700 close(firstHandlerDoneCh) 701 panic(fmt.Errorf("request handler panic'd as designed - %#v", r.RequestURI)) 702 case r.URL.Path == secondRequestPathShouldWork: 703 close(secondHandlerDoneCh) 704 705 } 706 }) 707 708 // NOTE: the server will enforce a 1m timeout on every incoming 709 // request, and the client enforces a timeout of 2m. 710 handler := newHandlerChain(t, requestHandler, controller, userName, time.Minute) 711 server, requestGetter := newHTTP2ServerWithClient(handler, 2*time.Minute) 712 defer server.Close() 713 714 // we send two requests synchronously, one at a time 715 // - first request is expected to panic as designed 716 // - second request is expected to succeed 717 _, err := requestGetter(firstRequestPathPanic) 718 719 // did the server handler panic, as expected? 720 select { 721 case <-firstHandlerDoneCh: 722 case <-time.After(wait.ForeverTestTimeout): 723 t.Errorf("Expected the server handler to panic for request: %q", firstRequestPathPanic) 724 } 725 if isClientTimeout(err) { 726 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", firstRequestPathPanic, err.Error()) 727 } 728 expectResetStreamError(t, err) 729 730 // the second request should be served successfully. 731 response, err := requestGetter(secondRequestPathShouldWork) 732 if err != nil { 733 t.Fatalf("Expected request: %q to get a response, but got error: %#v", secondRequestPathShouldWork, err) 734 } 735 if response.StatusCode != http.StatusOK { 736 t.Errorf("Expected HTTP status code: %d for request: %q, but got: %#v", http.StatusOK, secondRequestPathShouldWork, response) 737 } 738 select { 739 case <-secondHandlerDoneCh: 740 case <-time.After(wait.ForeverTestTimeout): 741 t.Errorf("Expected the server handler to have completed: %q", secondRequestPathShouldWork) 742 } 743 744 close(stopCh) 745 t.Log("Waiting for the controller to shutdown") 746 747 controllerErr := <-controllerCompletedCh 748 if controllerErr != nil { 749 t.Errorf("Expected no error from the controller, but got: %#v", controllerErr) 750 } 751 }) 752 753 t.Run("priority level concurrency is set to 1, request times out and inner handler hasn't written to the response yet", func(t *testing.T) { 754 t.Parallel() 755 const ( 756 userName = "alice" 757 fsName = "test-fs" 758 plName = "test-pl" 759 serverConcurrency, plConcurrencyShares, plConcurrency = 1, 1, 1 760 ) 761 762 apfConfiguration := newConfiguration(fsName, plName, userName, plConcurrencyShares, 0) 763 stopCh := make(chan struct{}) 764 controller, controllerCompletedCh := startAPFController(t, stopCh, apfConfiguration, serverConcurrency, plName, plConcurrency) 765 766 headerMatcher := headerMatcher{} 767 rquestTimesOutPath := "/request/time-out-as-designed" 768 reqHandlerCompletedCh, callerRoundTripDoneCh := make(chan struct{}), make(chan struct{}) 769 requestHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 770 headerMatcher.inspect(t, w, fsName, plName) 771 772 if r.URL.Path == rquestTimesOutPath { 773 defer close(reqHandlerCompletedCh) 774 775 // this will force the request to time out. 776 <-callerRoundTripDoneCh 777 } 778 }) 779 780 // NOTE: the server will enforce a 5s timeout on every 781 // incoming request, and the client enforces a timeout of 1m. 782 handler := newHandlerChain(t, requestHandler, controller, userName, 5*time.Second) 783 server, requestGetter := newHTTP2ServerWithClient(handler, time.Minute) 784 defer server.Close() 785 786 // send a request synchronously with a client timeout of 1m, this minimizes the 787 // chance of a flake in ci, the cient waits long enough for the server to send a 788 // timeout response to the client. 789 var ( 790 response *http.Response 791 err error 792 ) 793 func() { 794 defer close(callerRoundTripDoneCh) 795 796 t.Logf("Waiting for the request: %q to time out", rquestTimesOutPath) 797 response, err = requestGetter(rquestTimesOutPath) 798 if isClientTimeout(err) { 799 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", rquestTimesOutPath, err.Error()) 800 } 801 }() 802 803 t.Logf("Waiting for the inner handler of the request: %q to complete", rquestTimesOutPath) 804 select { 805 case <-reqHandlerCompletedCh: 806 case <-time.After(wait.ForeverTestTimeout): 807 t.Errorf("Expected the server handler to have completed: %q", rquestTimesOutPath) 808 } 809 810 if err != nil { 811 t.Fatalf("Expected request: %q to get a response, but got error: %#v", rquestTimesOutPath, err) 812 } 813 if response.StatusCode != http.StatusGatewayTimeout { 814 t.Errorf("Expected HTTP status code: %d for request: %q, but got: %#v", http.StatusGatewayTimeout, rquestTimesOutPath, response) 815 } 816 817 close(stopCh) 818 t.Log("Waiting for the controller to shutdown") 819 820 controllerErr := <-controllerCompletedCh 821 if controllerErr != nil { 822 t.Errorf("Expected no error from the controller, but got: %#v", controllerErr) 823 } 824 }) 825 826 t.Run("priority level concurrency is set to 1, inner handler panics after the request times out", func(t *testing.T) { 827 t.Parallel() 828 const ( 829 userName = "alice" 830 fsName = "test-fs" 831 plName = "test-pl" 832 serverConcurrency, plConcurrencyShares, plConcurrency = 1, 1, 1 833 ) 834 835 apfConfiguration := newConfiguration(fsName, plName, userName, plConcurrencyShares, 0) 836 stopCh := make(chan struct{}) 837 controller, controllerCompletedCh := startAPFController(t, stopCh, apfConfiguration, serverConcurrency, plName, plConcurrency) 838 839 headerMatcher := headerMatcher{} 840 reqHandlerErrCh, callerRoundTripDoneCh := make(chan error, 1), make(chan struct{}) 841 rquestTimesOutPath := "/request/time-out-as-designed" 842 requestHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 843 headerMatcher.inspect(t, w, fsName, plName) 844 845 if r.URL.Path == rquestTimesOutPath { 846 <-callerRoundTripDoneCh 847 848 // we expect the timeout handler to have timed out this request by now and any attempt 849 // to write to the response should return a http.ErrHandlerTimeout error. 850 _, innerHandlerWriteErr := w.Write([]byte("foo")) 851 reqHandlerErrCh <- innerHandlerWriteErr 852 853 panic(http.ErrAbortHandler) 854 } 855 }) 856 857 // NOTE: the server will enforce a 5s timeout on every 858 // incoming request, and the client enforces a timeout of 1m. 859 handler := newHandlerChain(t, requestHandler, controller, userName, 5*time.Second) 860 server, requestGetter := newHTTP2ServerWithClient(handler, time.Minute) 861 defer server.Close() 862 863 // send a request synchronously with a client timeout of 1m, this minimizes the 864 // chance of a flake in ci, the cient waits long enough for the server to send a 865 // timeout response to the client. 866 var ( 867 response *http.Response 868 err error 869 ) 870 func() { 871 defer close(callerRoundTripDoneCh) 872 t.Logf("Waiting for the request: %q to time out", rquestTimesOutPath) 873 response, err = requestGetter(rquestTimesOutPath) 874 if isClientTimeout(err) { 875 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", rquestTimesOutPath, err.Error()) 876 } 877 }() 878 879 t.Logf("Waiting for the inner handler of the request: %q to complete", rquestTimesOutPath) 880 select { 881 case innerHandlerWriteErr := <-reqHandlerErrCh: 882 if innerHandlerWriteErr != http.ErrHandlerTimeout { 883 t.Fatalf("Expected error: %#v, but got: %#v", http.ErrHandlerTimeout, err) 884 } 885 case <-time.After(wait.ForeverTestTimeout): 886 t.Errorf("Expected the server handler to have completed: %q", rquestTimesOutPath) 887 } 888 889 if err != nil { 890 t.Fatalf("Expected request: %q to get a response, but got error: %#v", rquestTimesOutPath, err) 891 } 892 if response.StatusCode != http.StatusGatewayTimeout { 893 t.Errorf("Expected HTTP status code: %d for request: %q, but got: %#v", http.StatusGatewayTimeout, rquestTimesOutPath, response) 894 } 895 896 close(stopCh) 897 t.Log("Waiting for the controller to shutdown") 898 899 controllerErr := <-controllerCompletedCh 900 if controllerErr != nil { 901 t.Errorf("Expected no error from the controller, but got: %#v", controllerErr) 902 } 903 }) 904 905 t.Run("priority level concurrency is set to 1, inner handler writes to the response before request times out", func(t *testing.T) { 906 t.Parallel() 907 const ( 908 userName = "alice" 909 fsName = "test-fs" 910 plName = "test-pl" 911 serverConcurrency, plConcurrencyShares, plConcurrency = 1, 1, 1 912 ) 913 914 apfConfiguration := newConfiguration(fsName, plName, userName, plConcurrencyShares, 0) 915 stopCh := make(chan struct{}) 916 controller, controllerCompletedCh := startAPFController(t, stopCh, apfConfiguration, serverConcurrency, plName, plConcurrency) 917 918 headerMatcher := headerMatcher{} 919 rquestTimesOutPath := "/request/time-out-as-designed" 920 reqHandlerErrCh, callerRoundTripDoneCh := make(chan error, 1), make(chan struct{}) 921 requestHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 922 headerMatcher.inspect(t, w, fsName, plName) 923 924 if r.URL.Path == rquestTimesOutPath { 925 926 // inner handler writes header and then let the request time out. 927 w.WriteHeader(http.StatusBadRequest) 928 <-callerRoundTripDoneCh 929 930 // we expect the timeout handler to have timed out this request by now and any attempt 931 // to write to the response should return a http.ErrHandlerTimeout error. 932 _, innerHandlerWriteErr := w.Write([]byte("foo")) 933 reqHandlerErrCh <- innerHandlerWriteErr 934 } 935 }) 936 937 // NOTE: the server will enforce a 5s timeout on every 938 // incoming request, and the client enforces a timeout of 1m. 939 handler := newHandlerChain(t, requestHandler, controller, userName, 5*time.Second) 940 server, requestGetter := newHTTP2ServerWithClient(handler, time.Minute) 941 defer server.Close() 942 943 // send a request synchronously with a client timeout of 1m, this minimizes the 944 // chance of a flake in ci, the cient waits long enough for the server to send a 945 // timeout response to the client. 946 var err error 947 func() { 948 defer close(callerRoundTripDoneCh) 949 t.Logf("Waiting for the request: %q to time out", rquestTimesOutPath) 950 _, err = requestGetter(rquestTimesOutPath) 951 if isClientTimeout(err) { 952 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", rquestTimesOutPath, err.Error()) 953 } 954 }() 955 956 t.Logf("Waiting for the inner handler of the request: %q to complete", rquestTimesOutPath) 957 select { 958 case innerHandlerWriteErr := <-reqHandlerErrCh: 959 if innerHandlerWriteErr != http.ErrHandlerTimeout { 960 t.Fatalf("Expected error: %#v, but got: %#v", http.ErrHandlerTimeout, err) 961 } 962 case <-time.After(wait.ForeverTestTimeout): 963 t.Errorf("Expected the server handler to have completed: %q", rquestTimesOutPath) 964 } 965 966 expectResetStreamError(t, err) 967 968 close(stopCh) 969 t.Log("Waiting for the controller to shutdown") 970 971 controllerErr := <-controllerCompletedCh 972 if controllerErr != nil { 973 t.Errorf("Expected no error from the controller, but got: %#v", controllerErr) 974 } 975 }) 976 977 t.Run("priority level concurrency is set to 1, queue length is 1, first request should time out and second (enqueued) request should time out as well", func(t *testing.T) { 978 t.Parallel() 979 980 type result struct { 981 err error 982 response *http.Response 983 } 984 985 const ( 986 userName = "alice" 987 fsName = "test-fs" 988 plName = "test-pl" 989 serverConcurrency, plConcurrencyShares, plConcurrency, queueLength = 1, 1, 1, 1 990 ) 991 992 apfConfiguration := newConfiguration(fsName, plName, userName, plConcurrencyShares, queueLength) 993 stopCh := make(chan struct{}) 994 controller, controllerCompletedCh := startAPFController(t, stopCh, apfConfiguration, serverConcurrency, plName, plConcurrency) 995 996 headerMatcher := headerMatcher{} 997 firstRequestTimesOutPath, secondRequestEnqueuedPath := "/request/first/time-out-as-designed", "/request/second/enqueued-as-designed" 998 firstReqHandlerErrCh, firstReqInProgressCh := make(chan error, 1), make(chan struct{}) 999 firstReqRoundTripDoneCh, secondReqRoundTripDoneCh := make(chan struct{}), make(chan struct{}) 1000 requestHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 1001 headerMatcher.inspect(t, w, fsName, plName) 1002 switch { 1003 case r.URL.Path == firstRequestTimesOutPath: 1004 close(firstReqInProgressCh) 1005 <-firstReqRoundTripDoneCh 1006 1007 // make sure we wait until the caller of the second request returns, this is to 1008 // ensure that second request never has a chance to be executed (to avoid flakes) 1009 <-secondReqRoundTripDoneCh 1010 1011 // we expect the timeout handler to have timed out this request by now and any attempt 1012 // to write to the response should return a http.ErrHandlerTimeout error. 1013 _, firstRequestInnerHandlerWriteErr := w.Write([]byte("foo")) 1014 firstReqHandlerErrCh <- firstRequestInnerHandlerWriteErr 1015 1016 case r.URL.Path == secondRequestEnqueuedPath: 1017 // we expect the concurrency to be set to 1 and so this request should never be executed. 1018 t.Errorf("Expected second request to be enqueued: %q", secondRequestEnqueuedPath) 1019 } 1020 }) 1021 1022 // NOTE: the server will enforce a 5s timeout on every 1023 // incoming request, and the client enforces a timeout of 1m. 1024 handler := newHandlerChain(t, requestHandler, controller, userName, 5*time.Second) 1025 server, requestGetter := newHTTP2ServerWithClient(handler, time.Minute) 1026 defer server.Close() 1027 1028 // This test involves two requests sent to the same priority level, which has 1 queue and 1029 // a concurrency limit of 1. The handler chain include the timeout filter. 1030 // Each request is sent from a separate goroutine, with a client-side timeout of 1m, on 1031 // the other hand, the server enforces a timeout of 5s (via the timeout filter). 1032 // The first request should get dispatched immediately; execution (a) starts with closing 1033 // the channel that triggers the second client goroutine to send its request and then (b) 1034 // waits for both client goroutines to have gotten a response (expected to be timeouts). 1035 // The second request sits in the queue until the timeout filter does its thing, which 1036 // it does concurrently to both requests. For the first request this should make the client 1037 // get a timeout response without directly affecting execution. For the second request, the 1038 // fact that the timeout filter closes the request's Context.Done() causes the request to be 1039 // promptly ejected from its queue. The goroutine doing the APF handling writes an HTTP 1040 // response message with status 429. 1041 // The timeout handler invokes its inner handler in one goroutine while reacting to the 1042 // passage of time in its original goroutine. That reaction to a time out consists of either 1043 // (a) writing an HTTP response message with status 504 to indicate the timeout or (b) doing an 1044 // HTTP/2 stream close; the latter is done if either the connection has been "hijacked" or some 1045 // other goroutine (e.g., the one running the inner handler) has started to write a response. 1046 // In the scenario tested here, there is thus a race between two goroutines to respond to 1047 // the second request and any of their responses is allowed by the test. 1048 firstReqResultCh, secondReqResultCh := make(chan result, 1), make(chan result, 1) 1049 go func() { 1050 defer close(firstReqRoundTripDoneCh) 1051 t.Logf("At %s, Sending request: %q", time.Now().Format(timeFmt), firstRequestTimesOutPath) 1052 resp, err := requestGetter(firstRequestTimesOutPath) 1053 t.Logf("At %s, RoundTrip of request: %q has completed", time.Now().Format(timeFmt), firstRequestTimesOutPath) 1054 firstReqResultCh <- result{err: err, response: resp} 1055 }() 1056 go func() { 1057 // we must wait for the "first" request to start executing before 1058 // we can initiate the "second". 1059 defer close(secondReqRoundTripDoneCh) 1060 1061 <-firstReqInProgressCh 1062 t.Logf("At %s, Sending request: %q", time.Now().Format(timeFmt), secondRequestEnqueuedPath) 1063 resp, err := requestGetter(secondRequestEnqueuedPath) 1064 t.Logf("At %s, RoundTrip of request: %q has completed", time.Now().Format(timeFmt), secondRequestEnqueuedPath) 1065 secondReqResultCh <- result{err: err, response: resp} 1066 }() 1067 1068 firstReqResult := <-firstReqResultCh 1069 if isClientTimeout(firstReqResult.err) { 1070 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", firstRequestTimesOutPath, fmtError(firstReqResult.err)) 1071 } 1072 t.Logf("Waiting for the inner handler of the request: %q to complete", firstRequestTimesOutPath) 1073 select { 1074 case firstRequestInnerHandlerWriteErr := <-firstReqHandlerErrCh: 1075 if firstRequestInnerHandlerWriteErr != http.ErrHandlerTimeout { 1076 t.Fatalf("Expected error: %#v, but got: %s", http.ErrHandlerTimeout, fmtError(firstRequestInnerHandlerWriteErr)) 1077 } 1078 case <-time.After(wait.ForeverTestTimeout): 1079 t.Errorf("Expected the server handler to have completed: %q", firstRequestTimesOutPath) 1080 } 1081 1082 // first request is expected to time out. 1083 if isStreamReset(firstReqResult.err) || firstReqResult.response.StatusCode != http.StatusGatewayTimeout { 1084 // got what was expected 1085 } else if firstReqResult.err != nil { 1086 t.Fatalf("Expected request: %q to get a response or stream reset, but got error: %s", firstRequestTimesOutPath, fmtError(firstReqResult.err)) 1087 } else if firstReqResult.response.StatusCode != http.StatusGatewayTimeout { 1088 t.Errorf("Expected HTTP status code: %d for request: %q, but got: %#+v", http.StatusGatewayTimeout, firstRequestTimesOutPath, firstReqResult.response) 1089 } 1090 1091 // second request is expected to either be rejected (ideal behavior) or time out (current approximation of the ideal behavior) 1092 secondReqResult := <-secondReqResultCh 1093 if isClientTimeout(secondReqResult.err) { 1094 t.Fatalf("the client has unexpectedly timed out - request: %q error: %s", secondRequestEnqueuedPath, fmtError(secondReqResult.err)) 1095 } 1096 if isStreamReset(secondReqResult.err) || secondReqResult.response.StatusCode == http.StatusTooManyRequests || secondReqResult.response.StatusCode == http.StatusGatewayTimeout { 1097 // got what was expected 1098 } else if secondReqResult.err != nil { 1099 t.Fatalf("Expected request: %q to get a response or stream reset, but got error: %s", secondRequestEnqueuedPath, fmtError(secondReqResult.err)) 1100 } else if !(secondReqResult.response.StatusCode == http.StatusTooManyRequests || secondReqResult.response.StatusCode == http.StatusGatewayTimeout) { 1101 t.Errorf("Expected HTTP status code: %d or %d for request: %q, but got: %#+v", http.StatusTooManyRequests, http.StatusGatewayTimeout, secondRequestEnqueuedPath, secondReqResult.response) 1102 } 1103 1104 close(stopCh) 1105 t.Log("Waiting for the controller to shutdown") 1106 1107 controllerErr := <-controllerCompletedCh 1108 if controllerErr != nil { 1109 t.Errorf("Expected no error from the controller, but got: %s", fmtError(controllerErr)) 1110 } 1111 }) 1112 } 1113 1114 func fmtError(err error) string { 1115 return fmt.Sprintf("%#+v=%q", err, err.Error()) 1116 } 1117 1118 func startAPFController(t *testing.T, stopCh <-chan struct{}, apfConfiguration []runtime.Object, serverConcurrency int, 1119 plName string, plConcurrency int) (utilflowcontrol.Interface, <-chan error) { 1120 clientset := newClientset(t, apfConfiguration...) 1121 // this test does not rely on resync, so resync period is set to zero 1122 factory := informers.NewSharedInformerFactory(clientset, 0) 1123 controller := utilflowcontrol.New(factory, clientset.FlowcontrolV1(), serverConcurrency) 1124 1125 factory.Start(stopCh) 1126 1127 // wait for the informer cache to sync. 1128 timeout, cancel := context.WithTimeout(context.TODO(), 5*time.Second) 1129 defer cancel() 1130 cacheSyncDone := factory.WaitForCacheSync(timeout.Done()) 1131 if names := unsyncedInformers(cacheSyncDone); len(names) > 0 { 1132 t.Fatalf("WaitForCacheSync did not successfully complete, resources=%#v", names) 1133 } 1134 1135 controllerCompletedCh := make(chan error) 1136 var controllerErr error 1137 go func() { 1138 controllerErr = controller.Run(stopCh) 1139 controllerCompletedCh <- controllerErr 1140 }() 1141 1142 // make sure that apf controller syncs the priority level configuration object we are using in this test. 1143 // read the metrics and ensure the concurrency limit for our priority level is set to the expected value. 1144 pollErr := wait.PollImmediate(100*time.Millisecond, 5*time.Second, func() (done bool, err error) { 1145 if err := gaugeValueMatch("apiserver_flowcontrol_nominal_limit_seats", map[string]string{"priority_level": plName}, plConcurrency); err != nil { 1146 t.Logf("polling retry - error: %s", err) 1147 return false, nil 1148 } 1149 return true, nil 1150 }) 1151 if pollErr != nil { 1152 t.Fatalf("expected the apf controller to sync the priotity level configuration object: %s", plName) 1153 } 1154 1155 return controller, controllerCompletedCh 1156 } 1157 1158 // returns a started http2 server, with a client function to send request to the server. 1159 func newHTTP2ServerWithClient(handler http.Handler, clientTimeout time.Duration) (*httptest.Server, func(path string) (*http.Response, error)) { 1160 server := httptest.NewUnstartedServer(handler) 1161 server.EnableHTTP2 = true 1162 server.StartTLS() 1163 cli := server.Client() 1164 cli.Timeout = clientTimeout 1165 return server, func(path string) (*http.Response, error) { 1166 return cli.Get(server.URL + path) 1167 } 1168 } 1169 1170 type headerMatcher struct{} 1171 1172 // verifies that the expected flow schema and priority level UIDs are attached to the header. 1173 func (m *headerMatcher) inspect(t *testing.T, w http.ResponseWriter, expectedFS, expectedPL string) { 1174 t.Helper() 1175 err := func() error { 1176 if w == nil { 1177 return fmt.Errorf("expected a non nil HTTP response") 1178 } 1179 1180 key := flowcontrol.ResponseHeaderMatchedFlowSchemaUID 1181 if value := w.Header().Get(key); expectedFS != value { 1182 return fmt.Errorf("expected HTTP header %s to have value %q, but got: %q", key, expectedFS, value) 1183 } 1184 1185 key = flowcontrol.ResponseHeaderMatchedPriorityLevelConfigurationUID 1186 if value := w.Header().Get(key); expectedPL != value { 1187 return fmt.Errorf("expected HTTP header %s to have value %q, but got %q", key, expectedPL, value) 1188 } 1189 return nil 1190 }() 1191 if err == nil { 1192 return 1193 } 1194 t.Errorf("Expected APF headers to match, but got: %v", err) 1195 } 1196 1197 // when a request panics, http2 resets the stream with an INTERNAL_ERROR message 1198 func expectResetStreamError(t *testing.T, err error) { 1199 if err == nil { 1200 t.Fatalf("expected the server to send an error, but got nil") 1201 } 1202 if isStreamReset(err) { 1203 return 1204 } 1205 t.Fatalf("expected a stream reset error, but got %#+v=%s", err, err.Error()) 1206 } 1207 1208 func newClientset(t *testing.T, objects ...runtime.Object) clientset.Interface { 1209 clientset := fake.NewSimpleClientset(objects...) 1210 if clientset == nil { 1211 t.Fatal("unable to create fake client set") 1212 } 1213 return clientset 1214 } 1215 1216 // builds a chain of handlers that include the panic recovery and timeout filter, so we can simulate the behavior of 1217 // a real apiserver. 1218 // the specified user is added as the authenticated user to the request context. 1219 func newHandlerChain(t *testing.T, handler http.Handler, filter utilflowcontrol.Interface, userName string, requestTimeout time.Duration) http.Handler { 1220 requestInfoFactory := &apirequest.RequestInfoFactory{APIPrefixes: sets.NewString("apis", "api"), GrouplessAPIPrefixes: sets.NewString("api")} 1221 longRunningRequestCheck := BasicLongRunningRequestCheck(sets.NewString("watch"), sets.NewString("proxy")) 1222 1223 apfHandler := WithPriorityAndFairness(handler, longRunningRequestCheck, filter, defaultRequestWorkEstimator, time.Minute/4) 1224 1225 // add the handler in the chain that adds the specified user to the request context 1226 handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { 1227 r = r.WithContext(apirequest.WithUser(r.Context(), &user.DefaultInfo{ 1228 Name: userName, 1229 Groups: []string{user.AllAuthenticated}, 1230 })) 1231 1232 apfHandler.ServeHTTP(w, r) 1233 }) 1234 1235 handler = WithTimeoutForNonLongRunningRequests(handler, longRunningRequestCheck) 1236 // we don't have any request with invalid timeout, so leaving audit policy and sink nil. 1237 handler = apifilters.WithRequestDeadline(handler, nil, nil, longRunningRequestCheck, nil, requestTimeout) 1238 handler = apifilters.WithRequestInfo(handler, requestInfoFactory) 1239 handler = WithPanicRecovery(handler, requestInfoFactory) 1240 handler = apifilters.WithAuditInit(handler) 1241 return handler 1242 } 1243 1244 func unsyncedInformers(status map[reflect.Type]bool) []string { 1245 names := make([]string, 0) 1246 1247 for objType, synced := range status { 1248 if !synced { 1249 names = append(names, objType.Name()) 1250 } 1251 } 1252 1253 return names 1254 } 1255 1256 func newConfiguration(fsName, plName, user string, concurrency int32, queueLength int32) []runtime.Object { 1257 fs := &flowcontrol.FlowSchema{ 1258 ObjectMeta: metav1.ObjectMeta{ 1259 Name: fsName, 1260 UID: types.UID(fsName), 1261 }, 1262 Spec: flowcontrol.FlowSchemaSpec{ 1263 MatchingPrecedence: 1, 1264 PriorityLevelConfiguration: flowcontrol.PriorityLevelConfigurationReference{ 1265 Name: plName, 1266 }, 1267 DistinguisherMethod: &flowcontrol.FlowDistinguisherMethod{ 1268 Type: flowcontrol.FlowDistinguisherMethodByUserType, 1269 }, 1270 Rules: []flowcontrol.PolicyRulesWithSubjects{ 1271 { 1272 Subjects: []flowcontrol.Subject{ 1273 { 1274 Kind: flowcontrol.SubjectKindUser, 1275 User: &flowcontrol.UserSubject{ 1276 Name: user, 1277 }, 1278 }, 1279 }, 1280 NonResourceRules: []flowcontrol.NonResourcePolicyRule{ 1281 { 1282 Verbs: []string{flowcontrol.VerbAll}, 1283 NonResourceURLs: []string{flowcontrol.NonResourceAll}, 1284 }, 1285 }, 1286 }, 1287 }, 1288 }, 1289 } 1290 1291 var ( 1292 responseType flowcontrol.LimitResponseType = flowcontrol.LimitResponseTypeReject 1293 qcfg *flowcontrol.QueuingConfiguration 1294 ) 1295 if queueLength > 0 { 1296 responseType = flowcontrol.LimitResponseTypeQueue 1297 qcfg = &flowcontrol.QueuingConfiguration{ 1298 Queues: 1, 1299 QueueLengthLimit: queueLength, 1300 HandSize: 1, 1301 } 1302 } 1303 pl := &flowcontrol.PriorityLevelConfiguration{ 1304 ObjectMeta: metav1.ObjectMeta{ 1305 Name: plName, 1306 UID: types.UID(plName), 1307 }, 1308 Spec: flowcontrol.PriorityLevelConfigurationSpec{ 1309 Type: flowcontrol.PriorityLevelEnablementLimited, 1310 Limited: &flowcontrol.LimitedPriorityLevelConfiguration{ 1311 NominalConcurrencyShares: ptr.To(concurrency), 1312 LimitResponse: flowcontrol.LimitResponse{ 1313 Type: responseType, 1314 Queuing: qcfg, 1315 }, 1316 }, 1317 }, 1318 } 1319 1320 return []runtime.Object{fs, pl} 1321 } 1322 1323 // gathers and checks the metrics. 1324 func checkForExpectedMetrics(t *testing.T, expectedMetrics []string) { 1325 metricsFamily, err := legacyregistry.DefaultGatherer.Gather() 1326 if err != nil { 1327 t.Fatalf("Failed to gather metrics %v", err) 1328 } 1329 1330 metrics := map[string]interface{}{} 1331 for _, mf := range metricsFamily { 1332 metrics[*mf.Name] = mf 1333 } 1334 1335 for _, metricName := range expectedMetrics { 1336 if _, ok := metrics[metricName]; !ok { 1337 if !ok { 1338 t.Errorf("Scraped metrics did not include expected metric %s", metricName) 1339 } 1340 } 1341 } 1342 } 1343 1344 // gaugeValueMatch ensures that the value of gauge metrics matching the labelFilter is as expected. 1345 func gaugeValueMatch(name string, labelFilter map[string]string, wantValue int) error { 1346 metrics, err := legacyregistry.DefaultGatherer.Gather() 1347 if err != nil { 1348 return fmt.Errorf("failed to gather metrics: %s", err) 1349 } 1350 1351 sum := 0 1352 familyMatch, labelMatch := false, false 1353 for _, mf := range metrics { 1354 if mf.GetName() != name { 1355 continue 1356 } 1357 1358 familyMatch = true 1359 for _, metric := range mf.GetMetric() { 1360 if !testutil.LabelsMatch(metric, labelFilter) { 1361 continue 1362 } 1363 1364 labelMatch = true 1365 sum += int(metric.GetGauge().GetValue()) 1366 } 1367 } 1368 if !familyMatch { 1369 return fmt.Errorf("expected to find the metric family: %s in the gathered result", name) 1370 } 1371 if !labelMatch { 1372 return fmt.Errorf("expected to find metrics with matching labels: %#+v", labelFilter) 1373 } 1374 if wantValue != sum { 1375 return fmt.Errorf("expected the sum to be: %d, but got: %d for gauge metric: %s with labels %#+v", wantValue, sum, name, labelFilter) 1376 } 1377 1378 return nil 1379 } 1380 1381 func isClientTimeout(err error) bool { 1382 if urlErr, ok := err.(*url.Error); ok { 1383 return urlErr.Timeout() 1384 } 1385 return false 1386 } 1387 1388 func isStreamReset(err error) bool { 1389 if err == nil { 1390 return false 1391 } 1392 if urlErr, ok := err.(*url.Error); ok { 1393 // Sadly, the client does not receive a more specific indication 1394 // of stream reset. 1395 return strings.Contains(urlErr.Err.Error(), "INTERNAL_ERROR") 1396 } 1397 return false 1398 } 1399 1400 func TestGetRequestWaitContext(t *testing.T) { 1401 tests := []struct { 1402 name string 1403 defaultRequestWaitLimit time.Duration 1404 parent func(t time.Time) (context.Context, context.CancelFunc) 1405 newReqWaitCtxExpected bool 1406 reqWaitLimitExpected time.Duration 1407 }{ 1408 { 1409 name: "context deadline has exceeded", 1410 parent: func(time.Time) (context.Context, context.CancelFunc) { 1411 ctx, cancel := context.WithCancel(context.Background()) 1412 cancel() 1413 return ctx, cancel 1414 }, 1415 }, 1416 { 1417 name: "context has a deadline, 'received at' is not set, wait limit should be one fourth of the remaining deadline from now", 1418 parent: func(now time.Time) (context.Context, context.CancelFunc) { 1419 return context.WithDeadline(context.Background(), now.Add(60*time.Second)) 1420 }, 1421 newReqWaitCtxExpected: true, 1422 reqWaitLimitExpected: 15 * time.Second, 1423 }, 1424 { 1425 name: "context has a deadline, 'received at' is set, wait limit should be one fourth of the deadline starting from the 'received at' time", 1426 parent: func(now time.Time) (context.Context, context.CancelFunc) { 1427 ctx := apirequest.WithReceivedTimestamp(context.Background(), now.Add(-10*time.Second)) 1428 return context.WithDeadline(ctx, now.Add(50*time.Second)) 1429 }, 1430 newReqWaitCtxExpected: true, 1431 reqWaitLimitExpected: 5 * time.Second, // from now 1432 }, 1433 { 1434 name: "context does not have any deadline, 'received at' is not set, default wait limit should be in effect from now", 1435 defaultRequestWaitLimit: 15 * time.Second, 1436 parent: func(time.Time) (context.Context, context.CancelFunc) { 1437 return context.WithCancel(context.Background()) 1438 }, 1439 newReqWaitCtxExpected: true, 1440 reqWaitLimitExpected: 15 * time.Second, 1441 }, 1442 { 1443 name: "context does not have any deadline, 'received at' is set, default wait limit should be in effect starting from the 'received at' time", 1444 defaultRequestWaitLimit: 15 * time.Second, 1445 parent: func(now time.Time) (context.Context, context.CancelFunc) { 1446 ctx := apirequest.WithReceivedTimestamp(context.Background(), now.Add(-10*time.Second)) 1447 return context.WithCancel(ctx) 1448 }, 1449 newReqWaitCtxExpected: true, 1450 reqWaitLimitExpected: 5 * time.Second, // from now 1451 }, 1452 { 1453 name: "context has a deadline, wait limit should not exceed the hard limit of 1m", 1454 parent: func(now time.Time) (context.Context, context.CancelFunc) { 1455 // let 1/4th of the remaining deadline exceed the hard limit 1456 return context.WithDeadline(context.Background(), now.Add(8*time.Minute)) 1457 }, 1458 newReqWaitCtxExpected: true, 1459 reqWaitLimitExpected: time.Minute, 1460 }, 1461 { 1462 name: "context has no deadline, wait limit should not exceed the hard limit of 1m", 1463 defaultRequestWaitLimit: 2 * time.Minute, // it exceeds the hard limit 1464 parent: func(now time.Time) (context.Context, context.CancelFunc) { 1465 return context.WithCancel(context.Background()) 1466 }, 1467 newReqWaitCtxExpected: true, 1468 reqWaitLimitExpected: time.Minute, 1469 }, 1470 } 1471 1472 for _, test := range tests { 1473 t.Run(test.name, func(t *testing.T) { 1474 now := time.Now() 1475 parent, cancel := test.parent(now) 1476 defer cancel() 1477 1478 clock := clocktesting.NewFakePassiveClock(now) 1479 newReqWaitCtxGot, cancelGot := getRequestWaitContext(parent, test.defaultRequestWaitLimit, clock) 1480 if cancelGot == nil { 1481 t.Errorf("Expected a non nil context.CancelFunc") 1482 return 1483 } 1484 defer cancelGot() 1485 1486 switch { 1487 case test.newReqWaitCtxExpected: 1488 deadlineGot, ok := newReqWaitCtxGot.Deadline() 1489 if !ok { 1490 t.Errorf("Expected the new wait limit context to have a deadline") 1491 } 1492 if waitLimitGot := deadlineGot.Sub(now); test.reqWaitLimitExpected != waitLimitGot { 1493 t.Errorf("Expected request wait limit %s, but got: %s", test.reqWaitLimitExpected, waitLimitGot) 1494 } 1495 default: 1496 if parent != newReqWaitCtxGot { 1497 t.Errorf("Expected the parent context to be returned: want: %#v, got %#v", parent, newReqWaitCtxGot) 1498 } 1499 } 1500 }) 1501 } 1502 }