Locations of visitors to this page

Thursday, August 13, 2009

Slow queries issue

Troubleshooting case study: Slow queries issue


提问1
Focus on the queries of this form:
### 423 Queries 
### Total time: 13459, Average time: 31.8179669030733
### Taking 13  to 74  seconds to complete
### Rows analyzed 0 - 38
use db1;
SELECT *     FROM t_u_sch     WHERE s_time <= XXX     ORDER BY s_time ASC     LIMIT XXX     FOR UPDATE;

use db1;
SELECT *     FROM t_u_sch     WHERE s_time <= 1234567890     ORDER BY s_time ASC     LIMIT 38     FOR UPDATE;


These are scheduler related queries in the DB1 for FB, Twitter, MySpace, etc. We’re selecting a bunch of accounts to schedule work items for. So we select then update the last scheduled sync time column. We also insert new accts in these tables.


回答1
it's still hard to tell the root cause at the moment. but we found index of t_u_sch is fragmented,

mysql> show table status like
    -> 't_u_sch';
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| Name              | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation       | Checksum | Create_options | Comment                                                                          |
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| t_u_sch           | InnoDB |      10 | Compact    | 1140 |            172 |      196608 |               0 |    336592896 |         0 |           NULL | 2009-06-29 23:59:29 | NULL        | NULL       | utf8_general_ci |     NULL |                | InnoDB free: 3072 kB; (`b_a_id      `) REFER `db1/t_u     `(`b_a_id      `) ON D |
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
1 row in set (0.13 sec)

as you can see index length is abnormally larger than the data length, it may be caused by frequently deletion and insertion on table. when an index becomes fragmented, index scan query will take longer time. to defrag it and free up spaces, you can use "optimize table ..." or "alter table ... engine=innodb"

mysql> alter table t_u_sch ENGINE=INNODB;
Query OK, 763 rows affected (0.25 sec)
Records: 763  Duplicates: 0  Warnings: 0

mysql> show table status like 't_u_sch';
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| Name              | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation       | Checksum | Create_options | Comment                                                                          |
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| t_u_sch           | InnoDB |      10 | Compact    |  871 |            131 |      114688 |               0 |        49152 |         0 |           NULL | 2009-08-06 10:46:00 | NULL        | NULL       | utf8_general_ci |     NULL |                | InnoDB free: 0 kB; (`b_a_id      `) REFER `db1/t_u     `(`b_a_id      `) ON DELE |
+-------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
1 row in set (0.00 sec)


other *_u_sch* tables also need to be defragmented by this way.

thanks.

发现有些InnoDB表的索引很大, 而且随着时间推移不断的增大, 与实际数据量很不相符, 实际只有1000条左右的记录.
对这个表的操作主要是大量的UPDATE, 怀疑索引因此产生了碎片或平衡树的结构"失衡"了(Oracle数据库中也有这种情况)
但不能确定, 也不知道如何在测试系统上重现此错误(测试时发现如果不提交, UPDATE操作确实会导致索引一直变大, 但提交后, 发现过一段时间MySQL会自动收缩索引, 可以看到index_length变小)
临时的解决方法是, 定期优化表(optimize table ...), 达到重建索引, 释放空间的目的



提问2

We are continuing to get slow queries and used "SHOW TABLE STATUS' to see if there is index fragmentation. For some tables, I am finding that 'Index_length' is zero even though there are indexes on the table. This is happening on db.some.where.com.

For example:
# Time: 090806 21:48:12
# User@Host: user1[user1] @ a1.some.where.com [12.34.56.78]
# Query_time: 7  Lock_time: 0  Rows_sent: 6  Rows_examined: 6
use db1;
SELECT * FROM t_s_ch      WHERE b_a_id = '123456ABC' AND           s_a >= 28924     ORDER BY s_a ASC     LIMIT 2147483647;

mysql> show table status like 't_s_ch';
+-------------------+--------+---------+------------+---------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| Name              | Engine | Version | Row_format | Rows    | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation       | Checksum | Create_options | Comment                                                                          |
+-------------------+--------+---------+------------+---------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
| t_s_ch            | InnoDB |      10 | Compact    | 9462693 |            164 |  1559756800 |               0 |            0 |         0 |           NULL | 2009-04-24 17:21:19 | NULL        | NULL       | utf8_general_ci |     NULL |                | InnoDB free: 45056 kB; (`b_a_id      `) REFER `db1/f_u     `(`b_a_id      `) ON  | 
+-------------------+--------+---------+------------+---------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+----------------------------------------------------------------------------------+
1 row in set (0.70 sec)

