03_mycat通过debug日志来分析sql的完整执行逻辑

1，执行select * from travelrecord ，分析Debug日志，说明整个执行逻辑，包括连接获取，连接同步信息，数据合并，数据返回，连接释放

1.1清空debug信息

[root@wgq_idc_squid_1_11 logs]# cat /dev/null > mycat.log

[root@wgq_idc_squid_1_11 logs]# ll

修改日志为debug：

vim log4j.xml

获取日志：

[root@wgq_idc_squid_1_11 logs]# cp mycat.log 1.log

[root@wgq_idc_squid_1_11 logs]# vim 1.log

1.1连接获取

01/24 21:59:12.850 DEBUG [$_NIOREACTOR-3-RW] (EnchachePool.java:76) -SQLRouteCache miss cache ,key:TESTDBselect * from travelrecord

01/24 21:59:12.851 DEBUG [$_NIOREACTOR-3-RW] (EnchachePool.java:59) -SQLRouteCache add cache ,key:TESTDBselect * from travelrecord value:select * from travelrecord, route={

1 -> dn1{SELECT *

FROM travelrecord

LIMIT 100}

2 -> dn2{SELECT *

FROM travelrecord

LIMIT 100}

3 -> dn3{SELECT *

FROM travelrecord

LIMIT 100}

}

01/24 21:59:12.852 DEBUG [$_NIOREACTOR-3-RW] (NonBlockingSession.java:113) -ServerConnection [id=4, schema=TESTDB, host=127.0.0.1, user=test,txIsolation=3, autocommit=true, schema=TESTDB]select * from travelrecord, route={

1 -> dn1{SELECT *

FROM travelrecord

LIMIT 100}

2 -> dn2{SELECT *

FROM travelrecord

LIMIT 100}

3 -> dn3{SELECT *

FROM travelrecord

LIMIT 100}

} rrs

1.2连接同步信息：

