Shrine: IOError - Closed Stream

[vital-edu]

Configurations:

Rails 5.0
Ruby: 2.3.1
Shrine with plugins:

• activerecord,
• cached_attachment_data
• direct_upload, presign: true
• determine_mime_type

That always happen when I save the record. The file is upload to the Cloudinary in cache mode only, and the exceptions above is reache.

[janko]

@vital-edu Could you post here you uploader, controller, and any other Shine-related code?

[janko]

If you're using versions, the issue is likely that you have two versions which are the same Ruby object. Since Shrine closes each file it uploads, it will raise an error because the same file will attempted to be closed twice (see https://github.com/janko-m/shrine/issues/106).

It would probably be good to add some detection for that to the versions plugin, to raise a descriptive error if two versions are the same Ruby object. Because the main scenario when this happens is because of a mistake in processing code.

I think this wouldn't limit functionality, because even if someone wanted to do it intentionally, it is not guaranteed that this will always work. Because even if Shrine didn't close uploaded files and rewinded them instead, some storage gems will automatically close the file after upload (the only one that currently does that is coincidentally the cloudinary_gem), and once a file is closed it cannot be reopened (been there, done that). I will work on adding this error.

[vital-edu]

I am not using the plugin Versions.

All my project it is open, but I will let here the files that I judge important:

• initializers/shrine.rb
• models/service-category
• service_categories_controller
• service_categories/_form
• Gemfile

I thought that could be the SimpleForm gem but I already replaced the code in _form.html.erb to the default form_for of the rails and the problem still happened.

[janko]

@vital-edu Thanks, I will investigate. In the meanwhile, could you also post the backtrace?

[janko]

@vital-edu I'm not able to get your app working, as there are too many things to set up, which is to be expected. I've tried creating a minimal app to reproduce the bug (I used Roda, because I couldn't get Rails to work, it couldn't find the database table), but the upload was successful.

So I would definitely need a backtrace, and if I don't see anything there, I would need you to produce a minimal app that reproduces the problem.

[vital-edu]

This is the whole backtrace.
The get in the form and the post followed by the error:

I'am sorry for make you have so much hard work :/

I think that this Backtrace it is not good enough. I will try to create a simpler app to facilitate your work.
I really appreciate your effort to help me.

[janko]

@vital-edu Perhaps if you click "Full trace" in your Rails error UI, it will give you more details.

[vital-edu]

Sorry about that.

I will just copy and paste here:

