1. 程式人生 > >Mysql監控元件mymon報錯“NewMySQLConnection Error: Building mysql connection failed!: unexpected EOF”問題

Mysql監控元件mymon報錯“NewMySQLConnection Error: Building mysql connection failed!: unexpected EOF”問題

mymon是Open-falcon的用來監控Mysql的元件,今天使用起來遇到了一個問題,資料庫明明正確配置,但是啟動的時候總是報“NewMySQLConnection Error: Building mysql connection failed!: unexpected EOF”的錯誤

系統Centos6.10,Mysql5.1.73,中間都是我除錯的過程記錄,如果想看解決方案直接去第5節

1 粗略分析

定位一下程式碼,發現Mysql的連線是common/mysql.go這個檔案負責的,看一下程式碼如下

我開始以為是conf.DataBase這幾個配置項出了問題,直接替換成了文字,仍然報錯

mymon呼叫的是一個叫mymysql的mysql驅動,無奈,只好開始排查mymysql的問題

決定抓包分析之,看一下mymysql和Mysql之間的TCP連線

2 報文分析

用Linux自帶工具tcpdump,在mysql端抓取,-w表示儲存為檔案,網絡卡根據自己的情況選擇

tcpdump -w tcp.pcap -i [網絡卡] port 3306

登陸完mysql,把檔案弄回windows用wireshark開啟

2.1 正常連線的TCP報文

登入Mysql,密碼正確登陸成功,mysql的機器ip是56.24,登陸的機子是56.21

sudo tcpdump -w correct.pcap -i eth1 port 3306 #在mysql的機器上
mysql -u root -p  #用另一臺虛擬機器,遠端登入mysql

wireshark開啟

2.2 mymon的報文

sudo tcpdump -w mymon.pcap -i lo port 3306 #在mysql的機器上
./mymon etc/myMon.cfg  #啟動mymon

同樣wireshark開啟

2.3 分析

兩個報文一對比很明顯了,上面是mymon下面是正常的,可以看到在資料庫傳送了版本號等資訊後,mymon沒有給資料庫傳送登陸請求的報文,然後等待了10秒之後資料庫斷開了連線

3 mymysql原始碼分析

分析原始碼定位到native/init.go資料夾下的auth()函式,這個函式是負責傳送登陸使用者名稱和密碼的,程式碼如下

func (my *Conn) auth() {
	if my.Debug {
		log.Printf("[%2d <-] Authentication packet", my.seq)
	}
	flags := uint32(
		_CLIENT_PROTOCOL_41 |
			_CLIENT_LONG_PASSWORD |
			_CLIENT_LONG_FLAG |
			_CLIENT_TRANSACTIONS |
			_CLIENT_SECURE_CONN |
			_CLIENT_LOCAL_FILES |
			_CLIENT_MULTI_STATEMENTS |
			_CLIENT_MULTI_RESULTS)
	// Reset flags not supported by server
	flags &= uint32(my.info.caps) | 0xffff0000
	if my.plugin != string(my.info.plugin) {
		my.plugin = string(my.info.plugin)
	}
	var scrPasswd []byte
	switch my.plugin {
	case "caching_sha2_password":
		flags |= _CLIENT_PLUGIN_AUTH
		scrPasswd = encryptedSHA256Passwd(my.passwd, my.info.scramble[:])
	case "mysql_old_password":
		my.oldPasswd()
		return
	default:
		// mysql_native_password by default
		scrPasswd = encryptedPasswd(my.passwd, my.info.scramble[:])
	}

	// encode length of the auth plugin data
	var authRespLEIBuf [9]byte
	authRespLEI := appendLengthEncodedInteger(authRespLEIBuf[:0], uint64(len(scrPasswd)))
	if len(authRespLEI) > 1 {
		// if the length can not be written in 1 byte, it must be written as a
		// length encoded integer
		flags |= _CLIENT_PLUGIN_AUTH_LENENC_CLIENT_DATA
	}

	pay_len := 4 + 4 + 1 + 23 + len(my.user) + 1 + len(authRespLEI) + len(scrPasswd) + 21 + 1

	if len(my.dbname) > 0 {
		pay_len += len(my.dbname) + 1
		flags |= _CLIENT_CONNECT_WITH_DB
	}
	pw := my.newPktWriter(pay_len)
	pw.writeU32(flags)
	pw.writeU32(uint32(my.max_pkt_size))
	pw.writeByte(my.info.lang)   // Charset number
	pw.writeZeros(23)            // Filler
	pw.writeNTB([]byte(my.user)) // Username
	pw.writeBin(scrPasswd)       // Encrypted password

	// write database name
	if len(my.dbname) > 0 {
		pw.writeNTB([]byte(my.dbname))
	}

	// write plugin name
	if my.plugin != "" {
		pw.writeNTB([]byte(my.plugin))
	}
	return
}

 

