Add support for JSON logging #1467

torredil · 2023-01-03T21:56:55Z

Is this a bug fix or adding new feature?

New feature.

What is this PR about? / Why do we need it?

Add support for JSON logging: Introduce logging-format driver option for the controller and node pods to set the log format. Permitted formats: text (default), json.
Migrate to Structured Logging. For more information see: Structured and Contextual Logging migration instructions.
Remove deprecated logtostderr flag. For more information see: KEP-2845: Deprecate klog specific flags in Kubernetes Components.
Updated relevant documentation.
closes Support JSON logging using klog library #1310.

What testing is done?

CI
Manual testing instructions:
1. Pull changes locally and build driver container image.
2. Modify loggingFormat: text -> loggingFormat: json in charts/aws-ebs-csi-driver/values.yaml.
3. Deploy driver via Helm: helm upgrade --install aws-ebs-csi-driver --namespace kube-system ./charts/aws-ebs-csi-driver --values ./charts/aws-ebs-csi-driver/values.yaml.

Testing logs

(loggingFormat: text):

$ kubectl describe pod ebs-csi-controller-7bff9cbf9d-58kwm -n kube-system

Name:                 ebs-csi-controller-7bff9cbf9d-58kwm
...
Containers:
  ebs-plugin:
    Container ID:  containerd://aaf3708e4972e38ab437003d1f2a3e1f40635f7bce423a9b28b29177bb63e6e3
    Image:         docker.io/torredil/aws-ebs-csi-driver:d37380af19bbfc1cb35ac024cca52d7fe8b4ad81
    Image ID:      docker.io/torredil/aws-ebs-csi-driver@sha256:37f7fa0a9a38123c68a5c4356882b973b464b2ec5057ca8c275ec547e2d9942d
    Port:          9808/TCP
    Host Port:     0/TCP
    Args:
      controller
      --endpoint=$(CSI_ENDPOINT)
      --logging-format=text
      --v=2
      
      
$ kubectl logs ebs-csi-controller-7bff9cbf9d-58kwm -n kube-system -c ebs-plugin

I0103 21:42:25.828855       1 metadata.go:85] "retrieving instance data from ec2 metadata"
I0103 21:42:25.839042       1 metadata.go:92] "ec2 metadata is available"
I0103 21:42:25.840023       1 metadata_ec2.go:25] "Retrieveing EC2 instance identity metadata" regionFromSession=""

(loggingFormat: json):

$ kubectl describe pod ebs-csi-controller-7645d645-qzrcx -n kube-system

Name:                 ebs-csi-controller-7645d645-qzrcx
...
Containers:
  ebs-plugin:
    Container ID:  containerd://cd4f78d05070f8d6c76c79f7e7841783f02d34529e36b9540b19a944b1ea8760
    Image:         docker.io/torredil/aws-ebs-csi-driver:d37380af19bbfc1cb35ac024cca52d7fe8b4ad81
    Image ID:      docker.io/torredil/aws-ebs-csi-driver@sha256:37f7fa0a9a38123c68a5c4356882b973b464b2ec5057ca8c275ec547e2d9942d
    Port:          9808/TCP
    Host Port:     0/TCP
    Args:
      controller
      --endpoint=$(CSI_ENDPOINT)
      --logging-format=json
      --v=2
      
$ kubectl logs ebs-csi-controller-7645d645-qzrcx -n kube-system -c ebs-plugin

{"ts":1672782461904.7024,"caller":"cloud/metadata.go:85","msg":"retrieving instance data from ec2 metadata","v":0}
{"ts":1672782461917.3455,"caller":"cloud/metadata.go:92","msg":"ec2 metadata is available","v":0}
{"ts":1672782461918.2651,"caller":"cloud/metadata_ec2.go:25","msg":"Retrieveing EC2 instance identity metadata","v":0,"regionFromSession":""}

(loggingFormat: json) | logLevel: 6.

$ kubectl describe pod ebs-csi-controller-86c7449547-ll84m -n kube-system

