Skip to content
  • Christian Gregg's avatar
    903ebae1
    Make ActionView::LookupContext::DetailsKey thread-safe · 903ebae1
    Christian Gregg authored
    Hi, we recently upgraded to Rails 6 and have had some 'random' issues
    pop up twice now in the last two weeks where upon scaling our
    application instances we found a single instance failing when trying to
    render with stack traces that looked a bit like this:
    
    ```
    vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/base.rb:274:in `_run': undefined method `_app_views_dealers_call_centre_index_html_haml__1117437046933042982_70191578841420' for #<#<Class:0x00007fad784998c8>:0x00007fad6ae237a8>
    Did you mean?  _app_views_dealers_active_leads_index_html_haml__2989992190908713101_70191398405520 (ActionView::Template::Error)
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:185:in `block in render'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:386:in `instrument_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:183:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:59:in `block (2 levels) in render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/abstract_renderer.rb:89:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/abstract_renderer.rb:88:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:58:in `block in render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:66:in `render_with_layout'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:57:in `render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:13:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/renderer.rb:61:in `render_template_to_object'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/renderer.rb:29:in `render_to_object'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:118:in `block in _render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/base.rb:304:in `in_rendering_context'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:117:in `_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/streaming.rb:219:in `_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:103:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:52:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/renderers.rb:142:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/rendering.rb:25:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:36:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
        from vendor/ruby-2.6.5/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/core_ext/benchmark.rb:14:in `ms'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:44:in `block in render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:85:in `cleanup_view_runtime'
        from vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/railties/controller_runtime.rb:34:in `cleanup_view_runtime'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:43:in `render'
        from app/controllers/dealers/call_centre_controller.rb:11:in `index'
    ```
    
    After some investigation it seems to me that there is some non-thread
    safe code (we run single process, multi-thread instance of our apps in
    production) in the rendering process.
    
    Specifically in accessing the memoized `@view_context_class` variable
    (which is what `ActionView::Template#compile` ends up adding methods
    to). I've built a reproducible example at
    CGA1123/action-view-race-condition specifically
    CGA1123/action-view-race-condition@64c023081dd898be1f99c558e47726bc648a0374
    which introduces some extra work on assignment in order to force the
    ruby process to schedule another request thread.
    
    The race means that we 'lose' the methods adding during a call to
    `ActionView::Templace#compile!` but that instance still has `@compile`
    set to `true` causing all subsequent attempts to render that template to
    fail.
    
    I'm not sure whether adding a mutex on the access is the best way to
    solve this? Perhaps the caching logic should be smarter and check that
    the method exists?
    
    I'm also not sure of the performance implications of synchronizing
    accessing this variable might have?
    903ebae1
    Make ActionView::LookupContext::DetailsKey thread-safe
    Christian Gregg authored
    Hi, we recently upgraded to Rails 6 and have had some 'random' issues
    pop up twice now in the last two weeks where upon scaling our
    application instances we found a single instance failing when trying to
    render with stack traces that looked a bit like this:
    
    ```
    vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/base.rb:274:in `_run': undefined method `_app_views_dealers_call_centre_index_html_haml__1117437046933042982_70191578841420' for #<#<Class:0x00007fad784998c8>:0x00007fad6ae237a8>
    Did you mean?  _app_views_dealers_active_leads_index_html_haml__2989992190908713101_70191398405520 (ActionView::Template::Error)
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:185:in `block in render'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:386:in `instrument_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/template.rb:183:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:59:in `block (2 levels) in render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/abstract_renderer.rb:89:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `block in instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/notifications.rb:180:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/abstract_renderer.rb:88:in `instrument'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:58:in `block in render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:66:in `render_with_layout'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:57:in `render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/template_renderer.rb:13:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/renderer.rb:61:in `render_template_to_object'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/renderer/renderer.rb:29:in `render_to_object'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:118:in `block in _render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/base.rb:304:in `in_rendering_context'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:117:in `_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/streaming.rb:219:in `_render_template'
        from vendor/bundle/ruby/2.6.0/gems/actionview-6.0.1/lib/action_view/rendering.rb:103:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:52:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/renderers.rb:142:in `render_to_body'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/abstract_controller/rendering.rb:25:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/rendering.rb:36:in `render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
        from vendor/ruby-2.6.5/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'
        from vendor/bundle/ruby/2.6.0/gems/activesupport-6.0.1/lib/active_support/core_ext/benchmark.rb:14:in `ms'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:44:in `block in render'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:85:in `cleanup_view_runtime'
        from vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.1/lib/active_record/railties/controller_runtime.rb:34:in `cleanup_view_runtime'
        from vendor/bundle/ruby/2.6.0/gems/actionpack-6.0.1/lib/action_controller/metal/instrumentation.rb:43:in `render'
        from app/controllers/dealers/call_centre_controller.rb:11:in `index'
    ```
    
    After some investigation it seems to me that there is some non-thread
    safe code (we run single process, multi-thread instance of our apps in
    production) in the rendering process.
    
    Specifically in accessing the memoized `@view_context_class` variable
    (which is what `ActionView::Template#compile` ends up adding methods
    to). I've built a reproducible example at
    CGA1123/action-view-race-condition specifically
    CGA1123/action-view-race-condition@64c023081dd898be1f99c558e47726bc648a0374
    which introduces some extra work on assignment in order to force the
    ruby process to schedule another request thread.
    
    The race means that we 'lose' the methods adding during a call to
    `ActionView::Templace#compile!` but that instance still has `@compile`
    set to `true` causing all subsequent attempts to render that template to
    fail.
    
    I'm not sure whether adding a mutex on the access is the best way to
    solve this? Perhaps the caching logic should be smarter and check that
    the method exists?
    
    I'm also not sure of the performance implications of synchronizing
    accessing this variable might have?
Loading