Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Credentials Provider failed to source credentials with error 2058(aws-c-http: AWS_ERROR_HTTP_CONNECTION_CLOSED, The connection has closed or is closing.) #1207

Open
at16cib opened this issue Jan 2, 2025 · 4 comments
Open

Credentials Provider failed to source credentials with error 2058(aws-c-http: AWS_ERROR_HTTP_CONNECTION_CLOSED, The connection has closed or is closing.) #1207

at16cib opened this issue Jan 2, 2025 · 4 comments
Labels
bug Something isn't working

Comments

@at16cib
Copy link

at16cib commented Jan 2, 2025 •
edited
Loading

Mountpoint for Amazon S3 version

mount-s3 1.13.0

AWS Region

eu-central-1

Describe the running environment

Batch job, ECS task using a Docker image Ubuntu 22.04.
The credentials to access the s3 bucket:

  • ECS task has a job/task role that is allowed to assume a given role that has all relevant access to S3
  • The assumed role is passed as an argument to the batch job, and during runtime an /root/.aws/config file is created with the following content:
[profile mountS3Profile]
role_arn=arn:aws:iam::XXXXXXXX:role/some-role
credential_source=EcsContainer
  • The profile mountS3Profile is used to setup mount-s3
  • 3 prefixes are mounted using the same mountS3Profile profile

Mountpoint options

mount-s3 --debug-crt --debug --log-directory /tmp/mount-s3-logs --cache /tmp/mount-s3-cache-ilKIXx94ajBp3mneRSq00g --metadata-ttl indefinite --max-cache-size 30720 --read-only --allow-root --profile ecsProfile data-bucket-1 --prefix data-prefix-1/ /data-prefix-1

mount-s3 --debug-crt --debug --log-directory /tmp/mount-s3-logs --cache /tmp/mount-s3-cache-7HAqRZPAzOohOLSsaT0pyQ --metadata-ttl indefinite --max-cache-size 30720 --read-only --allow-root --profile ecsProfile data-bucket-2 --prefix data-prefix-2/ /data-prefix-2

mount-s3 --debug-crt --debug --log-directory /tmp/mount-s3-logs --cache /tmp/mount-s3-cache-lOK757NJ390bei0hosytkQ --metadata-ttl indefinite --max-cache-size 30720 --read-only --allow-root --profile ecsProfile data-bucket-3 --prefix data-prefix-3/ /data-prefix-3

What happened?

All mount points are established successfully:

2024-12-18T10:23:09.424752Z  INFO mountpoint_s3::cli: successfully mounted prefix data-prefix-1/ of bucket data-bucket-1 at /data/prefix-1

2024-12-18T10:23:10.093370Z  INFO mountpoint_s3::cli: successfully mounted prefix data-prefix-2/ of bucket data-bucket-2 at /data/prefix-2

2024-12-18T10:23:10.505804Z  INFO mountpoint_s3::cli: successfully mounted prefix data/prefix-3 of bucket data-bucket-3 at /data/prefix-3

But as soon as a file is getting accessed from the 2. mountpoint multiple errors are logged:

2024-12-18T10:24:09.936431Z ERROR awscrt::http-stream: id=0x7f1588019790: Status code not yet received.    
2024-12-18T10:24:09.936436Z ERROR awscrt::AuthSigning: (id=0x7f1440000bf0) Credentials Provider failed to source credentials with error 2058(aws-c-http: AWS_ERROR_HTTP_CONNECTION_CLOSED, The connection has closed or is closing.)    
2024-12-18T10:24:09.936441Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)    
2024-12-18T10:24:09.936445Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Could not prepare request 0x7f14c8006820 due to error 6146 (Attempt to sign an http request without credentials).    
2024-12-18T10:24:09.936485Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: User releasing connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936493Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: 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=1, ref_count=1    
2024-12-18T10:24:09.936496Z  INFO awscrt::connection-manager: id=0x55e51b2d0480: Releasing connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936506Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588016618 shutdown in write dir completed.    
2024-12-18T10:24:09.936509Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Scheduling delayed write direction shutdown    
2024-12-18T10:24:09.936515Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Delayed shut down in write direction    
2024-12-18T10:24:09.936512Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936539Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588012590 shutdown in write dir completed.    
2024-12-18T10:24:09.936539Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936543Z DEBUG awscrt::socket: id=0x7f1588001080 fd=201: closing    
2024-12-18T10:24:09.936527Z DEBUG lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=HeadObject crt_error=None range=None duration=81.800221ms ttfb=None request_id=<unknown>
2024-12-18T10:24:09.936545Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936560Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936582Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936590Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936593Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936596Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936602Z DEBUG awscrt::S3MetaRequest: id=0x7f1224006ac0 Meta request finished with error code 6146 (Attempt to sign an http request without credentials)    
2024-12-18T10:24:09.936601Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f13c4001670 shutdown in write dir completed.    
2024-12-18T10:24:09.936612Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: channel 0x7f1588001700 shutdown with error 0.    
2024-12-18T10:24:09.936617Z  INFO awscrt::http-connection: 0x7f1588016610: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).    
2024-12-18T10:24:09.936620Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: shutdown received for connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936625Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: 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-12-18T10:24:09.936629Z DEBUG awscrt::channel: id=0x7f1588001700: destroying channel.    
2024-12-18T10:24:09.936632Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: releasing bootstrap reference    
2024-12-18T10:24:09.936636Z  WARN lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: mountpoint_s3_client::s3_crt_client: duration=82.136227ms request_id=<unknown> error=ClientError(NoSigningCredentials) meta request failed
2024-12-18T10:24:09.936646Z DEBUG lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: 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-12-18T10:24:09.936675Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936681Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936723Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936727Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936729Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936733Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936727Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::S3MetaRequest: id=0x7f1224006ac0 Cleaning up meta request    
2024-12-18T10:24:09.936738Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936775Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936779Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936782Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936775Z  WARN lookup{req=3 ino=1 name="file.csv"}: mountpoint_s3::fuse: lookup failed: inode error: error from ObjectClient: HeadObject failed: Client error: No signing credentials available, see CRT debug logs
  • The setup works most of the time. It only happens sporadically.
  • The setup of the credentials has to be fine, otherwise the list objects while establishing the mount point would fail.
  • I could not figure out what could cause the initial error AWS_ERROR_HTTP_CONNECTION_CLOSED

