Added observability into build and extraction.

cmd/build-helpers/extract.go

@@ -146,10 +146,11 @@ func extractSourcePackage(ctx context.Context, sourcePackageNamespace, sourcePac
 	}
 
 	r := tar.NewReader(bytes.NewReader(bs))
-	err = sourceimage.ExtractTar(targetPath, sourcePath, r)
+	count, err := sourceimage.ExtractTar(targetPath, sourcePath, r)
 	if err != nil {
 		return errors.Wrap(err, "failed to extract tar")
 	}
+	log.Printf("Extracted %d files\n", count)
 	return nil
 }
 
@@ -173,7 +174,12 @@ func extractSourceImage(sourceImage, sourcePath, targetPath string) error {
 	}
 
 	log.Printf("Extracting contents from: %s to %s\n", sourcePath, targetPath)
-	return sourceimage.ExtractImage(targetPath, sourcePath, image)
+	count, err := sourceimage.ExtractImage(targetPath, sourcePath, image)
+	if err != nil {
+		return err
+	}
+	log.Printf("Extracted %d files\n", count)
+	return nil
 }
 
 func extractSourceImageWithRetry(retryDuration time.Duration, sourceImage, sourcePath, targetPath string) error {

pkg/kf/sourcepackages/client.go

@@ -24,6 +24,7 @@ import (
 	"log"
 	"os"
 	"path/filepath"
+	"time"
 
 	v1alpha1 "github.com/google/kf/v2/pkg/apis/kf/v1alpha1"
 	cv1alpha1 "github.com/google/kf/v2/pkg/client/kf/clientset/versioned/typed/kf/v1alpha1"
@@ -160,7 +161,7 @@ func (p *sourcePackagesClient) UploadSourcePath(
 	// Upload the data.
 	logger := logging.FromContext(ctx).With(zap.Namespace("source upload"))
 	logger.Infof("Uploading directory %s (size=%0.2fKiB)", sourcePath, float64(fi.Size()/1024.0))
-
+	uploadStart := time.Now()
 	requestURI := fmt.Sprintf(
 		"/apis/upload.kf.dev/v1alpha1/proxy/namespaces/%s/%s",
 		app.Namespace,
@@ -173,7 +174,7 @@ func (p *sourcePackagesClient) UploadSourcePath(
 		return fmt.Errorf("failed to upload source directory: %v", err)
 	}
 
-	logger.Info("Successfully uploaded directory")
+	logger.Infof("Successfully uploaded source in %0.2f seconds", time.Since(uploadStart).Seconds())
 
 	// Success!
 	return nil

pkg/kf/testutil/acceptance/acceptance_tests.go

@@ -177,9 +177,8 @@ func useCachedImage(t *testing.T, dir, acceptanceImage string) map[string]string
 	image, err := remote.Image(imageRef, remote.WithAuthFromKeychain(authn.DefaultKeychain))
 	testutil.AssertNil(t, "remote.Image", err)
 
-	testutil.AssertNil(t, "sourceImage.ExtractImage",
-		sourceimage.ExtractImage(dir, sourceimage.DefaultSourcePath, image),
-	)
+	_, err = sourceimage.ExtractImage(dir, sourceimage.DefaultSourcePath, image)
+	testutil.AssertNil(t, "sourceImage.ExtractImage", err)
 
 	files, err := ioutil.ReadDir(dir)
 	testutil.AssertNil(t, "ioutil.ReadDir", err)

pkg/sourceimage/extract.go

@@ -27,7 +27,7 @@ import (
 
 // ExtractImage extracts the files and directories from the given sourcePath in
 // image to targetPath on the current system.
-func ExtractImage(targetPath, sourcePath string, image v1.Image) error {
+func ExtractImage(targetPath, sourcePath string, image v1.Image) (int, error) {
 	tarReader := mutate.Extract(image)
 	defer tarReader.Close()
 	r := tar.NewReader(tarReader)
@@ -39,19 +39,21 @@ func ExtractImage(targetPath, sourcePath string, image v1.Image) error {
 //
 // Special files are skipped, and all files are converted to their absolute
 // path equivalents to avoid traversal attacks.
-func ExtractTar(targetPath, sourcePath string, tarReader *tar.Reader) error {
+func ExtractTar(targetPath, sourcePath string, tarReader *tar.Reader) (int, error) {
+	fileCount := 0
 	for {
 		header, err := tarReader.Next()
 
 		switch {
 		case err == io.EOF:
-			return nil
+			return fileCount, nil
 		case err != nil:
-			return err
+			return fileCount, err
 		default:
 			if err := extract(targetPath, sourcePath, header, tarReader); err != nil {
-				return err
+				return fileCount, err
 			}
+			fileCount++
 		}
 	}
 }

pkg/sourceimage/extract_test.go

@@ -98,8 +98,9 @@ func TestExtractTar(t *testing.T) {
 	defer os.RemoveAll(temp)
 
 	r := tar.NewReader(tarBytes)
-	tarErr := ExtractTar(temp, "/home", r)
+	count, tarErr := ExtractTar(temp, "/home", r)
 	testutil.AssertNil(t, "tar err", tarErr)
+	testutil.AssertEqual(t, "file count", 8, count)
 
 	AssertFile(t, temp, "foo/readme.txt", 0600, []byte("some-text"))
 	AssertFile(t, temp, "foo/prog", 0700, []byte("ELF"))