mysql log bin 分析_MySQL bin-log分析方法

Author：Echo Chen(陈斌)

Email：chenb19870707@gmail.com

Date：September9th, 2014

Explain      前段时间，游戏服务器停服的时候总是很慢，幸运的是游戏数据库都开了bin-log，于是可以通过bin-log来分析停服时执行SQL语句的数量和执行时间，下面整理了一些关键步骤。

找到对应时间的bin-log文件

如果没有在/etc/my.cnf中配置bin-log位置，MySQL的bin-log默认文件位置在/var/lib/mysql下：

cd /var/lib/mysql

ll -t

找到想要查找的时间段的SQL文件，如果时间在两个个文件内，两个文件都需要。例如：这里要查找的是8月21 15:30 ~16:00，需要的文件就是mysql-bin.000006

把二进制的文件转换成文本文件

mysqlbinlog mysql-bin.000006 > mysql-bin.000006.txt

这个需要等待一点时间，需要等待一会儿.

将文本文件压缩拷贝到本地

tar jcvf binlog.tar.bz2 mysql-bin.000006.txt

sz binlog.tar.bz2

用文本工具打开文件，截取需要的时间段

先看一下文本格式 bin-log 的记录格式：

# at 7473

#110630 11:56:05 server id 1 end_log_pos 7612 Query thread_id=6 exec_time=0 error_code=0

SET TIMESTAMP=1309406165/*!*/;

UPDATE ssmatch.young_league_match_7 SET status='playing' WHERE mid=699617

/*!*/;

这里有每一条SQL的执行时间，根据自己的需要，将不需要的时间段内的SQL删掉，这里最好用UltraEdit,因为文件比较大。

分析bin-log文件-----执行次数分析

table_list=(

Account_tbl

Activity_tbl

AwardMsg_tbl

BBRankFightPos_tbl

BloodBattleRank_tbl

BloodBattle_tbl

Card_tbl

Checkin_tbl

ClickMsg_tbl

DuelRank_tbl

DynamicRune_tbl

EquipFragment_tbl

Equipment_tbl

FightingPos_tbl

Friends_tbl

Gemstone_tbl

Ghost_tbl

HeroAttribute_tbl

HeroJuedi_table

ItemMarket_tbl

Item_tbl

LadderData_tbl

LadderPlayer_tbl

LadderRankList_tbl

Mission_tbl

MysteryShop_tbl

PlayerStatistics_tbl

Player_tbl

RuneScapeRecovery_tbl

Skill_tbl

SkyLadderFightingPosition_tbl

TipsMsg_tbl

Treasure_tbl

UserRuneScape_tbl

VipCard_tbl

)

for i in ${table_list[@]}; do

echo ${i}

grep -w ${i} . -r | grep -w UPDATE | wc -l

done

table_list为所有表的表名，执行以上脚本将打印所有表的UPDATE次数。

Account_tbl

0

Activity_tbl

4281

AwardMsg_tbl

0

BBRankFightPos_tbl

1527

BloodBattleRank_tbl

190

BloodBattle_tbl

4281

Card_tbl

376

Checkin_tbl

4273

ClickMsg_tbl

0

DuelRank_tbl

83

DynamicRune_tbl

4276

EquipFragment_tbl

0

Equipment_tbl

95

FightingPos_tbl

103

Friends_tbl

34

Gemstone_tbl

43

Ghost_tbl

3

HeroAttribute_tbl

4271

HeroJuedi_table

0

ItemMarket_tbl

0

Item_tbl

486

LadderData_tbl

0

LadderPlayer_tbl

3616

LadderRankList_tbl

0

Mission_tbl

4281

MysteryShop_tbl

4279

PlayerStatistics_tbl

0

Player_tbl

4282

RuneScapeRecovery_tbl

10

Skill_tbl

15

SkyLadderFightingPosition_tbl

3744

TipsMsg_tbl

0

Treasure_tbl

4274

UserRuneScape_tbl

15519

VipCard_tbl

6

在这里看到UserRuneScape这个表执行的次数很多。

分析bin-log文件-----执行时间分析

再看一下文本格式 bin-log 的记录格式：

# at 7473

#110630 11:56:05 server id 1 end_log_pos 7612 Query thread_id=6 exec_time=0 error_code=0

SET TIMESTAMP=1309406165/*!*/;

UPDATE ssmatch.young_league_match_7 SET status='playing' WHERE mid=699617

/*!*/;

exec_time即为执行时间，执行

grep -w exec_time=1 -r . |wc -l

即可查出执行在1s时间的条数，此外greo的参数-b表示在取出前几行，-a表示取出后几行，我们这里找出执行慢的SQL语句。

grep -a1b6 -w exec_time=1 -r . > ~/test/result.txt

将结果保存在result.txt中，再grep UPDATE 即可得到执行慢的SQL.

cd ~/test

grep -w UPDATE -r . > ~/Desktop/result.txt

在稍作处理，去除每一行的文件名，即可得到SQL语句

Reference

-

-