質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

ただいまの
回答率

90.04%

Rails4で何故かレンダリングに時間がかかりすぎタイムアウトしてしまう。

受付中

回答 1

投稿 編集

  • 評価
  • クリップ 0
  • VIEW 1,841

Ruby on Rails4.2.5 で開発をしているのですが、突然localhostにアクセスしてもタイムアウトしてしまうようになってしまいました。ログを見てみるとデータベスの接続やキャッシュとかは何msなのですが、レンダリングに異常なほど時間がかかっていて、それでタイムアウトしてしまいます。

今までは正常なレスポンスタイムで描画していたのですが、突然このようにタイムアウトしてしまうほど時間がかかってしまった原因がわかりません。わかる方いましたらご教授お願いします。

環境

  • unciron 5.0.1
  • rails 4.2.5
  • ruby 2.2.3
  • slim 3.0.6
  • slim-rails 3.0.1
source=rack-timeout id=af394e65fcb94164bd551f8e325d478f timeout=25000ms service=33170ms state=active
source=rack-timeout id=af394e65fcb94164bd551f8e325d478f timeout=25000ms service=33216ms state=timed_out
  Rendered evideos/show.html.slim within layouts/full (33171.4ms)
Completed 500 Internal Server Error in 33207ms (ActiveRecord: 3.3ms)

