title: Rails: Troubleshooting a Rack::Timeout::RequestTimeoutException
body: <p>Getting some:</p>
  <blockquote>
  <p>Rack::Timeout::RequestTimeoutException: Request waited {7ms}, then ran for longer than 15000ms</p>
  </blockquote>
  <p>After upgrading Rails 4.2.9 app to Rails 5.2.1.1.</p>
  <p>This is raised by the <strong>rack-timeout</strong> gem <a href="https://github.com/heroku/rack-timeout/blob/master/doc/exceptions.md" rel="nofollow noreferrer">documented here</a>.</p>
  <p>That said, I'm having trouble identifying the root cause of the timeouts. I can successfully load the URLs that were the triggers from my machine but clearly others users are having issues.</p>
  <p>Any help in how to troubleshoot this would be appreciated.</p>
  <p>Backtrace (from Airbrake – includes &quot;code hunks&quot;):</p>
  <pre><code>/gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql_adapter.rb:603 in async_exec
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql_adapter.rb:603 in block (2 levels) in exec_no_cache
  /gems/activesupport-5.2.1.1/lib/active_support/dependencies/interlock.rb:48 in block in permit_concurrent_loads
  /gems/activesupport-5.2.1.1/lib/active_support/concurrency/share_lock.rb:187 in yield_shares
  /gems/activesupport-5.2.1.1/lib/active_support/dependencies/interlock.rb:47 in permit_concurrent_loads
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql_adapter.rb:602 in block in exec_no_cache
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract_adapter.rb:579 in block (2 levels) in log
  vendor/ruby-2.4.4/lib/ruby/2.4.0/monitor.rb:214 in mon_synchronize
  212:
      mon_enter
  213:
      begin
  214:
        yield
  215:
      ensure
  216:
        mon_exit
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract_adapter.rb:578 in block in log
  /gems/activesupport-5.2.1.1/lib/active_support/notifications/instrumenter.rb:23 in instrument
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract_adapter.rb:569 in log
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql_adapter.rb:601 in exec_no_cache
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql_adapter.rb:590 in execute_and_clear
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:81 in exec_query
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/database_statements.rb:465 in select
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/database_statements.rb:57 in select_all
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/query_cache.rb:99 in block in select_all
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/query_cache.rb:122 in block in cache_sql
  vendor/ruby-2.4.4/lib/ruby/2.4.0/monitor.rb:214 in mon_synchronize
  212:
      mon_enter
  213:
      begin
  214:
        yield
  215:
      ensure
  216:
        mon_exit
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/query_cache.rb:108 in cache_sql
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/query_cache.rb:99 in select_all
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/database_statements.rb:81 in select_rows
  /gems/activerecord-5.2.1.1/lib/active_record/connection_adapters/abstract/database_statements.rb:69 in select_value
  /gems/activerecord-5.2.1.1/lib/active_record/relation/finder_methods.rb:322 in block in exists?
  /gems/activerecord-5.2.1.1/lib/active_record/relation.rb:578 in skip_query_cache_if_necessary
  /gems/activerecord-5.2.1.1/lib/active_record/relation/finder_methods.rb:322 in exists?
  /gems/unread-0.10.1/lib/unread/readable.rb:124 in unread?
  app/views/stories/_story.html.slim:4 in _app_views_stories__story_html_slim___4341629232572424476_47283389142580
  2:
    - if story.time_capsule?
  3:
      .flag = t(&quot;stories.time_capsule.label&quot;)
  4:
    - elsif story.unread?(current_user)
  5:
      .flag = t(&quot;stories.unread&quot;)
  6:
    = link_to story_path(story), class: &quot;open-block&quot; do
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:159 in block in render
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications/instrumenter.rb:23 in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:354 in instrument_render_template
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:157 in render
  /gems/actionview-5.2.1.1/lib/action_view/renderer/partial_renderer.rb:344 in block in render_partial
  /gems/actionview-5.2.1.1/lib/action_view/renderer/abstract_renderer.rb:44 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications/instrumenter.rb:23 in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/renderer/abstract_renderer.rb:43 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/renderer/partial_renderer.rb:333 in render_partial
  /gems/actionview-5.2.1.1/lib/action_view/renderer/partial_renderer.rb:312 in render
  /gems/actionview-5.2.1.1/lib/action_view/renderer/renderer.rb:49 in render_partial
  /gems/actionview-5.2.1.1/lib/action_view/helpers/rendering_helper.rb:36 in render
  app/views/stories/index.html.slim:19 in block in _app_views_stories_index_html_slim___2178368229094429886_47283376767280
  17:
        ul.stories.blocks
  18:
          - @stories.each do |story|
  19:
            = render &quot;stories/story&quot;, story: story
  20:
        = render 'comments/compact_list'
  21:
      - else
  app/views/stories/index.html.slim:18 in each
  16:
      - if @stories.to_a.any?
  17:
        ul.stories.blocks
  18:
          - @stories.each do |story|
  19:
            = render &quot;stories/story&quot;, story: story
  20:
        = render 'comments/compact_list'
  app/views/stories/index.html.slim:18 in _app_views_stories_index_html_slim___2178368229094429886_47283376767280
  16:
      - if @stories.to_a.any?
  17:
        ul.stories.blocks
  18:
          - @stories.each do |story|
  19:
            = render &quot;stories/story&quot;, story: story
  20:
        = render 'comments/compact_list'
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:159 in block in render
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications/instrumenter.rb:23 in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:354 in instrument_render_template
  /gems/actionview-5.2.1.1/lib/action_view/template.rb:157 in render
  /gems/actionview-5.2.1.1/lib/action_view/renderer/template_renderer.rb:54 in block (2 levels) in render_template
  /gems/actionview-5.2.1.1/lib/action_view/renderer/abstract_renderer.rb:44 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in block in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications/instrumenter.rb:23 in instrument
  /gems/activesupport-5.2.1.1/lib/active_support/notifications.rb:168 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/renderer/abstract_renderer.rb:43 in instrument
  /gems/actionview-5.2.1.1/lib/action_view/renderer/template_renderer.rb:53 in block in render_template
  /gems/actionview-5.2.1.1/lib/action_view/renderer/template_renderer.rb:61 in render_with_layout
  /gems/actionview-5.2.1.1/lib/action_view/renderer/template_renderer.rb:52 in render_template
  /gems/actionview-5.2.1.1/lib/action_view/renderer/template_renderer.rb:16 in render
  /gems/actionview-5.2.1.1/lib/action_view/renderer/renderer.rb:44 in render_template
  /gems/actionview-5.2.1.1/lib/action_view/renderer/renderer.rb:25 in render
  /gems/actionview-5.2.1.1/lib/action_view/rendering.rb:103 in _render_template
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/streaming.rb:219 in _render_template
  /gems/actionview-5.2.1.1/lib/action_view/rendering.rb:84 in render_to_body
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/rendering.rb:52 in render_to_body
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/renderers.rb:142 in render_to_body
  /gems/actionpack-5.2.1.1/lib/abstract_controller/rendering.rb:25 in render
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/rendering.rb:36 in render
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/instrumentation.rb:46 in block (2 levels) in render
  /gems/activesupport-5.2.1.1/lib/active_support/core_ext/benchmark.rb:14 in block in ms
  vendor/ruby-2.4.4/lib/ruby/2.4.0/benchmark.rb:308 in realtime
  306:
    def realtime # :yield:
  307:
      r0 = Process.clock_gettime(Process::CLOCK_MONOTONIC)
  308:
      yield
  309:
      Process.clock_gettime(Process::CLOCK_MONOTONIC) - r0
  310:
    end
  /gems/activesupport-5.2.1.1/lib/active_support/core_ext/benchmark.rb:14 in ms
  /gems/actionpack-5.2.1.1/lib/action_controller/metal/instrumentation.rb:46 in block in render
  </code></pre>