docker: improvement logs on pulling image (#748)

Previously when we call `checkIfImageNotExists` function we check for
errors and if image does not exists on the same statement and only log
if some errors occurs, which turn the code a bit confuse to read.

This commit change to check for errors and if image does not exists on
different statements and also add a debug logging to inform that image
does not exists on cache and we will try to pull from registry.

This commit also add some tests to assert that we are pulling the image
only if its not exists on cache.

Signed-off-by: Matheus Alcantara <[email protected]>

internal/helpers/messages/debug.go

@@ -32,4 +32,5 @@ const (
 	MsgDebugShowWorkdir                  = "{HORUSEC_CLI} The workdir setup for run in path:"
 	MsgDebugToolIgnored                  = "{HORUSEC_CLI} The tool was ignored for run in this analysis: "
 	MsgDebugVulnHashToFix                = "{HORUSEC_CLI} Vulnerability Hash expected to be FIXED: "
+	MsgDebugDockerImageDoesNotExists     = "{HORUSEC_CLI} Image %s does not exists. Pulling from registry"
 )

internal/services/docker/docker_api.go

@@ -103,20 +103,27 @@ func (d *API) CreateLanguageAnalysisContainer(data *docker.AnalysisData) (contai
 	return d.logStatusAndExecuteCRDContainer(data.GetCustomOrDefaultImage(), d.replaceCMDAnalysisID(data.CMD))
 }
 
+// PullImage check if an image already exists on cache, if its not, pull from registry.
+//
+// nolint:funlen
 func (d *API) PullImage(imageWithTagAndRegistry string) error {
 	if d.config.DisableDocker {
 		return nil
 	}
 
-	if imageNotExist, err := d.checkImageNotExists(imageWithTagAndRegistry); err != nil || !imageNotExist {
+	imageNotExist, err := d.checkIfImageNotExists(imageWithTagAndRegistry)
+	if err != nil {
 		logger.LogError(fmt.Sprintf("%s -> %s",
 			messages.MsgErrorFailedToPullImage, imageWithTagAndRegistry), err)
 		return err
+	} else if imageNotExist {
+		logger.LogDebugWithLevel(fmt.Sprintf(messages.MsgDebugDockerImageDoesNotExists, imageWithTagAndRegistry))
+		err = d.downloadImage(imageWithTagAndRegistry)
+		logger.LogError(fmt.Sprintf("%s -> %s", messages.MsgErrorFailedToPullImage, imageWithTagAndRegistry), err)
+		return err
 	}
 
-	err := d.downloadImage(imageWithTagAndRegistry)
-	logger.LogError(fmt.Sprintf("%s -> %s", messages.MsgErrorFailedToPullImage, imageWithTagAndRegistry), err)
-	return err
+	return nil
 }
 
 func (d *API) downloadImage(imageWithTagAndRegistry string) error {
@@ -157,7 +164,8 @@ func (d *API) readPullReader(imageWithTagAndRegistry string, reader io.ReadClose
 	return nil
 }
 
-func (d *API) checkImageNotExists(imageWithTagAndRegistry string) (bool, error) {
+// checkIfImageNotExists return true if image does not exists on cache, otherwise false.
+func (d *API) checkIfImageNotExists(imageWithTagAndRegistry string) (bool, error) {
 	d.mutex.Lock()
 	defer d.mutex.Unlock()
 	args := dockerTypesFilters.NewArgs()

internal/services/docker/docker_api_test.go

@@ -249,6 +249,40 @@ func TestDockerAPI_CreateLanguageAnalysisContainer(t *testing.T) {
 
 		assert.NoError(t, err)
 	})
+
+	t.Run("Should pull image from registry when not exists on cache", func(t *testing.T) {
+		dockerAPIClient := new(client.Mock)
+		dockerAPIClient.On("ImageList").Return([]types.ImageSummary{}, nil)
+		dockerAPIClient.On("ImagePull").Return(io.NopCloser(bytes.NewReader([]byte("Some data"))), nil)
+		dockerAPIClient.On("ContainerCreate").Return(container.ContainerCreateCreatedBody{ID: uuid.New().String()}, nil)
+		dockerAPIClient.On("ContainerStart").Return(nil)
+		dockerAPIClient.On("ContainerWait").Return(container.ContainerWaitOKBody{}, nil)
+		dockerAPIClient.On("ContainerLogs").Return(io.NopCloser(bytes.NewReader([]byte("{}"))), nil)
+		dockerAPIClient.On("ContainerRemove").Return(nil)
+
+		api := New(dockerAPIClient, &cliConfig.Config{}, uuid.New())
+
+		err := api.PullImage("random/image")
+
+		assert.NoError(t, err)
+	})
+
+	t.Run("Should not pull image from registry when exists on cache", func(t *testing.T) {
+		dockerAPIClient := new(client.Mock)
+		dockerAPIClient.On("ImageList").Return([]types.ImageSummary{{ID: uuid.New().String()}}, nil)
+		dockerAPIClient.On("ContainerCreate").Return(container.ContainerCreateCreatedBody{ID: uuid.New().String()}, nil)
+		dockerAPIClient.On("ContainerStart").Return(nil)
+		dockerAPIClient.On("ContainerWait").Return(container.ContainerWaitOKBody{}, nil)
+		dockerAPIClient.On("ContainerLogs").Return(io.NopCloser(bytes.NewReader([]byte("{}"))), nil)
+		dockerAPIClient.On("ContainerRemove").Return(nil)
+
+		api := New(dockerAPIClient, &cliConfig.Config{}, uuid.New())
+
+		err := api.PullImage("random/image")
+
+		assert.NoError(t, err)
+		dockerAPIClient.AssertNotCalled(t, "ImagePull")
+	})
 }
 
 func TestDeleteContainersFromAPI(t *testing.T) {