Ruby China

Rails 性能问题求助：ActiveRecord 单次查询超过 1 秒怎么破 [已解决]

yuanyiz · 2014年11月13日 · 最后由 showlovel 回复于 2014年11月25日 · 3446 次阅读

今天服务器忽然出现性能问题，ActiveRecord 单次查询超过 1 秒，有的甚至超过了 10 秒，但是直接在 mysql 里面查询没有这样的问题：

I, [2014-11-13T09:27:21.299661 #10541] INFO -- : Completed 200 OK in 1598ms (Views: 0.2ms | ActiveRecord: 1589.2ms) I, [2014-11-13T09:27:21.300004 #10561] INFO -- : Completed 200 OK in 2303ms (Views: 0.2ms | ActiveRecord: 2293.5ms) I, [2014-11-13T09:27:21.301630 #10558] INFO -- : Completed 200 OK in 1760ms (Views: 0.2ms | ActiveRecord: 1750.8ms) I, [2014-11-13T09:27:21.304669 #10538] INFO -- : Completed 200 OK in 2201ms (Views: 0.2ms | ActiveRecord: 2192.2ms)

应用服务器是 unicorn，起了 15 个 worker，并发应该在 40 到 50 之间，绝大部分请求都是写操作，uptime 显示负载很高，但是 CPU 和内存占用率都还正常：

09:32:26 up 52 days, 19:46, 1 user, load average: 7.89, 7.50, 7.36

本地同样数据量也没有问题，所以感觉问题还是出在 Rails 这边，有没有人遇到过同样的问题，求破

99% 都是下面这样的请求，3 条写入操作，widgets 表数据最多，但是也不到 100 万记录：

Started PUT "/widgets/wAF3C974C44" for 127.0.0.1 at 2014-11-13 18:00:25 +0800 Processing by WidgetsController#update as JSON User Load (0.4ms) SELECT users.* FROM users WHERE users.id = 4 LIMIT 1 Widget Load (0.4ms) SELECT widgets.* FROM widgets WHERE widgets.cid = 'wAF3C974C44' ORDER BY widgets.id ASC LIMIT 1 Screen Load (0.4ms) SELECT screens.* FROM screens WHERE screens.id = 75148 LIMIT 1 Project Load (0.3ms) SELECT projects.* FROM projects WHERE projects.id = 12631 LIMIT 1 Unpermitted parameters: id (0.2ms) BEGIN Widget Exists (0.4ms) SELECT 1 AS one FROM widgets WHERE (widgets.cid = BINARY 'wAF3C974C44' AND widgets.id != 1123015 AND widgets.screen_cid = 's48C67660EE2D') LIMIT 1 SQL (0.4ms) UPDATE widgets SET height = 568, left = 94, top = 0, updated_at = '2014-11-13 10:00:25', width = 320 WHERE widgets.id = 1123015 (0.6ms) COMMIT (0.4ms) BEGIN SQL (2.2ms) UPDATE screens SET screens.updated_at = '2014-11-13 10:00:25' WHERE screens.id = 75148 (1.7ms) COMMIT (0.1ms) BEGIN SQL (0.5ms) UPDATE projects SET projects.updated_at = '2014-11-13 10:00:25' WHERE projects.id = 12631 (0.7ms) COMMIT Completed 200 OK in 26ms (Views: 0.5ms | ActiveRecord: 8.7ms)

找了个 DBA 看了下，说是磁盘 IO 太高，把 mysql 放到一块 SSD 上之后，目前看似乎是解决了。

2 个赞
easyhappy #1 2014年11月13日

信息给的不够多呀，查询 user 表是多少，查询语句是什么 都不告诉我们 你让我们怎么破

zj0713001 #2 2014年11月13日

load average 看起来是 8 核 CPU 但是你开了 15 个 worker 这不科学

yuanyiz #4 2014年11月13日

#2 楼 @zj0713001 额，那应该开多少？

dongqs #5 2014年11月13日

在 config/environments/production.rb 中设置 log_level 为 debug 看看具体是哪条 sql 慢

zj0713001 #6 2014年11月13日

#4 楼 @yuanyiz 一般如果是单台服务器又有 rails 又有数据库 肯定互相影响 如果单台服务器只有 rails 的话 worker 数量一般为 CPU 核数 -1 8 核就开 7 个 worker 甚至更少 如果这个服务器上有数据库 一般开 5 个

yuanyiz #7 2014年11月13日

#6 楼 @zj0713001 恩，那我先把 Rails 和数据库分开，然后减少一点 worker 数量试试看

yedingding #8 2014年11月13日

#6 楼 @zj0713001 你这样肯定浪费，对于运算要求不高的应用 CPU 闲置率很高。Worker 设多少跟应用、内存和核数都有关系，不是一个 Worker 在一个 CPU 上其他 Worker 就不能被这个 CPU 调度了的，IO 操作时就空出来了，所以还是得实际看应用类型测试，对于大部分 Rails 应用程序来说，都不是 CPU-bound 应用。

@yuanyiz 有两种可能性，一种是索引有问题，一种是锁机制导致竞态。你在服务器上打开日志看看哪些 SQL 请求耗时，还有打开 MySQL 的 slowlog 看看是什么问题。

zj0713001 #9 2014年11月14日

#8 楼 @yedingding 目前来看 稍微复杂一点的应用场景 比方说需要同时计算价格库存的时候 瞬间 worker 进程都需要 CPU 70% 以上，业务量大了现在遇到的基本上都是每个 worker 700M 以上内存 实时有 3-4 个 worker 70%CPU 所以开多了肯定不行的

zj0713001 #10 2014年11月14日

#8 楼 @yedingding 当然我遇到的一些项目有历史原因 都是单线程的 已经没法改成多线程了 开的多了就意味着互相等 IO

hooopo #11 2014年11月14日

建议上 NewRelic，分分钟找到问题根源。。。我们之前也有类似问题，按经验去找无果，，通过 NewRelic 发现是 Redis 搞的鬼。。。换 Memcached 后问题消除。

yuanyiz #12 2014年11月14日

#11 楼 @hooopo @yedingding 恩，这就把 newrelic 加上，问题已经找到了，找了个 DBA 看了下，说是 IO 太高，把 mysql 转移到一块 SSD 硬盘上之后，暂时看起来又正常了

showlovel #13 2014年11月25日

IO 高的原因是什么，做了热备？

需要 登录 后方可回复, 如果你还没有账号请 注册新账号