View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0003845 | SymmetricDS | Bug | public | 2019-01-03 17:30 | 2022-09-19 18:41 |
Reporter | lukasz.krawczyk | Assigned To | pmarzullo | ||
Priority | high | ||||
Status | closed | Resolution | fixed | ||
Product Version | 3.9.16 | ||||
Target Version | 3.14.2 | Fixed in Version | 3.14.2 | ||
Summary | 0003845: Primary key constraint violation while replicating single table from MSSQL 2017 into PostgreSQL 9.6 | ||||
Description | This bug does NOT appear in SymmetricDS 3.8.41 version and is due to erroneous MSSQL database trigger definition in 3.9.16 version. Consider the following MSSQL table: CREATE TABLE [dbo].[rightsholder_invoice]( [rightsholder_invoice_id] [int] NOT NULL, [rightsholder_invoice_datetime] [datetime] NOT NULL, [rightsholder_id] [int] NOT NULL, [number] [varchar](128) NOT NULL, [income_date] [date] NOT NULL, [invoice_date] [date] NOT NULL, [sale_date] [date] NOT NULL, [rightsholder_invoice_type_id] [int] NOT NULL, [status_description] [varchar](128) NULL, [comment] [varchar](max) NULL, [correcting_rightshaolder_invoice_id] [int] NULL, [GUID] [uniqueidentifier] NOT NULL, [LAST_UPDATE_DATE_TIME] [datetime2](7) NOT NULL, CONSTRAINT [PK_rightsholder_invoice] PRIMARY KEY CLUSTERED ( [rightsholder_invoice_id] ASC )WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY] ) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY] GO Initial table definition creation and initial loading of data is performed correctly. After performing simple update on multiple records at once exception occurs (mutiple records changed in single transaction are a must for this error to occur): UPDATE [zol].[dbo].[rightsholder_message] SET [message_content] = 'some_text'; (1252 rows affected) Error in changes replication: 2019-01-03 18:10:51,796 INFO [zapaonline-001] [DefaultDatabaseWriter] [zapaonline-001-dataloader-6] Failed to process update event in batch 000-32 on channel 'zol_to_zapaonline'. Failed sql was: update "public"."rightsholder_invoice" set "rightsholder_invoice_id" = 1, "rightsholder_invoice_datetime" = {ts '2012-12-05 12:24:17.433'}, "rightsholder_id" = 5982, "number" = '11/2012', "income_date" = '2012-11-16', "invoice_date" = '2012-11-09', "sale_date" = '2012-11-09', "rightsholder_invoice_type_id" = 1, "status_description" = 'Zaakceptowana', "comment" = 'wZjKbXąJŚźHyżtohmoĄei9ćTQpLłŻ7ŁNxDuęqFóg', "correcting_rightsholder_invoice_id" = null, "guid" = 'EE49EA84-105E-435B-9D79-06558EBEA744', "last_update_date_time" = {ts '2018-11-06 14:43:39.606'} where "rightsholder_invoice_id" = 4285 Failed raw sql was: update "public"."rightsholder_invoice" set "rightsholder_invoice_id" = ?, "rightsholder_invoice_datetime" = ?, "rightsholder_id" = ?, "number" = ?, "income_date" = ?, "invoice_date" = ?, "sale_date" = ?, "rightsholder_invoice_type_id" = ?, "status_description" = ?, "comment" = ?, "correcting_rightsholder_invoice_id" = ?, "guid" = ?, "last_update_date_time" = ? where "rightsholder_invoice_id" = ? Failed sql parameters: [1, {ts '2012-12-05 12:24:17.433'}, 5982, '11/2012', '2012-11-16', '2012-11-09', '2012-11-09', 1, 'Zaakceptowana', 'wZjKbXąJŚźHyżtohmoĄei9ćTQpLłŻ7ŁNxDuęqFóg', null, 'EE49EA84-105E-435B-9D79-06558EBEA744', {ts '2018-11-06 14:43:39.606'}, 4285] Failed sql parameters types: [INTEGER, TIMESTAMP, INTEGER, VARCHAR, VARCHAR, VARCHAR, VARCHAR, INTEGER, VARCHAR, LONGVARCHAR, INTEGER, CHAR, TIMESTAMP, INTEGER] Failed sql state and code: 23505 (0) Failed pk data was: "4285" Failed row data was: "1","2012-12-05 12:24:17.433","5982","11/2012","2012-11-16","2012-11-09","2012-11-09","1","Zaakceptowana","wZjKbXąJŚźHyżtohmoĄei9ćTQpLłŻ7ŁNxDuęqFóg",,"EE49EA84-105E-435B-9D79-06558EBEA744","2018-11-06 14:43:39.6066667" Failed old data was: "4285","2018-10-26 14:29:28.987","1469","12/2018","2018-10-26","2018-10-15","2018-10-15","1","Zaakceptowana",,,"0A16CC16-1216-4C59-A3EE-6521517E52F2","2018-11-06 14:43:39.6066667" StackTraceKey.init [UniqueKeyException:2026926579] org.jumpmind.db.sql.UniqueKeyException: org.postgresql.util.PSQLException: BŁĄD: podwójna wartość klucza narusza ograniczenie unikalności "rightsholder_invoice_pkey" Detail: Klucz (rightsholder_invoice_id)=(1) już istnieje. at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:296) at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291) at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:466) at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.execute(DefaultDatabaseWriter.java:904) at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.update(DefaultDatabaseWriter.java:488) at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:188) at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64) at org.jumpmind.symmetric.model.ProcessInfoDataWriter.write(ProcessInfoDataWriter.java:84) at org.jumpmind.symmetric.io.data.writer.NestedDataWriter.write(NestedDataWriter.java:64) at org.jumpmind.symmetric.io.data.writer.TransformWriter.write(TransformWriter.java:201) at org.jumpmind.symmetric.io.data.DataProcessor.forEachDataInTable(DataProcessor.java:210) at org.jumpmind.symmetric.io.data.DataProcessor.forEachTableInBatch(DataProcessor.java:177) at org.jumpmind.symmetric.io.data.DataProcessor.process(DataProcessor.java:123) at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1039) at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$2.call(DataLoaderService.java:1016) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: org.postgresql.util.PSQLException: BŁĄD: podwójna wartość klucza narusza ograniczenie unikalności "rightsholder_invoice_pkey" Detail: Klucz (rightsholder_invoice_id)=(1) już istnieje. at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2422) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2167) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365) at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155) at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:132) at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105) at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105) at org.jumpmind.db.sql.JdbcSqlTransaction.executePreparedUpdate(JdbcSqlTransaction.java:485) at org.jumpmind.db.sql.JdbcSqlTransaction.addRow(JdbcSqlTransaction.java:463) ... 16 more Full log attached. The problem is due to the error on ordering changes while inserting them into [sym_data] mssql table in [SYM_ON_U_FOR_RGHTSHLDR_NVC_ZL] trigger (after update trigger on [dbo].[rightsholder_invoice] table). The pk_data and respecting row_data in [sym_data] are inserted in REVERSE order - please see attached screenshot. | ||||
Tags | dialect: sql-server, trigger | ||||
|
|
|
You have the sym_trigger.use_handle_key_updates=1, is that correct? I believe that causes the trigger to be generated with logic that is vulnerable to mis-ordering. Here's why. SQL-Server provides two virtual tables to the trigger: "inserted" is the new rows and "deleted" is the old rows. The trigger needs to join those two virtual tables, and it normally joins on the primary key columns. But when you enable handling of primary key updates, it can no longer join on the PK because the new and old values are different. So it assumes row 1 of "inserted" will match row 1 of "deleted", and so on. It used to open a cursor to loop through the rows, but it was changed to join the tables using row_number(), because cursors have a performance penalty. The change in technique was supposed to be equivalent logic. In reality, there is no guarantee from SQL-Server that there is any kind of order on the virtual tables. Does your test fail every time you run it on 3.9, or just sometimes? Does your test work every time on 3.8, or just sometimes? |
|
Hi, and thanks for reply. The sym_trigger.use_handle_key_updates setting was not changed by me, and I believe it is still at default (0) value. Also, this test always fails on 3.9, and always works on 3.8 . I`m attaching two database triggers versions for further investigation (generated from 3.8 and 3.9 versions). If You'll look at this fragment - this is the difference which probably causes the error: 3.8: ... from inserted inner join "zol"."dbo"."rightsholder_invoice" orig on orig."rightsholder_invoice_id"=inserted."rightsholder_invoice_id" inner join deleted on deleted."rightsholder_invoice_id"=inserted."rightsholder_invoice_id" 3.9: ... from (select "rightsholder_invoice_id","rightsholder_invoice_datetime","rightsholder_id","number","income_date","invoice_date","sale_date","rightsholder_invoice_type_id","status_description","comment","correcting_rightsholder_invoice_id","GUID","LAST_UPDATE_DATE_TIME", row_number() over (order by (select 1)) as __row_num from inserted) inserted inner join "zol"."dbo"."rightsholder_invoice" orig on orig."rightsholder_invoice_id"=inserted."rightsholder_invoice_id" inner join (select "rightsholder_invoice_id","rightsholder_invoice_datetime","rightsholder_id","number","income_date","invoice_date","sale_date","rightsholder_invoice_type_id","status_description","comment","correcting_rightsholder_invoice_id","GUID","LAST_UPDATE_DATE_TIME", row_number() over (order by (select 1)) as __row_num from deleted)deleted on (inserted.__row_num = deleted.__row_num) PS.: The query used to update multiple rows in my previous post should be: UPDATE [zol].[dbo].[rightsholder_invoice] SET [comment] = 'some_text'; |
|
Oh, I`ve just checked that the default value for sym_trigger.use_handle_key_updates changed between versions: In 3.9: https://www.jumpmind.com/downloads/symmetricds/doc/3.9/html/user-guide.html USE_HANDLE_KEY_UPDATES = default 1 In 3.8: https://www.jumpmind.com/downloads/symmetricds/doc/3.8/html/user-guide.html USE_HANDLE_KEY_UPDATES = default 0 Well, that was unexpected, although mentioned in changelog for 3.9: 0003053: [Improvement] Default handle_key_updates in sym_trigger to 1 (chenson) However, error probably still remains in SQL server for this case - as I didn't change PK value, only 'comment' column value on multiple rows at once. |
|
This situation was improved in issue 0005157 for SymmetricDS 3.14, where it only uses the "handle key updates" logic when the primary key values are actually changing. |
Date Modified | Username | Field | Change |
---|---|---|---|
2019-01-03 17:30 | lukasz.krawczyk | New Issue | |
2019-01-03 17:30 | lukasz.krawczyk | File Added: symmetric.log | |
2019-01-03 17:30 | lukasz.krawczyk | File Added: 2019-01-03 18_27_34-SQLQuery6.sql - localhost.zol (sa (57)) - Microsoft SQL Server Management Studio.png | |
2019-01-14 15:08 | elong | Note Added: 0001378 | |
2019-01-14 23:11 | lukasz.krawczyk | File Added: 3.8_new.sql | |
2019-01-14 23:11 | lukasz.krawczyk | File Added: 3.9_new.sql | |
2019-01-14 23:11 | lukasz.krawczyk | Note Added: 0001381 | |
2019-01-14 23:23 | lukasz.krawczyk | Note Added: 0001382 | |
2019-04-25 18:47 | elong | Tag Attached: dialect: sql-server | |
2019-04-25 18:47 | elong | Tag Attached: trigger | |
2022-09-19 18:40 | elong | Note Added: 0002200 | |
2022-09-19 18:41 | elong | Assigned To | => pmarzullo |
2022-09-19 18:41 | elong | Status | new => closed |
2022-09-19 18:41 | elong | Resolution | open => fixed |
2022-09-19 18:41 | elong | Fixed in Version | => 3.14.2 |
2022-09-19 18:41 | elong | Target Version | => 3.14.2 |
2022-09-19 18:41 | elong | Description Updated | View Revisions |