Failed to create S3 client when enabling authenticationSource: pod

[inesshz]

/kind bug

NOTE: If this is a filesystem related bug, please take a look at the Mountpoint repo to submit a bug report

What happened?
I upgraded to version 1.9.0 and set podInfoOnMountCompat to true and also added authenticationSource=pod to PV and I'm now receiving the following :

Warning FailedMount 37s (x12 over 9m13s) kubelet MountVolume.SetUp failed for volume "s3-pv" : rpc error: code = Internal desc = Could not mount "" at "/var/lib/kubelet/pods/78dfad8e-3eaf-44ba-93c8-fbf8cae8abc0/volumes/kubernetes.io~csi/s3-pv/mount": Mount failed: Failed to start service output: Error: Failed to create S3 client Caused by: 0: initial ListObjectsV2 failed for bucket in region us-east-1 1: Client error 2: No signing credentials available, see CRT debug logs Error: Failed to create mount process

If I switch back to using s3 csi driver role instead of using pod role, it works fine and the mount operation works successfully.

What you expected to happen?
S3 bucket is mounted

How to reproduce it (as minimally and precisely as possible)?
I followed the following https://github.com/awslabs/mountpoint-s3-csi-driver/blob/main/examples/kubernetes/static_provisioning/pod_level_identity.yaml

Deploy s3 csi with podInfoOnMountCompat set to true.

Both driver and pod roles are configured correctly and they have the correct Trusted entities and policies attached (s3:* and kms:*)

Here is the pv yaml :

spec:
  accessModes:
  - ReadWriteMany
  capacity:
    storage: 1Gi
  claimRef:
    apiVersion: v1
    kind: PersistentVolumeClaim
    name: s3-pvc
  csi:
    driver: s3.csi.aws.com
    volumeAttributes:
      authenticationSource: pod
      bucketName: <bucket-name>
      stsRegion: us-east-1
    volumeHandle: s3-csi-driver-volume
  mountOptions:
  - allow-delete
  - region us-east-1
  - allow-other
  - allow-overwrite
  persistentVolumeReclaimPolicy: Retain
  volumeMode: Filesystem

Anything else we need to know?:

Environment

• Kubernetes version (use kubectl version): 1.30
• Driver version: 1.9.0

[unexge]

Hey @inesshz, thanks for the report. Would you be able to share your Mountpoint logs with us after enabling debug CRT logs by adding debug and debug-crt to your mountOptions?

[inesshz]

Here are the logs from the driver's pod :

I1114 10:22:24.899999       1 node.go:241] NodeGetCapabilities: called with args
I1114 10:22:24.901197       1 node.go:241] NodeGetCapabilities: called with args
I1114 10:22:24.902137       1 node.go:241] NodeGetCapabilities: called with args
I1114 10:22:24.902849       1 node.go:91] NodePublishVolume: new request: volume_id:"s3-csi-driver-volume" target_path:"/var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount" volume_capability:<mount:<mount_flags:"allow-delete" mount_flags:"region us-east-1" mount_flags:"allow-other" mount_flags:"allow-overwrite" mount_flags:"debug" mount_flags:"debug-crt" > access_mode:<mode:MULTI_NODE_MULTI_WRITER > > volume_context:<key:"authenticationSource" value:"pod" > volume_context:<key:"bucketName" value:"<bucket-name>" > volume_context:<key:"csi.storage.k8s.io/ephemeral" value:"false" > volume_context:<key:"csi.storage.k8s.io/pod.name" value:"busybox-pod-level" > volume_context:<key:"csi.storage.k8s.io/pod.namespace" value:"<namespace>" > volume_context:<key:"csi.storage.k8s.io/pod.uid" value:"fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac" > volume_context:<key:"csi.storage.k8s.io/serviceAccount.name" value:"s3-csi-pod-sa" > volume_context:<key:"stsRegion" value:"us-east-1" >
I1114 10:22:24.903232       1 credential.go:114] NodePublishVolume: Using pod identity
I1114 10:22:24.920874       1 node.go:146] NodePublishVolume: mounting <bucket-name> at /var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount with options [--allow-delete --allow-other --allow-overwrite --debug --debug-crt --region=us-east-1]
E1114 10:22:26.953452       1 driver.go:136] GRPC error: rpc error: code = Internal desc = Could not mount "<bucket-name>" at "/var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount": Mount failed: Failed to start service output: Error: Failed to create S3 client  Caused by:     0: initial ListObjectsV2 failed for bucket <bucket-name> in region us-east-1     1: Client error     2: No signing credentials available, see CRT debug logs Error: Failed to create mount process
E1114 10:22:26.953452       1 driver.go:136] GRPC error: rpc error: code = Internal desc = Could not mount "<bucket-name>" at "/var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount": Mount failed: Failed to start service output: Error: Failed to create S3 client  Caused by:     0: initial ListObjectsV2 failed for bucket <bucket-name> in region us-east-1     1: Client error     2: No signing credentials available, see CRT debug logs Error: Failed to create mount process
E1114 10:22:26.953452       1 driver.go:136] GRPC error: rpc error: code = Internal desc = Could not mount "<bucket-name>" at "/var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount": Mount failed: Failed to start service output: Error: Failed to create S3 client  Caused by:     0: initial ListObjectsV2 failed for bucket <bucket-name> in region us-east-1     1: Client error     2: No signing credentials available, see CRT debug logs Error: Failed to create mount process
E1114 10:22:26.953452       1 driver.go:136] GRPC error: rpc error: code = Internal desc = Could not mount "<bucket-name>" at "/var/lib/kubelet/pods/fbaddd1c-7c5e-4b26-90c4-c1fc507e42ac/volumes/kubernetes.io~csi/s3-pv/mount": Mount failed: Failed to start service output: Error: Failed to create S3 client  Caused by:     0: initial ListObjectsV2 failed for bucket <bucket-name> in region us-east-1     1: Client error     2: No signing credentials available, see CRT debug logs Error: Failed to create mount process

