search

awslabs / aws-sdk-rust

AWS SDK for the Rust Programming Language
https://awslabs.github.io/aws-sdk-rust/
Apache License 2.0
2.98k stars 245 forks source link

AWS S3 fails to get credentials #871

Closed OZoneGuy closed 1 year ago

OZoneGuy commented 1 year ago

Describe the bug

When trying to create an S3 client using config and listing the objects in bucket, the request takes a long time and ends up timing out.

Expected Behavior

Create the client, call the function, get the output. Not return an error

Current Behavior

Fails with this log:

2023-08-16T23:13:40Z INFO  tracing::span] try_op;
[2023-08-16T23:13:40Z INFO  tracing::span] try_attempt;
[2023-08-16T23:13:40Z INFO  tracing::span] lazy_load_credentials;
[2023-08-16T23:13:40Z INFO  aws_credential_types::cache::lazy_caching] credentials cache miss occurred; added new AWS credentials (took Ok(64.862µs))
[2023-08-16T23:13:43Z INFO  tracing::span] finally_attempt;
[2023-08-16T23:13:44Z INFO  tracing::span] try_attempt;
[2023-08-16T23:13:47Z INFO  tracing::span] finally_attempt;
[2023-08-16T23:13:48Z INFO  tracing::span] try_attempt;
[2023-08-16T23:13:51Z INFO  tracing::span] finally_attempt;
[2023-08-16T23:13:51Z INFO  tracing::span] finally_op;

And returns this error value:

Err(DispatchFailure(DispatchFailure { source: ConnectorError { kind: Timeout, source: hyper::Error(Connect, HttpTimeoutError { kind: "HTTP connect", duration: 3.1s }), connection: Unknown } }))

Reproduction Steps

  1. Create the config and the S3 client

    async fn create_s3_client(provider: &Secrets) -> aws_sdk_s3::Client {
let config = aws_config::from_env()
    .credentials_provider(provider.aws_creds())
    .load()
    .await;

aws_sdk_s3::Client::new(&config)
}

  2. Call the list_objects_v2() function:

    let objects = s3
    .list_objects_v2()
    .send()
    .await;

  3. Get the error.

Possible Solution

No response

Additional Information/Context

No response

Version

