MyCAT日志对于了解MyCAT的运行信息不可获取,譬如MyCAT是否采用读写分离,对于一个查询语句,MyCAT是怎样执行的,每个分片会分发到哪个节点上等等。
默认是info级别,通过log4j.xml可将其设置debug级别,这样就可获得更多有关MyCAT运行的内部信息。
下面通过对MyCAT的启动以及执行一个查询语句来分析MyCAT的运行流程。
Here We Go!
Mycat的启动 日志输入如下:
processors指的是CPU的核数,aio thread pool size指的是AIO线程池,为CPU核数的两倍
-sysconfig params:指的是mycat的启动参数,可在server.xml中修改。
其中idleTimeout=1800000指的是外部应用与mycat最大空闲连接时长为30min,超过30min,则外部应用到mycat的连接将被断开。
dataNodeHeartbeatPeriod=10000 节点心跳检测的频率为10s一次。
9066是MyCAT的管理端口
8066是MyCAT的默认端口,类似于MySQL的3306端口。
接下来 初始化MyCAT连接池 ,默认最小为10个连接
可通过schema.xml中dataHost处定义
-init backend myqsl source ,create connections total 10 for hostM1 index :0:初始化后端MySQL连接,master节点是hostM1,可根据conf目录下dnindex.properties文件指定。
再下面的输出信息就是创建连接,释放channel。
创建完毕后,会输出如下信息,代表连接创建完毕
执行心跳检测 ,所以需建立新的连接,因为我配置的是一主两从,所以需判断localhost,192.168.244.144和192.168.244.146的心跳,localhost已启动10个连接,所以不需要创建新的连接,但hostS1(即192.168.244.146)和hostS2(即192.168.244.144)需要。
threadID对应的是MySQL中的进程ID
接下来是 前端连接到MyCAT的输出信息 ,可以看出,连接到MyCAT后,会执行show database,show tables,select @@version_comment limit 1命令。个人感觉这是为后续的路由分析缓存数据库及表信息。
首先会 判断该SQL语句的路由信息 (根据下面的输出,MyCAT内部应该用了一个map集合来存储SQL语句的路由信息),如果没有,则会首先生成路由信息。
路由的主要作用是用于确定SQL语句的执行路径,包括查询的数据在哪些分片上。
-SQLRouteCache miss cache:没有路由信息
-SQLRouteCache add cache:生成路由信息
-execute mutinode query select * from travelrecord:确认该查询会跨多个分片
-has data merge logic:会存在数据的合并
下面就可以 确认具体在哪个节点去读了
因为我配置的是一主两从,且balance="1",全部的readHost与stand by writeHost参与select语句的负载均衡,所以hostS1(192.168.244.146)和hostS2(192.168.244.144)均参与select语句的负载均衡。
在执行select语句之前,需同步连接,为什么要同步连接呢?
MyCAT为了高效的使用后端的MySQL连接,采用了基于MySQL实例的连接池模式。
在Mycat的连接池里,当前可用的MySQL连接是放到一个HashMap的数据结构里,Key为当前连接对应的Database,另外还有二级分类,即按照连接是自动提交还是手动提交模式进行区分,这个设计是为了高效的查询匹配的可用连接,具体逻辑如下:
当某个用户会话需要一个自动提交的,到分片dn1(对应db1)的SQL连接的时候,连接池首先找是否有db1上的可用连接,如果有,看是否有自动提交模式的连接,找到就返回,否则返回db1上的手动提交模式的连接,若没有db1的可用连接,则随机返回一个其他db对应的可用连接,若没有可用连接,并且连接池还没达到上限,则创建一个新连接并返回,这个逻辑过程,我们会发现,用户会话得到的连接可能不是他原先想要的,比如Database不对应,或者事务模式不匹配,因此在执行具体的SQL之前,还有一个自动同步数据库连接的过程,包括事务隔离级别、事务模式、字符集、Database等四个指标,同步完成以后,才会执行具体的SQL指令。
在执行select * from travelrecord语句时,因为会涉及到3个分片,故MyCAT选择了三个read source进行查询,其中,两个在hostS2上,一个在hostS1上。对于hostS2的两个连接,其中一个会复用MyCAT之前对hostS2执行心跳检测的连接,另一个需创建。
对于hostS2复用之前的连接,因为之前执行心跳检测的时候即使用的db1,所以这次schema change为false,不用修改。
而对于hostS1复用之前的连接,因为之前使用的是db1,这次是db3,所以schema change为true,需修改。
对于每一个同步的连接,需在连接同步后才开始执行查询。
一共有5个received ok response,其中2个对应上图中的total syn cmd 2 commands,另外3个对应于上图中的total syn cmd 3 commands,根据host也能很轻易的对应起来。
下面开始执行程序,
第一个红色方框针对的是192.168.244.146中dn3分片上,因为我整个select * from travelrecord输出只有两行,
mysql> select * from travelrecord; +---------+---------------+------------+------+------+ | id | user_id | traveldate | fee | days | +---------+---------------+------------+------+------+ | 1 | mysql-server2 | 2016-01-01 | 100 | 10 | | 5000001 | mysql-server3 | 2016-01-02 | 100 | 10 | +---------+---------------+------------+------+------+ 2 rows in set (0.04 sec)
只跨两个分片,dn1和dn2,所以dn3的查询没有结果输出,直接释放connection和channel 。
蓝色方框和第二个红色方框的内容是有关192.168.244.144中dn1的,有结果输出。
-field metadata inf: DataMergeService先合并了输出列的信息。
-on row end reseponse:代表dn1的结果的输出。
下面是dn2分片的输出,因为dn2分片是刚才新建的连接,所以同样需要同步,收到两次received ok response后,返回结果,然后释放connection和channel。
最后是DataMergeService合并所有返回的结果。
last packet id预计是MyCAT将结果反馈给前段程序。
至此,一个查询语句的日志分析完毕~
总结:
1. 其实同步连接的时候,并不必然会产生received ok response信息,譬如我在执行SELECT * FROM travelrecord WHERE id = 1语句时,
在执行同步连接后,就直接释放了connection和channel,并没有产生received ok response信息,也没有产生on row end reseponse。
看来,这个只能通过源码才能知晓个中原因。
2. 平时分析MyCAT日志,一般会使用tailf命令,但频繁的心跳检测信息又确实是个干扰,可通过 tailf mycat.log |grep -Ev "Timer|release channel"过滤掉部分信息。