View Issue Details

IDProjectCategoryView StatusLast Update
0002826SymmetricDSBugpublic2023-10-01 23:46
Reporterwrygiel Assigned Tocquamme  
Prioritynormal 
Status closedResolutionfixed 
Product Version3.8.4 
Target Version3.15.0Fixed in Version3.15.0 
Summary0002826: Monitor event duplicate key when syncing
DescriptionI'd to reopen issue 0002819, but I think I don't have proper permissions (or, I cannot find a proper button?)

I have upgraded to 3.8.4. (Or, to be exact, it's a custom build based on tag 3.8.4 + cherry-picked commit c964148f.) But I'm still getting heartbeat conflicts after this upgrade.

org.jumpmind.symmetric.io.data.writer.ConflictException: Detected conflict while executing UPDATE on wrygiel_usosweb.sym_monitor_event. The primary key data was: {monitor_id=error_detector, node_id=oracle, event_time=2016-09-23 07:30:00
.000000000}. Failed to fallback. The original error message was: Duplicate entry 'error_detector-oracle-2016-09-23 07:30:00' for key 'PRIMARY'
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriterConflictResolver.performFallbackToUpdate(AbstractDatabaseWriterConflictResolver.java:239)
        at org.jumpmind.symmetric.io.data.writer.DefaultTransformWriterConflictResolver.performFallbackToUpdate(DefaultTransformWriterConflictResolver.java:110)
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriterConflictResolver.needsResolved(AbstractDatabaseWriterConflictResolver.java:92)
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:175)
        at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
        at org.jumpmind.symmetric.model.ProcessInfoDataWriter.write(ProcessInfoDataWriter.java:65)
        at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
        at org.jumpmind.symmetric.io.data.writer.TransformWriter.write(TransformWriter.java:207)
        at org.jumpmind.symmetric.io.data.DataProcessor.forEachDataInTable(DataProcessor.java:200)
        at org.jumpmind.symmetric.io.data.DataProcessor.forEachTableInBatch(DataProcessor.java:170)
        at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:116)
        at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$1.call(DataLoaderService.java:925)
        at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$1.call(DataLoaderService.java:911)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
[mytest] - DataLoaderService - Failed to load batch oracle-5999
org.jumpmind.symmetric.io.data.writer.ConflictException: Detected conflict while executing UPDATE on wrygiel_usosweb.sym_monitor_event. The primary key data was: {monitor_id=error_detector, node_id=oracle, event_time=2016-09-23 07:30:00.000000000}. Failed to fallback. The original error message was: Duplicate entry 'error_detector-oracle-2016-09-23 07:30:00' for key 'PRIMARY'
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriterConflictResolver.performFallbackToUpdate(AbstractDatabaseWriterConflictResolver.java:239)
        at org.jumpmind.symmetric.io.data.writer.DefaultTransformWriterConflictResolver.performFallbackToUpdate(DefaultTransformWriterConflictResolver.java:110)
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriterConflictResolver.needsResolved(AbstractDatabaseWriterConflictResolver.java:92)
        at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:175)
        at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
        at org.jumpmind.symmetric.model.ProcessInfoDataWriter.write(ProcessInfoDataWriter.java:65)
        at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64)
        at org.jumpmind.symmetric.io.data.writer.TransformWriter.write(TransformWriter.java:207)
        at org.jumpmind.symmetric.io.data.DataProcessor.forEachDataInTable(DataProcessor.java:200)
        at org.jumpmind.symmetric.io.data.DataProcessor.forEachTableInBatch(DataProcessor.java:170)
        at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:116)
        at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$1.call(DataLoaderService.java:925)
        at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$1.call(DataLoaderService.java:911)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
[oracle] - AcknowledgeService - Batch 5998 for mytest was set to OK. Updating the status to OK
[oracle] - AcknowledgeService - Batch 5999 for mytest was set to OK. Updating the status to OK
[oracle] - AcknowledgeService - The outgoing batch mytest-5999 failed: [CONFLICT,-999] Detected conflict while executing UPDATE on wrygiel_usosweb.sym_monitor_event. The primary key data was: {monitor_id=error_detector, node_id=oracle, event_time=2016-09-23 07:30:00.000000000}. Failed to fallback. The original error message was: Duplicate entry 'error_detector-oracle-2016-09-23 07:30:00' for key 'PRIMARY'
Tagsmonitoring

Relationships

related to 0005778 closedcquamme Change timestamp size on sym tables with a timestamp as a primary key 

Activities

wrygiel

2016-09-23 08:48

reporter   ~0000863

