Add GoFlag in CommandLine #3884

satya-dillikar · 2021-12-02T00:48:35Z

Description of the change

Adding GoFlag command-line argument to kubeapps-apis binary.

Benefits

Developers can control the verbosity (--v) of log levels.

Possible drawbacks

A bunch of more flags are listed in usage/help.

Applicable issues

fixes #

Additional information

PR 3766

satya-dillikar · 2021-12-02T00:55:27Z

Usage/Help output


go run main.go --help
kubeapps-apis is a plugin-based API server for interacting with Kubernetes packages.

The api service serves both gRPC and HTTP requests for the configured APIs.

Usage:
  kubeapps-apis [flags]

Flags:
      --add_dir_header                   If true, adds the file directory to the header of the log messages
      --alsologtostderr                  log to standard error as well as files
      --clusters-config-path string      Configuration for clusters
      --config string                    config file (default is $HOME/.kubeapps-apis.yaml)
  -h, --help                             help for kubeapps-apis
      --log_backtrace_at traceLocation   when logging hits line file:N, emit a stack trace (default :0)
      --log_dir string                   If non-empty, write log files in this directory
      --log_file string                  If non-empty, use this log file
      --log_file_max_size uint           Defines the maximum size a log file can grow to. Unit is megabytes. If the value is 0, the maximum file size is unlimited. (default 1800)
      --logtostderr                      log to standard error instead of files (default true)
      --one_output                       If true, only write logs to their native severity level (vs also writing to each lower severity level)
      --pinniped-proxy-url string        internal url to be used for requests to clusters configured for credential proxying via pinniped (default "http://kubeapps-internal-pinniped-proxy.kubeapps:3333")
      --plugin-config-path string        Configuration for plugins
      --plugin-dir strings               A directory to be scanned for .so plugins. May be specified multiple times. (default [.])
      --port int                         The port on which to run this api server. Both gRPC and HTTP requests will be served on this port. (default 50051)
      --skip_headers                     If true, avoid header prefixes in the log messages
      --skip_log_headers                 If true, avoid headers when opening log files
      --stderrthreshold severity         logs at or above this threshold go to stderr (default 2)
      --unsafe-local-dev-kubeconfig      if true, it will use the local kubeconfig at the KUBECONFIG env var instead of using the inCluster configuration.
  -v, --v Level                          number for the log level verbosity (default 3)
      --version                          version for kubeapps-apis
      --vmodule moduleSpec               comma-separated list of pattern=N settings for file-filtered logging

For testing/verification purposes I added Diffs:


 // initConfig reads in config file and ENV variables if set.
diff --git a/cmd/kubeapps-apis/plugins/helm/packages/v1alpha1/server.go b/cmd/kubeapps-apis/plugins/helm/packages/v1alpha1/server.go
index 4fa008b44..7a8731d35 100644
--- a/cmd/kubeapps-apis/plugins/helm/packages/v1alpha1/server.go
+++ b/cmd/kubeapps-apis/plugins/helm/packages/v1alpha1/server.go
@@ -167,6 +167,13 @@ func NewServer(configGetter core.KubernetesConfigGetter, globalPackagingCluster
                log.Infof("+helm using default config since pluginConfigPath is empty")
        }