Name:                 ebs-csi-controller-86c7449547-ll84m
...
    Args:
      controller
      --endpoint=$(CSI_ENDPOINT)
      --logging-format=json
      --v=6
      
$ kubectl logs ebs-csi-controller-86c7449547-ll84m -n kube-system -c ebs-plugin

{"ts":1672782835169.6929,"caller":"driver/driver.go:73","msg":"Driver Information","v":4,"Driver":"ebs.csi.aws.com","Version":"v1.14.0"}
{"ts":1672782835169.7332,"caller":"driver/controller.go:82","msg":"[Debug] Retrieving region from metadata service","v":5}
{"ts":1672782835169.7505,"caller":"cloud/metadata.go:85","msg":"retrieving instance data from ec2 metadata","v":0}
{"ts":1672782835172.3145,"caller":"cloud/metadata.go:92","msg":"ec2 metadata is available","v":0}
{"ts":1672782835173.2476,"caller":"cloud/metadata_ec2.go:25","msg":"Retrieveing EC2 instance identity metadata","v":0,"regionFromSession":""}
{"ts":1672782835177.0625,"caller":"driver/driver.go:143","msg":"Listening for connections","v":4,"address":"/var/lib/csi/sockets/pluginproxy/csi.sock"}
{"ts":1672782835274.995,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835275.761,"caller":"driver/identity.go:27","msg":"GetPluginInfo: called","v":6,"args":{}}
{"ts":1672782835276.9556,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835277.2979,"caller":"driver/identity.go:37","msg":"GetPluginCapabilities: called","v":6,"args":{}}
{"ts":1672782835277.9148,"caller":"driver/controller.go:416","msg":"ControllerGetCapabilities: called","v":4,"args":{}}
{"ts":1672782835388.9587,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835389.6196,"caller":"driver/identity.go:27","msg":"GetPluginInfo: called","v":6,"args":{}}
{"ts":1672782835390.958,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835391.306,"caller":"driver/identity.go:37","msg":"GetPluginCapabilities: called","v":6,"args":{}}
{"ts":1672782835391.7463,"caller":"driver/controller.go:416","msg":"ControllerGetCapabilities: called","v":4,"args":{}}
{"ts":1672782835524.8044,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835525.4236,"caller":"driver/identity.go:27","msg":"GetPluginInfo: called","v":6,"args":{}}
{"ts":1672782835526.804,"caller":"driver/identity.go:61","msg":"Probe: called","v":6,"args":{}}
{"ts":1672782835527.1367,"caller":"driver/identity.go:37","msg":"GetPluginCapabilities: called","v":6,"args":{}}
{"ts":1672782835527.6257,"caller":"driver/controller.go:416","msg":"ControllerGetCapabilities: called","v":4,"args":{}}
{"ts":1672782835528.082,"caller":"driver/controller.go:416","msg":"ControllerGetCapabilities: called","v":4,"args":{}}
{"ts":1672782835647.2812,"caller":"driver/identity.go:27","msg":"GetPluginInfo: called","v":6,"args":{}}

Signed-off-by: Eddie Torres [email protected]

rdpsin · 2023-01-03T22:10:22Z

charts/aws-ebs-csi-driver/values.yaml

@@ -112,6 +112,7 @@ fullnameOverride:
 controller:
  additionalArgs: []
  sdkDebugLog: false
+  loggingFormat: text


Not now, but we should consider making JSON the default sometime in the future.

Looking at the proposal, they seem to have text as default. Do we want to have this changed prematurely, considering that this will render the divergence between the default formats for core k8s and CSI driver's logs, which may not be a good customer experience?

My feeling is that we should keep the parity with k8s on that. When they change the default setting, it will make sense for us to do the same.

In my opinion, we should keep the same default as k8s unless we have a strong reason not to do so.

cmd/main.go

ConnorJC3

Some minor nits. Largely lgtm other than fixing the known helm chart bug.

charts/aws-ebs-csi-driver/templates/controller.yaml

ConnorJC3 · 2023-01-11T18:41:03Z

