search

zxs / tungsten-replicator

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

replication fails if master is running with addPkeyToInserts #923

Open GoogleCodeExporter opened 9 years ago

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

1. install a regular mysql-to-mysql master/slave replication
2. for the master node, add the options
--enable-heterogenous-master 
--property=replicator.filter.pkey.addPkeyToInserts=true
3. run the following SQL commands

create table t1 (i int not null primary key);
insert into t1 values (1);
insert into t1 values (2), (3);

What is the expected output?

Replication succeeds. All three records are replicated

What do you see instead?

the first record is replicated. The second and third (multiple insert) fails

trepctl status
Processing status command...
NAME                     VALUE
----                     -----
appliedLastEventId     : NONE
appliedLastSeqno       : -1
appliedLatency         : -1.0
autoRecoveryEnabled    : false
autoRecoveryTotal      : 0
channels               : -1
clusterName            : tsandbox
currentEventId         : NONE
currentTimeMillis      : 1400816563406
dataServerHost         : gmini
extensions             :
host                   : gmini
latestEpochNumber      : -1
masterConnectUri       : thl://gmini:12110/
masterListenUri        : thl://gmini:12120/
maximumStoredSeqNo     : -1
minimumStoredSeqNo     : -1
offlineRequests        : NONE
pendingError           : Stage task failed: stage=q-to-dbms seqno=3 fragno=0
pendingErrorCode       : NONE
pendingErrorEventId    : mysql-bin.000002:0000000000000834;-1
pendingErrorSeqno      : 3
pendingExceptionMessage: Index: 1, Size: 1
pipelineSource         : UNKNOWN
relativeLatency        : -1.0
resourcePrecedence     : 99
rmiPort                : 10120
role                   : slave
seqnoType              : java.lang.Long
serviceName            : tsandbox
serviceType            : unknown
simpleServiceName      : tsandbox
siteName               : default
sourceId               : gmini
state                  : OFFLINE:ERROR
timeInStateSeconds     : 117.967
transitioningTo        :
uptimeSeconds          : 158.699
useSSLConnection       : false
version                : Tungsten Replicator 3.0.0 build 69

What is the possible cause?

Perhaps ininfluent, but the key listed in THL is shown as NULL:

thl list -seqno 3
SEQ# = 3 / FRAG# = 0 (last frag)
- TIME = 2014-05-23 10:40:45.0
- EPOCH# = 0
- EVENTID = mysql-bin.000002:0000000000000834;-1
- SOURCEID = gmini
- METADATA = [mysql_server_id=101;dbms_type=mysql;service=tsandbox;shard=test]
- TYPE = com.continuent.tungsten.replicator.event.ReplDBMSEvent
- OPTIONS = [foreign_key_checks = 1, unique_checks = 1]
- SQL(0) =
 - ACTION = INSERT
 - SCHEMA = test
 - TABLE = t1
 - ROW# = 0
  - COL(1: i) = 2
  - KEY(1: i) = NULL
 - ROW# = 1
  - COL(1: i) = 3
  - KEY(1: i) = NULL
What is the proposed solution?

N/A

Original issue reported on code.google.com by g.maxia on 23 May 2014 at 3:45

GoogleCodeExporter commented 9 years ago 
Here's the relevant portion of the slave log:

