Merge pull request kubernetes#1807 from dmpe/strcuturedlogging_part1

feat(logging): migration to structure logging for main.go, pkg/ & internal/ folders

internal/store/builder.go

@@ -178,7 +178,7 @@ func (b *Builder) WithCustomResourceStoreFactories(fs ...customresource.Registry
 	for i := range fs {
 		f := fs[i]
 		if _, ok := availableStores[f.Name()]; ok {
-			klog.Warningf("The internal resource store named %s already exists and is overridden by a custom resource store with the same name, please make sure it meets your expectation", f.Name())
+			klog.InfoS("The internal resource store already exists and is overridden by a custom resource store with the same name, please make sure it meets your expectation", "registryName", f.Name())
 		}
 		availableStores[f.Name()] = func(b *Builder) []cache.Store {
 			return b.buildCustomResourceStoresFunc(
@@ -230,7 +230,7 @@ func (b *Builder) Build() []metricsstore.MetricsWriter {
 		}
 	}
 
-	klog.Infof("Active resources: %s", strings.Join(activeStoreNames, ","))
+	klog.InfoS("Active resources", "activeStoreNames", strings.Join(activeStoreNames, ","))
 
 	return metricsWriters
 }
@@ -255,7 +255,7 @@ func (b *Builder) BuildStores() [][]cache.Store {
 		}
 	}
 
-	klog.Infof("Active resources: %s", strings.Join(activeStoreNames, ","))
+	klog.InfoS("Active resources", "activeStoreNames", strings.Join(activeStoreNames, ","))
 
 	return allStores
 }
