TableMetadataCache uses a case sensitive cache

[GoogleCodeExporter]

What steps will reproduce the problem?

Run the following sql :

drop table if exists testPK;
drop table if exists testPK2;
drop table if exists testPK_save;
create table testPK (id1 integer primary key, val integer);
set session binlog_format=row;
insert into testPK values (1, 1) , (2,10), (3,5), (4,7);
create table testPK2 as select * from testPK;
alter table testPK2 ADD COLUMN id2 INT(11) NULL, add primary key(id1, id2);
insert into testPK2 select id1, val , 1 from testPK;

What is the expected output?
Replication works ok

What do you see instead?
Replication stops with error :
INFO   | jvm 1    | 2014/12/13 00:45:01 | Event application failed: seqno=226 
fragno=0 message=java.sql.SQLSyntaxErrorException: Unknown column '' in 'field 
list'
INFO   | jvm 1    | 2014/12/13 00:45:01 | Failing statement : INSERT INTO 
`test`.`testpk2` ( `id1`, `val`, ``) VALUES ( ?  ,  ?  ,  ? ), ( ?  ,  ?  ,  ? 
), ( ?  ,  ?  ,  ? ), ( ?  ,  ?  ,  ? )
INFO   | jvm 1    | 2014/12/13 00:45:01 | Arguments:
INFO   | jvm 1    | 2014/12/13 00:45:01 |  - ROW# = 0
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=1 name=id1 type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=2 name=val type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=3 name= type=4 
[INTEGER] length=4 unsigned=false blob=false desc=null) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |  - ROW# = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=1 name=id1 type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 2
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=2 name=val type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 10
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=3 name= type=4 
[INTEGER] length=4 unsigned=false blob=false desc=null) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |  - ROW# = 2
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=1 name=id1 type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 3
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=2 name=val type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 5
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=3 name= type=4 
[INTEGER] length=4 unsigned=false blob=false desc=null) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 |  - ROW# = 3
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=1 name=id1 type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 4
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=2 name=val type=4 
[INTEGER] length=4 unsigned=false blob=false desc=INT(11)) = 7
INFO   | jvm 1    | 2014/12/13 00:45:01 |   - COL(index=3 name= type=4 
[INTEGER] length=4 unsigned=false blob=false desc=null) = 1
INFO   | jvm 1    | 2014/12/13 00:45:01 | 
com.continuent.tungsten.replicator.applier.ApplierException: 
java.sql.SQLSyntaxErrorException: Unknown column '' in 'field list'
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.MySQLApplier.executePreparedStatement
(MySQLApplier.java:511)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.MySQLApplier.applyOneRowChangePrepare
d(MySQLApplier.java:351)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyRowChangeData(JdbcAp
plier.java:1278)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.JdbcApplier.apply(JdbcApplier.java:13
75)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.ApplierWrapper.apply(ApplierWrapper.j
ava:101)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.apply(SingleTh
readStageTask.java:797)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.runTask(Single
ThreadStageTask.java:530)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.run(SingleThre
adStageTask.java:179)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
java.lang.Thread.run(Thread.java:695)
INFO   | jvm 1    | 2014/12/13 00:45:01 | Caused by: 
java.sql.SQLSyntaxErrorException: Unknown column '' in 'field list'
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
org.drizzle.jdbc.internal.SQLExceptionMapper.get(SQLExceptionMapper.java:99)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
org.drizzle.jdbc.DrizzlePreparedStatement.executeUpdate(DrizzlePreparedStatement
.java:128)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
com.continuent.tungsten.replicator.applier.MySQLApplier.executePreparedStatement
(MySQLApplier.java:500)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       ... 8 more
INFO   | jvm 1    | 2014/12/13 00:45:01 | Caused by: 
org.drizzle.jdbc.internal.common.QueryException: Unknown column '' in 'field 
list'
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
org.drizzle.jdbc.internal.mysql.MySQLProtocol.executeQuery(MySQLProtocol.java:46
4)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       at 
org.drizzle.jdbc.DrizzlePreparedStatement.executeUpdate(DrizzlePreparedStatement
.java:125)
INFO   | jvm 1    | 2014/12/13 00:45:01 |       ... 9 more

What is the possible cause?
Cache entry for testPK2 is not invalidated as shown by the following traces :

applier.JdbcApplier Getting metadata for test.testpk2
applier.JdbcApplier Metadata for test.testpk2 retrieved from DB
filter.PrimaryKeyFilter ALTER TABLE detected - no cached table metadata to 
remove for 'test.testPK2'
applier.JdbcApplier Table metadata no invalidation: stmt=set 
@@session.pseudo_thread_id=186
applier.JdbcApplier Table metadata no invalidation: stmt=alter table testPK2 
ADD COLUMN id2 INT(11) NULL, add primary key(id1, id2)
---> we would expect this to indicate that it invalidated a cache entry for 
testPK2
applier.JdbcApplier Getting metadata for test.testpk2
applier.JdbcApplier Metadata for test.testpk2 found in cache
---> As cache was not properly invalidated, testPK2 metadata is retrieved from 
cache instead of from database, which means it still uses the old cache 
definition (one column missing) 

What is the proposed solution?

Additional information
Putting replicator back online works around the problem (as it refreshes the 
cache)

Original issue reported on code.google.com by stephane...@continuent.com on 13 Dec 2014 at 12:07

• Blocked on: #1071

[GoogleCodeExporter]

Original comment by linas.vi...@continuent.com on 19 Dec 2014 at 6:59

• Added labels: FixedIn-3.1.0
• Removed labels: FixedIn-3.0.1

[GoogleCodeExporter]

This issue seems to be related to MySQL master host.
In my case, I was testing on MacOS, which does not use case sensitive 
identifiers.

This can be solved by adding case sensitive metadata flag to events metadata.
On the slave, if the event is marked as not case sensitive, it is stored or 
retrieved from cache use lower case letters.
Otherwise, it is stored in the same case as it was extracted from master.

We should also probably flush the cache if we detect a change in case 
sensitivity (in order to be sure that we get correct behavior -- not mixing 
table name that were normalized in lower case and table name that are case 
sensitive).

Not sure if we want to commit this kind of change now or later.

Original comment by stephane...@continuent.com on 19 Dec 2014 at 10:59

[GoogleCodeExporter]

This can be delayed

Original comment by stephane...@continuent.com on 15 Jan 2015 at 3:26

[GoogleCodeExporter]

Original comment by linas.vi...@continuent.com on 19 Jan 2015 at 2:18

• Added labels: FixedIn-4.0.1
• Removed labels: FixedIn-3.1.0