Re: TransactionManager ERROR There are now active transactions

Thu, 02 Aug 2018 02:56:59 -0700 

Fuseki configuration?

The stacktrace isn't GSP.

>>> I'm not able to produce a sendable script that
>>> would case these errors.

It (still) looks like there is an environment factor.

    Andy


On 02/08/18 10:41, Mikael Pesonen wrote:


3.7.0.

On 2.8.2018 12:40, Andy Seaborne wrote:

version?

On 02/08/18 10:06, Mikael Pesonen wrote:
It does happen in our test environment on high load quite often. More sleep I put in the test script, less frequently error happens.
Most of the time transactions are executed after the error, but not always. Fuseki never returns error. Rarely below error happens, don't know if it's related. 

I'm not able to produce a sendable script that would case these errors.
So as a fix I'm planning just to add enough sleep between every Fuseki call. 50-100ms seems to work.
org.apache.jena.query.QueryException: Secondary index duplicate: GSPO->GPOS -> [[0000000000A9D430], [0000000015AFB422], [0000000000002602], [04007E280A6A5DC0]]
         at org.apache.jena.sparql.lang.ParserARQUpdate._parse(ParserARQUpdate.java:78)          at org.apache.jena.sparql.lang.ParserARQUpdate.parse$(ParserARQUpdate.java:45)          at org.apache.jena.sparql.lang.UpdateParser.parse(UpdateParser.java:48)          at org.apache.jena.update.UpdateAction.parseExecute(UpdateAction.java:421)          at org.apache.jena.update.UpdateAction.parseExecute(UpdateAction.java:380)          at org.apache.jena.fuseki.servlets.SPARQL_Update.execute(SPARQL_Update.java:234)          at org.apache.jena.fuseki.servlets.SPARQL_Update.executeBody(SPARQL_Update.java:189)          at org.apache.jena.fuseki.servlets.SPARQL_Update.perform(SPARQL_Update.java:106)          at org.apache.jena.fuseki.servlets.ActionService.executeLifecycle(ActionService.java:192)          at org.apache.jena.fuseki.servlets.ActionService.execCommonWorker(ActionService.java:106)          at org.apache.jena.fuseki.servlets.ActionBase.doCommon(ActionBase.java:73)          at org.apache.jena.fuseki.servlets.FusekiFilter.doFilter(FusekiFilter.java:73)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)          at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)          at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)          at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)          at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)          at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)          at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)          at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)          at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)          at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)          at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)          at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)          at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)          at org.apache.jena.fuseki.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:285)          at org.apache.jena.fuseki.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:248)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1629)          at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)          at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)          at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190)          at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)          at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)          at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)          at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)          at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)          at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)          at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)          at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)          at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:455)          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) 
         at org.eclipse.jetty.server.Server.handle(Server.java:561)
         at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:334)          at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)          at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)          at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:104)          at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)          at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:243)          at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:679)          at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:597) 
         at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.jena.tdb.TDBException: Secondary index duplicate: GSPO->GPOS -> [[0000000000A9D430], [0000000015AFB422], [0000000000002602], [04007E280A6A5DC0]]          at org.apache.jena.tdb.store.tupletable.TupleTable.add(TupleTable.java:103)          at org.apache.jena.tdb.store.nodetupletable.NodeTupleTableConcrete.addRow(NodeTupleTableConcrete.java:88) 
         at org.apache.jena.tdb.store.QuadTable.add(QuadTable.java:60)
         at org.apache.jena.tdb.store.DatasetGraphTDB.addToNamedGraph(DatasetGraphTDB.java:97)          at org.apache.jena.sparql.core.DatasetGraphTriplesQuads.add(DatasetGraphTriplesQuads.java:44)          at org.apache.jena.sparql.core.DatasetGraphTriplesQuads.add(DatasetGraphTriplesQuads.java:31)          at org.apache.jena.sparql.core.DatasetGraphWrapper.add(DatasetGraphWrapper.java:116)          at org.apache.jena.sparql.modify.UpdateEngineWorker.addToDatasetGraph(UpdateEngineWorker.java:539)          at org.apache.jena.sparql.modify.UpdateEngineWorker.lambda$execInsert$4(UpdateEngineWorker.java:532) 
         at java.util.Iterator.forEachRemaining(Iterator.java:116)
         at org.apache.jena.sparql.modify.UpdateEngineWorker.execInsert(UpdateEngineWorker.java:532)          at org.apache.jena.sparql.modify.UpdateEngineWorker.execInsert(UpdateEngineWorker.java:521)          at org.apache.jena.sparql.modify.UpdateEngineWorker.visit(UpdateEngineWorker.java:418)          at org.apache.jena.sparql.modify.request.UpdateModify.visit(UpdateModify.java:100)          at org.apache.jena.sparql.modify.UpdateVisitorSink.send(UpdateVisitorSink.java:46)          at org.apache.jena.sparql.modify.UpdateVisitorSink.send(UpdateVisitorSink.java:26)          at org.apache.jena.sparql.modify.UsingUpdateSink.send(UsingUpdateSink.java:61)          at org.apache.jena.sparql.modify.UsingUpdateSink.send(UsingUpdateSink.java:31)          at org.apache.jena.sparql.lang.SPARQLParserBase.emitUpdate(SPARQLParserBase.java:189)          at org.apache.jena.sparql.lang.arq.ARQParser.Update1(ARQParser.java:1491)          at org.apache.jena.sparql.lang.arq.ARQParser.Update(ARQParser.java:1419)          at org.apache.jena.sparql.lang.arq.ARQParser.UpdateUnit(ARQParser.java:52)          at org.apache.jena.sparql.lang.ParserARQUpdate._parse(ParserARQUpdate.java:62) 
         ... 57 more
