导轨。第一个请求太慢，超时，下一个更快

Question

我正在开发一个 Rails 应用程序。在 Heroku 上顺利推送 git 后，该应用程序在网络浏览器中显示错误“请求超时”。

如果我在 1 分钟后重新尝试，该应用程序会在网络浏览器上非常快速地显示该页面。

配置

在我的配置下面找到

• 导轨 5.1.2

• psql (PostgreSQL) 9.6.1

gem文件中的主要信息：

ruby '2.2.6'

gem 'rails', '~> 5.1.1'

gem 'pg', '~> 0.18'

gem 'puma', '~> 3.7'

赫鲁库

Standard-2X dynos, Shared, 1 GB RAM

Heroku Postgres :: Brown

Memcached Cloud :free

Papertrail :free

STANDARD PLAN

日志

第一个很长的请求的日志（注意我在测试前重新启动服务器以重现每天早上在第一个请求时附加的问题）

Aug 25 03:28:15 myapplication app/web.1:  => Booting Puma 
Aug 25 03:28:15 myapplication app/web.1:  => Rails 5.1.2 application starting in production on http://0.0.0.0:41080 
Aug 25 03:28:15 myapplication app/web.1:  => Run `rails server -h` for more startup options 
Aug 25 03:28:15 myapplication app/web.1:  [4] Puma starting in cluster mode... 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Version 3.9.1 (ruby 2.2.6-p396), codename: Private Caller 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Min threads: 5, max threads: 5 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Environment: production 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Process workers: 2 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Preloading application 
Aug 25 03:28:15 myapplication app/web.1:  [4] * Listening on tcp://0.0.0.0:41080 
Aug 25 03:28:15 myapplication app/web.1:  [4] Use Ctrl-C to stop 
Aug 25 03:28:15 myapplication app/web.1:  [4] - Worker 0 (pid: 6) booted, phase: 0 
Aug 25 03:28:15 myapplication app/web.1:  [4] - Worker 1 (pid: 19) booted, phase: 0 
Aug 25 03:28:15 myapplication heroku/web.1:  State changed from starting to up 
Aug 25 03:28:37 myapplication app/heroku-postgres:  source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.057733 sample#memory-total=4044984kB sample#memory-free=1550168kB sample#memory-cached=1945532kB sample#memory-postgres=16880kB 
Aug 25 03:30:38 myapplication app/heroku-postgres:  source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.029687 sample#memory-total=4044984kB sample#memory-free=1550000kB sample#memory-cached=1945544kB sample#memory-postgres=16880kB 
Aug 25 03:31:39 myapplication app/heroku-postgres:  source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.029687 sample#memory-total=4044984kB sample#memory-free=1549940kB sample#memory-cached=1945564kB sample#memory-postgres=16880kB 
Aug 25 03:32:38 myapplication app/heroku-postgres:  source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.029687 sample#memory-total=4044984kB sample#memory-free=1550284kB sample#memory-cached=1945568kB sample#memory-postgres=16880kB 
Aug 25 03:33:39 myapplication app/heroku-postgres: source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=2 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.030191 sample#memory-total=4044984kB sample#memory-free=1550128kB sample#memory-cached=1945580kB sample#memory-postgres=16880kB 
Aug 25 03:33:51 myapplication heroku/router: at=info method=GET path="/" host=myapplication.herokuapp.com request_id=afa5c118-7319-4b9b-a945-60ed57a63062 fwd="90.87.43.215" dyno=web.1 connect=0ms service=72ms status=301 bytes=371 protocol=https 
Aug 25 03:33:51 myapplication app/web.1: I, [2017-08-25T10:33:50.584824 #19]  INFO -- : [afa5c118-7319-4b9b-a945-60ed57a63062] Started GET "/" for 90.87.43.215 at 2017-08-25 10:33:50 +0000 
Aug 25 03:33:51 myapplication app/web.1: I, [2017-08-25T10:33:50.665212 #19]  INFO -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61] Started GET "/projets/new" for 90.87.43.215 at 2017-08-25 10:33:50 +0000 
Aug 25 03:33:51 myapplication app/web.1: I, [2017-08-25T10:33:50.670054 #19]  INFO -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61] Processing by ProjetsController#new as HTML 
Aug 25 03:33:51 myapplication app/web.1: D, [2017-08-25T10:33:50.783930 #19] DEBUG -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61]   User Load (3.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2  [["id", 2], ["LIMIT", 1]] 
Aug 25 03:33:51 myapplication app/web.1: D, [2017-08-25T10:33:50.928475 #19] DEBUG -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61]   Regleconfiguration Load (3.4ms)  SELECT  "regleconfigurations".* FROM "regleconfigurations" ORDER BY "regleconfigurations"."id" DESC LIMIT $1  [["LIMIT", 1]] 
Aug 25 03:33:51 myapplication app/web.1: D, [2017-08-25T10:33:50.955570 #19] DEBUG -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61]   Tarifoptionbt Load (3.2ms)  SELECT "tarifoptionbts".* FROM "tarifoptionbts" 
Aug 25 03:33:51 myapplication app/web.1: I, [2017-08-25T10:33:50.989799 #19]  INFO -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61]   Rendering projets/new.html.erb within layouts/application 
Aug 25 03:34:21 myapplication heroku/router: at=error code=H12 desc="Request timeout" method=GET path="/projets/new" host=myapplication.herokuapp.com request_id=6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61 fwd="90.87.43.215" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=https 
Aug 25 03:34:39 myapplication app/heroku-postgres: source=HEROKU_POSTGRESQL_BROWN sample#current_transaction=2339 sample#db_size=25066008bytes sample#tables=21 sample#active-connections=3 sample#waiting-connections=0 sample#index-cache-hit-rate=0.99931 sample#table-cache-hit-rate=0.996 sample#load-avg-1m=0 sample#load-avg-5m=0 sample#load-avg-15m=0 sample#read-iops=0 sample#write-iops=0.029687 sample#memory-total=4044984kB sample#memory-free=1547512kB sample#memory-cached=1945596kB sample#memory-postgres=20036kB 
Aug 25 03:35:37 myapplication app/web.1: I, [2017-08-25T10:35:37.131381 #19]  INFO -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61]   Rendered projets/_etapebar.html.erb (106132.4ms) 

[.....] 渲染 30 局部视图

Aug 25 03:35:38 myapplication app/web.1: I, [2017-08-25T10:35:37.495939 #19]  INFO -- : [6db31a1a-39a5-4a8f-9ba1-cf35ceae5f61] Completed 200 OK in 106826ms (Views: 106499.5ms | ActiveRecord: 50.2ms) 

如果我第二次渲染相同的视图，我会得到这个日志：

Aug 25 05:42:45 myapplication app/web.1: I, [2017-08-25T12:42:44.339695 #19]  INFO -- : [9c38a6b8-73d4-4e31-9ac3-df2ec8b21049] Started GET "/projets/new" for 90.87.43.215 at 2017-08-25 12:42:44 +0000 
Aug 25 05:42:45 myapplication app/web.1: I, [2017-08-25T12:42:44.341197 #19]  INFO -- : [9c38a6b8-73d4-4e31-9ac3-df2ec8b21049] Processing by ProjetsController#new as HTML 
Aug 25 05:42:45 myapplication app/web.1: D, [2017-08-25T12:42:44.348612 #19] DEBUG -- : [9c38a6b8-73d4-4e31-9ac3-df2ec8b21049]   User Load (1.7ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2  [["id", 2], ["LIMIT", 1]] 
Aug 25 05:42:45 myapplication app/web.1: I, [2017-08-25T12:42:44.351579 #19]  INFO -- : [9c38a6b8-73d4-4e31-9ac3-df2ec8b21049] Completed 200 OK in 10ms (ActiveRecord: 1.7ms)

应用程序从 106 秒跳转到服务第一个请求（即创建 Heroku 错误）到第二个渲染中的很短时间

资产

日志显示第二次调用从请求中获取资产。

在我的应用程序中，在每个页面上，我加载当前控制器的 js：

在 application.html.erb

<%= stylesheet_link_tag controller.controller_name if TarifsDynamique::Application.assets.find_asset("#{controller.controller_name}.css") %>
<%= javascript_include_tag params[:controller] if TarifsDynamique::Application.assets.find_asset("#{controller.controller_name}.js") %> 

在 application.js 和 .css 中，我删除了 //=require 。

在 asset.rb 中，我添加

 Rails.application.config.assets.precompile += ["#{controller}.js", "#{controller}.css"]

与所有控制器。

这是工作 find （在 devvellpoment 和第一次调用后的生产中）。

但是当我尝试

$Heroku run assets:precompile

我收到这个错误

Running rake assets:precompile on ? myapplication... up, run.9829 (Standard-1X)
Yarn executable was not detected in the system.
Download Yarn at https://yarnpkg.com/en/docs/install
...

缓存

我尝试添加缓存以加速第一页

• 控制器内的缓存操作：

  class ProjetsController < ApplicationController
  
    caches_action :new, :edit
  

• 缓存视图：new.html.erb

  <%= render 'form', projet: @projet, cached: true %>
  

• production.rb 中的活动缓存

  Rails.application.configure do
  
      config.cache_classes = true
  

不知道

我不知道如果你有一个想法，它会很有帮助！

谢谢。

[编辑] 解决方案

嗨，我终于找到了怎么回事！我有 50 张图像要在资产文件夹中编译。即使我预编译它们，在长时间睡眠后的第一个请求时，Rails 也会再次预编译它们，这需要很多时间。

1- 我在 amason S3 上移动图像，2- 将 image_tag 更改为 image_static_tag 3- 创建一个 image_static_tag 帮助程序，用于从 s3 提供静态文件 4- 重新部署应用程序，现在一切正常！

感谢您的帮助