ruby-on-rails-3 - Rails 应用程序因 Rack::Lock 而面临性能问题

Question

我有一个具有以下版本的 Ruby on Rails 应用程序:

ruby :1.9.3-p547

导轨:3.2.16

我在此应用程序中遇到一些性能问题。我最初诊断此问题的努力使我开始使用文章中提到的 RackTimer gem ( https://github.com/joelhegg/rack_timer ) http://www.codinginthecrease.com/news_article/show/137153记录中间件时间戳。

使用它我发现 Rack::Lock 消耗了大量时间。下列的以下是以下日志中的一些 RackTimer 日志:

    Rack Timer (incoming) -- Rack::Lock: 73.77910614013672 ms
    Rack Timer (incoming) -- Rack::Lock: 67.05522537231445 ms
    Rack Timer (incoming) -- Rack::Lock: 87.3713493347168 ms
    Rack Timer (incoming) -- Rack::Lock: 59.815168380737305 ms
    Rack Timer (incoming) -- Rack::Lock: 55.583953857421875 ms
    Rack Timer (incoming) -- Rack::Lock: 111.56821250915527 ms
    Rack Timer (incoming) -- Rack::Lock: 119.28486824035645 ms
    Rack Timer (incoming) -- Rack::Lock: 69.2741870880127 ms
    Rack Timer (incoming) -- Rack::Lock: 75.4690170288086 ms
    Rack Timer (incoming) -- Rack::Lock: 86.68923377990723 ms
    Rack Timer (incoming) -- Rack::Lock: 113.18349838256836 ms
    Rack Timer (incoming) -- Rack::Lock: 116.78934097290039 ms
    Rack Timer (incoming) -- Rack::Lock: 118.49355697631836 ms
    Rack Timer (incoming) -- Rack::Lock: 132.1699619293213 ms

可以看出，Rack::Lock 中间件处理时间在 10 毫秒到 130 秒以上之间波动。 其中大部分内容都是在我的主页上提供资源时出现的。

顺便说一句，我在 config/application.rb 中启用了 Assets 管道

    # Enable the asset pipeline
    config.assets.enabled = true

我已将生产版本应用程序配置为由 NewRelic 进行监控。图表还突出显示了 Rack::Lock 所用的最高百分比和时间。

我完全不知道是什么导致 Rack::Lock 花费如此多的毫秒。如果社区中的任何人能够提供宝贵的指导来找出可能导致此问题的原因以及如何解决它，我将不胜感激？

下面可以找到Gemfile，所有中间件涉及的内容以及开发环境日志。

gem 文件:

https://gist.github.com/JigneshGohel-BoTreeConsulting/1b10977de58d09452e19

涉及的中间件:

https://gist.github.com/JigneshGohel-BoTreeConsulting/91c004686de21bd6ebc1

开发环境日志:

-----首次加载主页索引页

https://gist.github.com/JigneshGohel-BoTreeConsulting/990fab655f156a920131

----- 第二次加载主页索引页而无需重新启动服务器

https://gist.github.com/JigneshGohel-BoTreeConsulting/f5233302c955e3b31e2f

谢谢，吉格内什

Answer 1

在我发布上面的问题后，我在这里发布我的发现。希望其他人在遇到上述情况时能从这些发现中受益。

与我的一位高级同事Juha Litola讨论Rack::Lock问题时，以下是他的第一想法(原样引用他自己的话):

Could it just be possible that you are seeing measuring artifact in sense that you are just seeing Rack::Lock as taking a lot of time, but that is just because it is wrapping the actual call? So the Rack::Lock time is cumulative time from everything that happens in the request processing. See

https://github.com/rack/rack/blob/master/lib/rack/lock.rb .

As for the performance issues, could you elaborate on what kind of problems you have so I could help?

我认为这是有可能的。然而，由于以下疑问，我无法说服自己相信这种可能性:

Rack::Lock 位于中间件链中带有 Rails 应用程序的第二个位置(请参阅我在上面的帖子中提到的中间件列表 https://gist.github.com/JigneshGohel-BoTreeConsulting/91c004686de21bd6ebc1 )。并且每个中间件在链中按顺序进行处理。因此 Rack::Lock 将是第二个处理请求的然后链条中的其他人就有机会加入。

在这种情况下，根据我的理解，我不认为 Rack::Lock 中间件记录的时间戳是请求处理中发生的所有事情的累积时间。它应该是 Rack::Lock 所花费的时间中间件本身。

后来 Juha，花了几分钟查看服务器(参见下面的注释)配置提供了以下输入:

With a quick look I think that there is a quite clear problem in how the application has been configured. Application doesn’t have config.threadsafe! enabled, which means that Rack::Lock is enabled, and request processing is limited to one thread / process. Now puma is configured only to have one process, but 16-32 threads. What this means in effect that puma is currently processing only one request at given moment.

Best solution would of course be if you could enable thread safe mode, but that will require thorough testing. If that fails or is not an option puma should be configured with multiple workers with 1 thread each.

注意:我忘记添加有关部署我的应用程序的 Web 服务器配置的任何详细信息。我们正在使用 Puma Web 服务器 ( https://github.com/puma/puma )

这样我就得到了进一步深入了解config.threadsafe!的提示。在网上搜索我发现了以下文章

http://www.sitepoint.com/config-threadsafe/

http://tenderlovemaking.com/2012/06/18/removing-config-threadsafe.html

关于启用或禁用选项config.threadsafe!如何影响生产中部署在多线程或多进程网络服务器上的应用程序的性能提供了深刻的见解。

上述文章内容的简要总结

什么是 Rack::Lock？

Rack::Lock is a middleware that is inserted to the Rails middleware stack in order to protect our applications from the multi-threaded Bogeyman. This middleware is supposed to protect us from nasty race conditions and deadlocks by wrapping our requests with a mutex. The middleware locks a mutex at the beginning of the request, and unlocks the mutex when the request finishes.

假设有一个程序正在运行，并向其代码(例如 Controller )不是线程安全的应用程序同时发送 5 个请求 100 次。

现在让我们观察一下 Rack::Lock 中间件与 config.threadsafe 组合的影响!启用或禁用选项、应用程序中的线程不安全代码以及多线程或多进程 Web 服务器，在程序完成或被终止后

多线程 Web 服务器 (Puma)

# Combination 1:
    config.threadsafe! option   : Disabled
    Rack::Lock middleware       : Available in app's middleware stack because of config.threadsafe! option disabled

    With this combination the web server is successfully able to entertain all the 500 requests received.
    This is because each request is augmented by Rack::Lock so as to execute it synchronously.In other words
    Rack::Lock ensures we have only one concurrent request at a time.Thus each of the 500 requests gets a chance to
    execute.

# Combination 2:
    config.threadsafe! option   : Enabled
    Rack::Lock middleware       : Unavailable in app's middleware stack because of config.threadsafe! option enabled

    With this combination the web server is able to entertain only 200 out of 500 requests received.
    This is because of the absence of Rack::Lock middleware, which ensures that we have only one concurrent request
    at a time and thus each request gets a chance.

However there are advantages as well as disadvantages of each combination mentioned above:

# Combination 1
    Advantage:
        Each of the request received gets chance to be processed

    Disadvantage:
        * The runtime to process all of the 500 requests took 1 min 46 secs (compare it to runtime of Combination 2)
        * Using a multi-threaded webserver is useless, if Rack::Lock remains available in middleware stack.

# Combination 2
    Advantage:
        The runtime to process 200 requests took 24 secs (compare it to runtime of Combination 1).
        The reason being the multi-threaded nature of webserver is being leveraged in this case to entertain concurrent requests coming in.

    Disadvantage:
        * Not all 500 requests got a chance to be processed

注意:示例和运行时统计数据引用自 http://tenderlovemaking.com/2012/06/18/removing-config-threadsafe.html

多进程 Web 服务器 (Unicorn)

# Combination 1:
    config.threadsafe! option   : Disabled
    Rack::Lock middleware       : Available in app's middleware stack because of config.threadsafe! option disabled

    Since multiple processes are forked by the webserver and each of them listens for requests and also
    Rack::Lock middleware is available, the web server is successfully able to entertain all the 500 requests received.

# Combination 2:
    config.threadsafe! option   : Enabled
    Rack::Lock middleware       : Unavailable in app's middleware stack because of config.threadsafe! option enabled

    Here too multiple processes are forked by the webserver and each of them listens for requests,
    however Rack::Lock middleware is unavailable which enables multi-threading, which in turn means that we'll
    get a race condition in the thread-unsafe code we have in the application.But strangely with this combination
    too the web server is successfully able to entertain all the 500 requests received.

    The reason being a process-based web server creates worker processes and each process holds one instance of
    our application. When a request is received webserver spawns a child process for handling it.

结论:

• 在多进程环境中，如果我们保持 config.threadsafe，Rack::Lock 就会变得多余!选项已禁用。 这是因为在多进程环境中，套接字就是我们的锁，我们不需要任何额外的锁。 因此启用 config.threadsafe 是有好处的!并消除生产环境中的 Rack::Lock 开销。

• 在多线程环境中如果我们保持config.threadsafe!启用后，开发人员需要确保应用程序的代码是线程安全的。 以及保持 config.threadsafe 的优点!是处理传入请求所需的运行时间更少。

在我的应用程序上下文中，我们通过增加工作线程来调整 Puma 服务器的配置。希望性能有所提高。