rails: ActiveStorage: invalid Attachment when last step of direct upload fails

I am trying to handle the case where the last step of a direct upload fails (the PATCH call to my model), and I have noticed an odd behaviour. Here goes:

Steps to reproduce

Set up the Profile model with has_one_attached :document.
Create an instance of Profile (referred to as profile)
Use a direct upload form to attach a document to profile (controller and view code below)
Everything works fine so far, I can see the image and its filename.
Force a failure in the PATCH call to /profile/document: intentionally modify a validation in the Profile model so that any call to Profile#update fails
Upload another document for the same Profile, and watch the PATCH fail.

Expected behavior

When this last step fails, I’d expect the whole state of my app to go back to its state from before the beginning of the upload process (the POST call to rails/active_storage/direct_uploads).

I’d also expect the former file to still be there on the storage, and the new one to not be there.

Actual behavior

The Attachment record for my Profile is still the same, but the original Blob was destroyed, and replaced by a new one (created by the first POST to rails/active_storage/direct_uploads). The Attachment points to the destroyed Blob.

profile.document.attached? returns true, but other methods, e.g. filename or service_url are undefined. This breaks my views: the if passes, the statements inside break.

S3/Disk contains the new file, and does not contain the former one.

The logs tell me that the first call from the client to /rails/active_storage/direct_uploads creates a Blob. Then, after the upload to S3 is done, the PATCH call to /profile/document destroys the former Attachment and creates a new one, but this is all rolled back when my validation fails. However, it also enqueues a job that purges the former Blob, instead of purging the newly created one.

From my understanding, what this job does should depend upon the success of the PATCH call. Is this an actual bug, or am I supposed to handle this manually? Or maybe there’s just another way to write things and make it work automagically?

One workaround I found is to call purge or detach on the document when the update fails. From a user’s point of view it removes the former document, which isn’t so nice, but at least my views don’t break. The Attachment is destroyed, the Blob remains, the former file is destroyed, the new one is stored. This fix is commented out in the code sample.

System configuration

I get the bug on my local environment, both with S3 and Disk as targets.

Rails version: Rails 5.2.0.rc1

Ruby version: ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-darwin17]

Code samples

Adapted for better readability.

class ProfilesController < ApplicationController
  def update
    if current_user.profile.update(document_params)
      flash[:notice] = "Your document was successfully uploaded"
    else
      # current_profile.reload.identity_document.purge # The fix
      flash[:alert] = "Something went wrong."
    end
    redirect_to my_form_url
  end

  private

  def document_params
    params.require(:profile).permit(:document)
  end
end

<% if @profile.document.attached? %>
    <%= @profile.document.filename %>
    <%= image_tag @profile.document %>
<% else %>
    No document yet
<% end %>

<%= form_for @profile do |f| %>
    <%= f.file_field :document, direct_upload: true %>
    <%= f.submit %>
<% end %>

Thanks in advance for your help!

About this issue

Original URL
State: open
Created 6 years ago
Reactions: 12
Comments: 16 (4 by maintainers)

Most upvoted comments

I found a similar issue (not using direct upload). I was going to raise it as a new issue, until I read yours. I’d already written up the whole issue report, so I’ve included it here. I feel they are caused by the same issue. I think my steps reproduce the issue in a simple way.

Attachment without Blob on update of record with validation error

When a record fails validation at the same time as updating an attachment, the old Blob is deleted and the Attachment exists in an orphaned state without its parent Blob.

Steps to reproduce

Create new rails app rails new.
Install ActiveStorage rails active_storage:install.
Create scaffolded model rails g scaffold user name:string.
Migrate db rails db:migrate.
Update User model with the following:

class User < ApplicationRecord
  validates :name, presence: true
  has_one_attached :avatar
end

Update app/views/users/_form.html.erb and add a basic file upload field:

<div class="field">
  <%= form.label :avatar %>
  <%= form.file_field :avatar %>
</div>

Add :avatar to permitted params in app/controllers/users_controller.rb:

