ProxySQL中使用了MariaDB的Client API.对后端mysql的请求都是异步的(KILL QUERY/CONNECTION 命令除外,因为这个操作ProxySQL是启动了一个线程来执行的,没有必要再使用异步了),也就是说一个SQL发送给后端mysql,ProxySQL的session不会在这里等待查询结果。我们知道ProxySQL中有慢查询统计功能,能够统计慢查询的个数,在stats_mysql_query_digest表中也对每条SQL的执行时间进行了记录,那么既然每条SQL都是异步请求,对于后端每条SQL的执行时间ProxySQL是如何统计的呢?

Query_Info类中有一个begin函数,该函数中初始化了SQL执行的开始时间(MySQL_Session.cpp#L166)。

1
2
3
4
void Query_Info::begin(unsigned char *_p, int len, bool mysql_header) {
...
start_time=sess->thread->curtime
...

该类中还有一个end函数,end函数中记录了慢查询。但变量end_time是在什么地方确定的呢?(@1)

1
2
3
4
5
6
7
8
void Query_Info::end() {
query_parser_update_counters();
query_parser_free();
// 记录慢查询
if ((end_time-start_time) > (unsigned int)mysql_thread___long_query_time*1000) {
__sync_add_and_fetch(&sess->thread->status_variables.queries_slow,1);
}
...

此函数调用了query_parser_update_counters函数,而query_parser_update_counters函数中又调用了QueryProcessor中的query_parser_update_counters

1
2
3
4
5
6
7
8
9
10
11
12
13
unsigned long long Query_Info::query_parser_update_counters() {
if (stmt_info) {
MyComQueryCmd=stmt_info->MyComQueryCmd;
}
if (MyComQueryCmd==MYSQL_COM_QUERY___NONE) return 0; // this means that it was never initialized
if (MyComQueryCmd == MYSQL_COM_QUERY__UNINITIALIZED) return 0; // this means that it was never initialized
// Here...
unsigned long long ret=GloQPro->query_parser_update_counters(sess, MyComQueryCmd, &QueryParserArgs, end_time-start_time);
MyComQueryCmd=MYSQL_COM_QUERY___NONE;
QueryPointer=NULL;
QueryLength=0;
return ret;
}

Query_Processor.cpp#L1290
Query_Processor类的query_parser_update_counters方法又调用了update_query_digest函数。这个函数中有一行:qds->add_time(t,n);在这个add_time中详细处理SQL执行时间的问题。L133

1
2
3
4
5
6
7
8
9
10
11
12
13
14
void add_time(unsigned long long t, unsigned long long n) {
count_star++;
sum_time+=t;
if (t < min_time || min_time==0) {
if (t) min_time = t;
}
if (t > max_time) {
max_time = t;
}
if (first_seen==0) {
first_seen=n;
}
last_seen=n;
}

update_query_digest的定义如下。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
 void Query_Processor::update_query_digest(SQP_par_t *qp, int hid, MySQL_Connection_userinfo *ui, unsigned long long t, unsigned long long n, MySQL_STMT_Global_info *_stmt_info) {
#ifdef PROXYSQL_QPRO_PTHREAD_MUTEX
pthread_rwlock_wrlock(&digest_rwlock);
#else
spin_wrlock(&digest_rwlock);
#endif
QP_query_digest_stats *qds;

std::unordered_map<uint64_t, void *>::iterator it;
it=digest_umap.find(qp->digest_total);
if (it != digest_umap.end()) {
// found
qds=(QP_query_digest_stats *)it->second;
qds->add_time(t,n);
} else {
if (_stmt_info==NULL) {
qds=new QP_query_digest_stats(ui->username, ui->schemaname, qp->digest, qp->digest_text, hid);
} else {
qds=new QP_query_digest_stats(ui->username, ui->schemaname, _stmt_info->digest, _stmt_info->digest_text, hid);
}
qds->add_time(t,n);
digest_umap.insert(std::make_pair(qp->digest_total,(void *)qds));
}

#ifdef PROXYSQL_QPRO_PTHREAD_MUTEX
pthread_rwlock_unlock(&digest_rwlock);
#else
spin_wrunlock(&digest_rwlock);
#endif
}

这里我们大致知道了它的处理流程,我们再回到问题@1. end_time的最终是在MySQL_Session类中的一个RequestEnd方法中确定的.这个方法的定义如下。(MySQL_Session.cpp#L4471)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
// this should execute most of the commands executed when a request is finalized
// this should become the place to hook other functions
void MySQL_Session::RequestEnd(MySQL_Data_Stream *myds) {
// we need to access statistics before calling CurrentQuery.end()
// so we track the time here
CurrentQuery.end_time=thread->curtime;

if (qpo) {
if (qpo->log==1) {
GloMyLogger->log_request(this, myds); // we send for logging only if logging is enabled for this query
}
}

GloQPro->delete_QP_out(qpo);
// if there is an associated myds, clean its status
if (myds) {
// if there is a mysql connection, clean its status
if (myds->myconn) {
myds->myconn->async_free_result();
myds->myconn->compute_unknown_transaction_status();
}
myds->free_mysql_real_query();
}
// reset status of the session
status=WAITING_CLIENT_DATA;
// reset status of client data stream
client_myds->DSS=STATE_SLEEP;
// finalize the query
CurrentQuery.end();
started_sending_data_to_client=false;
}

它是在对每一个后端请求结束时调用,确定CurrentQuery.end_time的值,如此确定该SQL的最终执行时间(将网络开销包含在内了)。这个方法在何处被调用呢? MySQL_Session类中有个handler方法,这个方法非常复杂,是MySQL_Session类的核心,包含了异步处理客户端请求的所有流程。里面是用了一大堆switch语句,switch里面嵌套 switch,这种swtich嵌套 竟然多达三四层,不由令人眼花缭乱不知所云。其实这里面主要针对三种status进行switch, 第一类是session_status;第二类是mysql_data_stream_status;第三类是enum_mysql_command.这三中status都是enum类型,定义在文件proxysql_struncts.h中。有兴趣的同修可以认真读一下。