> (Or, to be exact, it's a custom build based on tag 3.8.4 + cherry-picked commit c964148f.)

I gave a wrong commit-id in the sentence above. I meant f573bd49dbd (0002805: mysql_bulk may cause NullPointerException). Just to make mysql_bulk work without waiting for 3.8.5.

elong

2016-09-27 20:31

developer   ~0000865

What is the source and target databases? I just tried using it with Oracle, but I can't reproduce the conflict when syncing monitor events.

Did you change how often the monitor job runs? It runs every 60 seconds by default.

That you got a time of exactly 7:30:00 with 0 seconds is suspicious. Is the database truncating the seconds?

wrygiel

2016-09-28 16:55

reporter   ~0000866

> What is the source and target databases?

Oracle and MariaDB. (I have described my setup in the original issue. Perhaps we should reopen it, to avoid confusion?)

> That you got a time of exactly 7:30:00 with 0 seconds is suspicious. Is the database truncating the seconds?

I don't think so... I have "db.treat.date.time.as.varchar.enabled=true" set in both engine files. Perhaps this might have affected it?

wrygiel

2016-09-28 16:58

reporter   ~0000867

Oracle properties:

engine.name=oracle
db.driver=oracle.jdbc.driver.OracleDriver
db.url=jdbc:oracle:thin:@...:1521:...
db.user=...
db.password=...
registration.url=
sync.url=http://localhost:31415/sync/oracle
group.id=oracle
external.id=oracle
job.routing.period.time.ms=2500
job.push.period.time.ms=5000
job.pull.period.time.ms=5000
initial.load.delete.first=true
initial.load.delete.first.sql=truncate %s
db.treat.date.time.as.varchar.enabled=true

MariaDB properties:

engine.name=usosweb
external.id=usosweb
group.id=usosweb
sync.url=http://localhost:31415/sync/usosweb
registration.url=http://localhost:31415/sync/oracle
db.driver=com.mysql.jdbc.Driver
db.url=jdbc:mysql://.../...?tinyInt1isBit=false&characterEncoding=utf8&zeroDateTimeBehavior=convertToNull
db.user=...
db.password=...
job.routing.period.time.ms=2500
job.push.period.time.ms=5000
job.pull.period.time.ms=5000
db.treat.date.time.as.varchar.enabled=true

admin

2016-09-30 14:28

administrator   ~0000883

Re-opening. Was accidentally closed when performing the release.

enedil

2023-04-28 08:45

reporter   ~0002310

This problem affects me as well.

cquamme

2023-05-03 17:27

developer   ~0002313

Last edited: 2023-05-03 17:28

View 2 revisions

What version of SymmetricDS are you using? @enedil

enedil

2023-05-04 20:02

reporter   ~0002316

@cquamme it's the latest one, 3.15. In fact, I already built SymmetricDS from source and tried to debug it using debug prints.

For me, the issue occurs when I perform a reload request. I have two databases, Oracle and MariaDB.
I tracked the problem a bit. I insert truncated date to Oracle:

insert into sym_table_reload_request(TARGET_NODE_ID, SOURCE_NODE_ID, TRIGGER_ID, ROUTER_ID, CREATE_TIME,
                                     DELETE_FIRST, LAST_UPDATE_TIME)
values ('mariadb', 'oracle', 'trig_x', 'router_x', cast(current_timestamp as date), '1', cast(current_timestamp as date));


SymmetricDS reads the date (truncated to seconds). At the time of insert to MariaDB (this is what SymmetricDS does), the create_time is already with 8 zeros precision (checked via WireShark on the server symmetricds is running on).

This is a problem ( https://stackoverflow.com/questions/76076318/filtering-on-datetime-field-works-different-for-select-and-delete ).

Perhaps you know how does exactly SymmetricDS parse and stringify retrieved dates? Note that the conversion from zero zeroes after decimal point in seconds, to 8 shouldn't be a fault of ojdbc, since sym_table_reload_request is declared to hold only 6 digits of precision. Perhaps some Java automatic conversion? If you could point me to the right direction, I can investigate further, and perhaps contribute back to SymmetricDS.

jvanmeter

2023-05-10 17:48

developer   ~0002322

Do you have the following parameter set:

db.treat.date.time.as.varchar.enabled=true

If so, try setting this parameter to false and then doing your reload request.

enedil

2023-05-15 20:54

reporter   ~0002323

Thank you, it indeed helped. Maybe you should include information about this setting on MariaDB part of the docs? This is assuming the issue is universal to every setup with MariaDB.

elong

2023-05-16 12:58

developer   ~0002324

Will be fixed by 0005778

Issue History

Date Modified Username Field Change
2016-09-23 08:08 wrygiel New Issue
2016-09-23 08:48 wrygiel Note Added: 0000863
2016-09-27 20:31 elong Note Added: 0000865
2016-09-27 20:31 elong Status new => feedback
2016-09-28 16:55 wrygiel Note Added: 0000866
2016-09-28 16:55 wrygiel Status feedback => new
2016-09-28 16:58 wrygiel Note Added: 0000867
2016-09-30 01:01 admin Status new => closed
2016-09-30 14:28 admin Status closed => new
2016-09-30 14:28 admin Note Added: 0000883
2019-04-24 13:24 elong Tag Attached: monitoring
2019-04-25 20:22 elong Summary Cannot reopen issues? => Monitor event duplicate key when syncing
2019-04-25 20:24 elong Category Task => Bug
2019-04-25 20:24 elong Product Version => 3.8.4
2023-04-28 08:45 enedil Note Added: 0002310
2023-05-03 17:27 cquamme Note Added: 0002313
2023-05-03 17:28 cquamme Note Edited: 0002313 View Revisions
2023-05-04 20:02 enedil Note Added: 0002316
2023-05-10 17:48 jvanmeter Note Added: 0002322
2023-05-15 18:03 cquamme Status new => feedback
2023-05-15 20:54 enedil Note Added: 0002323
2023-05-16 12:58 elong Relationship added related to 0005778
2023-05-16 12:58 elong Note Added: 0002324
2023-05-16 12:59 elong Assigned To => cquamme
2023-05-16 12:59 elong Status feedback => resolved
2023-05-16 12:59 elong Resolution open => fixed
2023-05-16 12:59 elong Fixed in Version => 3.15.0
2023-05-16 12:59 elong Target Version => 3.15.0
2023-10-01 23:46 admin Status resolved => closed