diff --git a/cloudprofilesync/imageupdater.go b/cloudprofilesync/imageupdater.go index 9b2fd48..4f5929b 100644 --- a/cloudprofilesync/imageupdater.go +++ b/cloudprofilesync/imageupdater.go @@ -16,9 +16,8 @@ import ( func filterImages(log logr.Logger, versions []SourceImage) []SourceImage { filtered := make([]SourceImage, 0, len(versions)) - log.Info("starting to filter source images", "total_versions", len(versions)) for _, version := range versions { - parsed, err := semver.Parse(version.Version) + _, err := semver.Parse(version.Version) if err != nil { log.V(1).Info("skipping invalid version", "version", version.Version) continue @@ -27,10 +26,8 @@ func filterImages(log logr.Logger, versions []SourceImage) []SourceImage { log.V(1).Info("skipping version with no architectures", "version", version.Version) continue } - log.V(1).Info("valid version found", "version", version.Version, "major", parsed.Major, "minor", parsed.Minor, "patch", parsed.Patch, "pre_release", parsed.Pre) filtered = append(filtered, version) } - log.Info("finished filtering source images", "valid_versions", len(filtered)) return filtered } @@ -42,45 +39,33 @@ type ImageUpdater struct { } func (iu *ImageUpdater) Update(ctx context.Context, cpSpec *gardenerv1beta1.CloudProfileSpec) error { - iu.Log.Info("checking source", "image", iu.ImageName) sourceImages, err := iu.Source.GetVersions(ctx) if err != nil { - iu.Log.Error(err, "failed to retrieve image versions from OCI registry", "image", iu.ImageName, "error_msg", err.Error()) return fmt.Errorf("failed to retrieve image versions from OCI registry: %w", err) } - iu.Log.Info("retrieved source images", "count", len(sourceImages), "image", iu.ImageName) sourceImages = filterImages(iu.Log, sourceImages) // Images from a source arrive in no guaranteed order. A changed order // in the source images may lead to a changed order in the CloudProfile, // causing unnecesscary reconciliations. - iu.Log.Info("filtered valid images", "count", len(sourceImages), "image", iu.ImageName) - for _, img := range sourceImages { - iu.Log.V(1).Info("valid source image", "version", img.Version, "architectures", img.Architectures) - } slices.SortFunc(sourceImages, func(a, b SourceImage) int { return cmp.Compare(a.Version, b.Version) }) - iu.Log.V(1).Info("sorted source images", "image", iu.ImageName) imageIndex := slices.IndexFunc(cpSpec.MachineImages, func(img gardenerv1beta1.MachineImage) bool { return img.Name == iu.ImageName }) if imageIndex == -1 { cpSpec.MachineImages = append(cpSpec.MachineImages, gardenerv1beta1.MachineImage{Name: iu.ImageName}) imageIndex = len(cpSpec.MachineImages) - 1 - iu.Log.Info("created new MachineImage entry", "image", iu.ImageName) } image := &cpSpec.MachineImages[imageIndex] existingVersions := make(map[string]int, len(image.Versions)) for idx, version := range image.Versions { existingVersions[version.Version] = idx } - iu.Log.V(1).Info("existing versions in CloudProfile", "count", len(existingVersions), "image", iu.ImageName) for _, sourceImage := range sourceImages { if idx, exists := existingVersions[sourceImage.Version]; exists { - iu.Log.V(1).Info("updating existing version architectures", "version", sourceImage.Version, "architectures", sourceImage.Architectures) image.Versions[idx].Architectures = sourceImage.Architectures } else { - iu.Log.Info("adding new version to CloudProfile", "version", sourceImage.Version, "architectures", sourceImage.Architectures) image.Versions = append(image.Versions, gardenerv1beta1.MachineImageVersion{ ExpirableVersion: gardenerv1beta1.ExpirableVersion{ Version: sourceImage.Version, @@ -90,13 +75,9 @@ func (iu *ImageUpdater) Update(ctx context.Context, cpSpec *gardenerv1beta1.Clou } } if iu.Provider != nil { - iu.Log.Info("invoking provider Configure", "image", iu.ImageName, "versions_count", len(sourceImages)) if err := iu.Provider.Configure(cpSpec, sourceImages); err != nil { - iu.Log.Error(err, "provider Configure failed", "image", iu.ImageName, "error_msg", err.Error()) return fmt.Errorf("failed to invoke provider: %w", err) } - iu.Log.Info("provider Configure succeeded", "image", iu.ImageName) } - iu.Log.Info("finished updating CloudProfile for image", "image", iu.ImageName, "total_versions", len(image.Versions)) return nil } diff --git a/controllers/managedcloudprofile_controller.go b/controllers/managedcloudprofile_controller.go index 9317bba..a22b08a 100644 --- a/controllers/managedcloudprofile_controller.go +++ b/controllers/managedcloudprofile_controller.go @@ -84,42 +84,33 @@ func (r *Reconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Resu return ctrl.Result{}, client.IgnoreNotFound(err) } - log.Info("starting reconciliation", "ManagedCloudProfile", mcp.Name, "generation", mcp.Generation) - if err := r.reconcileCloudProfile(ctx, log, &mcp); err != nil { return ctrl.Result{}, err } - log.Info("reconciled ManagedCloudProfile") - if err := r.reconcileGarbageCollection(ctx, log, &mcp); err != nil { + if err := r.reconcileGarbageCollection(ctx, &mcp); err != nil { return ctrl.Result{}, err } + log.Info("reconciled ManagedCloudProfile") return ctrl.Result{RequeueAfter: 5 * time.Minute}, nil } func (r *Reconciler) reconcileCloudProfile(ctx context.Context, log logr.Logger, mcp *v1alpha1.ManagedCloudProfile) error { var cloudProfile gardenerv1beta1.CloudProfile cloudProfile.Name = mcp.Name - log.V(1).Info("starting CloudProfile reconciliation", "name", cloudProfile.Name, "generation", mcp.Generation) op, err := controllerutil.CreateOrPatch(ctx, r.Client, &cloudProfile, func() error { if err := controllerutil.SetControllerReference(mcp, &cloudProfile, r.Scheme()); err != nil { - log.Error(err, "failed to set controller reference") return err } - log.V(1).Info("controller reference set") cloudProfile.Spec = CloudProfileSpecToGardener(&mcp.Spec.CloudProfile) - log.V(1).Info("converted ManagedCloudProfile spec to CloudProfileSpec", "machineImages", len(cloudProfile.Spec.MachineImages)) errs := make([]error, 0) for _, updates := range mcp.Spec.MachineImageUpdates { - log.V(1).Info("updating machine images from source", "imageName", updates.ImageName) if updateErr := r.updateMachineImages(ctx, log, updates, &cloudProfile.Spec); updateErr != nil { - log.Error(updateErr, "failed to update machine images", "imageName", updates.ImageName) errs = append(errs, updateErr) } } gardenerv1beta1.SetObjectDefaults_CloudProfile(&cloudProfile) - log.V(1).Info("set CloudProfile defaults") return errors.Join(errs...) }) if err != nil { @@ -131,17 +122,13 @@ func (r *Reconciler) reconcileCloudProfile(ctx context.Context, log logr.Logger, Message: fmt.Sprintf("Failed to apply CloudProfile: %s", err), }) if statusErr != nil { - log.Error(statusErr, "failed to patch ManagedCloudProfile status") return fmt.Errorf("failed to patch ManagedCloudProfile status: %w", statusErr) } if apierrors.IsInvalid(err) { - log.Error(err, "CloudProfile invalid, skipping apply") return nil } - log.Error(err, "failed to create or patch CloudProfile") return fmt.Errorf("failed to create or patch CloudProfile: %w", err) } - log.Info("applied cloud profile", "op", op) if op != controllerutil.OperationResultNone { statusErr := r.patchStatusAndCondition(ctx, mcp, v1alpha1.SucceededReconcileStatus, metav1.Condition{ Type: CloudProfileAppliedConditionType, @@ -151,19 +138,14 @@ func (r *Reconciler) reconcileCloudProfile(ctx context.Context, log logr.Logger, Message: "Generated CloudProfile applied successfully", }) if statusErr != nil { - log.Error(statusErr, "failed to patch ManagedCloudProfile status after apply") return fmt.Errorf("failed to patch ManagedCloudProfile status: %w", statusErr) } - log.V(1).Info("ManagedCloudProfile status updated to SucceededReconcileStatus") } - log.V(1).Info("finished CloudProfile reconciliation", "name", cloudProfile.Name) return nil } -func (r *Reconciler) reconcileGarbageCollection(ctx context.Context, log logr.Logger, mcp *v1alpha1.ManagedCloudProfile) error { - log.V(1).Info("starting garbage collection", "ManagedCloudProfile", mcp.Name) +func (r *Reconciler) reconcileGarbageCollection(ctx context.Context, mcp *v1alpha1.ManagedCloudProfile) error { if mcp.Spec.GarbageCollection == nil || !mcp.Spec.GarbageCollection.Enabled { - log.V(1).Info("garbage collection disabled or not configured") return nil } if mcp.Spec.GarbageCollection.MaxAge.Duration < 0 { @@ -171,23 +153,17 @@ func (r *Reconciler) reconcileGarbageCollection(ctx context.Context, log logr.Lo } cutoff := time.Now().Add(-mcp.Spec.GarbageCollection.MaxAge.Duration) - log.V(1).Info("garbage collection cutoff time calculated", "cutoff", cutoff) for _, updates := range mcp.Spec.MachineImageUpdates { if updates.Source.OCI == nil { - log.V(1).Info("skipping update with no OCI source", "image", updates.ImageName) continue } - log.V(1).Info("retrieving source registry", "registry", updates.Source.OCI.Registry) registryClient, err := r.RegistryProviderFunc(updates.Source.OCI.Registry) if err != nil { return r.failWithStatusUpdate(ctx, mcp, fmt.Errorf("no registry provider found for registry %q: %w", updates.Source.OCI.Registry, err)) } - - log.V(1).Info("retrieving source versions", "image", updates.ImageName) - ctx = logr.NewContext(ctx, log) tags, err := registryClient.GetTags( ctx, updates.Source.OCI.Registry, @@ -197,53 +173,38 @@ func (r *Reconciler) reconcileGarbageCollection(ctx context.Context, log logr.Lo return r.failWithStatusUpdate(ctx, mcp, fmt.Errorf("failed to fetch tags: %w", err)) } - log.V(1).Info("retrieved source versions", "count", len(tags)) - referencedVersions, err := r.getReferencedVersions(ctx, mcp.Name, updates.ImageName, log) + referencedVersions, err := r.getReferencedVersions(ctx, mcp.Name, updates.ImageName) if err != nil { return r.failWithStatusUpdate(ctx, mcp, fmt.Errorf("failed to determine referenced versions for garbage collection: %w", err)) } - log.V(1).Info("referenced versions retrieved", "count", len(referencedVersions), "image", updates.ImageName) versionsToDelete := make(map[string]struct{}) for tag, pushedAt := range tags { if _, isReferenced := referencedVersions[tag]; isReferenced { - log.V(2).Info("skipping referenced version", "version", tag) continue } if pushedAt.Before(cutoff) { versionsToDelete[tag] = struct{}{} - log.V(1).Info("marking version for deletion", "version", tag, "pushedAt", pushedAt) } } if len(versionsToDelete) > 0 { - log.V(1).Info("deleting versions from CloudProfile", "image", updates.ImageName, "count", len(versionsToDelete)) if err := r.deleteVersions(ctx, mcp.Name, updates.ImageName, versionsToDelete); err != nil { if apierrors.IsInvalid(err) { - log.V(1).Info("garbage collection validation failed, skipping", "image", updates.ImageName) continue } return r.failWithStatusUpdate(ctx, mcp, fmt.Errorf("failed to delete image versions: %w", err)) } - for v := range versionsToDelete { - log.Info("deleted image version from CloudProfile", "image", updates.ImageName, "version", v) - } - } else { - log.V(1).Info("no versions to delete for image", "image", updates.ImageName) } } - log.V(1).Info("completed garbage collection", "ManagedCloudProfile", mcp.Name) return nil } func (r *Reconciler) deleteVersions(ctx context.Context, cloudProfileName, imageName string, versionsToDelete map[string]struct{}) error { - log := ctrl.LoggerFrom(ctx) - log.V(1).Info("starting deleteVersions", "cloudProfile", cloudProfileName, "image", imageName, "versionsToDelete", versionsToDelete) var cp gardenerv1beta1.CloudProfile if err := r.Get(ctx, types.NamespacedName{Name: cloudProfileName}, &cp); err != nil { - log.Error(err, "failed to get CloudProfile") return err } @@ -251,27 +212,20 @@ func (r *Reconciler) deleteVersions(ctx context.Context, cloudProfileName, image if cp.Spec.MachineImages[i].Name != imageName { continue } - originalCount := len(cp.Spec.MachineImages[i].Versions) cp.Spec.MachineImages[i].Versions = slices.DeleteFunc(cp.Spec.MachineImages[i].Versions, func(mv gardenerv1beta1.MachineImageVersion) bool { _, exists := versionsToDelete[mv.Version] - if exists { - log.V(1).Info("removing version from CloudProfile MachineImages", "version", mv.Version) - } return exists }) - log.V(1).Info("updated CloudProfile MachineImages versions", "original", originalCount, "remaining", len(cp.Spec.MachineImages[i].Versions)) } if cp.Spec.ProviderConfig != nil { var cfg providercfg.CloudProfileConfig if err := json.Unmarshal(cp.Spec.ProviderConfig.Raw, &cfg); err != nil { - log.Error(err, "failed to unmarshal ProviderConfig") return fmt.Errorf("failed to unmarshal ProviderConfig: %w", err) } for i := range cfg.MachineImages { if cfg.MachineImages[i].Name != imageName { continue } - originalCount := len(cfg.MachineImages[i].Versions) cfg.MachineImages[i].Versions = slices.DeleteFunc(cfg.MachineImages[i].Versions, func(mv providercfg.MachineImageVersion) bool { idx := strings.LastIndex(mv.Image, ":") if idx == -1 { @@ -279,35 +233,26 @@ func (r *Reconciler) deleteVersions(ctx context.Context, cloudProfileName, image } version := mv.Image[idx+1:] _, exists := versionsToDelete[version] - if exists { - log.V(1).Info("removing version from ProviderConfig", "version", version, "imageRef", mv.Image) - } return exists }) - log.V(1).Info("updated ProviderConfig MachineImages versions", "original", originalCount, "remaining", len(cfg.MachineImages[i].Versions)) } raw, err := json.Marshal(cfg) if err != nil { - log.Error(err, "failed to marshal ProviderConfig after deletion") return fmt.Errorf("failed to marshal ProviderConfig: %w", err) } cp.Spec.ProviderConfig.Raw = raw } if err := r.Update(ctx, &cp); err != nil { - log.Error(err, "failed to update CloudProfile after deleting versions") return err } - log.V(1).Info("finished deleteVersions successfully") return nil } -func (r *Reconciler) getReferencedVersions(ctx context.Context, cloudProfileName, imageName string, log logr.Logger) (map[string]struct{}, error) { +func (r *Reconciler) getReferencedVersions(ctx context.Context, cloudProfileName, imageName string) (map[string]struct{}, error) { referenced := make(map[string]struct{}) - log.V(1).Info("retrieving referenced versions", "cloudProfile", cloudProfileName, "image", imageName) shootList := &gardenerv1beta1.ShootList{} if err := r.List(ctx, shootList, client.InNamespace(metav1.NamespaceAll)); err != nil { - log.Error(err, "failed to list Shoots") return nil, fmt.Errorf("failed to list Shoots: %w", err) } for _, shoot := range shootList.Items { @@ -321,24 +266,19 @@ func (r *Reconciler) getReferencedVersions(ctx context.Context, cloudProfileName } if worker.Machine.Image.Version != nil { referenced[*worker.Machine.Image.Version] = struct{}{} - log.V(1).Info("found referenced version in Shoot", "shoot", shoot.Name, "worker", worker.Name, "version", *worker.Machine.Image.Version) } } } - log.V(1).Info("completed retrieval of referenced versions", "count", len(referenced)) return referenced, nil } func (r *Reconciler) updateMachineImages(ctx context.Context, log logr.Logger, update v1alpha1.MachineImageUpdate, cpSpec *gardenerv1beta1.CloudProfileSpec) error { - log.Info("updating machine images", "imageName", update.ImageName) var source cloudprofilesync.Source switch { case update.Source.OCI != nil: - log.V(1).Info("using OCI source", "registry", update.Source.OCI.Registry, "repository", update.Source.OCI.Repository) password, err := r.getCredential(ctx, update.Source.OCI.Password) if err != nil { - log.Error(err, "failed to get credentials for OCI source", "imageName", update.ImageName) return err } src, err := r.OCISourceFactory.Create(cloudprofilesync.OCIParams{ @@ -349,19 +289,16 @@ func (r *Reconciler) updateMachineImages(ctx context.Context, log logr.Logger, u Parallel: 1, }, update.Source.OCI.Insecure) if err != nil { - log.Error(err, "failed to initialize OCI source", "imageName", update.ImageName) return fmt.Errorf("failed to initialize OCI source: %w", err) } source = src default: - log.Error(nil, "no machine images source configured", "imageName", update.ImageName) return errors.New("no machine images source configured") } var provider cloudprofilesync.Provider if update.Provider.IroncoreMetal != nil { - log.V(1).Info("using provider IroncoreMetal", "registry", update.Provider.IroncoreMetal.Registry, "repository", update.Provider.IroncoreMetal.Repository) provider = &cloudprofilesync.IroncoreProvider{ Registry: update.Provider.IroncoreMetal.Registry, Repository: update.Provider.IroncoreMetal.Repository, @@ -374,12 +311,9 @@ func (r *Reconciler) updateMachineImages(ctx context.Context, log logr.Logger, u Provider: provider, ImageName: update.ImageName, } - log.V(1).Info("calling ImageUpdater.Update", "imageName", update.ImageName) if err := imageUpdater.Update(ctx, cpSpec); err != nil { - log.Error(err, "ImageUpdater.Update failed", "imageName", update.ImageName) return fmt.Errorf("updating machine images failed: %w", err) } - log.Info("successfully updated machine images", "imageName", update.ImageName) return nil } @@ -458,31 +392,16 @@ func (r *Reconciler) failWithStatusUpdate(ctx context.Context, mcp *v1alpha1.Man } func fetchKeppelTags(ctx context.Context, registry, repository string) (map[string]time.Time, error) { - log, err := logr.FromContext(ctx) - if err != nil { - return nil, fmt.Errorf("failed to extract logger from context: %w", err) - } - baseURL := registryBaseURL(log, registry, false) + baseURL := registryBaseURL(registry, false) - keppelURL, err := keppelURL(log, baseURL, repository) + keppelURL, err := keppelURL(baseURL, repository) if err != nil { - log.Error(err, "failed to build keppel URL", - "registry", registry, - "repository", repository, - ) - return nil, err + return nil, fmt.Errorf("failed to build keppel URL: %w", err) } - log.V(1).Info("fetching keppel tags", - "url", keppelURL, - "registry", registry, - "repository", repository, - ) - req, err := http.NewRequestWithContext(ctx, http.MethodGet, keppelURL, http.NoBody) if err != nil { - log.Error(err, "failed to create keppel request") - return nil, err + return nil, fmt.Errorf("failed to create keppel request: %w", err) } tr := &http.Transport{ @@ -499,59 +418,37 @@ func fetchKeppelTags(ctx context.Context, registry, repository string) (map[stri resp, err := httpClient.Do(req) if err != nil { - log.Error(err, "keppel http request failed", "url", keppelURL) return nil, err } defer resp.Body.Close() - log.V(1).Info("keppel response received", "status", resp.StatusCode) - if resp.StatusCode != http.StatusOK { err := fmt.Errorf("keppel API returned status %d", resp.StatusCode) - log.Error(err, "unexpected keppel status code") return nil, err } var result KeppelManifestsResponse if err := json.NewDecoder(resp.Body).Decode(&result); err != nil { - log.Error(err, "failed to decode keppel response") return nil, err } - log.V(1).Info("decoded keppel response", "manifests", len(result.Manifests)) - tagMap := make(map[string]time.Time) - for i, m := range result.Manifests { - log.V(2).Info("processing manifest", - "index", i, - "digest", m.Digest, - "tags", len(m.Tags), - ) - + for _, m := range result.Manifests { for _, t := range m.Tags { if t.PushedAt == 0 { - log.V(1).Info("tag without pushed at", "name", t.Name) continue } - - log.V(2).Info("processing tag", - "tag", t.Name, - "pushedAt", t.PushedAt, - ) tagMap[t.Name] = time.Unix(t.PushedAt, 0) } } - log.V(1).Info("finished fetching keppel tags", "count", len(tagMap)) - return tagMap, nil } -func keppelURL(log logr.Logger, baseURL, repository string) (string, error) { - account, repo, err := splitKeppelRepository(log, repository) +func keppelURL(baseURL, repository string) (string, error) { + account, repo, err := splitKeppelRepository(repository) if err != nil { - log.Error(err, "failed to split keppel repository", "repository", repository) return "", err } @@ -562,17 +459,10 @@ func keppelURL(log logr.Logger, baseURL, repository string) (string, error) { repo, ) - log.V(1).Info("constructed keppel url", - "baseURL", baseURL, - "account", account, - "repo", repo, - "url", keppelURL, - ) - return keppelURL, nil } -func registryBaseURL(log logr.Logger, registryHost string, insecure bool) string { +func registryBaseURL(registryHost string, insecure bool) string { scheme := "https" if insecure { scheme = "http" @@ -585,37 +475,21 @@ func registryBaseURL(log logr.Logger, registryHost string, insecure bool) string base := u.String() - log.V(2).Info("computed registry base url", - "registryHost", registryHost, - "insecure", insecure, - "baseURL", base, - ) - return base } -func splitKeppelRepository(log logr.Logger, repository string) (account, repo string, err error) { +func splitKeppelRepository(repository string) (account, repo string, err error) { parts := strings.SplitN(repository, "/", 2) if len(parts) != 2 || parts[0] == "" || parts[1] == "" { err := fmt.Errorf("invalid repository format %q, must be /", repository) - log.Error(err, "invalid keppel repository format", - "repository", repository, - ) - return "", "", err } account = parts[0] repo = parts[1] - log.V(2).Info("split keppel repository", - "repository", repository, - "account", account, - "repo", repo, - ) - return account, repo, nil }