cmd/options_test.go

@@ -56,20 +57,19 @@ func TestGetOptions(t *testing.T) {
 		}, additionalArgs...)

 		if withServerOptions {
-			args = append(args, "-"+endpointFlagName+"="+endpoint)
+			args = append(args, "--"+endpointFlagName+"="+endpoint)


Do the previous versions not work anymore? Do we care about this theoretically breaking change?

To provide some context, this change was introduced as a result of migrating to the pflag package which is a "drop-in replacement for Go's flag package". This flag type is used to add the component-based flags: https://pkg.go.dev/k8s.io/component-base/logs/api/v1#AddFlags.

Unlike Go's standard flag package, when using the pflag package, a single dash before an option means something different than a double dash. Single dashes signify a series of shorthand letters for flags. Hence this change.

The new behavior for using the "shorthand flags" - is as follows:

$ ./aws-ebs-csi-driver -aws-sdk-debug-log=true unknown shorthand flag: 'a' in -aws-sdk-debug-log=true

It is common convention to use a single hyphen - to specify a single character flag, and a double hyphen -- to specify a keyword flag so I don't believe this change is particularly dangerous but if it is a concern we could theoretically support shorthand flags as well.

I think this is an acceptable justification, but we MUST make sure to call this out in the changelog.

pkg/cloud/cloud.go

pkg/driver/node.go

pkg/util/template/template.go

vkuzniet · 2023-01-13T19:25:41Z

cmd/main.go

 	"k8s.io/component-base/metrics/legacyregistry"

 	"k8s.io/klog/v2"
 )

 func main() {
 	fs := flag.NewFlagSet("aws-ebs-csi-driver", flag.ExitOnError)
+
+	if err := logsapi.RegisterLogFormat(logsapi.JSONLogFormat, json.Factory{}, logsapi.LoggingBetaOptions); err != nil {


If we go with the default logging format, e.g. text, do we still need to register json log format?

Similar to other K8s components such as Kubelet we register supported log formats as early possible and before the flag is set, as this information needs to be known in advance:

https://github.com/kubernetes/component-base/blob/33f62c7b28186a591e1b25e900fe573ed296e181/logs/api/v1/options.go#L186 (names of registered log formats retrieved) -> https://github.com/kubernetes/component-base/blob/33f62c7b28186a591e1b25e900fe573ed296e181/logs/api/v1/options.go#L187 (logging-format flag is added, listing permitted formats).

charts/aws-ebs-csi-driver/values.yaml

ConnorJC3 · 2023-01-18T21:10:12Z

cmd/options_test.go

@@ -56,20 +57,19 @@ func TestGetOptions(t *testing.T) {
 		}, additionalArgs...)

 		if withServerOptions {
-			args = append(args, "-"+endpointFlagName+"="+endpoint)
+			args = append(args, "--"+endpointFlagName+"="+endpoint)


I think this is an acceptable justification, but we MUST make sure to call this out in the changelog.

Introduce logging-format driver option for the controller and node pods to set the log format. Permitted formats: text (default), json. Migrate to Structured Logging. Deprecate logtostderr flag. Signed-off-by: Eddie Torres <[email protected]>

ConnorJC3 · 2023-01-18T22:25:15Z

/lgtm

If there are no additional comments/issues brought up, I will be approving this PR for merge at the end of Friday, January 20th.

vkuzniet · 2023-01-20T15:46:11Z

/lgtm

k8s-ci-robot · 2023-01-20T15:46:15Z

@vkuzniet: changing LGTM is restricted to collaborators

In response to this:

/lgtm

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

ConnorJC3 · 2023-01-23T05:24:49Z

/approve

k8s-ci-robot · 2023-01-23T05:25:00Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: ConnorJC3

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [ConnorJC3]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

It has been deprecated upstream, kubernetes-sigs/aws-ebs-csi-driver#1467

torredil requested review from ConnorJC3 and rdpsin January 3, 2023 21:56

torredil self-assigned this Jan 3, 2023

k8s-ci-robot added cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Jan 3, 2023

torredil marked this pull request as draft January 3, 2023 21:57

k8s-ci-robot added the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Jan 3, 2023

rdpsin reviewed Jan 3, 2023

View reviewed changes

torredil force-pushed the log-format-json branch from 44ea899 to f310cf4 Compare January 3, 2023 22:37

torredil marked this pull request as ready for review January 3, 2023 22:41

k8s-ci-robot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Jan 3, 2023

k8s-ci-robot requested review from gtxu and rdpsin January 3, 2023 22:41

torredil force-pushed the log-format-json branch 2 times, most recently from 5d4903b to 20a5fe7 Compare January 4, 2023 20:08

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jan 6, 2023

torredil force-pushed the log-format-json branch from 20a5fe7 to 5d0b388 Compare January 6, 2023 17:06

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jan 6, 2023

torredil force-pushed the log-format-json branch from 5d0b388 to d41be12 Compare January 6, 2023 17:19

ConnorJC3 reviewed Jan 11, 2023

View reviewed changes

torredil force-pushed the log-format-json branch from d41be12 to cdf7c53 Compare January 11, 2023 19:31

vkuzniet reviewed Jan 13, 2023

View reviewed changes

torredil force-pushed the log-format-json branch 2 times, most recently from c198b38 to edddc1f Compare January 17, 2023 17:14

kubernetes-sigs deleted a comment from ConnorJC3 Jan 18, 2023

torredil mentioned this pull request Jan 18, 2023

Use test driver image when testing upgrades with CT #1486

Merged

torredil force-pushed the log-format-json branch 2 times, most recently from ae59c6c to a58eb8c Compare January 18, 2023 20:38

ConnorJC3 reviewed Jan 18, 2023

View reviewed changes

torredil force-pushed the log-format-json branch from a58eb8c to ab6b587 Compare January 18, 2023 22:06

Add support for JSON logging

ad25982

Introduce logging-format driver option for the controller and node pods to set the log format. Permitted formats: text (default), json. Migrate to Structured Logging. Deprecate logtostderr flag. Signed-off-by: Eddie Torres <[email protected]>

torredil force-pushed the log-format-json branch from ab6b587 to ad25982 Compare January 18, 2023 22:16

k8s-ci-robot assigned ConnorJC3 Jan 18, 2023

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jan 18, 2023

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jan 23, 2023

k8s-ci-robot merged commit 27e2601 into kubernetes-sigs:master Jan 23, 2023

jsafrane added a commit to jsafrane/aws-ebs-csi-driver-operator that referenced this pull request Apr 26, 2023

Remove --logtostderr driver option

aacc6cc

It has been deprecated upstream, kubernetes-sigs/aws-ebs-csi-driver#1467

jacobwolfaws mentioned this pull request May 12, 2023

Adopting Multiple CSI Driver improvements kubernetes-sigs/aws-fsx-csi-driver#309

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add support for JSON logging #1467

Add support for JSON logging #1467

torredil commented Jan 3, 2023

rdpsin Jan 3, 2023

vkuzniet Jan 13, 2023

ConnorJC3 Jan 13, 2023

ConnorJC3 left a comment

ConnorJC3 Jan 11, 2023

torredil Jan 11, 2023

ConnorJC3 Jan 18, 2023

vkuzniet Jan 13, 2023

torredil Jan 18, 2023

ConnorJC3 Jan 18, 2023

ConnorJC3 commented Jan 18, 2023

vkuzniet commented Jan 20, 2023

k8s-ci-robot commented Jan 20, 2023

ConnorJC3 commented Jan 23, 2023

k8s-ci-robot commented Jan 23, 2023

Add support for JSON logging #1467

Add support for JSON logging #1467

Conversation

torredil commented Jan 3, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ConnorJC3 left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ConnorJC3 commented Jan 18, 2023

vkuzniet commented Jan 20, 2023

k8s-ci-robot commented Jan 20, 2023

ConnorJC3 commented Jan 23, 2023

k8s-ci-robot commented Jan 23, 2023