fix: avoid concurrency during initialization

using a filelock to ensure that initialization of the same version happens only once.

also improved debug logging a bit

cliv2/go.mod

@@ -5,6 +5,7 @@ go 1.18
 require (
 	github.com/elazarl/goproxy v0.0.0-20220901064549-fbd10ff4f5a1
 	github.com/elazarl/goproxy/ext v0.0.0-20220901064549-fbd10ff4f5a1
+	github.com/gofrs/flock v0.8.1
 	github.com/google/uuid v1.3.0
 	github.com/pkg/errors v0.9.1
 	github.com/snyk/cli-extension-sbom v0.0.0-20221212093410-6b474ed1a42a

cliv2/go.sum

@@ -69,6 +69,8 @@ github.com/fsnotify/fsnotify v1.5.4/go.mod h1:OVB6XrOHzAwXMpEM7uPOzcehqUV2UqJxmV
 github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9AVAgeJqvqgH9Q5CA+iKCZ2gyEVpxRU=
 github.com/go-gl/glfw/v3.3/glfw v0.0.0-20191125211704-12ad95a8df72/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8=
 github.com/go-gl/glfw/v3.3/glfw v0.0.0-20200222043503-6f7a984d4dc4/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8=
+github.com/gofrs/flock v0.8.1 h1:+gYjHKf32LDeiEEFhQaotPbLuUXjY5ZqxKgXy7n59aw=
+github.com/gofrs/flock v0.8.1/go.mod h1:F1TvTiK9OcQqauNUHlbJvyl9Qa1QvF/gOUDKA14jxHU=
 github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q=
 github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=
 github.com/golang/groupcache v0.0.0-20191227052852-215e87163ea7/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=

cliv2/internal/cliv2/cliv2.go

@@ -14,10 +14,12 @@ import (
 	"regexp"
 	"strings"
 
+	"github.com/gofrs/flock"
 	"github.com/snyk/cli/cliv2/internal/constants"
 	"github.com/snyk/cli/cliv2/internal/embedded"
 	"github.com/snyk/cli/cliv2/internal/embedded/cliv1"
 	"github.com/snyk/cli/cliv2/internal/proxy"
+	local_utils "github.com/snyk/cli/cliv2/internal/utils"
 	"github.com/snyk/go-application-framework/pkg/utils"
 )
 
@@ -62,15 +64,54 @@ func NewCLIv2(cacheDirectory string, debugLogger *log.Logger) (*CLI, error) {
 		stderr:           os.Stderr,
 	}
 
-	cli.ClearCache()
+	return &cli, nil
+}
 
