awslabs / mountpoint-s3

A simple, high-throughput file client for mounting an Amazon S3 bucket as a local file system.
Apache License 2.0
4.42k stars 149 forks source link

Mountpoint doesn't work with credential_process in combination with source_profile #927

Open sdauhuchytsrf opened 2 months ago

sdauhuchytsrf commented 2 months ago

Mountpoint for Amazon S3 version

mount-s3 1.7.2

AWS Region

eu-central-1

Describe the running environment

Running on non-EC2 instance which uses IAM Roles Anywhere configuration. AWS profile configuration is the following:

[profile my-profile-name]
credential_source = Ec2InstanceMetadata
region = eu-central-1
role_arn = arn:aws:iam::123456789012:role/my-role-name

aws_signing_helper tool is running in serve mode:

aws_signing_helper serve --certificate certificate.crt --private-key private.key --trust-anchor-arn arn:aws:rolesanywhere:eu-central-1:123456789012:trust-anchor/some-uuid-here --profile-arn arn:aws:rolesanywhere:eu-central-1:123456789012:profile/some-uuid-here --role-arn arn:aws:iam::123456789012:role/my-role-name --region eu-central-1

Exported AWS_EC2_METADATA_SERVICE_ENDPOINT env var:

export AWS_EC2_METADATA_SERVICE_ENDPOINT=http://127.0.0.1:9911/

Check configuration with AWS CLI to be sure that it works:

aws s3 ls my-bucket-name --profile my-profile-name
...shows some contents here...

Try to mount S3:

mount-s3 my-bucket-name /path/to/mnt/dir --profile my-profile-name --region eu-central-1
Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-name in region eu-central-1
    1: Client error
    2: No signing credentials found
Error: Failed to create mount process

Mountpoint options

mount-s3 my-bucket-name /path/to/mnt/dir --profile my-profile-name --region eu-central-1

What happened?

Mountpoint failed to use config file to sign request. No signing credentials found error.

Relevant log output

