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

Error when uploading a file to ActiveStorage from a request body #3163

Open
1 task done
adamdebono opened this issue Jan 9, 2025 · 4 comments
Open
1 task done

Error when uploading a file to ActiveStorage from a request body #3163

adamdebono opened this issue Jan 9, 2025 · 4 comments
Labels
bug This issue is a bug. needs-triage This issue or PR still needs to be triaged. potential-regression Marking this issue as a potential regression to be checked by team member

Comments

@adamdebono
Copy link

Describe the bug

I am receiving an uploaded file as the request body in a Rails request, which I am then forwarding directly to ActiveStorage which uses S3 as it's backend.

Regression Issue

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

Expected Behavior

The file should be uploaded correctly to S3.

Current Behavior

An error occurs when the AWS SDK is trying to create a log of the upload. Without too much digging, it appears that it is trying to retrieve file information for the request body, which may not be an actual file on disk, rather a different sort of I/O object.

Stack trace below:

gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:61:in `File.size': No such file or directory @ rb_file_s_size - /tmp/puma20250109-55-6s7703 (Errno::ENOENT)
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:61:in `Aws::Log::ParamFormatter#summarize_file'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:54:in `Aws::Log::ParamFormatter#summarize_value'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:31:in `block in Aws::Log::ParamFormatter#summarize_symbol_hash'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:30:in `Hash#each'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:30:in `Enumerable#map'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:30:in `Aws::Log::ParamFormatter#summarize_symbol_hash'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:26:in `Aws::Log::ParamFormatter#summarize_hash'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/param_formatter.rb:18:in `Aws::Log::ParamFormatter#summarize'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/formatter.rb:136:in `Aws::Log::Formatter#_request_params'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/formatter.rb:107:in `block in Aws::Log::Formatter#format'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/formatter.rb:107:in `String#gsub'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/log/formatter.rb:107:in `Aws::Log::Formatter#format'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/logging.rb:62:in `Aws::Plugins::Logging::Handler#format'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/logging.rb:55:in `Aws::Plugins::Logging::Handler#log'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/logging.rb:45:in `block in Aws::Plugins::Logging::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/logging.rb:43:in `Aws::Plugins::Logging::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/seahorse/client/plugins/raise_response_errors.rb:16:in `Seahorse::Client::Plugins::RaiseResponseErrors::Handler#call'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/plugins/sse_cpk.rb:24:in `Aws::S3::Plugins::SseCpk::Handler#call'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/plugins/dualstack.rb:21:in `Aws::S3::Plugins::Dualstack::OptionHandler#call'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/plugins/accelerate.rb:43:in `Aws::S3::Plugins::Accelerate::OptionHandler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/checksum_algorithm.rb:111:in `Aws::Plugins::ChecksumAlgorithm::OptionHandler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/jsonvalue_converter.rb:16:in `Aws::Plugins::JsonvalueConverter::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/invocation_id.rb:16:in `Aws::Plugins::InvocationId::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/idempotency_token.rb:19:in `Aws::Plugins::IdempotencyToken::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/param_converter.rb:26:in `Aws::Plugins::ParamConverter::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/seahorse/client/plugins/request_callback.rb:89:in `Seahorse::Client::Plugins::RequestCallback::OptionHandler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/response_paging.rb:12:in `Aws::Plugins::ResponsePaging::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/seahorse/client/plugins/response_target.rb:24:in `Seahorse::Client::Plugins::ResponseTarget::Handler#call'
    from gems/aws-sdk-rails-5.1.0/lib/aws/rails/notifications.rb:22:in `block in Aws::Rails::Notifications::Handler#call'
    from gems/activesupport-8.0.1/lib/active_support/notifications.rb:212:in `ActiveSupport::Notifications.instrument'
    from gems/aws-sdk-rails-5.1.0/lib/aws/rails/notifications.rb:21:in `Aws::Rails::Notifications::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/telemetry.rb:39:in `block in Aws::Plugins::Telemetry::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/telemetry/no_op.rb:29:in `Aws::Telemetry::NoOpTracer#in_span'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/telemetry.rb:53:in `Aws::Plugins::Telemetry::Handler#span_wrapper'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/telemetry.rb:39:in `Aws::Plugins::Telemetry::Handler#call'
    from gems/aws-sdk-core-3.214.1/lib/seahorse/client/request.rb:72:in `Seahorse::Client::Request#send_request'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/client.rb:17185:in `Aws::S3::Client#put_object'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/object.rb:2956:in `block in Aws::S3::Object#put'
    from gems/aws-sdk-core-3.214.1/lib/aws-sdk-core/plugins/user_agent.rb:60:in `Aws::Plugins::UserAgent.metric'
    from gems/aws-sdk-s3-1.177.0/lib/aws-sdk-s3/object.rb:2955:in `Aws::S3::Object#put'
    from gems/activestorage-8.0.1/lib/active_storage/service/s3_service.rb:134:in `ActiveStorage::Service::S3Service#upload_with_single_part'
    from gems/activestorage-8.0.1/lib/active_storage/service/s3_service.rb:33:in `block in ActiveStorage::Service::S3Service#upload'
    from gems/activesupport-8.0.1/lib/active_support/notifications.rb:210:in `block in ActiveSupport::Notifications.instrument'
    from gems/activesupport-8.0.1/lib/active_support/notifications/instrumenter.rb:58:in `ActiveSupport::Notifications::Instrumenter#instrument'
    from gems/activesupport-8.0.1/lib/active_support/notifications.rb:210:in `ActiveSupport::Notifications.instrument'
    from gems/activestorage-8.0.1/lib/active_storage/service.rb:165:in `ActiveStorage::Service#instrument'
    from gems/activestorage-8.0.1/lib/active_storage/service/s3_service.rb:29:in `ActiveStorage::Service::S3Service#upload'
    from gems/activestorage-8.0.1models/active_storage/blob.rb:272:in `ActiveStorage::Blob#upload_without_unfurling'
    from gems/activestorage-8.0.1models/active_storage/blob.rb:97:in `block in ActiveStorage::Blob.create_and_upload!'
    from gems/activestorage-8.0.1models/active_storage/blob.rb:96:in `ActiveStorage::Blob.create_and_upload!'

