On 03/07/2020 17:02, Chris Tomlinson wrote:
Hi Andy,
On Jul 3, 2020, at 8:41 AM, Andy Seaborne <[email protected]> wrote:
On 02/07/2020 21:55, Chris Tomlinson wrote:
grep -v "ThriftConvert WARN visit: Unrecognized: <RDF_StreamRow >" catalina.out
Is there any signature as to when they occur? Two PUTs overlapping, certain
usage by your clients (which probably isn't visible in the logs)? earlier
connections broken? high load on the server? Time of day? Anything else that
looks like a characteristic?
Our issue <https://github.com/buda-base/buda-base/issues/30> has a bit of a
discussion on the first occurrence on 30 April which might shed some light. The one
thing in common in the two occurrences is that in both cases the graph that was
being PUT was the ontologySchema but there were changes to that graph between 30
April and 30 Jun so it was not the same graph as far as content. Also there were not
overlapping puts in the first case.
This is ignorable:
30-Apr-2020 12:46:56.941 WARNING [localhost-startStop-2]
org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks
Unable to determine string representation of value of type
[org.apache.jena.tdb.transaction.DatasetGraphTxn]
java.lang.UnsupportedOperationException: Transactional.begin(TxnType
at
org.apache.jena.sparql.core.TransactionalNotSupported.begin(TransactionalNotSupported.java:66)
at
org.apache.jena.tdb.store.DatasetGraphTDB.begin(DatasetGraphTDB.java:265)
because the later log shows its part of the Tomcat shutdown report.
BTW Fuseki does not participate deeply in a clean web shutdown so TDB
does not release its ThreadLocals on shutdown and they are involved in
transactions.
Other than that, I'm lost.
Strange things happen, possible one, possibly two cases, with no obvious
cause.
Using RDFConnectionRemote will change the situation (no thrift used),
but the Thrift error seems to be a symptom, not a reason.
PersonUIShapes.ttl has been sent many times without problems.
Andy
No unusual load - in fact lightly loaded is the typical situation except during
the daily migration of legacy data which sometimes may have a lot of changed
graphs to PUT. We haven’t seen the WARNings happen at that time.
Since we’ve only had 2 occurrences of the issue it’s a bit hard to establish a
pattern.
Thanks,
Chris
Andy
On 03/07/2020 00:13, Chris Tomlinson wrote:
On Jul 2, 2020, at 17:44, Andy Seaborne <[email protected]> wrote:
On 02/07/2020 21:55, Chris Tomlinson wrote:
From what I can see, it (WARN) isn't database related.
No it seems to me to be related to getting the payload off the wire.
I think you said the same payload had been sent before.
??
Yes a copy/clone of the same payload, i.e., the serialization of the given
graph, has been sent many times w/o issue.
...
Even the concurrency looks OK because it locally writes a buffer so the HTTP
length is available.
(in case of corruption, not repeat, is happening)
So it seems to me that there may be an opportunity for some sort of
robustification in RDFConnection. There is evidently a loop somewhere that
doesn't terminate, retrying the parsing repeatedly or something like that. The
payload is finite so there wold appear to be a test that repeatedly fails but
doesn't make progress in consuming the payload.
RDFConnection (client-side) is sending, not parsing.
I'm referring to the Fuseki receiving end of the connection, where the WARNing
is being logged.
The WARN says that an empty <RDF_StreamRow > was seen.
There is no information about the stalled transactions although not finishing
the write would explain this:
30-Jun-2020 16:21:30.778
java.io.BufferedInputStream.read(BufferedInputStream.java:345)
org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:127)
so it's waiting for input. What's the proxy/reverse-proxy setup?
None. For the client on the same ec2 instance, obviously none; and for the
client on a second ec2 instance, we have nothing between our two internal ec2's
In the current situation, the two precipitating PUTs are from a client on the
same ec2 instance.
The code writes the payload to a ByteArrayOutputStream and sends those bytes.
That's how it gets the length for the HTTP header.
https://github.com/apache/jena/blob/master/jena-rdfconnection/src/main/java/org/apache/jena/rdfconnection/RDFConnectionRemote.java#L615
(run Fuseki with "verbose" to see the headers ... but it is quite verbose)
It sent something so the RDF->Thrift->bytes had finished and then it sent bytes.
As I tried to clarify, my remarks were w.r.t. the Fuseki/receiving end where
the issue is getting logged. Not the sending/client end.
Chris
Anyway - you have the source code ... :-)
Andy
