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  }