hooks: prepend pod/container name to container hooks log lines

integration/examples/lifecycle-hooks/README.md

@@ -32,7 +32,7 @@ Starting pre-sync hooks for artifact "hooks-example"...
 file changes detected: hello.txt
 Completed pre-sync hooks for artifact "hooks-example"
 Starting post-sync hooks for artifact "hooks-example"...
-Running command kill -HUP 1
+[hooks-example] + kill -HUP 1
 Completed post-sync hooks for artifact "hooks-example"
 Watching for changes...
 [hooks-example] Hello World!!

integration/examples/lifecycle-hooks/skaffold.yaml

@@ -28,7 +28,7 @@ build:
               os: [windows]
         after:
           - container:
-              command: ["sh", "-c", "echo Running command 'kill -HUP 1'; kill -HUP 1"]
+              command: ["sh", "-c", "set -x; kill -HUP 1"]
 deploy:
   kubectl:
     manifests:

pkg/skaffold/deploy/component/kubernetes/component.go

@@ -31,7 +31,6 @@ import (
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/portforward"
 	k8sstatus "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/status"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/loader"
-	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/status"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/sync"
 )
@@ -88,7 +87,7 @@ func newImageLoader(cfg k8sloader.Config, cli *kubectl.CLI) loader.ImageLoader {
 	return &loader.NoopImageLoader{}
 }
 