Reproduction Steps

My controller code is as follows:

def upload
  filename = params.require!(:filename)
  blob = ActiveStorage::Blob.create_and_upload!(io: request.body, filename:)
end

Possible Solution

I have patched the SDK with the following code as a workaround:

module AwsLogParamFormatter
  def summarize_file path
    return "#<File:#{path} (doesn't exist)>" unless File.exist?(path)

    super
  end
end

Aws::Log::ParamFormatter.prepend(AwsLogParamFormatter)

That produces log entries as follows:

[Aws::S3::Client 200 0.258169 0 retries] put_object(body:#<File:/tmp/puma20250109-54-doexe9 (doesn't exist)>,content_md5:"bHguYZMIx/15yEM5wVhsSQ==",content_type:"application/pdf",content_disposition:nil,metadata:{},bucket:"bucket-name",key:"5yk6v4wfea7vgox7aqkv72dbi251")

Additional Information/Context

This has begun happening after upgrading to the latest version of Ruby, Rails and the SDK, so while I've marked it as a regression it may have been caused by Ruby or Rails.

Gem name ('aws-sdk', 'aws-sdk-resources' or service gems like 'aws-sdk-s3') and its version

aws-sdk-core 3.214.1, aws-sdk-s3 1.177.0

Environment details (Version of Ruby, OS environment)

Ruby 3.4.1, Rails 8.0.1

@adamdebono adamdebono added bug This issue is a bug. needs-triage This issue or PR still needs to be triaged. labels Jan 9, 2025
@github-actions github-actions bot added the potential-regression Marking this issue as a potential regression to be checked by team member label Jan 9, 2025
@alextwoods
Copy link
Contributor

What versions of Rails and the SDK did you upgrade from? The behavior of the log formatter for file summary has not changed for a long time (I think in ~10 years). It is interesting that the file does not exist - I'm guessing it could still be valid since the logging is done after the request is actually sent (possibly reading the entire file triggers its deletion?). I'm not sure on the details on the rails/active storage side.

@adamdebono
Copy link
Author

It was Ruby 3.3.5 and Rails 7.1.3.2, but I've done a bit more testing and narrowed it down to the puma gem which was updated from 6.4.2 to 6.5.0.

On the previous version, request.body is a Tempfile, whereas now it is a File instance. I've added a couple of output statements before calling for the ActiveStorage, which produces some interesting output:

def upload
  filename = params.require!(:filename)

  p request.body.class
  p request.body.read
  p request.body.size
  p File.exist?(request.body.path)
  blob = ActiveStorage::Blob.create_and_upload!(io: request.body, filename:)
end

# => File
# => <the file contents>
# => 123456
# => false

I don't understand what's going on here, because I don't see why it should be possible to write contents to a file without it existing on disk. I've created an issue in the Puma repo to see if there's a solution there.

@alextwoods
Copy link
Contributor

Yeah, thats strange - can you link the Puma issue here as well?

@adamdebono
Copy link
Author

Here is the discussion - puma/puma#3597

The "missing" file is completely legitimate - basically on linux you can create a Tempfile, and immediately remove the pointer from the filesystem, but it won't delete the data until the handle is closed.

That being the case, we can still determine the file size from that file instance, so we could update the following code in the param formatter:

# gems/aws-sdk-core/lib/aws-sdk-core/log/param_formatter.rb
def summarize_value(value)
  case value
  when String   then summarize_string(value)
  when Hash     then '{' + summarize_hash(value) + '}'
  when Array    then summarize_array(value)
  when File     then summarize_file(value)
  when Pathname then summarize_filepath(value)
  else value.inspect
  end
end

def summarize_file(file)
  "#<File:#{file.path} (#{file.size} bytes)>"
end

def summarize_filepath(path)
  "#<File:#{path} (#{File.size(path)} bytes)>"
end

If that seems reasonable I can raise a PR.

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. needs-triage This issue or PR still needs to be triaged. potential-regression Marking this issue as a potential regression to be checked by team member
Projects
None yet
Development

No branches or pull requests

2 participants