/home/stern/.rvm/rubies/ruby-2.3.1/lib/ruby/2.3.0/delegate.rb:341:in `read'
/home/stern/.rvm/rubies/ruby-2.3.1/lib/ruby/2.3.0/delegate.rb:341:in `block in delegating_block'
actionpack (5.0.0.1) lib/action_dispatch/http/upload.rb:44:in `read'
shrine (2.4.1) lib/shrine/plugins/determine_mime_type.rb:135:in `magic_header'
shrine (2.4.1) lib/shrine/plugins/determine_mime_type.rb:88:in `_extract_mime_type_with_file'
shrine (2.4.1) lib/shrine/plugins/determine_mime_type.rb:74:in `call'
shrine (2.4.1) lib/shrine/plugins/determine_mime_type.rb:74:in `extract_mime_type'
shrine (2.4.1) lib/shrine.rb:260:in `extract_metadata'
shrine (2.4.1) lib/shrine.rb:352:in `get_metadata'
shrine (2.4.1) lib/shrine.rb:295:in `_store'
shrine (2.4.1) lib/shrine.rb:228:in `store'
shrine (2.4.1) lib/shrine.rb:206:in `upload'
shrine (2.4.1) lib/shrine.rb:605:in `cache!'
shrine (2.4.1) lib/shrine.rb:498:in `assign'
shrine (2.4.1) lib/shrine/plugins/rack_file.rb:34:in `assign'
shrine (2.4.1) lib/shrine.rb:400:in `image='
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:46:in `public_send'
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:46:in `_assign_attribute'
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:40:in `block in _assign_attributes'
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:39:in `each'
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:39:in `_assign_attributes'
activerecord (5.0.0.1) lib/active_record/attribute_assignment.rb:26:in `_assign_attributes'
activemodel (5.0.0.1) lib/active_model/attribute_assignment.rb:33:in `assign_attributes'
activerecord (5.0.0.1) lib/active_record/core.rb:319:in `initialize'
activerecord (5.0.0.1) lib/active_record/inheritance.rb:65:in `new'
activerecord (5.0.0.1) lib/active_record/inheritance.rb:65:in `new'
app/controllers/service_categories_controller.rb:20:in `create'
actionpack (5.0.0.1) lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
actionpack (5.0.0.1) lib/abstract_controller/base.rb:188:in `process_action'
actionpack (5.0.0.1) lib/action_controller/metal/rendering.rb:30:in `process_action'
actionpack (5.0.0.1) lib/abstract_controller/callbacks.rb:20:in `block in process_action'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:126:in `call'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:455:in `call'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:101:in `__run_callbacks__'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:90:in `run_callbacks'
actionpack (5.0.0.1) lib/abstract_controller/callbacks.rb:19:in `process_action'
actionpack (5.0.0.1) lib/action_controller/metal/rescue.rb:20:in `process_action'
actionpack (5.0.0.1) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
activesupport (5.0.0.1) lib/active_support/notifications.rb:164:in `block in instrument'
activesupport (5.0.0.1) lib/active_support/notifications/instrumenter.rb:21:in `instrument'
activesupport (5.0.0.1) lib/active_support/notifications.rb:164:in `instrument'
actionpack (5.0.0.1) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
actionpack (5.0.0.1) lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
activerecord (5.0.0.1) lib/active_record/railties/controller_runtime.rb:18:in `process_action'
actionpack (5.0.0.1) lib/abstract_controller/base.rb:126:in `process'
actionview (5.0.0.1) lib/action_view/rendering.rb:30:in `process'
actionpack (5.0.0.1) lib/action_controller/metal.rb:190:in `dispatch'
actionpack (5.0.0.1) lib/action_controller/metal.rb:262:in `dispatch'
actionpack (5.0.0.1) lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
actionpack (5.0.0.1) lib/action_dispatch/routing/route_set.rb:32:in `serve'
actionpack (5.0.0.1) lib/action_dispatch/journey/router.rb:39:in `block in serve'
actionpack (5.0.0.1) lib/action_dispatch/journey/router.rb:26:in `each'
actionpack (5.0.0.1) lib/action_dispatch/journey/router.rb:26:in `serve'
actionpack (5.0.0.1) lib/action_dispatch/routing/route_set.rb:725:in `call'
rack-pjax (1.0.0) lib/rack/pjax.rb:12:in `call'
remotipart (1.3.1) lib/remotipart/middleware.rb:32:in `call'
warden (1.2.6) lib/warden/manager.rb:35:in `block in call'
warden (1.2.6) lib/warden/manager.rb:34:in `catch'
warden (1.2.6) lib/warden/manager.rb:34:in `call'
rack (2.0.1) lib/rack/etag.rb:25:in `call'
rack (2.0.1) lib/rack/conditional_get.rb:38:in `call'
rack (2.0.1) lib/rack/head.rb:12:in `call'
rack (2.0.1) lib/rack/session/abstract/id.rb:222:in `context'
rack (2.0.1) lib/rack/session/abstract/id.rb:216:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/cookies.rb:613:in `call'
activerecord (5.0.0.1) lib/active_record/migration.rb:552:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:97:in `__run_callbacks__'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
activesupport (5.0.0.1) lib/active_support/callbacks.rb:90:in `run_callbacks'
actionpack (5.0.0.1) lib/action_dispatch/middleware/callbacks.rb:36:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
web-console (3.3.1) lib/web_console/middleware.rb:131:in `call_app'
web-console (3.3.1) lib/web_console/middleware.rb:28:in `block in call'
web-console (3.3.1) lib/web_console/middleware.rb:18:in `catch'
web-console (3.3.1) lib/web_console/middleware.rb:18:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
railties (5.0.0.1) lib/rails/rack/logger.rb:36:in `call_app'
railties (5.0.0.1) lib/rails/rack/logger.rb:24:in `block in call'
activesupport (5.0.0.1) lib/active_support/tagged_logging.rb:70:in `block in tagged'
activesupport (5.0.0.1) lib/active_support/tagged_logging.rb:26:in `tagged'
activesupport (5.0.0.1) lib/active_support/tagged_logging.rb:70:in `tagged'
railties (5.0.0.1) lib/rails/rack/logger.rb:24:in `call'
sprockets-rails (3.2.0) lib/sprockets/rails/quiet_assets.rb:13:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/request_id.rb:24:in `call'
rack (2.0.1) lib/rack/method_override.rb:22:in `call'
rack (2.0.1) lib/rack/runtime.rb:22:in `call'
activesupport (5.0.0.1) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.0.0.1) lib/action_dispatch/middleware/static.rb:136:in `call'
rack (2.0.1) lib/rack/sendfile.rb:111:in `call'
railties (5.0.0.1) lib/rails/engine.rb:522:in `call'
puma (3.6.0) lib/puma/configuration.rb:225:in `call'
puma (3.6.0) lib/puma/server.rb:578:in `handle_request'
puma (3.6.0) lib/puma/server.rb:415:in `process_client'
puma (3.6.0) lib/puma/server.rb:275:in `block in run'
puma (3.6.0) lib/puma/thread_pool.rb:116:in `block in spawn_thread'

[janko]

@vital-edu Thanks, this helps a lot. Ok, so it seems that the Rails uploaded file (ActionDispatch::Http::UploadedFile) is already closed before it even gets assigned to the Shrine attachment attribute.

Could you verify if this is true by checking whether params[:service_category][:image].closed? returns true, before ServiceCategory.new is called? If closed? doesn't work, you can also do p params[:service_category][:image] and see if it contains (closed) in the output.

If that's really the case, then it could be same Rack middleware that's affecting the file, in which case the output of rails middleware might be of some help. However, I can't imagine which middleware would do that, looking from your Gemfile.

[vital-edu]

Yes. It is closed.

I know that there is two Rack Middleware implemented by gems in my app:

• omniauth
• rails_admin

But I am not sure about how I can check what Middleware it is causing the problem. When I run _middleware_stack_, returns just:

#<ActionController::MiddlewareStack:0x007f51a0012cc0 @middlewares=[]>

[janko]

If I comment out everything from ApplicationController and the two before filters in ServicesCategoriesController, and send a request via curl, the file is not closed.

curl -XPOST http://localhost:3000/service_categories -F "service_category[image]=@/path/to/file.jpg"

So it might be that the issue is somewhere there. However, I will leave that debugging to you and close this issue, because we've determined that this isn't an issue with Shrine.

[iozeey]

I was also facing similar issue in my create method

Just before saving method i reopen file then

IOError Closed stream

has gone.

document_params[:document].open

@janko-m is this good solution?

[janko]

@zeeshan-za-ahmad Yes, that is a good workaround, reopening the Tempfile doesn't bring any side-effects. Though it would still be good to find out what closes the Tempfile in the first place.

[lacus]

Hi guys, I know its an older topic, but this time I was facing this issue too.
I use cancancan for my project and the method load_and_authorize_resource triggered this error (I think so).
Setting the resource manually and using authorize_resource solved this issue.

I can see vital-edu uses load_and_authorize_resource too.

[ryanb]

For anyone debugging this error, it can happen in Rails when assigning attributes twice. For example:

product.attributes = params[:product]
product.attributes = params[:product] # triggers IOError stream closed

Since the file is processed and closed on the first assignment it will be still closed on the second assignment. The best solution is to only assign the attributes once.

[mur-wtag]

I think @ryanb found the exact reason of this issue.

If we use cancancan and in controller we add this kind of assignment Model.new(model_params) again after adding load_and_authorize_resource, this issue will be raised.