Merge pull request #81786 from sttts/sttts-openapi-log-why

aggregator/apiextensions: logs & metrics why OpenAPI spec is regenerated

staging/src/k8s.io/apiextensions-apiserver/pkg/controller/openapi/BUILD

@@ -2,7 +2,10 @@ load("@io_bazel_rules_go//go:def.bzl", "go_library")
 
 go_library(
     name = "go_default_library",
-    srcs = ["controller.go"],
+    srcs = [
+        "controller.go",
+        "metrics.go",
+    ],
     importmap = "k8s.io/kubernetes/vendor/k8s.io/apiextensions-apiserver/pkg/controller/openapi",
     importpath = "k8s.io/apiextensions-apiserver/pkg/controller/openapi",
     visibility = ["//visibility:public"],
@@ -17,6 +20,8 @@ go_library(
         "//staging/src/k8s.io/apimachinery/pkg/util/wait:go_default_library",
         "//staging/src/k8s.io/client-go/tools/cache:go_default_library",
         "//staging/src/k8s.io/client-go/util/workqueue:go_default_library",
+        "//staging/src/k8s.io/component-base/metrics:go_default_library",
+        "//staging/src/k8s.io/component-base/metrics/legacyregistry:go_default_library",
         "//vendor/github.com/go-openapi/spec:go_default_library",
         "//vendor/k8s.io/klog:go_default_library",
         "//vendor/k8s.io/kube-openapi/pkg/handler:go_default_library",

staging/src/k8s.io/apiextensions-apiserver/pkg/controller/openapi/controller.go

@@ -168,11 +168,13 @@ func (c *Controller) sync(name string) error {
 			return nil
 		}
 		delete(c.crdSpecs, name)
+		klog.V(2).Infof("Updating CRD OpenAPI spec because %s was removed", name)
+		regenerationCounter.With(map[string]string{"crd": name, "reason": "remove"})
 		return c.updateSpecLocked()
 	}
 
 	// compute CRD spec and see whether it changed
-	oldSpecs := c.crdSpecs[crd.Name]
+	oldSpecs, updated := c.crdSpecs[crd.Name]
 	newSpecs, changed, err := buildVersionSpecs(crd, oldSpecs)
 	if err != nil {
 		return err
@@ -183,6 +185,12 @@ func (c *Controller) sync(name string) error {
 
 	// update specs of this CRD
 	c.crdSpecs[crd.Name] = newSpecs
+	klog.V(2).Infof("Updating CRD OpenAPI spec because %s changed", name)
+	reason := "add"
+	if updated {
+		reason = "update"
+	}
+	regenerationCounter.With(map[string]string{"crd": name, "reason": reason})
 	return c.updateSpecLocked()
 }
 

staging/src/k8s.io/apiextensions-apiserver/pkg/controller/openapi/metrics.go

@@ -0,0 +1,37 @@
+/*
+Copyright 2019 The Kubernetes Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package openapi
+
+import (
+	"k8s.io/component-base/metrics"
+	"k8s.io/component-base/metrics/legacyregistry"
+)
+
+var (
+	regenerationCounter = metrics.NewCounterVec(
+		&metrics.CounterOpts{
+			Name:           "apiextensions_openapi_v2_regeneration_count",
+			Help:           "Counter of OpenAPI v2 spec regeneration count broken down by causing CRD name and reason.",
+			StabilityLevel: metrics.ALPHA,
+		},
+		[]string{"crd", "reason"},
+	)
+)
+
+func init() {
+	legacyregistry.MustRegister(regenerationCounter)
+}

staging/src/k8s.io/kube-aggregator/pkg/controllers/openapi/aggregator/BUILD

@@ -5,6 +5,7 @@ go_library(
     srcs = [
         "aggregator.go",
         "downloader.go",
+        "metrics.go",
         "priority.go",
     ],
     importmap = "k8s.io/kubernetes/vendor/k8s.io/kube-aggregator/pkg/controllers/openapi/aggregator",
@@ -14,9 +15,12 @@ go_library(
         "//staging/src/k8s.io/apiserver/pkg/authentication/user:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/server:go_default_library",
+        "//staging/src/k8s.io/component-base/metrics:go_default_library",
+        "//staging/src/k8s.io/component-base/metrics/legacyregistry:go_default_library",
         "//staging/src/k8s.io/kube-aggregator/pkg/apis/apiregistration/v1:go_default_library",
         "//vendor/github.com/emicklei/go-restful:go_default_library",
         "//vendor/github.com/go-openapi/spec:go_default_library",
+        "//vendor/k8s.io/klog:go_default_library",
         "//vendor/k8s.io/kube-openapi/pkg/aggregator:go_default_library",
         "//vendor/k8s.io/kube-openapi/pkg/builder:go_default_library",
         "//vendor/k8s.io/kube-openapi/pkg/common:go_default_library",

staging/src/k8s.io/kube-aggregator/pkg/controllers/openapi/aggregator/aggregator.go

@@ -26,8 +26,10 @@ import (
 	restful "github.com/emicklei/go-restful"
 	"github.com/go-openapi/spec"
 
+	"k8s.io/klog"
+
 	"k8s.io/apiserver/pkg/server"
-	"k8s.io/kube-aggregator/pkg/apis/apiregistration/v1"
+	v1 "k8s.io/kube-aggregator/pkg/apis/apiregistration/v1"
 	"k8s.io/kube-openapi/pkg/aggregator"
 	"k8s.io/kube-openapi/pkg/builder"
 	"k8s.io/kube-openapi/pkg/common"
@@ -104,6 +106,14 @@ func BuildAndRegisterAggregator(downloader *Downloader, delegationTarget server.
 	}
 
 	// Build initial spec to serve.
+	klog.V(2).Infof("Building initial OpenAPI spec")
+	defer func(start time.Time) {
+		duration := time.Now().Sub(start)
+		klog.V(2).Infof("Finished initial OpenAPI spec generation after %v", duration)
+
+		regenerationCounter.With(map[string]string{"apiservice": "*", "reason": "startup"})
+		regenerationDurationGauge.With(map[string]string{"reason": "startup"}).Set(duration.Seconds())
+	}(time.Now())
 	specToServe, err := s.buildOpenAPISpec()
 	if err != nil {
 		return nil, err
@@ -202,13 +212,27 @@ func (s *specAggregator) tryUpdatingServiceSpecs(specInfo *openAPISpecInfo) erro
 	if specInfo == nil {
 		return fmt.Errorf("invalid input: specInfo must be non-nil")
 	}
+	_, updated := s.openAPISpecs[specInfo.apiService.Name]
 	origSpecInfo, existedBefore := s.openAPISpecs[specInfo.apiService.Name]
 	s.openAPISpecs[specInfo.apiService.Name] = specInfo
 
 	// Skip aggregation if OpenAPI spec didn't change
 	if existedBefore && origSpecInfo != nil && origSpecInfo.etag == specInfo.etag {
 		return nil
 	}
+	klog.V(2).Infof("Updating OpenAPI spec because %s is updated", specInfo.apiService.Name)
+	defer func(start time.Time) {
+		duration := time.Now().Sub(start)
+		klog.V(2).Infof("Finished OpenAPI spec generation after %v", duration)
+
+		reason := "add"
+		if updated {
+			reason = "update"
+		}
+
+		regenerationCounter.With(map[string]string{"apiservice": specInfo.apiService.Name, "reason": reason})
+		regenerationDurationGauge.With(map[string]string{"reason": reason}).Set(duration.Seconds())
+	}(time.Now())
 	if err := s.updateOpenAPISpec(); err != nil {
 		if existedBefore {
 			s.openAPISpecs[specInfo.apiService.Name] = origSpecInfo
@@ -228,6 +252,14 @@ func (s *specAggregator) tryDeleteServiceSpecs(apiServiceName string) error {
 		return nil
 	}
 	delete(s.openAPISpecs, apiServiceName)
+	klog.V(2).Infof("Updating OpenAPI spec because %s is removed", apiServiceName)
+	defer func(start time.Time) {
+		duration := time.Now().Sub(start)
+		klog.V(2).Infof("Finished OpenAPI spec generation after %v", duration)
+
+		regenerationCounter.With(map[string]string{"apiservice": apiServiceName, "reason": "delete"})
+		regenerationDurationGauge.With(map[string]string{"reason": "delete"}).Set(duration.Seconds())
+	}(time.Now())
 	if err := s.updateOpenAPISpec(); err != nil {
 		s.openAPISpecs[apiServiceName] = orgSpecInfo
 		return err

staging/src/k8s.io/kube-aggregator/pkg/controllers/openapi/aggregator/metrics.go

@@ -0,0 +1,46 @@
+/*
+Copyright 2019 The Kubernetes Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package aggregator
+
+import (
+	"k8s.io/component-base/metrics"
+	"k8s.io/component-base/metrics/legacyregistry"
+)
+
+var (
+	regenerationCounter = metrics.NewCounterVec(
+		&metrics.CounterOpts{
+			Name:           "aggregator_openapi_v2_regeneration_count",
+			Help:           "Counter of OpenAPI v2 spec regeneration count broken down by causing APIService name and reason.",
+			StabilityLevel: metrics.ALPHA,
+		},
+		[]string{"apiservice", "reason"},
+	)
+	regenerationDurationGauge = metrics.NewGaugeVec(
+		&metrics.GaugeOpts{
+			Name:           "aggregator_openapi_v2_regeneration_duration",
+			Help:           "Gauge of OpenAPI v2 spec regeneration duration in seconds.",
+			StabilityLevel: metrics.ALPHA,
+		},
+		[]string{"reason"},
+	)
+)
+
+func init() {
+	legacyregistry.MustRegister(regenerationCounter)
+	legacyregistry.MustRegister(regenerationDurationGauge)
+}

vendor/modules.txt

@@ -1637,6 +1637,7 @@ k8s.io/component-base/featuregate
 k8s.io/component-base/featuregate/testing
 k8s.io/component-base/logs
 k8s.io/component-base/metrics
+k8s.io/component-base/metrics/legacyregistry
 k8s.io/component-base/version
 # k8s.io/cri-api v0.0.0 => ./staging/src/k8s.io/cri-api
 k8s.io/cri-api/pkg/apis