mount-s3 --debug --debug-crt -f my-bucket-name /path/to/mnt/dir --profile my-profile-name --region eu-central-1
2024-06-28T08:08:17.058928Z  INFO mountpoint_s3::cli: mount-s3 1.7.2
2024-06-28T08:08:17.059081Z DEBUG mountpoint_s3::cli: CliArgs { bucket_name: "my-bucket-name", mount_point: "/path/to/mnt/dir", prefix: None, region: Some("eu-central-1"), endpoint_url: None, force_path_style: false, transfer_acceleration: false, dual_stack: false, requester_pays: false, bucket_type: None, no_sign_request: false, profile: Some("my-profile-name"), read_only: false, storage_class: None, allow_delete: false, allow_overwrite: false, auto_unmount: false, allow_root: false, allow_other: false, maximum_throughput_gbps: None, max_threads: 16, part_size: 8388608, uid: None, gid: None, dir_mode: None, file_mode: None, foreground: true, expected_bucket_owner: None, log_directory: None, log_metrics: false, debug: true, debug_crt: true, no_log: false, cache: None, metadata_ttl: None, max_cache_size: None, user_agent_prefix: None, sse: None, sse_kms_key_id: None, upload_checksums: None }
2024-06-28T08:08:17.059362Z DEBUG awscrt::libcrypto_resolve: searching process and loaded modules
2024-06-28T08:08:17.059387Z DEBUG awscrt::libcrypto_resolve: found static aws-lc HMAC symbols
2024-06-28T08:08:17.059413Z DEBUG awscrt::libcrypto_resolve: found static aws-lc libcrypto 1.1.1 EVP_MD symbols
2024-06-28T08:08:17.059441Z  INFO awscrt::tls-handler: static: Initializing TLS using s2n.
2024-06-28T08:08:17.059701Z DEBUG awscrt::tls-handler: ctx: Based on OS, we detected the default PKI path as /etc/ssl/certs, and ca file as /etc/ssl/certs/ca-certificates.crt
2024-06-28T08:08:17.059769Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: Initializing edge-triggered epoll
2024-06-28T08:08:17.059899Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: Using eventfd for cross-thread notifications.
2024-06-28T08:08:17.060112Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: Starting event-loop thread.
2024-06-28T08:08:17.060307Z  INFO awscrt::dns: id=0x55bc5e9e1050: Initializing default host resolver with 8 max host entries.
2024-06-28T08:08:17.060383Z  INFO awscrt::channel-bootstrap: id=0x55bc5e9fd120: Initializing client bootstrap with event-loop group 0x55bc5e9e3970
2024-06-28T08:08:17.060333Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: main loop started
2024-06-28T08:08:17.060602Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: acquiring bootstrap reference
2024-06-28T08:08:17.060730Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: Successfully created
2024-06-28T08:08:17.060783Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: default timeout 100000, and max events to process per tick 100
2024-06-28T08:08:17.060921Z  INFO awscrt::exp-backoff-strategy: id=0x55bc5e9fe860: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-06-28T08:08:17.060945Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: releasing bootstrap reference
2024-06-28T08:08:17.060987Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5e9fe860: Initializing retry token 0x55bc5e9fd3e0
2024-06-28T08:08:17.061017Z DEBUG awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client's token is invalid and is now updating.
2024-06-28T08:08:17.061318Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5e9fe860: Vending retry_token 0x55bc5e9fd3e0
2024-06-28T08:08:17.061370Z DEBUG awscrt::Unknown: id=0x55bc5e9f4f10: IMDS Client successfully acquired retry token.
2024-06-28T08:08:17.061413Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Acquire connection
2024-06-28T08:08:17.061479Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-06-28T08:08:17.061557Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: Requesting 1 new connections from http
2024-06-28T08:08:17.061710Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: acquiring bootstrap reference
2024-06-28T08:08:17.061733Z DEBUG awscrt::dns: id=0x55bc5e9e1050: Host resolution requested for 169.254.169.254
2024-06-28T08:08:17.061747Z DEBUG awscrt::dns: id=0x55bc5e9e1050: No cached entries found for 169.254.169.254 starting new resolver thread.
2024-06-28T08:08:17.061848Z DEBUG awscrt::dns: static: resolving host 169.254.169.254
2024-06-28T08:08:17.061904Z DEBUG awscrt::dns: static: resolved record: 169.254.169.254
2024-06-28T08:08:17.061941Z DEBUG awscrt::dns: static, resolving host 169.254.169.254 successful, returned 1 addresses
2024-06-28T08:08:17.061977Z DEBUG awscrt::dns: static: new address resolved 169.254.169.254 for host 169.254.169.254 caching
2024-06-28T08:08:17.062012Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.169.254 with 1 addresses
2024-06-28T08:08:17.062265Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: initializing with domain 0 and type 0
2024-06-28T08:08:17.062284Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-06-28T08:08:17.062295Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: beginning connect.
2024-06-28T08:08:17.062304Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: connecting to endpoint 169.254.169.254:80.
2024-06-28T08:08:17.063912Z  INFO awscrt::socket: id=0x7fb7d40043a0 fd=8: connection success
2024-06-28T08:08:17.063962Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: assigning to event loop 0x55bc5e9e6e20
2024-06-28T08:08:17.063979Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: client connection on socket 0x7fb7d40043a0 completed with error 0.
2024-06-28T08:08:17.063988Z DEBUG awscrt::channel: id=0x7fb7d4004f20: Beginning creation and setup of new channel.
2024-06-28T08:08:17.063996Z DEBUG awscrt::channel: id=0x7fb7d4004f20: setup complete, notifying caller.
2024-06-28T08:08:17.064006Z DEBUG awscrt::channel: id=0x7fb7d4004f20: no message pool is currently stored in the event-loop local storage, adding 0x7fb7d4004680 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-06-28T08:08:17.064024Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: channel 0x7fb7d4004f20 setup succeeded: bootstrapping.
2024-06-28T08:08:17.064034Z DEBUG awscrt::socket-handler: id=0x7fb7d4015c80: Socket handler created with max_read_size of 16384
2024-06-28T08:08:17.064046Z  INFO awscrt::http-connection: id=0x7fb7d40160a0: HTTP/1.1 client connection established.
2024-06-28T08:08:17.064054Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Received new connection (id=0x7fb7d40160a0) from http layer
2024-06-28T08:08:17.064062Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Grabbing pooled connection (0x7fb7d40160a0)
2024-06-28T08:08:17.064071Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.064079Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Successfully completed connection acquisition with connection id=0x7fb7d40160a0
2024-06-28T08:08:17.064099Z DEBUG awscrt::http-stream: id=0x7fb7d4017120: Created client request on connection=0x7fb7d40160a0: PUT /latest/api/token HTTP/1.1
2024-06-28T08:08:17.064317Z DEBUG awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client query received http status code 404 for requester 0x55bc5e9f5aa0.
2024-06-28T08:08:17.064331Z DEBUG awscrt::http-stream: id=0x7fb7d4017120: Client request complete, response status: 404 (Not Found).
2024-06-28T08:08:17.064341Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: User releasing connection (id=0x7fb7d40160a0)
2024-06-28T08:08:17.064351Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.064363Z DEBUG awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client failed to fetch token for requester 0x55bc5e9f5aa0, fall back to v1 for the same requester. Received response status code: 404
2024-06-28T08:08:17.064373Z DEBUG awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client failed to fetch token, fallback to v1. requester 0x55bc5e9e38d0.
2024-06-28T08:08:17.064380Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5e9fe860: Initializing retry token 0x7fb7d4018090
2024-06-28T08:08:17.064391Z ERROR awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client failed to update the token from IMDS.
2024-06-28T08:08:17.064402Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5e9fe860: Vending retry_token 0x7fb7d4018090
2024-06-28T08:08:17.064410Z DEBUG awscrt::Unknown: id=0x55bc5e9f4f10: IMDS Client successfully acquired retry token.
2024-06-28T08:08:17.064417Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Acquire connection
2024-06-28T08:08:17.064425Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Grabbing pooled connection (0x7fb7d40160a0)
2024-06-28T08:08:17.064434Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.064442Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: Successfully completed connection acquisition with connection id=0x7fb7d40160a0
2024-06-28T08:08:17.064456Z DEBUG awscrt::http-stream: id=0x7fb7d4018ab0: Created client request on connection=0x7fb7d40160a0: GET /latest/dynamic/instance-identity/document HTTP/1.1
2024-06-28T08:08:17.064635Z DEBUG awscrt::Unknown: (id=0x55bc5e9f4f10) IMDS client query received http status code 404 for requester 0x55bc5e9e38d0.
2024-06-28T08:08:17.064657Z DEBUG awscrt::http-stream: id=0x7fb7d4018ab0: Client request complete, response status: 404 (Not Found).
2024-06-28T08:08:17.064682Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: User releasing connection (id=0x7fb7d40160a0)
2024-06-28T08:08:17.064701Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.065270Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: release
2024-06-28T08:08:17.065378Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: ref count now zero, starting shut down process
2024-06-28T08:08:17.065488Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.065597Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=2, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=0
2024-06-28T08:08:17.065730Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: Releasing connection (id=0x7fb7d40160a0)
2024-06-28T08:08:17.065852Z DEBUG mountpoint_s3_client::instance_info: EC2 instance info not retrieved: ImdsQueryFailed(InvalidResponse("Not Found"))
2024-06-28T08:08:17.065910Z DEBUG awscrt::channel: id=0x7fb7d4004f20: beginning shutdown process
2024-06-28T08:08:17.065959Z DEBUG awscrt::channel: id=0x7fb7d4004f20: handler 0x7fb7d4015c80 shutdown in read dir completed.
2024-06-28T08:08:17.065997Z DEBUG awscrt::channel: id=0x7fb7d4004f20: handler 0x7fb7d40160a8 shutdown in read dir completed.
2024-06-28T08:08:17.066077Z DEBUG awscrt::channel: id=0x7fb7d4004f20: handler 0x7fb7d40160a8 shutdown in write dir completed.
2024-06-28T08:08:17.066119Z DEBUG awscrt::socket: id=0x7fb7d40043a0 fd=8: closing
2024-06-28T08:08:17.066185Z DEBUG awscrt::channel: id=0x7fb7d4004f20: handler 0x7fb7d4015c80 shutdown in write dir completed.
2024-06-28T08:08:17.066231Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: channel 0x7fb7d4004f20 shutdown with error 0.
2024-06-28T08:08:17.066315Z  INFO awscrt::http-connection: 0x7fb7d40160a0: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).
2024-06-28T08:08:17.066359Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: shutdown received for connection (id=0x7fb7d40160a0)
2024-06-28T08:08:17.066396Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.066455Z DEBUG awscrt::connection-manager: id=0x55bc5ea004e0: snapshot - state=2, 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=0
2024-06-28T08:08:17.066501Z  INFO awscrt::connection-manager: id=0x55bc5ea004e0: Destroying self
2024-06-28T08:08:17.066537Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: releasing bootstrap reference
2024-06-28T08:08:17.066572Z DEBUG awscrt::channel: id=0x7fb7d4004f20: destroying channel.
2024-06-28T08:08:17.066609Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: releasing bootstrap reference
2024-06-28T08:08:17.066645Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9fd120: bootstrap destroying
2024-06-28T08:08:17.067108Z  WARN mountpoint_s3::cli: failed to detect network throughput. Using 10 gbps as throughput. Use --maximum-throughput-gbps CLI flag to configure a target throughput appropriate for the instance. Detection failed due to: failed to get instance type: IMDS query failed: Invalid response from Imds: Not Found
2024-06-28T08:08:17.067134Z  INFO mountpoint_s3::cli: target network throughput 10 Gbps
2024-06-28T08:08:17.067191Z  INFO awscrt::event-loop: id=0x55bc5ea040d0: Initializing edge-triggered epoll
2024-06-28T08:08:17.067216Z  INFO awscrt::event-loop: id=0x55bc5ea040d0: Using eventfd for cross-thread notifications.
2024-06-28T08:08:17.067237Z  INFO awscrt::event-loop: id=0x55bc5ea040d0: Starting event-loop thread.
2024-06-28T08:08:17.067296Z  INFO awscrt::dns: id=0x55bc5e9f6470: Initializing default host resolver with 8 max host entries.
2024-06-28T08:08:17.067311Z  INFO awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: Initializing client bootstrap with event-loop group 0x55bc5e9f5ae0
2024-06-28T08:08:17.067319Z  INFO awscrt::standard-retry-strategy: static: creating new standard retry strategy
2024-06-28T08:08:17.067329Z  INFO awscrt::standard-retry-strategy: id=0x55bc5e9f6250: creating backing exponential backoff strategy with max_retries of 9
2024-06-28T08:08:17.067340Z  INFO awscrt::exp-backoff-strategy: id=0x55bc5e9ef8a0: Initializing exponential backoff retry strategy with scale factor: 500 jitter mode: 2 and max retries 9
2024-06-28T08:08:17.067349Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5e9f6250: maximum bucket capacity set to 500
2024-06-28T08:08:17.067369Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-06-28T08:08:17.067400Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/credentials"
2024-06-28T08:08:17.067442Z ERROR awscrt::common-io: static: Failed to open file. path:'/home/admin/.aws/credentials' mode:'rb' errno:2 aws-error:44(AWS_ERROR_FILE_INVALID_PATH)
2024-06-28T08:08:17.067456Z DEBUG awscrt::AWSProfile: Failed to read file at "/home/admin/.aws/credentials"
2024-06-28T08:08:17.067466Z DEBUG awscrt::AWSProfile: property "credential_source" has value "" replaced during merge
2024-06-28T08:08:17.067476Z DEBUG awscrt::AWSProfile: property "role_arn" has value "" replaced during merge
2024-06-28T08:08:17.067486Z DEBUG awscrt::AWSProfile: property "region" has value "" replaced during merge
2024-06-28T08:08:17.067511Z  INFO awscrt::AuthCredentialsProvider: static: profile my-profile-name has role_arn property is set to arn:aws:iam::123456789012:role/my-role-name, attempting to create an STS credentials provider.
2024-06-28T08:08:17.067532Z DEBUG awscrt::AuthCredentialsProvider: static: computed session_name as aws-common-runtime-profile-config-21339
2024-06-28T08:08:17.067550Z  INFO awscrt::AuthCredentialsProvider: TLS context not provided, initializing a new one for querying STS
2024-06-28T08:08:17.070487Z DEBUG awscrt::dns: static: Either no requests have been made for an address for 169.254.169.254 for the duration of the ttl, or this thread is being forcibly shutdown. Killing thread.
2024-06-28T08:08:17.070694Z DEBUG awscrt::dns: static: purging address 169.254.169.254 for host 169.254.169.254 from the cache due to cache eviction or shutdown
2024-06-28T08:08:17.072474Z  INFO awscrt::AuthCredentialsProvider: static: credential_source property set to Ec2InstanceMetadata
2024-06-28T08:08:17.072490Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: acquiring bootstrap reference
2024-06-28T08:08:17.072520Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: Successfully created
2024-06-28T08:08:17.072541Z  INFO awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-06-28T08:08:17.072553Z DEBUG awscrt::AuthCredentialsProvider: static: creating STS credentials provider
2024-06-28T08:08:17.072571Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55bc5eb3a540): using session_name aws-common-runtime-profile-config-21339
2024-06-28T08:08:17.072581Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55bc5eb3a540): using assume_role_arn arn:aws:iam::123456789012:role/my-role-name
2024-06-28T08:08:17.072616Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55bc5eb3a540): using credentials duration 900
2024-06-28T08:08:17.072639Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-06-28T08:08:17.072690Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-06-28T08:08:17.072708Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: acquiring bootstrap reference
2024-06-28T08:08:17.072719Z  INFO awscrt::connection-manager: id=0x55bc5eb3b710: Successfully created
2024-06-28T08:08:17.072729Z  INFO awscrt::standard-retry-strategy: static: creating new standard retry strategy
2024-06-28T08:08:17.072739Z  INFO awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: creating backing exponential backoff strategy with max_retries of 3
2024-06-28T08:08:17.072750Z  INFO awscrt::exp-backoff-strategy: id=0x55bc5eb3bec0: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 3
2024-06-28T08:08:17.072767Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: maximum bucket capacity set to 500
2024-06-28T08:08:17.072848Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: acquiring bootstrap reference
2024-06-28T08:08:17.074492Z  INFO awscrt::event-loop: id=0x55bc5ea040d0: main loop started
2024-06-28T08:08:17.074661Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: Destroying event_loop
2024-06-28T08:08:17.074843Z  INFO awscrt::event-loop: id=0x55bc5e9e6e20: Stopping event-loop thread.
2024-06-28T08:08:17.075033Z DEBUG awscrt::event-loop: id=0x55bc5e9e6e20: exiting main loop
2024-06-28T08:08:17.078153Z  INFO awscrt::event-loop: id=0x55bc5ec10450: Initializing edge-triggered epoll
2024-06-28T08:08:17.078168Z  INFO awscrt::event-loop: id=0x55bc5ec10450: Using eventfd for cross-thread notifications.
2024-06-28T08:08:17.078179Z  INFO awscrt::event-loop: id=0x55bc5ec10450: Starting event-loop thread.
2024-06-28T08:08:17.078466Z  INFO awscrt::event-loop: id=0x55bc5ea040d0: default timeout 100000, and max events to process per tick 100
2024-06-28T08:08:17.078664Z  INFO awscrt::event-loop: id=0x55bc5ec10450: main loop started
2024-06-28T08:08:17.078841Z  INFO awscrt::event-loop: id=0x55bc5ec10450: default timeout 100000, and max events to process per tick 100
2024-06-28T08:08:17.079625Z DEBUG awscrt::AWSEndpointsResolution: Resolved endpoint with status 0
2024-06-28T08:08:17.079673Z DEBUG list_objects{id=0 bucket="my-bucket-name" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client::list_objects: new request
2024-06-28T08:08:17.079695Z  INFO awscrt::S3Client: id=0x55bc5eb3c910 Initiating making of meta request
2024-06-28T08:08:17.079711Z DEBUG awscrt::S3MetaRequest: id=0x55bc5ecf5620 Created new Default Meta Request. operation=?
2024-06-28T08:08:17.079725Z DEBUG awscrt::dns: id=0x55bc5e9f6470: Host resolution requested for my-bucket-name.s3.eu-central-1.amazonaws.com
2024-06-28T08:08:17.079735Z DEBUG awscrt::dns: id=0x55bc5e9f6470: No cached entries found for my-bucket-name.s3.eu-central-1.amazonaws.com starting new resolver thread.
2024-06-28T08:08:17.079787Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: acquiring bootstrap reference
2024-06-28T08:08:17.079806Z  INFO awscrt::connection-manager: id=0x55bc5ed02a70: Successfully created
2024-06-28T08:08:17.079825Z DEBUG awscrt::S3Endpoint: id=0x55bc5ecf5cd0: Created connection manager 0x55bc5ed02a70 for endpoint
2024-06-28T08:08:17.079848Z  INFO awscrt::S3Client: id=0x55bc5eb3c910: Created meta request 0x55bc5ecf5620
2024-06-28T08:08:17.079893Z DEBUG awscrt::dns: static: resolving host my-bucket-name.s3.eu-central-1.amazonaws.com
2024-06-28T08:08:17.081884Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-06-28T08:08:17.081936Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Processing any new meta requests.
2024-06-28T08:08:17.082017Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating meta requests.
2024-06-28T08:08:17.082077Z DEBUG awscrt::S3MetaRequest: id=0x55bc5ecf5620: Meta Request Default created request 0x7fb7d80030d0
2024-06-28T08:08:17.082125Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating connections, assigning requests where possible.
2024-06-28T08:08:17.082159Z DEBUG awscrt::S3MetaRequest: id=0x55bc5ecf5620: Meta Request prepared request 0x7fb7d80030d0
2024-06-28T08:08:17.082167Z  INFO awscrt::S3ClientStats: id=0x55bc5eb3c910 Requests-in-flight(approx/exact):1/1  Requests-preparing:1  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-06-28T08:08:17.082219Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55bc5eb3a540): fetching credentials
2024-06-28T08:08:17.082253Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: attempting to acquire retry token for partition_id
2024-06-28T08:08:17.082266Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: bucket for partition_id  does not exist, attempting to create one
2024-06-28T08:08:17.082273Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: bucket 0x7fb7cc004790 for partition_id  created
2024-06-28T08:08:17.082283Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3bec0: Initializing retry token 0x7fb7cc004b90
2024-06-28T08:08:17.082335Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3bec0: Vending retry_token 0x7fb7cc004b90
2024-06-28T08:08:17.082384Z DEBUG awscrt::standard-retry-strategy: id=0x55bc5eb3bd50: token acquired callback invoked with error Success. with token 0x7fb7cc004380 and nested token 0x7fb7cc004b90
2024-06-28T08:08:17.082569Z DEBUG awscrt::AuthCredentialsProvider: id=0x55bc5eb2d030: IMDS provider trying to load credentials
2024-06-28T08:08:17.084345Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Initializing retry token 0x7fb7d8006480
2024-06-28T08:08:17.084393Z DEBUG awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client's token is invalid and is now updating.
2024-06-28T08:08:17.084433Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Vending retry_token 0x7fb7d8006480
2024-06-28T08:08:17.084470Z DEBUG awscrt::Unknown: id=0x55bc5eb2d370: IMDS Client successfully acquired retry token.
2024-06-28T08:08:17.084505Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Acquire connection
2024-06-28T08:08:17.084546Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-06-28T08:08:17.084585Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: Requesting 1 new connections from http
2024-06-28T08:08:17.084622Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: acquiring bootstrap reference
2024-06-28T08:08:17.084658Z DEBUG awscrt::dns: id=0x55bc5e9f6470: Host resolution requested for 169.254.169.254
2024-06-28T08:08:17.084693Z DEBUG awscrt::dns: id=0x55bc5e9f6470: No cached entries found for 169.254.169.254 starting new resolver thread.
2024-06-28T08:08:17.084797Z DEBUG awscrt::dns: static: resolving host 169.254.169.254
2024-06-28T08:08:17.084816Z DEBUG awscrt::dns: static: resolved record: 169.254.169.254
2024-06-28T08:08:17.084823Z DEBUG awscrt::dns: static, resolving host 169.254.169.254 successful, returned 1 addresses
2024-06-28T08:08:17.084835Z DEBUG awscrt::dns: static: new address resolved 169.254.169.254 for host 169.254.169.254 caching
2024-06-28T08:08:17.084846Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.169.254 with 1 addresses
2024-06-28T08:08:17.084903Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: initializing with domain 0 and type 0
2024-06-28T08:08:17.084950Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-06-28T08:08:17.085018Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: beginning connect.
2024-06-28T08:08:17.085057Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: connecting to endpoint 169.254.169.254:80.
2024-06-28T08:08:17.086524Z  INFO awscrt::socket: id=0x7fb7d8008320 fd=11: connection success
2024-06-28T08:08:17.086539Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: assigning to event loop 0x55bc5ea040d0
2024-06-28T08:08:17.086551Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: client connection on socket 0x7fb7d8008320 completed with error 0.
2024-06-28T08:08:17.086561Z DEBUG awscrt::channel: id=0x7fb7d8008df0: Beginning creation and setup of new channel.
2024-06-28T08:08:17.086570Z DEBUG awscrt::channel: id=0x7fb7d8008df0: setup complete, notifying caller.
2024-06-28T08:08:17.086582Z DEBUG awscrt::channel: id=0x7fb7d8008df0: no message pool is currently stored in the event-loop local storage, adding 0x7fb7d80067c0 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-06-28T08:08:17.086602Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: channel 0x7fb7d8008df0 setup succeeded: bootstrapping.
2024-06-28T08:08:17.086612Z DEBUG awscrt::socket-handler: id=0x7fb7d8009290: Socket handler created with max_read_size of 16384
2024-06-28T08:08:17.086625Z  INFO awscrt::http-connection: id=0x7fb7d80198e0: HTTP/1.1 client connection established.
2024-06-28T08:08:17.086635Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Received new connection (id=0x7fb7d80198e0) from http layer
2024-06-28T08:08:17.086644Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Grabbing pooled connection (0x7fb7d80198e0)
2024-06-28T08:08:17.086657Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.086666Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Successfully completed connection acquisition with connection id=0x7fb7d80198e0
2024-06-28T08:08:17.086682Z DEBUG awscrt::http-stream: id=0x7fb7d801a7f0: Created client request on connection=0x7fb7d80198e0: PUT /latest/api/token HTTP/1.1
2024-06-28T08:08:17.086940Z DEBUG awscrt::dns: static: resolved record: 52.219.171.214
2024-06-28T08:08:17.086955Z DEBUG awscrt::dns: static: resolved record: 3.5.134.190
2024-06-28T08:08:17.086963Z DEBUG awscrt::dns: static: resolved record: 52.219.169.170
2024-06-28T08:08:17.086972Z DEBUG awscrt::dns: static: resolved record: 3.5.138.137
2024-06-28T08:08:17.086978Z DEBUG awscrt::dns: static: resolved record: 52.219.47.41
2024-06-28T08:08:17.086988Z DEBUG awscrt::dns: static: resolved record: 52.219.169.158
2024-06-28T08:08:17.086997Z DEBUG awscrt::dns: static: resolved record: 3.5.139.118
2024-06-28T08:08:17.087006Z DEBUG awscrt::dns: static: resolved record: 3.5.137.167
2024-06-28T08:08:17.087017Z DEBUG awscrt::dns: static, resolving host my-bucket-name.s3.eu-central-1.amazonaws.com successful, returned 8 addresses
2024-06-28T08:08:17.087027Z DEBUG awscrt::dns: static: new address resolved 52.219.171.214 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087037Z DEBUG awscrt::dns: static: new address resolved 3.5.134.190 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087047Z DEBUG awscrt::dns: static: new address resolved 52.219.169.170 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087056Z DEBUG awscrt::dns: static: new address resolved 3.5.138.137 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087066Z DEBUG awscrt::dns: static: new address resolved 52.219.47.41 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087076Z DEBUG awscrt::dns: static: new address resolved 52.219.169.158 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087086Z DEBUG awscrt::dns: static: new address resolved 3.5.139.118 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087096Z DEBUG awscrt::dns: static: new address resolved 3.5.137.167 for host my-bucket-name.s3.eu-central-1.amazonaws.com caching
2024-06-28T08:08:17.087108Z DEBUG awscrt::dns: static, invoking resolution callback for host my-bucket-name.s3.eu-central-1.amazonaws.com with 1 addresses
2024-06-28T08:08:17.087164Z DEBUG awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client query received http status code 404 for requester 0x7fb7d8005320.
2024-06-28T08:08:17.087214Z DEBUG awscrt::http-stream: id=0x7fb7d801a7f0: Client request complete, response status: 404 (Not Found).
2024-06-28T08:08:17.087253Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: User releasing connection (id=0x7fb7d80198e0)
2024-06-28T08:08:17.087296Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.087336Z DEBUG awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client failed to fetch token for requester 0x7fb7d8005320, fall back to v1 for the same requester. Received response status code: 404
2024-06-28T08:08:17.087373Z DEBUG awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client failed to fetch token, fallback to v1. requester 0x7fb7d8005280.
2024-06-28T08:08:17.087409Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Initializing retry token 0x7fb7d801b2d0
2024-06-28T08:08:17.087447Z ERROR awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client failed to update the token from IMDS.
2024-06-28T08:08:17.087488Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Vending retry_token 0x7fb7d801b2d0
2024-06-28T08:08:17.087523Z DEBUG awscrt::Unknown: id=0x55bc5eb2d370: IMDS Client successfully acquired retry token.
2024-06-28T08:08:17.087559Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Acquire connection
2024-06-28T08:08:17.087595Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Grabbing pooled connection (0x7fb7d80198e0)
2024-06-28T08:08:17.087632Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.090493Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Successfully completed connection acquisition with connection id=0x7fb7d80198e0
2024-06-28T08:08:17.090520Z DEBUG awscrt::http-stream: id=0x7fb7d801b970: Created client request on connection=0x7fb7d80198e0: GET /latest/meta-data/iam/security-credentials/ HTTP/1.1
2024-06-28T08:08:17.090700Z DEBUG awscrt::Unknown: (id=0x55bc5eb2d370) IMDS client query received http status code 404 for requester 0x7fb7d8005280.
2024-06-28T08:08:17.090721Z DEBUG awscrt::http-stream: id=0x7fb7d801b970: Client request complete, response status: 404 (Not Found).
2024-06-28T08:08:17.090734Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: User releasing connection (id=0x7fb7d80198e0)
2024-06-28T08:08:17.090745Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.090758Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Initializing retry token 0x7fb7d8005c70
2024-06-28T08:08:17.090773Z DEBUG awscrt::exp-backoff-strategy: id=0x55bc5eb3a4c0: Vending retry_token 0x7fb7d8005c70
2024-06-28T08:08:17.090783Z DEBUG awscrt::Unknown: id=0x55bc5eb2d370: IMDS Client successfully acquired retry token.
2024-06-28T08:08:17.090793Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Acquire connection
2024-06-28T08:08:17.090802Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Grabbing pooled connection (0x7fb7d80198e0)
2024-06-28T08:08:17.090812Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.090822Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: Successfully completed connection acquisition with connection id=0x7fb7d80198e0
2024-06-28T08:08:17.090833Z ERROR awscrt::http-stream: id=static: Request path is invalid
2024-06-28T08:08:17.090847Z ERROR awscrt::http-connection: id=0x7fb7d80198e0: Cannot create request stream, error 2054 (AWS_ERROR_HTTP_INVALID_PATH)
2024-06-28T08:08:17.090866Z  INFO awscrt::AuthCredentialsProvider: id=0x55bc5eb2d030: IMDS provider failed to retrieve credentials: Path is invalid.
2024-06-28T08:08:17.090883Z ERROR awscrt::AuthSigning: (id=0x7fb7d8001490) Credentials Provider failed to source credentials with error 2054(aws-c-http: AWS_ERROR_HTTP_INVALID_PATH, Path is invalid.)
2024-06-28T08:08:17.090893Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55bc5eb3a540): signing completed with error code 6146
2024-06-28T08:08:17.090909Z ERROR awscrt::AuthSigning: (id=0x7fb7cc002570) Credentials Provider failed to source credentials with error 6146(aws-c-auth: AWS_AUTH_SIGNING_NO_CREDENTIALS, Attempt to sign an http request without credentials)
2024-06-28T08:08:17.090920Z ERROR awscrt::S3MetaRequest: id=0x55bc5ecf5620 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)
2024-06-28T08:08:17.090930Z ERROR awscrt::S3MetaRequest: id=0x55bc5ecf5620 Could not prepare request 0x7fb7d80030d0 due to error 6146 (Attempt to sign an http request without credentials).
2024-06-28T08:08:17.090980Z DEBUG list_objects{id=0 bucket="my-bucket-name" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=Default crt_error=None range=None duration=8.795349ms ttfb=None request_id=<unknown>
2024-06-28T08:08:17.091041Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: User releasing connection (id=0x7fb7d80198e0)
2024-06-28T08:08:17.091064Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-06-28T08:08:17.091087Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-06-28T08:08:17.091103Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Processing any new meta requests.
2024-06-28T08:08:17.091120Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating meta requests.
2024-06-28T08:08:17.091141Z DEBUG awscrt::S3MetaRequest: id=0x55bc5ecf5620 Meta request finished with error code 6146 (Attempt to sign an http request without credentials)
2024-06-28T08:08:17.091190Z  WARN list_objects{id=0 bucket="my-bucket-name" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: duration=11.465463ms request_id=<unknown> error=ClientError(NoSigningCredentials) meta request failed
2024-06-28T08:08:17.091210Z DEBUG list_objects{id=0 bucket="my-bucket-name" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 0, crt_error: Error(6146, "aws-c-auth: AWS_AUTH_SIGNING_NO_CREDENTIALS, Attempt to sign an http request without credentials"), error_response_headers: None, error_response_body: None }
2024-06-28T08:08:17.091238Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.091267Z DEBUG awscrt::S3MetaRequest: id=0x55bc5ecf5620 Cleaning up meta request
2024-06-28T08:08:17.091279Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client starting destruction.
2024-06-28T08:08:17.091326Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating connections, assigning requests where possible.
2024-06-28T08:08:17.091341Z  INFO awscrt::S3ClientStats: id=0x55bc5eb3c910 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-06-28T08:08:17.091355Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=1  process_work_task_in_progress=0  num_endpoints_allocated=1 s3express_provider_active=0 finish_destroy=0
2024-06-28T08:08:17.091369Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-06-28T08:08:17.091381Z  INFO awscrt::connection-manager: id=0x55bc5ed02a70: release
2024-06-28T08:08:17.091391Z  INFO awscrt::connection-manager: id=0x55bc5ed02a70: ref count now zero, starting shut down process
2024-06-28T08:08:17.091400Z  INFO awscrt::connection-manager: id=0x55bc5ed02a70: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.091412Z DEBUG awscrt::connection-manager: id=0x55bc5ed02a70: snapshot - state=2, 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=0
2024-06-28T08:08:17.091422Z  INFO awscrt::connection-manager: id=0x55bc5ed02a70: Destroying self
2024-06-28T08:08:17.091433Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.091450Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Processing any new meta requests.
2024-06-28T08:08:17.091470Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating meta requests.
2024-06-28T08:08:17.091483Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating connections, assigning requests where possible.
2024-06-28T08:08:17.091496Z  INFO awscrt::S3ClientStats: id=0x55bc5eb3c910 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-06-28T08:08:17.091508Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=1  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-06-28T08:08:17.091519Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-06-28T08:08:17.091528Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Processing any new meta requests.
2024-06-28T08:08:17.091537Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating meta requests.
2024-06-28T08:08:17.091545Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating connections, assigning requests where possible.
2024-06-28T08:08:17.091556Z  INFO awscrt::S3ClientStats: id=0x55bc5eb3c910 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-06-28T08:08:17.091568Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-06-28T08:08:17.091604Z  INFO mountpoint_s3::metrics: process.memory_usage: 13590528
2024-06-28T08:08:17.091628Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.mem_limit: 2013265920
2024-06-28T08:08:17.091608Z  INFO awscrt::event-loop: id=0x55bc5ec10450: Destroying event_loop
2024-06-28T08:08:17.091643Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_allocated: 0
2024-06-28T08:08:17.091670Z  INFO awscrt::event-loop: id=0x55bc5ec10450: Stopping event-loop thread.
2024-06-28T08:08:17.091673Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_cutoff: 33554432
2024-06-28T08:08:17.091691Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_num_blocks: 0
2024-06-28T08:08:17.091695Z DEBUG awscrt::event-loop: id=0x55bc5ec10450: exiting main loop
2024-06-28T08:08:17.091707Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_reserved: 0
2024-06-28T08:08:17.091720Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_used: 0
2024-06-28T08:08:17.091731Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_reserved: 0
2024-06-28T08:08:17.091748Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client body streaming ELG shutdown.
2024-06-28T08:08:17.091768Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_used: 0
2024-06-28T08:08:17.091775Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-06-28T08:08:17.091788Z  INFO mountpoint_s3::metrics: s3.client.host_count[host=my-bucket-name.s3.eu-central-1.amazonaws.com]: 8
2024-06-28T08:08:17.091792Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 s_s3_client_process_work_default - Processing any new meta requests.
2024-06-28T08:08:17.091811Z  INFO mountpoint_s3::metrics: s3.client.num_auto_default_network_io: 0
2024-06-28T08:08:17.091820Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating meta requests.
2024-06-28T08:08:17.091836Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_copy_network_io: 0
2024-06-28T08:08:17.091845Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Updating connections, assigning requests where possible.
2024-06-28T08:08:17.091861Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_get_network_io: 0
2024-06-28T08:08:17.091868Z  INFO awscrt::S3ClientStats: id=0x55bc5eb3c910 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-06-28T08:08:17.091881Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_put_network_io: 0
2024-06-28T08:08:17.091885Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=0  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=1
2024-06-28T08:08:17.091902Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_prepared: 0
2024-06-28T08:08:17.091909Z DEBUG awscrt::S3Client: id=0x55bc5eb3c910 Client finishing destruction.
2024-06-28T08:08:17.091921Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_processed: 0
2024-06-28T08:08:17.091932Z  INFO mountpoint_s3::metrics: s3.client.num_requests_stream_queued_waiting: 0
2024-06-28T08:08:17.091943Z  INFO mountpoint_s3::metrics: s3.client.num_requests_streaming_response: 0
2024-06-28T08:08:17.091954Z  INFO mountpoint_s3::metrics: s3.client.num_total_network_io: 0
2024-06-28T08:08:17.091964Z  INFO mountpoint_s3::metrics: s3.client.request_queue_size: 0
2024-06-28T08:08:17.091975Z  INFO mountpoint_s3::metrics: s3.meta_requests.failures[op=list_objects,status=-6146]: 1
2024-06-28T08:08:17.091986Z  INFO mountpoint_s3::metrics: s3.meta_requests.first_byte_latency_us[op=list_objects]: n=1: min=11456 p10=11519 p50=11519 avg=11488.00 p90=11519 p99=11519 p99.9=11519 max=11519
2024-06-28T08:08:17.091997Z  INFO mountpoint_s3::metrics: s3.meta_requests.total_latency_us[op=list_objects]: n=1: min=11456 p10=11519 p50=11519 avg=11488.00 p90=11519 p99=11519 p99.9=11519 max=11519
2024-06-28T08:08:17.092008Z  INFO mountpoint_s3::metrics: s3.meta_requests[op=list_objects]: 1
2024-06-28T08:08:17.092018Z  INFO mountpoint_s3::metrics: s3.requests.failures[op=list_objects,type=Default,status=-1]: 1
2024-06-28T08:08:17.092029Z  INFO mountpoint_s3::metrics: s3.requests.total_latency_us[op=list_objects,type=Default]: n=1: min=8768 p10=8831 p50=8831 avg=8800.00 p90=8831 p99=8831 p99.9=8831 max=8831
2024-06-28T08:08:17.092040Z  INFO mountpoint_s3::metrics: s3.requests[op=list_objects,type=Default]: 1
2024-06-28T08:08:17.092054Z  INFO mountpoint_s3::metrics: system.available_memory: 1548193792
2024-06-28T08:08:17.092555Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.092575Z  INFO awscrt::connection-manager: id=0x55bc5eb3b710: release
2024-06-28T08:08:17.092586Z  INFO awscrt::connection-manager: id=0x55bc5eb3b710: ref count now zero, starting shut down process
2024-06-28T08:08:17.092592Z  INFO awscrt::connection-manager: id=0x55bc5eb3b710: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.092603Z DEBUG awscrt::connection-manager: id=0x55bc5eb3b710: snapshot - state=2, 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=0
2024-06-28T08:08:17.092614Z  INFO awscrt::connection-manager: id=0x55bc5eb3b710: Destroying self
2024-06-28T08:08:17.093321Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.093337Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: release
2024-06-28T08:08:17.093355Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: ref count now zero, starting shut down process
2024-06-28T08:08:17.093365Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.093374Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=2, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=0
2024-06-28T08:08:17.093384Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: Releasing connection (id=0x7fb7d80198e0)
2024-06-28T08:08:17.093396Z DEBUG awscrt::channel: id=0x7fb7d8008df0: beginning shutdown process
2024-06-28T08:08:17.093405Z DEBUG awscrt::channel: id=0x7fb7d8008df0: handler 0x7fb7d8009290 shutdown in read dir completed.
2024-06-28T08:08:17.093414Z DEBUG awscrt::channel: id=0x7fb7d8008df0: handler 0x7fb7d80198e8 shutdown in read dir completed.
2024-06-28T08:08:17.093423Z DEBUG awscrt::channel: id=0x7fb7d8008df0: handler 0x7fb7d80198e8 shutdown in write dir completed.
2024-06-28T08:08:17.093432Z DEBUG awscrt::socket: id=0x7fb7d8008320 fd=11: closing
2024-06-28T08:08:17.093465Z DEBUG awscrt::channel: id=0x7fb7d8008df0: handler 0x7fb7d8009290 shutdown in write dir completed.
2024-06-28T08:08:17.093483Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: channel 0x7fb7d8008df0 shutdown with error 0.
2024-06-28T08:08:17.093496Z  INFO awscrt::http-connection: 0x7fb7d80198e0: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).
2024-06-28T08:08:17.093508Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: shutdown received for connection (id=0x7fb7d80198e0)
2024-06-28T08:08:17.093517Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: manager release, failing 0 pending acquisitions
2024-06-28T08:08:17.093524Z DEBUG awscrt::connection-manager: id=0x55bc5eb2d480: snapshot - state=2, 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=0
2024-06-28T08:08:17.093533Z  INFO awscrt::connection-manager: id=0x55bc5eb2d480: Destroying self
2024-06-28T08:08:17.093538Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.093545Z DEBUG awscrt::channel: id=0x7fb7d8008df0: destroying channel.
2024-06-28T08:08:17.093552Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: releasing bootstrap reference
2024-06-28T08:08:17.093559Z DEBUG awscrt::channel-bootstrap: id=0x55bc5e9e4bc0: bootstrap destroying
Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-name in region eu-central-1
    1: Client error
    2: No signing credentials found
arsh commented 2 months ago

Mountpoint uses the Common Runtime (CRT) as its S3 client and I suspect that does not support IAM Roles Anywhere. I'm asking internally and will post back an update when I get it. If CRT does not support it, this will become a feature request to them and later us.

arsh commented 2 months ago

Can you try using credential_process as per https://docs.aws.amazon.com/rolesanywhere/latest/userguide/credential-helper.html#credential-helper-examples instead of credential_source = Ec2InstanceMetadata?

arsh commented 2 months ago

The CRT supports Ec2InstanceMetadata credential source, however it does not support custom endpoints. That is, setting AWS_EC2_METADATA_SERVICE_ENDPOINT will not have any effect for Mountpoint.

sdauhuchytsrf commented 2 months ago

Hi @arsh. Thank you for your response.

Here is the contests of my ~/.aws/config file:

[profile default]
credential_process = aws_signing_helper credential-process --certificate /path/to/cert/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:region:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:region:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/my-role-name

[profile test]
source_profile = default
role_arn=arn:aws:iam::987654321098:role/another-role-name
region = eu-central-1
output = json

Checking the identity:

aws sts get-caller-identity --profile test
{
    "UserId": "AROA...VVVG:botocore-session-1234567890",
    "Account": "987654321098",
    "Arn": "arn:aws:sts::987654321098:assumed-role/another-role-name/botocore-session-1234567890"
}

Listing the buckets:

aws s3 ls --profile test
...
I see the output here, permissions are OK
...

Trying to mount S3 bucket:

mount-s3 my-bucket-in-987654321098-account /path/to/mount/dir --region eu-central-1 --profile test
Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-in-987654321098-account in region eu-central-1
    1: Client error
    2: No signing credentials found
Error: Failed to create mount process

I've noticed that when I remove --region eu-central-1 from mount-s3 command it tries to connect to us-east-1. Looks like mount-s3 doesn't see config in ~/.aws/config file since profile is already set there (see profile above):

mount-s3 my-bucket-in-987654321098-account /path/to/mount/dir --profile test
Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-in-987654321098-account in region us-east-1
    1: Client error
    2: No signing credentials found
Error: Failed to create mount process
arsh commented 2 months ago

I'd like to see the logs for this last run. Can you specify a log directory with the -l cli option. For example

mount-s3 my-bucket-in-987654321098-account /path/to/mount/dir --profile test -l <LOG_DIR_PATH>
dannycjones commented 2 months ago

@sdauhuchytsrf, can you try setting environment variable AWS_PROFILE=test instead of using --profile test. This is a workaround for a known issue we have at the moment with credential_process and using the profile CLI argument: https://github.com/awslabs/mountpoint-s3/issues/389#issuecomment-1643908183.

sdauhuchytsrf commented 2 months ago

@dannycjones @arsh here is the output:

AWS_PROFILE=test mount-s3 my-bucket-in-987654321098-account /path/to/mount/dir -l mount-s3-logs/ --debug --debug-crt

Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-in-987654321098-account in region us-east-1
    1: Client error
    2: No signing credentials found
Error: Failed to create mount process

cat mount-s3-logs/mountpoint-s3-2024-07-04T10-07-28Z.log
2024-07-04T10:07:28.173210Z DEBUG mountpoint_s3::cli: waiting up to 30 seconds for child process to be ready
2024-07-04T10:07:28.173330Z  INFO mountpoint_s3::cli: mount-s3 1.7.2
2024-07-04T10:07:28.173343Z DEBUG mountpoint_s3::cli: CliArgs { bucket_name: "my-bucket-in-987654321098-account", mount_point: "test", prefix: None, region: None, endpoint_url: None, force_path_style: false, transfer_acceleration: false, dual_stack: false, requester_pays: false, bucket_type: None, no_sign_request: false, profile: None, read_only: false, storage_class: None, allow_delete: false, allow_overwrite: false, auto_unmount: false, allow_root: false, allow_other: false, maximum_throughput_gbps: None, max_threads: 16, part_size: 8388608, uid: None, gid: None, dir_mode: None, file_mode: None, foreground: false, expected_bucket_owner: None, log_directory: Some("mount-s3-logs/"), log_metrics: false, debug: true, debug_crt: true, no_log: false, cache: None, metadata_ttl: None, max_cache_size: None, user_agent_prefix: None, sse: None, sse_kms_key_id: None, upload_checksums: None }
2024-07-04T10:07:28.173619Z DEBUG awscrt::libcrypto_resolve: searching process and loaded modules
2024-07-04T10:07:28.173630Z DEBUG awscrt::libcrypto_resolve: found static aws-lc HMAC symbols
2024-07-04T10:07:28.173637Z DEBUG awscrt::libcrypto_resolve: found static aws-lc libcrypto 1.1.1 EVP_MD symbols
2024-07-04T10:07:28.173644Z  INFO awscrt::tls-handler: static: Initializing TLS using s2n.
2024-07-04T10:07:28.173834Z DEBUG awscrt::tls-handler: ctx: Based on OS, we detected the default PKI path as /etc/ssl/certs, and ca file as /etc/ssl/certs/ca-certificates.crt
2024-07-04T10:07:28.173869Z  INFO awscrt::event-loop: id=0x556c30f9e640: Initializing edge-triggered epoll
2024-07-04T10:07:28.173881Z  INFO awscrt::event-loop: id=0x556c30f9e640: Using eventfd for cross-thread notifications.
2024-07-04T10:07:28.173894Z  INFO awscrt::event-loop: id=0x556c30f9e640: Starting event-loop thread.
2024-07-04T10:07:28.173935Z  INFO awscrt::dns: id=0x556c30f90050: Initializing default host resolver with 8 max host entries.
2024-07-04T10:07:28.173948Z  INFO awscrt::channel-bootstrap: id=0x556c310144d0: Initializing client bootstrap with event-loop group 0x556c30f9e690
2024-07-04T10:07:28.173986Z  INFO awscrt::event-loop: id=0x556c30f9e640: main loop started
2024-07-04T10:07:28.173999Z  INFO awscrt::event-loop: id=0x556c30f9e640: default timeout 100000, and max events to process per tick 100
2024-07-04T10:07:28.174034Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: acquiring bootstrap reference
2024-07-04T10:07:28.174039Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: Successfully created
2024-07-04T10:07:28.174043Z  INFO awscrt::exp-backoff-strategy: id=0x556c30fa10f0: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-07-04T10:07:28.174046Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: releasing bootstrap reference
2024-07-04T10:07:28.174052Z DEBUG awscrt::exp-backoff-strategy: id=0x556c30fa10f0: Initializing retry token 0x556c30f8fb90
2024-07-04T10:07:28.174071Z DEBUG awscrt::Unknown: (id=0x556c30fb2a90) IMDS client's token is invalid and is now updating.
2024-07-04T10:07:28.174090Z DEBUG awscrt::exp-backoff-strategy: id=0x556c30fa10f0: Vending retry_token 0x556c30f8fb90
2024-07-04T10:07:28.174095Z DEBUG awscrt::Unknown: id=0x556c30fb2a90: IMDS Client successfully acquired retry token.
2024-07-04T10:07:28.174101Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Acquire connection
2024-07-04T10:07:28.174106Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-07-04T10:07:28.174110Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: Requesting 1 new connections from http
2024-07-04T10:07:28.174114Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: acquiring bootstrap reference
2024-07-04T10:07:28.174123Z DEBUG awscrt::dns: id=0x556c30f90050: Host resolution requested for 169.254.169.254
2024-07-04T10:07:28.174129Z DEBUG awscrt::dns: id=0x556c30f90050: No cached entries found for 169.254.169.254 starting new resolver thread.
2024-07-04T10:07:28.174218Z DEBUG awscrt::dns: static: resolving host 169.254.169.254
2024-07-04T10:07:28.174235Z DEBUG awscrt::dns: static: resolved record: 169.254.169.254
2024-07-04T10:07:28.174239Z DEBUG awscrt::dns: static, resolving host 169.254.169.254 successful, returned 1 addresses
2024-07-04T10:07:28.174244Z DEBUG awscrt::dns: static: new address resolved 169.254.169.254 for host 169.254.169.254 caching
2024-07-04T10:07:28.174248Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.169.254 with 1 addresses
2024-07-04T10:07:28.174285Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: initializing with domain 0 and type 0
2024-07-04T10:07:28.174294Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-07-04T10:07:28.174299Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: beginning connect.
2024-07-04T10:07:28.174303Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: connecting to endpoint 169.254.169.254:80.
2024-07-04T10:07:28.174919Z  INFO awscrt::socket: id=0x7fec84002b00 fd=10: connection success
2024-07-04T10:07:28.174937Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: assigning to event loop 0x556c30f9e640
2024-07-04T10:07:28.174945Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: client connection on socket 0x7fec84002b00 completed with error 0.
2024-07-04T10:07:28.174950Z DEBUG awscrt::channel: id=0x7fec84003150: Beginning creation and setup of new channel.
2024-07-04T10:07:28.174956Z DEBUG awscrt::channel: id=0x7fec84003150: setup complete, notifying caller.
2024-07-04T10:07:28.174962Z DEBUG awscrt::channel: id=0x7fec84003150: no message pool is currently stored in the event-loop local storage, adding 0x7fec84002d80 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-07-04T10:07:28.174974Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: channel 0x7fec84003150 setup succeeded: bootstrapping.
2024-07-04T10:07:28.174981Z DEBUG awscrt::socket-handler: id=0x7fec84013d80: Socket handler created with max_read_size of 16384
2024-07-04T10:07:28.174991Z  INFO awscrt::http-connection: id=0x7fec84013f70: HTTP/1.1 client connection established.
2024-07-04T10:07:28.174996Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Received new connection (id=0x7fec84013f70) from http layer
2024-07-04T10:07:28.174999Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Grabbing pooled connection (0x7fec84013f70)
2024-07-04T10:07:28.175003Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.175006Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Successfully completed connection acquisition with connection id=0x7fec84013f70
2024-07-04T10:07:28.175016Z DEBUG awscrt::http-stream: id=0x7fec84014a40: Created client request on connection=0x7fec84013f70: PUT /latest/api/token HTTP/1.1
2024-07-04T10:07:28.175213Z DEBUG awscrt::Unknown: (id=0x556c30fb2a90) IMDS client query received http status code 404 for requester 0x556c30fa5570.
2024-07-04T10:07:28.175228Z DEBUG awscrt::http-stream: id=0x7fec84014a40: Client request complete, response status: 404 (Not Found).
2024-07-04T10:07:28.175235Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: User releasing connection (id=0x7fec84013f70)
2024-07-04T10:07:28.175244Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.175254Z DEBUG awscrt::Unknown: (id=0x556c30fb2a90) IMDS client failed to fetch token for requester 0x556c30fa5570, fall back to v1 for the same requester. Received response status code: 404
2024-07-04T10:07:28.175257Z DEBUG awscrt::Unknown: (id=0x556c30fb2a90) IMDS client failed to fetch token, fallback to v1. requester 0x556c30fa5ac0.
2024-07-04T10:07:28.175260Z DEBUG awscrt::exp-backoff-strategy: id=0x556c30fa10f0: Initializing retry token 0x7fec840151b0
2024-07-04T10:07:28.175266Z ERROR awscrt::Unknown: (id=0x556c30fb2a90) IMDS client failed to update the token from IMDS.
2024-07-04T10:07:28.175272Z DEBUG awscrt::exp-backoff-strategy: id=0x556c30fa10f0: Vending retry_token 0x7fec840151b0
2024-07-04T10:07:28.175275Z DEBUG awscrt::Unknown: id=0x556c30fb2a90: IMDS Client successfully acquired retry token.
2024-07-04T10:07:28.175278Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Acquire connection
2024-07-04T10:07:28.175280Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Grabbing pooled connection (0x7fec84013f70)
2024-07-04T10:07:28.175283Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.175286Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: Successfully completed connection acquisition with connection id=0x7fec84013f70
2024-07-04T10:07:28.175292Z DEBUG awscrt::http-stream: id=0x7fec84015570: Created client request on connection=0x7fec84013f70: GET /latest/dynamic/instance-identity/document HTTP/1.1
2024-07-04T10:07:28.175528Z DEBUG awscrt::Unknown: (id=0x556c30fb2a90) IMDS client query received http status code 404 for requester 0x556c30fa5ac0.
2024-07-04T10:07:28.175539Z DEBUG awscrt::http-stream: id=0x7fec84015570: Client request complete, response status: 404 (Not Found).
2024-07-04T10:07:28.175543Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: User releasing connection (id=0x7fec84013f70)
2024-07-04T10:07:28.175547Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.175581Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: release
2024-07-04T10:07:28.175591Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: ref count now zero, starting shut down process
2024-07-04T10:07:28.175596Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: manager release, failing 0 pending acquisitions
2024-07-04T10:07:28.175604Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=2, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=0
2024-07-04T10:07:28.175608Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: Releasing connection (id=0x7fec84013f70)
2024-07-04T10:07:28.175623Z DEBUG mountpoint_s3_client::instance_info: EC2 instance info not retrieved: ImdsQueryFailed(InvalidResponse("Not Found"))
2024-07-04T10:07:28.175634Z  WARN mountpoint_s3::cli: failed to detect network throughput. Using 10 gbps as throughput. Use --maximum-throughput-gbps CLI flag to configure a target throughput appropriate for the instance. Detection failed due to: failed to get instance type: IMDS query failed: Invalid response from Imds: Not Found
2024-07-04T10:07:28.175641Z  INFO mountpoint_s3::cli: target network throughput 10 Gbps
2024-07-04T10:07:28.175651Z DEBUG awscrt::channel: id=0x7fec84003150: beginning shutdown process
2024-07-04T10:07:28.175658Z DEBUG mountpoint_s3::cli: using default region us-east-1
2024-07-04T10:07:28.175662Z DEBUG awscrt::channel: id=0x7fec84003150: handler 0x7fec84013d80 shutdown in read dir completed.
2024-07-04T10:07:28.175675Z DEBUG awscrt::channel: id=0x7fec84003150: handler 0x7fec84013f78 shutdown in read dir completed.
2024-07-04T10:07:28.175681Z DEBUG awscrt::channel: id=0x7fec84003150: handler 0x7fec84013f78 shutdown in write dir completed.
2024-07-04T10:07:28.175686Z DEBUG awscrt::socket: id=0x7fec84002b00 fd=10: closing
2024-07-04T10:07:28.175685Z  INFO awscrt::event-loop: id=0x556c30fa56f0: Initializing edge-triggered epoll
2024-07-04T10:07:28.175697Z  INFO awscrt::event-loop: id=0x556c30fa56f0: Using eventfd for cross-thread notifications.
2024-07-04T10:07:28.175704Z  INFO awscrt::event-loop: id=0x556c30fa56f0: Starting event-loop thread.
2024-07-04T10:07:28.175718Z DEBUG awscrt::channel: id=0x7fec84003150: handler 0x7fec84013d80 shutdown in write dir completed.
2024-07-04T10:07:28.175725Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: channel 0x7fec84003150 shutdown with error 0.
2024-07-04T10:07:28.175729Z  INFO awscrt::http-connection: 0x7fec84013f70: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).
2024-07-04T10:07:28.175734Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: shutdown received for connection (id=0x7fec84013f70)
2024-07-04T10:07:28.175737Z  INFO awscrt::dns: id=0x556c30f903d0: Initializing default host resolver with 8 max host entries.
2024-07-04T10:07:28.175738Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: manager release, failing 0 pending acquisitions
2024-07-04T10:07:28.175744Z  INFO awscrt::channel-bootstrap: id=0x556c30fa9140: Initializing client bootstrap with event-loop group 0x556c30f8fc90
2024-07-04T10:07:28.175746Z DEBUG awscrt::connection-manager: id=0x556c30f91ab0: snapshot - state=2, 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=0
2024-07-04T10:07:28.175748Z  INFO awscrt::standard-retry-strategy: static: creating new standard retry strategy
2024-07-04T10:07:28.175750Z  INFO awscrt::connection-manager: id=0x556c30f91ab0: Destroying self
2024-07-04T10:07:28.175752Z  INFO awscrt::standard-retry-strategy: id=0x556c30fa91b0: creating backing exponential backoff strategy with max_retries of 9
2024-07-04T10:07:28.175757Z  INFO awscrt::exp-backoff-strategy: id=0x556c30fb1cd0: Initializing exponential backoff retry strategy with scale factor: 500 jitter mode: 2 and max retries 9
2024-07-04T10:07:28.175757Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: releasing bootstrap reference
2024-07-04T10:07:28.175759Z DEBUG awscrt::standard-retry-strategy: id=0x556c30fa91b0: maximum bucket capacity set to 500
2024-07-04T10:07:28.175761Z DEBUG awscrt::channel: id=0x7fec84003150: destroying channel.
2024-07-04T10:07:28.175763Z  INFO awscrt::AuthCredentialsProvider: (id=0x556c30f9c930): TLS context not provided, initializing a new one for credentials provider.
2024-07-04T10:07:28.175766Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: releasing bootstrap reference
2024-07-04T10:07:28.175770Z DEBUG awscrt::channel-bootstrap: id=0x556c310144d0: bootstrap destroying
2024-07-04T10:07:28.179227Z  INFO awscrt::event-loop: id=0x556c30fa56f0: main loop started
2024-07-04T10:07:28.179242Z  INFO awscrt::event-loop: id=0x556c30fa56f0: default timeout 100000, and max events to process per tick 100
2024-07-04T10:07:28.181109Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-04T10:07:28.181143Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/credentials"
2024-07-04T10:07:28.181150Z ERROR awscrt::common-io: static: Failed to open file. path:'/home/admin/.aws/credentials' mode:'rb' errno:2 aws-error:44(AWS_ERROR_FILE_INVALID_PATH)
2024-07-04T10:07:28.181153Z DEBUG awscrt::AWSProfile: Failed to read file at "/home/admin/.aws/credentials"
2024-07-04T10:07:28.181157Z DEBUG awscrt::AWSProfile: property "credential_process" has value "" replaced during merge
2024-07-04T10:07:28.181165Z DEBUG awscrt::AWSProfile: property "output" has value "" replaced during merge
2024-07-04T10:07:28.181168Z DEBUG awscrt::AWSProfile: property "region" has value "" replaced during merge
2024-07-04T10:07:28.181171Z DEBUG awscrt::AWSProfile: property "source_profile" has value "" replaced during merge
2024-07-04T10:07:28.181176Z DEBUG awscrt::AWSProfile: property "role_arn" has value "" replaced during merge
2024-07-04T10:07:28.181182Z  INFO awscrt::AuthCredentialsProvider: static: profile test has role_arn property is set to arn:aws:iam::987654321098:role/another-role-name, attempting to create an STS credentials provider.
2024-07-04T10:07:28.181186Z DEBUG awscrt::AuthCredentialsProvider: static: computed session_name as aws-common-runtime-profile-config-8256
2024-07-04T10:07:28.181188Z DEBUG awscrt::AuthCredentialsProvider: static: source_profile set to default
2024-07-04T10:07:28.181191Z  INFO awscrt::AuthCredentialsProvider: static: profile default attempting to create profile-based credentials provider
2024-07-04T10:07:28.181194Z DEBUG awscrt::AuthCredentialsProvider: static: creating STS credentials provider
2024-07-04T10:07:28.181197Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8450): using session_name aws-common-runtime-profile-config-8256
2024-07-04T10:07:28.181200Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8450): using assume_role_arn arn:aws:iam::987654321098:role/another-role-name
2024-07-04T10:07:28.181203Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8450): using credentials duration 900
2024-07-04T10:07:28.181207Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-04T10:07:28.181222Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-07-04T10:07:28.181228Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: acquiring bootstrap reference
2024-07-04T10:07:28.181231Z  INFO awscrt::connection-manager: id=0x556c310e9d70: Successfully created
2024-07-04T10:07:28.181233Z  INFO awscrt::standard-retry-strategy: static: creating new standard retry strategy
2024-07-04T10:07:28.181236Z  INFO awscrt::standard-retry-strategy: id=0x556c310e9f20: creating backing exponential backoff strategy with max_retries of 3
2024-07-04T10:07:28.181239Z  INFO awscrt::exp-backoff-strategy: id=0x556c310ea010: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 3
2024-07-04T10:07:28.181241Z DEBUG awscrt::standard-retry-strategy: id=0x556c310e9f20: maximum bucket capacity set to 500
2024-07-04T10:07:28.181247Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-04T10:07:28.181264Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-07-04T10:07:28.181269Z ERROR awscrt::AuthCredentialsProvider: Failed to resolve token file path during sts web identity provider initialization.
2024-07-04T10:07:28.181273Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-04T10:07:28.181284Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-07-04T10:07:28.181287Z ERROR awscrt::AuthCredentialsProvider: Failed to resolve credentials_process command during process credentials provider initialization.
2024-07-04T10:07:28.181292Z  INFO awscrt::AuthCredentialsProvider: ECS provider: Unable to initialize from environment because AWS_CONTAINER_CREDENTIALS_FULL_URI and AWS_CONTAINER_CREDENTIALS_RELATIVE_URI are not set.
2024-07-04T10:07:28.181296Z  INFO awscrt::AuthCredentialsProvider: default chain: IMDS credentials provider will be used to retrieve credentials
2024-07-04T10:07:28.181299Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: acquiring bootstrap reference
2024-07-04T10:07:28.181305Z  INFO awscrt::connection-manager: id=0x556c310ea610: Successfully created
2024-07-04T10:07:28.181308Z  INFO awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-07-04T10:07:28.181353Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: acquiring bootstrap reference
2024-07-04T10:07:28.183218Z DEBUG awscrt::dns: static: Either no requests have been made for an address for 169.254.169.254 for the duration of the ttl, or this thread is being forcibly shutdown. Killing thread.
2024-07-04T10:07:28.183236Z DEBUG awscrt::dns: static: purging address 169.254.169.254 for host 169.254.169.254 from the cache due to cache eviction or shutdown
2024-07-04T10:07:28.186966Z  INFO awscrt::event-loop: id=0x556c3109a500: Initializing edge-triggered epoll
2024-07-04T10:07:28.186983Z  INFO awscrt::event-loop: id=0x556c3109a500: Using eventfd for cross-thread notifications.
2024-07-04T10:07:28.186992Z  INFO awscrt::event-loop: id=0x556c3109a500: Starting event-loop thread.
2024-07-04T10:07:28.187065Z  INFO awscrt::event-loop: id=0x556c3109a500: main loop started
2024-07-04T10:07:28.187079Z  INFO awscrt::event-loop: id=0x556c3109a500: default timeout 100000, and max events to process per tick 100
2024-07-04T10:07:28.187214Z  INFO awscrt::event-loop: id=0x556c30f9e640: Destroying event_loop
2024-07-04T10:07:28.187223Z  INFO awscrt::event-loop: id=0x556c30f9e640: Stopping event-loop thread.
2024-07-04T10:07:28.187241Z DEBUG awscrt::event-loop: id=0x556c30f9e640: exiting main loop
2024-07-04T10:07:28.188458Z DEBUG awscrt::AWSEndpointsResolution: Resolved endpoint with status 0
2024-07-04T10:07:28.188504Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client::list_objects: new request
2024-07-04T10:07:28.188515Z  INFO awscrt::S3Client: id=0x556c310eaf90 Initiating making of meta request
2024-07-04T10:07:28.188523Z DEBUG awscrt::S3MetaRequest: id=0x556c312a42d0 Created new Default Meta Request. operation=?
2024-07-04T10:07:28.188527Z DEBUG awscrt::dns: id=0x556c30f903d0: Host resolution requested for my-bucket-in-987654321098-account.s3.us-east-1.amazonaws.com
2024-07-04T10:07:28.188531Z DEBUG awscrt::dns: id=0x556c30f903d0: No cached entries found for my-bucket-in-987654321098-account.s3.us-east-1.amazonaws.com starting new resolver thread.
2024-07-04T10:07:28.188576Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: acquiring bootstrap reference
2024-07-04T10:07:28.188580Z  INFO awscrt::connection-manager: id=0x556c312b1140: Successfully created
2024-07-04T10:07:28.188583Z DEBUG awscrt::S3Endpoint: id=0x556c312a47a0: Created connection manager 0x556c312b1140 for endpoint
2024-07-04T10:07:28.188602Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.188604Z DEBUG awscrt::dns: static: resolving host my-bucket-in-987654321098-account.s3.us-east-1.amazonaws.com
2024-07-04T10:07:28.188612Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.188617Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.188622Z DEBUG awscrt::S3MetaRequest: id=0x556c312a42d0: Meta Request Default created request 0x7fec7c0010c0
2024-07-04T10:07:28.188634Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.188639Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):1/1  Requests-preparing:1  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-04T10:07:28.188658Z DEBUG awscrt::S3MetaRequest: id=0x556c312a42d0: Meta Request prepared request 0x7fec7c0010c0
2024-07-04T10:07:28.188693Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c30f9c930) Credentials provider chain get credentials dispatch
2024-07-04T10:07:28.188697Z  INFO awscrt::AuthCredentialsProvider: (id=0x556c310ea550) Cached credentials provider has expired credentials.  Requerying.
2024-07-04T10:07:28.188701Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain get credentials dispatch
2024-07-04T10:07:28.188705Z  INFO awscrt::AuthCredentialsProvider: id=0x556c30fafd40: Failed to load credentials from environment variables: Required environment variables could not be sourced from process environment
2024-07-04T10:07:28.188709Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain callback 1 invoked with invalid credentials and error code 6150
2024-07-04T10:07:28.188711Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain invoking chain member #1
2024-07-04T10:07:28.188714Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8450): fetching credentials
2024-07-04T10:07:28.188717Z DEBUG awscrt::standard-retry-strategy: id=0x556c310e9f20: attempting to acquire retry token for partition_id
2024-07-04T10:07:28.188720Z DEBUG awscrt::standard-retry-strategy: id=0x556c310e9f20: bucket for partition_id  does not exist, attempting to create one
2024-07-04T10:07:28.188728Z DEBUG awscrt::standard-retry-strategy: id=0x556c310e9f20: bucket 0x7fec88003b70 for partition_id  created
2024-07-04T10:07:28.188731Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea010: Initializing retry token 0x7fec88003c50
2024-07-04T10:07:28.188744Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea010: Vending retry_token 0x7fec88003c50
2024-07-04T10:07:28.188749Z DEBUG awscrt::standard-retry-strategy: id=0x556c310e9f20: token acquired callback invoked with error Success. with token 0x7fec88003a90 and nested token 0x7fec88003c50
2024-07-04T10:07:28.188759Z  INFO awscrt::AuthCredentialsProvider: (id=0x556c310e9000) Profile credentials provider attempting to pull credentials from profile "default"
2024-07-04T10:07:28.188762Z  INFO awscrt::AuthCredentialsProvider: Failed to load credentials from profile provider: Attempt to pop an item from an empty queue.
2024-07-04T10:07:28.188767Z ERROR awscrt::AuthSigning: (id=0x7fec7c001070) Credentials Provider failed to source credentials with error 30(aws-c-common: AWS_ERROR_PRIORITY_QUEUE_EMPTY, Attempt to pop an item from an empty queue.)
2024-07-04T10:07:28.188770Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8450): signing completed with error code 6146
2024-07-04T10:07:28.188773Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain callback 2 invoked with invalid credentials and error code 6146
2024-07-04T10:07:28.188776Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain invoking chain member #2
2024-07-04T10:07:28.188779Z DEBUG awscrt::AuthCredentialsProvider: id=0x556c310e6220: IMDS provider trying to load credentials
2024-07-04T10:07:28.188784Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Initializing retry token 0x7fec7c004540
2024-07-04T10:07:28.188788Z DEBUG awscrt::Unknown: (id=0x556c310e8110) IMDS client's token is invalid and is now updating.
2024-07-04T10:07:28.188793Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Vending retry_token 0x7fec7c004540
2024-07-04T10:07:28.188796Z DEBUG awscrt::Unknown: id=0x556c310e8110: IMDS Client successfully acquired retry token.
2024-07-04T10:07:28.188799Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Acquire connection
2024-07-04T10:07:28.188803Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-07-04T10:07:28.188809Z  INFO awscrt::connection-manager: id=0x556c310ea610: Requesting 1 new connections from http
2024-07-04T10:07:28.188813Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: acquiring bootstrap reference
2024-07-04T10:07:28.188816Z DEBUG awscrt::dns: id=0x556c30f903d0: Host resolution requested for 169.254.169.254
2024-07-04T10:07:28.188818Z DEBUG awscrt::dns: id=0x556c30f903d0: No cached entries found for 169.254.169.254 starting new resolver thread.
2024-07-04T10:07:28.188848Z  INFO awscrt::S3Client: id=0x556c310eaf90: Created meta request 0x556c312a42d0
2024-07-04T10:07:28.188872Z DEBUG awscrt::dns: static: resolving host 169.254.169.254
2024-07-04T10:07:28.188879Z DEBUG awscrt::dns: static: resolved record: 169.254.169.254
2024-07-04T10:07:28.188882Z DEBUG awscrt::dns: static, resolving host 169.254.169.254 successful, returned 1 addresses
2024-07-04T10:07:28.188886Z DEBUG awscrt::dns: static: new address resolved 169.254.169.254 for host 169.254.169.254 caching
2024-07-04T10:07:28.188890Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.169.254 with 1 addresses
2024-07-04T10:07:28.189005Z DEBUG awscrt::socket: id=0x7fec7c005d10 fd=8: initializing with domain 0 and type 0
2024-07-04T10:07:28.189014Z DEBUG awscrt::socket: id=0x7fec7c005d10 fd=8: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-07-04T10:07:28.189021Z DEBUG awscrt::socket: id=0x7fec7c005d10 fd=8: beginning connect.
2024-07-04T10:07:28.189024Z DEBUG awscrt::socket: id=0x7fec7c005d10 fd=8: connecting to endpoint 169.254.169.254:80.
2024-07-04T10:07:28.189412Z  INFO awscrt::socket: id=0x7fec7c005d10 fd=8: connection success
2024-07-04T10:07:28.189421Z DEBUG awscrt::socket: id=0x7fec7c005d10 fd=8: assigning to event loop 0x556c30fa56f0
2024-07-04T10:07:28.189426Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: client connection on socket 0x7fec7c005d10 completed with error 0.
2024-07-04T10:07:28.189429Z DEBUG awscrt::channel: id=0x7fec7c0062a0: Beginning creation and setup of new channel.
2024-07-04T10:07:28.189432Z DEBUG awscrt::channel: id=0x7fec7c0062a0: setup complete, notifying caller.
2024-07-04T10:07:28.189435Z DEBUG awscrt::channel: id=0x7fec7c0062a0: no message pool is currently stored in the event-loop local storage, adding 0x7fec7c005f30 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-07-04T10:07:28.189453Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: channel 0x7fec7c0062a0 setup succeeded: bootstrapping.
2024-07-04T10:07:28.189456Z DEBUG awscrt::socket-handler: id=0x7fec7c016c50: Socket handler created with max_read_size of 16384
2024-07-04T10:07:28.189463Z  INFO awscrt::http-connection: id=0x7fec7c016e40: HTTP/1.1 client connection established.
2024-07-04T10:07:28.189466Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Received new connection (id=0x7fec7c016e40) from http layer
2024-07-04T10:07:28.189469Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Grabbing pooled connection (0x7fec7c016e40)
2024-07-04T10:07:28.189472Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.189475Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Successfully completed connection acquisition with connection id=0x7fec7c016e40
2024-07-04T10:07:28.189484Z DEBUG awscrt::http-stream: id=0x7fec7c017390: Created client request on connection=0x7fec7c016e40: PUT /latest/api/token HTTP/1.1
2024-07-04T10:07:28.189731Z DEBUG awscrt::Unknown: (id=0x556c310e8110) IMDS client query received http status code 404 for requester 0x7fec7c003c40.
2024-07-04T10:07:28.189741Z DEBUG awscrt::http-stream: id=0x7fec7c017390: Client request complete, response status: 404 (Not Found).
2024-07-04T10:07:28.189758Z DEBUG awscrt::connection-manager: id=0x556c310ea610: User releasing connection (id=0x7fec7c016e40)
2024-07-04T10:07:28.189762Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.189766Z DEBUG awscrt::Unknown: (id=0x556c310e8110) IMDS client failed to fetch token for requester 0x7fec7c003c40, fall back to v1 for the same requester. Received response status code: 404
2024-07-04T10:07:28.189769Z DEBUG awscrt::Unknown: (id=0x556c310e8110) IMDS client failed to fetch token, fallback to v1. requester 0x7fec7c0032d0.
2024-07-04T10:07:28.189771Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Initializing retry token 0x7fec7c017a50
2024-07-04T10:07:28.189775Z ERROR awscrt::Unknown: (id=0x556c310e8110) IMDS client failed to update the token from IMDS.
2024-07-04T10:07:28.189781Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Vending retry_token 0x7fec7c017a50
2024-07-04T10:07:28.189783Z DEBUG awscrt::Unknown: id=0x556c310e8110: IMDS Client successfully acquired retry token.
2024-07-04T10:07:28.189786Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Acquire connection
2024-07-04T10:07:28.189788Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Grabbing pooled connection (0x7fec7c016e40)
2024-07-04T10:07:28.189791Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.189795Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Successfully completed connection acquisition with connection id=0x7fec7c016e40
2024-07-04T10:07:28.189804Z DEBUG awscrt::http-stream: id=0x7fec7c003ec0: Created client request on connection=0x7fec7c016e40: GET /latest/meta-data/iam/security-credentials/ HTTP/1.1
2024-07-04T10:07:28.190067Z DEBUG awscrt::Unknown: (id=0x556c310e8110) IMDS client query received http status code 404 for requester 0x7fec7c0032d0.
2024-07-04T10:07:28.190080Z DEBUG awscrt::http-stream: id=0x7fec7c003ec0: Client request complete, response status: 404 (Not Found).
2024-07-04T10:07:28.190087Z DEBUG awscrt::connection-manager: id=0x556c310ea610: User releasing connection (id=0x7fec7c016e40)
2024-07-04T10:07:28.190094Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.190106Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Initializing retry token 0x7fec7c004400
2024-07-04T10:07:28.190121Z DEBUG awscrt::exp-backoff-strategy: id=0x556c310ea9e0: Vending retry_token 0x7fec7c004400
2024-07-04T10:07:28.190126Z DEBUG awscrt::Unknown: id=0x556c310e8110: IMDS Client successfully acquired retry token.
2024-07-04T10:07:28.190130Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Acquire connection
2024-07-04T10:07:28.190134Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Grabbing pooled connection (0x7fec7c016e40)
2024-07-04T10:07:28.190139Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.190144Z DEBUG awscrt::connection-manager: id=0x556c310ea610: Successfully completed connection acquisition with connection id=0x7fec7c016e40
2024-07-04T10:07:28.190151Z ERROR awscrt::http-stream: id=static: Request path is invalid
2024-07-04T10:07:28.190156Z ERROR awscrt::http-connection: id=0x7fec7c016e40: Cannot create request stream, error 2054 (AWS_ERROR_HTTP_INVALID_PATH)
2024-07-04T10:07:28.190167Z  INFO awscrt::AuthCredentialsProvider: id=0x556c310e6220: IMDS provider failed to retrieve credentials: Path is invalid.
2024-07-04T10:07:28.190172Z  INFO awscrt::AuthCredentialsProvider: (id=0x556c310e8220) Credentials provider chain callback terminating on index 3, with invalid credentials and error code 2054
2024-07-04T10:07:28.190176Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310ea550) Cached credentials provider next refresh time set to 246017484181570
2024-07-04T10:07:28.190181Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310ea550) Cached credentials provider was unable to source credentials on refresh
2024-07-04T10:07:28.190185Z DEBUG awscrt::AuthCredentialsProvider: (id=0x556c310ea550) Cached credentials provider notifying pending queries of new credentials
2024-07-04T10:07:28.190190Z ERROR awscrt::AuthCredentialsProvider: (id=0x556c30f9c930) Default chain credentials provider failed to source credentials with error 2054(aws-c-http: AWS_ERROR_HTTP_INVALID_PATH, Path is invalid.)
2024-07-04T10:07:28.190196Z ERROR awscrt::AuthSigning: (id=0x7fec88001060) Credentials Provider failed to source credentials with error 2054(aws-c-http: AWS_ERROR_HTTP_INVALID_PATH, Path is invalid.)
2024-07-04T10:07:28.190201Z ERROR awscrt::S3MetaRequest: id=0x556c312a42d0 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)
2024-07-04T10:07:28.190206Z ERROR awscrt::S3MetaRequest: id=0x556c312a42d0 Could not prepare request 0x7fec7c0010c0 due to error 6146 (Attempt to sign an http request without credentials).
2024-07-04T10:07:28.190234Z DEBUG awscrt::connection-manager: id=0x556c310ea610: User releasing connection (id=0x7fec7c016e40)
2024-07-04T10:07:28.190243Z DEBUG awscrt::connection-manager: id=0x556c310ea610: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-04T10:07:28.190250Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190255Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190260Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190266Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190274Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-04T10:07:28.190296Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=Default crt_error=None range=None duration=1.562361ms ttfb=None request_id=<unknown>
2024-07-04T10:07:28.190360Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190365Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190378Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190382Z DEBUG awscrt::S3MetaRequest: id=0x556c312a42d0 Meta request finished with error code 6146 (Attempt to sign an http request without credentials)
2024-07-04T10:07:28.190399Z  WARN list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: duration=1.874018ms request_id=<unknown> error=ClientError(NoSigningCredentials) meta request failed
2024-07-04T10:07:28.190432Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 0, crt_error: Error(6146, "aws-c-auth: AWS_AUTH_SIGNING_NO_CREDENTIALS, Attempt to sign an http request without credentials"), error_response_headers: None, error_response_body: None }
2024-07-04T10:07:28.190456Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190461Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-04T10:07:28.190483Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190495Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190500Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190505Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190512Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-04T10:07:28.190521Z DEBUG awscrt::S3MetaRequest: id=0x556c312a42d0 Cleaning up meta request
2024-07-04T10:07:28.190533Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client starting destruction.
2024-07-04T10:07:28.190582Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190598Z  INFO awscrt::connection-manager: id=0x556c312b1140: release
2024-07-04T10:07:28.190604Z  INFO awscrt::connection-manager: id=0x556c312b1140: ref count now zero, starting shut down process
2024-07-04T10:07:28.190609Z  INFO awscrt::connection-manager: id=0x556c312b1140: manager release, failing 0 pending acquisitions
2024-07-04T10:07:28.190607Z  INFO awscrt::event-loop: id=0x556c3109a500: Destroying event_loop
2024-07-04T10:07:28.190616Z DEBUG awscrt::connection-manager: id=0x556c312b1140: snapshot - state=2, 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=0
2024-07-04T10:07:28.190619Z  INFO awscrt::event-loop: id=0x556c3109a500: Stopping event-loop thread.
2024-07-04T10:07:28.190622Z  INFO awscrt::connection-manager: id=0x556c312b1140: Destroying self
2024-07-04T10:07:28.190626Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: releasing bootstrap reference
2024-07-04T10:07:28.190632Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190637Z DEBUG awscrt::event-loop: id=0x556c3109a500: exiting main loop
2024-07-04T10:07:28.190637Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190643Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190647Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-04T10:07:28.190650Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=1  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-07-04T10:07:28.190658Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190661Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190663Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190665Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190669Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-04T10:07:28.190672Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client body streaming ELG shutdown.
2024-07-04T10:07:28.190676Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-07-04T10:07:28.190690Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: releasing bootstrap reference
2024-07-04T10:07:28.190710Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-04T10:07:28.190715Z DEBUG awscrt::S3Client: id=0x556c310eaf90 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-04T10:07:28.190718Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating meta requests.
2024-07-04T10:07:28.190723Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Updating connections, assigning requests where possible.
2024-07-04T10:07:28.190730Z  INFO awscrt::S3ClientStats: id=0x556c310eaf90 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-04T10:07:28.190736Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=0  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=1
2024-07-04T10:07:28.190740Z DEBUG awscrt::S3Client: id=0x556c310eaf90 Client finishing destruction.
2024-07-04T10:07:28.191508Z  INFO mountpoint_s3::metrics: process.memory_usage: 12611584
2024-07-04T10:07:28.191516Z DEBUG awscrt::channel-bootstrap: id=0x556c30fa9140: releasing bootstrap reference
2024-07-04T10:07:28.191522Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.mem_limit: 2013265920
2024-07-04T10:07:28.191530Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_allocated: 0
2024-07-04T10:07:28.191531Z  INFO awscrt::connection-manager: id=0x556c310e9d70: release
2024-07-04T10:07:28.191533Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_cutoff: 33554432
2024-07-04T10:07:28.191535Z  INFO awscrt::connection-manager: id=0x556c310e9d70: ref count now zero, starting shut down process
2024-07-04T10:07:28.191536Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_num_blocks: 0
2024-07-04T10:07:28.191538Z  INFO awscrt::connection-manager: id=0x556c310e9d70: manager release, failing 0 pending acquisitions
2024-07-04T10:07:28.191539Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_reserved: 0
2024-07-04T10:07:28.191542Z DEBUG awscrt::connection-manager: id=0x556c310e9d70: snapshot - state=2, 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=0
2024-07-04T10:07:28.191542Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_used: 0
2024-07-04T10:07:28.191545Z  INFO awscrt::connection-manager: id=0x556c310e9d70: Destroying self
2024-07-04T10:07:28.191551Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_reserved: 0
2024-07-04T10:07:28.191554Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_used: 0
2024-07-04T10:07:28.191557Z  INFO mountpoint_s3::metrics: s3.client.host_count[host=my-bucket-in-987654321098-account.s3.us-east-1.amazonaws.com]: 0
2024-07-04T10:07:28.191560Z  INFO mountpoint_s3::metrics: s3.client.num_auto_default_network_io: 0
2024-07-04T10:07:28.191562Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_copy_network_io: 0
2024-07-04T10:07:28.191565Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_get_network_io: 0
2024-07-04T10:07:28.191568Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_put_network_io: 0
2024-07-04T10:07:28.191571Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_prepared: 1
2024-07-04T10:07:28.191573Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_processed: 1
2024-07-04T10:07:28.191576Z  INFO mountpoint_s3::metrics: s3.client.num_requests_stream_queued_waiting: 0
2024-07-04T10:07:28.191578Z  INFO mountpoint_s3::metrics: s3.client.num_requests_streaming_response: 0
2024-07-04T10:07:28.191581Z  INFO mountpoint_s3::metrics: s3.client.num_total_network_io: 0
2024-07-04T10:07:28.191583Z  INFO mountpoint_s3::metrics: s3.client.request_queue_size: 0
2024-07-04T10:07:28.191585Z  INFO mountpoint_s3::metrics: s3.meta_requests.failures[op=list_objects,status=-6146]: 1
2024-07-04T10:07:28.191588Z  INFO mountpoint_s3::metrics: s3.meta_requests.first_byte_latency_us[op=list_objects]: n=1: min=1872 p10=1879 p50=1879 avg=1876.00 p90=1879 p99=1879 p99.9=1879 max=1879
2024-07-04T10:07:28.191590Z  INFO mountpoint_s3::metrics: s3.meta_requests.total_latency_us[op=list_objects]: n=1: min=1872 p10=1879 p50=1879 avg=1876.00 p90=1879 p99=1879 p99.9=1879 max=1879
2024-07-04T10:07:28.191593Z  INFO mountpoint_s3::metrics: s3.meta_requests[op=list_objects]: 1
2024-07-04T10:07:28.191596Z  INFO mountpoint_s3::metrics: s3.requests.failures[op=list_objects,type=Default,status=-1]: 1
2024-07-04T10:07:28.191598Z  INFO mountpoint_s3::metrics: s3.requests.total_latency_us[op=list_objects,type=Default]: n=1: min=1560 p10=1567 p50=1567 avg=1564.00 p90=1567 p99=1567 p99.9=1567 max=1567
2024-07-04T10:07:28.191601Z  INFO mountpoint_s3::metrics: s3.requests[op=list_objects,type=Default]: 1
2024-07-04T10:07:28.191604Z  INFO mountpoint_s3::metrics: system.available_memory: 1603567616
arsh commented 2 months ago