+       log.Infof("+helm/server.go main basic")
+       log.V(1).Infof("+helm/server.go main V1")
+       log.V(2).Infof("+helm/server.go main V2")
+       log.V(3).Infof("+helm/server.go main V3")
+       log.V(4).Infof("+helm/server.go main V4")
+       log.V(5).Infof("+helm/server.go main V5")
+
        return &Server{
                clientGetter: func(ctx context.Context, cluster string) (kubernetes.Interface, dynamic.Interface, error) {
                        if configGetter == nil {


diff --git a/cmd/kubeapps-apis/server/server.go b/cmd/kubeapps-apis/server/server.go
index 57d1c1050..10963b96c 100644
--- a/cmd/kubeapps-apis/server/server.go
+++ b/cmd/kubeapps-apis/server/server.go
@@ -46,6 +46,13 @@ func Serve(serveOpts core.ServeOptions) error {
        grpcSrv := grpc.NewServer()
        reflection.Register(grpcSrv)

+       log.Infof("+server/server.go main basic")
+       log.V(1).Infof("+server/server.go main V1")
+       log.V(2).Infof("+server/server.go main V2")
+       log.V(3).Infof("+server/server.go main V3")
+       log.V(4).Infof("+server/server.go main V4")
+       log.V(5).Infof("+server/server.go main V5")
+
        // Create the http server, register our core service followed by any plugins.
        listenAddr := fmt.Sprintf(":%d", serveOpts.Port)
        ctx, cancel := context.WithCancel(context.Background())
(END)

TESTING

case-1: OUTPUT WITH DEFAULT


✗ POD_NAMESPACE=kubeapps ASSET_SYNCER_DB_URL=127.0.0.1:5432 ASSET_SYNCER_DB_NAME=assets ASSET_SYNCER_DB_USERNAME=postgres ASSET_SYNCER_DB_USERPASSWORD=$(kubectl get secret --namespace kubeapps kubeapps-postgresql -o jsonpath="{.data.postgresql-password}" | base64 --decode) go run main.go --plugin-dir devel/ --unsafe-local-dev-kubeconfig=true
I1201 16:33:21.895149   68720 root.go:53] kubeapps-apis has been configured with: core.ServeOptions{Port:50051, PluginDirs:[]string{"devel/"}, ClustersConfigPath:"", PluginConfigPath:"", PinnipedProxyURL:"http://kubeapps-internal-pinniped-proxy.kubeapps:3333", UnsafeLocalDevKubeconfig:true}
I1201 16:33:21.895217   68720 server.go:49] +server/server.go main basic
I1201 16:33:21.895221   68720 server.go:50] +server/server.go main V1
I1201 16:33:21.895224   68720 server.go:51] +server/server.go main V2
I1201 16:33:21.895226   68720 server.go:52] +server/server.go main V3
W1201 16:33:21.895448   68720 plugins.go:277] Using the local kubeconfig configuration (in KUBECONFIG='/Users/sdillikar/.kube/kind-config-kubeapps' envar) since you passed --unsafe-local-dev-kubeconfig=true
I1201 16:33:22.060666   68720 server.go:167] +helm using default config since pluginConfigPath is empty
I1201 16:33:22.060691   68720 server.go:170] +helm/server.go main basic
I1201 16:33:22.060697   68720 server.go:171] +helm/server.go main V1
I1201 16:33:22.060700   68720 server.go:172] +helm/server.go main V2
I1201 16:33:22.060703   68720 server.go:173] +helm/server.go main V3
I1201 16:33:22.060842   68720 plugins.go:146] Successfully registered plugin "/Users/sdillikar/vmw_code/fork_repo/kubeapps/cmd/kubeapps-apis/devel/helm-packages-v1alpha1-plugin.so"
I1201 16:33:22.060915   68720 packages.go:57] Registered name:"helm.packages"  version:"v1alpha1" for core.packaging.v1alpha1 aggregation.
W1201 16:33:22.061360   68720 server.go:151] Using the local Kubeconfig file instead of the actual in-cluster's config. This is not recommended except for development purposes.
I1201 16:33:22.061376   68720 server.go:154] Starting server on :50051

case-2: OUTPUT WITH config: --v=4

POD_NAMESPACE=kubeapps ASSET_SYNCER_DB_URL=127.0.0.1:5432 ASSET_SYNCER_DB_NAME=assets ASSET_SYNCER_DB_USERNAME=postgres ASSET_SYNCER_DB_USERPASSWORD=$(kubectl get secret --namespace kubeapps kubeapps-postgresql -o jsonpath="{.data.postgresql-password}" | base64 --decode) go run main.go --plugin-dir devel/ --v=4 --unsafe-local-dev-kubeconfig=true
I1201 16:24:55.843842   66995 root.go:53] kubeapps-apis has been configured with: core.ServeOptions{Port:50051, PluginDirs:[]string{"devel/"}, ClustersConfigPath:"", PluginConfigPath:"", PinnipedProxyURL:"http://kubeapps-internal-pinniped-proxy.kubeapps:3333", UnsafeLocalDevKubeconfig:true}
I1201 16:24:55.843892   66995 server.go:49] +server/server.go main basic
I1201 16:24:55.843896   66995 server.go:50] +server/server.go main V1
I1201 16:24:55.843898   66995 server.go:51] +server/server.go main V2
I1201 16:24:55.843901   66995 server.go:52] +server/server.go main V3
I1201 16:24:55.843903   66995 server.go:53] +server/server.go main V4
W1201 16:24:55.844099   66995 plugins.go:277] Using the local kubeconfig configuration (in KUBECONFIG='/Users/sdillikar/.kube/kind-config-kubeapps' envar) since you passed --unsafe-local-dev-kubeconfig=true
I1201 16:24:56.012320   66995 server.go:167] +helm using default config since pluginConfigPath is empty
I1201 16:24:56.012342   66995 server.go:170] +helm/server.go main basic
I1201 16:24:56.012347   66995 server.go:171] +helm/server.go main V1
I1201 16:24:56.012350   66995 server.go:172] +helm/server.go main V2
I1201 16:24:56.012352   66995 server.go:173] +helm/server.go main V3
I1201 16:24:56.012355   66995 server.go:174] +helm/server.go main V4
I1201 16:24:56.012479   66995 plugins.go:146] Successfully registered plugin "/Users/sdillikar/vmw_code/fork_repo/kubeapps/cmd/kubeapps-apis/devel/helm-packages-v1alpha1-plugin.so"
I1201 16:24:56.012592   66995 packages.go:57] Registered name:"helm.packages"  version:"v1alpha1" for core.packaging.v1alpha1 aggregation.
W1201 16:24:56.013186   66995 server.go:151] Using the local Kubeconfig file instead of the actual in-cluster's config. This is not recommended except for development purposes.
I1201 16:24:56.013221   66995 server.go:154] Starting server on :50051

