View Issue Details

IDProjectCategoryView StatusLast Update
0004124SymmetricDSBugpublic2022-08-01 19:32
Reportermkurz Assigned Toelong  
Prioritynormal 
Status closedResolutionno change required 
Product Version3.9.20 
Summary0004124: sym_registration_request -> duplicate key
DescriptionWe 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 ReproduceThe 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 Informationfull 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)
TagsNo tags attached.

Activities

mkurz

2019-11-04 12:27

reporter   ~0001627

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.

elong

2021-07-28 17:47

developer   ~0001969

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.

elong

2022-08-01 19:32

developer   ~0002129

Closing due to lack of interest.

Issue History

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