01/24 21:59:12.852 DEBUG [$_NIOREACTOR-3-RW] (MySQLConnection.java:445) -con need syn ,total syn cmd 2 commands SET names latin1;SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;schema change:false con:MySQLConnection [id=11, lastTime=1453643952852, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=true, threadId=3425, charset=latin1, txIsolation=0, autocommit=true, attachment=dn1{SELECT *

FROM travelrecord

LIMIT 100}, respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler@30a6aae0,

host=127.0.0.1, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

1.3数据合并

01/24 21:59:12.856 DEBUG [BusinessExecutor6] (DataMergeService.java:296) -prepare mpp merge result for select * from travelrecord

01/24 21:59:12.856 DEBUG [BusinessExecutor6] (MultiNodeQueryHandler.java:324) -last packet id:11

01/24 21:59:21.910 DEBUG [Timer1] (SQLJob.java:85) -con query sql:show slave status to con:MySQLConnection [id=14, lastTime=1453643961910, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=false, threadId=22, charset=latin1, txIsolation=3,

autocommit=true, attachment=null, respHandler=null, host=127.0.0.1, port=3317, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

01/24 21:59:21.910 DEBUG [Timer1] (SQLJob.java:85) -con query sql:show slave status to con:MySQLConnection [id=27, lastTime=1453643961910, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=false, threadId=3442, charset=latin1, txIsolation=3, autocommit=true, attachment=null, respHandler=null, host=127.0.0.1, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

……………..

1.4数据返回

01/24 21:59:12.854 DEBUG [$_NIOREACTOR-3-RW] (MultiNodeQueryHandler.java:171) -received ok response ,executeResponse:false from MySQLConnection [id=11, lastTime=1453643952835, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=true, threadId=3425, charset=latin1, txIsolation=0, autocommit=true, attachment=dn1{SELECT *

FROM travelrecord

LIMIT 100}, respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler@30a6aae0, host=127.0.0.1, port=3327, statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync@6d43df48, writeQueue=0, modifiedSQLExecuted=false]

01/24 21:59:12.855 DEBUG [$_NIOREACTOR-3-RW] (MultiNodeQueryHandler.java:171) -received ok response ,executeResponse:false from MySQLConnection [id=11, lastTime=1453643952835, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=true, threadId=3425, charset=latin1, txIsolation=3, autocommit=true, attachment=dn1{SELECT *

FROM travelrecord

LIMIT 100}, respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler@30a6aae0, host=127.0.0.1, port=3327, statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync@6d43df48, writeQueue=0, modifiedSQLExecuted=false]

1.5连接释放：

01/24 21:59:21.911 DEBUG [$_NIOREACTOR-2-RW] (PhysicalDatasource.java:403) -release channel MySQLConnection [id=14, lastTime=1453643961901, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=false, threadId=22, charset=latin1, txIsolation=3, autocommit=true, attachment=null, respHandler=null, host=127.0.0.1, port=3317, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

01/24 21:59:21.911 DEBUG [$_NIOREACTOR-1-RW] (PhysicalDatasource.java:403) -release

channel MySQLConnection [id=27, lastTime=1453643961901, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=false, threadId=3442, charset=latin1, txIsolation=3, autocommit=true, attachment=null, respHandler=null, host=127.0.0.1, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

01/24 21:59:21.911 DEBUG [$_NIOREACTOR-2-RW] (PhysicalDatasource.java:403) -release channel MySQLConnection [id=16, lastTime=1453643961901, user=root, schema=db1, old shema=db1, borrowed=true, fromSlaveDB=true, threadId=3431, charset=utf8, txIsolation=0, autocommit=true, attachment=null, respHandler=null, host=127.0.0.1, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

2，新增一个分片表T_VOTE (ID,PROVINCE),PROVINCE用hash分片，并用reload命令方式重载生效，截图和文字说明整个过程。

2.1配置hash分片

Schema.xml文件，dataNode有dn21、dn22；dataHost有m1、m2，如下2.1.jpg所示：

Rule.xml ：

??

reload更新配置文件：

mysql> reload @@config;

ERROR 1064 (HY000): com.alibaba.druid.sql.parser.ParserException: syntax error, error in :'reload @@config',expect IDENTIFIER, actual IDENTIFIER reload

mysql>

问题好奇怪，虽然有报错信息，但是后台生效了，建表explain可以看到新的dn21和dn22 ，如下所示：

建表：

2.2 录入初始化数据验证数据分片：

总共录入了4条记录，去查看数据，2条记录在dn21分片上也就是mysql的3317实例上面，2条记录在dn22分片也就是mysql的3327实例上，如下所示：

Dn21分片3317mysql端口：

Dn22分片3327mysql端口：

3，该字符集为latin后的显示

3.1 Mysql服务器字符集为latin：

后台debug信息显示为charset=latin1了：

01/25 02:47:19.128 DEBUG [$_NIOREACTOR-1-RW] (MySQLConnection.java:445) -con need syn ,total syn cmd 1 commands SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;schema change:false con:MySQLConnection [id=32, lastTime=1453661239128, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=23, charset=latin1, txIsolation=0, autocommit=true, attachment=dn22{SELECT *

FROM T_VOTE

LIMIT 100}, respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler@5485687f, host=10.254.1.11, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

3.2 登录mycat的客户端设置成gbk：

1/25 02:50:26.348 DEBUG [$_NIOREACTOR-1-RW] (EnchachePool.java:76) -SQLRouteCache miss cache ,key:TESTDBselect * from T_VOTE where PROVINCE="beijing"

01/25 02:50:26.392 DEBUG [$_NIOREACTOR-1-RW] (EnchachePool.java:59) -SQLRouteCache add cache ,key:TESTDBselect * from T_VOTE where PROVINCE="beijing" value:select * from T_VOTE where PROVINCE="beijing", route={

1 -> dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'beijing'

LIMIT 100}

}

01/25 02:50:26.393 DEBUG [$_NIOREACTOR-1-RW] (NonBlockingSession.java:113) -ServerConnection [id=1, schema=TESTDB, host=127.0.0.1, user=test,txIsolation=3, autocommit=true, schema=TESTDB]select * from T_VOTE where PROVINCE="beijing", route={

1 -> dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'beijing'

LIMIT 100}

} rrs

01/25 02:50:26.393 DEBUG [$_NIOREACTOR-1-RW] (PhysicalDBPool.java:452) -select read source hostM2 for dataHost:m2

01/25 02:50:26.396 DEBUG [$_NIOREACTOR-3-RW] (NonBlockingSession.java:229) -release connection MySQLConnection [id=11, lastTime=1453661426394, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=16, charset=gbk, txIsolation=3, autocommit=true, attachment=dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'beijing'

LIMIT 100}, respHandler=SingleNodeHandler [node=dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'beijing'

LIMIT 100}, packetId=5], host=10.254.1.11, port=3327, statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync@54a7f2c7, writeQueue=0, modifiedSQLExecuted=false]

01/25 02:50:26.396 DEBUG [$_NIOREACTOR-3-RW] (PhysicalDatasource.java:403) -release channel MySQLConnection [id=11, lastTime=1453661426394, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=16, charset=gbk, txIsolation=3, autocommit=true, attachment=null, respHandler=null, host=10.254.1.11, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

01/25 02:50:32.191 DEBUG [Timer0] (SQLJob.java:85) -con query sql:select user() to con:MySQLConnection [id=2, lastTime=1453661432191, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=23, charset=latin1, txIsolation=0, autocommit=true, attachment=null, respHandler=null, host=10.254.1.11, port=3317, statusSync=null, writeQueue=0, modifiedSQLExecuted=false].

看到了charset=gbk，返回的数据和mysql数据库设置的字符集关系不大，和登录mycat客户端设置的字符集有关。

3.3设置成为utf8后

01/25 02:54:20.399 DEBUG [$_NIOREACTOR-1-RW] (EnchachePool.java:76) -SQLRouteCache miss cache ,key:TESTDBselect * from T_VOTE where PROVINCE="shanghai"

01/25 02:54:20.400 DEBUG [$_NIOREACTOR-1-RW] (EnchachePool.java:59) -SQLRouteCache add cache ,key:TESTDBselect * from T_VOTE where PROVINCE="shanghai" value:select * from T_VOTE where PROVINCE="shanghai", route={

1 -> dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'shanghai'

LIMIT 100}

}

01/25 02:54:20.401 DEBUG [$_NIOREACTOR-1-RW] (NonBlockingSession.java:113) -ServerConnection [id=1, schema=TESTDB, host=127.0.0.1, user=test,txIsolation=3, autocommit=true, schema=TESTDB]select * from T_VOTE where PROVINCE="shanghai", route={

1 -> dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'shanghai'

LIMIT 100}

} rrs

01/25 02:54:20.401 DEBUG [$_NIOREACTOR-1-RW] (PhysicalDBPool.java:452) -select read source hostM2 for dataHost:m2

01/25 02:54:20.403 DEBUG [$_NIOREACTOR-3-RW] (NonBlockingSession.java:229) -release connection MySQLConnection [id=11, lastTime=1453661660386, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=16, charset=utf8, txIsolation=3, autocommit=true, attachment=dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'shanghai'

LIMIT 100}, respHandler=SingleNodeHandler [node=dn22{SELECT *

FROM T_VOTE

WHERE PROVINCE = 'shanghai'

LIMIT 100}, packetId=5], host=10.254.1.11, port=3327, statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync@5017d906, writeQueue=0, modifiedSQLExecuted=false]

01/25 02:54:20.403 DEBUG [$_NIOREACTOR-3-RW] (PhysicalDatasource.java:403) -release channel MySQLConnection [id=11, lastTime=1453661660386, user=root, schema=db3, old shema=db3, borrowed=true, fromSlaveDB=false, threadId=16, charset=utf8, txIsolation=3, autocommit=true, attachment=null, respHandler=null, host=10.254.1.11, port=3327, statusSync=null, writeQueue=0, modifiedSQLExecuted=false]

看到debug信息中，返回的信息是utf8，所以客户端登录的字符集是啥，返回的数据就是啥字符集的。

3.3 改成latin？

Mysql数据库都是latin，登录mycat客户端也是latin，不用测试，肯定是latin

总结：mycat登录的所有字符集，数据处理返回结果都跟着登录设置的字符集走。