search

epermana / tungsten-replicator

Automatically exported from code.google.com/p/tungsten-replicator
1 stars 0 forks source link

SET with a single quote in the value fails to apply if logged to the binary log #121

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?

The following steps are taken from our RQG test suite and provided in an 
explicit fashion for easier reproduction:

0. Download and extract 
http://launchpad.net/randgen/2.0/2.2.0/+download/randgen-2.2.0.tgz
1. Setup a direct Tungsten slave topology (MySQL->Tungsten, no Tungsten on the 
master).
2. From within the extracted randgen-2.2.0 folder execute (substitue $mysql_* 
connection parameters as needed):
perl gentest.pl --engine=Innodb --gendata=conf/replication_single_engine.zz 
--grammar=conf/replication.yy --queries=1000 --threads=1 --duration=5 
--dsn=dbi:mysql:host=$mysql_master_host:port=$mysql_port:user=$mysql_user:passwo
rd=$mysql_pass:database=$mysql_db

What is the expected output?

After test completes slave Tungsten Replicator should be ONLINE.

What do you see instead?

If query count (see parameter above) is 100 - it is ONLINE;
If query count is increased to 1000, slave collapses:

INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:10,985 INFO  
commons.commands.FileDeleteTask File deleted: 
/home/tungsten/tinstall/relay/baltic/mysql-bin.000623
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,161 INFO  
extractor.mysql.RelayLogClient Closing relay log: 
name=/home/tungsten/tinstall/relay/baltic/mysql-bin.000626 bytes=10180
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,161 INFO  
extractor.mysql.RelayLogClient Opening relay log: 
name=/home/tungsten/tinstall/relay/baltic/mysql-bin.000627
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,161 INFO  
extractor.mysql.RelayLogClient Adding relay log to binlog index: 
/home/tungsten/tinstall/relay/baltic/mysql-bin.index
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,165 INFO  
extractor.mysql.MySQLExtractor Checking for old relay log files...
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,165 INFO  
commons.commands.FileDeleteTask File deleted: 
/home/tungsten/tinstall/relay/baltic/mysql-bin.000624
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,175 INFO  
extractor.mysql.RelayLogClient Closing relay log: 
name=/home/tungsten/tinstall/relay/baltic/mysql-bin.000627 bytes=149
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,175 INFO  
extractor.mysql.RelayLogClient Opening relay log: 
name=/home/tungsten/tinstall/relay/baltic/mysql-bin.000628
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,175 INFO  
extractor.mysql.RelayLogClient Adding relay log to binlog index: 
/home/tungsten/tinstall/relay/baltic/mysql-bin.index
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,176 INFO  
extractor.mysql.MySQLExtractor Checking for old relay log files...
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,176 INFO  
commons.commands.FileDeleteTask File deleted: 
/home/tungsten/tinstall/relay/baltic/mysql-bin.000625
INFO   | jvm 1    | 2011/06/16 20:50:11 | Jun 16, 2011 8:50:11 PM 
org.drizzle.jdbc.internal.mysql.MySQLProtocol executeQuery
INFO   | jvm 1    | 2011/06/16 20:50:11 | WARNING: Could not execute query 
org.drizzle.jdbc.internal.common.query.DrizzleQuery@56c6580c: You have an error 
in your SQL syntax; check the manual that corresponds to your MySQL server 
version for the right syntax to use near 'll'' at line 1
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,229 ERROR 
replicator.applier.JdbcApplier Statement failed: SET @a := 'I'll'
INFO   | jvm 1    | 2011/06/16 20:50:11 | 2011-06-16 20:50:11,230 ERROR 
replicator.pipeline.SingleThreadStageTask [d-pq-to-dbms-0] Event application 
failed: seqno=8058 fragno=0 message=java.sql.SQLException: Statement failed on 
slave but succeeded on master
INFO   | jvm 1    | 2011/06/16 20:50:11 | 
com.continuent.tungsten.replicator.applier.ApplierException: 
java.sql.SQLException: Statement failed on slave but succeeded on master
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyStatementData(JdbcAp
plier.java:624)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.applier.MySQLDrizzleApplier.applyStatementDat
a(MySQLDrizzleApplier.java:99)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.applier.JdbcApplier.apply(JdbcApplier.java:12
05)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.applier.ApplierWrapper.apply(ApplierWrapper.j
ava:100)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.runTask(Single
ThreadStageTask.java:438)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.run(SingleThre
adStageTask.java:148)
INFO   | jvm 1    | 2011/06/16 20:50:11 |     at java.lang.Thread.run(Unknown 
Source)re