In that log, I see the following

2024-07-04T10:07:28.181287Z ERROR awscrt::AuthCredentialsProvider: Failed to resolve credentials_process command during process credentials provider initialization.

Can you make sure that aws_signing_helper is executable and perhaps change the aws config to (note the ./aws_signing_helper).

[profile default]
credential_process = ./aws_signing_helper credential-process --certificate /path/to/cert/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:region:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:region:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/my-role-name

Also from the logs, it looks like it is falling back to IMDS, presumably due to the above failure.

2024-07-04T10:07:28.181296Z  INFO awscrt::AuthCredentialsProvider: default chain: IMDS credentials provider will be used to retrieve credentials
sdauhuchytsrf commented 2 months ago

@arsh aws_signing_helper binary is situated in /usr/local/bin/ and it's executable:

ll /usr/local/bin/
total 57012
drwxr-xr-x  2 root root     4096 Jul  4 08:24 ./
drwxr-xr-x 11 root root     4096 May  8 10:09 ../
-rwxr-xr-x  1 root root 13400616 Oct 12  2023 aws_signing_helper*

Edited ~/.aws/config credential process to ./aws_signing_helper. Still the same error.

Also tried to use absolute path /usr/local/bin/aws_signing_helper. The result is still the same.

arsh commented 2 months ago

