Merge pull request #73308 from krzysied/reflector_trace2

staging/src/k8s.io/client-go/Godeps/Godeps.json

@@ -623,6 +623,10 @@
 			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
 		},
 		{
+			"ImportPath": "k8s.io/utils/trace",
+			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
+		},
+		{
 			"ImportPath": "sigs.k8s.io/yaml",
 			"Rev": "fd68e9863619f6ec2fdd8625fe1f02e7c877e480"
 		}

staging/src/k8s.io/client-go/tools/cache/BUILD

@@ -84,6 +84,7 @@ go_library(
         "//staging/src/k8s.io/client-go/util/retry:go_default_library",
         "//vendor/k8s.io/klog:go_default_library",
         "//vendor/k8s.io/utils/buffer:go_default_library",
+        "//vendor/k8s.io/utils/trace:go_default_library",
     ],
 )
 

staging/src/k8s.io/client-go/tools/cache/reflector.go

@@ -41,6 +41,7 @@ import (
 	"k8s.io/apimachinery/pkg/util/wait"
 	"k8s.io/apimachinery/pkg/watch"
 	"k8s.io/klog"
+	"k8s.io/utils/trace"
 )
 
 // Reflector watches a specified resource and causes all changes to be reflected in the given store.
@@ -176,45 +177,56 @@ func (r *Reflector) ListAndWatch(stopCh <-chan struct{}) error {
 	r.metrics.numberOfLists.Inc()
 	start := r.clock.Now()
 
-	var list runtime.Object
-	var err error
-	listCh := make(chan struct{}, 1)
-	panicCh := make(chan interface{}, 1)
-	go func() {
-		defer func() {
-			if r := recover(); r != nil {
-				panicCh <- r
-			}
+	if err := func() error {
+		initTrace := trace.New("Reflector " + r.name + " ListAndWatch")
+		defer initTrace.LogIfLong(10 * time.Second)
+		var list runtime.Object
+		var err error
+		listCh := make(chan struct{}, 1)
+		panicCh := make(chan interface{}, 1)
+		go func() {
+			defer func() {
+				if r := recover(); r != nil {
+					panicCh <- r
+				}
+			}()
+			list, err = r.listerWatcher.List(options)
+			close(listCh)
 		}()
-		list, err = r.listerWatcher.List(options)
-		close(listCh)
-	}()
-	select {
-	case <-stopCh:
+		select {
+		case <-stopCh:
+			return nil
+		case r := <-panicCh:
+			panic(r)
+		case <-listCh:
+		}
+		if err != nil {
+			return fmt.Errorf("%s: Failed to list %v: %v", r.name, r.expectedType, err)
+		}
+		initTrace.Step("Objects listed")
+		r.metrics.listDuration.Observe(time.Since(start).Seconds())
+		listMetaInterface, err := meta.ListAccessor(list)
+		if err != nil {
+			return fmt.Errorf("%s: Unable to understand list result %#v: %v", r.name, list, err)
+		}
+		resourceVersion = listMetaInterface.GetResourceVersion()
+		initTrace.Step("Resource version extracted")
+		items, err := meta.ExtractList(list)
+		if err != nil {
+			return fmt.Errorf("%s: Unable to understand list result %#v (%v)", r.name, list, err)
+		}
+		initTrace.Step("Objects extracted")
+		r.metrics.numberOfItemsInList.Observe(float64(len(items)))
+		if err := r.syncWith(items, resourceVersion); err != nil {
+			return fmt.Errorf("%s: Unable to sync list result: %v", r.name, err)
+		}
+		initTrace.Step("SyncWith done")
+		r.setLastSyncResourceVersion(resourceVersion)
+		initTrace.Step("Resource version updated")
 		return nil
-	case r := <-panicCh:
-		panic(r)
-	case <-listCh:
-	}
-	if err != nil {
-		return fmt.Errorf("%s: Failed to list %v: %v", r.name, r.expectedType, err)
-	}
-
-	r.metrics.listDuration.Observe(time.Since(start).Seconds())
-	listMetaInterface, err := meta.ListAccessor(list)
-	if err != nil {
-		return fmt.Errorf("%s: Unable to understand list result %#v: %v", r.name, list, err)
-	}
-	resourceVersion = listMetaInterface.GetResourceVersion()
-	items, err := meta.ExtractList(list)
-	if err != nil {
-		return fmt.Errorf("%s: Unable to understand list result %#v (%v)", r.name, list, err)
-	}
-	r.metrics.numberOfItemsInList.Observe(float64(len(items)))
-	if err := r.syncWith(items, resourceVersion); err != nil {
-		return fmt.Errorf("%s: Unable to sync list result: %v", r.name, err)
+	}(); err != nil {
+		return err
 	}
-	r.setLastSyncResourceVersion(resourceVersion)
 
 	resyncerrc := make(chan error, 1)
 	cancelCh := make(chan struct{})

staging/src/k8s.io/cloud-provider/Godeps/Godeps.json

@@ -959,6 +959,10 @@
 			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
 		},
 		{
+			"ImportPath": "k8s.io/utils/trace",
+			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
+		},
+		{
 			"ImportPath": "sigs.k8s.io/yaml",
 			"Rev": "fd68e9863619f6ec2fdd8625fe1f02e7c877e480"
 		}

staging/src/k8s.io/csi-api/Godeps/Godeps.json

@@ -555,6 +555,10 @@
 			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
 		},
 		{
+			"ImportPath": "k8s.io/utils/trace",
+			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
+		},
+		{
 			"ImportPath": "sigs.k8s.io/yaml",
 			"Rev": "fd68e9863619f6ec2fdd8625fe1f02e7c877e480"
 		}

staging/src/k8s.io/node-api/Godeps/Godeps.json

@@ -555,6 +555,10 @@
 			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
 		},
 		{
+			"ImportPath": "k8s.io/utils/trace",
+			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
+		},
+		{
 			"ImportPath": "sigs.k8s.io/yaml",
 			"Rev": "fd68e9863619f6ec2fdd8625fe1f02e7c877e480"
 		}

staging/src/k8s.io/sample-controller/Godeps/Godeps.json

@@ -1163,6 +1163,10 @@
 			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
 		},
 		{
+			"ImportPath": "k8s.io/utils/trace",
+			"Rev": "8a87304934321b4b0ad72a7cb3cbc715d67d38c7"
+		},
+		{
 			"ImportPath": "sigs.k8s.io/yaml",
 			"Rev": "fd68e9863619f6ec2fdd8625fe1f02e7c877e480"
 		}