Re-registration of a disabled node causes foreign key violation

[krivoz]

Hi!

I'm using SymmetricClient in embedded mode, with embedded Derby database. Synchronization is mosty working, but I have trouble when client nodes come online after the given 'offline.node.detection.period.minutes'.
The server is disabling the sync on nodes when 'offline.node.detection.period.minutes' expires, which is just perfect.
On clients DefaultOfflineClientListener deletes NODE_IDENTITY in order to induce re-registration, which is also perfect.
But when the DataLoaderService is loading the virtual batch 9999, deleting from SYM_NODE causing violation of foreign key constraint 'SYM_FK_SEC_2_NODE'.
I've found out the possible cause of it, i.e. why deleting from SYM_NODE_SECURITY is not done beforehand. Symmetric is using the following SQL for that:
delete from sym_node_security where created_at_node_id='server',
while in the database the CREATED_AT_NODE_ID contains the client node id, not the server node id. It's a bit strange, as the column with the same name in SYM_NODE table contains server node id!
Why is it so? What can I do to make the re-registration of clients work?
Thanks!

The logs:

2017-05-24 08:25:01,448 ERROR org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter:547 - Failed to run the following sql: delete from sym_node where created_at_node_id='server'
2017-05-24 08:25:01,510 ERROR org.jumpmind.symmetric.service.impl.DataLoaderService$ManageIncomingBatchListener:1146 - Failed to load batch server--9999
org.jumpmind.db.sql.SqlException: DELETE on table 'SYM_NODE' caused a violation of foreign key constraint 'SYM_FK_SEC_2_NODE' for key (my-client-id). The statement has been rolled back.
at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:300)
at org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291)
at org.jumpmind.db.sql.JdbcSqlTransaction.executeCallback(JdbcSqlTransaction.java:406)
at org.jumpmind.db.sql.JdbcSqlTransaction.prepareAndExecute(JdbcSqlTransaction.java:372)
at org.jumpmind.symmetric.io.data.writer.DefaultDatabaseWriter.sql(DefaultDatabaseWriter.java:542)
at org.jumpmind.symmetric.io.data.writer.AbstractDatabaseWriter.write(AbstractDatabaseWriter.java:168)
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:975)
at org.jumpmind.symmetric.service.impl.DataLoaderService$LoadIntoDatabaseOnArrivalListener$1.call(DataLoaderService.java:950)
at java.util.concurrent.FutureTask.run(FutureTask.java:274)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1157)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:627)
at java.lang.Thread.run(Thread.java:809)
Caused by: java.sql.SQLIntegrityConstraintViolationException: DELETE on table 'SYM_NODE' caused a violation of foreign key constraint 'SYM_FK_SEC_2_NODE' for key (my-client-id). The statement has been rolled back.
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.execute(Unknown Source)
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172)
at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172)
at org.jumpmind.db.sql.JdbcSqlTransaction$6.execute(JdbcSqlTransaction.java:382)
at org.jumpmind.db.sql.JdbcSqlTransaction$6.execute(JdbcSqlTransaction.java:372)
at org.jumpmind.db.sql.JdbcSqlTransaction.executeCallback(JdbcSqlTransaction.java:404)
... 16 more
Caused by: java.sql.SQLException: DELETE on table 'SYM_NODE' caused a violation of foreign key constraint 'SYM_FK_SEC_2_NODE' for key (my-client-id). The statement has been rolled back.
at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source)
... 30 more
Caused by: ERROR 23503: DELETE on table 'SYM_NODE' caused a violation of foreign key constraint 'SYM_FK_SEC_2_NODE' for key (my-client-id). The statement has been rolled back.
at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
at org.apache.derby.impl.sql.execute.ReferencedKeyRIChecker.doCheck(Unknown Source)
at org.apache.derby.impl.sql.execute.RISetChecker.doPKCheck(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.collectAffectedRows(Unknown Source)
at org.apache.derby.impl.sql.execute.DeleteResultSet.open(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
... 24 more

[Chris Henson]

What version of SymmetricDS are you using? What is the state of sym_node and sym_node_security at both the server and the client before re-registration is attempted?

[krivoz]

I'm currently using 3.8.14, but tried also with 3.8.24 with the same results.
The status before attempting the re-registration is the following:
On the server:
the sym_node_security row is deleted when the sync on node is being disabled.
the sym_node:

NODE_ID        NODE_GROUP_ID      EXTERNAL_ID       SYNC_ENABLED  SYNC_URL                                            SCHEMA_VERSION       SYMMETRIC_VERSION       DATABASE_TYPE     DATABASE_VERSION       HEARTBEAT_TIME              TIMEZONE_OFFSET  BATCH_TO_SEND_COUNT  BATCH_IN_ERROR_COUNT  CREATED_AT_NODE_ID      DEPLOYMENT_TYPE    CONFIG_VERSION
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
my-client      clients            my-client         0             http://my-client:31415/sync/client-engine           ?                    3.8.14                  Apache Derby      10.10                  2017-05-31 14:36:40.768     +02:00           -1                   -1                    sntserver               client             <null>        

On the client:
* the sym_node_security:

NODE_ID      NODE_PASSWORD                       REGISTRATION_ENABLED  REGISTRATION_TIME              INITIAL_LOAD_ENABLED  INITIAL_LOAD_TIME              INITIAL_LOAD_ID       INITIAL_LOAD_CREATE_BY     REV_INITIAL_LOAD_ENABLED  REV_INITIAL_LOAD_TIME          REV_INITIAL_LOAD_ID   REV_INITIAL_LOAD_CREATE_BY         CREATED_AT_NODE_ID      
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
my-client    ae7c4c719821bb3bf52375a25c3b2d      0                     2017-05-31 13:57:15.348        0                     2017-05-31 13:57:24.849        24                    registration               0                         <null>                         0                     <null>                             my-client               

• the sym_node:

NODE_ID        NODE_GROUP_ID      EXTERNAL_ID       SYNC_ENABLED  SYNC_URL                                            SCHEMA_VERSION       SYMMETRIC_VERSION       DATABASE_TYPE     DATABASE_VERSION       HEARTBEAT_TIME              TIMEZONE_OFFSET  BATCH_TO_SEND_COUNT  BATCH_IN_ERROR_COUNT  CREATED_AT_NODE_ID      DEPLOYMENT_TYPE      
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
my-client      clients            my-client         1             http://my-client:31415/sync/client-engine           ?                    3.8.14                  Apache Derby      10.10                  2017-05-31 13:57:13.445     +02:00           -1                   -1                    sntserver               client               

[Klementina Chirico]

We just added a fix to this bug, it will come out in our next release, 3.8.26.

[krivoz]

Thank you Klementina. May I know the issue number? I'm just curious about the solution :).

[Klementina Chirico]

Here is the URL to the issue: https://www.symmetricds.org/issues/view.php?id=3154