-	err = cli.ExtractV1Binary()
+func (c *CLI) Init() (err error) {
+	c.DebugLogger.Println("Init start")
+
+	// ensure the specified base cache directory exists, this needs to be done even before acquiring the lock
+	if _, err = os.Stat(c.CacheDirectory); os.IsNotExist(err) {
+		err = os.Mkdir(c.CacheDirectory, local_utils.CACHEDIR_PERMISSION)
+		if err != nil {
+			return err
+		}
+	}
+
+	// use filelock to synchronize parallel executed processes
+	lockFileName := path.Join(c.CacheDirectory, GetFullVersion()+".lock")
+	fileLock := flock.New(lockFileName)
+	err = fileLock.Lock()
 	if err != nil {
-		fmt.Println(err)
-		return nil, err
+		return err
 	}
 
-	return &cli, nil
+	unlock := func() {
+		fileLock.Unlock()
+		os.Remove(lockFileName)
+	}
+	defer unlock()
+
+	c.DebugLogger.Printf("Init-Lock acquired: %v (%s)\n", fileLock.Locked(), lockFileName)
+
+	// create required cache and temp directories
+	err = local_utils.CreateAllDirectories(c.CacheDirectory, GetFullVersion())
+	if err != nil {
+		return err
+	}
+
+	// cleanup cache a bit
+	c.ClearCache()
+
+	// extract cliv1
+	err = c.ExtractV1Binary()
+	if err != nil {
+		return err
+	}
+
+	c.DebugLogger.Println("Init end")
+
+	return err
 }
 
 func (c *CLI) ClearCache() error {
@@ -83,16 +124,18 @@ func (c *CLI) ClearCache() error {
 	// Get current version binary's path
 	v1BinaryPath := path.Dir(c.v1BinaryLocation)
 	var maxVersionToDelete = 5
-	for i, file := range fileInfo {
+	var deleteCount = 0
+	for _, file := range fileInfo {
 		currentPath := path.Join(c.CacheDirectory, file.Name())
-		if currentPath != v1BinaryPath {
+		if currentPath != v1BinaryPath && !strings.Contains(currentPath, ".lock") {
+			deleteCount++
 			err = os.RemoveAll(currentPath)
 			if err != nil {
 				c.DebugLogger.Println("Error deleting an old version directory: ", currentPath)
 			}
 		}
 		// Stop the loop after 5 deletions to not create too much overhead
-		if i == maxVersionToDelete {
+		if deleteCount == maxVersionToDelete {
 			break
 		}
 	}
@@ -105,7 +148,7 @@ func (c *CLI) ExtractV1Binary() error {
 
 	isValid, err := embedded.ValidateFile(c.v1BinaryLocation, cliV1ExpectedSHA256, c.DebugLogger)
 	if err != nil || !isValid {
-		c.DebugLogger.Println("cliv1 is not valid, start extracting ", c.v1BinaryLocation)
+		c.DebugLogger.Println("Extract cliv1 to", c.v1BinaryLocation)
 
 		err = cliv1.ExtractTo(c.v1BinaryLocation)
 		if err != nil {
@@ -118,13 +161,13 @@ func (c *CLI) ExtractV1Binary() error {
 		}
 
 		if isValid {
-			c.DebugLogger.Println("cliv1 is valid after extracting", c.v1BinaryLocation)
+			c.DebugLogger.Println("Extracted cliv1 successfully")
 		} else {
-			fmt.Println("cliv1 is not valid after sha256 check")
+			c.DebugLogger.Println("Extracted cliv1 is not valid")
 			return err
 		}
 	} else {
-		c.DebugLogger.Println("cliv1 already exists and is valid at", c.v1BinaryLocation)
+		c.DebugLogger.Println("Extraction not required")
 	}
 
 	return nil

cliv2/internal/cliv2/cliv2_test.go

@@ -4,17 +4,27 @@ import (
 	"io/ioutil"
 	"log"
 	"os"
+	"os/exec"
 	"path"
 	"sort"
 	"testing"
+	"time"
 
 	"github.com/snyk/cli/cliv2/internal/cliv2"
 	"github.com/snyk/cli/cliv2/internal/constants"
 	"github.com/snyk/cli/cliv2/internal/proxy"
+	"github.com/snyk/cli/cliv2/internal/utils"
 
 	"github.com/stretchr/testify/assert"
 )
 
+func getCacheDir() string {
+	cacheDir := path.Join(os.TempDir(), "snyk")
+	os.RemoveAll(cacheDir)
+	os.MkdirAll(cacheDir, 0755)
+	return cacheDir
+}
+
 func Test_PrepareV1EnvironmentVariables_Fill_and_Filter(t *testing.T) {
 
 	input := []string{
@@ -150,98 +160,165 @@ func Test_prepareV1Command(t *testing.T) {
 func Test_executeRunV1(t *testing.T) {
 	expectedReturnCode := 0
 
-	cacheDir := "dasda"
+	cacheDir := getCacheDir()
+	tmpDir := utils.GetTemporaryDirectory(cacheDir, cliv2.GetFullVersion())
 	logger := log.New(ioutil.Discard, "", 0)
 
-	assert.NoDirExists(t, cacheDir)
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
+	assert.NoDirExists(t, tmpDir)
 
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
 
 	// run once
+	assert.Nil(t, cli.Init())
 	actualReturnCode := cliv2.DeriveExitCode(cli.Execute(getProxyInfoForTest(), []string{"--help"}))
 	assert.Equal(t, expectedReturnCode, actualReturnCode)
 	assert.FileExists(t, cli.GetBinaryLocation())
 	fileInfo1, _ := os.Stat(cli.GetBinaryLocation())
 
+	// sleep shortly to ensure that ModTimes would be different
+	time.Sleep(500 * time.Millisecond)
+
 	// run twice
+	assert.Nil(t, cli.Init())
 	actualReturnCode = cliv2.DeriveExitCode(cli.Execute(getProxyInfoForTest(), []string{"--help"}))
 	assert.Equal(t, expectedReturnCode, actualReturnCode)
 	assert.FileExists(t, cli.GetBinaryLocation())
 	fileInfo2, _ := os.Stat(cli.GetBinaryLocation())
 
 	assert.Equal(t, fileInfo1.ModTime(), fileInfo2.ModTime())
+}
+
+func Test_init_extractDueToInvalidBinary(t *testing.T) {
+
+	cacheDir := getCacheDir()
+	tmpDir := utils.GetTemporaryDirectory(cacheDir, cliv2.GetFullVersion())
+	logger := log.New(ioutil.Discard, "", 0)
 
 	// cleanup
-	os.RemoveAll(cacheDir)
+	defer os.RemoveAll(cacheDir)
+
+	assert.NoDirExists(t, tmpDir)
+
+	// create instance under test
+	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+
+	// fill binary with invalid data
+	os.MkdirAll(tmpDir, 0755)
+	os.WriteFile(cli.GetBinaryLocation(), []byte("Writing some strings"), 0755)
+	fileInfo1, _ := os.Stat(cli.GetBinaryLocation())
+
+	// prove that we can't execute the invalid binary
+	_, binError := exec.Command(cli.GetBinaryLocation(), "--help").Output()
+	assert.NotNil(t, binError)
+
+	// sleep shortly to ensure that ModTimes would be different
+	time.Sleep(500 * time.Millisecond)
+
+	// run init to ensure that the file system is being setup correctly
+	initError := cli.Init()
+	assert.Nil(t, initError)
+
+	// execute to test that the cli can run successfully
+	assert.FileExists(t, cli.GetBinaryLocation())
+
+	// prove that we now can execute the invalid binary
+	_, binError = exec.Command(cli.GetBinaryLocation(), "--help").Output()
+	assert.Nil(t, binError)
+
+	fileInfo2, _ := os.Stat(cli.GetBinaryLocation())
+
+	assert.NotEqual(t, fileInfo1.ModTime(), fileInfo2.ModTime())
 }
 
 func Test_executeRunV2only(t *testing.T) {
 	expectedReturnCode := 0
 
-	cacheDir := "dasda"
+	cacheDir := getCacheDir()
+	tmpDir := utils.GetTemporaryDirectory(cacheDir, cliv2.GetFullVersion())
 	logger := log.New(ioutil.Discard, "", 0)
 
-	assert.NoDirExists(t, cacheDir)
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
+	assert.NoDirExists(t, tmpDir)
 
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+	assert.Nil(t, cli.Init())
+
 	actualReturnCode := cliv2.DeriveExitCode(cli.Execute(getProxyInfoForTest(), []string{"--version"}))
 	assert.Equal(t, expectedReturnCode, actualReturnCode)
 	assert.FileExists(t, cli.GetBinaryLocation())
 
-	os.RemoveAll(cacheDir)
 }
 
 func Test_executeEnvironmentError(t *testing.T) {
 	expectedReturnCode := 0
 
-	cacheDir := "dasda"
+	cacheDir := getCacheDir()
+	tmpDir := utils.GetTemporaryDirectory(cacheDir, cliv2.GetFullVersion())
 	logger := log.New(ioutil.Discard, "", 0)
 
-	assert.NoDirExists(t, cacheDir)
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
+	assert.NoDirExists(t, tmpDir)
 
 	// fill Environment Variable
 	os.Setenv(constants.SNYK_INTEGRATION_NAME_ENV, "someName")
 
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+	assert.Nil(t, cli.Init())
+
 	actualReturnCode := cliv2.DeriveExitCode(cli.Execute(getProxyInfoForTest(), []string{"--help"}))
 	assert.Equal(t, expectedReturnCode, actualReturnCode)
 	assert.FileExists(t, cli.GetBinaryLocation())
-
-	os.RemoveAll(cacheDir)
 }
 
 func Test_executeUnknownCommand(t *testing.T) {
 	expectedReturnCode := constants.SNYK_EXIT_CODE_ERROR
 
-	cacheDir := "dasda"
+	cacheDir := getCacheDir()
 	logger := log.New(ioutil.Discard, "", 0)
 
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+	assert.Nil(t, cli.Init())
+
 	actualReturnCode := cliv2.DeriveExitCode(cli.Execute(getProxyInfoForTest(), []string{"bogusCommand"}))
 	assert.Equal(t, expectedReturnCode, actualReturnCode)
-
-	os.RemoveAll(cacheDir)
 }
 
 func Test_clearCache(t *testing.T) {
-	cacheDir := "cacheDir"
+	cacheDir := getCacheDir()
 	logger := log.New(ioutil.Discard, "", 0)
 
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+	assert.Nil(t, cli.Init())
+
 	// create folders and files in cache dir
 	versionWithV := path.Join(cli.CacheDirectory, "v1.914.0")
 	versionNoV := path.Join(cli.CacheDirectory, "1.1048.0-dev.2401acbc")
+	lockfile := path.Join(cli.CacheDirectory, "v1.914.0.lock")
 	randomFile := path.Join(versionNoV, "filename")
 	currentVersion := cli.GetBinaryLocation()
 
 	os.Mkdir(versionWithV, 0755)
 	os.Mkdir(versionNoV, 0755)
 	os.WriteFile(randomFile, []byte("Writing some strings"), 0666)
+	os.WriteFile(lockfile, []byte("Writing some strings"), 0666)
 
 	// clear cache
 	err := cli.ClearCache()
@@ -253,14 +330,20 @@ func Test_clearCache(t *testing.T) {
 	assert.NoFileExists(t, randomFile)
 	// check if directories that need to exist still exist
 	assert.FileExists(t, currentVersion)
+	assert.FileExists(t, lockfile)
 }
 
 func Test_clearCacheBigCache(t *testing.T) {
-	cacheDir := "cacheDir"
+	cacheDir := getCacheDir()
 	logger := log.New(ioutil.Discard, "", 0)
 
+	// cleanup
+	defer os.RemoveAll(cacheDir)
+
 	// create instance under test
 	cli, _ := cliv2.NewCLIv2(cacheDir, logger)
+	assert.Nil(t, cli.Init())
+
 	// create folders and files in cache dir
 	dir1 := path.Join(cli.CacheDirectory, "dir1")
 	dir2 := path.Join(cli.CacheDirectory, "dir2")

cliv2/internal/embedded/sha.go

@@ -10,7 +10,6 @@ import (
 func ComputeSHA256(filePath string, debugLogger *log.Logger) (string, error) {
 	fileBytes, err := ioutil.ReadFile(filePath)
 	if err != nil {
-		debugLogger.Println("failed to read file:", filePath)
 		return "", err
 	}
 
@@ -21,15 +20,16 @@ func ComputeSHA256(filePath string, debugLogger *log.Logger) (string, error) {
 }
 
 func ValidateFile(filePath string, expectedSHA256 string, debugLogger *log.Logger) (bool, error) {
-	debugLogger.Println("validating", filePath)
+	debugLogger.Println("Validating sha256 of", filePath)
 
 	hashStr, err := ComputeSHA256(filePath, debugLogger)
 	if err != nil {
+		debugLogger.Println(" ", err)
 		return false, err
 	}
 
-	debugLogger.Println("found sha256:", hashStr)
-	debugLogger.Println("expected sha256:", expectedSHA256)
+	debugLogger.Println("  expected: ", expectedSHA256)
+	debugLogger.Println("  actual:   ", hashStr)
 
 	return hashStr == expectedSHA256, nil
 }