├── aws-config v0.56.0
│   ├── aws-credential-types v0.56.0
│   │   ├── aws-smithy-async v0.56.0
│   │   ├── aws-smithy-types v0.56.0
│   ├── aws-http v0.56.0
│   │   ├── aws-credential-types v0.56.0 (*)
│   │   ├── aws-smithy-http v0.56.0
│   │   │   ├── aws-smithy-eventstream v0.56.0
│   │   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-types v0.56.0
│   │   │   ├── aws-credential-types v0.56.0 (*)
│   │   │   ├── aws-smithy-async v0.56.0 (*)
│   │   │   ├── aws-smithy-client v0.56.0
│   │   │   │   ├── aws-smithy-async v0.56.0 (*)
│   │   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   │   ├── aws-smithy-http-tower v0.56.0
│   │   │   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   ├── aws-smithy-types v0.56.0 (*)
│   ├── aws-sdk-sso v0.29.0
│   │   ├── aws-credential-types v0.56.0 (*)
│   │   ├── aws-http v0.56.0 (*)
│   │   ├── aws-runtime v0.56.0
│   │   │   ├── aws-credential-types v0.56.0 (*)
│   │   │   ├── aws-http v0.56.0 (*)
│   │   │   ├── aws-sigv4 v0.56.0
│   │   │   │   ├── aws-smithy-eventstream v0.56.0 (*)
│   │   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   ├── aws-smithy-async v0.56.0 (*)
│   │   │   ├── aws-smithy-eventstream v0.56.0 (*)
│   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   ├── aws-smithy-runtime-api v0.56.0
│   │   │   │   ├── aws-smithy-async v0.56.0 (*)
│   │   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   │   ├── aws-types v0.56.0 (*)
│   │   ├── aws-smithy-async v0.56.0 (*)
│   │   ├── aws-smithy-client v0.56.0 (*)
│   │   ├── aws-smithy-http v0.56.0 (*)
│   │   ├── aws-smithy-json v0.56.0
│   │   │   └── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-smithy-runtime v0.56.0
│   │   │   ├── aws-smithy-async v0.56.0 (*)
│   │   │   ├── aws-smithy-client v0.56.0 (*)
│   │   │   ├── aws-smithy-http v0.56.0 (*)
│   │   │   ├── aws-smithy-runtime-api v0.56.0 (*)
│   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-smithy-runtime-api v0.56.0 (*)
│   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-types v0.56.0 (*)
│   ├── aws-sdk-sts v0.29.0
│   │   ├── aws-credential-types v0.56.0 (*)
│   │   ├── aws-http v0.56.0 (*)
│   │   ├── aws-runtime v0.56.0 (*)
│   │   ├── aws-smithy-async v0.56.0 (*)
│   │   ├── aws-smithy-client v0.56.0 (*)
│   │   ├── aws-smithy-http v0.56.0 (*)
│   │   ├── aws-smithy-json v0.56.0 (*)
│   │   ├── aws-smithy-query v0.56.0
│   │   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-smithy-runtime v0.56.0 (*)
│   │   ├── aws-smithy-runtime-api v0.56.0 (*)
│   │   ├── aws-smithy-types v0.56.0 (*)
│   │   ├── aws-smithy-xml v0.56.0
│   │   ├── aws-types v0.56.0 (*)
│   ├── aws-smithy-async v0.56.0 (*)
│   ├── aws-smithy-client v0.56.0 (*)
│   ├── aws-smithy-http v0.56.0 (*)
│   ├── aws-smithy-http-tower v0.56.0 (*)
│   ├── aws-smithy-json v0.56.0 (*)
│   ├── aws-smithy-types v0.56.0 (*)
│   ├── aws-types v0.56.0 (*)
├── aws-credential-types v0.56.0 (*)
├── aws-sdk-s3 v0.29.0
│   ├── aws-credential-types v0.56.0 (*)
│   ├── aws-http v0.56.0 (*)
│   ├── aws-runtime v0.56.0 (*)
│   ├── aws-sigv4 v0.56.0 (*)
│   ├── aws-smithy-async v0.56.0 (*)
│   ├── aws-smithy-checksums v0.56.0
│   │   ├── aws-smithy-http v0.56.0 (*)
│   │   ├── aws-smithy-types v0.56.0 (*)
│   ├── aws-smithy-client v0.56.0 (*)
│   ├── aws-smithy-eventstream v0.56.0 (*)
│   ├── aws-smithy-http v0.56.0 (*)
│   ├── aws-smithy-json v0.56.0 (*)
│   ├── aws-smithy-runtime v0.56.0 (*)
│   ├── aws-smithy-runtime-api v0.56.0 (*)
│   ├── aws-smithy-types v0.56.0 (*)
│   ├── aws-smithy-xml v0.56.0 (*)
│   ├── aws-types v0.56.0 (*)

Environment details (OS name and version, etc.)

Linux 6.4.9-arch1-1 x86_64 GNU/Linux

Logs

