[WIP] Add more initializer-related info to /insights API

components/ws-daemon/cmd/content-initializer.go

@@ -5,6 +5,8 @@
 package cmd
 
 import (
+	"fmt"
+
 	"github.com/spf13/cobra"
 
 	"github.com/gitpod-io/gitpod/ws-daemon/pkg/content"
@@ -16,7 +18,14 @@ var contentInitializerCmd = &cobra.Command{
 	Short: "fork'ed by ws-daemon to initialize content",
 	Args:  cobra.ExactArgs(0),
 	RunE: func(cmd *cobra.Command, args []string) error {
-		return content.RunInitializerChild()
+		stats, err := content.RunInitializerChild()
+		if err != nil {
+			return err
+		}
+
+		fmt.Printf(content.FormatStatsBytes(stats))
+
+		return nil
 	},
 }
 

components/ws-daemon/cmd/content-initializer/main.go

@@ -21,11 +21,13 @@ func main() {
 	log.Init("content-initializer", "", true, false)
 	tracing.Init("content-initializer")
 
-	err := content.RunInitializerChild()
+	stats, err := content.RunInitializerChild()
 	if err != nil {
 		errfd := os.NewFile(uintptr(3), "errout")
 		_, _ = fmt.Fprintf(errfd, err.Error())
 
 		os.Exit(content.FAIL_CONTENT_INITIALIZER_EXIT_CODE)
 	}
+
+	fmt.Printf(content.FormatStatsBytes(stats))
 }

components/ws-daemon/cmd/debug-run-initializer.go

@@ -22,7 +22,7 @@ var debugRunInitializer = &cobra.Command{
 	RunE: func(cmd *cobra.Command, args []string) error {
 		dst := args[0]
 		log.WithField("dst", dst).Info("running content initializer")
-		return content.RunInitializer(context.Background(), dst, &api.WorkspaceInitializer{
+		_, err := content.RunInitializer(context.Background(), dst, &api.WorkspaceInitializer{
 			Spec: &api.WorkspaceInitializer_Git{
 				Git: &api.GitInitializer{
 					RemoteUri:        "https://github.com/gitpod-io/gitpod.git",
@@ -35,6 +35,7 @@ var debugRunInitializer = &cobra.Command{
 				},
 			},
 		}, make(map[string]storage.DownloadInfo), content.RunInitializerOpts{})
+		return err
 	},
 }
 

components/ws-daemon/pkg/content/initializer.go

@@ -5,10 +5,12 @@
 package content
 
 import (
+	"bufio"
 	"bytes"
 	"context"
 	"encoding/json"
 	"errors"
+	"fmt"
 	"io/ioutil"
 	"os"
 	"os/exec"
@@ -122,21 +124,22 @@ func CollectRemoteContent(ctx context.Context, rs storage.DirectAccess, ps stora
 }
 
 // RunInitializer runs a content initializer in a user, PID and mount namespace to isolate it from ws-daemon
-func RunInitializer(ctx context.Context, destination string, initializer *csapi.WorkspaceInitializer, remoteContent map[string]storage.DownloadInfo, opts RunInitializerOpts) (err error) {
+func RunInitializer(ctx context.Context, destination string, initializer *csapi.WorkspaceInitializer, remoteContent map[string]storage.DownloadInfo, opts RunInitializerOpts) (*csapi.InitializerMetrics, error) {
 	//nolint:ineffassign,staticcheck
 	span, ctx := opentracing.StartSpanFromContext(ctx, "RunInitializer")
+	var err error
 	defer tracing.FinishSpan(span, &err)
 
 	// it's possible the destination folder doesn't exist yet, because the kubelet hasn't created it yet.
 	// If we fail to create the folder, it either already exists, or we'll fail when we try and mount it.
 	err = os.MkdirAll(destination, 0755)
 	if err != nil && !os.IsExist(err) {
-		return xerrors.Errorf("cannot mkdir destination: %w", err)
+		return nil, xerrors.Errorf("cannot mkdir destination: %w", err)
 	}
 
 	init, err := proto.Marshal(initializer)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	if opts.GID == 0 {
@@ -148,13 +151,13 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 
 	tmpdir, err := os.MkdirTemp("", "content-init")
 	if err != nil {
-		return err
+		return nil, err
 	}
 	defer os.RemoveAll(tmpdir)
 
 	err = os.MkdirAll(filepath.Join(tmpdir, "rootfs"), 0755)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	msg := msgInitContent{
@@ -169,11 +172,11 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 	}
 	fc, err := json.MarshalIndent(msg, "", "  ")
 	if err != nil {
-		return err
+		return nil, err
 	}
 	err = os.WriteFile(filepath.Join(tmpdir, "rootfs", "content.json"), fc, 0644)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	spec := specconv.Example()
@@ -226,11 +229,11 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 
 	fc, err = json.MarshalIndent(spec, "", "  ")
 	if err != nil {
-		return err
+		return nil, err
 	}
 	err = os.WriteFile(filepath.Join(tmpdir, "config.json"), fc, 0644)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	args := []string{"--root", "state"}
@@ -243,7 +246,7 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 	if opts.OWI.InstanceID == "" {
 		id, err := uuid.NewRandom()
 		if err != nil {
-			return err
+			return nil, err
 		}
 		name = "init-rnd-" + id.String()
 	} else {
@@ -256,7 +259,7 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 
 	errIn, errOut, err := os.Pipe()
 	if err != nil {
-		return err
+		return nil, err
 	}
 	errch := make(chan []byte, 1)
 	go func() {
@@ -286,27 +289,49 @@ func RunInitializer(ctx context.Context, destination string, initializer *csapi.
 			// The program has exited with an exit code != 0. If it's FAIL_CONTENT_INITIALIZER_EXIT_CODE, it was deliberate.
 			if status, ok := exiterr.Sys().(syscall.WaitStatus); ok && status.ExitStatus() == FAIL_CONTENT_INITIALIZER_EXIT_CODE {
 				log.WithError(err).WithFields(opts.OWI.Fields()).WithField("errmsgsize", len(errmsg)).WithField("exitCode", status.ExitStatus()).WithField("args", args).Error("content init failed")
-				return xerrors.Errorf(string(errmsg))
+				return nil, xerrors.Errorf(string(errmsg))
 			}
 		}
 
-		return err
+		return nil, err
 	}
 
+	stats := parseStats(&cmdOut)
+
+	return stats, nil
+}
+
+func parseStats(buf *bytes.Buffer) *csapi.InitializerMetrics {
+	scanner := bufio.NewScanner(buf)
+	for scanner.Scan() {
+		line := string(scanner.Bytes())
+		if !strings.HasPrefix(line, STATS_PREFIX) {
+			continue
+		}
+
+		b := strings.TrimSpace(strings.TrimPrefix(line, STATS_PREFIX))
+		var stats csapi.InitializerMetrics
+		err := json.Unmarshal([]byte(b), &stats)
+		if err != nil {
+			log.WithError(err).WithField("line", line).Error("cannot unmarshal stats")
+			return nil
+		}
+		return &stats
+	}
 	return nil
 }
 
 // RunInitializerChild is the function that's expected to run when we call `/proc/self/exe content-initializer`
-func RunInitializerChild() (err error) {
+func RunInitializerChild() (serializedStats []byte, err error) {
 	fc, err := os.ReadFile("/content.json")
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	var initmsg msgInitContent
 	err = json.Unmarshal(fc, &initmsg)
 	if err != nil {
-		return err
+		return nil, err
 	}
 	log.Log = logrus.WithFields(initmsg.OWI)
 
@@ -323,15 +348,15 @@ func RunInitializerChild() (err error) {
 	var req csapi.WorkspaceInitializer
 	err = proto.Unmarshal(initmsg.Initializer, &req)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	rs := &remoteContentStorage{RemoteContent: initmsg.RemoteContent}
 
 	dst := initmsg.Destination
 	initializer, err := wsinit.NewFromRequest(ctx, dst, rs, &req, wsinit.NewFromRequestOpts{ForceGitpodUserForGit: false})
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	initSource, stats, err := wsinit.InitializeWorkspace(ctx, dst, rs,
@@ -341,23 +366,35 @@ func RunInitializerChild() (err error) {
 		wsinit.WithCleanSlate,
 	)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	// some workspace content may have a `/dst/.gitpod` file or directory. That would break
 	// the workspace ready file placement (see https://github.com/gitpod-io/gitpod/issues/7694).
 	err = wsinit.EnsureCleanDotGitpodDirectory(ctx, dst)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
 	// Place the ready file to make Theia "open its gates"
 	err = wsinit.PlaceWorkspaceReadyFile(ctx, dst, initSource, stats, initmsg.UID, initmsg.GID)
 	if err != nil {
-		return err
+		return nil, err
 	}
 
-	return nil
+	// Serialize metrics, so we can pass them back to the caller
+	serializedStats, err = json.Marshal(stats)
+	if err != nil {
+		return nil, err
+	}
+
+	return serializedStats, nil
+}
+
+const STATS_PREFIX = "STATS:"
+
+func FormatStatsBytes(statsBytes []byte) string {
+	return fmt.Sprintf("%s %s\n", STATS_PREFIX, string(statsBytes))
 }
 
 var _ storage.DirectAccess = &remoteContentStorage{}

components/ws-daemon/pkg/controller/workspace_controller.go

@@ -179,7 +179,7 @@ func (wsc *WorkspaceController) handleWorkspaceInit(ctx context.Context, ws *wor
 		}
 
 		initStart := time.Now()
-		failure, initErr := wsc.operations.InitWorkspace(ctx, InitOptions{
+		stats, failure, initErr := wsc.operations.InitWorkspace(ctx, InitOptions{
 			Meta: WorkspaceMeta{
 				Owner:       ws.Spec.Ownership.Owner,
 				WorkspaceID: ws.Spec.Ownership.WorkspaceID,
@@ -190,18 +190,25 @@ func (wsc *WorkspaceController) handleWorkspaceInit(ctx context.Context, ws *wor
 			StorageQuota: ws.Spec.StorageQuota,
 		})
 
+		initMetrics := initializerMetricsFromInitializerStats(stats)
 		err = retry.RetryOnConflict(retryParams, func() error {
 			if err := wsc.Get(ctx, req.NamespacedName, ws); err != nil {
 				return err
 			}
 
+			// persist init failure/success
 			if failure != "" {
 				log.Error(initErr, "could not initialize workspace", "name", ws.Name)
 				ws.Status.SetCondition(workspacev1.NewWorkspaceConditionContentReady(metav1.ConditionFalse, workspacev1.ReasonInitializationFailure, failure))
 			} else {
 				ws.Status.SetCondition(workspacev1.NewWorkspaceConditionContentReady(metav1.ConditionTrue, workspacev1.ReasonInitializationSuccess, ""))
 			}
 
+			// persist initializer metrics
+			if initMetrics != nil {
+				ws.Status.InitializerMetrics = initMetrics
+			}
+
 			return wsc.Status().Update(ctx, ws)
 		})
 
@@ -218,6 +225,50 @@ func (wsc *WorkspaceController) handleWorkspaceInit(ctx context.Context, ws *wor
 	return ctrl.Result{}, nil
 }
 
+func initializerMetricsFromInitializerStats(stats *csapi.InitializerMetrics) *workspacev1.InitializerMetrics {
+	if stats == nil {
+		return nil
+	}
+
+	result := workspacev1.InitializerMetrics{}
+	for _, metric := range *stats {
+		switch metric.Type {
+		case "git":
+			result.Git = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		case "fileDownload":
+			result.FileDownload = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		case "snapshot":
+			result.Snapshot = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		case "fromBackup":
+			result.Backup = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		case "composite":
+			result.Composite = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		case "prebuild":
+			result.Composite = &workspacev1.InitializerStepMetric{
+				Duration: &metav1.Duration{Duration: metric.Duration},
+				Size:     metric.Size,
+			}
+		}
+	}
+
+	return &result
+}
+
 func (wsc *WorkspaceController) handleWorkspaceRunning(ctx context.Context, ws *workspacev1.Workspace, req ctrl.Request) (result ctrl.Result, err error) {
 	span, ctx := opentracing.StartSpanFromContext(ctx, "handleWorkspaceRunning")
 	defer tracing.FinishSpan(span, &err)