diff --git a/cmd/root.go b/cmd/root.go index e2d49ba3..1c78a0c8 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -1,6 +1,7 @@ package cmd import ( + "context" "fmt" "os" "strings" @@ -45,8 +46,9 @@ func init() { // will be logged and the process will exit with status 1. func Execute() { logs.AddFlags(rootCmd.PersistentFlags()) + ctx := klog.NewContext(context.Background(), klog.Background()) var exitCode int - if err := rootCmd.Execute(); err != nil { + if err := rootCmd.ExecuteContext(ctx); err != nil { exitCode = 1 klog.ErrorS(err, "Exiting due to error", "exit-code", exitCode) } diff --git a/pkg/agent/config.go b/pkg/agent/config.go index 25e4d253..5bccf1d9 100644 --- a/pkg/agent/config.go +++ b/pkg/agent/config.go @@ -3,11 +3,11 @@ package agent import ( "fmt" "io" - "log" "net/url" "os" "time" + "github.com/go-logr/logr" "github.com/hashicorp/go-multierror" "github.com/pkg/errors" "github.com/spf13/cobra" @@ -355,32 +355,35 @@ type CombinedConfig struct { // The error returned may be a multierror.Error. Use multierror.Prefix(err, // "context:") rather than fmt.Errorf("context: %w", err) when wrapping the // error. -func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) (CombinedConfig, client.Client, error) { +func ValidateAndCombineConfig(log logr.Logger, cfg Config, flags AgentCmdFlags) (CombinedConfig, client.Client, error) { res := CombinedConfig{} var errs error { - var mode AuthMode + var ( + mode AuthMode + reason string + ) switch { case flags.VenafiCloudMode && flags.CredentialsPath != "": mode = VenafiCloudKeypair - log.Printf("Using the %s auth mode since --venafi-cloud and --credentials-path were specified.", mode) + reason = fmt.Sprintf("Using the %s auth mode since --venafi-cloud and --credentials-path were specified.", mode) case flags.ClientID != "" && flags.PrivateKeyPath != "": mode = VenafiCloudKeypair - log.Printf("Using the %s auth mode since --client-id and --private-key-path were specified.", mode) + reason = fmt.Sprintf("Using the %s auth mode since --client-id and --private-key-path were specified.", mode) case flags.ClientID != "": return CombinedConfig{}, nil, fmt.Errorf("if --client-id is specified, --private-key-path must also be specified") case flags.PrivateKeyPath != "": return CombinedConfig{}, nil, fmt.Errorf("--private-key-path is specified, --client-id must also be specified") case flags.VenConnName != "": mode = VenafiCloudVenafiConnection - log.Printf("Using the %s auth mode since --venafi-connection was specified.", mode) + reason = fmt.Sprintf("Using the %s auth mode since --venafi-connection was specified.", mode) case flags.APIToken != "": mode = JetstackSecureAPIToken - log.Printf("Using the %s auth mode since --api-token was specified.", mode) + reason = fmt.Sprintf("Using the %s auth mode since --api-token was specified.", mode) case !flags.VenafiCloudMode && flags.CredentialsPath != "": mode = JetstackSecureOAuth - log.Printf("Using the %s auth mode since --credentials-file was specified without --venafi-cloud.", mode) + reason = fmt.Sprintf("Using the %s auth mode since --credentials-file was specified without --venafi-cloud.", mode) default: return CombinedConfig{}, nil, fmt.Errorf("no auth mode specified. You can use one of four auth modes:\n" + " - Use (--venafi-cloud with --credentials-file) or (--client-id with --private-key-path) to use the " + string(VenafiCloudKeypair) + " mode.\n" + @@ -389,6 +392,7 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) " - Use --api-token if you want to use the " + string(JetstackSecureAPIToken) + " mode.\n") } res.AuthMode = mode + log.Info(reason) } // Validation and defaulting of `server` and the deprecated `endpoint.path`. @@ -403,10 +407,10 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) case hasServerField && hasEndpointField: // The `server` field takes precedence over the deprecated // `endpoint` field. - log.Printf("The `server` and `endpoint` fields are both set in the config; using the `server` field.") + log.Info("The `server` and `endpoint` fields are both set in the config; using the `server` field.") server = cfg.Server case !hasServerField && hasEndpointField: - log.Printf("Using deprecated Endpoint configuration. User Server instead.") + log.Info("Using deprecated Endpoint configuration. User Server instead.") if cfg.Endpoint.Protocol == "" && cfg.Server == "" { cfg.Endpoint.Protocol = "http" } @@ -424,7 +428,7 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) errs = multierror.Append(errs, fmt.Errorf("server %q is not a valid URL", server)) } if res.AuthMode == VenafiCloudVenafiConnection && server != "" { - log.Printf("ignoring the server field specified in the config file. In %s mode, this field is not needed.", VenafiCloudVenafiConnection) + log.Info(fmt.Sprintf("ignoring the server field specified in the config file. In %s mode, this field is not needed.", VenafiCloudVenafiConnection)) server = "" } res.Server = server @@ -454,7 +458,7 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) // change this value with the new --venafi-connection flag, and this // field is simply ignored. if cfg.VenafiCloud != nil && cfg.VenafiCloud.UploadPath != "" { - log.Printf(`ignoring the venafi-cloud.upload_path field in the config file. In %s mode, this field is not needed.`, res.AuthMode) + log.Info(fmt.Sprintf(`ignoring the venafi-cloud.upload_path field in the config file. In %s mode, this field is not needed.`, res.AuthMode)) } uploadPath = "" } @@ -472,7 +476,7 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) // https://venafi.atlassian.net/browse/VC-35385 is done. { if cfg.VenafiCloud != nil && cfg.VenafiCloud.UploaderID != "" { - log.Printf(`ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in %s mode.`, res.AuthMode) + log.Info(fmt.Sprintf(`ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in %s mode.`, res.AuthMode)) } } @@ -524,13 +528,13 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) case flags.Period == 0 && cfg.Period == 0: errs = multierror.Append(errs, fmt.Errorf("period must be set using --period or -p, or using the 'period' field in the config file")) case flags.Period == 0 && cfg.Period > 0: - log.Printf("Using period from config %s", cfg.Period) + log.Info("Using period from config", "period", cfg.Period) period = cfg.Period case flags.Period > 0 && cfg.Period == 0: period = flags.Period case flags.Period > 0 && cfg.Period > 0: // The flag takes precedence. - log.Printf("Both the 'period' field and --period are set. Using the value provided with --period.") + log.Info("Both the 'period' field and --period are set. Using the value provided with --period.") period = flags.Period } res.Period = period @@ -599,7 +603,7 @@ func ValidateAndCombineConfig(log *log.Logger, cfg Config, flags AgentCmdFlags) // The error returned may be a multierror.Error. Use multierror.Prefix(err, // "context:") rather than fmt.Errorf("context: %w", err) when wrapping the // error. -func validateCredsAndCreateClient(log *log.Logger, flagCredentialsPath, flagClientID, flagPrivateKeyPath, flagAPIToken string, cfg CombinedConfig) (client.Client, error) { +func validateCredsAndCreateClient(log logr.Logger, flagCredentialsPath, flagClientID, flagPrivateKeyPath, flagAPIToken string, cfg CombinedConfig) (client.Client, error) { var errs error var preflightClient client.Client @@ -719,7 +723,7 @@ func ValidateDataGatherers(dataGatherers []DataGatherer) error { // The error returned may be a multierror.Error. Instead of adding context to // the error with fmt.Errorf("%w", err), use multierror.Prefix(err, "context"). -func createCredentialClient(log *log.Logger, credentials client.Credentials, cfg CombinedConfig, agentMetadata *api.AgentMetadata) (client.Client, error) { +func createCredentialClient(log logr.Logger, credentials client.Credentials, cfg CombinedConfig, agentMetadata *api.AgentMetadata) (client.Client, error) { switch creds := credentials.(type) { case *client.VenafiSvcAccountCredentials: // The uploader ID isn't actually used in the backend, let's use an @@ -730,7 +734,7 @@ func createCredentialClient(log *log.Logger, credentials client.Credentials, cfg if cfg.AuthMode == VenafiCloudKeypair { // We don't do this for the VenafiCloudVenafiConnection mode because // the upload_path field is ignored in that mode. - log.Println("Loading upload_path from \"venafi-cloud\" configuration.") + log.Info("Loading upload_path from \"venafi-cloud\" configuration.") uploadPath = cfg.UploadPath } return client.NewVenafiCloudClient(agentMetadata, creds, cfg.Server, uploaderID, uploadPath, cfg.DisableCompression) diff --git a/pkg/agent/config_test.go b/pkg/agent/config_test.go index 87751592..6a3bd07e 100644 --- a/pkg/agent/config_test.go +++ b/pkg/agent/config_test.go @@ -6,15 +6,16 @@ import ( "context" "fmt" "io" - "log" "net/http" "os" "testing" "time" + "github.com/go-logr/logr" "github.com/spf13/cobra" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "k8s.io/klog/v2/ktesting" "github.com/jetstack/preflight/pkg/client" "github.com/jetstack/preflight/pkg/testutil" @@ -86,7 +87,7 @@ func Test_ValidateAndCombineConfig(t *testing.T) { t.Run("--period flag takes precedence over period field in config, shows warning", func(t *testing.T) { t.Setenv("POD_NAMESPACE", "venafi") - log, gotLogs := recordLogs() + log, gotLogs := recordLogs(t) got, _, err := ValidateAndCombineConfig(log, withConfig(testutil.Undent(` server: https://api.venafi.eu @@ -97,8 +98,8 @@ func Test_ValidateAndCombineConfig(t *testing.T) { withCmdLineFlags("--period", "99m", "--credentials-file", fakeCredsPath)) require.NoError(t, err) assert.Equal(t, testutil.Undent(` - Using the Jetstack Secure OAuth auth mode since --credentials-file was specified without --venafi-cloud. - Both the 'period' field and --period are set. Using the value provided with --period. + INFO Using the Jetstack Secure OAuth auth mode since --credentials-file was specified without --venafi-cloud. + INFO Both the 'period' field and --period are set. Using the value provided with --period. `), gotLogs.String()) assert.Equal(t, 99*time.Minute, got.Period) }) @@ -573,7 +574,7 @@ func Test_ValidateAndCombineConfig(t *testing.T) { t.Run("venafi-cloud-workload-identity-auth: warning about server, venafi-cloud.uploader_id, and venafi-cloud.upload_path being skipped", func(t *testing.T) { t.Setenv("POD_NAMESPACE", "venafi") t.Setenv("KUBECONFIG", withFile(t, fakeKubeconfig)) - log, gotLogs := recordLogs() + log, gotLogs := recordLogs(t) got, gotCl, err := ValidateAndCombineConfig(log, withConfig(testutil.Undent(` server: https://api.venafi.eu @@ -587,11 +588,11 @@ func Test_ValidateAndCombineConfig(t *testing.T) { ) require.NoError(t, err) assert.Equal(t, testutil.Undent(` - Using the Venafi Cloud VenafiConnection auth mode since --venafi-connection was specified. - ignoring the server field specified in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed. - ignoring the venafi-cloud.upload_path field in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed. - ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in Venafi Cloud VenafiConnection mode. - Using period from config 1h0m0s + INFO Using the Venafi Cloud VenafiConnection auth mode since --venafi-connection was specified. + INFO ignoring the server field specified in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed. + INFO ignoring the venafi-cloud.upload_path field in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed. + INFO ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in Venafi Cloud VenafiConnection mode. + INFO Using period from config period="1h0m0s" `), gotLogs.String()) assert.Equal(t, VenafiCloudVenafiConnection, got.AuthMode) assert.IsType(t, &client.VenConnClient{}, gotCl) @@ -994,13 +995,15 @@ func withFile(t testing.TB, content string) string { return f.Name() } -func recordLogs() (*log.Logger, *bytes.Buffer) { - b := bytes.Buffer{} - return log.New(&b, "", 0), &b +func recordLogs(t *testing.T) (logr.Logger, ktesting.Buffer) { + log := ktesting.NewLogger(t, ktesting.NewConfig(ktesting.BufferLogs(true))) + testingLogger, ok := log.GetSink().(ktesting.Underlier) + require.True(t, ok) + return log, testingLogger.GetBuffer() } -func discardLogs() *log.Logger { - return log.New(io.Discard, "", 0) +func discardLogs() logr.Logger { + return logr.Discard() } // Shortcut for ParseConfig. diff --git a/pkg/agent/run.go b/pkg/agent/run.go index 2458befe..3b641c7f 100644 --- a/pkg/agent/run.go +++ b/pkg/agent/run.go @@ -9,11 +9,13 @@ import ( "io" "net" "net/http" + "net/http/pprof" "os" "strings" "time" "github.com/cenkalti/backoff" + "github.com/go-logr/logr" "github.com/hashicorp/go-multierror" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promhttp" @@ -33,10 +35,7 @@ import ( "github.com/jetstack/preflight/pkg/client" "github.com/jetstack/preflight/pkg/datagatherer" "github.com/jetstack/preflight/pkg/kubeconfig" - "github.com/jetstack/preflight/pkg/logs" "github.com/jetstack/preflight/pkg/version" - - "net/http/pprof" ) var Flags AgentCmdFlags @@ -51,14 +50,10 @@ const schemaVersion string = "v2.0.0" // Run starts the agent process func Run(cmd *cobra.Command, args []string) (returnErr error) { - logs.Log.Printf("Preflight agent version: %s (%s)", version.PreflightVersion, version.Commit) - ctx, cancel := context.WithCancel( - klog.NewContext( - context.Background(), - klog.Background(), - ), - ) + ctx, cancel := context.WithCancel(cmd.Context()) defer cancel() + log := klog.FromContext(ctx).WithName("Run") + log.Info("Starting", "version", version.PreflightVersion, "commit", version.Commit) file, err := os.Open(Flags.ConfigFilePath) if err != nil { @@ -76,7 +71,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { return fmt.Errorf("Failed to parse config file: %s", err) } - config, preflightClient, err := ValidateAndCombineConfig(logs.Log, cfg, Flags) + config, preflightClient, err := ValidateAndCombineConfig(log, cfg, Flags) if err != nil { return fmt.Errorf("While evaluating configuration: %v", err) } @@ -95,7 +90,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { { server := http.NewServeMux() const serverAddress = ":8081" - log := klog.FromContext(ctx).WithName("APIServer").WithValues("addr", serverAddress) + log := log.WithName("APIServer").WithValues("addr", serverAddress) if Flags.Profiling { log.Info("Profiling endpoints enabled", "path", "/debug/pprof") @@ -159,7 +154,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { // To help users notice issues with the agent, we show the error messages in // the agent pod's events. - eventf, err := newEventf(config.InstallNS) + eventf, err := newEventf(log, config.InstallNS) if err != nil { return fmt.Errorf("failed to create event recorder: %v", err) } @@ -179,7 +174,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { return fmt.Errorf("failed to instantiate %q data gatherer %q: %v", kind, dgConfig.Name, err) } - logs.Log.Printf("starting %q datagatherer", dgConfig.Name) + log.Info("Starting DataGatherer", "name", dgConfig.Name) // start the data gatherers and wait for the cache sync group.Go(func() error { @@ -217,7 +212,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { // the run. if err := dg.WaitForCacheSync(bootCtx.Done()); err != nil { // log sync failure, this might recover in future - logs.Log.Printf("failed to complete initial sync of %q data gatherer %q: %v", dgConfig.Kind, dgConfig.Name, err) + log.Error(err, "Failed to complete initial sync of DataGatherer", "kind", dgConfig.Kind, "name", dgConfig.Name) } } @@ -230,7 +225,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { // TODO(wallrj): Pass a context to gatherAndOutputData, so that we don't // have to wait for it to finish before exiting the process. for { - if err := gatherAndOutputData(eventf, config, preflightClient, dataGatherers); err != nil { + if err := gatherAndOutputData(ctx, eventf, config, preflightClient, dataGatherers); err != nil { return err } @@ -251,7 +246,7 @@ func Run(cmd *cobra.Command, args []string) (returnErr error) { // POD_NAME to contain the pod name. Note that the RBAC rule allowing sending // events is attached to the pod's service account, not the impersonated service // account (venafi-connection). -func newEventf(installNS string) (Eventf, error) { +func newEventf(log logr.Logger, installNS string) (Eventf, error) { restcfg, err := kubeconfig.LoadRESTConfig("") if err != nil { return nil, fmt.Errorf("failed to load kubeconfig: %v", err) @@ -262,7 +257,7 @@ func newEventf(installNS string) (Eventf, error) { var eventf Eventf if os.Getenv("POD_NAME") == "" { eventf = func(eventType, reason, msg string, args ...interface{}) {} - logs.Log.Printf("error messages will not show in the pod's events because the POD_NAME environment variable is empty") + log.Error(nil, "Error messages will not show in the pod's events because the POD_NAME environment variable is empty") } else { podName := os.Getenv("POD_NAME") @@ -284,11 +279,12 @@ func newEventf(installNS string) (Eventf, error) { // Like Printf but for sending events to the agent's Pod object. type Eventf func(eventType, reason, msg string, args ...interface{}) -func gatherAndOutputData(eventf Eventf, config CombinedConfig, preflightClient client.Client, dataGatherers map[string]datagatherer.DataGatherer) error { +func gatherAndOutputData(ctx context.Context, eventf Eventf, config CombinedConfig, preflightClient client.Client, dataGatherers map[string]datagatherer.DataGatherer) error { + log := klog.FromContext(ctx).WithName("gatherAndOutputData") var readings []*api.DataReading if config.InputPath != "" { - logs.Log.Printf("Reading data from local file: %s", config.InputPath) + log.Info("Reading data from local file", "inputPath", config.InputPath) data, err := os.ReadFile(config.InputPath) if err != nil { return fmt.Errorf("failed to read local data file: %s", err) @@ -299,7 +295,7 @@ func gatherAndOutputData(eventf Eventf, config CombinedConfig, preflightClient c } } else { var err error - readings, err = gatherData(config, dataGatherers) + readings, err = gatherData(ctx, config, dataGatherers) if err != nil { return err } @@ -314,18 +310,18 @@ func gatherAndOutputData(eventf Eventf, config CombinedConfig, preflightClient c if err != nil { return fmt.Errorf("failed to output to local file: %s", err) } - logs.Log.Printf("Data saved to local file: %s", config.OutputPath) + log.Info("Data saved to local file", "outputPath", config.OutputPath) } else { backOff := backoff.NewExponentialBackOff() backOff.InitialInterval = 30 * time.Second backOff.MaxInterval = 3 * time.Minute backOff.MaxElapsedTime = config.BackoffMaxTime post := func() error { - return postData(config, preflightClient, readings) + return postData(ctx, config, preflightClient, readings) } err := backoff.RetryNotify(post, backOff, func(err error, t time.Duration) { eventf("Warning", "PushingErr", "retrying in %v after error: %s", t, err) - logs.Log.Printf("retrying in %v after error: %s", t, err) + log.Info("Warning: PushingErr: retrying", "in", t, "reason", err) }) if err != nil { return fmt.Errorf("Exiting due to fatal error uploading: %v", err) @@ -334,7 +330,9 @@ func gatherAndOutputData(eventf Eventf, config CombinedConfig, preflightClient c return nil } -func gatherData(config CombinedConfig, dataGatherers map[string]datagatherer.DataGatherer) ([]*api.DataReading, error) { +func gatherData(ctx context.Context, config CombinedConfig, dataGatherers map[string]datagatherer.DataGatherer) ([]*api.DataReading, error) { + log := klog.FromContext(ctx).WithName("gatherData") + var readings []*api.DataReading var dgError *multierror.Error @@ -346,11 +344,7 @@ func gatherData(config CombinedConfig, dataGatherers map[string]datagatherer.Dat continue } - if count >= 0 { - logs.Log.Printf("successfully gathered %d items from %q datagatherer", count, k) - } else { - logs.Log.Printf("successfully gathered data from %q datagatherer", k) - } + log.Info("Successfully gathered", "count", count, "name", k) readings = append(readings, &api.DataReading{ ClusterID: config.ClusterID, DataGatherer: k, @@ -379,10 +373,11 @@ func gatherData(config CombinedConfig, dataGatherers map[string]datagatherer.Dat return readings, nil } -func postData(config CombinedConfig, preflightClient client.Client, readings []*api.DataReading) error { +func postData(ctx context.Context, config CombinedConfig, preflightClient client.Client, readings []*api.DataReading) error { + log := klog.FromContext(ctx).WithName("postData") baseURL := config.Server - logs.Log.Println("Posting data to:", baseURL) + log.Info("Posting data", "baseURL", baseURL) if config.AuthMode == VenafiCloudKeypair || config.AuthMode == VenafiCloudVenafiConnection { // orgID and clusterID are not required for Venafi Cloud auth @@ -393,7 +388,7 @@ func postData(config CombinedConfig, preflightClient client.Client, readings []* if err != nil { return fmt.Errorf("post to server failed: %+v", err) } - logs.Log.Println("Data sent successfully.") + log.Info("Data sent successfully") return nil } @@ -409,7 +404,7 @@ func postData(config CombinedConfig, preflightClient client.Client, readings []* prometheus.Labels{"organization": config.OrganizationID, "cluster": config.ClusterID}, ) metric.Set(float64(len(data))) - logs.Log.Printf("Data readings upload size: %d", len(data)) + log.Info("Data readings", "uploadSize", len(data)) path := config.EndpointPath if path == "" { path = "/api/v1/datareadings" @@ -429,7 +424,8 @@ func postData(config CombinedConfig, preflightClient client.Client, readings []* return fmt.Errorf("received response with status code %d. Body: [%s]", code, errorContent) } - logs.Log.Println("Data sent successfully.") + log.Info("Data sent successfully") + return err } @@ -441,7 +437,7 @@ func postData(config CombinedConfig, preflightClient client.Client, readings []* if err != nil { return fmt.Errorf("post to server failed: %+v", err) } - logs.Log.Println("Data sent successfully.") + log.Info("Data sent successfully") return nil }