def user_params
  params.require(:user).permit(:name, :avatar)
end

Use the scaffolded form to create a User with both a name and avatar (any file).
On submission, record saves correctly and attachment uploaded (as expected). See log below.
Use the edit form on the record just created, clear the name field, choose a new (different) file.
Submit the form and notice validation error on name (as expected). See log below.
There is now an Attachment for this User in an invalid state.

Expected behaviour

I would expect that due to a validation error on updating the User, the attached avatar should not change and remain as the original file (Blob with key XdCRghPAcU721RtB7ERgAjAT uploaded in step 9).

Inspecting the User record (expected):

irb> user = User.last
#=> #<User id: 1, name: "David", created_at: "2018-03-25 05:53:28", updated_at: "2018-03-25 05:53:28">
irb> user.avatar.attached?
#=> true
irb> user.avatar.attachment
#=> #<ActiveStorage::Attachment id: 1, name: "avatar", record_type: "User", record_id: 1, blob_id: 1, created_at: "2018-03-25 05:53:28">
irb> user.avatar.attachment.blob
#=> #<ActiveStorage::Blob id: 1, key: "XdCRghPAcU721RtB7ERgAjAT", filename: "0502-013.JPG", content_type: "image/jpeg", metadata: {"identified"=>true, "analyzed"=>true}, byte_size: 1029028, checksum: "LcqeZ9prqs/FHZSv89BnBQ==", created_at: "2018-03-25 05:53:28">
irb> ActiveStorage::Blob.count
#=> 1

Actual behavior

The transaction in step 11 rolled back reverting the User record and Attachment record. However, a PurgeJob still runs deleting the original Blob (key XdCRghPAcU721RtB7ERgAjAT).

The new attachment (uploaded in step 11) is added to storage with a key of duahAp6ATEsrAmnP2Ax5frLA and remains on disk but no Blob record exists pointing to this file.

Inspecting the User record (actual):

irb> user = User.last
#=> #<User id: 1, name: "David", created_at: "2018-03-25 05:53:28", updated_at: "2018-03-25 05:53:28">
irb> user.avatar.attached?
#=> true
irb> user.avatar.attachment
#=> #<ActiveStorage::Attachment id: 1, name: "avatar", record_type: "User", record_id: 1, blob_id: 1, created_at: "2018-03-25 05:53:28">
irb> user.avatar.attachment.blob
#=> nil
irb> ActiveStorage::Blob.count
#=> 0

System configuration

Rails version: 5.2.0.rc2

Ruby version: 2.4.2

Log from step 9

