MySQLbin-log分析方法

Author：Echo Chen（陳斌）Email：[email protected]：Blog.csdn.net/chen19870707Date：September 9th, 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
<span style="color:#ff0000;">UserRuneScape_tbl
15519</span>
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

http://www.cnblogs.com/edwardlost/archive/2011/07/13/2105598.html

Echo Chen：Blog.csdn.net/chen19870707