2023-08-17T22:54:36.178327Z DEBUG aws_config::fs_util: loaded home directory src="HOME"
2023-08-17T22:54:36.178381Z DEBUG load_config_file{file=Default(Config)}: aws_config::profile::parser::source: performing home directory substitution home="/home/omar" path="~/.aws/config"
2023-08-17T22:54:36.178434Z DEBUG load_config_file{file=Default(Config)}: aws_config::profile::parser::source: home directory expanded before="~/.aws/config" after="/home/omar/.aws/config"
2023-08-17T22:54:36.178504Z DEBUG load_config_file{file=Default(Config)}: aws_config::profile::parser::source: config file loaded path=Some("/home/omar/.aws/config") size=43
2023-08-17T22:54:36.178566Z DEBUG load_config_file{file=Default(Credentials)}: aws_config::profile::parser::source: performing home directory substitution home="/home/omar" path="~/.aws/credentials"
2023-08-17T22:54:36.178593Z DEBUG load_config_file{file=Default(Credentials)}: aws_config::profile::parser::source: home directory expanded before="~/.aws/credentials" after="/home/omar/.aws/credentials"
2023-08-17T22:54:36.178634Z DEBUG load_config_file{file=Default(Credentials)}: aws_config::profile::parser::source: config file loaded path=Some("/home/omar/.aws/credentials") size=116
2023-08-17T22:54:36.185907Z DEBUG hyper_rustls::config: with_native_roots processed 144 valid and 0 invalid certs
2023-08-17T22:54:36.228073Z DEBUG aws_sdk_s3::config: using retry strategy with partition 's3'
2023-08-17T22:54:36.231303Z  INFO actix_server::builder: starting 8 workers
2023-08-17T22:54:36.231343Z  INFO actix_server::server: Actix runtime found; starting in Actix runtime
2023-08-17T22:54:38.656562Z DEBUG actix_web::types::query: Failed during Query extractor deserialization. Request path: "/s3/list_objects"
2023-08-17T22:54:38.656610Z DEBUG actix_web::extract: Error for Option<T> extractor: Query deserialize error: missing field `path`
2023-08-17T22:54:38.657038Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime_api::client::interceptors::context: entering 'serialization' phase
2023-08-17T22:54:38.657175Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime_api::client::interceptors::context: entering 'before transmit' phase
2023-08-17T22:54:38.657259Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::retries::strategy::standard: no client rate limiter configured, so no token is required for the initial request.
2023-08-17T22:54:38.657285Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: retry strategy has OKed initial request
2023-08-17T22:54:38.657326Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: beginning attempt #1
2023-08-17T22:54:38.684474Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator::endpoints: will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-1.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"signingName": String("s3"), "name": String("sigv4"), "signingRegion": String("us-east-1"), "disableDoubleEncoding": Bool(true)})])} }
2023-08-17T22:54:38.684713Z  INFO invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt:lazy_load_credentials: aws_credential_types::cache::lazy_caching: credentials cache miss occurred; added new AWS credentials (took Ok(29.171µs))
2023-08-17T22:54:38.684751Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_credential_types::cache::lazy_caching: loaded credentials
2023-08-17T22:54:38.685219Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime_api::client::interceptors::context: entering 'transmit' phase
2023-08-17T22:54:38.685519Z DEBUG hyper::client::connect::dns: resolving host="remote-data-sync.s3.us-east-1.amazonaws.com"
2023-08-17T22:54:41.786776Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator: encountered orchestrator error; halting
2023-08-17T22:54:41.786958Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::retries::strategy::standard: attempt #1 failed with Error(TransientError); retrying after 979.561366ms
2023-08-17T22:54:41.787020Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: delaying for 979.561366ms
2023-08-17T22:54:42.767402Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: beginning attempt #2
2023-08-17T22:54:42.767609Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator::endpoints: will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-1.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"signingName": String("s3"), "name": String("sigv4"), "disableDoubleEncoding": Bool(true), "signingRegion": String("us-east-1")})])} }
2023-08-17T22:54:42.767832Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_credential_types::cache::lazy_caching: loaded credentials from cache
2023-08-17T22:54:42.768338Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime_api::client::interceptors::context: entering 'transmit' phase
2023-08-17T22:54:42.768688Z DEBUG hyper::client::connect::dns: resolving host="remote-data-sync.s3.us-east-1.amazonaws.com"
2023-08-17T22:54:45.868923Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator: encountered orchestrator error; halting
2023-08-17T22:54:45.869108Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::retries::strategy::standard: attempt #2 failed with Error(TransientError); retrying after 1.129896447s
2023-08-17T22:54:45.869171Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: delaying for 1.129896447s
2023-08-17T22:54:46.999950Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: beginning attempt #3
2023-08-17T22:54:47.000160Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator::endpoints: will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-1.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"signingRegion": String("us-east-1"), "name": String("sigv4"), "disableDoubleEncoding": Bool(true), "signingName": String("s3")})])} }
2023-08-17T22:54:47.000376Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_credential_types::cache::lazy_caching: loaded credentials from cache
2023-08-17T22:54:47.000875Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime_api::client::interceptors::context: entering 'transmit' phase
2023-08-17T22:54:47.001073Z DEBUG hyper::client::connect::dns: resolving host="remote-data-sync.s3.us-east-1.amazonaws.com"
2023-08-17T22:54:50.102387Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op:try_attempt: aws_smithy_runtime::client::orchestrator: encountered orchestrator error; halting
2023-08-17T22:54:50.102615Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::retries::strategy::standard: not retrying because we are out of attempts attempts=3 max_attempts=3
2023-08-17T22:54:50.102696Z DEBUG invoke{service=s3 operation=ListObjectsV2}:try_op: aws_smithy_runtime::client::orchestrator: a retry is either unnecessary or not possible, exiting attempt loop
rcoh commented 1 year ago

