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

1、1, 执行select*fromtravelrecord,分析Debug日志,说明整个执行逻辑，包括连接获取，连接同步信息，数据合并，数据返回，连接释放1.1 清空debug信息rootwgq_idc_squid_1_11logs#cat/dev/null>mycat.logrootwgq_idc_squid_1_11logs#ll修改日志为debug：vim10g4j.xml<root><levelvalue="debug"/><appender-refref="FILE"/><!-<appende

2、r-refref="FILE"/>-></root>获取日志：rootwgq_idc_squid_1_11logs#cpmycat.log1.logrootwgq_idc_squid_1_11logs#vim1.log1.1 连接获取01/2421:59:12.850DEBUG$_NIOREACTOR-3-RW(EnchachePool.java:76)-SQLRouteCachemisscache,key:TESTDBselect*fromtravelrecord01/2421:59:12.851DEBUG$_NIOREACTOR-3-RW(Enc

3、hachePool.java:59)-SQLRouteCacheaddcache,key:TESTDBselect*fromtravelrecordvalue:select*fromtravelrecord,route=1 ->dn1SELECT*FROMtravelrecordLIMIT1002 ->dn2SELECT*FROMtravelrecordLIMIT1003 ->dn3SELECT*FROMtravelrecordLIMIT100)01/2421:59:12.852DEBUG$_NIOREACTOR-3-RW(NonBlockingSession.java:11

4、3)-ServerConnectionid=4,schema=TESTDB,host=127.0.0.1,user=test,txIsolation=3,autocommit=true,schema=TESTDBselect*fromtravelrecord,route=4 ->dn1SELECT*FROMtravelrecordLIMIT1005 ->dn2SELECT*FROMtravelrecordLIMIT1006 ->dn3SELECT*FROMtravelrecordLIMIT100rrs1.2 连接同步信息:01/2421:59:12.852DEBUG$_NIO

5、REACTOR-3-RW(MySQLConnection.java:445)-conneedsyn,totalsyncmd2commandsSETnameslatin1;SETSESSIONTRANSACTIONISOLATIONLEVELREPEATABLEREAD;schemachange:falsecon:MySQLConnectionid=11,lastTime=1453643952852,user=root,schema=db1,oldshema=db1,borrowed=true,fromSlaveDB=true,threadId=3425,charset=latin1,txIso

6、lation=0,autocommit=true,attachment=dn1SELECT*FROMtravelrecordLIMIT100,respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler30a6aae0,host=127.0.0.1,port=3327,statusSync=null,writeQueue=0,modifiedSQLExecuted=false1.3 数据合并01/2421:59:12.856DEBUGBusinessExecutor6(DataMergeService.java:296)-

7、preparemppmergeresultforselect*fromtravelrecord01/2421:59:12.856DEBUGBusinessExecutor6(MultiNodeQueryHandler.java:324)-lastpacketid:1101/2421:59:21.910DEBUGTimer1(SQLJob.java:85)-conquerysql:showslavestatustocon:MySQLConnectionid=14,lastTime=1453643961910,user=root,schema=db1,oldshema=db1,borrowed=t

8、rue,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,modfiedSQLExecuted=false01/2421:59:21.910DEBUGTimer1(SQLJob.java:85)-conquerysql:showslavestatustocon:MySQLConnectionid=27,lastTime=14

9、53643961910,user=root,schema=db1,oldshema=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=false1.4 数据返回01/2421:59:12.854DEBUG$_NIOREACTOR-3-RW(Mul

10、tiNodeQueryHandler.java:171)-receivedokresponse,executeResponse:falsefromMySQLConnectionid=11,lastTime=1453643952835,user=root,schema=db1,oldshema=db1,borrowed=true,fromSlaveDB=true,threadId=3425,charset=latin1,txIsolation=0,autocommit=true,attachment=dn1SELECT*FROMtravelrecordLIMIT100,respHandler=o

11、rg.opencloudb.mysql.nio.handler.MultiNodeQueryHandler30a6aae0,host=127.0.0.1,port=3327,statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync6d43df48,writeQueue=0,modifiedSQLExecuted=false01/2421:59:12.855DEBUG$_NIOREACTOR-3-RW(MultiNodeQueryHandler.java:171)-receivedokresponse,executeRespon

12、se:falsefromMySQLConnectionid=11,lastTime=1453643952835,user=root,schema=db1,oldshema=db1,borrowed=true,fromSlaveDB=true,threadId=3425,charset=latin1,txIsolation=3,autocommit=true,attachment=dn1SELECT*FROMtravelrecordLIMIT100,respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler30a6aae0

13、,host=127.0.0.1,port=3327,statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync6d43df48,writeQueue=0,modifiedSQLExecuted=false1.5 连接释放:01/2421:59:21.911DEBUG$_NIOREACTOR-2-RW(PhysicalDatasource.java:403)-releasechannelMySQLConnectionid=14,lastTime=1453643961901,user=root,schema=db1,oldshema

