diff --git a/cli/internal/cmd/configfetchmeasurements.go b/cli/internal/cmd/configfetchmeasurements.go index 5e2172d9c..77642d142 100644 --- a/cli/internal/cmd/configfetchmeasurements.go +++ b/cli/internal/cmd/configfetchmeasurements.go @@ -72,12 +72,12 @@ func (cfm *configFetchMeasurementsCmd) configFetchMeasurements( fileHandler file.Handler, client *http.Client, ) error { flags, err := cfm.parseFetchMeasurementsFlags(cmd) - cfm.log.Debugf("Using flags %v", flags) if err != nil { return err } + cfm.log.Debugf("Using flags %v", flags) - cfm.log.Debugf("Loading config file from %s", flags.configPath) + cfm.log.Debugf("Loading configuration file from %q", flags.configPath) conf, err := config.New(fileHandler, flags.configPath) if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) @@ -118,7 +118,7 @@ func (cfm *configFetchMeasurementsCmd) configFetchMeasurements( cmd.PrintErrln("Make sure the downloaded measurements are trustworthy!") } - cfm.log.Debugf("Verified measurements with Rekor, updating measurements in config") + cfm.log.Debugf("Verified measurements with Rekor, updating measurements in configuration") conf.UpdateMeasurements(fetchedMeasurements) if err := fileHandler.WriteYAML(flags.configPath, conf, file.OptOverwrite); err != nil { return err @@ -134,9 +134,9 @@ func (cfm *configFetchMeasurementsCmd) parseURLFlag(cmd *cobra.Command, flag str if err != nil { return nil, fmt.Errorf("parsing config generate flags '%s': %w", flag, err) } - cfm.log.Debugf("Flag %s has raw URL %s", flag, rawURL) + cfm.log.Debugf("Flag %s has raw URL %q", flag, rawURL) if rawURL != "" { - cfm.log.Debugf("Parsing raw URL %s", rawURL) + cfm.log.Debugf("Parsing raw URL") return url.Parse(rawURL) } return nil, nil @@ -147,19 +147,19 @@ func (cfm *configFetchMeasurementsCmd) parseFetchMeasurementsFlags(cmd *cobra.Co if err != nil { return &fetchMeasurementsFlags{}, err } - cfm.log.Debugf("Parsed measurements URL") + cfm.log.Debugf("Parsed measurements URL as %v", measurementsURL) measurementsSignatureURL, err := cfm.parseURLFlag(cmd, "signature-url") if err != nil { return &fetchMeasurementsFlags{}, err } - cfm.log.Debugf("Parsed measurements signature URL") + cfm.log.Debugf("Parsed measurements signature URL as %v", measurementsSignatureURL) config, err := cmd.Flags().GetString("config") if err != nil { return &fetchMeasurementsFlags{}, fmt.Errorf("parsing config path argument: %w", err) } - cfm.log.Debugf("Config path is %s", config) + cfm.log.Debugf("Configuration path is %q", config) return &fetchMeasurementsFlags{ measurementsURL: measurementsURL, diff --git a/cli/internal/cmd/create.go b/cli/internal/cmd/create.go index e6d0e94d4..0ff59d59c 100644 --- a/cli/internal/cmd/create.go +++ b/cli/internal/cmd/create.go @@ -49,7 +49,7 @@ func runCreate(cmd *cobra.Command, args []string) error { return fmt.Errorf("creating logger: %w", err) } defer log.Sync() - spinner, err := newSpinnerOrStdout(cmd) + spinner, err := newSpinnerOrStderr(cmd) if err != nil { return fmt.Errorf("creating spinner: %w", err) } @@ -72,7 +72,7 @@ func (c *createCmd) create(cmd *cobra.Command, creator cloudCreator, fileHandler return err } - c.log.Debugf("Loading config file from %s", flags.configPath) + c.log.Debugf("Loading configuration file from %q", flags.configPath) conf, err := config.New(fileHandler, flags.configPath) if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) @@ -124,7 +124,7 @@ func (c *createCmd) create(cmd *cobra.Command, creator cloudCreator, fileHandler cpus := conf.Provider.QEMU.VCPUs instanceType = fmt.Sprintf("%d-vCPU", cpus) } - c.log.Debugf("Configured with instance type %s", instanceType) + c.log.Debugf("Configured with instance type %q", instanceType) if !flags.yes { // Ask user to confirm action. @@ -160,28 +160,28 @@ func (c *createCmd) create(cmd *cobra.Command, creator cloudCreator, fileHandler // parseCreateFlags parses the flags of the create command. func (c *createCmd) parseCreateFlags(cmd *cobra.Command) (createFlags, error) { controllerCount, err := cmd.Flags().GetInt("control-plane-nodes") - c.log.Debugf("Control-plane nodes flag is %d", controllerCount) if err != nil { return createFlags{}, fmt.Errorf("parsing number of control-plane nodes: %w", err) } + c.log.Debugf("Control-plane nodes flag is %d", controllerCount) if controllerCount < constants.MinControllerCount { return createFlags{}, fmt.Errorf("number of control-plane nodes must be at least %d", constants.MinControllerCount) } workerCount, err := cmd.Flags().GetInt("worker-nodes") - c.log.Debugf("Worker nodes falg is %d", workerCount) if err != nil { return createFlags{}, fmt.Errorf("parsing number of worker nodes: %w", err) } + c.log.Debugf("Worker nodes flag is %d", workerCount) if workerCount < constants.MinWorkerCount { return createFlags{}, fmt.Errorf("number of worker nodes must be at least %d", constants.MinWorkerCount) } name, err := cmd.Flags().GetString("name") - c.log.Debugf("Name flag is %s", name) if err != nil { return createFlags{}, fmt.Errorf("parsing name argument: %w", err) } + c.log.Debugf("Name flag is %q", name) if len(name) > constants.ConstellationNameLength { return createFlags{}, fmt.Errorf( "name for Constellation cluster too long, maximum length is %d, got %d: %s", @@ -190,16 +190,16 @@ func (c *createCmd) parseCreateFlags(cmd *cobra.Command) (createFlags, error) { } yes, err := cmd.Flags().GetBool("yes") - c.log.Debugf("Yes flag is %t", yes) if err != nil { return createFlags{}, fmt.Errorf("%w; Set '-yes' without a value to automatically confirm", err) } + c.log.Debugf("Yes flag is %t", yes) configPath, err := cmd.Flags().GetString("config") - c.log.Debugf("Config path flag is %s", configPath) if err != nil { return createFlags{}, fmt.Errorf("parsing config path argument: %w", err) } + c.log.Debugf("Configuration path flag is %q", configPath) return createFlags{ controllerCount: controllerCount, diff --git a/cli/internal/cmd/init.go b/cli/internal/cmd/init.go index 4d39de07b..a06426adc 100644 --- a/cli/internal/cmd/init.go +++ b/cli/internal/cmd/init.go @@ -70,7 +70,10 @@ func runInitialize(cmd *cobra.Command, args []string) error { return dialer.New(nil, validator.V(cmd), &net.Dialer{}) } - spinner := newSpinner(cmd.ErrOrStderr()) + spinner, err := newSpinnerOrStderr(cmd) + if err != nil { + return err + } defer spinner.Stop() ctx, cancel := context.WithTimeout(cmd.Context(), time.Hour) @@ -89,7 +92,7 @@ func (i *initCmd) initialize(cmd *cobra.Command, newDialer func(validator *cloud return err } i.log.Debugf("Using flags: %+v", flags) - i.log.Debugf("Loading config file from %s", flags.configPath) + i.log.Debugf("Loading configuration file from %q", flags.configPath) conf, err := config.New(fileHandler, flags.configPath) if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) @@ -126,16 +129,15 @@ func (i *initCmd) initialize(cmd *cobra.Command, newDialer func(validator *cloud if err != nil { return err } - i.log.Debugf("Got service account uri %s", serviceAccURI) - i.log.Debugf("Loading master secret file from %s", flags.masterSecretPath) + i.log.Debugf("Successfully marshaled service account URI") masterSecret, err := i.readOrGenerateMasterSecret(cmd.OutOrStdout(), fileHandler, flags.masterSecretPath) if err != nil { return fmt.Errorf("parsing or generating master secret from file %s: %w", flags.masterSecretPath, err) } helmLoader := helm.NewLoader(provider, k8sVersion) - i.log.Debugf("Created new helm loader") + i.log.Debugf("Created new Helm loader") helmDeployments, err := helmLoader.Load(conf, flags.conformance, masterSecret.Key, masterSecret.Salt) - i.log.Debugf("Loaded helm heployments") + i.log.Debugf("Loaded Helm heployments") if err != nil { return fmt.Errorf("loading Helm charts: %w", err) } @@ -159,7 +161,6 @@ func (i *initCmd) initialize(cmd *cobra.Command, newDialer func(validator *cloud } i.log.Debugf("Sending initialization request") resp, err := i.initCall(cmd.Context(), newDialer(validator), idFile.IP, req) - i.log.Debugf("Got initialization response") spinner.Stop() if err != nil { var nonRetriable *nonRetriableError @@ -169,7 +170,8 @@ func (i *initCmd) initialize(cmd *cobra.Command, newDialer func(validator *cloud } return err } - i.log.Debugf("Writing Constellation id file") + i.log.Debugf("Initialization request succeeded") + i.log.Debugf("Writing Constellation ID file") idFile.CloudProvider = provider if err := i.writeOutput(idFile, resp, cmd.OutOrStdout(), fileHandler); err != nil { return err @@ -185,8 +187,16 @@ func (i *initCmd) initCall(ctx context.Context, dialer grpcDialer, ip string, re req: req, log: i.log, } + + // Create a wrapper function that allows logging any returned error from the retrier before checking if it's the expected retriable one. + serviceIsUnavailable := func(err error) bool { + isServiceUnavailable := grpcRetry.ServiceIsUnavailable(err) + i.log.Debugf("Encountered error (retriable: %t): %s", isServiceUnavailable, err) + return isServiceUnavailable + } + i.log.Debugf("Making initialization call, doer is %+v", doer) - retrier := retry.NewIntervalRetrier(doer, 30*time.Second, grpcRetry.ServiceIsUnavailable) + retrier := retry.NewIntervalRetrier(doer, 30*time.Second, serviceIsUnavailable) if err := retrier.Do(ctx); err != nil { return nil, err } @@ -222,7 +232,7 @@ func (i *initCmd) writeOutput(idFile clusterid.File, resp *initproto.InitRespons fmt.Fprint(wr, "Your Constellation cluster was successfully initialized.\n\n") ownerID := hex.EncodeToString(resp.OwnerId) - i.log.Debugf("Owner id is %s", ownerID) + // i.log.Debugf("Owner id is %s", ownerID) clusterID := hex.EncodeToString(resp.ClusterId) tw := tabwriter.NewWriter(wr, 0, 0, 2, ' ', 0) @@ -257,20 +267,20 @@ func writeRow(wr io.Writer, col1 string, col2 string) { // reading the content from file path flags and deriving other values from flag combinations. func (i *initCmd) evalFlagArgs(cmd *cobra.Command) (initFlags, error) { masterSecretPath, err := cmd.Flags().GetString("master-secret") - i.log.Debugf("Master secret path flag value is %s", masterSecretPath) if err != nil { return initFlags{}, fmt.Errorf("parsing master-secret path flag: %w", err) } + i.log.Debugf("Master secret path flag value is %q", masterSecretPath) conformance, err := cmd.Flags().GetBool("conformance") - i.log.Debugf("Conformance flag is %t", conformance) if err != nil { - return initFlags{}, fmt.Errorf("parsing autoscale flag: %w", err) + return initFlags{}, fmt.Errorf("parsing conformance flag: %w", err) } + i.log.Debugf("Conformance flag is %t", conformance) configPath, err := cmd.Flags().GetString("config") - i.log.Debugf("Config path flag is %s", conformance) if err != nil { return initFlags{}, fmt.Errorf("parsing config path flag: %w", err) } + i.log.Debugf("Configuration path flag is %q", configPath) return initFlags{ configPath: configPath, @@ -295,7 +305,7 @@ type masterSecret struct { // readOrGenerateMasterSecret reads a base64 encoded master secret from file or generates a new 32 byte secret. func (i *initCmd) readOrGenerateMasterSecret(outWriter io.Writer, fileHandler file.Handler, filename string) (masterSecret, error) { if filename != "" { - i.log.Debugf("Reading master secret from file") + i.log.Debugf("Reading master secret from file %q", filename) var secret masterSecret if err := fileHandler.ReadJSON(filename, &secret); err != nil { return masterSecret{}, err diff --git a/cli/internal/cmd/miniup.go b/cli/internal/cmd/miniup.go index f7cf0d463..96ce8969b 100644 --- a/cli/internal/cmd/miniup.go +++ b/cli/internal/cmd/miniup.go @@ -56,7 +56,10 @@ func runUp(cmd *cobra.Command, args []string) error { return fmt.Errorf("creating logger: %w", err) } defer log.Sync() - spinner := newSpinner(cmd.ErrOrStderr()) + spinner, err := newSpinnerOrStderr(cmd) + if err != nil { + return err + } defer spinner.Stop() creator := cloudcmd.NewCreator(spinner) @@ -76,7 +79,7 @@ func (m *miniUpCmd) up(cmd *cobra.Command, creator cloudCreator, spinner spinner if err != nil { return fmt.Errorf("preparing config: %w", err) } - m.log.Debugf("Prepared config") + m.log.Debugf("Prepared configuration") // create cluster spinner.Start("Creating cluster in QEMU ", false) @@ -171,7 +174,7 @@ func (m *miniUpCmd) checkSystemRequirements(out io.Writer) error { // prepareConfig reads a given config, or creates a new minimal QEMU config. func (m *miniUpCmd) prepareConfig(cmd *cobra.Command, fileHandler file.Handler) (*config.Config, error) { - m.log.Debugf("Preparing config") + m.log.Debugf("Preparing configuration") configPath, err := cmd.Flags().GetString("config") if err != nil { return nil, err @@ -187,7 +190,7 @@ func (m *miniUpCmd) prepareConfig(cmd *cobra.Command, fileHandler file.Handler) } return conf, nil } - m.log.Debugf("Config path is %s", configPath) + m.log.Debugf("Configuration path is %q", configPath) if err := cmd.Flags().Set("config", constants.ConfigFilename); err != nil { return nil, err } @@ -207,7 +210,7 @@ func (m *miniUpCmd) prepareConfig(cmd *cobra.Command, fileHandler file.Handler) config := config.Default() config.RemoveProviderExcept(cloudprovider.QEMU) config.StateDiskSizeGB = 8 - m.log.Debugf("Prepared config") + m.log.Debugf("Prepared configuration") return config, fileHandler.WriteYAML(constants.ConfigFilename, config, file.OptOverwrite) } diff --git a/cli/internal/cmd/recover.go b/cli/internal/cmd/recover.go index 2d45c4ff5..aa77f505f 100644 --- a/cli/internal/cmd/recover.go +++ b/cli/internal/cmd/recover.go @@ -79,7 +79,7 @@ func (r *recoverCmd) recover( return err } - r.log.Debugf("Loading configuration file from %s", flags.configPath) + r.log.Debugf("Loading configuration file from %q", flags.configPath) conf, err := config.New(fileHandler, flags.configPath) if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) @@ -119,17 +119,19 @@ func (r *recoverCmd) recoverCall(ctx context.Context, out io.Writer, interval ti for { once := sync.Once{} retryOnceOnFailure := func(err error) bool { + var retry bool // retry transient GCP LB errors if grpcRetry.LoadbalancerIsNotReady(err) { - return true + retry = true + } else { + // retry connection errors once + // this is necessary because Azure's LB takes a while to remove unhealthy instances + once.Do(func() { + retry = grpcRetry.ServiceIsUnavailable(err) + }) } - retry := false - // retry connection errors once - // this is necessary because Azure's LB takes a while to remove unhealthy instances - once.Do(func() { - retry = grpcRetry.ServiceIsUnavailable(err) - }) + r.log.Debugf("Encountered error (retriable: %t): %s", retry, err) return retry } @@ -268,7 +270,7 @@ func (r *recoverCmd) parseRecoverFlags(cmd *cobra.Command, fileHandler file.Hand if err != nil { return recoverFlags{}, fmt.Errorf("parsing config path argument: %w", err) } - r.log.Debugf("Config path flag is %s", configPath) + r.log.Debugf("Configuration path flag is %s", configPath) return recoverFlags{ endpoint: endpoint, diff --git a/cli/internal/cmd/spinner.go b/cli/internal/cmd/spinner.go index 1087b4949..a72374cdd 100644 --- a/cli/internal/cmd/spinner.go +++ b/cli/internal/cmd/spinner.go @@ -43,7 +43,7 @@ type spinner struct { spinFunc func(out io.Writer, wg *sync.WaitGroup, stop *atomic.Bool, delay time.Duration, text string, showDots bool) } -func newSpinnerOrStdout(cmd *cobra.Command) (spinnerInterf, error) { +func newSpinnerOrStderr(cmd *cobra.Command) (spinnerInterf, error) { debug, err := cmd.Flags().GetBool("debug") if err != nil { return nil, err diff --git a/cli/internal/cmd/upgradeplan.go b/cli/internal/cmd/upgradeplan.go index 92c7e0783..f94a03d8f 100644 --- a/cli/internal/cmd/upgradeplan.go +++ b/cli/internal/cmd/upgradeplan.go @@ -83,7 +83,7 @@ func (up *upgradePlanCmd) upgradePlan(cmd *cobra.Command, planner upgradePlanner if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) } - up.log.Debugf("Read config from %s", flags.configPath) + up.log.Debugf("Read configuration from %q", flags.configPath) // get current image version of the cluster csp := conf.GetProvider() up.log.Debugf("Using provider %s", csp.String()) @@ -140,7 +140,7 @@ func (up *upgradePlanCmd) upgradePlan(cmd *cobra.Command, planner upgradePlanner // filter out versions that are not compatible with the current cluster compatibleImages := getCompatibleImages(version, updateCandidates) - up.log.Debugf("Of those images, these ones are compaitble %v", compatibleImages) + up.log.Debugf("Of those images, these ones are compatible %v", compatibleImages) // get expected measurements for each image upgrades, err := getCompatibleImageMeasurements(cmd.Context(), cmd, client, rekor, []byte(flags.cosignPubKey), csp, compatibleImages) diff --git a/cli/internal/cmd/verify.go b/cli/internal/cmd/verify.go index 3747fb97e..215239832 100644 --- a/cli/internal/cmd/verify.go +++ b/cli/internal/cmd/verify.go @@ -74,7 +74,7 @@ func (v *verifyCmd) verify(cmd *cobra.Command, fileHandler file.Handler, verifyC } v.log.Debugf("Using flags: %+v", flags) - v.log.Debugf("Loading config file from %s", flags.configPath) + v.log.Debugf("Loading configuration file from %q", flags.configPath) conf, err := config.New(fileHandler, flags.configPath) if err != nil { return displayConfigValidationErrors(cmd.ErrOrStderr(), err) @@ -118,26 +118,26 @@ func (v *verifyCmd) parseVerifyFlags(cmd *cobra.Command, fileHandler file.Handle if err != nil { return verifyFlags{}, fmt.Errorf("parsing config path argument: %w", err) } - v.log.Debugf("config: %s", configPath) + v.log.Debugf("Configuration file flag is %q", configPath) ownerID := "" clusterID, err := cmd.Flags().GetString("cluster-id") if err != nil { return verifyFlags{}, fmt.Errorf("parsing cluster-id argument: %w", err) } - v.log.Debugf("cluster-id: %s", clusterID) + v.log.Debugf("Cluster ID flag is %q", clusterID) endpoint, err := cmd.Flags().GetString("node-endpoint") if err != nil { return verifyFlags{}, fmt.Errorf("parsing node-endpoint argument: %w", err) } - v.log.Debugf("node-endpoint: %s", endpoint) + v.log.Debugf("'node-endpoint' flag is %q", endpoint) // Get empty values from ID file emptyEndpoint := endpoint == "" emptyIDs := ownerID == "" && clusterID == "" if emptyEndpoint || emptyIDs { - v.log.Debugf("Trying to supplement empty flag values from %s", constants.ClusterIDsFileName) + v.log.Debugf("Trying to supplement empty flag values from %q", constants.ClusterIDsFileName) var idFile clusterid.File if err := fileHandler.ReadJSON(constants.ClusterIDsFileName, &idFile); err == nil { if emptyEndpoint { @@ -204,7 +204,7 @@ type constellationVerifier struct { func (v *constellationVerifier) Verify( ctx context.Context, endpoint string, req *verifyproto.GetAttestationRequest, validator atls.Validator, ) error { - v.log.Debugf("Dialing endpoint: %s", endpoint) + v.log.Debugf("Dialing endpoint: %q", endpoint) conn, err := v.dialer.DialInsecure(ctx, endpoint) if err != nil { return fmt.Errorf("dialing init server: %w", err)