Started POST "/users" for 127.0.0.1 at 2018-03-25 16:53:28 +1100
Processing by UsersController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"8y48cZPyXOqWyF3b9a+8czgBbGr8TfhcSohP49blIT6PfNw4RM2RMcecdREk0RmH33y+qUjolDHR3RdGK2g1Cw==", "user"=>{"name"=>"David", "avatar"=>#<ActionDispatch::Http::UploadedFile:0x00007fd0bc2831f8 @tempfile=#<Tempfile:/tmp/RackMultipart20180325-22404-zzs4xp.JPG>, @original_filename="0502-013.JPG", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"user[avatar]\"; filename=\"0502-013.JPG\"\r\nContent-Type: image/jpeg\r\n">}, "commit"=>"Create User"}
  Disk Storage (3.2ms) Uploaded file to key: XdCRghPAcU721RtB7ERgAjAT (checksum: LcqeZ9prqs/FHZSv89BnBQ==)
   (0.1ms)  begin transaction
  ↳ app/controllers/users_controller.rb:27
  ActiveStorage::Blob Create (0.6ms)  INSERT INTO "active_storage_blobs" ("key", "filename", "content_type", "metadata", "byte_size", "checksum", "created_at") VALUES (?, ?, ?, ?, ?, ?, ?)  [["key", "XdCRghPAcU721RtB7ERgAjAT"], ["filename", "0502-013.JPG"], ["content_type", "image/jpeg"], ["metadata", "{\"identified\":true}"], ["byte_size", 1029028], ["checksum", "LcqeZ9prqs/FHZSv89BnBQ=="], ["created_at", "2018-03-25 05:53:28.421255"]]
  ↳ app/controllers/users_controller.rb:27
   (7.0ms)  commit transaction
  ↳ app/controllers/users_controller.rb:27
   (0.3ms)  begin transaction
  ↳ app/controllers/users_controller.rb:27
   (0.1ms)  commit transaction
  ↳ app/controllers/users_controller.rb:27
   (0.1ms)  begin transaction
  ↳ app/controllers/users_controller.rb:30
  User Create (1.6ms)  INSERT INTO "users" ("name", "created_at", "updated_at") VALUES (?, ?, ?)  [["name", "David"], ["created_at", "2018-03-25 05:53:28.447893"], ["updated_at", "2018-03-25 05:53:28.447893"]]
  ↳ app/controllers/users_controller.rb:30
  ActiveStorage::Attachment Create (0.2ms)  INSERT INTO "active_storage_attachments" ("name", "record_type", "record_id", "blob_id", "created_at") VALUES (?, ?, ?, ?, ?)  [["name", "avatar"], ["record_type", "User"], ["record_id", 1], ["blob_id", 1], ["created_at", "2018-03-25 05:53:28.451802"]]
  ↳ app/controllers/users_controller.rb:30
  User Update (0.1ms)  UPDATE "users" SET "updated_at" = ? WHERE "users"."id" = ?  [["updated_at", "2018-03-25 05:53:28.452930"], ["id", 1]]
  ↳ app/controllers/users_controller.rb:30
   (6.8ms)  commit transaction
  ↳ app/controllers/users_controller.rb:30
[ActiveJob] Enqueued ActiveStorage::AnalyzeJob (Job ID: 82133636-739c-4d09-bd54-3b758eea7a25) to Async(default) with arguments: #<GlobalID:0x00005579f0dccef8 @uri=#<URI::GID gid://active-storage/ActiveStorage::Blob/1>>
  ActiveStorage::Blob Load (0.2ms)  SELECT  "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
Redirected to http://localhost:3000/users/1
  ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
Completed 302 Found in 117ms (ActiveRecord: 17.9ms)


[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25] Performing ActiveStorage::AnalyzeJob (Job ID: 82133636-739c-4d09-bd54-3b758eea7a25) from Async(default) with arguments: #<GlobalID:0x00007fd0b8672ba0 @uri=#<URI::GID gid://active-storage/ActiveStorage::Blob/1>>
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25] Skipping image analysis because the mini_magick gem isn't installed
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]    (0.1ms)  begin transaction
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]   ActiveStorage::Blob Update (0.3ms)  UPDATE "active_storage_blobs" SET "metadata" = ? WHERE "active_storage_blobs"."id" = ?  [["metadata", "{\"identified\":true,\"analyzed\":true}"], ["id", 1]]
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]    (6.7ms)  commit transaction
Started GET "/users/1" for 127.0.0.1 at 2018-03-25 16:53:28 +1100
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
Processing by UsersController#show as HTML
[ActiveJob] [ActiveStorage::AnalyzeJob] [82133636-739c-4d09-bd54-3b758eea7a25] Performed ActiveStorage::AnalyzeJob (Job ID: 82133636-739c-4d09-bd54-3b758eea7a25) from Async(default) in 17.82ms
  Parameters: {"id"=>"1"}
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:67
  Rendering users/show.html.erb within layouts/application
  Rendered users/show.html.erb within layouts/application (0.5ms)
Completed 200 OK in 30ms (Views: 27.1ms | ActiveRecord: 0.2ms)

Log from step 11

