Hi.

On 17 Oct 2016 18:16, "Andy Seaborne" <a...@apache.org> 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$
>>

Reply via email to