Latch導致MySQL Crash

沃趣科技高級數據庫專家  董 紅 禹

一、問題概述

最近我們遇到一個MySQL的問題，分析后很有代表意義，特地寫出來供大家參考。 
出現問題是，數據庫先是被置為只讀，然后過了一段時間，MySQL直接Crash掉了 
發生Crash時MySQL的error日志中打印了以下內容:

		


	
	

		---------- 
	

	

		SEMAPHORES 
	

	

		---------- 
	

	

		OS WAIT ARRAY INFO: reservation count 1246555 
	

	

		--Thread 140363572082432 has waited at row0upd.cc line 2354 for 253.00 seconds the semaphore: 
	

	

		X-lock (wait_ex) on RW-latch at 0x7fa949340740 created in file buf0buf.cc line 1069 
	

	

		a writer (thread id 140363572082432) has reserved it in mode  wait exclusive 
	

	

		number of readers 1, waiters flag 1, lock_word: ffffffffffffffff 
	

	

		Last time read locked in file btr0sea.cc line 931 
	

	

		Last time write locked in file /export/home/pb2/build/sb_0-17068951-1447697721.44/mysql-5.6.28/storage/innobase/row/row0upd.cc line 2354 
	

根據日志中我們可以看到，線程140363572082432要對記錄上一個X鎖，但是等待0x7fa949340740線程的RW-latch的釋放

我們在向下看查詢到如下信息(涉及到用戶信息 謂詞就用xxx代替):

		


	
	

		173 lock struct(s), heap size 30248, 7925 row lock(s), undo log entries 7924 
	

	

		MySQL thread id 5709783, OS thread handle 0x7fa8f0da7700, query id 92213034 10.23.163.54 citicqyh updating 
	

	

		update TB_DEPARTMENT_INFO set TOTAL_USER=1 where ID='ac84f17e-82d3-4519-a1da-0d5a5a835d44' 
	

	

		---TRANSACTION 53065242, ACTIVE 313 sec fetching rows, thread declared inside InnoDB 2081 
	

	

		mysql tables in use 2, locked 0 
	

	

		MySQL thread id 5428690, OS thread handle 0x7fa8f0136700, query id 92213061 10.23.163.55 citicqyh Sending data 
	

	

		SELECT COUNT(DISTINCT r.user_id) FROM TB_DEPARTMENT_INFO d left join tb_qy_user_department_ref r on r.department_id = d.id WHERE d.org_id = 'xxx' AND (d.dept_full_name LIKE 'xxx%' or d.dept_full_name = 'xxx 
	

	

		Trx read view will not see trx with id >= xxx, sees < xxx 
	

	

		......還有很多select語句省略 
	

根據上面信息我們去數據庫中查看了這些select語句，發現執行計劃都是全表掃描。 
首先數據庫變成了只讀，最后數據庫crash了，crash輸出的信息如下:

		


	
	

		---------------------------- 
	

	

		END OF INNODB MONITOR OUTPUT 
	

	

		============================ 
	

	

		InnoDB: ###### Diagnostic info printed to the standard error stream 
	

	

		InnoDB: Error: semaphore wait has lasted > 600 seconds 
	

	

		InnoDB: We intentionally crash the server, because it appears to be hung. 
	

	

		 7fa8f9580700 InnoDB: Assertion failure in thread 140363714529024 in file srv0srv.cc line 1754 
	

	

		InnoDB: We intentionally generate a memory trap. 
	

	

		InnoDB: Submit a detailed bug report to http://bugs.mysql.com. 
	

	

		InnoDB: If you get repeated assertion failures or crashes, even 
	

	

		InnoDB: immediately after the mysqld startup, there may be 
	

	

		InnoDB: corruption in the InnoDB tablespace. Please refer to 
	

	

		InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html 
	

	

		InnoDB: about forcing recovery. 
	

InnoDB: Error: semaphore wait has lasted > 600 seconds 提示600秒沒有響應 數據庫選擇了Crash 強制重啟

從報錯信息來看：

1. update語句需要在記錄上面加X鎖，但是必須等待RW-Latch的釋放
2. 由于有大量的select語句是全表掃描，一直占用latch沒有釋放，update遲遲競爭不到RW-latch
3. Innodb 的Diagnostic線程檢查到RW-Latch等待超過了600秒還沒有返回，認為系統出現了嚴重問題，于是觸發了MySQL服務的Crash。

二、進一步分析

這里首先需要補充一下Latch的概念：Latch在MySQL中是用于保護高速緩沖區中共享數據的，舉個例子: 
當我們執行select時，數據是緩存在buffer pool中的，多個線程并發訪問或者修改這個數據必然需要一個并發控制機制，這個就是Latch

大家知道，數據庫要訪問的數據都必須先存在緩存中，而緩存一般比磁盤空間要小，數據緩存使用hash表來記錄數據頁是否在內存中。在Oracle中的并發控制比較精細：首先會對hash桶加latch，并根據hash桶查找對應的數據并加上pin，然后釋放Latch。而MySQL相對沒有控制得這么精細，對應的RW-Latch在errlog中說的很清楚，該RW-Latch是在buf0buf.cc的1069行創建的 
RW-latch at 0x7fa949340740 created in file buf0buf.cc line 1069

對應的代碼摘錄如下：

		


	
	

		rw_lock_create(PFS_NOT_INSTRUMENTED, &block->lock, SYNC_LEVEL_VARYING); 
	

跟蹤源碼，知道這個Latch是MySQL在數據庫啟動，初始化 innodb_buffer_pool時，將Latch創建好的。對應的函數調用過·程:

		


	
	

		buf_pool_init_instance()->buf_chunk_init()->buf_block_init() 
	

正是由于這個RW-Latch被長時間占用了，其他的線程一直競爭不到，才導致了這個問題

三、修復建議

這類問題的發生多數都是因為SQL寫的不好，在表上面進行了大量的全表掃描占用了大量的Latch，解決方案就是避免SQL長時間占用latch：

1. 修改select查詢避免全表掃描，避免latch長期被占用
2. 適當的加索引，讓select執行更快，也避免一個select鎖的數據更少
3. 適當加大buffer pool instance，每個buffer pool都有自己獨立的Latch，避免latch競爭。