Relevant log output

2024-12-18T10:24:09.854095Z DEBUG fuser::request: FUSE(  2) ino 0x0000000000000001 GETATTR    
2024-12-18T10:24:09.854284Z DEBUG fuser::request: FUSE(  3) ino 0x0000000000000001 LOOKUP name "file.csv"    
2024-12-18T10:24:09.854460Z DEBUG lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: mountpoint_s3_client::s3_crt_client::head_object: new request
2024-12-18T10:24:09.854480Z  INFO lookup{req=3 ino=1 name="file.csv"}: awscrt::S3Client: id=0x55e51b2d1140 Initiating making of meta request    
2024-12-18T10:24:09.854501Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::S3MetaRequest: id=0x7f1224006ac0 Created new Default Meta Request. operation=HeadObject    
2024-12-18T10:24:09.854510Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::dns: id=0x55e51b100350: Host resolution requested for data-bucket-2.s3.eu-central-1.amazonaws.com    
2024-12-18T10:24:09.854518Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::dns: id=0x55e51b100350: cached entries found for data-bucket-2.s3.eu-central-1.amazonaws.com returning to caller.    
2024-12-18T10:24:09.854525Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::channel-bootstrap: id=0x55e51b1be810: acquiring bootstrap reference    
2024-12-18T10:24:09.854531Z  INFO lookup{req=3 ino=1 name="file.csv"}: awscrt::connection-manager: id=0x7f1224007440: Successfully created    
2024-12-18T10:24:09.854535Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::S3Endpoint: id=0x7f1224004410: Created connection manager 0x7f1224007440 for endpoint    
2024-12-18T10:24:09.854549Z  INFO lookup{req=3 ino=1 name="file.csv"}: awscrt::S3Client: id=0x55e51b2d1140: Created meta request 0x7f1224006ac0    
2024-12-18T10:24:09.854582Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.854596Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.854600Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.854607Z DEBUG awscrt::S3MetaRequest: id=0x7f1224006ac0: Meta Request Default created request 0x7f14c8006820    
2024-12-18T10:24:09.854620Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.854625Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.854625Z DEBUG lookup{req=3 ino=1 name="file.csv"}:list_objects{id=2 bucket="data-bucket-2" continued=false delimiter="/" max_keys="1" prefix="data-prefix-2/file.csv/"}: mountpoint_s3_client::s3_crt_client::list_objects: new request
2024-12-18T10:24:09.854634Z  INFO lookup{req=3 ino=1 name="file.csv"}: awscrt::S3Client: id=0x55e51b2d1140 Initiating making of meta request    
2024-12-18T10:24:09.854655Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::S3MetaRequest: id=0x7f1224008f60 Created new Default Meta Request. operation=ListObjectsV2    
2024-12-18T10:24:09.854664Z  INFO lookup{req=3 ino=1 name="file.csv"}: awscrt::S3Client: id=0x55e51b2d1140: Created meta request 0x7f1224008f60    
2024-12-18T10:24:09.854663Z DEBUG awscrt::S3MetaRequest: id=0x7f1224006ac0: Meta Request prepared request 0x7f14c8006820    
2024-12-18T10:24:09.854669Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.854673Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.854676Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.854679Z DEBUG awscrt::S3MetaRequest: id=0x7f1224008f60: Meta Request Default created request 0x7f14c8006960    
2024-12-18T10:24:09.854687Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b2b0c70): fetching credentials    
2024-12-18T10:24:09.854693Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: attempting to acquire retry token for partition_id     
2024-12-18T10:24:09.854702Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.854703Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: bucket 0x7f15600033f0 for partition_id  found    
2024-12-18T10:24:09.854707Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 Requests-in-flight(approx/exact):2/2  Requests-preparing:2  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-12-18T10:24:09.854708Z DEBUG awscrt::exp-backoff-strategy: id=0x55e51b2d07d0: Initializing retry token 0x7f14400030c0    
2024-12-18T10:24:09.854764Z DEBUG awscrt::exp-backoff-strategy: id=0x55e51b2d07d0: Vending retry_token 0x7f14400030c0    
2024-12-18T10:24:09.854772Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: token acquired callback invoked with error Success. with token 0x7f1440002ff0 and nested token 0x7f14400030c0    
2024-12-18T10:24:09.854773Z DEBUG awscrt::S3MetaRequest: id=0x7f1224008f60: Meta Request prepared request 0x7f14c8006960    
2024-12-18T10:24:09.854792Z DEBUG awscrt::AuthCredentialsProvider: id=0x55e51b1daa30: ECS provider trying to load credentials    
2024-12-18T10:24:09.854792Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b2b0c70): fetching credentials    
2024-12-18T10:24:09.854798Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Acquire connection    
2024-12-18T10:24:09.854799Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: attempting to acquire retry token for partition_id     
2024-12-18T10:24:09.854806Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: 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-12-18T10:24:09.854807Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: bucket 0x7f15600033f0 for partition_id  found    
2024-12-18T10:24:09.854809Z  INFO awscrt::connection-manager: id=0x55e51b2b0a10: Requesting 1 new connections from http    
2024-12-18T10:24:09.854810Z DEBUG awscrt::exp-backoff-strategy: id=0x55e51b2d07d0: Initializing retry token 0x7f1414003200    
2024-12-18T10:24:09.854814Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: acquiring bootstrap reference    
2024-12-18T10:24:09.854818Z DEBUG awscrt::dns: id=0x55e51b100350: Host resolution requested for 169.254.170.2    
2024-12-18T10:24:09.854821Z DEBUG awscrt::dns: id=0x55e51b100350: No cached entries found for 169.254.170.2 starting new resolver thread.    
2024-12-18T10:24:09.854846Z DEBUG awscrt::exp-backoff-strategy: id=0x55e51b2d07d0: Vending retry_token 0x7f1414003200    
2024-12-18T10:24:09.854869Z DEBUG awscrt::standard-retry-strategy: id=0x55e51b2d06e0: token acquired callback invoked with error Success. with token 0x7f1414003130 and nested token 0x7f1414003200    
2024-12-18T10:24:09.854883Z DEBUG awscrt::AuthCredentialsProvider: id=0x55e51b1daa30: ECS provider trying to load credentials    
2024-12-18T10:24:09.854890Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Acquire connection    
2024-12-18T10:24:09.854895Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: snapshot - state=1, idle_connection_count=0, pending_acquire_count=2, pending_settings_count=0, pending_connect_count=2, vended_connection_count=0, open_connection_count=0, ref_count=1    
2024-12-18T10:24:09.854899Z  INFO awscrt::connection-manager: id=0x55e51b2b0a10: Requesting 1 new connections from http    
2024-12-18T10:24:09.854903Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: acquiring bootstrap reference    
2024-12-18T10:24:09.854907Z DEBUG awscrt::dns: id=0x55e51b100350: Host resolution requested for 169.254.170.2    
2024-12-18T10:24:09.854925Z DEBUG awscrt::dns: static: resolving host 169.254.170.2    
2024-12-18T10:24:09.854961Z DEBUG awscrt::dns: static: resolved record: 169.254.170.2    
2024-12-18T10:24:09.854967Z DEBUG awscrt::dns: static, resolving host 169.254.170.2 successful, returned 1 addresses    
2024-12-18T10:24:09.854976Z DEBUG awscrt::dns: static: new address resolved 169.254.170.2 for host 169.254.170.2 caching    
2024-12-18T10:24:09.854982Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.170.2 with 1 addresses    
2024-12-18T10:24:09.855011Z DEBUG awscrt::dns: static, invoking resolution callback for host 169.254.170.2 with 1 addresses    
2024-12-18T10:24:09.855097Z DEBUG awscrt::socket: id=0x7f1478000f20 fd=1: initializing with domain 0 and type 0    
2024-12-18T10:24:09.855097Z DEBUG awscrt::socket: id=0x7f14e8001660 fd=2: initializing with domain 0 and type 0    
2024-12-18T10:24:09.855121Z DEBUG awscrt::socket: id=0x7f1478000f20 fd=1: setting socket options to: keep-alive 0, keep-alive timeout 0, keep-alive interval 0, keep-alive probe count 0.    
2024-12-18T10:24:09.855124Z DEBUG awscrt::socket: id=0x7f14e8001660 fd=2: setting socket options to: keep-alive 0, keep-alive timeout 0, keep-alive interval 0, keep-alive probe count 0.    
2024-12-18T10:24:09.855127Z DEBUG awscrt::socket: id=0x7f1478000f20 fd=1: beginning connect.    
2024-12-18T10:24:09.855131Z DEBUG awscrt::socket: id=0x7f14e8001660 fd=2: beginning connect.    
2024-12-18T10:24:09.855133Z DEBUG awscrt::socket: id=0x7f1478000f20 fd=1: connecting to endpoint 169.254.170.2:80.    
2024-12-18T10:24:09.855135Z DEBUG awscrt::socket: id=0x7f14e8001660 fd=2: connecting to endpoint 169.254.170.2:80.    
2024-12-18T10:24:09.855253Z  INFO awscrt::socket: id=0x7f1478000f20 fd=1: connection success    
2024-12-18T10:24:09.855261Z DEBUG awscrt::socket: id=0x7f1478000f20 fd=1: assigning to event loop 0x55e51b1d8340    
2024-12-18T10:24:09.855266Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: client connection on socket 0x7f1478000f20 completed with error 0.    
2024-12-18T10:24:09.855271Z DEBUG awscrt::channel: id=0x7f14780015b0: Beginning creation and setup of new channel.    
2024-12-18T10:24:09.855275Z DEBUG awscrt::channel: id=0x7f14780015b0: setup complete, notifying caller.    
2024-12-18T10:24:09.855281Z DEBUG awscrt::channel: id=0x7f14780015b0: no message pool is currently stored in the event-loop local storage, adding 0x7f1478001a00 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.    
2024-12-18T10:24:09.855296Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: channel 0x7f14780015b0 setup succeeded: bootstrapping.    
2024-12-18T10:24:09.855300Z DEBUG awscrt::socket-handler: id=0x7f13c4001340: Socket handler created with max_read_size of 16384    
2024-12-18T10:24:09.855309Z  INFO awscrt::http-connection: id=0x7f1478012460: HTTP/1.1 client connection established.    
2024-12-18T10:24:09.855320Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Received new connection (id=0x7f1478012460) from http layer    
2024-12-18T10:24:09.855324Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Grabbing pooled connection (0x7f1478012460)    
2024-12-18T10:24:09.855330Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=1, open_connection_count=1, ref_count=1    
2024-12-18T10:24:09.855338Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Successfully completed connection acquisition with connection id=0x7f1478012460    
2024-12-18T10:24:09.855353Z DEBUG awscrt::http-stream: id=0x7f1478013100: Created client request on connection=0x7f1478012460: GET /v2/credentials/3ea73479-88b1-4652-a50c-ee4b11962f8d HTTP/1.1    
2024-12-18T10:24:09.855434Z  INFO awscrt::socket: id=0x7f14e8001660 fd=2: connection success    
2024-12-18T10:24:09.855445Z DEBUG awscrt::socket: id=0x7f14e8001660 fd=2: assigning to event loop 0x55e51b1ca150    
2024-12-18T10:24:09.855451Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: client connection on socket 0x7f14e8001660 completed with error 0.    
2024-12-18T10:24:09.855455Z DEBUG awscrt::channel: id=0x7f14e8000af0: Beginning creation and setup of new channel.    
2024-12-18T10:24:09.855460Z DEBUG awscrt::channel: id=0x7f14e8000af0: setup complete, notifying caller.    
2024-12-18T10:24:09.855466Z DEBUG awscrt::channel: id=0x7f14e8000af0: no message pool is currently stored in the event-loop local storage, adding 0x7f14e8000f20 with max message size 16384, message count 4, with 4 small blocks of 128 bytes.    
2024-12-18T10:24:09.855472Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: channel 0x7f14e8000af0 setup succeeded: bootstrapping.    
2024-12-18T10:24:09.855476Z DEBUG awscrt::socket-handler: id=0x7f13c4001540: Socket handler created with max_read_size of 16384    
2024-12-18T10:24:09.855481Z  INFO awscrt::http-connection: id=0x7f14e8012230: HTTP/1.1 client connection established.    
2024-12-18T10:24:09.855486Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Received new connection (id=0x7f14e8012230) from http layer    
2024-12-18T10:24:09.855490Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Grabbing pooled connection (0x7f14e8012230)    
2024-12-18T10:24:09.855496Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: snapshot - state=1, idle_connection_count=0, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=2, open_connection_count=2, ref_count=1    
2024-12-18T10:24:09.855508Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: Successfully completed connection acquisition with connection id=0x7f14e8012230    
2024-12-18T10:24:09.855518Z DEBUG awscrt::http-stream: id=0x7f14e8012e70: Created client request on connection=0x7f14e8012230: GET /v2/credentials/3ea73479-88b1-4652-a50c-ee4b11962f8d HTTP/1.1    
2024-12-18T10:24:09.855783Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b1daa30) ECS credentials provider query received http status code 200    
2024-12-18T10:24:09.855899Z DEBUG awscrt::http-stream: id=0x7f1478013100: Client request complete, response status: 200 (OK).    
2024-12-18T10:24:09.855927Z  INFO awscrt::AuthCredentialsProvider: (id=0x55e51b1daa30) ECS credentials provider successfully queried instance role credentials    
2024-12-18T10:24:09.856003Z  INFO awscrt::AuthSigning: (id=0x7f14c4000bf0) Signing successfully built canonical request for algorithm SigV4, with contents 
POST
/