org.apache.jena.query.QueryException: Secondary index duplicate: GSPO->GPOS -> [[0000000000A9D430], [0000000015AFB422], [0000000000002602], [04007E280A6A5DC0]]          at org.apache.jena.sparql.lang.ParserARQUpdate._parse(ParserARQUpdate.java:78)          at org.apache.jena.sparql.lang.ParserARQUpdate.parse$(ParserARQUpdate.java:45)          at org.apache.jena.sparql.lang.UpdateParser.parse(UpdateParser.java:48)          at org.apache.jena.update.UpdateAction.parseExecute(UpdateAction.java:421)          at org.apache.jena.update.UpdateAction.parseExecute(UpdateAction.java:380)          at org.apache.jena.fuseki.servlets.SPARQL_Update.execute(SPARQL_Update.java:234)          at org.apache.jena.fuseki.servlets.SPARQL_Update.executeBody(SPARQL_Update.java:189)          at org.apache.jena.fuseki.servlets.SPARQL_Update.perform(SPARQL_Update.java:106)          at org.apache.jena.fuseki.servlets.ActionService.executeLifecycle(ActionService.java:192)          at org.apache.jena.fuseki.servlets.ActionService.execCommonWorker(ActionService.java:106)          at org.apache.jena.fuseki.servlets.ActionBase.doCommon(ActionBase.java:73)          at org.apache.jena.fuseki.servlets.FusekiFilter.doFilter(FusekiFilter.java:73)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)          at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)          at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)          at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)          at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)          at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)          at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)          at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)          at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)          at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)          at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)          at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)          at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)          at org.apache.jena.fuseki.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:285)          at org.apache.jena.fuseki.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:248)          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1629)          at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)          at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)          at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190)          at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)          at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)          at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)          at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)          at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)          at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)          at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)          at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)          at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:455)          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) 
         at org.eclipse.jetty.server.Server.handle(Server.java:561)
         at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:334)          at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)          at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)          at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:104)          at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)          at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)          at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:243)          at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:679)          at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:597) 
         at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.jena.tdb.TDBException: Secondary index duplicate: GSPO->GPOS -> [[0000000000A9D430], [0000000015AFB422], [0000000000002602], [04007E280A6A5DC0]]          at org.apache.jena.tdb.store.tupletable.TupleTable.add(TupleTable.java:103)          at org.apache.jena.tdb.store.nodetupletable.NodeTupleTableConcrete.addRow(NodeTupleTableConcrete.java:88) 
         at org.apache.jena.tdb.store.QuadTable.add(QuadTable.java:60)
         at org.apache.jena.tdb.store.DatasetGraphTDB.addToNamedGraph(DatasetGraphTDB.java:97)          at org.apache.jena.sparql.core.DatasetGraphTriplesQuads.add(DatasetGraphTriplesQuads.java:44)          at org.apache.jena.sparql.core.DatasetGraphTriplesQuads.add(DatasetGraphTriplesQuads.java:31)          at org.apache.jena.sparql.core.DatasetGraphWrapper.add(DatasetGraphWrapper.java:116)          at org.apache.jena.sparql.modify.UpdateEngineWorker.addToDatasetGraph(UpdateEngineWorker.java:539)          at org.apache.jena.sparql.modify.UpdateEngineWorker.lambda$execInsert$4(UpdateEngineWorker.java:532) 
         at java.util.Iterator.forEachRemaining(Iterator.java:116)
         at org.apache.jena.sparql.modify.UpdateEngineWorker.execInsert(UpdateEngineWorker.java:532)          at org.apache.jena.sparql.modify.UpdateEngineWorker.execInsert(UpdateEngineWorker.java:521)          at org.apache.jena.sparql.modify.UpdateEngineWorker.visit(UpdateEngineWorker.java:418)          at org.apache.jena.sparql.modify.request.UpdateModify.visit(UpdateModify.java:100)          at org.apache.jena.sparql.modify.UpdateVisitorSink.send(UpdateVisitorSink.java:46)          at org.apache.jena.sparql.modify.UpdateVisitorSink.send(UpdateVisitorSink.java:26)          at org.apache.jena.sparql.modify.UsingUpdateSink.send(UsingUpdateSink.java:61)          at org.apache.jena.sparql.modify.UsingUpdateSink.send(UsingUpdateSink.java:31)          at org.apache.jena.sparql.lang.SPARQLParserBase.emitUpdate(SPARQLParserBase.java:189)          at org.apache.jena.sparql.lang.arq.ARQParser.Update1(ARQParser.java:1491)          at org.apache.jena.sparql.lang.arq.ARQParser.Update(ARQParser.java:1419)          at org.apache.jena.sparql.lang.arq.ARQParser.UpdateUnit(ARQParser.java:52)          at org.apache.jena.sparql.lang.ParserARQUpdate._parse(ParserARQUpdate.java:62) 
         ... 57 more


On 2.8.2018 11:03, Andy Seaborne wrote:

(subject line changed - this is not the original thread report)


On 01/08/18 10:32, Mikael Pesonen wrote:


Hi,
is it somehow possible to get this error (TransactionManager ERROR There are now active transactions ) from Fuseki GSP so that client could sleep and retry later allowing db to finish the transaction? 

No - it's an internal consistency check.

Does the transaction still happen?
Do you have a reproducible script to make this happen? I've never seen it occur. 

    Andy





On 19.6.2018 23:56, Andy Seaborne wrote:



On 18/06/18 11:36, Mikael Pesonen wrote:



On 18.6.2018 13:30, Andy Seaborne wrote:



On 18/06/18 10:55, Mikael Pesonen wrote:


Hi Andy,

On 18.6.2018 12:05, Andy Seaborne wrote:



>>> errors occur less than before.

which errors?


   TransactionManager ERROR There are now active transactions
This occurs when Im inserting new data and trying to read it right away (get empty result), or deleting data and trying to read it to make sure it's deleted (get data that should be deleted). There are no other errors in the log.
From looking at the code, I can't see how that happens - is it now possible to provide a reproducible script so that I can run it on machine? 

    Andy



-ku
FINLAND

Reply via email to