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