OK. I'm going to try to reproduce this and report back any findings.

arsh commented 2 months ago

I was able to reproduce this and I will be talking to the CRT team to understand what is happening. In the meantime, can you try using the profile which declares the credential_process property (in your case the default profile)? When I did this, I did not see the problem. I suspect the problem is when using source_profile (need confirmation from CRT).

arsh commented 2 months ago

Actually, can you try the following. Basically, not using source_profile.

[profile default]
credential_process = aws_signing_helper credential-process --certificate /path/to/cert/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:region:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:region:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/my-role-name

[profile test]
credential_process = aws_signing_helper credential-process --certificate /path/to/cert/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:region:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:region:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/my-role-name
role_arn=arn:aws:iam::987654321098:role/another-role-name
region = eu-central-1
output = json
sdauhuchytsrf commented 2 months ago

Hi @arsh. Thanks for your fast response!

I applied the configuration above and get the following error while trying to do aws sts get-caller-identity:

aws sts get-caller-identity --profile test

Partial credentials found in assume-role, missing: source_profile or credential_source
arsh commented 2 months ago

Yes, I see that error when using the CLI. However, I do not see that when using Mountpoint. It is likely that Mountpoint (and CRT) isn't doing the right thing is this case (will need to check if it is actually assuming the role).

Can you try the same setting using Mountpoint ?