Can you include full logs (not just the span names)?

tracing_subscriber::fmt::init() + RUST_LOG=debug

It looks like you're getting timeouts and then a retry. Is there a reason you think credentials are to blame here? Seems like your passing static credentials into the client.

OZoneGuy commented 1 year ago

Added logs. Was following the template and didn't get any logs from RUST_LOG='aws_smithy_http_tower::dispatch=trace,aws_smithy_http::middleware=trace' cargo run.

jdisanti commented 1 year ago

That appears to be a networking issue rather than a credentials issue. It seems like it's making a request to S3 and not getting a response within the default 3.1 second timeout.

OZoneGuy commented 1 year ago

So what solution is there? I can access S3 using the command line, and I was able to interact with it using the JS SDK. So, is this a rust issue or what?

I tried the typescript SDK again from the same machine on the same network, and it works without an issue. I can see it fails after it tries to resolve the host. Is it failing to resolve the s3 host somehow?

jdisanti commented 1 year ago

Added logs. Was following the template and didn't get any logs from RUST_LOG='aws_smithy_http_tower::dispatch=trace,aws_smithy_http::middleware=trace' cargo run.

It looks like the instructions in the bug template were wrong. Sorry about that. Make sure tracing-subscriber has the env-filter feature enabled, and then it should be: RUST_LOG=debug cargo run.

So what solution is there? I can access S3 using the command line, and I was able to interact with it using the JS SDK. So, is this a rust issue or what?

I tried your code locally and wasn't able to reproduce the issue, although the list_objects_v2 without a bucket did fail in a different way (it got a ListBuckets response from S3). This is an unrelated issue.

I can't explain why it works for you with JS but not with Rust without more information about your environment. It seems like there's something about your host that is preventing the default Rustls hyper connector from making outbound HTTP calls.

Have you tried making a HTTP request to anything in Rust using the hyper-rustls and hyper crates? Does that work?

OZoneGuy commented 1 year ago

I tried making https requests using reqwest and the hyper-rustls crates. Both work. But when I try to make the request using the s3 library, it doesn't work...

    let https = hyper_rustls::HttpsConnectorBuilder::new()
        .with_native_roots()
        .https_only()
        .enable_http1()
        .build();
    let client: Client<_, hyper::Body> = Client::builder().build(https);

    let req = client
        .get(Uri::from_static(
            "https://remote-data-sync.s3.us-east-2.amazonaws.com",
        ))
        .await;

    dbg!(req); // suceeds to connect

    let s3_client = create_s3_client(&secrets).await;

    let objects = s3_client
        .list_objects_v2()
        .bucket(&config.bucket_name)
        .send()
        .await;

    dbg!(objects); // fails to connect
