诊断慢速视图渲染的原因

Abr*_*ram 79 ruby-on-rails

我不确定这是什么时候开始的,但我的应用程序中发生了一些不寻常的事情(在开发机器上本地运行).突然间,我看到的消息如下:

Started GET "/" for 127.0.0.1 at 2013-03-10 12:10:24 +1300
Processing by PagesController#home as HTML
  Rendered pages/home.html.erb within layouts/application (2.4ms)
Completed 200 OK in 3242ms (Views: 3241.4ms | ActiveRecord: 0.0ms)
Run Code Online (Sandbox Code Playgroud)

正如你可以看到3秒加载主页(一个相对简单的页面)...我们不是在说硬页重新加载...只是再次从另一个页面点击"主页"链接.

不确定从哪里开始,但这是我的application.rb:

#config/boot.rb is loaded
require File.expand_path('../boot', __FILE__)

require 'rails/all'

if defined?(Bundler)
  Bundler.require(*Rails.groups(:assets => %w(development test)))
end

module Goodsounds
  class Application < Rails::Application
    config.encoding = "utf-8"
    config.filter_parameters += [:password]
    config.assets.initialize_on_precompile = false
    config.assets.enabled = true
    config.action_controller.assets_dir = "#{File.dirname(File.dirname(__FILE__))}/public"
    config.assets.version = '1.0'
    config.autoload_paths += Dir["#{Rails.root}/lib/modules"]
    config.assets.paths += Dir["#{Rails.root}/app/assets/fonts/*"]
    config.assets.precompile += %w( .svg .eot .woff .ttf ) 
  end
end
Run Code Online (Sandbox Code Playgroud)

......和dev.rb:

Goodsounds::Application.configure do
  # Settings specified here will take precedence over those in config/application.rb
    Paperclip.options[:command_path] = "/usr/bin/"

    config.action_mailer.default_url_options = { :host => 'localhost:3000' }

  config.action_mailer.raise_delivery_errors = true

  # set delivery method to :smtp, :sendmail or :test
  config.action_mailer.delivery_method = :smtp

  # these options are only needed if you choose smtp delivery

  config.action_mailer.smtp_settings = { :address => "localhost", :port => 1025 }

  # In the development environment your application's code is reloaded on
  # every request. This slows down response time but is perfect for development
  # since you don't have to restart the web server when you make code changes.
  config.cache_classes = false

  # Log error messages when you accidentally call methods on nil.
  config.whiny_nils = true

  # Show full error reports and disable caching
  config.consider_all_requests_local       = true
  config.action_controller.perform_caching = false

  # Print deprecation notices to the Rails logger
  config.active_support.deprecation = :log

  # Only use best-standards-support built into browsers
  config.action_dispatch.best_standards_support = :builtin

  # Raise exception on mass assignment protection for Active Record models
  config.active_re
cord.mass_assignment_sanitizer = :strict

  # Log the query plan for queries taking more than this (works
  # with SQLite, MySQL, and PostgreSQL)
  config.active_record.auto_explain_threshold_in_seconds = 0.5

  # Do not compress assets
  config.assets.compress = false

  # Expands the lines which load the assets
  config.assets.debug = true
end
Run Code Online (Sandbox Code Playgroud)

编辑:

好的,这是我在新遗物上看到的.虽然不能帮助我.有什么想法吗?

在此输入图像描述

在此输入图像描述

哦,以及我从Chrome时间线中学到的东西:

Send Request - Details
Duration    0 (at 655?ms)
Resource    localhost
Request Method  GET

Receive Response - Details
Duration    0.043?ms (at 4.17?s)
Resource    localhost
Status Code 200
MIME Type   text/html

Receive Data - Details
Duration    176.329?ms (at 4.17?s)
Self Time   7.037?ms
CPU Time    176.329?ms
Aggregated Time 061.194?ms114.664?ms0.471?ms0
Resource    localhost
Encoded Data Length 303 Bytes
Used Heap Size  29.1?MB (+5.7?MB)

Finish Loading - Details
Duration    0 (at 4.35?s)
Resource    localhost
Run Code Online (Sandbox Code Playgroud)

顺便说一句,我禁用了quiet_assets宝石,看看我能在终端发现什么..再次..没有帮助:

Started GET "/" for 127.0.0.1 at 2013-03-10 21:46:40 +1300
Processing by PagesController#home as HTML
  Rendered pages/home.html.erb within layouts/application (43.4ms)
Completed 200 OK in 3501ms (Views: 3480.9ms | ActiveRecord: 19.4ms)


Started GET "/assets/dataTables/jquery.dataTables.bootstrap.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /dataTables/jquery.dataTables.bootstrap.css - 304 Not Modified (11ms)


Started GET "/assets/chosen.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /chosen.css - 304 Not Modified (5ms)


