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.

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

.NET 8: S3.PutObjectAsync request throws exception "Request headers must contain only ASCII characters." #3574

Closed
1 task done
indimini opened this issue Dec 10, 2024 · 13 comments
Assignees
Labels
bug This issue is a bug. p2 This is a standard priority issue s3

Comments

@indimini
Copy link

Describe the bug

In migrating to .NET 8, we've run into an issue when calling IAmazonS3.PutObjectAsync(). The call works when running on Windows (debug/dev environment), but when deployed to Linux servers (ECS/Fargate), any attempts to put an object results in the exception "Request headers must contain only ASCII characters".

The PutRequest object passed to the call contains no user-added headers, so it would appear that the offending header entry is being added within the call. The call stack from the exception thrown is as follows:

at System.Net.Http.HttpConnection.g__ThrowForInvalidCharEncoding|56_0()
at System.Net.Http.HttpConnection.WriteString(String s, Encoding encoding)
at System.Net.Http.HttpConnection.WriteHeaderCollection(HttpHeaders headers, String cookiesFromContainer)
at System.Net.Http.HttpConnection.WriteHeaders(HttpRequestMessage request, HttpMethod normalizedMethod)
at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
at Amazon.Runtime.HttpWebRequestMessage.GetResponseAsync(CancellationToken cancellationToken)
at Amazon.Runtime.Internal.HttpHandler`1.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.RedirectHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.Unmarshaller.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.S3.Internal.AmazonS3ResponseHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.ErrorHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.ErrorHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.CallbackHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.Signer.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.S3.Internal.S3Express.S3ExpressPreSigner.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.EndpointDiscoveryHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.EndpointDiscoveryHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.CredentialsRetriever.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.RetryHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.RetryHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.CallbackHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.CallbackHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.S3.Internal.AmazonS3ExceptionHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.ErrorCallbackHandler.InvokeAsync[T](IExecutionContext executionContext)
at Amazon.Runtime.Internal.MetricsHandler.InvokeAsync[T](IExecutionContext executionContext)

Installed version of AWSSDK.S3 is 3.7.410.1, but I have tried the earlier version that worked with .NET 6 and still had the exception thrown.

Regression Issue

  • Select this option if this issue appears to be a regression.

Expected Behavior

Call to PutObjectAsync() should succeed

Current Behavior

Exception thrown "Request headers must contain only ASCII characters."

Reproduction Steps

Deploy .NET 8 based code to ECS/Fargate Linux instance; call fails

Possible Solution

No response

Additional Information/Context

No response

AWS .NET SDK and/or Package version used

AWSSDK.S3 3.7.410.1

Targeted .NET Platform

.NET 8

Operating System and version

ECS/Fargate Linux instance

@indimini indimini added bug This issue is a bug. needs-triage This issue or PR still needs to be triaged. labels Dec 10, 2024
@github-actions github-actions bot added the potential-regression Marking this issue as a potential regression to be checked by team member label Dec 10, 2024
@ashishdhingra
Copy link
Contributor

@indimini Good morning. Please share the following to troubleshoot the issue:

Thanks,
Ashish

@ashishdhingra ashishdhingra added response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. s3 p2 This is a standard priority issue and removed needs-triage This issue or PR still needs to be triaged. labels Dec 10, 2024
@indimini
Copy link
Author

@ashishdhingra - thanks for the quick response

  • Sample Code (Simplified):

      PutObjectRequest putRequest = new PutObjectRequest
      {
        BucketName = s3bucket,
        Key = s3key, // Use an Object Id so we don't have to modify any models.
        ContentBody = Convert.ToBase64String(bytes),
      };
      putRequest.Metadata.Add("contenttype", contentType);
      putRequest.Metadata.Add("uploadtime", DateTime.Now.ToString());
      putRequest.Metadata.Add("filename", HttpUtility.UrlEncode(fileName, Encoding.ASCII));
    
      PutObjectResponse response = await client.PutObjectAsync(putRequest);
    

This code works w/o issue on Windows, fails when deployed. I've verified that the putRequest.Headers object we pass to the put method has no entries.

  • Locale of Environment:
    Service ARN = arn:aws:ecs:us-east-1:834521116217:service-deployment/dev-cluster/jan2025-service/s-30HNRQCDVgxmBZwZlZr
    Operating System/Architecture = Linux/X86_64
    App Environment = Fargate
    Network mode = awsvpc

  • Logging/Throwing: We log any exceptions to our log collection in our DB, then throw the exception. Contents of call stack provided in original post; note, there is no Inner Exception for the caught exception.

  • Key or bucket names do not contain Non-ASCII characters. (Note, the code works without issue on Windows server, but fails only when deployed to Linux service in AWS/Fargate)

  • We are not using S3Express

  • I tried added the verbose logging but received no additional details. Again, since this doesn't fail in Development on Windows, there is nothing to capture. I did subclass the TraceListener and added code to capture any messages passed and store them in our log, but no messages were captured

@dscpinheiro
Copy link
Contributor

You'll need to run this on your ECS cluster as well, but can you add AWSConfigs.LoggingConfig.LogMetrics = true; to the commands @ashishdhingra mentioned earlier? That'll include the request the SDK sent to S3 (including the headers):

AWSConfigs.LoggingConfig.LogTo = LoggingOptions.Console;
AWSConfigs.LoggingConfig.LogMetricsFormat = LogMetricsFormatOption.JSON;
AWSConfigs.LoggingConfig.LogResponses = ResponseLoggingOption.Always;
AWSConfigs.LoggingConfig.LogMetrics = true;

using var client= new AmazonS3Client();
await client.ListBucketsAsync(...);

Example logs:

AmazonS3Client 31|2024-12-10T15:06:31.132Z|INFO|Request metrics: {"properties":{"AsyncCall":"True","CanonicalRequest":"GET\n/\n\nhost:s3.us-west-2.amazonaws.com\nuser-agent:aws-sdk-dotnet-coreclr/3.7.410.2 ua/2.0 os/windows#10.0.22631.0 md/ARCH#X64 lang/.NET_Core#8.0.11 md/aws-sdk-dotnet-core#3.7.400.60 api/S3#3.7.410.2 cfg/retry-mode#legacy md/ClientAsync cfg/init-coll#1\nx-amz-content-sha256:...\nx-amz-date:20241210T200630Z\n\nhost;user-agent;x-amz-content-sha256;x-amz-date","StringToSign":"AWS4-HMAC-SHA256\n20241210T200630Z\n20241210/us-west-2/s3/aws4_request","ServiceName":"AmazonS3","ServiceEndpoint":"https://s3.us-west-2.amazonaws.com/","MethodName":"ListBucketsRequest","AmzId2":"...","StatusCode":"OK","BytesProcessed":"0","AWSRequestID":"..."},"timings":{"CredentialsRequestTime":0.8868,"RequestSigningTime":22.3808,"HttpRequestTime":582.7608,"ResponseUnmarshallTime":13.1556,"ResponseProcessingTime":29.586,"ClientExecuteTime":731.1859},"counters":{}}

GET
/

host:s3.us-west-2.amazonaws.com
user-agent:aws-sdk-dotnet-coreclr/3.7.410.2 ua/2.0 os/windows#10.0.22631.0 md/ARCH#X64 lang/.NET_Core#8.0.11 md/aws-sdk-dotnet-core#3.7.400.60 api/S3#3.7.410.2 cfg/retry-mode#legacy md/ClientAsync cfg/init-coll#1
x-amz-content-sha256:...
x-amz-date:20241210T200630Z

The SDK tries to fetch some information from the environment to build the user-agent, so I'm wondering if something wasn't parsed correctly.

@dscpinheiro dscpinheiro removed the potential-regression Marking this issue as a potential regression to be checked by team member label Dec 10, 2024
@indimini
Copy link
Author

when I capture the logs in my dev environment, calling ListBucketsAsync(), I see the following:

Amazon Verbose: 0 : Received response (truncated to 1024 bytes): [
c761c404745ae5badbe4174a608b6f0aa44dedf93f48fd3dbc85233c6609eb1badminrootagent-installation-bucket-skillsmart2020-10-26T13:50:10.000Zaws-cloudtrail-logs-834521116217-1509af7d2021-03-24T12:38:44.000Zcdktoolkit-stagingbucket-1u82o2oum2n6l2021-12-06T19:23:46.000Zcodepipeline-us-east-1-9859142755782023-11-04T06:48:14.000Zconnect-e6e1ed35f3b82020-04-03T17:03:52.000Zelasticbeanstalk-us-east-1-8345211162172021-12-06T17:44:49.000Zinsight-amazon-root2022-07-16T14:48:46]
Amazon Information: 1 : Request metrics: {"properties":{"AsyncCall":"True","CanonicalRequest":"GET\n/\n\nhost:s3.amazonaws.com\nuser-agent:aws-sdk-dotnet-coreclr/3.7.410.1 ua/2.0 os/windows#10.0.26100.0 md/ARCH#X64 lang/.NET_Core#8.0.8 md/aws-sdk-dotnet-core#3.7.400.59 api/S3#3.7.410.1 cfg/retry-mode#legacy md/ClientAsync cfg/init-coll#1\nx-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855\nx-amz-date:20241210T204720Z\n\nhost;user-agent;x-amz-content-sha256;x-amz-date\ne3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855","StringToSign":"AWS4-HMAC-SHA256\n20241210T204720Z\n20241210/us-east-1/s3/aws4_request\n63e7d88314de300d448a0e3a83d8a3049e9b31ccc24e85477f0160e203b0b97d","ServiceName":"AmazonS3","ServiceEndpoint":"https://s3.amazonaws.com/","MethodName":"ListBucketsRequest","AmzId2":"ldgHVuZaIrdLG5uvKrVYaK09vnI0pN3b/L2gcDhdcwpdGOn9RPmdXcQtjk8+xSWR1u5pHmIrrcg=","StatusCode":"OK","BytesProcessed":"0","AWSRequestID":"FTRHRX67QS7ZMH3R"},"timings":{"CredentialsRequestTime":0.625,"RequestSigningTime":11.3467,"HttpRequestTime":241.7178,"ResponseUnmarshallTime":7.1743,"ResponseProcessingTime":14.2298,"ClientExecuteTime":320.0976},"counters":{}}

@github-actions github-actions bot removed the response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. label Dec 11, 2024
@ashishdhingra
Copy link
Contributor

@indimini Thanks for your reply. As @dscpinheiro mentioned, please collect logs from your ECS cluster as well. May be there is some extra header which is parsed by SDK which contains some characters not well handled.

Also share the .NET 8 version used on both your dev environment and ECS cluster. There was a known issue in some .NET version, so just curious if it popped back up in .NET 8 in certain version.

Thanks,
Ashish

@ashishdhingra ashishdhingra added the response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. label Dec 11, 2024
@indimini
Copy link
Author

@ashishdhingra - not sure how to get the logs from an ECS cluster. Any guidance is appreciated.

The file version of System.Net.Http (where the exception is originating) is V 8.0.824.36612.

@github-actions github-actions bot removed the response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. label Dec 12, 2024
@indimini
Copy link
Author

@ashishdhingra - not sure if this helps, but I replaced the client.putObjectAsync() call with using the FileTransferUtility and still end up with the same Non-ASCII header exception.

This is the code I tested with. This works when running on a Windows server (same behavior as the putObjectAsync())

    using MemoryStream ms = new MemoryStream(bytes);
    ms.Position = 0;
    Amazon.S3.Transfer.TransferUtility utility = new TransferUtility(client);
    TransferUtilityUploadRequest request = new TransferUtilityUploadRequest();
    request.BucketName = s3bucket;
    request.Key = s3key;
    request.ContentType = contentType;
    request.InputStream = ms;
    request.Metadata.Add("contenttype", contentType);
    request.Metadata.Add("uploadtime", DateTime.Now.ToString());
    request.Metadata.Add("filename", HttpUtility.UrlEncode(fileName, Encoding.UTF8));
    await utility.UploadAsync(request);

@ashishdhingra
Copy link
Contributor

@ashishdhingra - not sure if this helps, but I replaced the client.putObjectAsync() call with using the FileTransferUtility and still end up with the same Non-ASCII header exception.

This is the code I tested with. This works when running on a Windows server (same behavior as the putObjectAsync())

    using MemoryStream ms = new MemoryStream(bytes);
    ms.Position = 0;
    Amazon.S3.Transfer.TransferUtility utility = new TransferUtility(client);
    TransferUtilityUploadRequest request = new TransferUtilityUploadRequest();
    request.BucketName = s3bucket;
    request.Key = s3key;
    request.ContentType = contentType;
    request.InputStream = ms;
    request.Metadata.Add("contenttype", contentType);
    request.Metadata.Add("uploadtime", DateTime.Now.ToString());
    request.Metadata.Add("filename", HttpUtility.UrlEncode(fileName, Encoding.UTF8));
    await utility.UploadAsync(request);

@indimini TransferUtility uses underlying S3 client behind the scenes and uses PutObjectAsync() if file size is within the limit. Hence, the same exception. For capturing ECS logs, enabling verbose logging writes to console. Please refer Logging and Monitoring in Amazon Elastic Container Service, for sending logs to CloudWatch, you might need to configure awslogs log driver in your task definitions.

Thanks,
Ashish

@ashishdhingra ashishdhingra added the response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. label Dec 13, 2024
@Decavoid
Copy link
Contributor

Decavoid commented Dec 14, 2024

@indimini DateTime.Now.ToString() is culture-specific. Specify CultureInfo.InvariantCulture as a ToString() parameter.

@github-actions github-actions bot removed the response-requested Waiting on additional info and feedback. Will move to "closing-soon" in 7 days. label Dec 15, 2024
@indimini
Copy link
Author

Here are the Amazon logs from our ECS deployment:
Amazon Information: 0 : Region found using environment variable. Amazon Information: 0 : The environment variable AWS_ENABLE_ENDPOINT_DISCOVERY was not set with a value. Amazon Information: 1 : The environment variable AWS_MAX_ATTEMPTS was not set with a value. Amazon Information: 2 : The environment variable AWS_RETRY_MODE was not set with a value. Amazon Information: 3 : The environment variable AWS_EC2_METADATA_SERVICE_ENDPOINT was not set with a value. Amazon Information: 4 : The environment variable AWS_EC2_METADATA_SERVICE_ENDPOINT_MODE was not set with a value. Amazon Information: 5 : The environment variable AWS_EC2_METADATA_V1_DISABLED was not set with a value. Amazon Information: 6 : The environment variable AWS_USE_DUALSTACK_ENDPOINT was not set with a value. Amazon Information: 7 : The environment variable AWS_USE_FIPS_ENDPOINT was not set with a value. Amazon Information: 8 : The environment variable AWS_IGNORE_CONFIGURED_ENDPOINT_URLS was not set with a value. Amazon Information: 9 : The environment variable AWS_DISABLE_REQUEST_COMPRESSION was not set with a value. Amazon Information: 10 : The environment variable AWS_REQUEST_MIN_COMPRESSION_SIZE_BYTES was not set with a value. Amazon Information: 11 : The environment variable AWS_ACCOUNT_ID_ENDPOINT_MODE was not set with a value. Amazon Information: 12 : The environment variable AWS_SDK_UA_APP_ID was not set with a value. Amazon Information: 0 : Unable to find a profile named 'default' in store Amazon.Runtime.CredentialManagement.CredentialProfileStoreChain Amazon Information: 0 : Resolved DefaultConfigurationMode for RegionEndpoint [us-east-1] to [Legacy]. Amazon Verbose: 0 : Received response (truncated to 1024 bytes): [ c761c404745ae5badbe4174a608b6f0aa44dedf93f48fd3dbc85233c6609eb1badminrootagent-installation-bucket-skillsmart2020-10-26T13:50:10.000Zaws-cloudtrail-logs-834521116217-1509af7d2021-03-24T12:38:44.000Zcdktoolkit-stagingbucket-1u82o2oum2n6l2021-12-06T19:23:46.000Zcodepipeline-us-east-1-9859142755782023-11-04T06:48:14.000Zconnect-e6e1ed35f3b82020-04-03T17:03:52.000Zelasticbeanstalk-us-east-1-8345211162172021-12-06T17:44:49.000Zinsight-amazon-root2022-07-16T14:48:46] Amazon Information: 1 : Request metrics: {"properties":{"AsyncCall":"True","CanonicalRequest":"GET\n/\n\nhost:s3.amazonaws.com\nuser-agent:aws-sdk-dotnet-coreclr/3.7.410.5 ua/2.0 os/linux#5.10.228.219 md/ARCH#X64 lang/.NET_Core#8.0.11 exec-env/AWS_ECS_FARGATE md/aws-sdk-dotnet-core#3.7.400.63 api/S3#3.7.410.5 cfg/retry-mode#legacy md/ClientAsync cfg/init-coll#1\nx-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855\nx-amz-date:20241216T153949Z\nx-amz-security-token:IQoJb3JpZ2luX2VjEGgaCXVzLWVhc3QtMSJGMEQCIHsE0BcRcG83qkyjNS4C3Y2AwRJLd7F0uoSNS3tYatcfAiBzkLRXSacOzQ/f0Mb1ww0JBYDP7u2Ny0LZHdtVS3qZHirtAwgxEAAaDDgzNDUyMTExNjIxNyIMaAsnF0JTtaqTlw+gKsoDKf/UKO25Bv27IFrXHrA+ULy1E/SNp5H5D/aNuRDA6XEmSrwuSLfGNE9szcMgsbKAsRVY7CzTDKOVvVSH1+nx9Hzn0D4ragSSXXr6RHIX7/xKZsKEE4xu+R7jzgFiBzTt3TCl+jtKs1oOarnkMi8lL5LYX+/QwbEmx9XyRddfxZqoA0Ak+h9UPB4S/Ox1DvrCJrjn0e+rZauwLIcnt+nmLXlNpQSbKPfF9KcYhsevOjEZiYbSqrkkD3qNyH9tF5zX8QXe4jJOy6py5oY3wd9homRX9mJkehlc+0kfy7O/DPW/XglvYkTDjlTA9NhFsQ3O5ARnnP+2af82ObehT0vTjmRNHH61YABif+z82ryTjoQk3xtlAb8NDNE4OzgpQGA/lnzWlnsVHduTfEt2KT+icZsKtmT3X0XGSkeUTCgw9YqczyehyV9F+dosoZ7ypi8HsYytAotLmVrpVUSTgwlq/2WMfO8DtrL1Td3mikJDZHLyru5fPrB0Ve1ogbQwQuByh3+y//fO4b+UySufzmG0em7/js/Dba8E65pd6igKYtMTROwWZBVBkgrHraLrUca3UAMTgGnsoFY3FPevMzgq6WR7Dy/OgP0T/x0wwJGBuwY6pgFR6YcHH0qDXkv/8vTYTXkYbu2t63k8LjtDP7S4+5zSoA3PbPKkg4xHHoL+POetON7SofUskElcVjJ/ZvuuZA6q67qXaIuFnCTgqUW2oJHCnsBOs2YMWJdPMF4S6iKbyg1ZqAOPXrJbOZdHaQHgw4EwDq8/J+jEimvrTmsIFrHqollBn66EzIVOdXez+4PiQ2DPT9WCCd2E0P8Zmuafa2515/DyKm2K\n\nhost;user-agent;x-amz-content-sha256;x-amz-date;x-amz-security-token\ne3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855","StringToSign":"AWS4-HMAC-SHA256\n20241216T153949Z\n20241216/us-east-1/s3/aws4_request\nedb7588a98a4d2cc5c181acb83cd79305fcc0d0cf1d4749b86ffde1de80753c7","ServiceName":"AmazonS3","ServiceEndpoint":"https://s3.amazonaws.com/","MethodName":"ListBucketsRequest","AmzId2":"dzHDKOxY2TOpwNevEs7dVPHeC9oG1tikmUYlDnTnqMQUXCYbsTwoKPI/GccDzOF6YVVe2QaSX4kPJRKoaPF+oA==","StatusCode":"OK","BytesProcessed":"0","AWSRequestID":"3YB8ER2WGAQRRKF6"},"timings":{"CredentialsRequestTime":58.2079,"RequestSigningTime":18.1309,"HttpRequestTime":53.9272,"ResponseUnmarshallTime":14.189,"ResponseProcessingTime":18.5681,"ClientExecuteTime":234.2948},"counters":{}}

@indimini
Copy link
Author

If I try to capture results when making the put call, this is the only entry in the logs:
Amazon Verbose: 0 : Single encoded /WH-347/676054e67a39f1a8ff62fcfc with endpoint https://insight-next-dev-root.s3.amazonaws.com/ for canonicalization: /WH-347/676054e67a39f1a8ff62fcfc

@indimini
Copy link
Author

It appears that the CultureInfo to the date to staring method does resolve this issue.

Copy link

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.

@ashishdhingra ashishdhingra self-assigned this Dec 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug This issue is a bug. p2 This is a standard priority issue s3
Projects
None yet
Development

No branches or pull requests

4 participants