rcoh commented 1 year ago

In your example you connected to us-east-2 but the logs are pointing to us east 1 — what happens if you change the client region to us-east-2?

OZoneGuy commented 1 year ago

Same result. Here are the updated logs:

[2023-08-22T02:47:36Z DEBUG hyper_rustls::config] with_native_roots processed 144 valid and 0 invalid certs
[2023-08-22T02:47:36Z DEBUG hyper::client::connect::dns] resolving host="remote-data-sync.s3.us-east-2.amazonaws.com"
[2023-08-22T02:47:41Z DEBUG hyper::client::connect::http] connecting to 52.219.141.90:443
[2023-08-22T02:47:41Z DEBUG hyper::client::connect::http] connected to 52.219.141.90:443
[2023-08-22T02:47:41Z DEBUG rustls::client::hs] No cached session for DnsName("remote-data-sync.s3.us-east-2.amazonaws.com")
[2023-08-22T02:47:41Z DEBUG rustls::client::hs] Not resuming any session
[2023-08-22T02:47:41Z DEBUG rustls::client::hs] ALPN protocol is None
[2023-08-22T02:47:41Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
[2023-08-22T02:47:41Z DEBUG rustls::client::tls12] ECDHE curve is ECParameters { curve_type: NamedCurve, named_group: secp256r1 }
[2023-08-22T02:47:41Z DEBUG rustls::client::tls12] Server DNS name is DnsName("remote-data-sync.s3.us-east-2.amazonaws.com")
[2023-08-22T02:47:42Z DEBUG hyper::proto::h1::io] flushed 69 bytes
[2023-08-22T02:47:42Z DEBUG hyper::proto::h1::io] parsed 7 headers
[2023-08-22T02:47:42Z DEBUG hyper::proto::h1::conn] incoming body is chunked encoding
[src/main.rs:132] req = Ok(
    Response {
        status: 403,
        version: HTTP/1.1,
        headers: {
            "x-amz-bucket-region": "us-east-2",
            "x-amz-request-id": "2QK8MEJAPYJ2CT9E",
            "x-amz-id-2": "t8TM3hV78ZW5+0g+b7OvbvbbYKUozqHlK1MdkVEgqtXEfs+YZcQwhZXHRrg3K+uoEoU2Aw9Edtc=",
            "content-type": "application/xml",
            "transfer-encoding": "chunked",
            "date": "Tue, 22 Aug 2023 02:47:41 GMT",
            "server": "AmazonS3",
        },
        body: Body(
            Streaming,
        ),
    },
)
[2023-08-22T02:47:42Z DEBUG reqwest::connect] starting new connection: https://api.ipify.org/
[2023-08-22T02:47:42Z DEBUG hyper::client::connect::dns] resolving host="api.ipify.org"
[2023-08-22T02:47:42Z DEBUG rustls::common_state] Sending warning alert CloseNotify
[2023-08-22T02:47:47Z DEBUG hyper::client::connect::http] connecting to 64.185.227.156:443
[2023-08-22T02:47:47Z DEBUG hyper::client::connect::http] connected to 64.185.227.156:443
[2023-08-22T02:47:47Z DEBUG hyper::proto::h1::io] flushed 52 bytes
[2023-08-22T02:47:47Z DEBUG hyper::proto::h1::io] parsed 6 headers
[2023-08-22T02:47:47Z DEBUG hyper::proto::h1::conn] incoming body is content-length (14 bytes)
[2023-08-22T02:47:47Z DEBUG hyper::proto::h1::conn] incoming body completed
[2023-08-22T02:47:47Z DEBUG hyper::client::pool] pooling idle connection for ("https", api.ipify.org)
[2023-08-22T02:47:47Z DEBUG misc_server] Got server IP
[2023-08-22T02:47:47Z DEBUG aws_config::fs_util] loaded home directory src="HOME"
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] load_config_file; file=Default(Config)
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] performing home directory substitution home="/home/omar" path="~/.aws/config"
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] home directory expanded before="~/.aws/config" after="/home/omar/.aws/config"
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] config file loaded path=Some("/home/omar/.aws/config") size=43
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] load_config_file; file=Default(Credentials)
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] performing home directory substitution home="/home/omar" path="~/.aws/credentials"
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] home directory expanded before="~/.aws/credentials" after="/home/omar/.aws/credentials"
[2023-08-22T02:47:47Z DEBUG aws_config::profile::parser::source] config file loaded path=Some("/home/omar/.aws/credentials") size=116
[2023-08-22T02:47:47Z DEBUG hyper_rustls::config] with_native_roots processed 144 valid and 0 invalid certs
[2023-08-22T02:47:47Z DEBUG aws_sdk_s3::config] using retry strategy with partition 's3'
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime::client::orchestrator] invoke; service=s3 operation=ListObjectsV2
[2023-08-22T02:47:47Z INFO  tracing::span] try_op;
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime_api::client::interceptors::context] entering 'serialization' phase
[2023-08-22T02:47:47Z DEBUG tracing::span] serialization;
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime_api::client::interceptors::context] entering 'before transmit' phase
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime::client::retries::strategy::standard] no client rate limiter configured, so no token is required for the initial request.
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime::client::orchestrator] retry strategy has OKed initial request
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime::client::orchestrator] beginning attempt #1
[2023-08-22T02:47:47Z INFO  tracing::span] try_attempt;
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime::client::orchestrator::endpoints] will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-2.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"name": String("sigv4"), "signingName": String("s3"), "disableDoubleEncoding": Bool(true), "signingRegion": String("us-east-2")})])} }
[2023-08-22T02:47:47Z INFO  tracing::span] lazy_load_credentials;
[2023-08-22T02:47:47Z INFO  aws_credential_types::cache::lazy_caching] credentials cache miss occurred; added new AWS credentials (took Ok(17.101µs))
[2023-08-22T02:47:47Z DEBUG aws_credential_types::cache::lazy_caching] loaded credentials
[2023-08-22T02:47:47Z DEBUG aws_smithy_runtime_api::client::interceptors::context] entering 'transmit' phase
[2023-08-22T02:47:47Z DEBUG hyper::client::connect::dns] resolving host="remote-data-sync.s3.us-east-2.amazonaws.com"
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime::client::orchestrator] encountered orchestrator error; halting
[2023-08-22T02:47:50Z INFO  tracing::span] finally_attempt;
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime::client::retries::strategy::standard] attempt #1 failed with Error(TransientError); retrying after 75.611861ms
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime::client::orchestrator] delaying for 75.611861ms
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime::client::orchestrator] beginning attempt #2
[2023-08-22T02:47:50Z INFO  tracing::span] try_attempt;
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime::client::orchestrator::endpoints] will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-2.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"disableDoubleEncoding": Bool(true), "signingName": String("s3"), "name": String("sigv4"), "signingRegion": String("us-east-2")})])} }
[2023-08-22T02:47:50Z DEBUG aws_credential_types::cache::lazy_caching] loaded credentials from cache
[2023-08-22T02:47:50Z DEBUG aws_smithy_runtime_api::client::interceptors::context] entering 'transmit' phase
[2023-08-22T02:47:50Z DEBUG hyper::client::connect::dns] resolving host="remote-data-sync.s3.us-east-2.amazonaws.com"
[2023-08-22T02:47:53Z DEBUG aws_smithy_runtime::client::orchestrator] encountered orchestrator error; halting
[2023-08-22T02:47:53Z INFO  tracing::span] finally_attempt;
[2023-08-22T02:47:53Z DEBUG aws_smithy_runtime::client::retries::strategy::standard] attempt #2 failed with Error(TransientError); retrying after 1.944612874s
[2023-08-22T02:47:53Z DEBUG aws_smithy_runtime::client::orchestrator] delaying for 1.944612874s
[2023-08-22T02:47:55Z DEBUG aws_smithy_runtime::client::orchestrator] beginning attempt #3
[2023-08-22T02:47:55Z INFO  tracing::span] try_attempt;
[2023-08-22T02:47:55Z DEBUG aws_smithy_runtime::client::orchestrator::endpoints] will use endpoint Endpoint { url: "https://remote-data-sync.s3.us-east-2.amazonaws.com", headers: {}, properties: {"authSchemes": Array([Object({"signingName": String("s3"), "disableDoubleEncoding": Bool(true), "name": String("sigv4"), "signingRegion": String("us-east-2")})])} }
[2023-08-22T02:47:55Z DEBUG aws_credential_types::cache::lazy_caching] loaded credentials from cache
[2023-08-22T02:47:55Z DEBUG aws_smithy_runtime_api::client::interceptors::context] entering 'transmit' phase
[2023-08-22T02:47:55Z DEBUG hyper::client::connect::dns] resolving host="remote-data-sync.s3.us-east-2.amazonaws.com"
[2023-08-22T02:47:58Z DEBUG aws_smithy_runtime::client::orchestrator] encountered orchestrator error; halting
[2023-08-22T02:47:58Z INFO  tracing::span] finally_attempt;
[2023-08-22T02:47:58Z DEBUG aws_smithy_runtime::client::retries::strategy::standard] not retrying because we are out of attempts attempts=3 max_attempts=3
[2023-08-22T02:47:58Z DEBUG aws_smithy_runtime::client::orchestrator] a retry is either unnecessary or not possible, exiting attempt loop
[2023-08-22T02:47:58Z INFO  tracing::span] finally_op;
jdisanti commented 1 year ago