-func newLogger(config k8slogger.Config, cli *kubectl.CLI, podSelector kubernetes.PodSelector, namespaces *[]string) log.Logger {
+func newLogger(config k8slogger.Config, cli *kubectl.CLI, podSelector kubernetes.PodSelector, namespaces *[]string) k8slogger.Logger {
 	return k8slogger.NewLogAggregator(cli, podSelector, namespaces, config)
 }
 
@@ -109,6 +108,6 @@ func newMonitor(cfg k8sstatus.Config, kubeContext string, labeller *label.Defaul
 	return k8sMonitor[kubeContext]
 }
 
-func newSyncer(cli *kubectl.CLI, namespaces *[]string) sync.Syncer {
-	return sync.NewPodSyncer(cli, namespaces)
+func newSyncer(cli *kubectl.CLI, namespaces *[]string, formatter k8slogger.Formatter) sync.Syncer {
+	return sync.NewPodSyncer(cli, namespaces, formatter)
 }

pkg/skaffold/deploy/helm/deploy.go

@@ -151,17 +151,17 @@ func NewDeployer(cfg Config, labeller *label.DefaultLabeller, h *latestV1.HelmDe
 	if err != nil {
 		logrus.Warnf("unable to parse namespaces - deploy might not work correctly!")
 	}
-
+	logger := component.NewLogger(cfg, kubectl, podSelector, &namespaces)
 	return &Deployer{
 		HelmDeploy:     h,
 		podSelector:    podSelector,
 		namespaces:     &namespaces,
 		accessor:       component.NewAccessor(cfg, cfg.GetKubeContext(), kubectl, podSelector, labeller, &namespaces),
 		debugger:       component.NewDebugger(cfg.Mode(), podSelector, &namespaces),
 		imageLoader:    component.NewImageLoader(cfg, kubectl),
-		logger:         component.NewLogger(cfg, kubectl, podSelector, &namespaces),
+		logger:         logger,
 		statusMonitor:  component.NewMonitor(cfg, cfg.GetKubeContext(), labeller, &namespaces),
-		syncer:         component.NewSyncer(kubectl, &namespaces),
+		syncer:         component.NewSyncer(kubectl, &namespaces, logger.GetFormatter()),
 		originalImages: originalImages,
 		kubeContext:    cfg.GetKubeContext(),
 		kubeConfig:     cfg.GetKubeConfig(),

pkg/skaffold/deploy/kpt/kpt.go

@@ -116,17 +116,17 @@ func NewDeployer(cfg Config, labeller *label.DefaultLabeller, d *latestV1.KptDep
 	if err != nil {
 		logrus.Warnf("unable to parse namespaces - deploy might not work correctly!")
 	}
-
+	logger := component.NewLogger(cfg, kubectl, podSelector, &namespaces)
 	return &Deployer{
 		KptDeploy:          d,
 		podSelector:        podSelector,
 		namespaces:         &namespaces,
 		accessor:           component.NewAccessor(cfg, cfg.GetKubeContext(), kubectl, podSelector, labeller, &namespaces),
 		debugger:           component.NewDebugger(cfg.Mode(), podSelector, &namespaces),
 		imageLoader:        component.NewImageLoader(cfg, kubectl),
-		logger:             component.NewLogger(cfg, kubectl, podSelector, &namespaces),
+		logger:             logger,
 		statusMonitor:      component.NewMonitor(cfg, cfg.GetKubeContext(), labeller, &namespaces),
-		syncer:             component.NewSyncer(kubectl, &namespaces),
+		syncer:             component.NewSyncer(kubectl, &namespaces, logger.GetFormatter()),
 		insecureRegistries: cfg.GetInsecureRegistries(),
 		labels:             labeller.Labels(),
 		globalConfig:       cfg.GlobalConfig(),

pkg/skaffold/deploy/kubectl/kubectl.go

@@ -95,6 +95,7 @@ func NewDeployer(cfg Config, labeller *label.DefaultLabeller, d *latestV1.Kubect
 	if err != nil {
 		logrus.Warnf("unable to parse namespaces - deploy might not work correctly!")
 	}
+	logger := component.NewLogger(cfg, kubectl.CLI, podSelector, &namespaces)
 
 	return &Deployer{
 		KubectlDeploy:      d,
@@ -103,9 +104,9 @@ func NewDeployer(cfg Config, labeller *label.DefaultLabeller, d *latestV1.Kubect
 		accessor:           component.NewAccessor(cfg, cfg.GetKubeContext(), kubectl.CLI, podSelector, labeller, &namespaces),
 		debugger:           component.NewDebugger(cfg.Mode(), podSelector, &namespaces),
 		imageLoader:        component.NewImageLoader(cfg, kubectl.CLI),
-		logger:             component.NewLogger(cfg, kubectl.CLI, podSelector, &namespaces),
+		logger:             logger,
 		statusMonitor:      component.NewMonitor(cfg, cfg.GetKubeContext(), labeller, &namespaces),
-		syncer:             component.NewSyncer(kubectl.CLI, &namespaces),
+		syncer:             component.NewSyncer(kubectl.CLI, &namespaces, logger.GetFormatter()),
 		workingDir:         cfg.GetWorkingDir(),
 		globalConfig:       cfg.GlobalConfig(),
 		defaultRepo:        cfg.DefaultRepo(),

pkg/skaffold/deploy/kustomize/kustomize.go

@@ -144,17 +144,17 @@ func NewDeployer(cfg kubectl.Config, labeller *label.DefaultLabeller, d *latestV
 	if err != nil {
 		logrus.Warnf("unable to parse namespaces - deploy might not work correctly!")
 	}
-
+	logger := component.NewLogger(cfg, kubectl.CLI, podSelector, &namespaces)
 	return &Deployer{
 		KustomizeDeploy:     d,
 		podSelector:         podSelector,
 		namespaces:          &namespaces,
 		accessor:            component.NewAccessor(cfg, cfg.GetKubeContext(), kubectl.CLI, podSelector, labeller, &namespaces),
 		debugger:            component.NewDebugger(cfg.Mode(), podSelector, &namespaces),
 		imageLoader:         component.NewImageLoader(cfg, kubectl.CLI),
-		logger:              component.NewLogger(cfg, kubectl.CLI, podSelector, &namespaces),
+		logger:              logger,
 		statusMonitor:       component.NewMonitor(cfg, cfg.GetKubeContext(), labeller, &namespaces),
-		syncer:              component.NewSyncer(kubectl.CLI, &namespaces),
+		syncer:              component.NewSyncer(kubectl.CLI, &namespaces, logger.GetFormatter()),
 		kubectl:             kubectl,
 		insecureRegistries:  cfg.GetInsecureRegistries(),
 		globalConfig:        cfg.GlobalConfig(),

pkg/skaffold/hooks/container.go

@@ -27,6 +27,8 @@ import (
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
 	kubernetesclient "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/client"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/logger"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log/stream"
 	latestV1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/util"
 )
@@ -56,6 +58,7 @@ type containerHook struct {
 	cli        *kubectl.CLI
 	selector   containerSelector
 	namespaces []string
+	formatter  logger.Formatter
 }
 
 // run executes the lifecycle hook inside the target container
@@ -83,17 +86,29 @@ func (h containerHook) run(ctx context.Context, out io.Writer) error {
 				args := []string{p.Name, "--namespace", p.Namespace, "-c", c.Name, "--"}
 				args = append(args, h.cfg.Command...)
 				cmd := h.cli.Command(ctx, "exec", args...)
-				cmd.Stderr = out
-				cmd.Stdout = out
+				tr, tw := io.Pipe()
+				cmd.Stderr = tw
+				cmd.Stdout = tw
 				podName := p.Name
 				containerName := c.Name
 				errs.Go(func() error {
+					defer tw.Close()
 					err := util.RunCmd(cmd)
 					if err != nil {
 						return fmt.Errorf("hook execution failed for pod %q container %q: %w", podName, containerName, err)
 					}
 					return nil
 				})
+				pod := p
+				var containerStatus v1.ContainerStatus
+				for _, status := range pod.Status.ContainerStatuses {
+					if status.Name == c.Name {
+						containerStatus = status
+					}
+				}
+				errs.Go(func() error {
+					return stream.StreamRequest(ctx, out, h.formatter(pod, containerStatus, func() bool { return false }), tr)
+				})
 			}
 		}
 	}

pkg/skaffold/hooks/container_test.go

@@ -30,6 +30,7 @@ import (
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
 	kubernetesclient "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/client"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log"
 	v1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/util"
 	"github.com/GoogleContainerTools/skaffold/testutil"
@@ -105,6 +106,7 @@ func TestContainerRun(t *testing.T) {
 				cli:        &kubectl.CLI{KubeContext: test.kubeContext},
 				selector:   test.selector,
 				namespaces: test.namespaces,
+				formatter:  func(corev1.Pod, corev1.ContainerStatus, func() bool) log.Formatter { return mockLogFormatter{} },
 			}
 			var output bytes.Buffer
 

pkg/skaffold/hooks/host.go

@@ -40,7 +40,7 @@ type hostHook struct {
 // run executes the lifecycle hook on the host machine
 func (h hostHook) run(ctx context.Context, out io.Writer) error {
 	if len(h.cfg.OS) > 0 && !util.StrSliceContains(h.cfg.OS, runtime.GOOS) {
-		logrus.Infof("host hook execution skipped due to OS criteria %s not matched for commands:\n%s\n", strings.Join(h.cfg.OS, ","), strings.Join(h.cfg.Command, "\n"))
+		logrus.Infof("host hook execution skipped due to OS criteria %q not matched for commands:\n%q\n", strings.Join(h.cfg.OS, ","), strings.Join(h.cfg.Command, " "))
 		return nil
 	}
 	cmd := h.retrieveCmd(ctx, out)

pkg/skaffold/hooks/sync.go

@@ -24,14 +24,16 @@ import (
 	"strings"
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/logger"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/output"
 	v1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/util"
 )
 
-func NewSyncRunner(cli *kubectl.CLI, imageName, imageRef string, namespaces []string, d v1.SyncHooks, opts SyncEnvOpts) Runner {
-	return syncRunner{d, cli, imageName, imageRef, namespaces, opts}
+func NewSyncRunner(cli *kubectl.CLI, imageName, imageRef string, namespaces []string, formatter logger.Formatter, d v1.SyncHooks, opts SyncEnvOpts) Runner {
+	return syncRunner{d, cli, imageName, imageRef, namespaces, formatter, opts}
 }
+
 func NewSyncEnvOpts(a *v1.Artifact, image string, addOrModifyFiles []string, deleteFiles []string, namespaces []string, kubeContext string) (SyncEnvOpts, error) {
 	workDir, err := filepath.Abs(a.Workspace)
 	if err != nil {
@@ -53,6 +55,7 @@ type syncRunner struct {
 	imageName  string
 	imageRef   string
 	namespaces []string
+	formatter  logger.Formatter
 	opts       SyncEnvOpts
 }
 
@@ -87,6 +90,7 @@ func (r syncRunner) run(ctx context.Context, out io.Writer, hooks []v1.SyncHookI
 				cli:        r.cli,
 				selector:   runningImageSelector(r.imageRef),
 				namespaces: r.namespaces,
+				formatter:  r.formatter,
 			}
 			if err := hook.run(ctx, out); err != nil {
 				return fmt.Errorf("failed to execute container %s hook %d for artifact %q: %w", phase, i+1, r.imageName, err)

pkg/skaffold/hooks/sync_test.go

@@ -20,6 +20,7 @@ import (
 	"bytes"
 	"context"
 	"fmt"
+	"io"
 	"path/filepath"
 	"strings"
 	"testing"
@@ -31,6 +32,7 @@ import (
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
 	kubernetesclient "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/client"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log"
 	v1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/util"
 	"github.com/GoogleContainerTools/skaffold/testutil"
@@ -96,7 +98,8 @@ func TestSyncHooks(t *testing.T) {
 		kubeContext := "context1"
 		opts, err := NewSyncEnvOpts(artifact, image, []string{"foo1", "bar1"}, []string{"foo2", "bar2"}, namespaces, kubeContext)
 		t.CheckNoError(err)
-		runner := NewSyncRunner(&kubectl.CLI{KubeContext: kubeContext}, artifact.ImageName, image, namespaces, artifact.Sync.LifecycleHooks, opts)
+		formatter := func(corev1.Pod, corev1.ContainerStatus, func() bool) log.Formatter { return mockLogFormatter{} }
+		runner := NewSyncRunner(&kubectl.CLI{KubeContext: kubeContext}, artifact.ImageName, image, namespaces, formatter, artifact.Sync.LifecycleHooks, opts)
 
 		t.Override(&util.DefaultExecCommand,
 			testutil.CmdRunWithOutput("kubectl --context context1 exec pod1 --namespace np1 -c container1 -- foo pre-hook", preContainerHookOut).
@@ -136,3 +139,9 @@ func fakeKubernetesClient() (kubernetes.Interface, error) {
 	}
 	return fakeclient.NewSimpleClientset(pod), nil
 }
+
+type mockLogFormatter struct{}
+
+func (mockLogFormatter) Name() string { return "" }
+
+func (mockLogFormatter) PrintLine(w io.Writer, s string) { fmt.Fprint(w, s) }

pkg/skaffold/kubernetes/logger/formatter.go

@@ -30,6 +30,8 @@ import (
 	tagutil "github.com/GoogleContainerTools/skaffold/pkg/skaffold/tag/util"
 )
 
+type Formatter func(pod v1.Pod, containerStatus v1.ContainerStatus, isMuted func() bool) log.Formatter
+
 type kubernetesLogFormatter struct {
 	colorPicker output.ColorPicker
 	prefix      string

pkg/skaffold/kubernetes/logger/log.go

@@ -30,20 +30,26 @@ import (
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/graph"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log/stream"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/output"
 	latestV1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 )
 
+type Logger interface {
+	log.Logger
+	GetFormatter() Formatter
+}
+
 // LogAggregator aggregates the logs for all the deployed pods.
 type LogAggregator struct {
-	output      io.Writer
-	kubectlcli  *kubectl.CLI
-	config      Config
-	podSelector kubernetes.PodSelector
-	podWatcher  kubernetes.PodWatcher
-	colorPicker output.ColorPicker
-
+	output            io.Writer
+	kubectlcli        *kubectl.CLI
+	config            Config
+	podSelector       kubernetes.PodSelector
+	podWatcher        kubernetes.PodWatcher
+	colorPicker       output.ColorPicker
+	formatter         Formatter
 	muted             int32
 	stopWatcher       func()
 	sinceTime         time.Time
@@ -60,7 +66,7 @@ type Config interface {
 
 // NewLogAggregator creates a new LogAggregator for a given output.
 func NewLogAggregator(cli *kubectl.CLI, podSelector kubernetes.PodSelector, namespaces *[]string, config Config) *LogAggregator {
-	return &LogAggregator{
+	a := &LogAggregator{
 		kubectlcli:  cli,
 		config:      config,
 		podSelector: podSelector,
@@ -70,6 +76,15 @@ func NewLogAggregator(cli *kubectl.CLI, podSelector kubernetes.PodSelector, name
 		events:      make(chan kubernetes.PodEvent),
 		namespaces:  namespaces,
 	}
+	a.formatter = func(p v1.Pod, c v1.ContainerStatus, isMuted func() bool) log.Formatter {
+		pod := p
+		return newKubernetesLogFormatter(config, a.colorPicker, isMuted, &pod, c)
+	}
+	return a
+}
+
+func (a *LogAggregator) GetFormatter() Formatter {
+	return a.formatter
 }
 
 // RegisterArtifacts tracks the provided build artifacts in the colorpicker
@@ -183,8 +198,7 @@ func (a *LogAggregator) streamContainerLogs(ctx context.Context, pod *v1.Pod, co
 		_ = tw.Close()
 	}()
 
-	formatter := NewKubernetesLogFormatter(a.config, a.colorPicker, a.IsMuted, pod, container)
-	if err := stream.StreamRequest(ctx, a.output, formatter, tr); err != nil {
+	if err := stream.StreamRequest(ctx, a.output, a.formatter(*pod, container, a.IsMuted), tr); err != nil {
 		logrus.Errorf("streaming request %s", err)
 	}
 }
@@ -232,3 +246,10 @@ func (t *trackedContainers) add(id string) bool {
 
 	return alreadyTracked
 }
+
+// NoopLogger is used in tests. It will never retrieve any logs from any resources.
+type NoopLogger struct {
+	*log.NoopLogger
+}
+
+func (*NoopLogger) GetFormatter() Formatter { return nil }

pkg/skaffold/log/stream/stream.go

@@ -38,14 +38,13 @@ func StreamRequest(ctx context.Context, out io.Writer, formatter log.Formatter,
 		default:
 			// Read up to newline
 			line, err := r.ReadString('\n')
+			formatter.PrintLine(out, line)
 			if err == io.EOF {
 				return nil
 			}
 			if err != nil {
 				return fmt.Errorf("reading bytes from log stream: %w", err)
 			}
-
-			formatter.PrintLine(out, line)
 		}
 	}
 }

pkg/skaffold/runner/deployer_test.go

@@ -37,7 +37,6 @@ import (
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/portforward"
 	k8sstatus "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/status"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/loader"
-	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/log"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/runner/runcontext"
 	latestV1 "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest/v1"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/status"
@@ -185,11 +184,11 @@ func TestGetDefaultDeployer(tOuter *testing.T) {
 		t.Override(&component.NewImageLoader, func(k8sloader.Config, *pkgkubectl.CLI) loader.ImageLoader {
 			return &loader.NoopImageLoader{}
 		})
-		t.Override(&component.NewSyncer, func(*pkgkubectl.CLI, *[]string) sync.Syncer {
+		t.Override(&component.NewSyncer, func(*pkgkubectl.CLI, *[]string, k8slogger.Formatter) sync.Syncer {
 			return &sync.NoopSyncer{}
 		})
-		t.Override(&component.NewLogger, func(k8slogger.Config, *pkgkubectl.CLI, kubernetes.PodSelector, *[]string) log.Logger {
-			return &log.NoopLogger{}
+		t.Override(&component.NewLogger, func(k8slogger.Config, *pkgkubectl.CLI, kubernetes.PodSelector, *[]string) k8slogger.Logger {
+			return &k8slogger.NoopLogger{}
 		})
 		tests := []struct {
 			name      string