case-3: OUTPUT WITH config: --v=2

POD_NAMESPACE=kubeapps ASSET_SYNCER_DB_URL=127.0.0.1:5432 ASSET_SYNCER_DB_NAME=assets ASSET_SYNCER_DB_USERNAME=postgres ASSET_SYNCER_DB_USERPASSWORD=$(kubectl get secret --namespace kubeapps kubeapps-postgresql -o jsonpath="{.data.postgresql-password}" | base64 --decode) make run
go build -o devel/helm-packages-v1alpha1-plugin.so -buildmode=plugin plugins/helm/packages/v1alpha1/*.go
go run main.go --plugin-dir devel/ --v=2 --unsafe-local-dev-kubeconfig=true
I1201 16:24:11.095601   66897 root.go:53] kubeapps-apis has been configured with: core.ServeOptions{Port:50051, PluginDirs:[]string{"devel/"}, ClustersConfigPath:"", PluginConfigPath:"", PinnipedProxyURL:"http://kubeapps-internal-pinniped-proxy.kubeapps:3333", UnsafeLocalDevKubeconfig:true}
I1201 16:24:11.095654   66897 server.go:49] +server/server.go main basic
I1201 16:24:11.095675   66897 server.go:50] +server/server.go main V1
I1201 16:24:11.095679   66897 server.go:51] +server/server.go main V2
W1201 16:24:11.095879   66897 plugins.go:277] Using the local kubeconfig configuration (in KUBECONFIG='/Users/sdillikar/.kube/kind-config-kubeapps' envar) since you passed --unsafe-local-dev-kubeconfig=true
I1201 16:24:11.829500   66897 server.go:167] +helm using default config since pluginConfigPath is empty
I1201 16:24:11.829587   66897 server.go:170] +helm/server.go main basic
I1201 16:24:11.829593   66897 server.go:171] +helm/server.go main V1
I1201 16:24:11.829597   66897 server.go:172] +helm/server.go main V2
I1201 16:24:11.829870   66897 plugins.go:146] Successfully registered plugin "/Users/sdillikar/vmw_code/fork_repo/kubeapps/cmd/kubeapps-apis/devel/helm-packages-v1alpha1-plugin.so"
I1201 16:24:11.830365   66897 packages.go:57] Registered name:"helm.packages"  version:"v1alpha1" for core.packaging.v1alpha1 aggregation.
W1201 16:24:11.831436   66897 server.go:151] Using the local Kubeconfig file instead of the actual in-cluster's config. This is not recommended except for development purposes.

absoludity

Awesome - very happy to see that the setting is still controlling the log level in the plugins. Thanks for the detailed examples.

Just want to make sure, you can set the log level via the CLI right? (using -v 4 or similar) I was a bit confused as to why you explicitly set the flag in the root.go

absoludity · 2021-12-02T03:19:09Z

cmd/kubeapps-apis/cmd/root.go

 	cobra.OnInitialize(initConfig)
 	rootCmd = newRootCmd()
 	rootCmd.SetVersionTemplate(version)
 	setFlags(rootCmd)
+	goflag.Set("v", "3")


Is this just for testing? Does that override the CLI flag?

satya-dillikar · 2021-12-02T15:05:57Z

Awesome - very happy to see that the setting is still controlling the log level in the plugins. Thanks for the detailed examples.

Just want to make sure, you can set the log level via the CLI right? (using -v 4 or similar) I was a bit confused as to why you explicitly set the flag in the root.go

Yes, you can set in the CLI, see the examples given above.

satya-dillikar · 2021-12-02T15:08:51Z

goflag.Set("v", "3") - this is the initial default value and CLI can overwrite it using --v. Let me know if you want to change it to something else.

absoludity · 2021-12-02T19:49:41Z

Yes, you can set in the CLI, see the examples given above.

Ah - the one I checked (--v=2) was using make run , but I see the other one (--v=4) has the full go run ... --v=4. Great.

goflag.Set("v", "3") - this is the initial default value and CLI can overwrite it using --v.

Ah - I see, thanks.

Let me know if you want to change it to something else.

Nope, already approved. Land when ready :) Thanks Satya!

satya-dillikar · 2021-12-03T19:23:16Z

I am not sure why 'ci/circleci: local_e2e_tests-1 ' is always failing. I manually triggered it a number of times and it still fails. Please let me know if this is also seen with other CI builds

absoludity · 2021-12-05T23:16:57Z

I am not sure why 'ci/circleci: local_e2e_tests-1 ' is always failing. I manually triggered it a number of times and it still fails. Please let me know if this is also seen with other CI builds

I just took a look at the past three failures and it's mostly Execution context was destroyed, most likely because of a navigation. Unfortunately we've not yet found the cause of these in CI (that is, why the test browser is navigating away, but do plan next quarter to allocate some time to improve the CI tests (and infrastructure - see #2898 ). Either way, you're seeing flaky test failures :/ I can't retry it for you, so just hit the Retry from Failed again.

migmartri · 2021-12-21T11:36:46Z

cmd/kubeapps-apis/cmd/root.go

 	cobra.OnInitialize(initConfig)
 	rootCmd = newRootCmd()
 	rootCmd.SetVersionTemplate(version)
 	setFlags(rootCmd)
+        //set initial value of verbosity
+	goflag.Set("v", "3")


Out of curiosity, how did you come up with this default number? In other projects I work on we use verbosity level default to 2 but to be fair I've never got a definitive answer on why.

Thanks!

satya-dillikar · 2021-12-21T19:06:47Z

@migmartri , It all depends on the specific project code. In the kubeapps code, we have many logs above level 3. (using log.V(4)). We want to suppress them by default. There is no global definitive answer.

migmartri · 2021-12-22T10:03:57Z

we have many logs above level 3. (using log.V(4))
setting the default to 2 will also hide the level 4 logs but I guess that your debugging baseline is level 4 and 3 is info territory then no?

Thanks!

Add GoFlag in CommandLine

b5e4cb1

satya-dillikar mentioned this pull request Dec 2, 2021

Add logging middleware for kubeapps-apis #3766

Closed

absoludity approved these changes Dec 2, 2021

View reviewed changes

satya-dillikar marked this pull request as ready for review December 2, 2021 15:22

to trigger CI build

05d400d

satya-dillikar merged commit 841d0b8 into vmware-tanzu:master Dec 6, 2021

satya-dillikar mentioned this pull request Dec 6, 2021

Add proper request logging middleware or similar for kubeapps-apis #3385

Closed

satya-dillikar deleted the klog branch December 8, 2021 00:33

migmartri reviewed Dec 21, 2021

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add GoFlag in CommandLine #3884

Add GoFlag in CommandLine #3884

satya-dillikar commented Dec 2, 2021

satya-dillikar commented Dec 2, 2021 •

edited

absoludity left a comment

absoludity Dec 2, 2021

satya-dillikar commented Dec 2, 2021

satya-dillikar commented Dec 2, 2021 •

edited

absoludity commented Dec 2, 2021

satya-dillikar commented Dec 3, 2021 •

edited

absoludity commented Dec 5, 2021

migmartri Dec 21, 2021

satya-dillikar commented Dec 21, 2021

migmartri commented Dec 22, 2021

Add GoFlag in CommandLine #3884

Add GoFlag in CommandLine #3884

Conversation

satya-dillikar commented Dec 2, 2021

Description of the change

Benefits

Possible drawbacks

Applicable issues

Additional information

satya-dillikar commented Dec 2, 2021 • edited

absoludity left a comment

Choose a reason for hiding this comment

absoludity Dec 2, 2021

Choose a reason for hiding this comment

satya-dillikar commented Dec 2, 2021

satya-dillikar commented Dec 2, 2021 • edited

absoludity commented Dec 2, 2021

satya-dillikar commented Dec 3, 2021 • edited

absoludity commented Dec 5, 2021

migmartri Dec 21, 2021

Choose a reason for hiding this comment

satya-dillikar commented Dec 21, 2021

migmartri commented Dec 22, 2021

satya-dillikar commented Dec 2, 2021 •

edited

satya-dillikar commented Dec 2, 2021 •

edited

satya-dillikar commented Dec 3, 2021 •

edited