Started GET "/assets/select2.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /select2.css - 304 Not Modified (4ms)


Started GET "/assets/autocomplete.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /autocomplete.css - 304 Not Modified (1ms)


Started GET "/assets/branches.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /branches.css - 304 Not Modified (2ms)


Started GET "/assets/bubbles.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bubbles.css - 304 Not Modified (1ms)


Started GET "/assets/business_show.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /business_show.css - 304 Not Modified (1ms)


Started GET "/assets/chunkyfive_font.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /chunkyfive_font.css - 304 Not Modified (1ms)


Started GET "/assets/consumer_show.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /consumer_show.css - 304 Not Modified (2ms)


Started GET "/assets/datatable_styling.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /datatable_styling.css - 304 Not Modified (1ms)


Started GET "/assets/datepicker.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /datepicker.css - 304 Not Modified (2ms)


Started GET "/assets/devise_links.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /devise_links.css - 304 Not Modified (1ms)


Started GET "/assets/dispenser_show.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /dispenser_show.css - 304 Not Modified (1ms)


Started GET "/assets/fonts.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /fonts.css - 304 Not Modified (1ms)


Started GET "/assets/forms.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /forms.css - 304 Not Modified (2ms)


Started GET "/assets/gmaps4rails.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails.css - 304 Not Modified (1ms)


Started GET "/assets/jquery-ui-1.10.0.custom.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jquery-ui-1.10.0.custom.css - 304 Not Modified (2ms)


Started GET "/assets/jumbotrons.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jumbotrons.css - 304 Not Modified (1ms)


Started GET "/assets/layout.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /layout.css - 304 Not Modified (1ms)


Started GET "/assets/open_sans.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /open_sans.css - 304 Not Modified (2ms)


Started GET "/assets/popover.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /popover.css - 304 Not Modified (1ms)


Started GET "/assets/reviews.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /reviews.css - 304 Not Modified (1ms)


Started GET "/assets/spinner.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /spinner.css - 304 Not Modified (2ms)


Started GET "/assets/style_show.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /style_show.css - 304 Not Modified (2ms)


Started GET "/assets/style_show_reviews.css?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /style_show_reviews.css - 304 Not Modified (2ms)


Started GET "/assets/jquery.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jquery.js - 304 Not Modified (3ms)


Started GET "/assets/jquery_ujs.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jquery_ujs.js - 304 Not Modified (3ms)


Started GET "/assets/ui.custom.min.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /ui.custom.min.js - 304 Not Modified (1ms)


Started GET "/assets/bootstrap-transition.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-transition.js - 304 Not Modified (5ms)


Started GET "/assets/bootstrap-affix.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-affix.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-alert.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-alert.js - 304 Not Modified (4ms)


Started GET "/assets/bootstrap-button.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-button.js - 304 Not Modified (5ms)


Started GET "/assets/bootstrap-carousel.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-carousel.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-collapse.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-collapse.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-dropdown.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-dropdown.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-modal.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-modal.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-scrollspy.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-scrollspy.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-tab.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-tab.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap-tooltip.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-tooltip.js - 304 Not Modified (5ms)


Started GET "/assets/bootstrap-popover.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-popover.js - 304 Not Modified (52ms)


Started GET "/assets/bootstrap-typeahead.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap-typeahead.js - 304 Not Modified (3ms)


Started GET "/assets/bootstrap.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /bootstrap.js - 304 Not Modified (13ms)


Started GET "/assets/gmaps4rails/gmaps4rails.base.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails/gmaps4rails.base.js - 304 Not Modified (1ms)


Started GET "/assets/gmaps4rails/gmaps4rails.bing.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails/gmaps4rails.bing.js - 304 Not Modified (2ms)


Started GET "/assets/gmaps4rails/gmaps4rails.googlemaps.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails/gmaps4rails.googlemaps.js - 304 Not Modified (2ms)


Started GET "/assets/gmaps4rails/gmaps4rails.mapquest.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails/gmaps4rails.mapquest.js - 304 Not Modified (2ms)


Started GET "/assets/gmaps4rails/gmaps4rails.openlayers.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /gmaps4rails/gmaps4rails.openlayers.js - 304 Not Modified (2ms)


Started GET "/assets/jqueryplugins/addresspicker.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/addresspicker.js - 304 Not Modified (2ms)


Started GET "/assets/jqueryplugins/browser_detect.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/browser_detect.js - 304 Not Modified (3ms)


Started GET "/assets/jqueryplugins/charts.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/charts.js - 304 Not Modified (2ms)


Started GET "/assets/jqueryplugins/jquery.alphanumeric.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/jquery.alphanumeric.js - 304 Not Modified (1ms)


