MySQL：不是MySQL問(wèn)題的MySQL問(wèn)題
一、自定義函數(shù)的BUG導(dǎo)致的問(wèn)題
這個(gè)問(wèn)題是跑一條如下的的SQL
update test set p_id=getPid(c_id);
這個(gè)表只有10w條數(shù)據(jù)，但是語(yǔ)句卻一直不能完成，如果將語(yǔ)句加上limit，當(dāng)limit 50000的時(shí)候是可以執(zhí)行完成的，但是當(dāng)limit 80000的時(shí)候就一直不能完成。并且有一個(gè)現(xiàn)象，就是語(yǔ)句會(huì)不斷會(huì)出現(xiàn)opening tables的狀態(tài)。
既然語(yǔ)句不能執(zhí)行完成，那么就需要找到為什么不能完成，先把等待的原因找到，比如：
- 鎖等待？
- CPU打滿？
- IO打滿？
排查下來(lái)發(fā)現(xiàn)這個(gè)語(yǔ)句在實(shí)際執(zhí)行的時(shí)候占用了大量的CPU，因此我們分別采集了正常執(zhí)行和異常的情況，發(fā)現(xiàn)異常的時(shí)候正常的邏輯幾乎成了一根線，而非正常的邏輯占用了大量的CPU如下：
那么很顯然，實(shí)際上本語(yǔ)句執(zhí)行異常的情況下，CPU都沒(méi)有處理正常的邏輯。而其上層調(diào)用sp_head::execute_function就是執(zhí)行函數(shù)的上層調(diào)用，而這里只有一個(gè)自定義函數(shù)，因此幾乎可以判定是自定義函數(shù)內(nèi)部邏輯遇到了什么問(wèn)題。接著我們使用pstack對(duì)異常情況的執(zhí)行棧進(jìn)行了查看，并且多次測(cè)試正常邏輯的pstack執(zhí)行棧，發(fā)現(xiàn)其中有一個(gè)邏輯入?yún)⒉粩嘣谂蛎?，且?nèi)存長(zhǎng)度不斷增加(length)，
當(dāng)然這里所有的都是我的測(cè)試環(huán)境的構(gòu)建，不是線上環(huán)境。那么就可以確認(rèn)函數(shù)內(nèi)部在做拼接的時(shí)候遇到了問(wèn)題，繼而我們打開(kāi)自定義函數(shù)getPid，發(fā)現(xiàn)其中有一個(gè)while循環(huán)，循環(huán)內(nèi)部在做字段的拼接，拼接完成后返回值，就是這個(gè)while循環(huán)，在滿足一定情況下會(huì)出現(xiàn)死循環(huán)，而且根據(jù)pstack入?yún)⑦@個(gè)字符串，實(shí)際上就是不斷在拼接某個(gè)字段，這個(gè)字段的值為1，由于死循環(huán)拼接了很長(zhǎng)很長(zhǎng)，這里看到就是1,1,1,1,1,1......，這樣我們也拿到了這個(gè)出現(xiàn)問(wèn)題行的字段值 1，并且我們通過(guò)死循環(huán)條件也能判斷出另外一個(gè)字段的值，接下來(lái)就根據(jù)這兩個(gè)字段在表里面查一下就可以找到導(dǎo)致死循環(huán)的行，當(dāng)然這里只是講一個(gè)思路，不方便給出這個(gè)自定義函數(shù)。出現(xiàn)死循環(huán)的問(wèn)題也剛好符合CPU打滿的情況。
其次由于自定義函數(shù)內(nèi)存有select 語(yǔ)句，這個(gè)語(yǔ)句在遇到自定義函數(shù)死循環(huán)的情況下要不斷的循環(huán)跑，因此就觀察到update 語(yǔ)句執(zhí)行異常期間，觀察到opening tables的情況。
二、應(yīng)用代碼static 變量導(dǎo)致的死鎖
這個(gè)問(wèn)題在MySQL層的表現(xiàn)就是出現(xiàn)了死鎖，但是這個(gè)死鎖表很簡(jiǎn)單，簡(jiǎn)單到只有少量的記錄，而且只有主鍵，并且沒(méi)有其他的索引這里假定主鍵就是id，且為RC隔離級(jí)別，每次執(zhí)行的語(yǔ)句也是根據(jù)主鍵來(lái)查詢和更新的，如下：
begin;
select * from test where id=1 for update；
update test set name='a' where id=1;
commit;
死鎖如下（這里刪除了詳細(xì)數(shù)據(jù)）：
------------------------
LATEST DETECTED DEADLOCK
------------------------
2022-07-06 19:48:38 0x7efc44162700
*** (1) TRANSACTION:
TRANSACTION 12739556, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 627119, OS thread handle 139619931977472, query id 129095157 192.168.1.81 root updating
update test set name='a' where id=1
*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 388279 page no 4 n bits 152 index PRIMARY of table `test`.`test` trx id 12739556 lock_mode X locks rec but not gap
Record lock, heap no 82 PHYSICAL RECORD: n_fields 16; compact format; info bits 0
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 388279 page no 4 n bits 152 index PRIMARY of table `test`.`test` trx id 12739556 lock_mode X locks rec but not gap waiting
Record lock, heap no 55 PHYSICAL RECORD: n_fields 16; compact format; info bits 0
*** (2) TRANSACTION:
TRANSACTION 12739557, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 627114, OS thread handle 139621354526464, query id 129095158 192.168.1.81 root updating
update test set name='o' where id=2
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 388279 page no 4 n bits 152 index PRIMARY of table `test`.`test` trx id 12739557 lock_mode X locks rec but not gap
Record lock, heap no 55 PHYSICAL RECORD: n_fields 16; compact format; info bits 0
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 388279 page no 4 n bits 152 index PRIMARY of table `test`.`test` trx id 12739557 lock_mode X locks rec but not gap waiting
Record lock, heap no 82 PHYSICAL RECORD: n_fields 16; compact format; info bits 0
*** WE ROLL BACK TRANSACTION (2)
那么出現(xiàn)這種死鎖問(wèn)題，一般分析路徑為：
- 業(yè)務(wù)代碼是否有問(wèn)題。
- 執(zhí)行計(jì)劃是否有問(wèn)題。
- 最后才是重現(xiàn)，分析MySQL本身的問(wèn)題。
當(dāng)我們分析第一點(diǎn)的時(shí)候，業(yè)務(wù)代碼寫得很簡(jiǎn)單，也很清晰就是前面的事務(wù)邏輯，這種事務(wù)說(shuō)實(shí)話出現(xiàn)死鎖貌似不太可能，因?yàn)楹芎?jiǎn)單查詢是查詢的主鍵，更新的時(shí)候也是通過(guò)主鍵更新一個(gè)字段的值而已，且除了主鍵沒(méi)有其他的索引，這種情況一般只會(huì)是堵塞而不會(huì)出現(xiàn)死鎖。
然后我們?cè)跍y(cè)試環(huán)境模擬死鎖的時(shí)候打開(kāi)了general log，發(fā)現(xiàn)并不是我們想象的，多線程的各個(gè)語(yǔ)句和事務(wù)是在一個(gè)session 交替進(jìn)行的，這就奇怪了，言外之意就是多個(gè)業(yè)務(wù)線程對(duì)應(yīng)了一個(gè)session，大概如下：
begin；
update set name='o' where id=2
commit；
begin；
select * from test where id=1 for update；
select * from test where id=3 for update；
select * from test where id=4 for update；
update test set name='a' where id=3；
update test set name='a' where id=1；
commit；
update set name='o' where id=4；
反正沒(méi)什么規(guī)律，這貌似很像多線程并發(fā)并且所有語(yǔ)句堆到了同一個(gè)session。
那么進(jìn)而分析，代碼變量的定義我們才發(fā)現(xiàn)代碼中將連接變量的屬性設(shè)置為了static類型的，開(kāi)發(fā)環(huán)境當(dāng)然是java的 ，我們可以類比C++，C++中如果將類變量的屬性加上static代表是靜態(tài)變量，這種變量的值不是存在棧上的，而是存在靜態(tài)全局區(qū)，所有通過(guò)本類實(shí)例化的對(duì)象，都共享了這個(gè)靜態(tài)變量，換一句話說(shuō)，如果某個(gè)實(shí)例化的對(duì)象修改了這個(gè)靜態(tài)變量那么所有的實(shí)例化對(duì)象都會(huì)修改，當(dāng)然java/python 都有類似的使用方法。主要還是看內(nèi)存到底是棧內(nèi)存/堆內(nèi)存/全局內(nèi)存。那么這個(gè)問(wèn)題就變得簡(jiǎn)單了，當(dāng)多個(gè)線程同時(shí)初始化建立好連接過(guò)后，所有的線程實(shí)際上最后得到連接只有一個(gè)。類似如下:
最后為了驗(yàn)證我寫了一個(gè)測(cè)試用例（見(jiàn)末尾），很難跑成功，因?yàn)?個(gè)線程同時(shí)使用了一個(gè)connect，感覺(jué)應(yīng)該是C下面這樣在獲取結(jié)果（mysql_store_result）和free結(jié)果（mysql_free_result）的時(shí)候可能的情況是未知的，當(dāng)然也沒(méi)去仔細(xì)研究lib庫(kù)函數(shù)的使用方式可能寫的方式也有問(wèn)題，反正各種crash（core dump）。但是在偶爾能夠成功的時(shí)候可以在general log中看到如下日志，這里就是所有線程的語(yǔ)句堆到同一個(gè)session：
static變量：
2022-07-08T07:07:50.364174Z 173 Query select 1
2022-07-08T07:07:50.365168Z 173 Query select 2
2022-07-08T07:07:50.365903Z 173 Query select 3
2022-07-08T07:07:50.370390Z 173 Query select 0
2022-07-08T07:07:51.367748Z 173 Query select 2
2022-07-08T07:07:51.367903Z 173 Query select 1
2022-07-08T07:07:51.368161Z 173 Query select 3
顯然這是一個(gè)session id 為173，而實(shí)際上測(cè)試用例4個(gè)線程會(huì)不斷的跑select 0/select 1/select 2/select 3。但是4個(gè)線程對(duì)應(yīng)了同一個(gè)session，這也和我們實(shí)際情況一致，這樣如果多個(gè)應(yīng)用各自啟動(dòng)了多個(gè)線程，那么混跑語(yǔ)句就會(huì)出現(xiàn)下面的情況：
app1 多線程：
begin;
select * from test where id=1 for update；
select * from test where id=2 for update；
select * from test where id=3 for update；
update set name='a' where id=1;
update set name='a' where id=2;
commit;
app2 多線程:
begin;
select * from test where id=2 for update；
select * from test where id=1 for update；
select * from test where id=3 for update；
update set name='a' where id=2;
update set name='a' where id=3;
commit;
事務(wù)被無(wú)序的擴(kuò)大了，死鎖概率當(dāng)然大大增加。這也是我們實(shí)際環(huán)境中看到的情況。當(dāng)然如果測(cè)試用例使用局部變量就沒(méi)有問(wèn)題，改為局部變量后正常執(zhí)行如下：
2022-07-08T07:18:22.582624Z 225 Query select 0
2022-07-08T07:18:22.582732Z 222 Query select 2
2022-07-08T07:18:22.582638Z 223 Query select 1
2022-07-08T07:18:22.583214Z 224 Query select 3
2022-07-08T07:18:23.583894Z 225 Query select 0
2022-07-08T07:18:23.583973Z 222 Query select 2
2022-07-08T07:18:23.583915Z 223 Query select 1
2022-07-08T07:18:23.584315Z 224 Query select 3
這里就是4個(gè)thread對(duì)應(yīng)了4個(gè)session，各自跑的各自的語(yǔ)句。
附件
C++ 測(cè)試用例，如果改成局部變量后4個(gè)線程對(duì)應(yīng)4個(gè)session，可以正常跑沒(méi)有問(wèn)題如下，static 變量容易導(dǎo)致各種crash。
#include<stdio.h>
#include<stdlib.h>
#include<iostream>
#include "/opt/mysql/mysql3306/install/include/mysql.h"
#include <time.h>
#include <unistd.h>
using namespace std;
class My_Con
{
public:
MYSQL conn_ptr;
My_Con(const char *host,const char *user,const char *passwd,unsigned int port)
{
mysql_init(&conn_ptr);
if(mysql_real_connect(&conn_ptr,host,user,passwd,NULL,port,NULL,0)==NULL)
{
printf("err: mysql_real_connect() error %s\n",mysql_error(&conn_ptr));
exit(1);
}
}
MYSQL* get_conn()
{
return &conn_ptr;
}
//~My_Con(){mysql_close(&conn_ptr);cout<<"close connect"<<endl;}
};
class My_Test
{
public:
static MYSQL* conn_ptr; //靜態(tài)指針
static My_Con* test; //靜態(tài)指針
int myid;
MYSQL_RES *query_res;
char strtest[30];
My_Test(const int i)
{
test = new My_Con("192.168.1.61","testuser","gelc123",3306);
conn_ptr = test->get_conn();
myid = i ;
query_res = NULL;
}
void* get_string(int id)
{
sprintf(strtest, "select %d ;", id);
cout<<strtest<<endl;
}
void test_query()
{
get_string(myid);
if(mysql_query(conn_ptr,strtest) != 0)
{
printf("err: mysql_query() error %s %s\n",mysql_error(conn_ptr),strtest);
//exit(1);
}
query_res=mysql_store_result(conn_ptr);
if(query_res == NULL)
{
;
}
mysql_free_result(query_res);
}
//TIPS: static variables
// ~My_Test(){delete []test;}
};
My_Con* My_Test::test = NULL;
MYSQL* My_Test::conn_ptr = NULL;
void* test_func(void* arg)
{
My_Test a(*((int*)arg)); //建立連接
struct timespec n_sec;
n_sec.tv_sec = 1;
n_sec.tv_nsec = 0;
for(;;)
{
nanosleep(&n_sec,NULL);
a.test_query();
}
}
int main()
{
pthread_t tid[4];
int tid_num = 0;
int i = 0;
int ret = 0;
int seq[4] = {0,1,2,3};
pthread_create(tid+tid_num,NULL,test_func,(void*)seq);
tid_num++;
pthread_create(tid+tid_num,NULL,test_func,(void*)(seq+1));
tid_num++;
pthread_create(tid+tid_num,NULL,test_func,(void*)(seq+2));
tid_num++;
pthread_create(tid+tid_num,NULL,test_func,(void*)(seq+3));
tid_num++;
//堵塞回收
for(i = 0;i<=tid_num;i++)
{
ret = pthread_join( *(tid+i) , NULL );
}
return 0 ;
}
