Menu
When running feature Rspecs, I receive the following error (full trace at the bottom of this message)
Rack app error handling request { GET /rails/active_storage/disk/eyJfcmFpbHMiOnsibWVzc2FnZSI6IkJBaDdDRG9JYTJWNVNTSm5kbUZ5YVdGdWRITXZSM0IxTkRGRFRWQlFaVXRNYVUxaVpuQjZXVmw1UTNBMUx6RXhNR1V3TVRka01UWTVNalZrWXpkak5UQTNNamhqT1dNeE5UUmhOREl3TURjNVlXRTJaVFZtWTJNME16VmtZak5sTm1VNU4ySXhNemd3WldObFl6Z0dPZ1pGVkRvUVpHbHpjRzl6YVhScGIyNUpJajFwYm14cGJtVTdJR1pwYkdWdVlXMWxQU0pwYldGblpTNXdibWNpT3lCbWFXeGxibUZ0WlNvOVZWUkdMVGduSjJsdFlXZGxMbkJ1WndZN0JsUTZFV052Ym5SbGJuUmZkSGx3WlVraURtbHRZV2RsTDNCdVp3WTdCbFE9IiwiZXhwIjoiMjAxOS0wMS0yNVQxMToxNjoyOS40NDBaIiwicHVyIjoiYmxvYl9rZXkifX0=--db9451afdc95b292aa6a77c40e00ab0ceb687766/image.png }
#<Errno::ENOENT: No such file or directory @ rb_file_s_mtime - /path/to/rails/app/tmp/storage/va/ri/variants/Gpu41CMPPeKLiMbfpzYYyCp5/110e017d16925dc7c50728c9c154a420079aa6e5fcc435db3e6e97b1380ecec8>
(followed by the full trace at the end of this message)
Failure/Error: last_modified = ::File.mtime(path).httpdate
Errno::ENOENT:
No such file or directory @ rb_file_s_mtime - /path/to/rails/app/tmp/storage/va/ri/variants/Gpu41CMPPeKLiMbfpzYYyCp5/110e017d16925dc7c50728c9c154a420079aa6e5fcc435db3e6e97b1380ecec8
(followed by the full trace at the end of this message)
product.image is an ActiveStorage attachment. During the test the "products/_form" partial is rendered and is displaying the attachment file (namely a png image) with the following code: = image_tag url_for(product.image.variant(resize: "120x120")). If I comment out this line, the error does not occur anymore.
The test itself succeed every times, the error seems to be triggered after the test. I verified all my after blocks, it seems to happen after all my after blocks.
The trace indicates that ActiveStorage::DiskController.serve_file triggers the errors. Is it that ActiveStorage app is not shutting down gracefully ?
I'm using active_storage.service = :test configuration, but :file gives the same errors.
While a test fail, I can see in the "remote controlled" browser that the image is not display and there is a broken image icon instead.
There is a group of 4 featured tests that are going through the render of the "products/_form" partial. When I run the 4 tests in a random order the error occurs randomly. Sometime I can see the error 2 times, sometimes 3 times.
when I run the tests individually the error does never appear.
This is the helper I use to attach the file to the model before going through the test :
path = Rails.root.join 'spec', 'support', 'fixtures', 'img1.png'
raise 'Image does not exist' unless File.exist? path
product.image.attach io: File.open(path), filename: 'image.png'
I also tried to use this helper :
path = Rails.root.join 'spec', 'support', 'fixtures', 'img1.png'
raise 'Image does not exist' unless File.exist? path
blob = ActiveStorage::Blob.create_after_upload! io: path.open, \
filename: 'img1.png', content_type: 'image/png'
product.images.attach blob
And this helper :
path = Rails.root.join 'spec', 'support', 'fixtures', 'img1.png'
raise 'Image does not exist' unless File.exist? path
byte_size = path.size
checksum = Digest::MD5.file(path).base64digest
blob = ActiveStorage::Blob.create_before_direct_upload!(filename: 'img1.png', \
byte_size: byte_size, checksum: checksum, content_type: 'image/png').tap do |blob|
ActiveStorage::Blob.service.upload(blob.key, path.open)
end
product.images.attach blob
Rails version: 5.2.2
Ruby version: ruby 2.5.3p105 (2018-10-18 revision 65156) [x86_64-linux]
Rbenv version: rbenv 1.1.1-39-g59785f6
Rspec related versions: rspec 3.8.0 - capybara 3.12.0 - selenium-webdriver 3.141.0
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/file.rb:63:in `mtime'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/file.rb:63:in `serving'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activestorage-5.2.2/app/controllers/active_storage/disk_controller.rb:42:in `serve_file'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activestorage-5.2.2/app/controllers/active_storage/disk_controller.rb:12:in `show'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:194:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/rendering.rb:30:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:132:in `run_callbacks'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/abstract_controller/callbacks.rb:41:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/rescue.rb:22:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `block in instrument'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/notifications.rb:168:in `instrument'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activerecord-5.2.2/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/abstract_controller/base.rb:134:in `process'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionview-5.2.2/lib/action_view/rendering.rb:32:in `process'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal.rb:191:in `dispatch'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_controller/metal.rb:252:in `dispatch'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:34:in `serve'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:52:in `block in serve'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `each'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/journey/router.rb:35:in `serve'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/routing/route_set.rb:840:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/tempfile_reaper.rb:15:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/etag.rb:25:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/conditional_get.rb:25:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/head.rb:12:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:232:in `context'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/session/abstract/id.rb:226:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/cookies.rb:670:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/callbacks.rb:98:in `run_callbacks'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:38:in `call_app'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:26:in `block in call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `block in tagged'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:28:in `tagged'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/tagged_logging.rb:71:in `tagged'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/railties-5.2.2/lib/rails/rack/logger.rb:26:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/request_id.rb:27:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/method_override.rb:22:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/runtime.rb:22:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/activesupport-5.2.2/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/actionpack-5.2.2/lib/action_dispatch/middleware/static.rb:127:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/sendfile.rb:111:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/railties-5.2.2/lib/rails/engine.rb:524:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/urlmap.rb:68:in `block in call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/urlmap.rb:53:in `each'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/rack-2.0.6/lib/rack/urlmap.rb:53:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/capybara-3.12.0/lib/capybara/server/middleware.rb:48:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/puma-3.12.0/lib/puma/configuration.rb:225:in `call'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/puma-3.12.0/lib/puma/server.rb:658:in `handle_request'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/puma-3.12.0/lib/puma/server.rb:472:in `process_client'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/puma-3.12.0/lib/puma/server.rb:332:in `block in run'
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/puma-3.12.0/lib/puma/thread_pool.rb:133:in `block in spawn_thread'
#
# Showing full backtrace because every line was filtered out.
# See docs for RSpec::Configuration#backtrace_exclusion_patterns and
# RSpec::Configuration#backtrace_inclusion_patterns for more information.
# ------------------
# --- Caused by: ---
# Capybara::CapybaraError:
# Your application server raised an error - It has been raised in your test code because Capybara.raise_server_errors == true
# /opt/rbenv/versions/2.5.3/lib/ruby/gems/2.5.0/gems/capybara-3.12.0/lib/capybara/session.rb:147:in `raise_server_error!'
(Sorry for being silent, I had an emergency to attend to)
Here is an interesting information. I inserted after this line, this code: puts "SERVING #{path} - Exist ? #{File.exist? path}"
And here is the output (observe the files names and the boolean value at the end of each line):
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Me/GK/MeGKkqgbb7Sg4RbPoCYWR6pZ - Exist ? true
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/sG/3v/sG3vd2viGWmaf69pNXSChZPa - Exist ? true
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/fy/2C/fy2C8PpaR96YgCzwt5WVBLrQ - Exist ? true
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/sG/3v/sG3vd2viGWmaf69pNXSChZPa - Exist ? true
. (green dot)
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Me/GK/MeGKkqgbb7Sg4RbPoCYWR6pZ - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/sG/3v/sG3vd2viGWmaf69pNXSChZPa - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Me/GK/MeGKkqgbb7Sg4RbPoCYWR6pZ - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/fy/2C/fy2C8PpaR96YgCzwt5WVBLrQ - Exist ? false
F (red F)
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Me/GK/MeGKkqgbb7Sg4RbPoCYWR6pZ - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/sG/3v/sG3vd2viGWmaf69pNXSChZPa - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Me/GK/MeGKkqgbb7Sg4RbPoCYWR6pZ - Exist ? false
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/fy/2C/fy2C8PpaR96YgCzwt5WVBLrQ - Exist ? false
F (red F)
SERVING /tmp/active_storage_tests20190129-10797-1rebdf7/Tx/DL/TxDLPEk3ykf8ETkURY5YZPgY - Exist ? true
As we can see the files path are the same, even between tests. Tough the database is cleaned between each tests. So there is "somewhere" where the file checksum is kept, for activestorage to reuse the same blob record. As a result it reuse the same file path and that's the reason why I have a FileNotFound error.
Any idea ? Please note that, additionally to DatabaseCleaner, I have an after block defined like this :
config.after(:each) do
ActiveStorage::Current.reset
ActiveStorage::Attachment.all.each(&:delete)
ActiveStorage::Blob.all.each(&:delete)
end
Filled a PR with an application to reproduce https://github.com/rails/rails/issues/34989
Waiting for them response
536
The fact that the test passes just means that the test does not depend on that image being found. A broken image link will not generally cause a test to fail and it is in fact often the case that test writers do not even bother to supply mock images because it is (perceived to be) too much work and not relevant to the thing being tested.
See folks, this is why we ask for an example. Now that the OP has posted an example, we can see that his problem is browser caching, and will be solved by replacing
product.images.attach io: File.open(path), filename: 'image.png'
with
product.images.attach io: File.open(path), filename: "image-#{Time.now.strftime("%s%L")}.png"
in the helper that does the attachment. I would not have solved this without having the example.
ActiveStorage handles saving and serving files. OP was saving and serving images with it, which is definitely what it was intended for. In order to allow for different services to serve files in different ways, ActiveStorage separates the published URL from the actual image serving URL.
The published URL is almost a permalink: it is an encoded version of the database key for the attachment. ActiveStorage processes a request for the URL by looking up where the file is stored and sending a 302 temporary redirect to the URL that can be used to access the file, called a "service URL". When using AWS S3 to store files, the service URL can be a signed URL that expires quickly but nevertheless connects the browser directly to S3 rather than having to go through the web server as intermediary.
By default, the service URL is good for 5 minutes, and ActiveRecord explicitly sets
Cache-Control: max-age=300, private
on the 302 redirect. The browser caches this redirect response and for the next 5 minutes the browser will not even attempt to use or verify the published URL, it will immediately replace the public URL with the cached service URL.
Unfortunately, while the public URL is predictably recreated, the service URL is randomly generated, so when the browser does its automatic redirection, the previously valid service URL no longer works. The solution (or workaround, depending on your point of view) is to distinguish the public URLs by including a timestamp in the filename, so that tests will not reuse public URLs.
Sidenote
By the way, you should not be using url_for with image_tag. Change your ERB from
= image_tag url_for(product.image.variant(resize: "120x120"))
to
= image_tag(product.image.variant(resize: "120x120"))
Rails is smart enough to handle either case, but the latter way is the recommended way.
103
Something is likely off with how you're setting up the image that you're testing against. You might want to update that to how the Rails team handles it in their own tests:
module ActiveStorageHelpers
# ported from https://github.com/rails/rails/blob/5-2-stable/activestorage/test/test_helper.rb#L57
def create_file_blob(filename: "image.jpg", content_type: "image/jpeg", metadata: nil)
ActiveStorage::Blob.create_after_upload! io: file_fixture(filename).open, filename: filename, content_type: content_type, metadata: metadata
end
end
RSpec.configure do |config|
config.include ActiveStorageHelpers
end
Then place a tiny image file in spec/fixtures/file/images.jpg (that's where the file_fixture method will look for it).
With that in place, you can setup the image on your model in your feature test with something like:
instance_of_model.images.attach(create_file_blob)
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