Started PATCH "/users/1" for 127.0.0.1 at 2018-03-25 16:56:05 +1100
Processing by UsersController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"BnJJG9fKS31dBABlx+CPA/1m44WwYhUO7JrK3ViSNxPqIR6cRKmMYpNpiuDepoacbMQKIvfU6QXs7/FKiSMwJg==", "user"=>{"name"=>"", "avatar"=>#<ActionDispatch::Http::UploadedFile:0x00007fd0b93cb7e8 @tempfile=#<Tempfile:/tmp/RackMultipart20180325-22404-13m7d71.JPG>, @original_filename="0502-001.JPG", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"user[avatar]\"; filename=\"0502-001.JPG\"\r\nContent-Type: image/jpeg\r\n">}, "commit"=>"Update User", "id"=>"1"}
  User Load (0.6ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:67
   (0.4ms)  begin transaction
  ↳ app/controllers/users_controller.rb:44
  ActiveStorage::Attachment Load (0.6ms)  SELECT  "active_storage_attachments".* FROM "active_storage_attachments" WHERE "active_storage_attachments"."record_id" = ? AND "active_storage_attachments"."record_type" = ? AND "active_storage_attachments"."name" = ? LIMIT ?  [["record_id", 1], ["record_type", "User"], ["name", "avatar"], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:44
  ActiveStorage::Blob Load (0.1ms)  SELECT  "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
  ↳ app/controllers/users_controller.rb:44
  Disk Storage (4.5ms) Uploaded file to key: duahAp6ATEsrAmnP2Ax5frLA (checksum: Gr6Z7GGbU4ci/2OTwTKVNw==)
  ActiveStorage::Blob Create (0.6ms)  INSERT INTO "active_storage_blobs" ("key", "filename", "content_type", "metadata", "byte_size", "checksum", "created_at") VALUES (?, ?, ?, ?, ?, ?, ?)  [["key", "duahAp6ATEsrAmnP2Ax5frLA"], ["filename", "0502-001.JPG"], ["content_type", "image/jpeg"], ["metadata", "{\"identified\":true}"], ["byte_size", 575122], ["checksum", "Gr6Z7GGbU4ci/2OTwTKVNw=="], ["created_at", "2018-03-25 05:56:05.648143"]]
  ↳ app/controllers/users_controller.rb:44
  ActiveStorage::Attachment Destroy (0.1ms)  DELETE FROM "active_storage_attachments" WHERE "active_storage_attachments"."id" = ?  [["id", 1]]
  ↳ app/controllers/users_controller.rb:44
  ActiveStorage::Attachment Create (0.1ms)  INSERT INTO "active_storage_attachments" ("name", "record_type", "record_id", "blob_id", "created_at") VALUES (?, ?, ?, ?, ?)  [["name", "avatar"], ["record_type", "User"], ["record_id", 1], ["blob_id", 2], ["created_at", "2018-03-25 05:56:05.652456"]]
  ↳ app/controllers/users_controller.rb:44
[ActiveJob] Enqueued ActiveStorage::PurgeJob (Job ID: fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c) to Async(default) with arguments: #<GlobalID:0x00007fd0b9f098d0 @uri=#<URI::GID gid://active-storage/ActiveStorage::Blob/1>>
  ActiveStorage::Blob Load (0.1ms)  SELECT  "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
   (0.2ms)  rollback transaction
  ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
  ↳ app/controllers/users_controller.rb:44
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c] Performing ActiveStorage::PurgeJob (Job ID: fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c) from Async(default) with arguments: #<GlobalID:0x00007fd0ba00cac0 @uri=#<URI::GID gid://active-storage/ActiveStorage::Blob/1>>
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   Disk Storage (0.2ms) Deleted file from key: XdCRghPAcU721RtB7ERgAjAT
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   Disk Storage (0.0ms) Deleted files by key prefix: variants/XdCRghPAcU721RtB7ERgAjAT/
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]    (0.1ms)  begin transaction
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
  Rendering users/edit.html.erb within layouts/application
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ActiveStorage::Blob Destroy (0.2ms)  DELETE FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = ?  [["id", 1]]
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
  Rendered users/_form.html.erb (2.5ms)
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]    (13.5ms)  commit transaction
  Rendered users/edit.html.erb within layouts/application (19.4ms)
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ActiveStorage::Attachment Load (0.2ms)  SELECT  "active_storage_attachments".* FROM "active_storage_attachments" WHERE "active_storage_attachments"."record_id" = ? AND "active_storage_attachments"."record_type" = ? AND "active_storage_attachments"."name" = ? LIMIT ?  [["record_id", 1], ["record_type", "ActiveStorage::Blob"], ["name", "preview_image"], ["LIMIT", 1]]
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c]   ↳ /home/dtcristo/.gem/ruby/2.4.2/gems/activerecord-5.2.0.rc2/lib/active_record/log_subscriber.rb:98
[ActiveJob] [ActiveStorage::PurgeJob] [fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c] Performed ActiveStorage::PurgeJob (Job ID: fe8e1fd7-d2c2-4987-9f35-47b8a5f1fb7c) from Async(default) in 55.0ms
Completed 200 OK in 100ms (Views: 59.0ms | ActiveRecord: 2.7ms)