content-length:199
content-type:application/x-www-form-urlencoded
host:sts.amazonaws.com
x-amz-date:20241218T102409Z
x-amz-security-token:XXX

content-length;content-type;host;x-amz-date;x-amz-security-token
xxxxxxxxxxx
    
2024-12-18T10:24:09.856003Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b1daa30) ECS credentials provider query received http status code 200    
2024-12-18T10:24:09.856020Z  INFO awscrt::AuthSigning: (id=0x7f14c4000bf0) Signing successfully built string-to-sign via algorithm SigV4, with contents 
AWS4-HMAC-SHA256
20241218T102409Z
20241218/us-east-1/sts/aws4_request
889a2b36797a58d155bd3db0780dc58f0d9a6b1a4e61b654a642ff4ff1395656
    
2024-12-18T10:24:09.856034Z DEBUG awscrt::http-stream: id=0x7f14e8012e70: Client request complete, response status: 200 (OK).    
2024-12-18T10:24:09.856035Z  INFO awscrt::AuthSigning: (id=0x7f14c4000bf0) Http request successfully built final authorization value via algorithm SigV4, with contents 
AWS4-HMAC-SHA256 Credential=XXX/20241218/us-east-1/sts/aws4_request, SignedHeaders=content-length;content-type;host;x-amz-date;x-amz-security-token, Signature=xxxxxxxxxxx
    
