Hi. On 17 Oct 2016 18:16, "Andy Seaborne" <[email protected]> wrote: > > Are you running with debug tracing on?
No, should I and what should I look for..? > > Andy > > > On 17/10/16 11:30, Dick Murray wrote: >> >> Hi. >> >> I'm getting odd behaviour in Jena when I execute the same query >> concurrently. >> >> The query has an optional which is unmatched but which appears to cause a >> java.lang.String exception from the atlas code. >> >> This only happens if multiple queries are submitted concurrently and >> closely. On a "fast" host both queries will typically fail but on a slower >> host (VirtualBox with throttled cpu) the first query will return but the >> second will fail. >> >> If I siege with 10 threads and a random delay of 2 seconds some queries >> will succeed. Which makes it seem like a timing issue. >> >> The crux appears to be the optional, remove it and I can siege (10 threads, >> 50 iterations) without any issues, with the optional I get exceptions. >> >> I originally thought it was the application/json format but returning >> text/plain causes the exception and the root cause appears to be something >> in the atlas code passing in the wrong index to create a new String. >> >> To test if I run (Ubuntu 16.04 desktop) i.e. the same query concurrently >> twice; >> >> wget -O q1 --header "accept: text/plain" " >> http://localhost:8080/tdb/sparql?query=PREFIX dxf: <urn:iungo:dxf/> SELECT >> * WHERE { GRAPH <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> >> { { ?equipment dxf:attribute ?attribute } . OPTIONAL { >> ?tier_two_containment dxf:no_such_property ?equipment ; >> dxf:still_no_such_property ?department_area }}}" & wget -O q2 --header >> "accept: text/plain" "http://localhost:8080/tdb/sparql?query=PREFIX dxf: >> <urn:iungo:dxf/> SELECT * WHERE { GRAPH >> <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> { { ?equipment >> dxf:attribute ?attribute } . OPTIONAL { ?tier_two_containment >> dxf:no_such_property ?equipment ; dxf:still_no_such_property >> ?department_area }}}" >> >> >> the q1 output will show the correct result but q2 will either be 0 bytes or >> truncated and the following exception is show. >> >> dick@Dick-M3800:/media/dick/Backup1/bc$ wget -O q1 --header "accept: >> text/plain" "http://localhost:8080/tdb/sparql?query=PREFIX dxf: >> <urn:iungo:dxf/> SELECT * WHERE { GRAPH >> <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> { { ?equipment >> dxf:attribute ?attribute } . OPTIONAL { ?tier_two_containment >> dxf:no_such_property ?equipment ; dxf:still_no_such_property >> ?department_area }}}" & wget -O q2 --header "accept: text/plain" " >> http://localhost:8080/tdb/sparql?query=PREFIX dxf: <urn:iungo:dxf/> SELECT >> * WHERE { GRAPH <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> >> { { ?equipment dxf:attribute ?attribute } . OPTIONAL { >> ?tier_two_containment dxf:no_such_property ?equipment ; >> dxf:still_no_such_property ?department_area }}}" >> [1] 7594 >> --2016-10-17 11:03:21-- >> http://localhost:8080/tdb/sparql?query=PREFIX%20dxf:%20%3Curn:iungo:dxf/%3E%20SELECT%20*%20WHERE%20%7B%20GRAPH%20%3Curn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4%3E%20%7B%20%7B%20?equipment%20dxf:attribute%20?attribute%20%20%7D%20.%20OPTIONAL%20%7B%20?tier_two_containment%20dxf:no_such_property%20?equipment%20;%20dxf:still_no_such_property%20?department_area%20%7D%7D%7D >> Resolving localhost (localhost)... --2016-10-17 11:03:21-- >> http://localhost:8080/tdb/sparql?query=PREFIX%20dxf:%20%3Curn:iungo:dxf/%3E%20SELECT%20*%20WHERE%20%7B%20GRAPH%20%3Curn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4%3E%20%7B%20%7B%20?equipment%20dxf:attribute%20?attribute%20%20%7D%20.%20OPTIONAL%20%7B%20?tier_two_containment%20dxf:no_such_property%20?equipment%20;%20dxf:still_no_such_property%20?department_area%20%7D%7D%7D >> Resolving localhost (localhost)... 127.0.0.1127.0.0.1 >> >> Connecting to localhost (localhost)|127.0.0.1|:8080... Connecting to >> localhost (localhost)|127.0.0.1|:8080... connected. >> connected. >> HTTP request sent, awaiting response... HTTP request sent, awaiting >> response... 200 OK >> 200 OK >> Length: Length: 00 [text/plain] >> [text/plain] >> Saving to: ‘q1’ >> Saving to: ‘q2’ >> >> >> q1 [ <=> >> ] 0 --.-KB/s in >> 0s >> >> q2 [ <=> >> ] 0 --.-KB/s in >> 0s >> >> 2016-10-17 11:03:22 (0.00 B/s) - ‘q1’ saved [0/0] >> >> 2016-10-17 11:03:22 (0.00 B/s) - ‘q2’ saved [0/0] >> >> >> and an exception is thrown from java.lang.String >> >> Exception java.lang.StringIndexOutOfBoundsException: String index out of >> range: 247 >> [java] java.lang.String.<init>(String.java:205) >> [java] java.lang.StringBuilder.toString(StringBuilder.java:407) >> [java] org.apache.jena.atlas.iterator.AccString.get(AccString.java:52) >> [java] org.apache.jena.atlas.iterator.AccString.get(AccString.java:21) >> [java] org.apache.jena.atlas.iterator.Iter.reduce(Iter.java:165) >> [java] org.apache.jena.atlas.iterator.Iter.asString(Iter.java:483) >> [java] org.apache.jena.atlas.iterator.Iter.asString(Iter.java:479) >> [java] >> org.apache.jena.sparql.engine.optimizer.reorder.ReorderTransformationSubstitution.reorder(ReorderTransformationSubstitution.java:85) >> [java] >> org.apache.jena.sparql.engine.optimizer.reorder.ReorderTransformationSubstitution.reorderIndexes(ReorderTransformationSubstitution.java:69) >> [java] >> org.apache.jena.tdb.solver.OpExecutorTDB1.reorder(OpExecutorTDB1.java:276) >> [java] >> org.apache.jena.tdb.solver.OpExecutorTDB1.optimizeExecuteQuads(OpExecutorTDB1.java:230) >> [java] >> org.apache.jena.tdb.solver.OpExecutorTDB1.execute(OpExecutorTDB1.java:148) >> [java] >> org.apache.jena.sparql.engine.main.ExecutionDispatch.visit(ExecutionDispatch.java:66) >> [java] >> org.apache.jena.sparql.algebra.op.OpQuadPattern.visit(OpQuadPattern.java:95) >> [java] >> org.apache.jena.sparql.engine.main.ExecutionDispatch.exec(ExecutionDispatch.java:46) >> [java] >> org.apache.jena.sparql.engine.main.OpExecutor.exec(OpExecutor.java:118) >> [java] >> org.apache.jena.tdb.solver.OpExecutorTDB1.exec(OpExecutorTDB1.java:87) >> [java] >> org.apache.jena.sparql.engine.main.OpExecutor.execute(OpExecutor.java:89) >> [java] org.apache.jena.sparql.engine.main.QC.execute(QC.java:52) >> [java] >> org.apache.jena.sparql.engine.main.iterator.QueryIterOptionalIndex.nextStage(QueryIterOptionalIndex.java:51) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIterRepeatApply.makeNextStage(QueryIterRepeatApply.java:108) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIterRepeatApply.hasNextBinding(QueryIterRepeatApply.java:65) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:111) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:39) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:111) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:39) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:111) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorWrapper.hasNextBinding(QueryIteratorWrapper.java:39) >> [java] >> org.apache.jena.sparql.engine.iterator.QueryIteratorBase.hasNext(QueryIteratorBase.java:111) >> [java] >> org.apache.jena.sparql.engine.ResultSetStream.hasNext(ResultSetStream.java:74) >> [java] >> org.apache.jena.sparql.engine.ResultSetCheckCondition.hasNext(ResultSetCheckCondition.java:59) >> [java] >> org.apache.jena.sparql.resultset.ResultSetMem.<init>(ResultSetMem.java:86) >> [java] >> org.apache.jena.query.ResultSetFactory.makeRewindable(ResultSetFactory.java:404) >> [java] >> org.apache.jena.sparql.resultset.TextOutput.write(TextOutput.java:145) >> [java] >> org.apache.jena.sparql.resultset.TextOutput.write(TextOutput.java:130) >> [java] >> org.apache.jena.sparql.resultset.TextOutput.write(TextOutput.java:118) >> [java] >> org.apache.jena.sparql.resultset.TextOutput.format(TextOutput.java:66) >> >> >> However if I run; >> >> wget -O q1 --header "accept: text/plain" " >> http://localhost:8080/tdb/sparql?query=PREFIX dxf: <urn:iungo:dxf/> SELECT >> * WHERE { GRAPH <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> >> { { ?equipment dxf:attribute ?attribute } . }}" & wget -O q2 --header >> "accept: text/plain" "http://localhost:8080/tdb/sparql?query=PREFIX dxf: >> <urn:iungo:dxf/> SELECT * WHERE { GRAPH >> <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> { { ?equipment >> dxf:attribute ?attribute } . }}" >> >> >> i.e. I remove the optional clause both queries return... >> >> dick@Dick-M3800:/media/dick/Backup1/bc$ wget -O q1 --header "accept: >> text/plain" "http://localhost:8080/tdb/sparql?query=PREFIX dxf: >> <urn:iungo:dxf/> SELECT * WHERE { GRAPH >> <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> { { ?equipment >> dxf:attribute ?attribute } . }}" & wget -O q2 --header "accept: >> text/plain" "http://localhost:8080/tdb/sparql?query=PREFIX dxf: >> <urn:iungo:dxf/> SELECT * WHERE { GRAPH >> <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> { { ?equipment >> dxf:attribute ?attribute } . }}" >> [1] 7898 >> --2016-10-17 11:14:27-- >> http://localhost:8080/tdb/sparql?query=PREFIX%20dxf:%20%3Curn:iungo:dxf/%3E%20SELECT%20*%20WHERE%20%7B%20GRAPH%20%3Curn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4%3E%20%7B%20%7B%20?equipment%20dxf:attribute%20?attribute%20%20%7D%20.%20%7D%7D >> Resolving localhost (localhost)... --2016-10-17 11:14:27-- >> http://localhost:8080/tdb/sparql?query=PREFIX%20dxf:%20%3Curn:iungo:dxf/%3E%20SELECT%20*%20WHERE%20%7B%20GRAPH%20%3Curn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4%3E%20%7B%20%7B%20?equipment%20dxf:attribute%20?attribute%20%20%7D%20.%20%7D%7D >> Resolving localhost (localhost)... 127.0.0.1 >> Connecting to localhost (localhost)|127.0.0.1|:8080... connected. >> HTTP request sent, awaiting response... 127.0.0.1 >> Connecting to localhost (localhost)|127.0.0.1|:8080... connected. >> HTTP request sent, awaiting response... 200 OK >> 200 OK >> Length: Length: unspecifiedunspecified [text/plain] >> [text/plain] >> Saving to: ‘q2’ >> Saving to: ‘q1’ >> >> >> q2 [<=> >> ] 0 --.-KB/s >> qq1 [ <=> >> ] 438.81K >> --.-KB/s in 0.05s >> >> 2016-10-17 11:14:28 (8.19 MB/s) - ‘q1’ saved [449344] >> >> q2 [ <=> >> ] 438.81K --.-KB/s in >> 0.05s >> >> 2016-10-17 11:14:28 (8.09 MB/s) - ‘q2’ saved [449344] >> >> [1]+ Done wget -O q1 --header "accept: text/plain" " >> http://localhost:8080/tdb/sparql?query=PREFIX dxf: <urn:iungo:dxf/> SELECT >> * WHERE { GRAPH <urn:iungo:dxf/graph/309ea4ce-dbdf-4d92-9828-1d99d35d0bb4> >> { { ?equipment dxf:attribute ?attribute } . }}" >> dick@Dick-M3800:/media/dick/Backup1/bc$ >>
