diff --git a/go.mod b/go.mod index be154e9e..8f3356b9 100644 --- a/go.mod +++ b/go.mod @@ -30,7 +30,7 @@ require ( golang.org/x/term v0.0.0-20210220032956-6a3ed077a48d golang.org/x/time v0.0.0-20210723032227-1f47c861a9ac google.golang.org/protobuf v1.26.0 - k8s.io/api v0.0.0-20210720141931-aa30bdaf750c + k8s.io/api v0.0.0-20210806000319-499b6f90564c k8s.io/apimachinery v0.0.0-20210805051055-f7769293e6f1 k8s.io/klog/v2 v2.9.0 k8s.io/kube-openapi v0.0.0-20210421082810-95288971da7e @@ -40,6 +40,6 @@ require ( ) replace ( - k8s.io/api => k8s.io/api v0.0.0-20210720141931-aa30bdaf750c + k8s.io/api => k8s.io/api v0.0.0-20210806000319-499b6f90564c k8s.io/apimachinery => k8s.io/apimachinery v0.0.0-20210805051055-f7769293e6f1 ) diff --git a/go.sum b/go.sum index af374795..db15551a 100644 --- a/go.sum +++ b/go.sum @@ -444,8 +444,8 @@ honnef.co/go/tools v0.0.0-20190418001031-e561f6794a2a/go.mod h1:rf3lG4BRIbNafJWh honnef.co/go/tools v0.0.0-20190523083050-ea95bdfd59fc/go.mod h1:rf3lG4BRIbNafJWhAfAdb/ePZxsR/4RtNHQocxwk9r4= honnef.co/go/tools v0.0.1-2019.2.3/go.mod h1:a3bituU0lyd329TUQxRnasdCoJDkEUEAqEt0JzvZhAg= honnef.co/go/tools v0.0.1-2020.1.3/go.mod h1:X/FiERA/W4tHapMX5mGpAtMSVEeEUOyHaw9vFzvIQ3k= -k8s.io/api v0.0.0-20210720141931-aa30bdaf750c h1:bQDI22QyjupmAGqhbVE2uIkAkAAVEVfTf/n8RG/Xtpo= -k8s.io/api v0.0.0-20210720141931-aa30bdaf750c/go.mod h1:FtqZiusVhnyM5jUPPFkDCU91OKo0sOpX9b9hotVGbIk= +k8s.io/api v0.0.0-20210806000319-499b6f90564c h1:/TwdwBIiHSFv2VnETc8qgoi/skGGBo1qlXszp8N/BMo= +k8s.io/api v0.0.0-20210806000319-499b6f90564c/go.mod h1:9J6nkHavSazyXmPeuA4f1YO9Ztdjw7nDibPjT4P+wsY= k8s.io/apimachinery v0.0.0-20210805051055-f7769293e6f1 h1:cVpwhaGeh/tNPBeYbFff3tjx5AxwG5zwImhz+eusG3k= k8s.io/apimachinery v0.0.0-20210805051055-f7769293e6f1/go.mod h1:O3oNtNadZdeOMxHFVxOreoznohCpy0z6mocxbZr7oJ0= k8s.io/gengo v0.0.0-20200413195148-3a45101e95ac/go.mod h1:ezvh/TsK7cY6rbqRK0oQQ8IAqLxYwwyPxAX1Pzy0ii0= diff --git a/tools/cache/delta_fifo.go b/tools/cache/delta_fifo.go index 82038e0f..54b81766 100644 --- a/tools/cache/delta_fifo.go +++ b/tools/cache/delta_fifo.go @@ -20,10 +20,12 @@ import ( "errors" "fmt" "sync" + "time" "k8s.io/apimachinery/pkg/util/sets" "k8s.io/klog/v2" + utiltrace "k8s.io/utils/trace" ) // DeltaFIFOOptions is the configuration parameters for DeltaFIFO. All are @@ -526,6 +528,7 @@ func (f *DeltaFIFO) Pop(process PopProcessFunc) (interface{}, error) { } id := f.queue[0] f.queue = f.queue[1:] + depth := len(f.queue) if f.initialPopulationCount > 0 { f.initialPopulationCount-- } @@ -536,6 +539,18 @@ func (f *DeltaFIFO) Pop(process PopProcessFunc) (interface{}, error) { continue } delete(f.items, id) + // Only log traces if the queue depth is greater than 10 and it takes more than + // 100 milliseconds to process one item from the queue. + // Queue depth never goes high because processing an item is locking the queue, + // and new items can't be added until processing finish. + // https://github.com/kubernetes/kubernetes/issues/103789 + if depth > 10 { + trace := utiltrace.New("DeltaFIFO Pop Process", + utiltrace.Field{Key: "ID", Value: id}, + utiltrace.Field{Key: "Depth", Value: depth}, + utiltrace.Field{Key: "Reason", Value: "slow event handlers blocking the queue"}) + defer trace.LogIfLong(100 * time.Millisecond) + } err := process(item) if e, ok := err.(ErrRequeue); ok { f.addIfNotPresent(id, item)