Bug 1450291 - Improve logs in image pruning #14405
+46
−36
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -6,15 +6,18 @@ import ( | |
| "net/http" | ||
| "reflect" | ||
| "sort" | ||
| "strings" | ||
| "time" | ||
|
|
||
| "github.com/docker/distribution/manifest/schema2" | ||
| "github.com/docker/distribution/registry/api/errcode" | ||
| "github.com/golang/glog" | ||
| gonum "github.com/gonum/graph" | ||
|
|
||
| kmeta "k8s.io/apimachinery/pkg/api/meta" | ||
| "k8s.io/apimachinery/pkg/api/resource" | ||
| metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" | ||
| "k8s.io/apimachinery/pkg/runtime" | ||
| kerrors "k8s.io/apimachinery/pkg/util/errors" | ||
| "k8s.io/apimachinery/pkg/util/sets" | ||
| kapi "k8s.io/kubernetes/pkg/api" | ||
|
|
@@ -377,7 +380,7 @@ func addImageStreamsToGraph(g graph.Graph, streams *imageapi.ImageStreamList, li | |
| for i := range streams.Items { | ||
| stream := &streams.Items[i] | ||
|
|
||
| glog.V(4).Infof("Examining ImageStream %s", getName(stream)) | ||
|
|
||
| // use a weak reference for old image revisions by default | ||
| oldImageRevisionReferenceKind := WeakReferencedImageEdgeKind | ||
|
|
@@ -388,7 +391,7 @@ func addImageStreamsToGraph(g graph.Graph, streams *imageapi.ImageStreamList, li | |
| oldImageRevisionReferenceKind = ReferencedImageEdgeKind | ||
| } | ||
|
|
||
| glog.V(4).Infof("Adding ImageStream %s to graph", getName(stream)) | ||
| isNode := imagegraph.EnsureImageStreamNode(g, stream) | ||
| imageStreamNode := isNode.(*imagegraph.ImageStreamNode) | ||
|
|
||
|
|
@@ -415,7 +418,7 @@ func addImageStreamsToGraph(g graph.Graph, streams *imageapi.ImageStreamList, li | |
| } | ||
| } | ||
|
|
||
| glog.V(4).Infof("Checking for existing strong reference from stream %s to image %s", getName(stream), imageNode.Image.Name) | ||
| if edge := g.Edge(imageStreamNode, imageNode); edge != nil && g.EdgeKinds(edge).Has(ReferencedImageEdgeKind) { | ||
| glog.V(4).Infof("Strong reference found") | ||
| continue | ||
|
|
@@ -432,7 +435,7 @@ func addImageStreamsToGraph(g graph.Graph, streams *imageapi.ImageStreamList, li | |
| continue | ||
| } | ||
|
|
||
| glog.V(4).Infof("Adding reference from stream %s to %s", getName(stream), cn.Describe()) | ||
| if cn.Type == imagegraph.ImageComponentTypeConfig { | ||
| g.AddEdge(imageStreamNode, s, ReferencedImageConfigEdgeKind) | ||
| } else { | ||
|
|
@@ -447,10 +450,7 @@ func addImageStreamsToGraph(g graph.Graph, streams *imageapi.ImageStreamList, li | |
| // exceedsLimits checks if given image exceeds LimitRanges defined in ImageStream's namespace. | ||
| func exceedsLimits(is *imageapi.ImageStream, image *imageapi.Image, limits map[string][]*kapi.LimitRange) bool { | ||
| limitRanges, ok := limits[is.Namespace] | ||
| if !ok || len(limitRanges) == 0 { | ||
| return false | ||
| } | ||
|
|
||
|
|
@@ -470,8 +470,8 @@ func exceedsLimits(is *imageapi.ImageStream, image *imageapi.Image, limits map[s | |
| } | ||
| if limitQuantity.Cmp(*imageSize) < 0 { | ||
| // image size is larger than the permitted limit range max size | ||
| glog.V(4).Infof("Image %s in stream %s exceeds limit %s: %v vs %v", | ||
| image.Name, getName(is), limitRange.Name, *imageSize, limitQuantity) | ||
| return true | ||
| } | ||
| } | ||
|
|
@@ -481,28 +481,26 @@ func exceedsLimits(is *imageapi.ImageStream, image *imageapi.Image, limits map[s | |
|
|
||
| // addPodsToGraph adds pods to the graph. | ||
| // | ||
| // Edges are added to the graph from each pod to the images specified by that | ||
| // pod's list of containers, as long as the image is managed by OpenShift. | ||
| func addPodsToGraph(g graph.Graph, pods *kapi.PodList, algorithm pruneAlgorithm) { | ||
| for i := range pods.Items { | ||
| pod := &pods.Items[i] | ||
|
|
||
| glog.V(4).Infof("Examining pod %s", getName(pod)) | ||
|
|
||
| // A pod is only *excluded* from being added to the graph if its phase is not | ||
| // pending or running. Additionally, it has to be at least as old as the minimum | ||
| // age threshold defined by the algorithm. | ||
| if pod.Status.Phase != kapi.PodRunning && pod.Status.Phase != kapi.PodPending { | ||
| age := metav1.Now().Sub(pod.CreationTimestamp.Time) | ||
| if age >= algorithm.keepYoungerThan { | ||
| glog.V(4).Infof("Pod %s is not running nor pending and age exceeds keepYoungerThan (%v) - skipping", getName(pod), age) | ||
| continue | ||
| } | ||
| } | ||
|
|
||
| glog.V(4).Infof("Adding pod %s to graph", getName(pod)) | ||
| podNode := kubegraph.EnsurePodNode(g, pod) | ||
|
|
||
| addPodSpecToGraph(g, &pod.Spec, podNode) | ||
|
|
@@ -548,7 +546,7 @@ func addPodSpecToGraph(g graph.Graph, spec *kapi.PodSpec, predecessor gonum.Node | |
| func addReplicationControllersToGraph(g graph.Graph, rcs *kapi.ReplicationControllerList) { | ||
| for i := range rcs.Items { | ||
| rc := &rcs.Items[i] | ||
| glog.V(4).Infof("Examining replication controller %s", getName(rc)) | ||
| rcNode := kubegraph.EnsureReplicationControllerNode(g, rc) | ||
| addPodSpecToGraph(g, &rc.Spec.Template.Spec, rcNode) | ||
| } | ||
|
|
@@ -562,7 +560,7 @@ func addReplicationControllersToGraph(g graph.Graph, rcs *kapi.ReplicationContro | |
| func addDeploymentConfigsToGraph(g graph.Graph, dcs *deployapi.DeploymentConfigList) { | ||
| for i := range dcs.Items { | ||
| dc := &dcs.Items[i] | ||
| glog.V(4).Infof("Examining DeploymentConfig %s", getName(dc)) | ||
| dcNode := deploygraph.EnsureDeploymentConfigNode(g, dc) | ||
| addPodSpecToGraph(g, &dc.Spec.Template.Spec, dcNode) | ||
| } | ||
|
|
@@ -574,7 +572,7 @@ func addDeploymentConfigsToGraph(g graph.Graph, dcs *deployapi.DeploymentConfigL | |
| func addBuildConfigsToGraph(g graph.Graph, bcs *buildapi.BuildConfigList) { | ||
| for i := range bcs.Items { | ||
| bc := &bcs.Items[i] | ||
| glog.V(4).Infof("Examining BuildConfig %s", getName(bc)) | ||
| bcNode := buildgraph.EnsureBuildConfigNode(g, bc) | ||
| addBuildStrategyImageReferencesToGraph(g, bc.Spec.Strategy, bcNode) | ||
| } | ||
|
|
@@ -586,7 +584,7 @@ func addBuildConfigsToGraph(g graph.Graph, bcs *buildapi.BuildConfigList) { | |
| func addBuildsToGraph(g graph.Graph, builds *buildapi.BuildList) { | ||
| for i := range builds.Items { | ||
| build := &builds.Items[i] | ||
| glog.V(4).Infof("Examining build %s", getName(build)) | ||
| buildNode := buildgraph.EnsureBuildNode(g, build) | ||
| addBuildStrategyImageReferencesToGraph(g, build.Spec.Strategy, buildNode) | ||
| } | ||
|
|
@@ -761,7 +759,7 @@ func pruneStreams(g graph.Graph, imageNodes []*imagegraph.ImageNode, streamPrune | |
| stream := streamNode.ImageStream | ||
| updatedTags := sets.NewString() | ||
|
|
||
| glog.V(4).Infof("Checking if ImageStream %s has references to image %s in status.tags", getName(stream), imageNode.Image.Name) | ||
|
|
||
| for tag, history := range stream.Status.Tags { | ||
| glog.V(4).Infof("Checking tag %q", tag) | ||
|
|
@@ -780,7 +778,7 @@ func pruneStreams(g graph.Graph, imageNodes []*imagegraph.ImageNode, streamPrune | |
| } | ||
| } | ||
| if len(newHistory.Items) == 0 { | ||
| glog.V(4).Infof("Removing tag %q from status.tags of ImageStream %s", tag, getName(stream)) | ||
| delete(stream.Status.Tags, tag) | ||
| } else { | ||
| stream.Status.Tags[tag] = newHistory | ||
|
|
@@ -789,7 +787,8 @@ func pruneStreams(g graph.Graph, imageNodes []*imagegraph.ImageNode, streamPrune | |
|
|
||
| updatedStream, err := streamPruner.DeleteImageStream(stream, imageNode.Image, updatedTags.List()) | ||
| if err != nil { | ||
| errs = append(errs, fmt.Errorf("error removing image %s from stream %s: %v", | ||
| imageNode.Image.Name, getName(stream), err)) | ||
| continue | ||
| } | ||
|
|
||
|
|
@@ -806,7 +805,7 @@ func pruneImages(g graph.Graph, imageNodes []*imagegraph.ImageNode, imagePruner | |
|
|
||
| for _, imageNode := range imageNodes { | ||
| if err := imagePruner.DeleteImage(imageNode.Image); err != nil { | ||
| errs = append(errs, fmt.Errorf("error removing image %q: %v", imageNode.Image.Name, err)) | ||
| } | ||
| } | ||
|
|
||
|
|
@@ -904,7 +903,7 @@ func (p *pruner) Prune( | |
| glog.V(1).Infof("Using registry: %s", registryURL) | ||
|
|
||
| if err := p.registryPinger.ping(registryURL); err != nil { | ||
| return fmt.Errorf("error communicating with registry %s: %v", registryURL, err) | ||
|
There was a problem hiding this comment. Is the url always present in the There was a problem hiding this comment. In some it might, in some it won't. I'd rather having it twice sometimes, than none in those cases. There was a problem hiding this comment. I find these messages already too long and they are quite common. Also I will need to update documentation here. Looking at the current logging, it seems like this statement will sometimes triple the url. Could you please either remove it from the pinger or from here to make sure it's logged at least once but no more than twice? |
||
| } | ||
|
|
||
| prunableImageNodes, prunableImageIDs := calculatePrunableImages(p.g, imageNodes) | ||
|
|
@@ -1001,9 +1000,9 @@ func pruneBlobs( | |
| errs := []error{} | ||
|
|
||
| for _, cn := range componentNodes { | ||
| if err := blobPruner.DeleteBlob(registryClient, registryURL, cn.Component); err != nil { | ||
| errs = append(errs, fmt.Errorf("error removing blob from registry %s: blob %q: %v", | ||
| registryURL, cn.Component, err)) | ||
| } | ||
| } | ||
|
|
||
|
|
@@ -1069,7 +1068,7 @@ func NewImageStreamDeleter(streams client.ImageStreamsNamespacer) ImageStreamDel | |
| } | ||
|
|
||
| func (p *imageStreamDeleter) DeleteImageStream(stream *imageapi.ImageStream, image *imageapi.Image, updatedTags []string) (*imageapi.ImageStream, error) { | ||
| glog.V(4).Infof("Updating ImageStream %s", getName(stream)) | ||
| glog.V(5).Infof("Updated stream: %#v", stream) | ||
| return p.streams.ImageStreams(stream.Namespace).UpdateStatus(stream) | ||
| } | ||
|
|
@@ -1081,14 +1080,16 @@ func deleteFromRegistry(registryClient *http.Client, url string) error { | |
| deleteFunc := func(proto, url string) error { | ||
| req, err := http.NewRequest("DELETE", url, nil) | ||
| if err != nil { | ||
| return err | ||
| } | ||
|
|
||
| glog.V(4).Infof("Sending request to registry") | ||
| resp, err := registryClient.Do(req) | ||
| if err != nil { | ||
| if proto != "https" && strings.Contains(err.Error(), "malformed HTTP response") { | ||
| return fmt.Errorf("%v.\n* Are you trying to connect to a TLS-enabled registry without TLS?", err) | ||
| } | ||
|
There was a problem hiding this comment. I'll update this now that the other one is in place. There was a problem hiding this comment. Or maybe I should ask in what way it will conflict? This will give you a hint that you should use https when remote end supports that. #14114 will force you to use that, so this error should be seen very rarely, in some weird cases, I guess. There was a problem hiding this comment. 👍 for the hint. Nevertheless, this should have been captured by the I must have forgotten to modify this code same the way as the origin/pkg/image/prune/prune.go Line 199 in 90592c5 There was a problem hiding this comment. By the way, the hint would be useful in the pinger as well. There was a problem hiding this comment. You can move it as a followup, in that case. |
||
| return err | ||
| } | ||
| defer resp.Body.Close() | ||
|
|
||
|
|
@@ -1147,7 +1148,7 @@ func NewLayerLinkDeleter() LayerLinkDeleter { | |
| } | ||
|
|
||
| func (p *layerLinkDeleter) DeleteLayerLink(registryClient *http.Client, registryURL, repoName, linkName string) error { | ||
| glog.V(4).Infof("Deleting layer link from registry %q: repo %q, layer link %q", registryURL, repoName, linkName) | ||
| return deleteFromRegistry(registryClient, fmt.Sprintf("%s/v2/%s/blobs/%s", registryURL, repoName, linkName)) | ||
| } | ||
|
|
||
|
|
@@ -1162,7 +1163,7 @@ func NewBlobDeleter() BlobDeleter { | |
| } | ||
|
|
||
| func (p *blobDeleter) DeleteBlob(registryClient *http.Client, registryURL, blob string) error { | ||
| glog.V(4).Infof("Deleting blob from registry %q: blob %q", registryURL, blob) | ||
| return deleteFromRegistry(registryClient, fmt.Sprintf("%s/admin/blobs/%s", registryURL, blob)) | ||
| } | ||
|
|
||
|
|
@@ -1177,6 +1178,15 @@ func NewManifestDeleter() ManifestDeleter { | |
| } | ||
|
|
||
| func (p *manifestDeleter) DeleteManifest(registryClient *http.Client, registryURL, repoName, manifest string) error { | ||
| glog.V(4).Infof("Deleting manifest from registry %q: repo %q, manifest %q", registryURL, repoName, manifest) | ||
| return deleteFromRegistry(registryClient, fmt.Sprintf("%s/v2/%s/manifests/%s", registryURL, repoName, manifest)) | ||
| } | ||
|
|
||
| func getName(obj runtime.Object) string { | ||
| accessor, err := kmeta.Accessor(obj) | ||
| if err != nil { | ||
| glog.V(4).Infof("Error getting accessor for %#v", obj) | ||
| return "<unknown>" | ||
| } | ||
| return fmt.Sprintf("%s/%s", accessor.GetNamespace(), accessor.GetName()) | ||
| } | ||
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
s/age exceeds/age is within/The name of the variable is misleading 😄.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ha, I was struggling with that log message for a while. Your suggestion is definitely the best!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Actually, no, what I said above is wrong. It has to say exceeds, because we're referring to pods that are not added to graph (skipped), which will allow the images to be pruned (because of lack of strong references).