[content-service] log duration for s3 download and tar extract (#18829)

* [content-service] log the duration for download and extraction for S3

The DirectDownloader interface does not differentiate between downloading and extract tarbal...when youdownload, you also extract.

https://github.com/gitpod-io/gitpod/blob/9a38b607055780fa7b2cd61c1379143d6c7b3715/components/content-service/pkg/storage/storage.go#L133

In the context of a prebuild initializer:
https://github.com/gitpod-io/gitpod/blob/9a38b607055780fa7b2cd61c1379143d6c7b3715/components/content-service/pkg/initializer/prebuild.go#L69

When we Run, we do DownloadSnapshot:
https://github.com/gitpod-io/gitpod/blob/9a38b607055780fa7b2cd61c1379143d6c7b3715/components/content-service/pkg/initializer/snapshot.go#L48

It does both operations:
https://github.com/gitpod-io/gitpod/blob/9a38b607055780fa7b2cd61c1379143d6c7b3715/components/content-service/pkg/storage/s3.go#L290

Supervisor, which records initializer metrics, reads them from /workspace/.gitpod/ready file:
https://github.com/gitpod-io/gitpod/blob/55414729fab00fa23888c1868579425907518a68/components/supervisor/pkg/supervisor/supervisor.go#L1639

* [content-service] denote when download is found

Author: kylos101

components/content-service/pkg/storage/s3.go

@@ -12,6 +12,7 @@ import (
 	"os/exec"
 	"path/filepath"
 	"strings"
+	"time"
 
 	"github.com/gitpod-io/gitpod/common-go/log"
 	"github.com/gitpod-io/gitpod/content-service/pkg/archive"
@@ -308,11 +309,14 @@ func (s3st *s3Storage) download(ctx context.Context, destination string, obj str
 		tempFile.Name(),
 	}
 	cmd := exec.Command("s5cmd", args...)
+	downloadStart := time.Now()
 	out, err := cmd.CombinedOutput()
 	if err != nil {
 		log.WithError(err).WithField("out", string(out)).Error("unexpected error downloading file")
-		return true, xerrors.Errorf("unexpected error downloading file")
+		return false, xerrors.Errorf("unexpected error downloading file")
 	}
+	downloadDuration := time.Since(downloadStart)
+	log.WithField("downloadDuration", downloadDuration.String()).Info("S3 download duration")
 
 	tempFile, err = os.Open(tempFile.Name())
 	if err != nil {
@@ -322,10 +326,13 @@ func (s3st *s3Storage) download(ctx context.Context, destination string, obj str
 	defer os.Remove(tempFile.Name())
 	defer tempFile.Close()
 
+	extractStart := time.Now()
 	err = archive.ExtractTarbal(ctx, tempFile, destination, archive.WithUIDMapping(mappings), archive.WithGIDMapping(mappings))
 	if err != nil {
 		return true, xerrors.Errorf("tar %s: %s", destination, err.Error())
 	}
+	extractDuration := time.Since(extractStart)
+	log.WithField("extractdDuration", extractDuration.String()).Info("tarbar extraction duration")
 
 	return true, nil
 }