View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0005617 | SymmetricDS | Bug | public | 2022-12-05 21:33 | 2023-09-13 17:25 |
| Reporter | jkeyne | Assigned To | |||
| Priority | normal | ||||
| Status | closed | Resolution | open | ||
| Product Version | 3.14.3 | ||||
| Summary | 0005617: When upgrading to 3.14.3 from an 3.9, "sym_data_event" can have duplicate entries that prevent migration | ||||
| Description | When upgrading to 3.14.3 from 3.9.4, I noticed that some of my servers were failing to start because there was duplicate data in the "sym_data_event" table. Manually deleting the extra entries in the database (in my case a postgresql database) and restarting symmetricds seemed to fix the issue. This is the SQL I had to run to get it working again: ```sql DELETE FROM sym_data_event WHERE data_id IN (SELECT data_id FROM (SELECT data_id, ROW_NUMBER() OVER( PARTITION BY batch_id ORDER BY data_id ) AS row_num FROM sym_data_event ) x WHERE x.row_num > 1 ); ``` | ||||
| Steps To Reproduce | 1. Deploy a setup of symmetricds 3.9.4 with a postgresql database 2. Generate duplicate data in the "sym_data_event" table (3.9.4 symmetricds should still be working with that duplicated data) 3. Try to upgrade symmetricds to 3.14.3 | ||||
| Additional Information | Not too sure if it's relevant but this came up while I was testing a cluster of 27 servers split into 3 groups of 1 master, 2 replica servers, and 6 load only servers | ||||
| Tags | upgrade | ||||
|
|
symmetricds_log.txt (8,848 bytes)
2022-12-02 11:50:53 (UTC-0700),663 INFO [eng-m-site1] [AbstractSymmetricEngine] [symmetric-engine-startup-1]
2022-12-05 12:08:51 (UTC-0700),187 INFO [] [AbstractSymmetricEngine] [Thread-9] Stopping SymmetricDS externalId=m-site1 version=3.14.2 database=PostgreSQL
2022-12-05 12:10:10 (UTC-0700),297 INFO [startup] [AbstractCommandLauncher] [main] Option: name=secure-port, value={8080}
2022-12-05 12:10:10 (UTC-0700),303 INFO [startup] [AbstractCommandLauncher] [main] Option: name=secure-server, value={}
2022-12-05 12:10:10 (UTC-0700),593 INFO [startup] [SymmetricUtils] [main]
_____ __ _ ____ _____
/ ___/ __ _____ __ ___ __ ___ _/ /_ ____(_)___ / __ | / ___/
\__ \ / / / / _ `_ \/ _ `_ \/ _ \/_ __// __/ / __/ / / / / \__ \
___/ // /_/ / // // / // // / __// / / / / / /_ / /_/ / ___/ /
/____/ \__ /_//_//_/_//_//_/\___/ \_/ /_/ /_/\__/ /_____/ /____/
/____/
+-----------------------------------------------------------------+
| Copyright (C) 2007-2022 JumpMind, Inc. |
| |
| Licensed under the GNU General Public License version 3. |
| This software comes with ABSOLUTELY NO WARRANTY. |
| See http://www.gnu.org/licenses/gpl.html |
+-----------------------------------------------------------------+
2022-12-05 12:10:10 (UTC-0700),701 INFO [startup] [SymmetricWebServer] [main] About to start SymmetricDS web server on 0.0.0.0:8080:HTTPS/1.1
2022-12-05 12:10:11 (UTC-0700),082 INFO [startup] [SymmetricEngineHolder] [main] Current directory is /opt/symdb
2022-12-05 12:10:11 (UTC-0700),082 INFO [startup] [SymmetricEngineHolder] [main] Starting in single-server mode
2022-12-05 12:10:11 (UTC-0700),180 INFO [eng-m-site1] [ClientSymmetricEngine] [symmetric-engine-startup-1] Initializing connection to database
2022-12-05 12:10:11 (UTC-0700),905 INFO [eng-m-site1] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] Detected database 'postgres95', version '10', protocol 'postgresql'
2022-12-05 12:10:11 (UTC-0700),927 INFO [eng-m-site1] [JdbcDatabasePlatformFactory] [symmetric-engine-startup-1] The IDatabasePlatform being used is org.jumpmind.db.platform.postgresql.PostgreSql95DatabasePlatform
2022-12-05 12:10:12 (UTC-0700),138 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] The DbDialect being used is org.jumpmind.symmetric.db.postgresql.PostgreSqlSymmetricDialect
2022-12-05 12:10:12 (UTC-0700),211 INFO [eng-m-site1] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered
2022-12-05 12:10:12 (UTC-0700),227 INFO [eng-m-site1] [StagingManager] [symmetric-engine-startup-1] The staging directory was initialized at the following location: /opt/symdb/tmp/eng-m-site1
2022-12-05 12:10:12 (UTC-0700),791 INFO [startup] [SymmetricWebServer] [main] Joining the web server main thread
2022-12-05 12:10:13 (UTC-0700),019 INFO [eng-m-site1] [ExtensionService] [symmetric-engine-startup-1] Found 0 extension points from the database that will be registered
2022-12-05 12:10:13 (UTC-0700),019 INFO [eng-m-site1] [ClientExtensionService] [symmetric-engine-startup-1] Found 7 extension points from spring that will be registered
2022-12-05 12:10:13 (UTC-0700),032 INFO [eng-m-site1] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Initializing SymmetricDS database
2022-12-05 12:10:13 (UTC-0700),052 INFO [eng-m-site1] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Checking tables and objects
2022-12-05 12:10:13 (UTC-0700),102 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] Checking if SymmetricDS tables need created or altered
2022-12-05 12:10:14 (UTC-0700),892 INFO [eng-m-site1] [DatabaseUpgradeListener] [symmetric-engine-startup-1] Detected upgrade from pre-3.12 version.
2022-12-05 12:10:14 (UTC-0700),892 INFO [eng-m-site1] [DatabaseUpgradeListener] [symmetric-engine-startup-1] Before upgrade, fixing router_type
2022-12-05 12:10:14 (UTC-0700),895 INFO [eng-m-site1] [DatabaseUpgradeListener] [symmetric-engine-startup-1] Detected upgrade from pre-3.12.5 version.
2022-12-05 12:10:14 (UTC-0700),895 INFO [eng-m-site1] [DatabaseUpgradeListener] [symmetric-engine-startup-1] Detected upgrade from pre-3.14 version.
2022-12-05 12:10:14 (UTC-0700),929 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] Dropping SYM_ON_I_FOR_SYM_JB_GMST1 trigger for sym_job
2022-12-05 12:10:15 (UTC-0700),065 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] Dropping SYM_ON_D_FOR_SYM_JB_GMST1 trigger for sym_job
2022-12-05 12:10:15 (UTC-0700),080 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] Dropping SYM_ON_U_FOR_SYM_JB_GMST1 trigger for sym_job
2022-12-05 12:10:16 (UTC-0700),834 INFO [eng-m-site1] [PostgreSqlSymmetricDialect] [symmetric-engine-startup-1] There are SymmetricDS tables that needed altered
2022-12-05 12:10:17 (UTC-0700),807 WARN [eng-m-site1] [LogSqlResultsListener] [symmetric-engine-startup-1] DDL failed: ALTER TABLE "sym_data_event"
ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id")
2022-12-05 12:10:17 (UTC-0700),808 WARN [eng-m-site1] [JdbcSqlTemplate] [symmetric-engine-startup-1] ERROR: could not create unique index "sym_data_event_PK"
Detail: Key (data_id, batch_id)=(39135943, 90063) is duplicated.. Failed to execute: ALTER TABLE "sym_data_event"
ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id")
2022-12-05 12:10:17 (UTC-0700),808 ERROR [eng-m-site1] [AbstractSymmetricEngine] [symmetric-engine-startup-1] An error occurred while starting SymmetricDS StackTraceKey.init [UniqueKeyException:3293746136] org.jumpmind.db.sql.UniqueKeyException: org.postgresql.util.PSQLException: ERROR: could not create unique index "sym_data_event_PK"
Detail: Key (data_id, batch_id)=(39135943, 90063) is duplicated.
at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:302)
at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:297)
at org.jumpmind.db.sql.JdbcSqlTemplate.execute(JdbcSqlTemplate.java:494)
at org.jumpmind.db.sql.JdbcSqlTemplate.update(JdbcSqlTemplate.java:405)
at org.jumpmind.db.sql.SqlScript.execute(SqlScript.java:108)
at org.jumpmind.symmetric.db.AbstractSymmetricDialect.createOrAlterTablesIfNecessary(AbstractSymmetricDialect.java:521)
at org.jumpmind.symmetric.db.AbstractSymmetricDialect.initTablesAndDatabaseObjects(AbstractSymmetricDialect.java:181)
at org.jumpmind.symmetric.AbstractSymmetricEngine.setupDatabase(AbstractSymmetricEngine.java:454)
at org.jumpmind.symmetric.AbstractSymmetricEngine.setup(AbstractSymmetricEngine.java:427)
at org.jumpmind.symmetric.AbstractSymmetricEngine.start(AbstractSymmetricEngine.java:612)
at org.jumpmind.symmetric.AbstractSymmetricEngine.start(AbstractSymmetricEngine.java:600)
at org.jumpmind.symmetric.ClientSymmetricEngine.start(ClientSymmetricEngine.java:259)
at org.jumpmind.symmetric.web.SymmetricEngineStarter.run(SymmetricEngineStarter.java:42)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.postgresql.util.PSQLException: ERROR: could not create unique index "sym_data_event_PK"
Detail: Key (data_id, batch_id)=(39135943, 90063) is duplicated.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:333)
at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:319)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:295)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:290)
at org.apache.commons.dbcp2.DelegatingStatement.execute(DelegatingStatement.java:193)
at org.apache.commons.dbcp2.DelegatingStatement.execute(DelegatingStatement.java:193)
at org.jumpmind.db.sql.JdbcSqlTemplate$6.execute(JdbcSqlTemplate.java:420)
at org.jumpmind.db.sql.JdbcSqlTemplate$6.execute(JdbcSqlTemplate.java:405)
at org.jumpmind.db.sql.JdbcSqlTemplate.execute(JdbcSqlTemplate.java:492)
... 13 more
2022-12-05 12:10:17 (UTC-0700),813 INFO [eng-m-site1] [AbstractSymmetricEngine] [symmetric-engine-startup-1] Stopping SymmetricDS externalId=m-site1 version=3.14.3 database=PostgreSQL
|
|
|
You can work around this issue by adding the following line to the engine file of the node being upgraded before you run the upgrade: upgrade.force.fix.data.event=true SymmetricDS uses the following query to detect whether it needs to fix sym_data_event: select t.trigger_id, r.target_node_group_id from sym_trigger t inner join sym_trigger_router tr on tr.trigger_id = t.trigger_id inner join sym_router r on r.router_id = tr.router_id where r.source_node_group_id = ? If it sees the same trigger ID and target node group twice, then it knows it needs to fix sym_data_event. Now that you know how it works, do you have any idea why SymmetricDS did not detect that it needed to fix sym_data_event? |
|
|
I ran that query on one of the servers, and I noticed that it didn't return any duplicated rows. I did happen to notice that before trying to upgrade the sym_data_event table had a constraint of `"sym_data_event_pkey" PRIMARY KEY, btree (data_id, batch_id, router_id)` already. Removing the router_id from the constraint seems to be what's causing the issue, do you happen to know why that was removed? psql# ALTER TABLE "sym_data_event" ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id"); ERROR: could not create unique index "sym_data_event_PK" DETAIL: Key (data_id, batch_id)=(51266233, 53284) is duplicated. psql# ALTER TABLE "sym_data_event" ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id", "router_id"); ALTER TABLE Also looking at the sql query for fixing the data event table, it's not selecting the rows that postgres is complaining about. So, I doubt that config change would fix the issue: psql# select batch_id, data_id, max(router_id) router_id from sym_data_event group by batch_id, data_id having count(*) > 1; batch_id | data_id | router_id ----------+----------+-------------------------- 53793 | 53192839 | sym_nd_hst_gmst2_2_gsst2 53793 | 53192843 | sym_nd_hst_gmst2_2_gsst2 53797 | 53195491 | sym_nd_hst_gmst2_2_gsst2 53793 | 53192844 | sym_nd_hst_gmst2_2_gsst2 53808 | 53208731 | sym_nd_hst_gmst2_2_gsst2 (5 rows) |
|
|
I turned on debug logging on the server after updating, and it looks like it's trying to remove the router_id column entirely. Is that supposed to be happening and if so, then at that step it should probably just remove the duplicated data_id and batch_id events that had different router_id values 2022-12-07 23:05:42,001 INFO [eng-m-site2] [LogSqlResultsListener] [symmetric-engine-startup-1] DDL applied: ALTER TABLE "public"."sym_data_event" DROP COLUMN "router_id" 2022-12-07 23:05:42,005 WARN [eng-m-site2] [LogSqlResultsListener] [symmetric-engine-startup-1] DDL failed: ALTER TABLE "sym_data_event" ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id") 2022-12-07 23:05:42,006 WARN [eng-m-site2] [JdbcSqlTemplate] [symmetric-engine-startup-1] ERROR: could not create unique index "sym_data_event_PK" Detail: Key (data_id, batch_id)=(53192839, 53793) is duplicated.. Failed to execute: ALTER TABLE "sym_data_event" ADD CONSTRAINT "sym_data_event_PK" PRIMARY KEY ("data_id", "batch_id") 2022-12-07 23:05:42,007 ERROR [eng-m-site2] [AbstractSymmetricEngine] [symmetric-engine-startup-1] An error occurred while starting SymmetricDS StackTraceKey.init [UniqueKeyException:3877026687] org.jumpmind.db.sql.UniqueKeyException: o rg.postgresql.util.PSQLException: ERROR: could not create unique index "sym_data_event_PK" Detail: Key (data_id, batch_id)=(53192839, 53793) is duplicated. at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:302) at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:297) at org.jumpmind.db.sql.JdbcSqlTemplate.execute(JdbcSqlTemplate.java:494) at org.jumpmind.db.sql.JdbcSqlTemplate.update(JdbcSqlTemplate.java:405) |
|
|
Looks like it was intentional to drop router_id: https://github.com/JumpMind/symmetric-ds/commit/0ec1d75612688005c52e356d6f5758b4488e6772 Maybe there needs to be a new database upgrade check added to force clean up after dropping router_id from sym_data_event |
|
|
Also, took a little while till I could test it, but I can confirm that setting "upgrade.force.fix.data.event=true" does fix the issue |
|
|
Can you export your sym_trigger and sym_trigger_router tables and send them as an attachment? |
|
|
@emiller, I can certainly do that, but I’m on vacation currently, so I’ll get that for you next week |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2022-12-05 21:33 | jkeyne | New Issue | |
| 2022-12-05 21:33 | jkeyne | Tag Attached: upgrade | |
| 2022-12-05 21:33 | jkeyne | File Added: symmetricds_log.txt | |
| 2022-12-07 18:25 | emiller | Note Added: 0002230 | |
| 2022-12-07 18:26 | emiller | Note Edited: 0002230 | View Revisions |
| 2022-12-07 22:43 | jkeyne | Note Added: 0002233 | |
| 2022-12-07 23:10 | jkeyne | Note Added: 0002234 | |
| 2022-12-08 16:45 | jkeyne | Note Added: 0002235 | |
| 2022-12-08 22:08 | jkeyne | Note Added: 0002238 | |
| 2022-12-28 18:16 | emiller | Note Added: 0002248 | |
| 2022-12-28 18:16 | emiller | Status | new => feedback |
| 2022-12-28 19:00 | jkeyne | Note Added: 0002249 | |
| 2022-12-28 19:00 | jkeyne | Status | feedback => new |
| 2023-01-06 17:07 | elong | Status | new => feedback |
| 2023-09-13 17:25 | emiller | Status | feedback => closed |