2024-12-18T10:24:09.856043Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b2b0c70): signing completed with error code 0    
2024-12-18T10:24:09.856048Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: Acquire connection    
2024-12-18T10:24:09.856052Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: Grabbing pooled connection (0x7f1588016610)    
2024-12-18T10:24:09.856057Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: 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-12-18T10:24:09.856061Z  INFO awscrt::AuthCredentialsProvider: (id=0x55e51b1daa30) ECS credentials provider successfully queried instance role credentials    
2024-12-18T10:24:09.856075Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: User releasing connection (id=0x7f1478012460)    
2024-12-18T10:24:09.856081Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: snapshot - state=1, idle_connection_count=1, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=1, open_connection_count=2, ref_count=1    
2024-12-18T10:24:09.856102Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: Successfully completed connection acquisition with connection id=0x7f1588016610    
2024-12-18T10:24:09.856107Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b2b0c70): connection returned with error code 0    
2024-12-18T10:24:09.856110Z  INFO awscrt::AuthSigning: (id=0x7f1488000b70) Signing successfully built canonical request for algorithm SigV4, with contents 
POST
/

content-length:199
content-type:application/x-www-form-urlencoded
host:sts.amazonaws.com
x-amz-date:20241218T102409Z
x-amz-security-token:XXX

content-length;content-type;host;x-amz-date;x-amz-security-token
xxxxxxxxxxx    
2024-12-18T10:24:09.856118Z DEBUG awscrt::http-stream: id=0x7f1588019790: Created client request on connection=0x7f1588016610: POST / HTTP/1.1    
2024-12-18T10:24:09.856124Z  INFO awscrt::AuthSigning: (id=0x7f1488000b70) Signing successfully built string-to-sign via algorithm SigV4, with contents 
AWS4-HMAC-SHA256
20241218T102409Z
20241218/us-east-1/sts/aws4_request
889a2b36797a58d155bd3db0780dc58f0d9a6b1a4e61b654a642ff4ff1395656
    