14、=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=false01/2421:59:21.911DEBUG$_NIOREACTOR-1-RW(PhysicalDatasource.java:403)-releasechannelMySQLConnec

15、tionid=27,lastTime=1453643961901,user=root,schema=db1,oldshema=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,modfiedSQLExecuted=false01/2421:59:21.911DEBUG$_NIOREAC

16、TOR-2-RW(PhysicalDatasource.java:403)-releasechannelMySQLConnectionid=16,lastTime=1453643961901,user=root,schema=db1,oldshema=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,writeQue

17、ue=0,modifiedSQLExecuted=false2,新增一个分片表T_VOTE(ID,PROVINCE),PROVINCE用hash分片，并用reload命令方式重载生效，截图和文字说明整个过程。2.1配置hash分片Schema.xml文件，dataNode有dn21、dn22;dataHost有m1、m2,如下2.1.jpg所示:Rule.xmlEWlCwgq_idc_sqi2id_l_llconftvimrul.xml<tableRule己丁：三<rule>stisrdin5-by-nrunnuq<coLumns>PRO7INCeJ-2Dlinn

18、ns><.d_ql-riri<.-digE/ruLe><AtBtLeEtule>reload更新配置文件:U|iqLJirEaaj自皿由1tftra.P19xijl4-iq|l-pyBCdjXantife曲in.i34hr-&iq3aeTMETTZFIES,打工1»)ZDEjlTTFZfJLrajaM|i冲Imysql>reloadconfig;ERROR1064(HY000):com.alibaba.druid.sql.parser.ParserException:syntaxerror,errorin:'reloadcon

19、fig',expectIDENTIFIER,actualIDENTIFIERreloadmysql>问题好奇怪，虽然有报错信息，但是后台生效了，建表explain可以看到新的dn21和dn22,如下所示：建表：mysq;1>explaincreatetableT_TOTE(LDinr,ERCVTNCEvarctiar(4);ImrA_NODEISOLI41-i-Idn21ICTatetableTVUTE<IDint,PROVINCEvarchar(64)IIdn.22IcreatetableTJTO7E任Dint,PROVINCEvarchar(4)|t+2ro-ws

