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

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

今天服务器忽然出现性能问题,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 上之后,目前看似乎是解决了。

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

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

#2 楼 @zj0713001 额,那应该开多少?

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

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

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

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

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

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

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

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

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

IO 高的原因是什么,做了热备?

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