Started GET "/assets/jqueryplugins/jquery.formrestrict.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/jquery.formrestrict.js - 304 Not Modified (2ms)


Started GET "/assets/jqueryplugins/jquery.lazyload.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/jquery.lazyload.js - 304 Not Modified (1ms)


Started GET "/assets/jqueryplugins/raty.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /jqueryplugins/raty.js - 304 Not Modified (2ms)


Started GET "/assets/dataTables/jquery.dataTables.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /dataTables/jquery.dataTables.js - 304 Not Modified (13ms)


Started GET "/assets/dataTables/jquery.dataTables.bootstrap.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /dataTables/jquery.dataTables.bootstrap.js - 304 Not Modified (63ms)


Started GET "/assets/lib/abstract-chosen.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /lib/abstract-chosen.js - 304 Not Modified (12ms)


Started GET "/assets/lib/select-parser.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /lib/select-parser.js - 304 Not Modified (12ms)


Started GET "/assets/chosen.jquery.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /chosen.jquery.js - 304 Not Modified (8ms)


Started GET "/assets/chosen-jquery.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /chosen-jquery.js - 304 Not Modified (9ms)


Started GET "/assets/select2.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /select2.js - 304 Not Modified (7ms)


Started GET "/assets/highcharts.js?body=1" for 127.0.0.1 at 2013-03-10 21:46:44 +1300
Served asset /highcharts.js - 304 Not Modified (1ms)
Run Code Online (Sandbox Code Playgroud)

顺便说一下,根据reddit的建议,我预先编译了资产并运行了服务器.看到梦幻般的速度:

Processing by PagesController#home as HTML
Rendered pages/home.html.erb within layouts/application (1.1ms)
Completed 200 OK in 6ms (Views: 5.4ms | ActiveRecord: 0.0ms)
Run Code Online (Sandbox Code Playgroud)

好吧不确定这是否提供任何帮助,但主要延迟发生在堆栈中这两行代码之间:

From: /home/funkdified/.rvm/gems/ruby-1.9.3-p392@goodsounds/gems/actionpack-3.2.13.rc1/lib/action_controller/metal/implicit_render.rb @ line 5 ActionController::ImplicitRender#send_action:

    3: def send_action(method, *args)
    4:   ret = super
 => 5:   default_render unless response_body
    6:   ret
    7: end

[2] pry(#<PagesController>)> next
Run Code Online (Sandbox Code Playgroud)

主要延迟

From: /home/funkdified/.rvm/gems/ruby-1.9.3-p392@goodsounds/gems/actionpack-3.2.13.rc1/lib/action_controller/metal/implicit_render.rb @ line 6 ActionController::ImplicitRender#send_action:

    3: def send_action(method, *args)
    4:   ret = super
    5:   default_render unless response_body
 => 6:   ret
    7: end
Run Code Online (Sandbox Code Playgroud)

Abr*_*ram 118

好吧,我想通了(最后).在不改变任何实际资产的情况下,我现在看到这是开发:

Started GET "/" for 127.0.0.1 at 2013-03-11 23:14:33 +1300
Processing by PagesController#home as HTML
Rendered pages/home.html.erb within layouts/application (1.3ms)
Run Code Online (Sandbox Code Playgroud)

事实证明延迟是由config.assets.debug = true开发内部引起的.rb.设置此项以false解决问题.

看起来Rails核心团队在默认情况下争论不休,但决定反对这个想法.在将来,我很乐意看到他们在development.rb的评论部分添加了一些内容,以便向用户提示可能存在重大延迟.

我可以建议如下:

# Expands the lines which load the assets 
# May cause significant delays in view rendering
Run Code Online (Sandbox Code Playgroud)

太棒了,他们听到我嘀咕着,更新了铁轨!

  • 这绝对有帮助.虽然有一个小的修正:问题实际上是由'config.assets.debug = true'引起的,并将其更改为false修复它. (2认同)

Ant*_*n K 34

在rails 4.1+中出现了同样的问题.亚伯兰的答案只是部分完成.

您可以离开config.assets.debug = true但应禁用新资产验证功能

# Adds additional error checking when serving assets at runtime.
# Checks for improperly declared sprockets dependencies.
# Raises helpful error messages.
config.assets.raise_runtime_errors = false
Run Code Online (Sandbox Code Playgroud)

具有config.assets.debug禁用功能的解决方案只能运行,因为它会编译一次资产并验证资产一次.资产验证是大部分时间花在的地方.


Sea*_*ara 8

如果你来自rails 3.2.13请注意,很多人都遇到过这个问题并且恢复到3.2.12似乎解决了它.你可以在github上找到更多信息.

在我的情况下,禁用config.assets.debug加速的东西,但恢复到3.2.12将请求时间从大约4秒减少到大约250ms.