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

yuanyiz · November 13, 2014 · Last by showlovel replied at November 25, 2014 · 3439 hits

今天服务器忽然出现性能问题,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 高的原因是什么,做了热备?

You need to Sign in before reply, if you don't have an account, please Sign up first.