@@ -483,7 +483,7 @@ func (b *Builder) buildCustomResourceStores(resourceName string,
 
 	customResourceClient, ok := b.customResourceClients[resourceName]
 	if !ok {
-		klog.Warningf("Custom resource client %s does not exist", resourceName)
+		klog.InfoS("Custom resource client does not exist", "resourceName", resourceName)
 		return []cache.Store{}
 	}
 

main.go

@@ -38,7 +38,8 @@ func main() {
 	opts.AddFlags()
 
 	if err := opts.Parse(); err != nil {
-		klog.Fatalf("Parsing flag definitions error: %v", err)
+		klog.ErrorS(err, "Parsing flag definitions error")
+		klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 	}
 
 	if opts.Version {
@@ -55,14 +56,16 @@ func main() {
 	if config, set := resolveCustomResourceConfig(opts); set {
 		crf, err := customresourcestate.FromConfig(config)
 		if err != nil {
-			klog.Fatal(err)
+			klog.ErrorS(err, "Parsing from Custom Resource State Metrics file failed")
+			klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 		}
 		factories = append(factories, crf...)
 	}
 
 	ctx := context.Background()
 	if err := app.RunKubeStateMetrics(ctx, opts, factories...); err != nil {
-		klog.Fatalf("Failed to run kube-state-metrics: %v", err)
+		klog.ErrorS(err, "Failed to run kube-state-metrics")
+		klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 	}
 }
 
@@ -73,7 +76,8 @@ func resolveCustomResourceConfig(opts *options.Options) (customresourcestate.Con
 	if file := opts.CustomResourceConfigFile; file != "" {
 		f, err := os.Open(file)
 		if err != nil {
-			klog.Fatal(err)
+			klog.ErrorS(err, "Custom Resource State Metrics file could not be opened")
+			klog.FlushAndExit(klog.ExitFlushTimeout, 1)
 		}
 		return yaml.NewDecoder(f), true
 	}

pkg/app/server.go

@@ -89,14 +89,14 @@ func RunKubeStateMetrics(ctx context.Context, opts *options.Options, factories .
 
 	var resources []string
 	if len(opts.Resources) == 0 {
-		klog.Info("Using default resources")
+		klog.InfoS("Used default resources")
 		resources = options.DefaultResources.AsSlice()
 		// enable custom resource
 		for _, factory := range factories {
 			resources = append(resources, factory.Name())
 		}
 	} else {
-		klog.Infof("Using resources %s", opts.Resources.String())
+		klog.InfoS("Used resources", "resources", opts.Resources.String())
 		resources = opts.Resources.AsSlice()
 	}
 
@@ -118,15 +118,15 @@ func RunKubeStateMetrics(ctx context.Context, opts *options.Options, factories .
 		return fmt.Errorf("error initializing the allowdeny list: %v", err)
 	}
 
-	klog.Infof("Metric allow-denylisting: %v", allowDenyList.Status())
+	klog.InfoS("Metric allow-denylisting", "allowDenyStatus", allowDenyList.Status())
 
 	optInMetricFamilyFilter, err := optin.NewMetricFamilyFilter(opts.MetricOptInList)
 	if err != nil {
 		return fmt.Errorf("error initializing the opt-in metric list: %v", err)
 	}
 
 	if optInMetricFamilyFilter.Count() > 0 {
-		klog.Infof("Metrics which were opted into: %v", optInMetricFamilyFilter.Status())
+		klog.InfoS("Metrics which were opted into", "optInMetricsFamilyStatus", optInMetricFamilyFilter.Status())
 	}
 
 	storeBuilder.WithFamilyGeneratorFilter(generator.NewCompositeFamilyGeneratorFilter(
@@ -187,7 +187,7 @@ func RunKubeStateMetrics(ctx context.Context, opts *options.Options, factories .
 	// Run Telemetry server
 	{
 		g.Add(func() error {
-			klog.Infof("Starting kube-state-metrics self metrics server: %s", telemetryListenAddress)
+			klog.InfoS("Started kube-state-metrics self metrics server", "telemetryAddress", telemetryListenAddress)
 			return web.ListenAndServe(&telemetryServer, tlsConfig, promLogger)
 		}, func(error) {
 			ctxShutDown, cancel := context.WithTimeout(ctx, 3*time.Second)
@@ -198,7 +198,7 @@ func RunKubeStateMetrics(ctx context.Context, opts *options.Options, factories .
 	// Run Metrics server
 	{
 		g.Add(func() error {
-			klog.Infof("Starting metrics server: %s", metricsServerListenAddress)
+			klog.InfoS("Started metrics server", "metricsServerAddress", metricsServerListenAddress)
 			return web.ListenAndServe(&metricsServer, tlsConfig, promLogger)
 		}, func(error) {
 			ctxShutDown, cancel := context.WithTimeout(ctx, 3*time.Second)
@@ -210,7 +210,7 @@ func RunKubeStateMetrics(ctx context.Context, opts *options.Options, factories .
 	if err := g.Run(); err != nil {
 		return fmt.Errorf("run server group error: %v", err)
 	}
-	klog.Info("Exiting")
+	klog.InfoS("Exited")
 	return nil
 }
 
@@ -246,14 +246,13 @@ func createKubeClient(apiserver string, kubeconfig string, factories ...customre
 	// Informers don't seem to do a good job logging error messages when it
 	// can't reach the server, making debugging hard. This makes it easier to
 	// figure out if apiserver is configured incorrectly.
-	klog.Infof("Testing communication with server")
+	klog.InfoS("Tested communication with server")
 	v, err := kubeClient.Discovery().ServerVersion()
 	if err != nil {
 		return nil, nil, nil, fmt.Errorf("error while trying to communicate with apiserver: %w", err)
 	}
-	klog.Infof("Running with Kubernetes cluster version: v%s.%s. git version: %s. git tree state: %s. commit: %s. platform: %s",
-		v.Major, v.Minor, v.GitVersion, v.GitTreeState, v.GitCommit, v.Platform)
-	klog.Infof("Communication with server successful")
+	klog.InfoS("Run with Kubernetes cluster version", "major", v.Major, "minor", v.Minor, "gitVersion", v.GitVersion, "gitTreeState", v.GitTreeState, "gitCommit", v.GitCommit, "platform", v.Platform)
+	klog.InfoS("Communication with server successful")
 
 	return kubeClient, vpaClient, customResourceClients, nil
 }

pkg/customresourcestate/registry_factory.go

@@ -440,7 +440,7 @@ func compilePath(path []string) (out valuePath, _ error) {
 }
 
 func (s fieldMetrics) MetricFamilyGenerators(_, _ []string) (result []generator.FamilyGenerator) {
-	klog.Infof("custom resource state adding metrics: %v", s.names())
+	klog.InfoS("Custom resource state added metrics", "familyNames", s.names())
 	for _, f := range s.Families {
 		result = append(result, famGen(f))
 	}
@@ -461,7 +461,7 @@ func famGen(f compiledFamily) generator.FamilyGenerator {
 }
 
 func generate(u *unstructured.Unstructured, f compiledFamily, errLog klog.Verbose) *metric.Family {
-	klog.V(10).Infof("%s: checking %s", f.Name, u.GetName())
+	klog.V(10).InfoS("Checked", "compiledFamilyName", f.Name, "unstructuredName", u.GetName())
 	var metrics []*metric.Metric
 	baseLabels := f.BaseLabels(u.Object)
 	values, errors := f.Each.Values(u.Object)
@@ -474,7 +474,7 @@ func generate(u *unstructured.Unstructured, f compiledFamily, errLog klog.Verbos
 		v.DefaultLabels(baseLabels)
 		metrics = append(metrics, v.ToMetric())
 	}
-	klog.V(10).Infof("%s: produced %d metrics for %s", f.Name, len(metrics), u.GetName())
+	klog.V(10).InfoS("Produced metrics for", "compiledFamilyName", f.Name, "metricsLength", len(metrics), "unstructuredName", u.GetName())
 
 	return &metric.Family{
 		Metrics: metrics,

pkg/metricshandler/metrics_handler.go

@@ -77,7 +77,7 @@ func (m *MetricsHandler) ConfigureSharding(ctx context.Context, shard int32, tot
 		m.cancel()
 	}
 	if totalShards != 1 {
-		klog.Infof("configuring sharding of this instance to be shard index %d (zero-indexed) out of %d total shards", shard, totalShards)
+		klog.InfoS("Configuring sharding of this instance to be shard index (zero-indexed) out of total shards", "shard", shard, "totalShards", totalShards)
 	}
 	ctx, m.cancel = context.WithCancel(ctx)
 	m.storeBuilder.WithSharding(shard, totalShards)
@@ -94,14 +94,14 @@ func (m *MetricsHandler) Run(ctx context.Context) error {
 	autoSharding := len(m.opts.Pod) > 0 && len(m.opts.Namespace) > 0
 
 	if !autoSharding {
-		klog.Info("Autosharding disabled")
+		klog.InfoS("Autosharding disabled")
 		m.ConfigureSharding(ctx, m.opts.Shard, m.opts.TotalShards)
 		<-ctx.Done()
 		return ctx.Err()
 	}
 
-	klog.Infof("Autosharding enabled with pod=%v pod_namespace=%v", m.opts.Pod, m.opts.Namespace)
-	klog.Infof("Auto detecting sharding settings.")
+	klog.InfoS("Autosharding enabled with pod", "pod", klog.KRef(m.opts.Namespace, m.opts.Pod))
+	klog.InfoS("Auto detecting sharding settings")
 	ss, err := detectStatefulSet(m.kubeClient, m.opts.Pod, m.opts.Namespace)
 	if err != nil {
 		return fmt.Errorf("detect StatefulSet: %w", err)
@@ -125,7 +125,7 @@ func (m *MetricsHandler) Run(ctx context.Context) error {
 
 			shard, totalShards, err := shardingSettingsFromStatefulSet(ss, m.opts.Pod)
 			if err != nil {
-				klog.Errorf("detect sharding settings from StatefulSet: %v", err)
+				klog.ErrorS(err, "Detected sharding settings from StatefulSet")
 				return
 			}
 
@@ -152,7 +152,7 @@ func (m *MetricsHandler) Run(ctx context.Context) error {
 
 			shard, totalShards, err := shardingSettingsFromStatefulSet(cur, m.opts.Pod)
 			if err != nil {
-				klog.Errorf("detect sharding settings from StatefulSet: %v", err)
+				klog.ErrorS(err, "Detected sharding settings from StatefulSet")
 				return
 			}
 

pkg/options/types.go

@@ -133,13 +133,13 @@ func (n *NamespaceList) Set(value string) error {
 func (n *NamespaceList) GetNamespaces() NamespaceList {
 	ns := *n
 	if len(*n) == 0 {
-		klog.Info("Using all namespace")
+		klog.InfoS("Using all namespaces")
 		ns = DefaultNamespaces
 	} else {
 		if n.IsAllNamespaces() {
-			klog.Info("Using all namespace")
+			klog.InfoS("Using all namespaces")
 		} else {
-			klog.Infof("Using %s namespaces", ns)
+			klog.InfoS("Using namespaces", "nameSpaces", ns)
 		}
 	}
 	return ns

pkg/util/proc/reaper.go

@@ -31,22 +31,22 @@ import (
 // that has pid 1.
 func StartReaper() {
 	if os.Getpid() == 1 {
-		klog.V(4).Infof("Launching reaper")
+		klog.V(4).InfoS("Launching reaper")
 		go func() {
 			sigs := make(chan os.Signal, 1)
 			signal.Notify(sigs, syscall.SIGCHLD)
 			for {
 				// Wait for a child to terminate
 				sig := <-sigs
-				klog.V(4).Infof("Signal received: %v", sig)
+				klog.V(4).InfoS("Signal received", "signal", sig)
 				for {
 					// Reap processes
 					cpid, _ := syscall.Wait4(-1, nil, syscall.WNOHANG, nil)
 					if cpid < 1 {
 						break
 					}
 
-					klog.V(4).Infof("Reaped process with pid %d", cpid)
+					klog.V(4).InfoS("Reaped process with pid", "cpid", cpid)
 				}
 			}
 		}()