sdauhuchytsrf commented 2 months ago

Unfortunately I still see the same error:

AWS_PROFILE=test AWS_REGION=eu-central-1 mount-s3 my-bucket-in-987654321098-account test
Error: Failed to create S3 client

Caused by:
    0: initial ListObjectsV2 failed for bucket my-bucket-in-987654321098-account in region eu-central-1
    1: Client error
    2: Forbidden: Access Denied
Error: Failed to create mount process
[default]
credential_process = /usr/local/bin/aws_signing_helper credential-process --certificate /path/to/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:eu-central-1:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:eu-central-1:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/transit-role

[profile test]
credential_process = /usr/local/bin/aws_signing_helper credential-process --certificate /path/to/cert.crt --private-key /path/to/private.key --trust-anchor-arn arn:aws:rolesanywhere:eu-central-1:123456789012:trust-anchor/uuid --profile-arn arn:aws:rolesanywhere:eu-central-1:123456789012:profile/uuid --role-arn arn:aws:iam::123456789012:role/transit-role
role_arn=arn:aws:iam::987654321098:role/target-role
region = eu-central-1
output = json
arsh commented 2 months ago

Can you also provide the logs of that last run?

sdauhuchytsrf commented 2 months ago

Here they are:

2024-07-05T12:02:31.382015Z DEBUG mountpoint_s3::cli: waiting up to 30 seconds for child process to be ready
2024-07-05T12:02:31.382672Z  INFO mountpoint_s3::cli: mount-s3 1.7.2
2024-07-05T12:02:31.382685Z DEBUG mountpoint_s3::cli: CliArgs { bucket_name: "my-bucket-in-987654321098-account", mount_point: "test", prefix: None, region: None, endpoint_url: None, force_path_style: false, transfer_acceleration: false, dual_stack: false, requester_pays: false, bucket_type: None, no_sign_request: false, profile: None, read_only: false, storage_class: None, allow_delete: false, allow_overwrite: false, auto_unmount: false, allow_root: false, allow_other: false, maximum_throughput_gbps: None, max_threads: 16, part_size: 8388608, uid: None, gid: None, dir_mode: None, file_mode: None, foreground: false, expected_bucket_owner: None, log_directory: Some("mount-s3-logs/"), log_metrics: false, debug: true, debug_crt: true, no_log: false, cache: None, metadata_ttl: None, max_cache_size: None, user_agent_prefix: None, sse: None, sse_kms_key_id: None, upload_checksums: None }
2024-07-05T12:02:31.382983Z DEBUG awscrt::libcrypto_resolve: searching process and loaded modules
2024-07-05T12:02:31.382995Z DEBUG awscrt::libcrypto_resolve: found static aws-lc HMAC symbols
2024-07-05T12:02:31.383005Z DEBUG awscrt::libcrypto_resolve: found static aws-lc libcrypto 1.1.1 EVP_MD symbols
2024-07-05T12:02:31.383018Z  INFO awscrt::tls-handler: static: Initializing TLS using s2n.
2024-07-05T12:02:31.383257Z DEBUG awscrt::tls-handler: ctx: Based on OS, we detected the default PKI path as /etc/ssl/certs, and ca file as /etc/ssl/certs/ca-certificates.crt
2024-07-05T12:02:31.383290Z  INFO awscrt::event-loop: id=0x5638ff0703d0: Initializing edge-triggered epoll
2024-07-05T12:02:31.383302Z  INFO awscrt::event-loop: id=0x5638ff0703d0: Using eventfd for cross-thread notifications.
2024-07-05T12:02:31.383311Z  INFO awscrt::event-loop: id=0x5638ff0703d0: Starting event-loop thread.
2024-07-05T12:02:31.383358Z  INFO awscrt::dns: id=0x5638ff050050: Initializing default host resolver with 8 max host entries.
2024-07-05T12:02:31.383370Z  INFO awscrt::channel-bootstrap: id=0x5638ff06c9b0: Initializing client bootstrap with event-loop group 0x5638ff052980
2024-07-05T12:02:31.383393Z  INFO awscrt::event-loop: id=0x5638ff0703d0: main loop started
2024-07-05T12:02:31.383406Z  INFO awscrt::event-loop: id=0x5638ff0703d0: default timeout 100000, and max events to process per tick 100
2024-07-05T12:02:31.383450Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: acquiring bootstrap reference
2024-07-05T12:02:31.383459Z  INFO awscrt::connection-manager: id=0x5638ff055180: Successfully created
2024-07-05T12:02:31.383466Z  INFO awscrt::exp-backoff-strategy: id=0x5638ff055bb0: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-07-05T12:02:31.383471Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: releasing bootstrap reference
2024-07-05T12:02:31.383479Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff055bb0: Initializing retry token 0x5638ff07d9c0
2024-07-05T12:02:31.383504Z DEBUG awscrt::Unknown: (id=0x5638ff072aa0) IMDS client's token is invalid and is now updating.
2024-07-05T12:02:31.383520Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff055bb0: Vending retry_token 0x5638ff07d9c0
2024-07-05T12:02:31.383528Z DEBUG awscrt::Unknown: id=0x5638ff072aa0: IMDS Client successfully acquired retry token.
2024-07-05T12:02:31.383536Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Acquire connection
2024-07-05T12:02:31.383544Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-07-05T12:02:31.383551Z  INFO awscrt::connection-manager: id=0x5638ff055180: Requesting 1 new connections from http
2024-07-05T12:02:31.383557Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: acquiring bootstrap reference
2024-07-05T12:02:31.383569Z DEBUG awscrt::dns: id=0x5638ff050050: Host resolution requested for 169.254.169.254
2024-07-05T12:02:31.383575Z DEBUG awscrt::dns: id=0x5638ff050050: No cached entries found for 169.254.169.254 starting new resolver thread.
2024-07-05T12:02:31.383679Z DEBUG awscrt::dns: static: resolving host 169.254.169.254
2024-07-05T12:02:31.383701Z DEBUG awscrt::dns: static: resolved record: 169.254.169.254
2024-07-05T12:02:31.383709Z DEBUG awscrt::dns: static, resolving host 169.254.169.254 successful, returned 1 addresses
2024-07-05T12:02:31.383716Z DEBUG awscrt::dns: static: new address resolved 169.254.169.254 for host 169.254.169.254 caching
2024-07-05T12:02:31.383724Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.169.254 with 1 addresses
2024-07-05T12:02:31.383780Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: initializing with domain 0 and type 0
2024-07-05T12:02:31.383792Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-07-05T12:02:31.383799Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: beginning connect.
2024-07-05T12:02:31.383805Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: connecting to endpoint 169.254.169.254:80.
2024-07-05T12:02:31.385461Z  INFO awscrt::socket: id=0x7fac88002b00 fd=10: connection success
2024-07-05T12:02:31.385476Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: assigning to event loop 0x5638ff0703d0
2024-07-05T12:02:31.385481Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: client connection on socket 0x7fac88002b00 completed with error 0.
2024-07-05T12:02:31.385485Z DEBUG awscrt::channel: id=0x7fac88003150: Beginning creation and setup of new channel.
2024-07-05T12:02:31.385488Z DEBUG awscrt::channel: id=0x7fac88003150: setup complete, notifying caller.
2024-07-05T12:02:31.385492Z DEBUG awscrt::channel: id=0x7fac88003150: no message pool is currently stored in the event-loop local storage, adding 0x7fac88002d80 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-07-05T12:02:31.385499Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: channel 0x7fac88003150 setup succeeded: bootstrapping.
2024-07-05T12:02:31.385503Z DEBUG awscrt::socket-handler: id=0x7fac88013d80: Socket handler created with max_read_size of 16384
2024-07-05T12:02:31.385518Z  INFO awscrt::http-connection: id=0x7fac88013f70: HTTP/1.1 client connection established.
2024-07-05T12:02:31.385522Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Received new connection (id=0x7fac88013f70) from http layer
2024-07-05T12:02:31.385525Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Grabbing pooled connection (0x7fac88013f70)
2024-07-05T12:02:31.385529Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-05T12:02:31.385532Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Successfully completed connection acquisition with connection id=0x7fac88013f70
2024-07-05T12:02:31.385541Z DEBUG awscrt::http-stream: id=0x7fac88014a40: Created client request on connection=0x7fac88013f70: PUT /latest/api/token HTTP/1.1
2024-07-05T12:02:31.385765Z DEBUG awscrt::Unknown: (id=0x5638ff072aa0) IMDS client query received http status code 404 for requester 0x5638ff05cb50.
2024-07-05T12:02:31.385778Z DEBUG awscrt::http-stream: id=0x7fac88014a40: Client request complete, response status: 404 (Not Found).
2024-07-05T12:02:31.385783Z DEBUG awscrt::connection-manager: id=0x5638ff055180: User releasing connection (id=0x7fac88013f70)
2024-07-05T12:02:31.385792Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-05T12:02:31.385802Z DEBUG awscrt::Unknown: (id=0x5638ff072aa0) IMDS client failed to fetch token for requester 0x5638ff05cb50, fall back to v1 for the same requester. Received response status code: 404
2024-07-05T12:02:31.385805Z DEBUG awscrt::Unknown: (id=0x5638ff072aa0) IMDS client failed to fetch token, fallback to v1. requester 0x5638ff061090.
2024-07-05T12:02:31.385808Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff055bb0: Initializing retry token 0x7fac880151b0
2024-07-05T12:02:31.385813Z ERROR awscrt::Unknown: (id=0x5638ff072aa0) IMDS client failed to update the token from IMDS.
2024-07-05T12:02:31.385819Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff055bb0: Vending retry_token 0x7fac880151b0
2024-07-05T12:02:31.385822Z DEBUG awscrt::Unknown: id=0x5638ff072aa0: IMDS Client successfully acquired retry token.
2024-07-05T12:02:31.385824Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Acquire connection
2024-07-05T12:02:31.385827Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Grabbing pooled connection (0x7fac88013f70)
2024-07-05T12:02:31.385830Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-05T12:02:31.385833Z DEBUG awscrt::connection-manager: id=0x5638ff055180: Successfully completed connection acquisition with connection id=0x7fac88013f70
2024-07-05T12:02:31.385841Z DEBUG awscrt::http-stream: id=0x7fac88015570: Created client request on connection=0x7fac88013f70: GET /latest/dynamic/instance-identity/document HTTP/1.1
2024-07-05T12:02:31.385991Z DEBUG awscrt::Unknown: (id=0x5638ff072aa0) IMDS client query received http status code 404 for requester 0x5638ff061090.
2024-07-05T12:02:31.386001Z DEBUG awscrt::http-stream: id=0x7fac88015570: Client request complete, response status: 404 (Not Found).
2024-07-05T12:02:31.386004Z DEBUG awscrt::connection-manager: id=0x5638ff055180: User releasing connection (id=0x7fac88013f70)
2024-07-05T12:02:31.386008Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=1
2024-07-05T12:02:31.386045Z  INFO awscrt::connection-manager: id=0x5638ff055180: release
2024-07-05T12:02:31.386057Z  INFO awscrt::connection-manager: id=0x5638ff055180: ref count now zero, starting shut down process
2024-07-05T12:02:31.386062Z  INFO awscrt::connection-manager: id=0x5638ff055180: manager release, failing 0 pending acquisitions
2024-07-05T12:02:31.386069Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=2, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=1, ref_count=0
2024-07-05T12:02:31.386073Z  INFO awscrt::connection-manager: id=0x5638ff055180: Releasing connection (id=0x7fac88013f70)
2024-07-05T12:02:31.386087Z DEBUG mountpoint_s3_client::instance_info: EC2 instance info not retrieved: ImdsQueryFailed(InvalidResponse("Not Found"))
2024-07-05T12:02:31.386096Z  WARN mountpoint_s3::cli: failed to detect network throughput. Using 10 gbps as throughput. Use --maximum-throughput-gbps CLI flag to configure a target throughput appropriate for the instance. Detection failed due to: failed to get instance type: IMDS query failed: Invalid response from Imds: Not Found
2024-07-05T12:02:31.386102Z  INFO mountpoint_s3::cli: target network throughput 10 Gbps
2024-07-05T12:02:31.386104Z DEBUG awscrt::channel: id=0x7fac88003150: beginning shutdown process
2024-07-05T12:02:31.386113Z DEBUG awscrt::channel: id=0x7fac88003150: handler 0x7fac88013d80 shutdown in read dir completed.
2024-07-05T12:02:31.386114Z DEBUG mountpoint_s3::cli: using AWS_REGION: eu-central-1
2024-07-05T12:02:31.386116Z DEBUG awscrt::channel: id=0x7fac88003150: handler 0x7fac88013f78 shutdown in read dir completed.
2024-07-05T12:02:31.386128Z DEBUG awscrt::channel: id=0x7fac88003150: handler 0x7fac88013f78 shutdown in write dir completed.
2024-07-05T12:02:31.386131Z DEBUG awscrt::socket: id=0x7fac88002b00 fd=10: closing
2024-07-05T12:02:31.386147Z  INFO awscrt::event-loop: id=0x5638ff061ab0: Initializing edge-triggered epoll
2024-07-05T12:02:31.386157Z  INFO awscrt::event-loop: id=0x5638ff061ab0: Using eventfd for cross-thread notifications.
2024-07-05T12:02:31.386162Z DEBUG awscrt::channel: id=0x7fac88003150: handler 0x7fac88013d80 shutdown in write dir completed.
2024-07-05T12:02:31.386165Z  INFO awscrt::event-loop: id=0x5638ff061ab0: Starting event-loop thread.
2024-07-05T12:02:31.386172Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: channel 0x7fac88003150 shutdown with error 0.
2024-07-05T12:02:31.386178Z  INFO awscrt::http-connection: 0x7fac88013f70: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).
2024-07-05T12:02:31.386183Z DEBUG awscrt::connection-manager: id=0x5638ff055180: shutdown received for connection (id=0x7fac88013f70)
2024-07-05T12:02:31.386187Z  INFO awscrt::connection-manager: id=0x5638ff055180: manager release, failing 0 pending acquisitions
2024-07-05T12:02:31.386191Z DEBUG awscrt::connection-manager: id=0x5638ff055180: snapshot - state=2, 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=0
2024-07-05T12:02:31.386194Z  INFO awscrt::connection-manager: id=0x5638ff055180: Destroying self
2024-07-05T12:02:31.386196Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: releasing bootstrap reference
2024-07-05T12:02:31.386199Z DEBUG awscrt::channel: id=0x7fac88003150: destroying channel.
2024-07-05T12:02:31.386202Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: releasing bootstrap reference
2024-07-05T12:02:31.386204Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06c9b0: bootstrap destroying
2024-07-05T12:02:31.386223Z  INFO awscrt::dns: id=0x5638ff04fc40: Initializing default host resolver with 8 max host entries.
2024-07-05T12:02:31.386234Z  INFO awscrt::channel-bootstrap: id=0x5638ff06bc50: Initializing client bootstrap with event-loop group 0x5638ff055330
2024-07-05T12:02:31.386241Z  INFO awscrt::standard-retry-strategy: static: creating new standard retry strategy
2024-07-05T12:02:31.386246Z  INFO awscrt::standard-retry-strategy: id=0x5638ff065cf0: creating backing exponential backoff strategy with max_retries of 9
2024-07-05T12:02:31.386253Z  INFO awscrt::exp-backoff-strategy: id=0x5638ff0658c0: Initializing exponential backoff retry strategy with scale factor: 500 jitter mode: 2 and max retries 9
2024-07-05T12:02:31.386259Z DEBUG awscrt::standard-retry-strategy: id=0x5638ff065cf0: maximum bucket capacity set to 500
2024-07-05T12:02:31.386262Z DEBUG awscrt::dns: static: Either no requests have been made for an address for 169.254.169.254 for the duration of the ttl, or this thread is being forcibly shutdown. Killing thread.
2024-07-05T12:02:31.386270Z  INFO awscrt::AuthCredentialsProvider: (id=0x5638ff061b00): TLS context not provided, initializing a new one for credentials provider.
2024-07-05T12:02:31.386273Z DEBUG awscrt::dns: static: purging address 169.254.169.254 for host 169.254.169.254 from the cache due to cache eviction or shutdown
2024-07-05T12:02:31.386355Z  INFO awscrt::event-loop: id=0x5638ff061ab0: main loop started
2024-07-05T12:02:31.386365Z  INFO awscrt::event-loop: id=0x5638ff061ab0: default timeout 100000, and max events to process per tick 100
2024-07-05T12:02:31.386388Z  INFO awscrt::event-loop: id=0x5638ff0703d0: Destroying event_loop
2024-07-05T12:02:31.386393Z  INFO awscrt::event-loop: id=0x5638ff0703d0: Stopping event-loop thread.
2024-07-05T12:02:31.386406Z DEBUG awscrt::event-loop: id=0x5638ff0703d0: exiting main loop
2024-07-05T12:02:31.394210Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-05T12:02:31.394264Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/credentials"
2024-07-05T12:02:31.394278Z ERROR awscrt::common-io: static: Failed to open file. path:'/home/admin/.aws/credentials' mode:'rb' errno:2 aws-error:44(AWS_ERROR_FILE_INVALID_PATH)
2024-07-05T12:02:31.394284Z DEBUG awscrt::AWSProfile: Failed to read file at "/home/admin/.aws/credentials"
2024-07-05T12:02:31.394292Z DEBUG awscrt::AWSProfile: property "credential_process" has value "" replaced during merge
2024-07-05T12:02:31.394298Z DEBUG awscrt::AWSProfile: property "output" has value "" replaced during merge
2024-07-05T12:02:31.394304Z DEBUG awscrt::AWSProfile: property "region" has value "" replaced during merge
2024-07-05T12:02:31.394309Z DEBUG awscrt::AWSProfile: property "credential_process" has value "" replaced during merge
2024-07-05T12:02:31.394315Z DEBUG awscrt::AWSProfile: property "role_arn" has value "" replaced during merge
2024-07-05T12:02:31.394327Z  INFO awscrt::AuthCredentialsProvider: static: profile test has role_arn property is set to arn:aws:iam::987654321098:role/target-role, attempting to create an STS credentials provider.
2024-07-05T12:02:31.394334Z DEBUG awscrt::AuthCredentialsProvider: static: computed session_name as aws-common-runtime-profile-config-11962
2024-07-05T12:02:31.394345Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-05T12:02:31.394376Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-07-05T12:02:31.394386Z ERROR awscrt::AuthCredentialsProvider: Failed to resolve token file path during sts web identity provider initialization.
2024-07-05T12:02:31.394394Z DEBUG awscrt::AWSProfile: Creating profile collection from file at "/home/admin/.aws/config"
2024-07-05T12:02:31.394417Z DEBUG awscrt::AuthCredentialsProvider: Successfully built config profile collection from file at (/home/admin/.aws/config)
2024-07-05T12:02:31.394423Z DEBUG awscrt::AuthCredentialsProvider: Successfully loaded credentials_process command for process credentials provider.
2024-07-05T12:02:31.394430Z  INFO awscrt::AuthCredentialsProvider: ECS provider: Unable to initialize from environment because AWS_CONTAINER_CREDENTIALS_FULL_URI and AWS_CONTAINER_CREDENTIALS_RELATIVE_URI are not set.
2024-07-05T12:02:31.394435Z  INFO awscrt::AuthCredentialsProvider: default chain: IMDS credentials provider will be used to retrieve credentials
2024-07-05T12:02:31.394441Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: acquiring bootstrap reference
2024-07-05T12:02:31.394446Z  INFO awscrt::connection-manager: id=0x5638ff1a8240: Successfully created
2024-07-05T12:02:31.394452Z  INFO awscrt::exp-backoff-strategy: id=0x5638ff1a8450: Initializing exponential backoff retry strategy with scale factor: 0 jitter mode: 0 and max retries 1
2024-07-05T12:02:31.395637Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: acquiring bootstrap reference
2024-07-05T12:02:31.402907Z  INFO awscrt::event-loop: id=0x5638ff0efea0: Initializing edge-triggered epoll
2024-07-05T12:02:31.402927Z  INFO awscrt::event-loop: id=0x5638ff0efea0: Using eventfd for cross-thread notifications.
2024-07-05T12:02:31.402938Z  INFO awscrt::event-loop: id=0x5638ff0efea0: Starting event-loop thread.
2024-07-05T12:02:31.403031Z  INFO awscrt::event-loop: id=0x5638ff0efea0: main loop started
2024-07-05T12:02:31.403050Z  INFO awscrt::event-loop: id=0x5638ff0efea0: default timeout 100000, and max events to process per tick 100
2024-07-05T12:02:31.404999Z DEBUG awscrt::AWSEndpointsResolution: Resolved endpoint with status 0
2024-07-05T12:02:31.405049Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client::list_objects: new request
2024-07-05T12:02:31.405067Z  INFO awscrt::S3Client: id=0x5638ff0d8e20 Initiating making of meta request
2024-07-05T12:02:31.405079Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0 Created new Default Meta Request. operation=?
2024-07-05T12:02:31.405083Z DEBUG awscrt::dns: id=0x5638ff04fc40: Host resolution requested for my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
2024-07-05T12:02:31.405087Z DEBUG awscrt::dns: id=0x5638ff04fc40: No cached entries found for my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com starting new resolver thread.
2024-07-05T12:02:31.405137Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: acquiring bootstrap reference
2024-07-05T12:02:31.405141Z  INFO awscrt::connection-manager: id=0x5638ff296a00: Successfully created
2024-07-05T12:02:31.405144Z DEBUG awscrt::S3Endpoint: id=0x5638ff28a060: Created connection manager 0x5638ff296a00 for endpoint
2024-07-05T12:02:31.405152Z  INFO awscrt::S3Client: id=0x5638ff0d8e20: Created meta request 0x5638ff289bf0
2024-07-05T12:02:31.405171Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.405183Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.405185Z DEBUG awscrt::dns: static: resolving host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
2024-07-05T12:02:31.405187Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.405194Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0: Meta Request Default created request 0x7fac8c001990
2024-07-05T12:02:31.405208Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.405213Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):1/1  Requests-preparing:1  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-05T12:02:31.405233Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0: Meta Request prepared request 0x7fac8c001990
2024-07-05T12:02:31.405269Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff061b00) Credentials provider chain get credentials dispatch
2024-07-05T12:02:31.405274Z  INFO awscrt::AuthCredentialsProvider: (id=0x5638ff1a8880) Cached credentials provider has expired credentials.  Requerying.
2024-07-05T12:02:31.405286Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a83f0) Credentials provider chain get credentials dispatch
2024-07-05T12:02:31.405291Z  INFO awscrt::AuthCredentialsProvider: id=0x5638ff0654a0: Failed to load credentials from environment variables: Required environment variables could not be sourced from process environment
2024-07-05T12:02:31.405294Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a83f0) Credentials provider chain callback 1 invoked with invalid credentials and error code 6150
2024-07-05T12:02:31.405297Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a83f0) Credentials provider chain invoking chain member #1
2024-07-05T12:02:31.432634Z DEBUG awscrt::dns: static: resolved record: 52.219.171.58
2024-07-05T12:02:31.432658Z DEBUG awscrt::dns: static: resolved record: 3.5.138.115
2024-07-05T12:02:31.432661Z DEBUG awscrt::dns: static: resolved record: 52.219.170.70
2024-07-05T12:02:31.432664Z DEBUG awscrt::dns: static: resolved record: 3.5.135.13
2024-07-05T12:02:31.432667Z DEBUG awscrt::dns: static: resolved record: 52.219.170.138
2024-07-05T12:02:31.432670Z DEBUG awscrt::dns: static: resolved record: 3.5.137.150
2024-07-05T12:02:31.432673Z DEBUG awscrt::dns: static: resolved record: 3.5.136.126
2024-07-05T12:02:31.432676Z DEBUG awscrt::dns: static: resolved record: 52.219.169.130
2024-07-05T12:02:31.432688Z DEBUG awscrt::dns: static, resolving host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com successful, returned 8 addresses
2024-07-05T12:02:31.432694Z DEBUG awscrt::dns: static: new address resolved 52.219.171.58 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432703Z DEBUG awscrt::dns: static: new address resolved 3.5.138.115 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432707Z DEBUG awscrt::dns: static: new address resolved 52.219.170.70 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432746Z DEBUG awscrt::dns: static: new address resolved 3.5.135.13 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432750Z DEBUG awscrt::dns: static: new address resolved 52.219.170.138 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432754Z DEBUG awscrt::dns: static: new address resolved 3.5.137.150 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432757Z DEBUG awscrt::dns: static: new address resolved 3.5.136.126 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432760Z DEBUG awscrt::dns: static: new address resolved 52.219.169.130 for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com caching
2024-07-05T12:02:31.432765Z DEBUG awscrt::dns: static, invoking resolution callback for host my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com with 1 addresses
2024-07-05T12:02:31.633505Z  INFO awscrt::AuthCredentialsProvider: (id=0x5638ff1a51b0) Process credentials provider successfully sourced credentials.
2024-07-05T12:02:31.633533Z  INFO awscrt::AuthCredentialsProvider: (id=0x5638ff1a83f0) Credentials provider chain callback terminating on index 2, with valid credentials and error code 0
2024-07-05T12:02:31.633538Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a8880) Cached credentials provider next refresh time set to 342012289104288
2024-07-05T12:02:31.633541Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a8880) Cached credentials provider succesfully sourced credentials on refresh
2024-07-05T12:02:31.633544Z DEBUG awscrt::AuthCredentialsProvider: (id=0x5638ff1a8880) Cached credentials provider notifying pending queries of new credentials
2024-07-05T12:02:31.633547Z  INFO awscrt::AuthCredentialsProvider: (id=0x5638ff061b00) Default chain credentials provider successfully sourced credentials
2024-07-05T12:02:31.633590Z  INFO awscrt::AuthSigning: (id=0x7fac80000b70) Signing successfully built canonical request for algorithm SigV4, with contents
GET
/
delimiter=&list-type=2&max-keys=0&prefix=
accept:application/xml
content-length:0
host:my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
x-amz-content-sha256:UNSIGNED-PAYLOAD
x-amz-date:20240705T120231Z
x-amz-optional-object-attributes:RestoreStatus
x-amz-security-token:IQoJb3JpZ2luX2VjEAQaDGV1LWNlbnRyYWwtMSJHMEUCIDdU4g1oF6o897aqCHuUuo2s/qyV0yh7TybFN2Y/FXFVAiEAsZOOBlPnAaKZBE2A05axAbUu8+pobkzntZyj9znqZI8qywQIvf//////////ARAFGgwzOTMyNzA3ODkzMjUiDCTKesB78npoScd+zCqfBKkJhLQaleE+e6MDI9+UCzrbEyV0qAExc8HD03Jr3iEf7MIhiWWDbQ2MMnI4th7QsDXeBhlqUhN4SKrntKv0extOtwHFJfjZGS5SRGS19xeOfv9Jb3bjLWETDogZx9QW45TRJrQlDrDWH1r+2sAqa61uyVMHfxU23GtE25WtBnu2NppKKBPNhy2zoG0o90EsV9rZLuObP7oBu8EbUJakEDAoNLE5RNM9ypdQioFI9ol3PKaqjmdboCPspr0qQdNRgTwNiWtkfRX3MRK6B6FLvm8O5Jr4cjHPCMVjCk4HffLf25Q3fcYlG4xhqEzJXDHV1FJDr1n7NrACNfY9WpJ2sGjJmm4vFL6RtkYYpDfJeGVSlNnLqzkZp6oAeihopyTnO9I1G1S86BbnQzLucLAzbiNRMMPgOCDG8mbxor/17Tz4veSHKCsVAxlpvP82+INAK5qL1cs4Y9ehANkv4913dqxDt5gSEtrnKznEYlt4GNty2WlFhCKySb+K3UpxuuF/xOKmQQUZJOT/9zG+uK+9taxtKeNtFdpudI2Arx8XXN/KsscgVnQKoUwvmI5nL4k3G2nOnQ/WnBPXJ6nG7FHEbNPtg2hfBBVR+wHU4bNL+cBMqEE+ZqTI2bq1/gjmnyndtpWKiylpd3qFtnjRnuQFdM2X3hBziKVWxuDElB8RfBg3WUi4hWDd1yNZNz+oEg3kwxHKOk2cYITLU5AHTCmxBTDXwZ+0BjqTAQZlYUY8CJTyyexTLMyCp5s9bT4JMBtwm5dxz3FhXBDr8ZG0wA+pvM+Ck/G/dCiNpI7Pdy3lPelim25Dkfz4ypWlbNwRpimzQYw8y7FEEtyPWevVrQvjcJIBGaZxLepCbqRSYsAsYWtZaVJYBp7GWb7O5OnTNsKntfnX7aS4VSqS9+s7IpSwYKJ1UMyUoZ0hDxKVMw==

