今天开始处理我们的后台数据库中的一个mysql的问题,问题症状是,每天有个不固定的时间,整个系统的sql执行会非常慢,如果你不理他,过会就自己好了。
简单分析了下,那个系统就两个表,被设计成了mysql cluster模式。
在slow log中有如下内容:
………
Count: 3568 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost
# Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N
SET timestamp=N;
select * from session where sky_id=N
Count: 284 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost
# Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N
SET timestamp=N;
delete from session where sky_id=N
Count: 690 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost
# Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N
SET timestamp=N;
insert into session(sky_id, user_name, nick_name, nick_name1, gender, age, portrait_id, token, province, city, pos_code, pos_desc, acc_esbaddr, acc_session_index, acc_type, ip, alive_check, rand_tag, last_oltime, logintime) values(N, ‘S’, ‘S’, ‘S’, N, N, N, N, ‘S’, ‘S’, N, ‘S’, N, N, N, ‘S’, N, N, N, N)
Count: 1572 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost
# Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N
SET timestamp=N;
select * from session where sky_id in (N,N)
Count: 3568 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost # Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N SET timestamp=N; select * from session where sky_id=N
Count: 284 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost # Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N SET timestamp=N; delete from session where sky_id=N
Count: 690 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost # Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N SET timestamp=N; insert into session(sky_id, user_name, nick_name, nick_name1, gender, age, portrait_id, token, province, city, pos_code, pos_desc, acc_esbaddr, acc_session_index, acc_type, ip, alive_check, rand_tag, last_oltime, logintime) values(N, ‘S’, ‘S’, ‘S’, N, N, N, N, ‘S’, ‘S’, N, ‘S’, N, N, N, ‘S’, N, N, N, N)
Count: 1572 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), session[session]@localhost # Query_time: N.N Lock_time: N.N Rows_sent: N Rows_examined: N SET timestamp=N; select * from session where sky_id in (N,N)
………………..
这段代码看,执行慢最多的sql居然是在session表上的,看看session表的结构
mysql> desc session;
+——————-+———————+——+—–+———+——-+
| Field | Type | Null | Key | Default | Extra |
+——————-+———————+——+—–+———+——-+
| sky_id | int(10) unsigned | NO | PRI | NULL | |
| user_name | char(32) | NO | | NULL | |
| nick_name | char(32) | YES | | NULL | |
| nick_name1 | char(64) | YES | | NULL | |
| gender | tinyint(1) | YES | | NULL | |
| age | int(10) unsigned | YES | | NULL | |
| portrait_id | int(10) unsigned | YES | | NULL | |
| token | int(10) unsigned | YES | | NULL | |
| province | char(32) | YES | | NULL | |
| city | char(32) | YES | | NULL | |
| pos_code | int(10) unsigned | YES | | NULL | |
| pos_desc | varchar(64) | YES | | NULL | |
| acc_esbaddr | int(10) unsigned | YES | | NULL | |
| acc_session_index | int(10) unsigned | YES | | NULL | |
| acc_type | tinyint(3) unsigned | YES | | NULL | |
| ip | char(15) | YES | | NULL | |
| alive_check | int(10) unsigned | YES | | NULL | |
| longitude | int(11) | YES | MUL | NULL | |
| latitude | int(11) | YES | MUL | NULL | |
| loc_desc | varchar(64) | YES | | NULL | |
| rand_tag | int(11) | YES | MUL | NULL | |
| mid | varchar(256) | YES | | NULL | |
| last_oltime | int(11) | YES | | 0 | |
| logintime | int(11) | YES | | 0 | |
+——————-+———————+——+—–+———+——-+
24 rows in set (0.05 sec)
可以看出,sky_id上是主键。
再看看这个执行最慢的几个sql的执行计划:
mysql> explain select * from session where sky_id=112414853 \G;
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: NULL
type: NULL
possible_keys: NULL
key: NULL
key_len: NULL
ref: NULL
rows: NULL
Extra: Impossible WHERE noticed after reading const tables
1 row in set (0.00 sec)
ERROR:
No query specified
mysql>
mysql>
mysql> explain select * from session where sky_id in (112414853,-1,-1) \G;
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: session
type: range
possible_keys: PRIMARY
key: PRIMARY
key_len: 4
ref: NULL
rows: 2
Extra: Using where with pushed condition
1 row in set (0.00 sec)
ERROR:
No query specified
居然,既然,在主键上使用了=比较的sql,执行计划不正常。
这个问题,到现在我还没分析出来是为啥,不过,千万别告诉我,第一次处理mysql的问题就是bug,虽然我个人觉得很像是某个bug
最后,看看我的数据库的版本吧
mysql> select version();
+——————————-+
| version() |
+——————————-+
| 5.1.27-ndb-6.3.17-cluster-gpl |
+——————————-+
1 row in set (0.01 sec)
嗯,还有操作系统的版本:
Linux 2.6.18-92.el5PAE #1 SMP 2008 i686 i686 i386 GNU/Linux
欢迎mysql高手,就这个问题给予建议。
—————————HLL的分隔线————————————————–
在昨天晚上的跟踪中,应用发现,出现过一次堵塞的情况,持续了大概一分多钟,幸运的是,抓取到了部分信息,不幸的是,只抓取到堵塞后期的信息。抓取到的信息如下: