View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0002826 | SymmetricDS | Bug | public | 2016-09-23 08:08 | 2023-10-01 23:46 |
Reporter | wrygiel | Assigned To | cquamme | ||
Priority | normal | ||||
Status | closed | Resolution | fixed | ||
Product Version | 3.8.4 | ||||
Target Version | 3.15.0 | Fixed in Version | 3.15.0 | ||
Summary | 0002826: Monitor event duplicate key when syncing | ||||
Description | I'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' | ||||
Tags | monitoring | ||||
|
> (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. |
|
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? |
|
> 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? |
|
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 |
|
Re-opening. Was accidentally closed when performing the release. |
|
This problem affects me as well. |
|
What version of SymmetricDS are you using? @enedil |
|
@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. |
|
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. |
|
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. |
|
Will be fixed by 0005778 |
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 |