Logs from the node ([ERROR]):

Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AWSProfile: Creating profile collection from file at "/var/lib/kubelet/plugins/s3.csi.aws.com/disable-config"
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::common-io: static: Failed to open file. path:'/var/lib/kubelet/plugins/s3.csi.aws.com/disable-config' mode:'rb' errno:2 aws-error:44(AWS_ERROR_FILE_INVALID_PATH)
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AWSProfile: Failed to read file at "/var/lib/kubelet/plugins/s3.csi.aws.com/disable-config"
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AWSProfile: Creating profile collection from file at "/var/lib/kubelet/plugins/s3.csi.aws.com/disable-credentials"
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::common-io: static: Failed to open file. path:'/var/lib/kubelet/plugins/s3.csi.aws.com/disable-credentials' mode:'rb' errno:2 aws-error:44(AWS_ERROR_FILE_INVALID_PATH)
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AWSProfile: Failed to read file at "/var/lib/kubelet/plugins/s3.csi.aws.com/disable-credentials"
Nov 14 10:20:26 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::AuthCredentialsProvider: static: Profile credentials parser could not load or parse a credentials or config file.

]: [ERROR] awscrt::socket: id=0x7f11000013c0 fd=16: timed out, shutting down.
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::socket: id=0x7f11000013c0 fd=16: closing
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::socket: id=0x7f11000013c0 fd=-1: connection failure
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::channel-bootstrap: id=0x55fb149c5f70: client connection on socket 0x7f11000013c0 completed with error 1048.
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::channel-bootstrap: id=0x55fb149c5f70: recording bad address 67.220.242.104.
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [INFO] awscrt::dns: id=0x55fb14949d80: recording failure for record 67.220.242.104 for sts.us-east-1.amazonaws.com, moving to bad list
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::dns: static: purging address 67.220.242.104 for host sts.us-east-1.amazonaws.com from the cache due to cache eviction or shutdown
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::socket: id=0x7f11000013c0 fd=-1: closing
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::channel-bootstrap: id=0x55fb149c5f70: Connection failed with error_code 1048.
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::http-connection: static: Client connection failed with error 1048 (AWS_IO_SOCKET_TIMEOUT).
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [WARN] awscrt::connection-manager: id=0x55fb14aadf20: Failed to obtain new connection from http layer, error 1048(socket operation timed out.)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::connection-manager: id=0x55fb14aadf20: Failing excess connection acquisition with error code 1048
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::connection-manager: id=0x55fb14aadf20: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=0, ref_count=1
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [WARN] awscrt::connection-manager: id=0x55fb14aadf20: Failed to complete connection acquisition with error_code 1048(socket operation timed out.)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [WARN] awscrt::AuthCredentialsProvider: id=0x55fb14991160: STS_WEB_IDENTITY provider failed to acquire a connection, error code 1048(socket operation timed out.)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [WARN] awscrt::AuthCredentialsProvider: (id=0x55fb14991160) STS_WEB_IDENTITY credentials provider failed to query credentials
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [INFO] awscrt::AuthCredentialsProvider: (id=0x55fb14a55930) Credentials provider chain callback terminating on index 2, with invalid credentials and error code 6160
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AuthCredentialsProvider: (id=0x55fb14aae160) Cached credentials provider next refresh time set to 170200353386144
Nov 14 10:20:28 ip-10-218-xx-xxec2.internal mount-s3[3881465]: [DEBUG] awscrt::AuthCredentialsProvider: (id=0x55fb14aae160) Cached credentials provider was unable to source credentials on refresh
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [DEBUG] awscrt::AuthCredentialsProvider: (id=0x55fb14aae160) Cached credentials provider notifying pending queries of new credentials
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::AuthCredentialsProvider: (id=0x55fb149302f0) Default chain credentials provider failed to source credentials with error 6160(aws-c-auth: AWS_AUTH_CREDENTIALS_PROVIDER_STS_WEB_IDENTITY_SOURCE_FAILURE, Valid credentials could not be sourced by the sts web identity provider)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::AuthSigning: (id=0x7f10f80020f0) Credentials Provider failed to source credentials with error 6160(aws-c-auth: AWS_AUTH_CREDENTIALS_PROVIDER_STS_WEB_IDENTITY_SOURCE_FAILURE, Valid credentials could not be sourced by the sts web identity provider)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::S3MetaRequest: id=0x55fb14c92940 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)
Nov 14 10:20:28 ip-10-218-xx-xx.ec2.internal mount-s3[3881465]: [ERROR] awscrt::S3MetaRequest: id=0x55fb14c92940 Could not prepare request 0x7f1104001ec0 due to error 6146 (Attempt to sign an http request without credentials).