也就是說經過重重包裝,pw就是往TCP連線的緩衝區寫資料的一個物件,但是資料為什麼沒有傳送出去呢

我修改了程式碼,在auth()函式return前強行呼叫pw.wr.Flush()重新整理緩衝區,抓包發現,一個長度128的包發出來了,但是並沒有被識別為一個Mysql連線

把這個包的頭部和正確的包對比

查閱資料,得知Protocols in frame封裝於物理層

 

又查了一下,說這個Protocols in frame是wireshark自己識別出來的一個東西,不是資料包裡面帶的,嗯

繼續詳細對比兩個資料包

紅框框出來的這一位,可以看到是表示資料的長度的,右邊正確資料包的資料長度為3a(十六進位制,就是58),左邊的長度不對,是80,所以這就是資料包沒有傳送的原因麼,長度設定得過大,資料沒有填滿所以一直沒有傳送

看一下這段程式碼,pay_len經過很長的算式計算出來,在我的賬號密碼情況下這個pay_len是80

而仔細看正確的資料包可以發現,資料包最後一個部分就是加密後的密碼,那麼後面的21+1是個啥呢,看程式碼,我沒有填dbname和my.plugin,那麼在密碼之後寫的資料應該就是"mysql_native_password"了吧,

pay_len := 4 + 4 + 1 + 23 + len(my.user) + 1 + len(authRespLEI) + len(scrPasswd) + 21 + 1

if len(my.dbname) > 0 {
	pay_len += len(my.dbname) + 1
	flags |= _CLIENT_CONNECT_WITH_DB
}
pw := my.newPktWriter(pay_len)
pw.writeU32(flags)
pw.writeU32(uint32(my.max_pkt_size))
pw.writeByte(my.info.lang)   // Charset number
pw.writeZeros(23)            // Filler
pw.writeNTB([]byte(my.user)) // Username
pw.writeBin(scrPasswd)       // Encrypted password


// write database name
if len(my.dbname) > 0 {
	pw.writeNTB([]byte(my.dbname))
}

// write plugin name
if my.plugin != "" {
	pw.writeNTB([]byte(my.plugin))
}

把my.plugin這個變數相關的程式碼抽出來,發現了問題,my.info這個變數儲存的是握手之後Mysql傳回的資料,在我的電腦上,Mysql並沒有傳回plugin相關的資訊,導致my.plugin被抹成了空字串

if my.plugin != string(my.info.plugin) {
    my.plugin = string(my.info.plugin)
}

這時候我發現了一個問題,我一直看的是mymon/vendor資料夾底下的mymysql程式碼,mymon本身使用的也是這個程式碼,但是我從github上下載的mymysql程式碼有所不同,沒有使用my.info.plugin,傳送plugin的程式碼改成了如下的一部分

https://github.com/ziutek/mymysql

if my.plugin != "" {
	pw.writeNTB([]byte(my.plugin))
} else {
	pw.writeNTB([]byte("mysql_native_password"))
}

我把vendor底下的程式碼改了一下,重新執行,已經可以連線了,但是報了其他的錯,也就是說這是mymon/vendor資料夾下的mymysql版本太低,和我的Mysql不適配造成的

 我決定用github上的mymysql替換一下,