accept;content-length;host;x-amz-content-sha256;x-amz-date;x-amz-optional-object-attributes;x-amz-security-token
UNSIGNED-PAYLOAD

2024-07-05T12:02:31.633607Z  INFO awscrt::AuthSigning: (id=0x7fac80000b70) Signing successfully built string-to-sign via algorithm SigV4, with contents
AWS4-HMAC-SHA256
20240705T120231Z
20240705/eu-central-1/s3/aws4_request
1db0972d3ca62c184e0f9bb5d471d724630908eeb264c3757831c970b138cf79

2024-07-05T12:02:31.633620Z  INFO awscrt::AuthSigning: (id=0x7fac80000b70) Http request successfully built final authorization value via algorithm SigV4, with contents
AWS4-HMAC-SHA256 Credential=ASIAVXEGEATGT3MNA34O/20240705/eu-central-1/s3/aws4_request, SignedHeaders=accept;content-length;host;x-amz-content-sha256;x-amz-date;x-amz-optional-object-attributes;x-amz-security-token, Signature=d69647188c94e037b99a76401944672b4414a169eafadadf282f3d06ad0a6dee

2024-07-05T12:02:31.633661Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.633673Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.633681Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.633687Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.633693Z DEBUG awscrt::standard-retry-strategy: id=0x5638ff065cf0: attempting to acquire retry token for partition_id my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
2024-07-05T12:02:31.633698Z DEBUG awscrt::standard-retry-strategy: id=0x5638ff065cf0: bucket for partition_id my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com does not exist, attempting to create one
2024-07-05T12:02:31.633703Z DEBUG awscrt::standard-retry-strategy: id=0x5638ff065cf0: bucket 0x7fac8c002280 for partition_id my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com created
2024-07-05T12:02:31.633706Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff0658c0: Initializing retry token 0x7fac8c002400
2024-07-05T12:02:31.633714Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):1/1  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/1/1  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-05T12:02:31.633718Z DEBUG awscrt::exp-backoff-strategy: id=0x5638ff0658c0: Vending retry_token 0x7fac8c002400
2024-07-05T12:02:31.633722Z DEBUG awscrt::standard-retry-strategy: id=0x5638ff065cf0: token acquired callback invoked with error Success. with token 0x7fac8c002160 and nested token 0x7fac8c002400
2024-07-05T12:02:31.633725Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: Acquire connection
2024-07-05T12:02:31.633730Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=0, open_connection_count=0, ref_count=1
2024-07-05T12:02:31.633735Z  INFO awscrt::connection-manager: id=0x5638ff296a00: Requesting 1 new connections from http
2024-07-05T12:02:31.633742Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: acquiring bootstrap reference
2024-07-05T12:02:31.633746Z DEBUG awscrt::dns: id=0x5638ff04fc40: Host resolution requested for my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
2024-07-05T12:02:31.633750Z DEBUG awscrt::dns: id=0x5638ff04fc40: cached entries found for my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com returning to caller.
2024-07-05T12:02:31.633775Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: initializing with domain 0 and type 0
2024-07-05T12:02:31.633780Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: setting socket options to: keep-alive 0, keep idle 0, keep-alive interval 0, keep-alive probe count 0.
2024-07-05T12:02:31.633784Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: beginning connect.
2024-07-05T12:02:31.633788Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: connecting to endpoint 3.5.138.115:443.
2024-07-05T12:02:31.640798Z  INFO awscrt::socket: id=0x7fac8c002e10 fd=12: connection success
2024-07-05T12:02:31.640812Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: assigning to event loop 0x5638ff061ab0
2024-07-05T12:02:31.640818Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: client connection on socket 0x7fac8c002e10 completed with error 0.
2024-07-05T12:02:31.640822Z DEBUG awscrt::channel: id=0x7fac8c0033c0: Beginning creation and setup of new channel.
2024-07-05T12:02:31.640825Z DEBUG awscrt::channel: id=0x7fac8c0033c0: setup complete, notifying caller.
2024-07-05T12:02:31.640830Z DEBUG awscrt::channel: id=0x7fac8c0033c0: no message pool is currently stored in the event-loop local storage, adding 0x7fac8c003090 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.
2024-07-05T12:02:31.640842Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: channel 0x7fac8c0033c0 setup succeeded: bootstrapping.
2024-07-05T12:02:31.640847Z DEBUG awscrt::socket-handler: id=0x7fac8c013d50: Socket handler created with max_read_size of 16384
2024-07-05T12:02:31.650419Z DEBUG awscrt::tls-handler: id=0x7fac8c013ed0: Remote server name is my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com
2024-07-05T12:02:31.650433Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: tls negotiation result 0 on channel 0x7fac8c0033c0
2024-07-05T12:02:31.650442Z  INFO awscrt::http-connection: id=0x7fac8c017ae0: HTTP/1.1 client connection established.
2024-07-05T12:02:31.650446Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: Received new connection (id=0x7fac8c017ae0) from http layer
2024-07-05T12:02:31.650449Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: Grabbing pooled connection (0x7fac8c017ae0)
2024-07-05T12:02:31.650454Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=1, ref_count=1
2024-07-05T12:02:31.650457Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: Successfully completed connection acquisition with connection id=0x7fac8c017ae0
2024-07-05T12:02:31.650471Z DEBUG awscrt::http-stream: id=0x7fac8c018030: Created client request on connection=0x7fac8c017ae0: GET /?list-type=2&delimiter=&max-keys=0&prefix= HTTP/1.1
2024-07-05T12:02:31.679368Z DEBUG awscrt::http-stream: id=0x7fac8c018030: Client request complete, response status: 403 (Forbidden).
2024-07-05T12:02:31.679399Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0: Request 0x7fac8c001990 finished with error code 14343 (aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request) and response status 403
2024-07-05T12:02:31.679404Z ERROR awscrt::S3MetaRequest: id=0x5638ff289bf0 Meta request cannot recover from error 14343 (Invalid response status from request). (request=0x7fac8c001990, response status=403)
2024-07-05T12:02:31.679410Z  INFO awscrt::http-connection: id=0x7fac8c017ae0: Shutting down connection with error code 0 (AWS_ERROR_SUCCESS).
2024-07-05T12:02:31.679424Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: User releasing connection (id=0x7fac8c017ae0)
2024-07-05T12:02:31.679429Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: 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=1, ref_count=1
2024-07-05T12:02:31.679443Z  INFO awscrt::connection-manager: id=0x5638ff296a00: Releasing connection (id=0x7fac8c017ae0)
2024-07-05T12:02:31.679452Z DEBUG awscrt::channel: id=0x7fac8c0033c0: Channel shutdown is already pending, not scheduling another.
2024-07-05T12:02:31.679460Z DEBUG awscrt::channel: id=0x7fac8c0033c0: beginning shutdown process
2024-07-05T12:02:31.679467Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c013d50 shutdown in read dir completed.
2024-07-05T12:02:31.679473Z DEBUG awscrt::tls-handler: id=0x7fac8c013ed0: Shutting down read direction with error code 0
2024-07-05T12:02:31.679478Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c013ed0 shutdown in read dir completed.
2024-07-05T12:02:31.679483Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c017ae8 shutdown in read dir completed.
2024-07-05T12:02:31.679473Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=Default crt_error=Some(Error(14343, "aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request")) http_status=403 range=None duration=274.18556ms ttfb=Some(28.8389ms) request_id=4PC1466N1G4QTG81
2024-07-05T12:02:31.679488Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.679496Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.679499Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.679504Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.679509Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-05T12:02:31.679513Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c017ae8 shutdown in write dir completed.
2024-07-05T12:02:31.679516Z DEBUG awscrt::tls-handler: id=0x7fac8c013ed0: Scheduling delayed write direction shutdown
2024-07-05T12:02:31.679520Z DEBUG awscrt::tls-handler: id=0x7fac8c013ed0: Delayed shut down in write direction
2024-07-05T12:02:31.679550Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c013ed0 shutdown in write dir completed.
2024-07-05T12:02:31.679555Z DEBUG awscrt::socket: id=0x7fac8c002e10 fd=12: closing
2024-07-05T12:02:31.679600Z DEBUG awscrt::channel: id=0x7fac8c0033c0: handler 0x7fac8c013d50 shutdown in write dir completed.
2024-07-05T12:02:31.679606Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.679609Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.679612Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.679618Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0 Meta request finished with error code 14343 (Invalid response status from request)
2024-07-05T12:02:31.679712Z  WARN list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: duration=274.558441ms request_id=4PC1466N1G4QTG81 error=ClientError(Forbidden("Access Denied")) meta request failed
2024-07-05T12:02:31.679722Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 403, crt_error: Error(14343, "aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request"), error_response_headers: Some(Headers { inner: 0x7fac8c018600 }), error_response_body: Some("<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<Error><Code>AccessDenied</Code><Message>Access Denied</Message><RequestId>4PC1466N1G4QTG81</RequestId><HostId>yUQn6lwUAnmWyuL7jiB7Jw3eTbo9BDpwhieG7G5RLzpb8wdOFByNk/Z0UMk0m55XuSeA/3DY6/TTDnTa1VtMNA==</HostId></Error>") }
2024-07-05T12:02:31.679754Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.679760Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):1/1
2024-07-05T12:02:31.679764Z DEBUG awscrt::channel: id=0x7fac8c0033c0: during shutdown, canceling task 0x7fac8c013f00
2024-07-05T12:02:31.679768Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: channel 0x7fac8c0033c0 shutdown with error 0.
2024-07-05T12:02:31.679771Z  INFO awscrt::http-connection: 0x7fac8c017ae0: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).
2024-07-05T12:02:31.679774Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: shutdown received for connection (id=0x7fac8c017ae0)
2024-07-05T12:02:31.679776Z DEBUG awscrt::S3MetaRequest: id=0x5638ff289bf0 Cleaning up meta request
2024-07-05T12:02:31.679778Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: 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
2024-07-05T12:02:31.679785Z DEBUG awscrt::channel: id=0x7fac8c0033c0: destroying channel.
2024-07-05T12:02:31.679794Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client starting destruction.
2024-07-05T12:02:31.679842Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: releasing bootstrap reference
2024-07-05T12:02:31.679852Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: releasing bootstrap reference
2024-07-05T12:02:31.679862Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.679869Z  INFO awscrt::connection-manager: id=0x5638ff296a00: release
2024-07-05T12:02:31.679873Z  INFO awscrt::connection-manager: id=0x5638ff296a00: ref count now zero, starting shut down process
2024-07-05T12:02:31.679878Z  INFO awscrt::connection-manager: id=0x5638ff296a00: manager release, failing 0 pending acquisitions
2024-07-05T12:02:31.679885Z DEBUG awscrt::connection-manager: id=0x5638ff296a00: snapshot - state=2, 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=0
2024-07-05T12:02:31.679890Z  INFO awscrt::connection-manager: id=0x5638ff296a00: Destroying self
2024-07-05T12:02:31.679892Z  INFO awscrt::event-loop: id=0x5638ff0efea0: Destroying event_loop
2024-07-05T12:02:31.679895Z DEBUG awscrt::channel-bootstrap: id=0x5638ff06bc50: releasing bootstrap reference
2024-07-05T12:02:31.679898Z  INFO awscrt::event-loop: id=0x5638ff0efea0: Stopping event-loop thread.
2024-07-05T12:02:31.679901Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.679903Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.679906Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.679910Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-05T12:02:31.679911Z DEBUG awscrt::event-loop: id=0x5638ff0efea0: exiting main loop
2024-07-05T12:02:31.679914Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=1  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-07-05T12:02:31.679921Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.679924Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.679926Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.679929Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.679933Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-05T12:02:31.679937Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=1  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=0
2024-07-05T12:02:31.679963Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client body streaming ELG shutdown.
2024-07-05T12:02:31.680011Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.
2024-07-05T12:02:31.680016Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 s_s3_client_process_work_default - Processing any new meta requests.
2024-07-05T12:02:31.680019Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating meta requests.
2024-07-05T12:02:31.680022Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Updating connections, assigning requests where possible.
2024-07-05T12:02:31.680026Z  INFO awscrt::S3ClientStats: id=0x5638ff0d8e20 Requests-in-flight(approx/exact):0/0  Requests-preparing:0  Requests-queued:0  Requests-network(get/put/default/total):0/0/0/0  Requests-streaming-waiting:0  Requests-streaming-response:0  Endpoints(in-table/allocated):0/0
2024-07-05T12:02:31.680029Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client shutdown progress: starting_destroy_executing=0  body_streaming_elg_allocated=0  process_work_task_scheduled=0  process_work_task_in_progress=0  num_endpoints_allocated=0 s3express_provider_active=0 finish_destroy=1
2024-07-05T12:02:31.680032Z DEBUG awscrt::S3Client: id=0x5638ff0d8e20 Client finishing destruction.
2024-07-05T12:02:31.680191Z  INFO mountpoint_s3::metrics: process.memory_usage: 11337728
2024-07-05T12:02:31.680198Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.mem_limit: 2013265920
2024-07-05T12:02:31.680200Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_allocated: 0
2024-07-05T12:02:31.680202Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_cutoff: 33554432
2024-07-05T12:02:31.680204Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_num_blocks: 0
2024-07-05T12:02:31.680205Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_reserved: 0
2024-07-05T12:02:31.680207Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_used: 0
2024-07-05T12:02:31.680209Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_reserved: 0
2024-07-05T12:02:31.680210Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_used: 0
2024-07-05T12:02:31.680212Z  INFO mountpoint_s3::metrics: s3.client.host_count[host=my-bucket-in-987654321098-account.s3.eu-central-1.amazonaws.com]: 8
2024-07-05T12:02:31.680214Z  INFO mountpoint_s3::metrics: s3.client.num_auto_default_network_io: 0
2024-07-05T12:02:31.680216Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_copy_network_io: 0
2024-07-05T12:02:31.680217Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_get_network_io: 0
2024-07-05T12:02:31.680223Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_put_network_io: 0
2024-07-05T12:02:31.680225Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_prepared: 0
2024-07-05T12:02:31.680226Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_processed: 0
2024-07-05T12:02:31.680228Z  INFO mountpoint_s3::metrics: s3.client.num_requests_stream_queued_waiting: 0
2024-07-05T12:02:31.680230Z  INFO mountpoint_s3::metrics: s3.client.num_requests_streaming_response: 0
2024-07-05T12:02:31.680231Z  INFO mountpoint_s3::metrics: s3.client.num_total_network_io: 0
2024-07-05T12:02:31.680233Z  INFO mountpoint_s3::metrics: s3.client.request_queue_size: 0
2024-07-05T12:02:31.680235Z  INFO mountpoint_s3::metrics: s3.meta_requests.failures[op=list_objects,status=403]: 1
2024-07-05T12:02:31.680236Z  INFO mountpoint_s3::metrics: s3.meta_requests.first_byte_latency_us[op=list_objects]: n=1: min=274432 p10=276479 p50=276479 avg=275456.00 p90=276479 p99=276479 p99.9=276479 max=276479
2024-07-05T12:02:31.680238Z  INFO mountpoint_s3::metrics: s3.meta_requests.total_latency_us[op=list_objects]: n=1: min=274432 p10=276479 p50=276479 avg=275456.00 p90=276479 p99=276479 p99.9=276479 max=276479
2024-07-05T12:02:31.680240Z  INFO mountpoint_s3::metrics: s3.meta_requests[op=list_objects]: 1
2024-07-05T12:02:31.680241Z  INFO mountpoint_s3::metrics: s3.requests.failures[op=list_objects,type=Default,status=403]: 1
2024-07-05T12:02:31.680243Z  INFO mountpoint_s3::metrics: s3.requests.first_byte_latency_us[op=list_objects,type=Default]: n=1: min=28800 p10=28927 p50=28927 avg=28864.00 p90=28927 p99=28927 p99.9=28927 max=28927
2024-07-05T12:02:31.680245Z  INFO mountpoint_s3::metrics: s3.requests.total_latency_us[op=list_objects,type=Default]: n=1: min=272384 p10=274431 p50=274431 avg=273408.00 p90=274431 p99=274431 p99.9=274431 max=274431
2024-07-05T12:02:31.680246Z  INFO mountpoint_s3::metrics: s3.requests[op=list_objects,type=Default]: 1
2024-07-05T12:02:31.680248Z  INFO mountpoint_s3::metrics: system.available_memory: 1589911552
arsh commented 2 months ago