+16

dtcristo on Mar 25, 2018

Good thing it’s almost 2020 and I’m still running into this 🤦‍♂

+15

bjgaynor on Dec 18, 2019

It’s now 2021…

+12

onhout on Feb 3, 2021

Helloooo 2022!

ChillyHoney on Jan 14, 2022

It’s the end of 2020…

NARKOZ on Nov 25, 2020

It’s the middle of 2020, but I’m still stuck by this.

paulleoniuk on Aug 9, 2020

Instead of reciting to us what year it is, how about providing additional detail about the situation that may have been missing from this thread? 🙇

“Me too” comments are unhelpful, which is why GitHub added the emoji reactions. This does help us identify issues that are impacting more people than we may realize. I don’t want to invalidate your experiences, I know it can be frustrating to end up on a GH issue that is several years old. 🙏

The last productive comment was nearly 5 years ago, which references multiple workarounds and even a fix landing in Rails 6.

Are the people experiencing this issue still on Rails 5? Have you tried the various workarounds mentioned here? Can you provide an executable test case against main?

zzak on Feb 16, 2023

It’s the end of 2021… I’m here

willy-wonka-git on Dec 5, 2021

I have the same issue as @dtcristo. Apparently it is fixed in Rails 6 (https://github.com/rails/rails/issues/32449#issuecomment-404938746), but still very annoying now.

The workaround suggested by @SimonFrr doesn’t work for me. The file remains corrupted. It seems like it isn’t purged when the update fails (when there is no save performed due to a validation error).

A workaround would be to check everywhere you use the file is to check whether the blob is present (model.upload.blog.present?), similar to the workaround suggested by @michaelschmitz in the other issue (which didn’t work for me). However it is annoying to have to think of it everywhere you use the file. And still you wouldn’t expect the file to disappear immediately when there is a validation error on some other field (and the model isn’t actually updated).

kreintjes on Nov 23, 2018

I’ve been seeing this same issue when an update validation fails at the same time as a new image is uploaded. I believe it is because the has_one_attached macro does:

        def #{name}=(attachable)
          #{name}.attach(attachable)
        end

and this occurs before validation. (The has_many_attached macro is coded similarly.)

Specifically, the new attachment change is rolled back in the transaction, but the PurgeJob still destroys the old blob.

CodingAnarchy on Jun 6, 2018

We are seeing a slightly different issue, albeit related: If a model fails validation upon submit, the image attached to it is still being uploaded. Obviously, we have no record of it now, but the bucket still gets the image. GCS and S3 are configured as mirrors; S3 is primary. The image shows up in GCS.

martinstreicher on Apr 6, 2018

Hello from 2023

tagrudev on Feb 15, 2023

Its 2022 are there any workarounds

toddhow on Oct 29, 2022

Hey Mid 2022!!

achref-rassas on Aug 24, 2022

Hi @JoseMPena, I haven’t investigated further. Will keep you posted if I find something.

SimonFrr on Mar 5, 2018