log_message IOError (closed stream) caused the website down for for hours

[chengguangnan]

I have been using rack-cache for years. When I woke up today, I found that the site is down for hours in a blank empty page.

I restarted unicorn and things back to normal. Below is the error log.

I have no idea why the stream was closed.

IOError (closed stream):
  rack-cache (1.2) lib/rack/cache/context.rb:82:in `write'
  rack-cache (1.2) lib/rack/cache/context.rb:82:in `call!'
  rack-cache (1.2) lib/rack/cache/context.rb:51:in `call'
  rack (1.6.4) lib/rack/head.rb:13:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/params_parser.rb:27:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/flash.rb:260:in `call'
  rack (1.6.4) lib/rack/session/abstract/id.rb:225:in `context'
  rack (1.6.4) lib/rack/session/abstract/id.rb:220:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/cookies.rb:560:in `call'
  activerecord (4.2.3) lib/active_record/query_cache.rb:36:in `call'
  activerecord (4.2.3) lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
  activesupport (4.2.3) lib/active_support/callbacks.rb:84:in `run_callbacks'
  actionpack (4.2.3) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/remote_ip.rb:78:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.2.3) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.2.3) lib/rails/rack/logger.rb:20:in `block in call'
  activesupport (4.2.3) lib/active_support/tagged_logging.rb:68:in `block in tagged'
  activesupport (4.2.3) lib/active_support/tagged_logging.rb:26:in `tagged'
  activesupport (4.2.3) lib/active_support/tagged_logging.rb:68:in `tagged'
  railties (4.2.3) lib/rails/rack/logger.rb:20:in `call'
  quiet_assets (1.1.0) lib/quiet_assets.rb:27:in `call_with_quiet_assets'
  actionpack (4.2.3) lib/action_dispatch/middleware/request_id.rb:21:in `call'
  rack (1.6.4) lib/rack/methodoverride.rb:22:in `call'
  rack (1.6.4) lib/rack/runtime.rb:18:in `call'
  activesupport (4.2.3) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  rack-rewrite (1.5.1) lib/rack/rewrite.rb:24:in `call'
  actionpack (4.2.3) lib/action_dispatch/middleware/static.rb:116:in `call'
  rack (1.6.4) lib/rack/sendfile.rb:113:in `call'
  railties (4.2.3) lib/rails/engine.rb:518:in `call'
  railties (4.2.3) lib/rails/application.rb:165:in `call'
  railties (4.2.3) lib/rails/railtie.rb:194:in `public_send'
  railties (4.2.3) lib/rails/railtie.rb:194:in `method_missing'
  unicorn (4.9.0) lib/unicorn/http_server.rb:580:in `process_client'
  unicorn (4.9.0) lib/unicorn/http_server.rb:674:in `worker_loop'
  unicorn (4.9.0) lib/unicorn/http_server.rb:529:in `spawn_missing_workers'
  unicorn (4.9.0) lib/unicorn/http_server.rb:140:in `start'
  unicorn (4.9.0) bin/unicorn:126:in `<top (required)>'
  /u/apps/###/shared/bundle/ruby/2.2.0/bin/unicorn:23:in `load'
  /u/apps/###/shared/bundle/ruby/2.2.0/bin/unicorn:23:in `<main>'

ruby 2.2.0p0 (2014-12-25 revision 49005) [x86_64-linux]

[chengguangnan]

It happened again, causing a downtime.

[chengguangnan]

I was suspecting that this is related to a hardware failure, however, this happened again on another brand new Linode VPS on the first day.

So I suspect that some other process closed this stream. I'm not an Rails internal expert. Does anybody know who might closed this stream? Or how to reopen it?

[chengguangnan]

I will close this as this seems that it's not rack-cache caused issue.