MySQL數據庫出現大量Locked的一個案例
雖說簡單,但show processlist顯示的信息確實是相當有用,有一回,三思收到反饋說MySQL查詢很慢,于是,趕緊登錄到mysql中,執行show processlist查看當前連接信息:
mysql> show processlist; +--------+-------------+--------------------+-------+---------+-------+----------------------------------+----------------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +--------+-------------+--------------------+-------+---------+-------+----------------------------------+----------------------------------------------------------------------------------+ | 1 | system user | | NULL | Connect | 342266| Waiting for master to send event | NULL | | 2 | system user | | hdpic | Connect | 872 | Locked | UPDATE a SET STATE=0 WHERE ID=83752 | | 123890 | hdpic_read | 192.168.1.79:54910 | hdpic | Query | 1512 | Sending data | select z.ID,z.TITLE,z.CREATOR_USER_NICK,z.CREATOR_USER_IDEN,z.LASTEDITOR_TI | | 124906 | hdpic_read | 192.168.1.39:18844 | hdpic | Query | 845 | Locked | select * from a where ((ID = 78789) AND (STATE != 0)) | | 124912 | hdpic_read | 192.168.1.39:18862 | hdpic | Query | 845 | Locked | select * from a where ((ID = 16031) AND (STATE != 0)) | | 124914 | hdpic_read | 192.168.1.39:18865 | hdpic | Query | 837 | Locked | select * from a where ((ID = 39109) AND (STATE != 0)) | | 124917 | hdpic_read | 192.168.1.39:18875 | hdpic | Query | 833 | Locked | select * from a where ((ID = 16031) AND (STATE != 0)) | ................ ................ ................ |
一堆的Locked,怪不得慢啊,阻塞的時間不短了,十幾分鐘。
通常來說存在Locked就說明當前讀寫操作存在被阻塞的情況,一般我們看到鎖都會下意識認為是由于寫阻塞了讀,上面的結果看仿佛也符合這一特征:只有一條UPDATE,而無數條的SELECT。猜是必須的,但不能瞎猜,這畢竟是線上系統,就算想殺連接的線程,也是要殺掉造成阻塞的那個,不能把所有Locked的全殺了,不然DBA本人很快也要被人殺了,因此具體情況如何還是需要繼續分析。
從show processlist查看到的信息來看,UPDATE的語句是很簡單的,分析a的表結構,該表為MyISAM表,ID為該表主鍵,該條更新應該能夠瞬間執行完,即使系統繁忙也不應該,而且通過查看當前的系統狀態,整體負載很低,iostat中看I/Owait幾可忽略,該寫操作不太可能這么長時間都沒有執行完。
這個時候再分析show processlist中顯示的信息,發現id 123890的語句執行時間最長,肯定是在該UPDATE語句之前執行的,通過show full processlist查看語句詳表,看到該查詢也訪問到了a表,經此分析,應該是該語句長時間的讀阻塞了寫,而被阻塞的寫操作由于處于最優先處理隊列,又阻塞了其它的讀。
不過這些都還只是我們的推論,考慮到線上系統服務的可靠性,最好還是能找到更確切的證據,而后再做操作。
mysqladmin命令有一個debug參數,可以分析當前MySQL服務的狀態信息,同時也可以用來幫助我們定位當前鎖的詳細情況,這里我們通過該命令分析一下當前MySQL服務的詳細狀態,執行mysqladmin命令如下:
[root@phpmysql02 data]# mysqladmin -ujss -p -S /data/3306/mysql.sock debug
Enter password:
debug會將狀態信息生成到mysql的錯誤文件,一般鎖的信息都會保存在最后幾行,這里我們在操作系統層error log最后幾行:
[root@phpmysql02 data]# tail -10 phpmysql02.err Thread database.table_name Locked/Waiting Lock_type 2 hdpic.t_wiki_zutu Waiting - write Highest priority write lock 123890 hdpic.t_wiki_zutu_category Locked - read Low priority read lock 123890 hdpic.t_wiki_zutu_photo Locked - read Low priority read lock 123890 hdpic.t_wiki_zutu Locked - read Low priority read lock 124906 hdpic.t_wiki_zutu Waiting - read Low priority read lock |
從上述信息可以看出,123890持有的讀鎖阻塞了2的寫入和124906的讀操作,這個狀態符合我們的推論,接下來處理就比較單純了,如果現狀不可接受,不能繼續等待,將123890殺掉,釋放資源即可:
mysql> kill 123890;
Query OK, 0 rows affected (0.00 sec)
再次執行show processlist查看:
mysql> show processlist; +--------+-------------+--------------------+-------+---------+--------+----------------------------------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +--------+-------------+--------------------+-------+---------+--------+----------------------------------+------------------+ | 1 | system user | | NULL | Connect | 342390 | Waiting for master to send event | NULL | | 124906 | hdpic_read | 192.168.1.39:18844 | hdpic | Sleep | 1 | | NULL | | 124912 | hdpic_read | 192.168.1.39:18862 | hdpic | Sleep | 2 | | NULL | | 124914 | hdpic_read | 192.168.1.39:18865 | hdpic | Sleep | 1 | | NULL | | 124917 | hdpic_read | 192.168.1.39:18875 | hdpic | Sleep | 1 | | NULL | | 124919 | hdpic_read | 192.168.1.39:18877 | hdpic | Sleep | 2 | | NULL | ................ ................ ................ |
已經沒有Locked的連接,此時向前端人員詢問,告知響應慢的現象也已經消除,服務恢復正常。
posted on 2014-01-07 10:44 順其自然EVO 閱讀(270) 評論(0) 編輯 收藏 所屬分類: 數據庫