From b9cb9305109fab82f9c80210498019dc71d3298f Mon Sep 17 00:00:00 2001 From: Michael Bridgen Date: Tue, 24 Jul 2018 14:05:59 +0100 Subject: [PATCH 1/2] Be more explicit and concise during automation run - say why an image was added for updating - add another safeguard against dubious updates -- check the image creation date is not zero - don't bother logging when nothing happens --- daemon/images.go | 28 ++++++++++++++++++---------- 1 file changed, 18 insertions(+), 10 deletions(-) diff --git a/daemon/images.go b/daemon/images.go index e72aa6f63..03659c0c2 100644 --- a/daemon/images.go +++ b/daemon/images.go @@ -2,6 +2,7 @@ package daemon import ( "context" + "fmt" "github.com/go-kit/kit/log" "github.com/pkg/errors" @@ -41,28 +42,35 @@ func (d *Daemon) pollForNewImages(logger log.Logger) { changes := &update.Automated{} for _, service := range services { for _, container := range service.ContainersOrNil() { - logger := log.With(logger, "service", service.ID, "container", container.Name, "currentimage", container.Image) - currentImageID := container.Image - if err != nil { - logger.Log("error", err) - continue - } - pattern := policy.GetTagPattern(candidateServicesPolicyMap, service.ID, container.Name) repo := currentImageID.Name - logger.Log("repo", repo, "pattern", pattern) + logger := log.With(logger, "service", service.ID, "container", container.Name, "repo", repo, "pattern", pattern, "current", currentImageID) filteredImages := imageRepos.GetRepoImages(repo).Filter(pattern) if latest, ok := filteredImages.Latest(); ok && latest.ID != currentImageID { if latest.ID.Tag == "" { - logger.Log("msg", "untagged image in available images", "action", "skip", "available", repo) + logger.Log("warning", "untagged image in available images", "action", "skip") + continue + } + if latest.CreatedAt.IsZero() { + logger.Log("warning", "image with zero created timestamp", "action", "skip") continue } newImage := currentImageID.WithNewTag(latest.ID.Tag) changes.Add(service.ID, container, newImage) - logger.Log("msg", "added image to changes", "newimage", newImage) + currentCreatedAt := "" + for _, info := range filteredImages { + if info.ID == currentImageID { + currentCreatedAt = info.CreatedAt.String() + } + } + if currentCreatedAt == "" { + currentCreatedAt = "filtered out or missing" + logger.Log("warning", "current image not in filtered images", "action", "add") + } + logger.Log("info", "added update to automation run", "new", newImage, "reason", fmt.Sprintf("latest %s (%s) > current %s (%s)", latest.ID.Tag, latest.CreatedAt, currentImageID.Tag, currentCreatedAt)) } } } From ebb3d3bd951b05a02ff7da0d2659af1d9cffce88 Mon Sep 17 00:00:00 2001 From: Michael Bridgen Date: Tue, 24 Jul 2018 15:01:23 +0100 Subject: [PATCH 2/2] Improve image with zero timestamp safeguard Since we'd expect an image with a zero timestamp to be shuffled to the end of the list, we probably won't hit the safeguard just put in, which checks whether the latest image has a zero timestamp. Instead, while we're looking for the current image so we can log the comparison, also check if _any_ images have a zero timestamp, and skip that container if they do. Ideally we'd avoid having data with this problem in the first place, but let's have defence in depth. --- daemon/images.go | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/daemon/images.go b/daemon/images.go index 03659c0c2..c0e9624e5 100644 --- a/daemon/images.go +++ b/daemon/images.go @@ -41,6 +41,7 @@ func (d *Daemon) pollForNewImages(logger log.Logger) { changes := &update.Automated{} for _, service := range services { + containers: for _, container := range service.ContainersOrNil() { currentImageID := container.Image pattern := policy.GetTagPattern(candidateServicesPolicyMap, service.ID, container.Name) @@ -51,24 +52,24 @@ func (d *Daemon) pollForNewImages(logger log.Logger) { if latest, ok := filteredImages.Latest(); ok && latest.ID != currentImageID { if latest.ID.Tag == "" { - logger.Log("warning", "untagged image in available images", "action", "skip") - continue - } - if latest.CreatedAt.IsZero() { - logger.Log("warning", "image with zero created timestamp", "action", "skip") - continue + logger.Log("warning", "untagged image in available images", "action", "skip container") + continue containers } newImage := currentImageID.WithNewTag(latest.ID.Tag) changes.Add(service.ID, container, newImage) currentCreatedAt := "" for _, info := range filteredImages { + if info.CreatedAt.IsZero() { + logger.Log("warning", "image with zero created timestamp", "image", info.ID, "action", "skip container") + continue containers + } if info.ID == currentImageID { currentCreatedAt = info.CreatedAt.String() } } if currentCreatedAt == "" { currentCreatedAt = "filtered out or missing" - logger.Log("warning", "current image not in filtered images", "action", "add") + logger.Log("warning", "current image not in filtered images", "action", "proceed anyway") } logger.Log("info", "added update to automation run", "new", newImage, "reason", fmt.Sprintf("latest %s (%s) > current %s (%s)", latest.ID.Tag, latest.CreatedAt, currentImageID.Tag, currentCreatedAt)) }