INFO   | jvm 1    | 2014/05/23 10:40:05 | 2014-05-23 10:40:05,235 [tsandbox - 
remote-to-thl-0] INFO  thl.RemoteTHLExtractor Connection is accepted
INFO   | jvm 1    | 2014/05/23 10:40:05 | 2014-05-23 10:40:05,235 [tsandbox - 
remote-to-thl-0] INFO  thl.RemoteTHLExtractor Connected to master on 
uri=thl://gmini:12110/ after 0 retries
INFO   | jvm 1    | 2014/05/23 10:40:05 | 2014-05-23 10:40:05,235 [tsandbox - 
pool-2-thread-1] INFO  management.OpenReplicatorManager Sent State Change 
Notification GOING-ONLINE:SYNCHRONIZING -> ONLINE
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,421 [tsandbox - 
q-to-dbms-0] ERROR pipeline.SingleThreadStageTask Stage task failed: 
stage=q-to-dbms seqno=3 fragno=0
INFO   | jvm 1    | 2014/05/23 10:40:45 | java.lang.IndexOutOfBoundsException: 
Index: 1, Size: 1
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.util.ArrayList.RangeCheck(ArrayList.java:547)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.util.ArrayList.get(ArrayList.java:322)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyOneRowChangePrepared
(JdbcApplier.java:1040)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyRowChangeData(JdbcAp
plier.java:1263)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.apply(JdbcApplier.java:13
56)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.ApplierWrapper.apply(ApplierWrapper.j
ava:101)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.apply(SingleTh
readStageTask.java:797)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.runTask(Single
ThreadStageTask.java:530)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.run(SingleThre
adStageTask.java:179)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.lang.Thread.run(Thread.java:695)
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,422 [tsandbox - 
q-to-dbms-0] INFO  pipeline.SingleThreadStageTask Performing emergency rollback 
of applied changes
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,423 [tsandbox - 
q-to-dbms-0] INFO  pipeline.SingleThreadStageTask Dispatching error event: 
Stage task failed: stage=q-to-dbms seqno=3 fragno=0
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,423 [tsandbox - 
q-to-dbms-0] INFO  pipeline.SingleThreadStageTask Terminating processing for 
stage task thread
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,423 [tsandbox - 
q-to-dbms-0] INFO  pipeline.SingleThreadStageTask Last successfully processed 
event prior to termination: seqno=3 eventid=mysql-bin.000002:0000000000000834;-1
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,423 [tsandbox - 
q-to-dbms-0] INFO  pipeline.SingleThreadStageTask Task event count: 4
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,424 [tsandbox - 
pool-2-thread-1] ERROR management.OpenReplicatorManager Received error 
notification, shutting down services :
INFO   | jvm 1    | 2014/05/23 10:40:45 | Stage task failed: stage=q-to-dbms 
seqno=3 fragno=0
INFO   | jvm 1    | 2014/05/23 10:40:45 | java.lang.IndexOutOfBoundsException: 
Index: 1, Size: 1
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.util.ArrayList.RangeCheck(ArrayList.java:547)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.util.ArrayList.get(ArrayList.java:322)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyOneRowChangePrepared
(JdbcApplier.java:1040)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.applyRowChangeData(JdbcAp
plier.java:1263)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.JdbcApplier.apply(JdbcApplier.java:13
56)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.applier.ApplierWrapper.apply(ApplierWrapper.j
ava:101)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.apply(SingleTh
readStageTask.java:797)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.runTask(Single
ThreadStageTask.java:530)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
com.continuent.tungsten.replicator.pipeline.SingleThreadStageTask.run(SingleThre
adStageTask.java:179)
INFO   | jvm 1    | 2014/05/23 10:40:45 |   at 
java.lang.Thread.run(Thread.java:695)
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,424 [tsandbox - 
pool-2-thread-1] WARN  management.OpenReplicatorManager Performing emergency 
service shutdown
INFO   | jvm 1    | 2014/05/23 10:40:45 | 2014-05-23 10:40:45,424 [tsandbox - 
pool-2-thread-1] INFO  pipeline.Pipeline Shutting down pipeline: slave

Original comment by g.maxia on 23 May 2014 at 3:46

GoogleCodeExporter commented 9 years ago 
Thanks for the detailed bug report.  I will investigate this first thing Friday 
 Does this problem occur in a 2.2.1 replicator?  (Just want to ensure it's a 
regression and not something that has been around for a while...)

Original comment by robert.h...@continuent.com on 23 May 2014 at 5:03

GoogleCodeExporter commented 9 years ago 
It also fails on 2.2.1-403.

I have removed the "regression" label

Original comment by g.maxia on 23 May 2014 at 6:09

GoogleCodeExporter commented 9 years ago

Original comment by linas.vi...@continuent.com on 19 Dec 2014 at 7:03

GoogleCodeExporter commented 9 years ago

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