ruby-on-rails - Rails 应用程序崩溃并显示 #true, 20687660=>true}>

Question

我们正在运行一个具有大量请求(每分钟 400 个请求)的 Rails 应用程序，其中有 3 个网络节点运行 nginx 和 passenger。

然而，过去几天我们遇到了几次崩溃并出现 500 错误。在 nginx 错误日志中找不到任何内容。 Rails 日志给出了一个相当非描述性的错误消息，我希望你们中的一些人可以帮助我追踪:

ArgumentError: uncaught throw {:__recursive_key__=>true, 20687660=>true}

堆栈跟踪:

/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:57:in `block in nary'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:57:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:57:in `nary'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `block in visit_Array'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `visit_Array'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:146:in `visit_Arel_Nodes_SelectCore'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `block in visit_Array'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:169:in `visit_Array'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:153:in `visit_Arel_Nodes_SelectStatement'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:29:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/depth_first.rb:12:in `visit'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/visitors/visitor.rb:9:in `accept'
/var/www/app/shared/bundle/ruby/2.1.0/gems/arel-6.0.3/lib/arel/nodes/node.rb:56:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/calculations.rb:210:in `grep'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/calculations.rb:210:in `perform_calculation'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/calculations.rb:127:in `calculate'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/calculations.rb:42:in `count'
/var/www/app/releases/20160607074820/app/models/webshop.rb:135:in `show_custom_pickup_identifier?'
/var/www/app/releases/20160607074820/app/controllers/standard/shopify_controller.rb:176:in `block (2 levels) in shop_shipping'
/var/www/app/releases/20160607074820/app/controllers/standard/shopify_controller.rb:173:in `each'
/var/www/app/releases/20160607074820/app/controllers/standard/shopify_controller.rb:173:in `block in shop_shipping'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/app/releases/20160607074820/app/controllers/standard/shopify_controller.rb:157:in `shop_shipping'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/abstract_controller/base.rb:198:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/rendering.rb:10:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:117:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:117:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:505:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:505:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/abstract_controller/callbacks.rb:19:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/rescue.rb:29:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/notifications.rb:164:in `block in instrument'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/notifications.rb:164:in `instrument'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/abstract_controller/base.rb:137:in `process'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionview-4.2.4/lib/action_view/rendering.rb:30:in `process'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal.rb:196:in `dispatch'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_controller/metal.rb:237:in `block in action'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/routing/route_set.rb:76:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/routing/route_set.rb:76:in `dispatch'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/routing/route_set.rb:45:in `serve'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/journey/router.rb:43:in `block in serve'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/journey/router.rb:30:in `each'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/journey/router.rb:30:in `serve'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/routing/route_set.rb:821:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/etag.rb:24:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/conditionalget.rb:38:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/head.rb:13:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/params_parser.rb:27:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/flash.rb:260:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:225:in `context'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/session/abstract/id.rb:220:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/cookies.rb:560:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/query_cache.rb:36:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activerecord-4.2.4/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:88:in `__run_callbacks__'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:778:in `_run_call_callbacks'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:81:in `run_callbacks'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/remote_ip.rb:78:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/rack/logger.rb:20:in `block in call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/tagged_logging.rb:68:in `block in tagged'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/tagged_logging.rb:26:in `tagged'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/tagged_logging.rb:68:in `tagged'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/rack/logger.rb:20:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/actionpack-4.2.4/lib/action_dispatch/middleware/request_id.rb:21:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/runtime.rb:18:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/activesupport-4.2.4/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/engine.rb:518:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/application.rb:165:in `call'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/railtie.rb:194:in `public_send'
/var/www/app/shared/bundle/ruby/2.1.0/gems/railties-4.2.4/lib/rails/railtie.rb:194:in `method_missing'
/usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:97:in `process_request'
/usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:160:in `accept_and_process_next_request'
/usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:113:in `main_loop'
/usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:416:in `block (3 levels) in start_threads'
/usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'

它似乎发生在应用程序的所有不同位置，除非不需要数据库查询。然而，我们的数据库看起来很健康，并且在连接、内存和 cpu 方面有很多容量。

希望有人能告诉我如何解决这个问题。

谢谢 :-)

Answer 1

感谢您的建议:-)

异常确实会定期抛出 - 但它似乎只在数据库调用时抛出( - 在 show_custom_pickup_identifier 中？它只进行简单的 AR 查询)。所以我追踪到了它 - 我们认为我们发现了 AWS RDS IOPS 限制中的问题。在应用更多存储空间(因此更多 IOPS)之后，它似乎已经消失了 - 至少在今天 :-) 如果亚马逊有一个明确的指示表明我们已经用完 IOPS 就好了 (!!)..

所以现在我们祈祷这将永久解决问题:-)