This looks relevant:

[2023-08-22T02:47:42Z DEBUG reqwest::connect] starting new connection: https://api.ipify.org/
[2023-08-22T02:47:42Z DEBUG hyper::client::connect::dns] resolving host="api.ipify.org"

What is this endpoint, and why is reqwest using it instead of the remote-data-sync.s3.us-east-2.amazonaws.com endpoint?

OZoneGuy commented 1 year ago

Not really, that is another request I am making as part of the application. Forgot to remove it when pasting the logs.

On Wed, Aug 23, 2023 at 12:37 PM, John DiSanti @.***(mailto:On Wed, Aug 23, 2023 at 12:37 PM, John DiSanti < wrote:

This looks relevant:

[2023-08-22T02:47:42Z DEBUG reqwest::connect] starting new connection: https://api.ipify.org/ [2023-08-22T02:47:42Z DEBUG hyper::client::connect::dns] resolving host="api.ipify.org"

What is this endpoint, and why is reqwest using it instead of the remote-data-sync.s3.us-east-2.amazonaws.com endpoint?

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you authored the thread.Message ID: @.***>

jdisanti commented 1 year ago

I'm at a loss here. I don't know why it's not working for you, and I'm not able to reproduce it. Does it work against the previous release (aws-sdk-s3 0.28 and aws-config 0.55)?

OZoneGuy commented 1 year ago

I tried the older version, still the same issue. Is there a way to increase the timeout? For the successful request, it looks like it takes 5 seconds to resolve the host, but the s3 client times out after 3 seconds. Could this the issue?

OZoneGuy commented 1 year ago

I just had to increase the timeout :'). It works now...

github-actions[bot] commented 1 year ago

⚠️COMMENT VISIBILITY WARNING⚠️

Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.

jdisanti commented 1 year ago

I'm glad you figured it out! 5 seconds seems like a really long time...