./thl list -seqno 8058 -service baltic output:

SEQ# = 8058 / FRAG# = 0 (last frag)
- TIME = 2011-06-16 20:50:11.0
- EVENTID = 000628:0000000000004264;292782
- SOURCEID = qa.r2.continuent.com
- STATUS = COMPLETED(2)
- METADATA = [mysql_server_id=10;service=baltic;shard=test]
- TYPE = com.continuent.tungsten.replicator.event.ReplDBMSEvent
- SQL(0) = SET INSERT_ID=130
- SQL(1) = SET @a := 'I'll'
- OPTIONS = [##charset = ISO8859_1, autocommit = 1, sql_auto_is_null = 1, 
foreign_key_checks = 1, unique_checks = 1, sql_mode = '', character_set_client 
= 8, collation_connection = 8, collation_server = 8]
- SCHEMA = test
- SQL(2) = INSERT INTO `table100_int_autoinc` ( `col_set_utf8` ) VALUES ( @a )

Another similar one:

INFO   | jvm 1    | 2011/06/16 20:57:24 | 2011-06-16 20:57:24,802 ERROR 
replicator.applier.JdbcApplier Statement failed: SET @a := 'don't'

What is the possible cause?

Apparently, the test flexes the binary log in such a way, that the SET 
statement together with the apostrophe is saved in it, which we then read and 
fail to apply, because of the incorrect quoting.

An example of a similar binary log record generated by this test (a whole file 
is attached to the case):

  autocommit^^1"^                                                                                                                                                                                  
  ^sql_auto_is_null^^1"^                                                                                                                                                                           
  ^foreign_key_checks^^1"^                                                                                                                                                                         
  ^unique_checks^^1"^                                                                                                                                                                              
  ^sql_mode^^''"^                                                                                                                                                                                  
  ^character_set_client^^8"^                                                                                                                                                                       
  ^collation_connection^^8"^                                                                                                                                                                       
  ^collation_server^^8(.2sUPDATE `table1_innodb` SET `col_decimal_unsigned_not_null` = RAND() WHERE `col_float_not_null` > 6 ORDER BY RAND ()^^                                                    
  ^mysql_server_id^^10^^                                                                                                                                                                            
  ^service^^baltic^^                                                                                                                                                                               
     ^shard^^test...........^d^..........^.........^qa.r2.continuent.com.^000017:0000000000005852;298584.^#DEFAULT..^0..1.Y^.^^.^^ ...މ&(...މ&2^qa.r2.continuent.com8.B^000017:000000                 
7^^^3^/SET @a := 'I'll' /* ___SERVICE___ = [baltic] */(.                        

.^^^^.^                                                                         

  ^test^...މ&"^                                                                                                                                                                                    
        ##charset^     ISO8859_1"^

Original issue reported on code.google.com by linas.vi...@gmail.com on 17 Jun 2011 at 4:52

Attachments:

GoogleCodeExporter commented 9 years ago

Original comment by linas.vi...@gmail.com on 17 Jun 2011 at 5:07

GoogleCodeExporter commented 9 years ago 
This issue was closed by revision r225.

Original comment by stephane...@gtempaccount.com on 17 Jun 2011 at 11:54