feat: Output builder logs to file

Makefile

@@ -33,7 +33,7 @@ lint.fix: ## Lint and fix source code
 
 .PHONY: test
 test: ## Run tests
-	go test -v ./... -coverprofile coverage.output
+	go test -race -v ./... -coverprofile coverage.output
 
 fmt: ## Run `go fmt` on all files
 	find -name '*.go' -exec gofmt -w -s '{}' ';'

dag/image.go

@@ -3,6 +3,7 @@ package dag
 import (
 	"fmt"
 	"os"
+	"path"
 	"strings"
 	"sync"
 	"time"
@@ -134,11 +135,21 @@ func (img *Image) doRebuild(newTag string, localOnly, disableRunTests bool) erro
 		labels["org.opencontainers.image.source"] = source
 	}
 
+	if err := os.MkdirAll("dist/logs", 0o755); err != nil {
+		return fmt.Errorf("could not create directory %s: %w", "dist/logs", err)
+	}
+	filePath := path.Join("dist/logs", fmt.Sprintf("%s.log", img.ShortName))
+	fileOutput, err := os.Create(filePath)
+	if err != nil {
+		return fmt.Errorf("failed to create file %s: %w", filePath, err)
+	}
+
 	opts := types.ImageBuilderOpts{
-		Context: img.Dockerfile.ContextPath,
-		Tag:     fmt.Sprintf("%s:%s", img.Name, newTag),
-		Labels:  labels,
-		Push:    !localOnly,
+		Context:   img.Dockerfile.ContextPath,
+		Tag:       fmt.Sprintf("%s:%s", img.Name, newTag),
+		Labels:    labels,
+		Push:      !localOnly,
+		LogOutput: fileOutput,
 	}
 
 	if err := img.Builder.Build(opts); err != nil {

docker/builder.go

@@ -43,13 +43,13 @@ func (b ImageBuilderTagger) Build(opts types.ImageBuilderOpts) error {
 		return nil
 	}
 
-	err := b.exec.ExecuteStdout("docker", dockerArgs...)
+	err := b.exec.ExecuteWithWriter(opts.LogOutput, "docker", dockerArgs...)
 	if err != nil {
 		return err
 	}
 
 	if opts.Push {
-		err = b.exec.ExecuteStdout("docker", "push", opts.Tag)
+		err = b.exec.ExecuteWithWriter(opts.LogOutput, "docker", "push", opts.Tag)
 		if err != nil {
 			return err
 		}

exec/shell.go

@@ -14,6 +14,8 @@ type Executor interface {
 	Execute(name string, args ...string) (string, error)
 	// ExecuteStdout executes a command and prints the standard output instead of returning it.
 	ExecuteStdout(name string, args ...string) error
+	// ExecuteWithWriter executes a command and forwards both stdout and stderr to a single io.Writer
+	ExecuteWithWriter(writer io.Writer, name string, args ...string) error
 	// ExecuteWithWriters executes a command and forwards stdout and stderr to an io.Writer
 	ExecuteWithWriters(stdout, stderr io.Writer, name string, args ...string) error
 }
@@ -41,6 +43,7 @@ func (e ShellExecutor) Execute(name string, args ...string) (string, error) {
 	return stdout.String(), nil
 }
 
+// ExecuteWithWriters executes a command and forwards stdout and stderr to an io.Writer.
 func (e ShellExecutor) ExecuteWithWriters(stdout, stderr io.Writer, name string, args ...string) error {
 	cmd := exec.Command(name, args...)
 	cmd.Env = e.Env
@@ -56,14 +59,12 @@ func (e ShellExecutor) ExecuteWithWriters(stdout, stderr io.Writer, name string,
 	return nil
 }
 
+// ExecuteWithWriter executes a command and forwards both stdout and stderr to a single io.Writer.
+func (e ShellExecutor) ExecuteWithWriter(writer io.Writer, name string, args ...string) error {
+	return e.ExecuteWithWriters(writer, writer, name, args...)
+}
+
 // ExecuteStdout executes a shell command and prints to the standard output.
 func (e ShellExecutor) ExecuteStdout(name string, args ...string) error {
-	cmd := exec.Command(name, args...)
-	cmd.Env = e.Env
-
-	cmd.Stderr = os.Stderr
-	cmd.Stdout = os.Stdout
-	cmd.Dir = e.Dir
-
-	return cmd.Run()
+	return e.ExecuteWithWriters(os.Stdout, os.Stderr, name, args...)
 }

kaniko/builder.go

@@ -3,6 +3,7 @@ package kaniko
 import (
 	"context"
 	"fmt"
+	"io"
 	"strings"
 
 	"github.com/radiofrance/dib/types"
@@ -20,7 +21,7 @@ type ContextProvider interface {
 // Executor executes the Kaniko build.
 type Executor interface {
 	// Execute the kaniko build, passing a slice of arguments to the kaniko command.
-	Execute(ctx context.Context, args []string) error
+	Execute(ctx context.Context, output io.Writer, args []string) error
 }
 
 // Builder uses Kaniko as build backend.
@@ -66,5 +67,5 @@ func (b Builder) Build(opts types.ImageBuilderOpts) error {
 		return nil
 	}
 
-	return b.executor.Execute(context.Background(), kanikoArgs)
+	return b.executor.Execute(context.Background(), opts.LogOutput, kanikoArgs)
 }

kaniko/builder_test.go

@@ -3,6 +3,7 @@ package kaniko_test
 import (
 	"context"
 	"errors"
+	"io"
 	"testing"
 
 	"github.com/radiofrance/dib/kaniko"
@@ -16,7 +17,7 @@ type fakeExecutor struct {
 	Error    error
 }
 
-func (e *fakeExecutor) Execute(_ context.Context, args []string) error {
+func (e *fakeExecutor) Execute(_ context.Context, _ io.Writer, args []string) error {
 	e.Args = args
 	e.Executed = true
 

kaniko/executor_docker.go

@@ -3,8 +3,11 @@ package kaniko
 import (
 	"context"
 	"fmt"
+	"io"
 	"os"
 
+	"github.com/sirupsen/logrus"
+
 	"github.com/radiofrance/dib/exec"
 )
 
@@ -37,7 +40,8 @@ func NewDockerExecutor(exec exec.Executor, config ContainerConfig) *DockerExecut
 }
 
 // Execute the Kaniko build using a Docker container.
-func (e DockerExecutor) Execute(_ context.Context, args []string) error {
+func (e DockerExecutor) Execute(_ context.Context, output io.Writer, args []string) error {
+	logrus.Info("Building image with kaniko local executor")
 	dockerArgs := []string{
 		"run",
 		"--rm",
@@ -57,5 +61,5 @@ func (e DockerExecutor) Execute(_ context.Context, args []string) error {
 	dockerArgs = append(dockerArgs, e.config.Image)
 	dockerArgs = append(dockerArgs, args...)
 
-	return e.exec.ExecuteStdout("docker", dockerArgs...)
+	return e.exec.ExecuteWithWriter(output, "docker", dockerArgs...)
 }

kaniko/executor_docker_test.go

@@ -28,7 +28,9 @@ func Test_DockerExecutor_Execute(t *testing.T) {
 		},
 	})
 
-	err := executor.Execute(context.Background(), []string{"kaniko-arg1", "kaniko-arg2"})
+	writer := mock.NewWriter()
+	err := executor.Execute(context.Background(), writer, []string{"kaniko-arg1", "kaniko-arg2"})
+	assert.Equal(t, writer.GetString(), "some output")
 
 	assert.NoError(t, err)
 

kaniko/executor_kubernetes.go

@@ -3,6 +3,7 @@ package kaniko
 import (
 	"context"
 	"fmt"
+	"io"
 	"strings"
 	"time"
 
@@ -50,7 +51,8 @@ func NewKubernetesExecutor(clientSet kubernetes.Interface, config PodConfig) *Ku
 }
 
 // Execute the Kaniko build using a Kubernetes Pod.
-func (e KubernetesExecutor) Execute(ctx context.Context, args []string) error {
+func (e KubernetesExecutor) Execute(ctx context.Context, output io.Writer, args []string) error {
+	logrus.Info("Building image with kaniko kubernetes executor")
 	if e.DockerConfigSecret == "" {
 		return fmt.Errorf("the DockerConfigSecret option is required")
 	}
@@ -221,7 +223,7 @@ func (e KubernetesExecutor) Execute(ctx context.Context, args []string) error {
 		}
 	}()
 
-	go printPodLog(ctx, readyChan, e.clientSet, e.PodConfig.Namespace, name)
+	go printPodLog(ctx, readyChan, output, e.clientSet, e.PodConfig.Namespace, name)
 	_, err = e.clientSet.CoreV1().Pods(e.PodConfig.Namespace).Create(ctx, &pod, metav1.CreateOptions{})
 	if err != nil {
 		return fmt.Errorf("failed to create kaniko pod: %w", err)

kaniko/executor_kubernetes_test.go

@@ -7,15 +7,17 @@ import (
 	"testing"
 	"time"
 
+	"github.com/radiofrance/dib/kaniko"
+	"github.com/radiofrance/dib/mock"
+
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	corev1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/api/resource"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
-	"k8s.io/client-go/kubernetes"
+	"k8s.io/apimachinery/pkg/watch"
 	"k8s.io/client-go/kubernetes/fake"
-
-	"github.com/radiofrance/dib/kaniko"
+	k8stest "k8s.io/client-go/testing"
 )
 
 const dockerSecretName = "some_kubernetes_secret_name" //nolint:gosec
@@ -26,7 +28,9 @@ func Test_KubernetesExecutor_ExecuteRequiresDockerSecret(t *testing.T) {
 	clientSet := fake.NewSimpleClientset()
 	executor := kaniko.NewKubernetesExecutor(clientSet, kaniko.PodConfig{})
 
-	err := executor.Execute(context.Background(), []string{"kaniko-arg1", "kaniko-arg2"})
+	writer := mock.NewWriter()
+	err := executor.Execute(context.Background(), writer, []string{"kaniko-arg1", "kaniko-arg2"})
+	assert.Empty(t, writer.GetString())
 
 	assert.EqualError(t, err, "the DockerConfigSecret option is required")
 }
@@ -41,7 +45,9 @@ func Test_KubernetesExecutor_ExecuteFailsOnInvalidContainerYamlOverride(t *testi
 		ContainerOverride: "{\n",
 	}
 
-	err := executor.Execute(context.Background(), []string{"kaniko-arg1", "kaniko-arg2"})
+	writer := mock.NewWriter()
+	err := executor.Execute(context.Background(), writer, []string{"kaniko-arg1", "kaniko-arg2"})
+	assert.Empty(t, writer.GetString())
 
 	assert.EqualError(t, err, "invalid yaml override for type *v1.Container: unexpected EOF")
 }
@@ -56,7 +62,9 @@ func Test_KubernetesExecutor_ExecuteFailsOnInvalidPodTemplateYamlOverride(t *tes
 		PodOverride: "{\n",
 	}
 
-	err := executor.Execute(context.Background(), []string{"kaniko-arg1", "kaniko-arg2"})
+	writer := mock.NewWriter()
+	err := executor.Execute(context.Background(), writer, []string{"kaniko-arg1", "kaniko-arg2"})
+	assert.Empty(t, writer.GetString())
 
 	assert.EqualError(t, err, "invalid yaml override for type *v1.Pod: unexpected EOF")
 }
@@ -75,6 +83,9 @@ func Test_KubernetesExecutor_Execute(t *testing.T) {
 		t.Run(test.name, func(t *testing.T) {
 			t.Parallel()
 			clientSet := fake.NewSimpleClientset()
+			watcher := watch.NewFake()
+			clientSet.PrependWatchReactor("pods", k8stest.DefaultWatchReactor(watcher, nil))
+
 			podConfig := kaniko.PodConfig{
 				Name: "name-overridden-by-name-generator",
 				NameGenerator: func() string {
@@ -172,37 +183,46 @@ spec:
 					},
 				})
 
-				simulatePodExecution(t, clientSet, pod, test.success)
+				simulatePodExecution(t, watcher, test.success)
 			}()
 
 			// Run the executor
-			err := executor.Execute(context.Background(), []string{"kaniko-arg1", "kaniko-arg2"})
+			writer := mock.NewWriter()
+			err := executor.Execute(context.Background(), writer, []string{"kaniko-arg1", "kaniko-arg2"})
 			if test.success {
 				assert.NoError(t, err)
 			} else {
 				assert.Error(t, err)
 			}
+			assert.Equal(t, "fake logs", writer.GetString())
 		})
 	}
 }
 
 // simulatePodExecution simulates the default behaviour of a Kubernetes pod controller
 // by creating a pod, and also simulates the pod lifecycle until it reaches completion.
-func simulatePodExecution(t *testing.T, clientSet kubernetes.Interface, pod *corev1.Pod, isSuccess bool) {
+func simulatePodExecution(t *testing.T, watcher *watch.FakeWatcher, isSuccess bool) {
 	t.Helper()
 
-	// Wait a moment to simulate the pod taking time to complete its task.
-	<-time.After(3 * time.Second)
+	watcher.Action(watch.Added, &corev1.Pod{
+		Status: corev1.PodStatus{Phase: corev1.PodPending},
+	})
 
-	// Set pod status to completed
+	<-time.After(1 * time.Second)
+	watcher.Action(watch.Modified, &corev1.Pod{
+		Status: corev1.PodStatus{Phase: corev1.PodRunning},
+	})
+
+	<-time.After(1 * time.Second)
 	if isSuccess {
-		pod.Status.Phase = corev1.PodSucceeded
+		watcher.Action(watch.Modified, &corev1.Pod{
+			Status: corev1.PodStatus{Phase: corev1.PodSucceeded},
+		})
 	} else {
-		pod.Status.Phase = corev1.PodFailed
+		watcher.Action(watch.Modified, &corev1.Pod{
+			Status: corev1.PodStatus{Phase: corev1.PodFailed},
+		})
 	}
-
-	_, err := clientSet.CoreV1().Pods(pod.Namespace).Update(context.Background(), pod, metav1.UpdateOptions{})
-	require.NoError(t, err)
 }
 
 func Test_UniquePodName(t *testing.T) {

kaniko/pod.go

@@ -3,7 +3,6 @@ package kaniko
 import (
 	"context"
 	"errors"
-	"fmt"
 	"io"
 
 	"github.com/sirupsen/logrus"
@@ -12,7 +11,8 @@ import (
 	"k8s.io/client-go/kubernetes"
 )
 
-func printPodLog(ctx context.Context, ready chan struct{}, k8s kubernetes.Interface, ns string, podName string) {
+func printPodLog(ctx context.Context, ready chan struct{}, output io.Writer, k8s kubernetes.Interface,
+	ns string, podName string) {
 	<-ready
 	req := k8s.CoreV1().Pods(ns).GetLogs(podName, &corev1.PodLogOptions{
 		Follow: true,
@@ -36,7 +36,9 @@ func printPodLog(ctx context.Context, ready chan struct{}, k8s kubernetes.Interf
 			logrus.Errorf("Error reading logs buffer of pod %s: %v", podName, err)
 			return
 		}
-		message := string(buf[:numBytes])
-		fmt.Print(message) // nolint: forbidigo
+		if _, err := output.Write(buf[:numBytes]); err != nil {
+			logrus.Errorf("Error writing log to output: %v", err)
+			return
+		}
 	}
 }

mock/executor.go

@@ -24,9 +24,20 @@ func (e *Executor) ExecuteStdout(name string, args ...string) error {
 	return e.Error
 }
 
-func (e *Executor) ExecuteWithWriters(_, _ io.Writer, name string, args ...string) error {
+func (e *Executor) ExecuteWithWriters(writer, _ io.Writer, name string, args ...string) error {
 	e.Command = name
 	e.Args = args
 
+	_, _ = writer.Write([]byte(e.Output))
+
+	return e.Error
+}
+
+func (e *Executor) ExecuteWithWriter(writer io.Writer, name string, args ...string) error {
+	e.Command = name
+	e.Args = args
+
+	_, _ = writer.Write([]byte(e.Output))
+
 	return e.Error
 }