cd ~
sudo rm -r $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/native $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/mysql
git clone git clone https://github.com/ziutek/mymysql.git
cp -r mymysql/native $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/native
cp -r mymysql/mysql $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/mysql
cd $GOPATH/src/github.com/open-falcon/mymon
make && ./mymon etc/myMon.cfg  #編譯執行

錯誤依舊,好吧,起碼資料庫是連上了

4 吾生有崖而bug無崖

這個錯誤發生在mymon/show.go的182行,newMetaData.SetValue(row.Int(0))這個呼叫上,ziutek報錯,相關程式碼如下,根據報錯,主要是Row.Int(0)這個出了問題,ziutek表示Row這個物件儲存Mysql返回的結果,估計是結果返回出錯

var row mysql.Row
newMetaData := NewMetric(conf, metric)
row, _, err = db.QueryFirst("SELECT /*!50504 @@GLOBAL.innodb_stats_on_metadata */;")
newMetaData.SetValue(row.Int(0))

這個select語句肥腸奇怪,我從來沒見過,進入Mysql執行一下這個select,Mysql直接給我報了個語法錯誤

我仔細看了看/* */,越看越覺得像一對註釋,又看了看其他語句,原來如此啊

給他改掉

var row mysql.Row
newMetaData := NewMetric(conf, metric)
row, _, err = db.QueryFirst("SELECT /*!50504 */@@GLOBAL.innodb_stats_on_metadata;")
newMetaData.SetValue(row.Int(0))

執行,成功了,沒有報錯

了嗎?

看一眼myMon.log

????

這個錯誤是在show.go的ShowBinaryLogs(()函式執行中產生的,我的Mysql沒有啟用binlog,所以返回了,這裡把直接返回改成一個Warning

binaryLogStatus, err := ShowBinaryLogs(conf, db)
if err != nil {
    Log.Warning("Binary Log is not used")
} else {
    data = append(data, binaryLogStatus...)
}

好了,去客戶端看一眼myMon回報的資料,mysql_alive_local/isSlave=0,port=3306,readOnly=0,type=mysql有了一個數據1,湊合湊合就這樣了

5 解決方案總結

5.1 unexpected EOF

碰到了這種錯誤“NewMySQLConnection Error: Building mysql connection failed!: unexpected EOF”

這個錯誤我將近研究了一週的時間,終於摸索出了一些,主要是mymon這個版本使用的Mysql驅動和我的Mysql不匹配,替換為最新版本的mymysql可以執行

cd ~
sudo rm -r $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/native $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/mysql
git clone git clone https://github.com/ziutek/mymysql.git
cp -r mymysql/native $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/native
cp -r mymysql/mysql $GOPATH/src/github.com/open-falcon/mymon/vendor/github.com/ziutek/mymysql/mysqlcd $GOPATH/src/github.com/open-falcon/mymon

5.2 index out of range

碰到這個“panic: runtime error: index out of range”

把show.go的181行修改一下

#修改前
row, _, err = db.QueryFirst("SELECT /*!50504 @@GLOBAL.innodb_stats_on_metadata */;")
#修改後
row, _, err = db.QueryFirst("SELECT /*!50504 */ @@GLOBAL.innodb_stats_on_metadata;")

編譯執行

make && ./mymon etc/myMon.cfg  #編譯執行

5.3 You are not using binary logging

看一眼myMon.log,如果出現“You are not using binary logging”,說明你的Mysql沒有開binlog

修改一下show.go的82-84行,這裡我在日誌裡打了一個Warning輸出,你把整個binlog的程式碼註釋掉也可以

#修改前
if err != nil {
    return []*MetaData{binlogFileCounts, binlogFileSize}, err
}
#修改後
if err != nil {
    Log.Warning("Binary Log is not used")
} else {
    data = append(data, binaryLogStatus...)
}

編譯執行

make && ./mymon etc/myMon.cfg  #編譯執行