2024-12-18T10:24:09.856139Z  INFO awscrt::AuthSigning: (id=0x7f1488000b70) Http request successfully built final authorization value via algorithm SigV4, with contents 
AWS4-HMAC-SHA256 Credential=XXX/20241218/us-east-1/sts/aws4_request, SignedHeaders=content-length;content-type;host;x-amz-date;x-amz-security-token, Signature=xxxxxxxxxxx
    
2024-12-18T10:24:09.856145Z DEBUG awscrt::AuthCredentialsProvider: (id=0x55e51b2b0c70): signing completed with error code 0    
2024-12-18T10:24:09.856152Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: Acquire connection    
2024-12-18T10:24:09.856160Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: snapshot - state=1, idle_connection_count=0, pending_acquire_count=1, pending_settings_count=0, pending_connect_count=1, vended_connection_count=1, open_connection_count=1, ref_count=1    
2024-12-18T10:24:09.856163Z  INFO awscrt::connection-manager: id=0x55e51b2d0480: Requesting 1 new connections from http    
2024-12-18T10:24:09.856169Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: acquiring bootstrap reference    
2024-12-18T10:24:09.856174Z DEBUG awscrt::dns: id=0x55e51b100350: Host resolution requested for sts.amazonaws.com    
2024-12-18T10:24:09.856178Z DEBUG awscrt::dns: id=0x55e51b100350: No cached entries found for sts.amazonaws.com starting new resolver thread.    
2024-12-18T10:24:09.856255Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: User releasing connection (id=0x7f14e8012230)    
2024-12-18T10:24:09.856264Z DEBUG awscrt::connection-manager: id=0x55e51b2b0a10: snapshot - state=1, idle_connection_count=2, pending_acquire_count=0, pending_settings_count=0, pending_connect_count=0, vended_connection_count=0, open_connection_count=2, ref_count=1    
2024-12-18T10:24:09.856310Z DEBUG awscrt::dns: static: resolving host sts.amazonaws.com    
2024-12-18T10:24:09.856863Z DEBUG awscrt::dns: static: resolved record: 52.119.198.216    
2024-12-18T10:24:09.856892Z DEBUG awscrt::dns: static, resolving host sts.amazonaws.com successful, returned 1 addresses    
2024-12-18T10:24:09.856899Z DEBUG awscrt::dns: static: new address resolved 52.119.198.216 for host sts.amazonaws.com caching    
2024-12-18T10:24:09.856906Z DEBUG awscrt::dns: static, invoking resolution callback for host sts.amazonaws.com with 1 addresses    
2024-12-18T10:24:09.856967Z DEBUG awscrt::socket: id=0x7f14b0001920 fd=3: initializing with domain 0 and type 0    
2024-12-18T10:24:09.856980Z DEBUG awscrt::socket: id=0x7f14b0001920 fd=3: setting socket options to: keep-alive 0, keep-alive timeout 0, keep-alive interval 0, keep-alive probe count 0.    
2024-12-18T10:24:09.856997Z DEBUG awscrt::socket: id=0x7f14b0001920 fd=3: beginning connect.    
2024-12-18T10:24:09.857003Z DEBUG awscrt::socket: id=0x7f14b0001920 fd=3: connecting to endpoint 52.119.198.216:443.    
2024-12-18T10:24:09.908584Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.908610Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.908614Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.908621Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.908627Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 Requests-in-flight(approx/exact):2/2  Requests-preparing:2  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-12-18T10:24:09.915558Z DEBUG awscrt::dns: static: resolving host data-bucket-2.s3.eu-central-1.amazonaws.com    
2024-12-18T10:24:09.918036Z DEBUG awscrt::dns: static: resolved record: 3.5.135.157    
2024-12-18T10:24:09.918053Z DEBUG awscrt::dns: static, resolving host data-bucket-2.s3.eu-central-1.amazonaws.com successful, returned 1 addresses    
2024-12-18T10:24:09.925379Z  INFO mountpoint_s3::metrics: fuse.op_latency_us[op=getattr]: n=1: min=47 p10=47 p50=47 avg=47.00 p90=47 p99=47 p99.9=47 max=47
2024-12-18T10:24:09.925407Z  INFO mountpoint_s3::metrics: metadata_cache.cache_hit: 0
2024-12-18T10:24:09.925409Z  INFO mountpoint_s3::metrics: metadata_cache.negative_cache.cache_hit: 0
2024-12-18T10:24:09.925411Z  INFO mountpoint_s3::metrics: metadata_cache.negative_cache.operation_duration_us[op=contains]: n=1: min=6 p10=6 p50=6 avg=6.00 p90=6 p99=6 p99.9=6 max=6
2024-12-18T10:24:09.925413Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.forced_used: 0
2024-12-18T10:24:09.925414Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.get_usage_latency_us: n=2: min=0 p10=0 p50=0 avg=0.50 p90=1 p99=1 p99.9=1 max=1
2024-12-18T10:24:09.925416Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.mem_limit: 4160749568
2024-12-18T10:24:09.925418Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_allocated: 0
2024-12-18T10:24:09.925419Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_cutoff: 33554432
2024-12-18T10:24:09.925421Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_num_blocks: 0
2024-12-18T10:24:09.925423Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_reserved: 0
2024-12-18T10:24:09.925425Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.primary_used: 0
2024-12-18T10:24:09.925426Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_reserved: 0
2024-12-18T10:24:09.925428Z  INFO mountpoint_s3::metrics: s3.client.buffer_pool.secondary_used: 0
2024-12-18T10:24:09.925430Z  INFO mountpoint_s3::metrics: s3.client.num_auto_default_network_io: 0
2024-12-18T10:24:09.925432Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_copy_network_io: 0
2024-12-18T10:24:09.925434Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_get_network_io: 0
2024-12-18T10:24:09.925436Z  INFO mountpoint_s3::metrics: s3.client.num_auto_ranged_put_network_io: 0
2024-12-18T10:24:09.925437Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_prepared: 1
2024-12-18T10:24:09.925439Z  INFO mountpoint_s3::metrics: s3.client.num_requests_being_processed: 1
2024-12-18T10:24:09.925441Z  INFO mountpoint_s3::metrics: s3.client.num_requests_stream_queued_waiting: 0
2024-12-18T10:24:09.925443Z  INFO mountpoint_s3::metrics: s3.client.num_requests_streaming_response: 0
2024-12-18T10:24:09.925445Z  INFO mountpoint_s3::metrics: s3.client.num_total_network_io: 0
2024-12-18T10:24:09.925447Z  INFO mountpoint_s3::metrics: s3.client.request_queue_size: 0
2024-12-18T10:24:09.936304Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Alert code 0    
2024-12-18T10:24:09.936383Z  INFO awscrt::socket: id=0x7f1588001080 fd=201: zero read, socket is closed    
2024-12-18T10:24:09.936391Z DEBUG awscrt::channel: id=0x7f1588001700: Channel shutdown is already pending, not scheduling another.    
2024-12-18T10:24:09.936396Z  INFO awscrt::socket: id=0x7f1588001080 fd=201: zero read, socket is closed    
2024-12-18T10:24:09.936398Z DEBUG awscrt::channel: id=0x7f1588001700: Channel shutdown is already pending, not scheduling another.    
2024-12-18T10:24:09.936403Z DEBUG awscrt::channel: id=0x7f1588001700: beginning shutdown process    
2024-12-18T10:24:09.936407Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f13c4001670 shutdown in read dir completed.    
2024-12-18T10:24:09.936411Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Shutting down read direction with error code 0    
2024-12-18T10:24:09.936414Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588012590 shutdown in read dir completed.    
2024-12-18T10:24:09.936417Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588016618 shutdown in read dir completed.    
2024-12-18T10:24:09.936426Z DEBUG awscrt::http-stream: id=0x7f1588019790: Stream completed with error code 2058 (AWS_ERROR_HTTP_CONNECTION_CLOSED).    
2024-12-18T10:24:09.936431Z ERROR awscrt::http-stream: id=0x7f1588019790: Status code not yet received.    
2024-12-18T10:24:09.936436Z ERROR awscrt::AuthSigning: (id=0x7f1440000bf0) Credentials Provider failed to source credentials with error 2058(aws-c-http: AWS_ERROR_HTTP_CONNECTION_CLOSED, The connection has closed or is closing.)    
2024-12-18T10:24:09.936441Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)    
2024-12-18T10:24:09.936445Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Could not prepare request 0x7f14c8006820 due to error 6146 (Attempt to sign an http request without credentials).    
2024-12-18T10:24:09.936485Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: User releasing connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936493Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: 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=1, ref_count=1    
2024-12-18T10:24:09.936496Z  INFO awscrt::connection-manager: id=0x55e51b2d0480: Releasing connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936506Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588016618 shutdown in write dir completed.    
2024-12-18T10:24:09.936509Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Scheduling delayed write direction shutdown    
2024-12-18T10:24:09.936515Z DEBUG awscrt::tls-handler: id=0x7f1588012590: Delayed shut down in write direction    
2024-12-18T10:24:09.936512Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936539Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f1588012590 shutdown in write dir completed.    
2024-12-18T10:24:09.936539Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936543Z DEBUG awscrt::socket: id=0x7f1588001080 fd=201: closing    
2024-12-18T10:24:09.936527Z DEBUG lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: mountpoint_s3_client::s3_crt_client: S3 request failed request_type=HeadObject crt_error=None range=None duration=81.800221ms ttfb=None request_id=<unknown>
2024-12-18T10:24:09.936545Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936560Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936582Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936590Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936593Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936596Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936602Z DEBUG awscrt::S3MetaRequest: id=0x7f1224006ac0 Meta request finished with error code 6146 (Attempt to sign an http request without credentials)    
2024-12-18T10:24:09.936601Z DEBUG awscrt::channel: id=0x7f1588001700: handler 0x7f13c4001670 shutdown in write dir completed.    
2024-12-18T10:24:09.936612Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: channel 0x7f1588001700 shutdown with error 0.    
2024-12-18T10:24:09.936617Z  INFO awscrt::http-connection: 0x7f1588016610: Client shutdown completed with error 0 (AWS_ERROR_SUCCESS).    
2024-12-18T10:24:09.936620Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: shutdown received for connection (id=0x7f1588016610)    
2024-12-18T10:24:09.936625Z DEBUG awscrt::connection-manager: id=0x55e51b2d0480: 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-12-18T10:24:09.936629Z DEBUG awscrt::channel: id=0x7f1588001700: destroying channel.    
2024-12-18T10:24:09.936632Z DEBUG awscrt::channel-bootstrap: id=0x55e51b1be810: releasing bootstrap reference    
2024-12-18T10:24:09.936636Z  WARN lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: mountpoint_s3_client::s3_crt_client: duration=82.136227ms request_id=<unknown> error=ClientError(NoSigningCredentials) meta request failed
2024-12-18T10:24:09.936646Z DEBUG lookup{req=3 ino=1 name="file.csv"}:head_object{id=1 bucket="data-bucket-2" key="data-prefix-2/file.csv"}: 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-12-18T10:24:09.936675Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936681Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936723Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936727Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936729Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936733Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating connections, assigning requests where possible.    
2024-12-18T10:24:09.936727Z DEBUG lookup{req=3 ino=1 name="file.csv"}: awscrt::S3MetaRequest: id=0x7f1224006ac0 Cleaning up meta request    
2024-12-18T10:24:09.936738Z  INFO awscrt::S3ClientStats: id=0x55e51b2d1140 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-12-18T10:24:09.936775Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Moving relevant synced_data into threaded_data.    
2024-12-18T10:24:09.936779Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 s_s3_client_process_work_default - Processing any new meta requests.    
2024-12-18T10:24:09.936782Z DEBUG awscrt::S3Client: id=0x55e51b2d1140 Updating meta requests.    
2024-12-18T10:24:09.936775Z  WARN lookup{req=3 ino=1 name="file.csv"}: mountpoint_s3::fuse: lookup failed: inode error: error from ObjectClient: HeadObject failed: Client error: No signing credentials available, see CRT debug logs
@at16cib at16cib added the bug Something isn't working label Jan 2, 2025
@at16cib
Copy link
Author