20、inaL(C.00sec)inysq;1>createtbleT_WIE(IDint,PR(?VINCEvarciiar(64);QueryOK0rowaaffected(0.02sec)mysq：1>I2.2录入初始化数据验证数据分片:mysql>insertTJTOTEIDrPRINCEJvalues(Lrbeijing;QueryOEff1rowaffecxed(C.Clmuc)mysql>explaininsertT_VOTE(IDrPROVINCEvalues(2tTshanghai');IMTA_NaD£ISQLIH+Idn22Iinser

21、tTVOTE(ZD,PROVIWCE)values2,1shanghai1JI1rowinsee(fl.00secJmy31>insertT_VOTE(IDrPROVINCE)values(2.rahangKai1>：QueryOK,1rowaffsexed(O.COsee.)inysql>mysql>insertTVDTE(IDrPROVINCE)values(3rTtianjingT);QueryOK.1rowaffecred(O,C13ec.)Dysql>insertT_VOTI(ID,PROVINCE)values(4,FctiongiiTifl"

22、;);QueryOK,1rowaffected(04C2sec)mysql>jnysql>explainseleat/fromTJVDTE;IQftTA_NODKISQLI+1-HIdn21I5ELECT*FROMTJVOTELIHIT100IIdn22ISELECT*FROMT_VOTtLIMIT10QII+Zrowsin(QP07呢Gmy3ql>|总共录入了4条记录，去查看数据，2条记录在dn21分片上也就是mysql的3317实例上面,2条记录在dn22分片也就是mysql的3327实例上，如下所示：Dn21分片3317mysql端口:福kd.4.曾，/MI/XMAX/

23、W11mgi"»Hi-flhMtn户:|L的37JMCKh/wM制与工”CiterEUEiE三IdtparcIISiJlTIIICD1fflJVTMEI-31TiKijliqII，«MhH3H4IIE«ti|*W_l19e_fJiLS_LJL3ILac_agu!.J_L_in"Dn22分片3327mysql端口:3,该字符集为latin后的显示3.1 Mysql服务器字符集为latin:后台debug信息显示为charset=latin1了：01/2502:47:19.128DEBUG$_NIOREACTOR-1-RW(MySQLConnect

24、ion.java:445)-conneedsyn,totalsyncmd1commandsSETSESSIONTRANSACTIONISOLATIONLEVELREPEATABLEREAD;schemachange:falsecon:MySQLConnectionid=32,lastTime=1453661239128,user=root,schema=db3,oldshema=db3,borrowed=true,fromSlaveDB=false,threadId=23,charset=latin1,txIsolation=0,autocommit=true,attachment=dn22S

25、ELECT*FROMT_VOTELIMIT100,respHandler=org.opencloudb.mysql.nio.handler.MultiNodeQueryHandler5485687f,host=10.254.1.11,port=3327,statusSync=null,writeQueue=0,modifiedSQLExecuted=false3.2 登录mycat的客户端设置成gbk:面setnameagblr;Query0Kfra-wsaffec-t-ed0.01aecjKiysl>mysl>mystjl>select-*franT_VC-TEp-ib|I

26、D|PROVINCE|+4-I3Iti皿lugII4IqgngqHngII1IXLLagII2IshMighaiI4+qn>wginse.(C-10aeclmysq：l>m¥3q：l>inym工二select*fruraT_WTEwherePROVlKCEl="beijinflw;十十十IIDIPROVINCEI,+-十I1IbeijiTigI1rowinsen(0.05sec)ERROR!Ndtfueryspecifiedinysq：1>|1/2502:50:26.348DEBUG$_NIOREACTOR-1-RW(EnchachePool.jav

27、a:76)-SQLRouteCachemisscache,key:TESTDBselect*fromT_VOTEwherePROVINCE="beijing"01/2502:50:26.392DEBUG$_NIOREACTOR-1-RW(EnchachePool.java:59)-SQLRouteCacheaddcache,key:TESTDBselect*fromT_VOTEwherePROVINCE="beijing"value:select*fromT_VOTEwherePROVINCE="beijing",route=1-&g

28、t;dn22SELECT*FROMT_VOTEWHEREPROVINCE='beijing'LIMIT100)01/2502:50:26.393DEBUG$_NIOREACTOR-1-RW(NonBlockingSession.java:113)-ServerConnectionid=1,schema=TESTDB,host=127.0.0.1,user=test,txIsolation=3,autocommit=true,schema=TESTDBselect*fromT_VOTEwherePROVINCE="beijing",route=1->dn

29、22SELECT*FROMT_VOTEWHEREPROVINCE='beijing'LIMIT100rrs01/2502:50:26.393DEBUG$_NIOREACTOR-1-RW(PhysicalDBPool.java:452)-selectreadsourcehostM2fordataHost:m201/2502:50:26.396DEBUG$_NIOREACTOR-3-RW(NonBlockingSession.java:229)-releaseconnectionMySQLConnectionid=11,lastTime=1453661426394,user=roo

30、t,schema=db3,oldshema=db3,borrowed=true,fromSlaveDB=false,threadId=16,charset=gbk,txIsolation=3,autocommit=true,attachment=dn22SELECT*FROMT_VOTEWHEREPROVINCE='beijing'LIMIT100,respHandler=SingleNodeHandlernode=dn22SELECT*FROMT_VOTEWHEREPROVINCE='beijing'LIMIT100,packetId=5,host=10.25

31、4.1.11,port=3327,statusSync=org.opencloudb.mysql.nio.MySQLConnection$StatusSync54a7f2c7,writeQueue=0,modifiedSQLExecuted=false01/2502:50:26.396DEBUG$_NIOREACTOR-3-RW(PhysicalDatasource.java:403)-releasechannelMySQLConnectionid=11,lastTime=1453661426394,user=root,schema=db3,oldshema=db3,borrowed=true

32、,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=false01/2502:50:32.191DEBUGTimer0(SQLJob.java:85)-conquerysql:selectuser()tocon:MySQLConnectionid=2,lastTime=145366143

33、2191,user=root,schema=db3,oldshema=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客户端设置的字符集

34、有关。3.3设置成为utf8后mysill>setTimmEgut£E;Query0Kf口rowsaffected(0.00sec)mygq：l>aeLect+fromT_WTEwherePRamNCEsiianghai"：1+IIDIPROVINCEII14I2I9iiariiaiI_i1卜1ro-winset(0.01sec)ERROR；Nobehyapecifiedmysq：l>|01/2502:54:20.399DEBUG$_NIOREACTOR-1-RW(EnchachePool.java:76)-SQLRouteCachemisscache,k

35、ey:TESTDBselect*fromT_VOTEwherePROVINCE="shanghai"01/2502:54:20.400DEBUG$_NIOREACTOR-1-RW(EnchachePool.java:59)-SQLRouteCacheaddcache,key:TESTDBselect*fromT_VOTEwherePROVINCE="shanghai"value:select*fromT_VOTEwherePROVINCE="shanghai",route=1->dn22SELECT*FROMT_VOTEWHER

36、EPROVINCE='shanghai'LIMIT100)01/2502:54:20.401DEBUG$_NIOREACTOR-1-RW(NonBlockingSession.java:113)-ServerConnectionid=1,schema=TESTDB,host=127.0.0.1,user=test,txIsolation=3,autocommit=true,schema=TESTDBselect*fromT_VOTEwherePROVINCE="shanghai",route=1->dn22SELECT*FROMT_VOTEWHEREPROVINCE=