Fix issue with s3fs mount randomly taking time using IAM credentials on Private VPC clusters (#259)

* Fix issue with s3fs mount randomly taking time using IAM credentials on Private VPC clusters

* Fix log messages

* Fix the testcase

Author: mssachan

cos-csi-mounter/server/s3fs.go

@@ -59,6 +59,23 @@ func (args S3FSArgs) PopulateArgsSlice(bucket, targetPath string) ([]string, err
 
 	// Convert to key=value slice
 	result := []string{bucket, targetPath}
+
+	// Add ibm_iam_auth first before ibm_iam_endpoint for correctly setting provided iam endpoint in s3fs-fuse for fetching token
+	if val, ok := m["ibm_iam_auth"]; ok {
+		if strings.ToLower(strings.TrimSpace(val)) == "true" {
+			result = append(result, "-o", "ibm_iam_auth")
+		} else {
+			result = append(result, "-o", fmt.Sprintf("ibm_iam_auth=%v", val)) // pragma: allowlist secret
+		}
+		delete(m, "ibm_iam_auth")
+	}
+
+	// Add ibm_iam_endpoint
+	if val, ok := m["ibm_iam_endpoint"]; ok {
+		result = append(result, "-o", fmt.Sprintf("ibm_iam_endpoint=%v", val))
+		delete(m, "ibm_iam_endpoint")
+	}
+	
 	for k, v := range m {
 		result = append(result, "-o")
 		if strings.ToLower(strings.TrimSpace(v)) == "true" {

cos-csi-mounter/server/s3fs_test.go

@@ -13,19 +13,23 @@ var (
 	testBucket         = "testBucket"
 	testTargetPath     = "/var/data/kubelet/pods/"
 	testEndPoint       = "testEndPoint"
+	testIAMEndpoint    = "https://test.iam.cloud.ibm.com"
 	testPasswdFilePath = "testPasswdFilePath"
 	testURL            = "https://testURL"
 )
 
 func TestS3FSPopulateArgsSlice_Success(t *testing.T) {
 	args := S3FSArgs{
-		AllowOther: "true",
-		EndPoint:   "testEndPoint",
+		AllowOther:     "true",
+		EndPoint:       "testEndPoint",
+		IBMIamAuth:     "true",
+		IBMIamEndpoint: testIAMEndpoint,
+
 	}
 
 	resp, err := args.PopulateArgsSlice(testBucket, testTargetPath)
 	assert.NoError(t, err)
-	expectedVal := []string{testBucket, testTargetPath, "-o", "allow_other", "-o", "endpoint=" + testEndPoint}
+	expectedVal := []string{testBucket, testTargetPath, "-o", "ibm_iam_auth", "-o", "ibm_iam_endpoint=" + testIAMEndpoint, "-o", "allow_other", "-o", "endpoint=" + testEndPoint}
 	slices.Sort(expectedVal)
 	slices.Sort(resp)
 	assert.Equal(t, expectedVal, resp)

pkg/mounter/utils/mounter_utils.go

@@ -15,6 +15,7 @@ import (
 	"github.com/IBM/ibm-object-csi-driver/pkg/constants"
 	"github.com/mitchellh/go-ps"
 	"k8s.io/klog/v2"
+	k8sMountUtils "k8s.io/mount-utils"
 )
 
 var unmount = syscall.Unmount
@@ -32,16 +33,19 @@ type MounterOptsUtils struct {
 
 func (su *MounterOptsUtils) FuseMount(path string, comm string, args []string) error {
 	klog.Info("-FuseMount-")
-	klog.Infof("FuseMount params:\n\tpath: <%s>\n\tcommand: <%s>\n\targs: <%s>", path, comm, args)
+	klog.Infof("FuseMount params:\n\tpath: <%s>\n\tcommand: <%s>\n\targs: <%v>", path, comm, args)
 	out, err := command(comm, args...).CombinedOutput()
 	if err != nil {
+		klog.Warningf("FuseMount: mount command failed: mounter=%s, args=%v, error=%v, output=%s", comm, args, err, string(out))
+		klog.Infof("FuseMount: checking if path already exists and is a mountpoint: path=%s", path)
 		if mounted, err1 := isMountpoint(path); err1 == nil && mounted { // check if bucket already got mounted
 			klog.Infof("bucket is already mounted using '%s' mounter", comm)
 			return nil
 		}
-		klog.Errorf("FuseMount: command execution failed: <%s>\nargs: <%s>\nerror: <%v>\noutput: <%v>", comm, args, err, string(out))
+		klog.Errorf("FuseMount: path is not mountpoint, mount failed: path=%s", path)
 		return fmt.Errorf("'%s' mount failed: <%v>", comm, string(out))
 	}
+	klog.Infof("mount command succeeded: mounter=%s, output=%s", comm, string(out))
 	if err := waitForMount(path, 10*time.Second); err != nil {
 		return err
 	}
@@ -126,20 +130,21 @@ func isMountpoint(pathname string) (bool, error) {
 
 func waitForMount(path string, timeout time.Duration) error {
 	var elapsed time.Duration
+	attempt := 1
 	for {
-		out, err := exec.Command("mountpoint", path).CombinedOutput()
-		outStr := strings.TrimSpace(string(out))
-		if err == nil && strings.HasSuffix(outStr, "is a mountpoint") {
-			klog.Infof("Path is a mountpoint: pathname - %s", path)
+		isMount, err := k8sMountUtils.New("").IsMountPoint(path)
+		if err == nil && isMount {
+			klog.Infof("Path is a mountpoint: pathname: %s", path)
 			return nil
 		}
 
-		klog.Infof("Mountpoint check in progress: path=%s, output=%s, err=%v", path, outStr, err)
+		klog.Infof("Mountpoint check in progress: attempt=%d, path=%s, isMount=%v, err=%v", attempt, path, isMount, err)
 		time.Sleep(constants.Interval)
-		elapsed = elapsed + constants.Interval
+		elapsed += constants.Interval
 		if elapsed >= timeout {
-			return fmt.Errorf("timeout waiting for mount: last check output: %s", outStr)
+			return fmt.Errorf("timeout waiting for mount. Last check response: isMount=%v, err=%v", isMount, err)
 		}
+		attempt++
 	}
 }