Thanks.

In the latest log, I see you are no longer getting the Failed to resolve credentials_process command error.

# OLD LOG
2024-07-04T10:07:28.181287Z ERROR awscrt::AuthCredentialsProvider: Failed to resolve credentials_process command during process credentials provider initialization.

#LATEST LOG
2024-07-05T12:02:31.394423Z DEBUG awscrt::AuthCredentialsProvider: Successfully loaded credentials_process command for process credentials provider.

Also, it seems that now this is a legitimate access denied error. Perhaps because it is not assuming the role you intended.

# OLD LOG
2024-07-04T10:07:28.190432Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 0, crt_error: Error(6146, "aws-c-auth: AWS_AUTH_SIGNING_NO_CREDENTIALS, Attempt to sign an http request without credentials"), error_response_headers: None, error_response_body: None }

#LATEST LOG
2024-07-05T12:02:31.679722Z DEBUG list_objects{id=0 bucket="my-bucket-in-987654321098-account" continued=false delimiter="" max_keys="0" prefix=""}: mountpoint_s3_client::s3_crt_client: meta request result: MetaRequestResult { response_status: 403, crt_error: Error(14343, "aws-c-s3: AWS_ERROR_S3_INVALID_RESPONSE_STATUS, Invalid response status from request"), error_response_headers: Some(Headers { inner: 0x7fac8c018600 }), error_response_body: Some("<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<Error><Code>AccessDenied</Code><Message>Access Denied</Message><RequestId>4PC1466N1G4QTG81</RequestId><HostId>yUQn6lwUAnmWyuL7jiB7Jw3eTbo9BDpwhieG7G5RLzpb8wdOFByNk/Z0UMk0m55XuSeA/3DY6/TTDnTa1VtMNA==</HostId></Error>") }

As I said before, I will be bringing this up with the CRT team.