Rack::Timeout::RequestTimeoutException - Request ran for longer than 25000ms:
  sprockets (3.5.2) lib/sprockets/cache/file_store.rb:101:in `set'
  sprockets (3.5.2) lib/sprockets/cache.rb:210:in `set'
  sprockets (3.5.2) lib/sprockets/cache.rb:136:in `set'
  sprockets (3.5.2) lib/sprockets/loader.rb:244:in `store_asset'
  ...
  sprockets-rails (3.0.4) lib/sprockets/rails/helper.rb:229:in `block in resolve_asset'
  sprockets-rails (3.0.4) lib/sprockets/rails/helper.rb:228:in `resolve_asset'
  sprockets-rails (3.0.4) lib/sprockets/rails/helper.rb:215:in `lookup_debug_asset'
  sprockets-rails (3.0.4) lib/sprockets/rails/helper.rb:128:in `block in javascript_include_tag'
  sprockets-rails (3.0.4) lib/sprockets/rails/helper.rb:127:in `javascript_include_tag'
  app/views/evideos/show.html.slim:7:in `block in _app_views_evideos_show_html_slim___135235524447124923_70234700341860'
  actionview (4.2.5) lib/action_view/helpers/capture_helper.rb:38:in `block in capture'
  actionview (4.2.5) lib/action_view/helpers/capture_helper.rb:202:in `with_output_buffer'
  actionview (4.2.5) lib/action_view/helpers/capture_helper.rb:38:in `capture'
  actionview (4.2.5) lib/action_view/helpers/capture_helper.rb:152:in `content_for'
  app/views/evideos/show.html.slim:6:in `_app_views_evideos_show_html_slim___135235524447124923_70234700341860'
  actionview (4.2.5) lib/action_view/template.rb:145:in `block in render'
  activesupport (4.2.5) lib/active_support/notifications.rb:166:in `instrument'
  actionview (4.2.5) lib/action_view/template.rb:333:in `instrument'
  actionview (4.2.5) lib/action_view/template.rb:143:in `render'
  actionview (4.2.5) lib/action_view/rendering.rb:83:in `render_to_body'
  activesupport (4.2.5) lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
  actionpack (4.2.5) lib/action_controller/metal/instrumentation.rb:43:in `render'
  meta-tags (2.1.0) lib/meta_tags/controller_helper.rb:26:in `render_with_meta_tags'
  app/controllers/evideos_controller.rb:77:in `show'
  ...
  actionpack (4.2.5) lib/action_dispatch/middleware/params_parser.rb:27:in `call'
  actionpack (4.2.5) 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.5) lib/action_dispatch/middleware/cookies.rb:560:in `call'
  activerecord (4.2.5) lib/active_record/query_cache.rb:36:in `call'
  activerecord (4.2.5) lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call'
  activerecord (4.2.5) lib/active_record/migration.rb:377:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
  activesupport (4.2.5) lib/active_support/callbacks.rb:88:in `__run_callbacks__'
  activesupport (4.2.5) lib/active_support/callbacks.rb:778:in `_run_call_callbacks'
  activesupport (4.2.5) lib/active_support/callbacks.rb:81:in `run_callbacks'
  actionpack (4.2.5) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/reloader.rb:73:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/remote_ip.rb:78:in `call'
  better_errors (2.1.1) lib/better_errors/middleware.rb:84:in `protected_app_call'
  better_errors (2.1.1) lib/better_errors/middleware.rb:79:in `better_errors_call'
  better_errors (2.1.1) lib/better_errors/middleware.rb:57:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
  web-console (3.1.1) lib/web_console/middleware.rb:131:in `call_app'
  web-console (3.1.1) lib/web_console/middleware.rb:28:in `block in call'
  web-console (3.1.1) lib/web_console/middleware.rb:18:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.2.5) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.2.5) lib/rails/rack/logger.rb:22:in `call'
  quiet_assets (1.1.0) lib/quiet_assets.rb:27:in `call_with_quiet_assets'
  request_store (1.3.0) lib/request_store/middleware.rb:9:in `call'
  actionpack (4.2.5) 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'
  rack-timeout (0.3.2) lib/rack/timeout/core.rb:125:in `block in call'
  rack-timeout (0.3.2) lib/rack/timeout/support/timeout.rb:19:in `timeout'
  rack-timeout (0.3.2) lib/rack/timeout/core.rb:124:in `call'
  activesupport (4.2.5) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  rack (1.6.4) lib/rack/lock.rb:17:in `call'
  actionpack (4.2.5) lib/action_dispatch/middleware/static.rb:116:in `call'
  rack (1.6.4) lib/rack/sendfile.rb:113:in `call'
  rack-mini-profiler (0.9.8) lib/mini_profiler/profiler.rb:282:in `call'
  railties (4.2.5) lib/rails/engine.rb:518:in `call'
  railties (4.2.5) lib/rails/application.rb:165:in `call'
  rack-cors (0.3.0) lib/rack/cors.rb:72:in `call'
  rack (1.6.4) lib/rack/lock.rb:17:in `call'
  rack (1.6.4) lib/rack/content_length.rb:15:in `call'
  rack (1.6.4) lib/rack/handler/webrick.rb:88:in `service'
  /Users/sakaihidenobu/.rbenv/versions/2.2.3/lib/ruby/2.2.0/webrick/httpserver.rb:138:in `service'
  /Users/sakaihidenobu/.rbenv/versions/2.2.3/lib/ruby/2.2.0/webrick/httpserver.rb:94:in `run'
  /Users/sakaihidenobu/.rbenv/versions/2.2.3/lib/ruby/2.2.0/webrick/server.rb:294:in `block in start_thread'

source=rack-timeout id=af394e65fcb94164bd551f8e325d478f timeout=25000ms service=33298ms state=completed
source=rack-timeout id=41ede62d2caf4d887d50593db080aa6a timeout=25000ms state=ready
source=rack-timeout id=41ede62d2caf4d887d50593db080aa6a timeout=25000ms service=0ms state=active

source=rack-timeout id=41ede62d2caf4d887d50593db080aa6a timeout=25000ms service=156ms state=completed

また、今回のレンダリングにとてつもなく時間をかけているレイアウトです。

doctype html
head
  = include_gon
  = stylesheet_link_tag    "application", media: "all", :debug => true
  = javascript_include_tag "application", :debug => true
  = csrf_meta_tags
  - if content_for(:page_title)
    - set_meta_tags site: 'aaaaaa', title: yield(:page_title), reverse: true
  - else
    - set_meta_tags site: 'aaaaaa'
  = display_meta_tags default_meta_tags
  = favicon_link_tag('favicon.ico')
  == yield :head
  = analytics_init if Rails.env.production?
.wrap
  body class="#{controller_name} #{action_name}"
  #fb-root
  javascript:
    (function(d, s, id) { var js, fjs = d.getElementsByTagName(s)[0]; if (d.getElementById(id)) return; js = d.createElement(s); js.id = id; js.async = true; js.src = "//connect.facebook.net/ja_JP/sdk.js#xfbml=1&version=v2.5&appId=1830645683829206"; fjs.parentNode.insertBefore(js, fjs); }(document, 'script', 'facebook-jssdk'));
  #loading
    = image_tag "loading.gif", size: '43x11', alt: 'loading...'
  .countatiner-fluid
    .row
      .col-sm-12.col-md-12 style="padding:0;margin:0"
        header.clearfix
          == render 'templates/header'
          == render 'templates/category'
          == yield :header
      .col-sm-12.col-md-12.col-lg-offset-1.col-lg-10
        = alert_or_notice alert, notice
        aritlce.main
          == yield
      .col-sm-12.col-md-12
        footer
          == render 'templates/footer'
  #pagetop.pagetop
    i.glyphicon.glyphicon-chevron-up
  • 気になる質問をクリップする

    クリップした質問は、後からいつでもマイページで確認できます。

    またクリップした質問に回答があった際、通知やメールを受け取ることができます。

    クリップを取り消します

  • 良い質問の評価を上げる

    以下のような質問は評価を上げましょう

    • 質問内容が明確
    • 自分も答えを知りたい
    • 質問者以外のユーザにも役立つ

    評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

    質問の評価を上げたことを取り消します

  • 評価を下げられる数の上限に達しました

    評価を下げることができません

    • 1日5回まで評価を下げられます
    • 1日に1ユーザに対して2回まで評価を下げられます

    質問の評価を下げる

    teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

    • プログラミングに関係のない質問
    • やってほしいことだけを記載した丸投げの質問
    • 問題・課題が含まれていない質問
    • 意図的に内容が抹消された質問
    • 広告と受け取られるような投稿

    評価が下がると、TOPページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

    質問の評価を下げたことを取り消します

    この機能は開放されていません

    評価を下げる条件を満たしてません

    評価を下げる理由を選択してください

    詳細な説明はこちら

    上記に当てはまらず、質問内容が明確になっていない質問には「情報の追加・修正依頼」機能からコメントをしてください。

    質問の評価を下げる機能の利用条件

    この機能を利用するためには、以下の事項を行う必要があります。

回答 1

0

config/environment/development.rb
config.assets.compress = true
  config.assets.js_compressor = :uglifier
  config.assets.css_compressor = :sass
  config.assets.debug = true

としていたが、開発環境では1リクエストごとに動的にコンパイルしているらしいので、これが原因でページ遷移するたびに異常に時間がかかっていた。
この設定の

config.assets.debug = false

に変更することで、最初のリクエスト時にassetsをキャッシュして、それ以後はキャッシュしたjsとcssを使うようになったので、正常なレスポンスタイムに戻りました。

 参考

Rails3?のassets precompileの日本語訳
やっぱりassets precompileとかもしっかりと理解しないといけないなと改めて実感しました。

投稿

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

15分調べてもわからないことは、teratailで質問しよう!

  • ただいまの回答率 90.04%
  • 質問をまとめることで、思考を整理して素早く解決
  • テンプレート機能で、簡単に質問をまとめられる