View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0004124 | SymmetricDS | Bug | public | 2019-10-28 13:41 | 2022-08-01 19:32 |
Reporter | mkurz | Assigned To | elong | ||
Priority | normal | ||||
Status | closed | Resolution | no change required | ||
Product Version | 3.9.20 | ||||
Summary | 0004124: sym_registration_request -> duplicate key | ||||
Description | We observe 1-70 cases of the following exception every day for sql server db's with up to 350 nodes: org.jumpmind.db.sql.UniqueKeyException: com.microsoft.sqlserver.jdbc.SQLServerException: Violation of PRIMARY KEY constraint 'PK__sym_regi__89EADC886767D057'. Cannot insert duplicate key in object 'dbo.sym_registration_request'. The duplicate key value is (mobil, clientxy, 2019-10-28 12:55:01.5670000).: Error while processing GET request for node: 222 at 127.0.0.1 with path: /central-0/pull That's strange, because the create_time of sym_registration_request is part of the PK. It stands out that it seems to be always(?) with the ip 127.0.0.1. We observe this on different central machines. | ||||
Steps To Reproduce | The only way we could reproduce this was doing 2 inserts into 1 transaction: BEGIN TRANSACTION INSERT INTO sym_registration_request (node_group_id, external_id, status, create_time, last_update_time, host_name, ip_address) VALUES ( 'mobil', 'x', 'OK', CURRENT_TIMESTAMP, CURRENT_TIMESTAMP, 'h', '127.0') INSERT INTO sym_registration_request (node_group_id, external_id, status, create_time, last_update_time, host_name, ip_address) VALUES ( 'mobil', 'x', 'OK', CURRENT_TIMESTAMP, CURRENT_TIMESTAMP, 'h', '127.0') COMMIT But that isn't the case in the symmetricds code. | ||||
Additional Information | full stack trace: org.jumpmind.db.sql.UniqueKeyException: com.microsoft.sqlserver.jdbc.SQLServerException: Violation of PRIMARY KEY constraint 'PK__sym_regi__89EADC886767D057'. Cannot insert duplicate key in object 'dbo.sym_registration_request'. The duplicate key value is (mobil, clientxy, 2019-10-28 12:55:01.5670000).: Error while processing GET request for node: 222 at 127.0.0.1 with path: /central-0/pull org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:296) org.jumpmind.db.sql.AbstractSqlTemplate.translate(AbstractSqlTemplate.java:291) org.jumpmind.db.sql.JdbcSqlTemplate.execute(JdbcSqlTemplate.java:503) org.jumpmind.db.sql.JdbcSqlTemplate.update(JdbcSqlTemplate.java:342) org.jumpmind.symmetric.service.impl.RegistrationService.saveRegistrationRequest(RegistrationService.java:371) org.jumpmind.symmetric.service.impl.RegistrationService.processRegistration(RegistrationService.java:272) org.jumpmind.symmetric.service.impl.RegistrationService.registerNode(RegistrationService.java:295) org.jumpmind.symmetric.web.PullUriHandler.handlePull(PullUriHandler.java:120) org.jumpmind.symmetric.web.PullUriHandler.handleWithCompression(PullUriHandler.java:100) org.jumpmind.symmetric.web.AbstractCompressionUriHandler.handle(AbstractCompressionUriHandler.java:84) org.jumpmind.symmetric.web.SymmetricServlet.service(SymmetricServlet.java:114) javax.servlet.http.HttpServlet.service(HttpServlet.java:790) org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:864) org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655) org.jumpmind.symmetric.web.LogRequestResponseFilter.doFilter(LogRequestResponseFilter.java:53) org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634) org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:215) org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) org.jumpmind.symmetric.web.HttpMethodFilter.doFilter(HttpMethodFilter.java:62) org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) org.eclipse.jetty.server.Server.handle(Server.java:531) org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:319) org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:175) org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:133) org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:754) org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:672) java.lang.Thread.run(Thread.java:748) | ||||
Tags | No tags attached. | ||||
|
I could reproduce this by doing: update sym_node_security set registration_enabled=1 where node_id=1 Then PullUriHandler.java -> registrationService.registerNode(... is executed by the next requests, which causes the Exceptions in this case. This could be fixed by a synchronized named mutex in RegistrationService . See. Pull request https://github.com/JumpMind/symmetric-ds/pull/107 I our case this is caused by nodes which were set as offline nodes by a custom implementation of IOfflineServerListener, when the nodes come online again. |
|
The problem is all the clients' IP addresses are all 127.0.0.1. That is why it violates the primary key. You can set -Dip.address=something-unique system property. I've never seen this problem on a production deployment. |
|
Closing due to lack of interest. |
Date Modified | Username | Field | Change |
---|---|---|---|
2019-10-28 13:41 | mkurz | New Issue | |
2019-11-04 12:27 | mkurz | Note Added: 0001627 | |
2021-07-28 17:47 | elong | Note Added: 0001969 | |
2021-07-28 17:47 | elong | Assigned To | => elong |
2021-07-28 17:47 | elong | Status | new => feedback |
2022-08-01 19:32 | elong | Status | feedback => closed |
2022-08-01 19:32 | elong | Resolution | open => no change required |
2022-08-01 19:32 | elong | Note Added: 0002129 |