Is there a reason why 'Index_length' would be zero? I am checking Google and I haven't found a reason so far. Does this table not have an index anymore?


回答2

I think it's an expected behavior. In InnoDB, every table must have a clustered index, data records are stored as leaf nodes of this index, which means clustered index is the data records, it is counted as data_length not index_length. In your case, the primacy key is the clustered index, and no other indexes exist, so index_length is zero.

InnDB表都必须有一个聚集索引(clustered index), 记录数据存储在这个聚集索引中, 类似于Oracle的索引组织表(index-organized table).
如果表上定义了主键, 则使用主键作为聚集索引
否则选择第一个非空的唯一索引作为聚集索引
如果都没有, 则内部创建一个隐藏的rowid单调递增列, 基于该列创建隐藏的聚集索引
(参考13.6.10.1. Clustered and Secondary Indexes)

所以聚集索引也就是记录数据, 算作data_length,而不是index_length


回答3

1.
from mysqladmin status output and slow query log, it seems there are some slow queries using full table scans

so we suggest:
1)add an index on customer_tab(custid,deptid)

2)extend the index in con_gr_tab/con_tab/con_id_tab/con_tab2 from (cust_id) to (cust_id,sn)

3)for following select statement, it is better to use "=" for comparision rather than "like"
SELECT d.deptid, d.customid, d.sn, d.version, d.email, d.dmi, d.area, d.provider, d.manufacturer, d.nation, d.number FROM custominfo d WHERE d.deptid LIKE '1234567890' LIMIT 100;

4)change dept_id in db_a_tab/db_base_tab/db_queue_tab/db_b_tab from varchar(80) to bigint(20)

5)decrease the size of cust_id in customs_tab from varchar(512) to varchar(80)


2.
in dbs, general/slow query logs are growing huge,
[db1.some.where.com]
-rw-rw---- 1 mysql mysql           0 Aug 11 15:56 /mysql_logs/error.log
-rw-rw---- 1 mysql mysql 41254683176 Aug 12 06:41 /mysql_logs/general.log
-rw-rw---- 1 mysql mysql  2117239370 Aug 12 06:41 /mysql_logs/slow-queries.log
[db2.some.where.com]
-rw-rw---- 1 mysql mysql           0 Aug 11 15:56 /mysql_logs/error.log
-rw-rw---- 1 mysql mysql 32935022398 Aug 12 06:41 /mysql_logs/general.log
-rw-rw---- 1 mysql mysql   458081312 Aug 12 06:41 /mysql_logs/slow-queries.log
[db3.some.where.com]
-rw-rw---- 1 mysql mysql           0 Aug 11 15:56 /mysql_logs/error.log
-rw-rw---- 1 mysql mysql 30089483757 Aug 12 06:41 /mysql_logs/general.log
-rw-rw---- 1 mysql mysql  1156294323 Aug 12 06:41 /mysql_logs/slow-queries.log
[db4.some.where.com]
-rw-rw---- 1 mysql mysql           0 Aug 11 15:56 /mysql_logs/error.log
-rw-rw---- 1 mysql mysql 29886541601 Aug 12 06:41 /mysql_logs/general.log
-rw-rw---- 1 mysql mysql  1871892345 Aug 12 06:41 /mysql_logs/slow-queries.log

these logs need to be cleaned up, logrotate can do this, for example:
# cat /etc/logrotate.d/mysql
/mysql/logs/error.log /mysql/logs/general.log /mysql/logs/slow-queries.log {
  daily
  create 0660 mysql mysql
  notifempty
  #size 100M
  missingok
  nocompress
  rotate 120
  sharedscripts
  postrotate
    /usr/bin/mysqladmin flush-logs
  endscript
}
 
# logrotate -f /etc/logrotate.d/mysql

it is also recommended to turn on general query log only when needed, since it is probably an impact on performance. to disable it, a restart of mysql server is required.
if using mysql 5.1, it can be disabled/enabled dynamically without restarting mysql.


3. for better innodb performance, increase innodb_buffer_pool_size, for example to 6g. in general, it can be set up to 80% of phsical memory size.


1.使用命令"mysqladmin extented-status -r -i60", 查看指定时间间隔内的数据库状态值的变化情况
Select_scan,Sort_scan说明存在全表扫描
通过查看慢速查询日志(slow query log), 能够发现运行时间超过指定时长的SQL语句
2.Linux自带Logrotate工具实现Mysql查询日志的归档
3.InnoDB缓冲池最好设大些, 比如通常可以设置为物理内存的80%



-fin-

No comments:

Website Analytics

Followers