at16cib commented Jan 21, 2025

Any help here? Could someone confirm that usually multiple mounts should be supported by mount-s3? And that this is a authentication issue?

@vladem
Copy link
Contributor

vladem commented Jan 22, 2025

Hi @at16cib, thanks for this finding. Your use case should be supported. Those logs point to a transient issue with the container credentials provider:

2024-12-18T10:24:09.936436Z ERROR awscrt::AuthSigning: (id=0x7f1440000bf0) Credentials Provider failed to source credentials with error 2058(aws-c-http: AWS_ERROR_HTTP_CONNECTION_CLOSED, The connection has closed or is closing.)    
2024-12-18T10:24:09.936441Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Meta request could not sign HTTP request due to error code 6146 (Attempt to sign an http request without credentials)    
2024-12-18T10:24:09.936445Z ERROR awscrt::S3MetaRequest: id=0x7f1224006ac0 Could not prepare request 0x7f14c8006820 due to error 6146 (Attempt to sign an http request without credentials).

We suspect that retrying credential retrieval will help in this case. The CRT team implemented the fix for that: https://github.com/awslabs/aws-c-auth/pull/259/files. This will be included in the next release of Mountpoint.

@dannycjones dannycjones mentioned this issue Jan 22, 2025
Merged
github-merge-queue bot pushed a commit that referenced this issue Jan 23, 2025
@dannycjones
Update CRT submodules to latest releases (#1242)
814c5c7 
Update the CRT to the latest releases.

This change also updates the exclude list, primarily due to one of the
test files being replaced by a compressed (but still large) file:
aws/aws-lc#2123

This change pulls in a bug fix
(awslabs/aws-c-auth#259), addressing
#1207.

### Does this change impact existing behavior?

One bug fix is included in CRT changes.

### Does this change need a changelog entry? Does it require a version
change?

Change log entry added for the CRT fix. It is a bug fix, so patch
version bump to `mountpoint-s3-client` remains appropriate.

---

By submitting this pull request, I confirm that my contribution is made
under the terms of the Apache 2.0 license and I agree to the terms of
the [Developer Certificate of Origin
(DCO)](https://developercertificate.org/).

Signed-off-by: Daniel Carl Jones <[email protected]>
@at16cib
Copy link
Author

at16cib commented Jan 23, 2025

Awesome, great to hear that this will be fixed soon! Do you know the release date and the version that will include the fix?

@dannycjones
Copy link
Contributor

Hey @at16cib, the next version will include the fix. Currently, that would be 1.14.1 as no new features are added. We don't have a date yet, but based on past releases we aim for no more than a month between releases.

keremnc pushed a commit to keremnc/mountpoint-s3 that referenced this issue Jan 24, 2025
@dannycjones @keremnc
Update CRT submodules to latest releases (awslabs#1242)
e4a713e 
Update the CRT to the latest releases.

This change also updates the exclude list, primarily due to one of the
test files being replaced by a compressed (but still large) file:
aws/aws-lc#2123

This change pulls in a bug fix
(awslabs/aws-c-auth#259), addressing
awslabs#1207.

### Does this change impact existing behavior?

One bug fix is included in CRT changes.

### Does this change need a changelog entry? Does it require a version
change?

Change log entry added for the CRT fix. It is a bug fix, so patch
version bump to `mountpoint-s3-client` remains appropriate.

---

By submitting this pull request, I confirm that my contribution is made
under the terms of the Apache 2.0 license and I agree to the terms of
the [Developer Certificate of Origin
(DCO)](https://developercertificate.org/).

Signed-off-by: Daniel Carl Jones <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@dannycjones @vladem @at16cib