You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@jena.apache.org by Ivan Lagunov <iv...@semaku.com> on 2021/07/05 09:01:34 UTC

Jena hangs while reading HTTP stream

Hello,

We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:


Model sub = ModelFactory.createDefaultModel();

TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)

// The following part sometimes hangs:
RDFParser.create()
        .source(stream)
        .lang(Lang.NTRIPLES)
        .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
        .parse(sub.getGraph());
// This point is not reached

The issue is not persistent, moreover it happens infrequently. When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"

So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream, and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.

Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.

Met vriendelijke groet, with kind regards,

Ivan Lagunov
Technical Lead / Software Architect
Skype: lagivan

Semaku B.V.
Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com

Re: Jena hangs while reading HTTP stream

Posted by james anderson <ja...@dydra.com>.
good afternoon;

is it possible that the client had no readable connection given the 3072/55397664 entry in the http proxy log?
it should indicate that some sort of connection existed long enough for nginx to send over 55 million bytes.

> On 2021-07-05, at 15:10:03, Rob Vesse <rv...@dotnetrdf.org> wrote:
> 
> That's a really good suggestion.  In the normal code flow do you ever call stream.close() ? And is createHttpClient() re-using an existing HttpClient object ? And is the hang only happening after some requests have succeeded ?
> 
> It is possible what is happening is that you aren't closing the stream (and I don't believe Jena's parsers ever close the stream for you) so after so many requests (10 I think by default) you are exhausting the max connections per route for the HTTP Client.  If that is the case wrapping the use of the stream in a try-with-resources block may be the solution.
> 
> Rob
> 
> On 05/07/2021, 14:03, "Martynas Jusevičius" <ma...@atomgraph.com> wrote:
> 
>    HTTPClient is not running out of connections? It is known to hang in such cases.
> 
>    On Mon, Jul 5, 2021 at 2:58 PM james anderson <ja...@dydra.com> wrote:
>> 
>> good afternoon;
>> 
>>> On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org> wrote:
>>> 
>>> 
>>> 
>>> On 05/07/2021 10:01, Ivan Lagunov wrote:
>>>> Hello,
>>>> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
>>>> Model sub = ModelFactory.createDefaultModel();
>>>> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
>>>> // The following part sometimes hangs:
>>>> RDFParser.create()
>>>>        .source(stream)
>>>>        .lang(Lang.NTRIPLES)
>>>>        .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>>>>        .parse(sub.getGraph());
>>>> // This point is not reached
>>>> 
>>>> The issue is not persistent, moreover it happens infrequently.
>>> 
>>> Then it looks like the data has stopped arriving but the connection is still open. (or the system has gone in GC overload due to heap pressure.)
>>> 
>>> Is intermittent on the same data? Or is the data changing? because maybe the data can't be written properly and the sender stops sending, though I'd expect the sender to close the connection (it's now in an unknown state and can't be reused).
>>> 
>>>> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
>>>> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"
>> 
>> the situation involves an nginx proxy and an upstream sparql processor.
>> 
>>> 
>>> What do the fields mean?
>> 
>> the line is an excerpt from an entry from the nginx request log. that line contains:
>> 
>>  protocol  code  requestLength/responseLength  upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt  upstreamPort
>> 
>>> 
>>> Is that 3072 bytes sent (so far) of 55397664?
>>> 
>>> If so, is Content-Length set (and then chunk encoding isn't needed).
>> 
>> likely not, as the response is (i believe) that from a sparql request, which is emitted as it is generated.
>> 
>>> 
>>> Unfortunately, in HTTP, 200 really means "I started to send stuff", not "I completed sending stuff". There is no way in HTTP 1/1 to signal an error after starting the response.
>> 
>> that is true, but there are indications in other logs which imply that the sparql processor believes the response to have been completely sent to nginx.
>> there are several reasons to believe this.
>> the times and the 200 response code in the nginx log indicate completion.
>> otherwise, it would either indicate that it timed out, or would include a 499 code, to the effect that the client closed the connection before the response was sent.
>> neither is the case.
>> in addition, the elapsed time is well below that for which nginx would time out an upstream connection.
>> 
>>> 
>>> The HttpClient - how is it configured?
>>> 
>>>> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream
>>> 
>>> Does any data reach the graph?
>>> 
>>> There is no timeout at the client end - otherwise you would get an exception. The parser is reading the input stream from Apache HttpClient. If it hangs, it's because the data has stopped arriving but the connection is still open.
>>> 
>>> You could try replacing .parse(graph) with parse(StreamRDF) and plug in a logging StreamRDF so you can see the progress, either sending on data to the graph or for investigation, merely logging.
>>> 
>>> In HTTP 1.1, a streamed response requires chunk encoding only when the Content-Length isn't given.
>> 
>> i believe, the content length is not given.
>> 
>>> 
>>>> 
>>> , and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.
>>>> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.
>>> 
>>> The HttpClient determines the transfer.
>>> 
>>>   Andy
>>> 
>>> FYI: RDFConnectionRemote is an abstraction to make this a little easier. No need to go to the low-level HttpOp.
>>> 
>>> 
>>> FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the HTTP code. There has to be some change anyway to get HTTP/2  (Apache HttpClient v5+, not v4, has HTTP/2 support).
>>> 
>>> This will include a new Graph Store Protocol client.
>>> 
>>>> Met vriendelijke groet, with kind regards,
>>>> Ivan Lagunov
>>>> Technical Lead / Software Architect
>>>> Skype: lagivan
>>>> Semaku B.V.
>>>> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
>> 
> 
> 
> 
> 


Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.
Hi John - thanks for the update.

     Andy

On 16/07/2021 09:31, John Walker wrote:
> Hi
> 
> After introducing the 120s timeout at client, we are no longer seeing the 'hanging' processes, so I don't think there is any bug in Jena.
> 
> Since the patch was introduced around 10 days ago we are seeing a few requests where the timeout is reached and the client closes the connection.
> We'd expect those requests to typically complete in under 120s, so need to see with James why those spaecific requests are taking longer.
> We'll do that offline as it is not really a concern for Jena.
> 
> John
> 
>> -----Original Message-----
>> From: James Anderson <an...@gmail.com>
>> Sent: Saturday, July 10, 2021 10:51 PM
>> To: users@jena.apache.org
>> Subject: Re: Jena hangs while reading HTTP stream
>>
>>
>>> On 2021-07-10, at 22:02:43, Andy Seaborne <an...@apache.org> wrote:
>>>
>>> Hi John,
>>>
>>>
>>>
>>> On 10/07/2021 17:03, John Walker wrote:
>>>> We're using a 120s timeout for all the requests, which should give plenty
>> of time for the query requests to complete in regular circumstances.
>>>
>>> That's 120s at the server?
>>
>> i understood that to describe a timeout which they have introduced into
>> some stage in the client process(es).
>>
>> the logs in the served indicate that the two requests for which they have
>> provided identifiers completed.
>>
>> were the proxy to time a request out the client would receive a 504. that
>> does not appear in its log.
>> were the sparql processor to time them out, the response would be a
>> generic 500. that also does not appear.
>>
>>> What happens if that goes off? The response is closed? (a Q for james)
>>
>> were the request to time out, the upstream connection would be closed.
>> the proxy should close its client connection as a consequence.
>>>
>>>> As we use N-Triples, I was wondering if the N-Triples parser uses the
>> readLine method to read from the stream.
>>>> If there were some line that is not terminated with an EOL character,
>> might that cause this issue?
>>>
>>>  From the information so far, not likely. The parse has not changed and this
>> parsing path is well trodden.
>>>
>>> What matter is that it's three terms then a DOT until end-of-stream is seen.
>>>
>>> End-of-stream happens when the chunking transfer layer says so - that's in
>> Apache HttpClient.
>>
>> one can expect the response to have been chunked.
>> the proxy is not configured to cache responses.
>>
>>>
>>> If you see a single CPU thread at 100%, the parser is looping but there isn't
>> a loop except delivering triples to the graph.  And the NT parse is well-used
>> and quite simple.
>>>
>>> so it seems to be it is one of two cases:
>>>
>>> 1 - bytes are flowing but the parser can't send output triples in the
>> destination - java heap pressure (you'll see multiple CPU threads at 100%)
>>>
>>> How long do you leave it? Eventually - many minutes (20 is possible) - this
>> case will out-of-memory.
>>>
>>> 55Mbytes isn't a very large number of triples. 500K maybe (without
>> knowing the data, rule of thumb 100 bytes per N-triple triple) and it's a
>> freshly create graph.  heap has been used up by the rest of the application?
>>
>> the log entries for the two researched requests indicated 398940 and 398914
>> statements in the respective responses.
>>
>>>
>>> 2 - Bytes are not flowing into the application, the parser is waiting. CPU
>> usage 0%.
>>>
>>> The next question is whether the same operation will fault again or if the
>> same requestURL sometimes works.
>>>
>>> The Jena code for all this is deterministic. There's no hidden parallelism in
>> this case.
>>>
>>> ----
>>>
>>> HTTP is layered:
>>>
>>> Transfer-Encoding [lowest level]
>>> Content-Encoding
>>> Actual stuff (Content-type).
>>>
>>> Transfer is point-to-point, Content-Encoding is end-to-end.
>>> "Transfer-Encoding: chunked" is used for a stream of response bytes
>> without Content-Length.
>>>
>>> What intermediaries are there between the app and Dydra? There is an
>> nginx but is that acting as a reverse proxy (and what connection method
>> does it use) or is Dydra providing an nginx module?
>>>
>>> Presumably there is a load balancer.
>>>
>>> Does the app talk to a gateway?
>>>
>>> Do any intermediaries cache?
>>>
>>> Each hop between systems is a point-to-point "transfer".
>>>
>>>> Model sub = ModelFactory.createDefaultModel();
>>>> try (TypedInputStream stream = HttpOp.execHttpGet(requestURL,
>> WebContent.contentTypeNTriples, createHttpClient(auth), null)) {
>>>>     // The following part sometimes hangs:
>>>
>>> Are you positive it returns from HttpOp.execHttpGet and enters the parser?
>>>
>>>>     RDFParser.create()
>>>>         .source(stream)
>>>>         .lang(Lang.NTRIPLES)
>>>>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>>>>         .parse(sub.getGraph());
>>>> } catch (Exception ex) {
>>>>     // Handle the exception
>>>> }
>>>
>>>
>>> The parser does not use readLine.  NT, TTL, NQ, TriG share a tokenizer and
>> tokens get read from the character stream.  Whitespace is discarded. The NT
>> parsing is slightly permissive here (but you can't have """-strings).
>>>
>>> End of (chunked) stream will happen and that is end-of-triples. The TCP
>> connection is still open but the response stream has ended. TCP is handled
>> by Apache HttpClient - that's quite unlikely to be broken.
>>>
>>>
>>>> Otherwise if the output stream from Dydra is not closed, or the socket is
>> not closed?
>>>
>>> As james says - chunking happens (transfer presumably), and if the server
>> say "end of response", a chunk of zero bytes is sent which makes the end of
>> the content.  If each transfer is chunked, then all close this response but the
>> TCP connection is kept open.
>>>
>>> HTTP is not a simple protocol!
>>>
>>> The version of Apache Client (v4) does not support HTTP/2 so protocol
>> upgrade in HTTP/2 is not happening. We in HTTP/1.1.
>>>
>>>     Andy
> 

RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi

After introducing the 120s timeout at client, we are no longer seeing the 'hanging' processes, so I don't think there is any bug in Jena.

Since the patch was introduced around 10 days ago we are seeing a few requests where the timeout is reached and the client closes the connection.
We'd expect those requests to typically complete in under 120s, so need to see with James why those spaecific requests are taking longer.
We'll do that offline as it is not really a concern for Jena.

John

> -----Original Message-----
> From: James Anderson <an...@gmail.com>
> Sent: Saturday, July 10, 2021 10:51 PM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> > On 2021-07-10, at 22:02:43, Andy Seaborne <an...@apache.org> wrote:
> >
> > Hi John,
> >
> >
> >
> > On 10/07/2021 17:03, John Walker wrote:
> >> We're using a 120s timeout for all the requests, which should give plenty
> of time for the query requests to complete in regular circumstances.
> >
> > That's 120s at the server?
> 
> i understood that to describe a timeout which they have introduced into
> some stage in the client process(es).
> 
> the logs in the served indicate that the two requests for which they have
> provided identifiers completed.
> 
> were the proxy to time a request out the client would receive a 504. that
> does not appear in its log.
> were the sparql processor to time them out, the response would be a
> generic 500. that also does not appear.
> 
> > What happens if that goes off? The response is closed? (a Q for james)
> 
> were the request to time out, the upstream connection would be closed.
> the proxy should close its client connection as a consequence.
> >
> >> As we use N-Triples, I was wondering if the N-Triples parser uses the
> readLine method to read from the stream.
> >> If there were some line that is not terminated with an EOL character,
> might that cause this issue?
> >
> > From the information so far, not likely. The parse has not changed and this
> parsing path is well trodden.
> >
> > What matter is that it's three terms then a DOT until end-of-stream is seen.
> >
> > End-of-stream happens when the chunking transfer layer says so - that's in
> Apache HttpClient.
> 
> one can expect the response to have been chunked.
> the proxy is not configured to cache responses.
> 
> >
> > If you see a single CPU thread at 100%, the parser is looping but there isn't
> a loop except delivering triples to the graph.  And the NT parse is well-used
> and quite simple.
> >
> > so it seems to be it is one of two cases:
> >
> > 1 - bytes are flowing but the parser can't send output triples in the
> destination - java heap pressure (you'll see multiple CPU threads at 100%)
> >
> > How long do you leave it? Eventually - many minutes (20 is possible) - this
> case will out-of-memory.
> >
> > 55Mbytes isn't a very large number of triples. 500K maybe (without
> knowing the data, rule of thumb 100 bytes per N-triple triple) and it's a
> freshly create graph.  heap has been used up by the rest of the application?
> 
> the log entries for the two researched requests indicated 398940 and 398914
> statements in the respective responses.
> 
> >
> > 2 - Bytes are not flowing into the application, the parser is waiting. CPU
> usage 0%.
> >
> > The next question is whether the same operation will fault again or if the
> same requestURL sometimes works.
> >
> > The Jena code for all this is deterministic. There's no hidden parallelism in
> this case.
> >
> > ----
> >
> > HTTP is layered:
> >
> > Transfer-Encoding [lowest level]
> > Content-Encoding
> > Actual stuff (Content-type).
> >
> > Transfer is point-to-point, Content-Encoding is end-to-end.
> > "Transfer-Encoding: chunked" is used for a stream of response bytes
> without Content-Length.
> >
> > What intermediaries are there between the app and Dydra? There is an
> nginx but is that acting as a reverse proxy (and what connection method
> does it use) or is Dydra providing an nginx module?
> >
> > Presumably there is a load balancer.
> >
> > Does the app talk to a gateway?
> >
> > Do any intermediaries cache?
> >
> > Each hop between systems is a point-to-point "transfer".
> >
> >> Model sub = ModelFactory.createDefaultModel();
> >> try (TypedInputStream stream = HttpOp.execHttpGet(requestURL,
> WebContent.contentTypeNTriples, createHttpClient(auth), null)) {
> >>    // The following part sometimes hangs:
> >
> > Are you positive it returns from HttpOp.execHttpGet and enters the parser?
> >
> >>    RDFParser.create()
> >>        .source(stream)
> >>        .lang(Lang.NTRIPLES)
> >>        .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
> >>        .parse(sub.getGraph());
> >> } catch (Exception ex) {
> >>    // Handle the exception
> >> }
> >
> >
> > The parser does not use readLine.  NT, TTL, NQ, TriG share a tokenizer and
> tokens get read from the character stream.  Whitespace is discarded. The NT
> parsing is slightly permissive here (but you can't have """-strings).
> >
> > End of (chunked) stream will happen and that is end-of-triples. The TCP
> connection is still open but the response stream has ended. TCP is handled
> by Apache HttpClient - that's quite unlikely to be broken.
> >
> >
> >> Otherwise if the output stream from Dydra is not closed, or the socket is
> not closed?
> >
> > As james says - chunking happens (transfer presumably), and if the server
> say "end of response", a chunk of zero bytes is sent which makes the end of
> the content.  If each transfer is chunked, then all close this response but the
> TCP connection is kept open.
> >
> > HTTP is not a simple protocol!
> >
> > The version of Apache Client (v4) does not support HTTP/2 so protocol
> upgrade in HTTP/2 is not happening. We in HTTP/1.1.
> >
> >    Andy


Re: Jena hangs while reading HTTP stream

Posted by James Anderson <an...@gmail.com>.
> On 2021-07-10, at 22:02:43, Andy Seaborne <an...@apache.org> wrote:
> 
> Hi John,
> 
> 
> 
> On 10/07/2021 17:03, John Walker wrote:
>> We're using a 120s timeout for all the requests, which should give plenty of time for the query requests to complete in regular circumstances.
> 
> That's 120s at the server?

i understood that to describe a timeout which they have introduced into some stage in the client process(es).

the logs in the served indicate that the two requests for which they have provided identifiers completed.

were the proxy to time a request out the client would receive a 504. that does not appear in its log.
were the sparql processor to time them out, the response would be a generic 500. that also does not appear.

> What happens if that goes off? The response is closed? (a Q for james)

were the request to time out, the upstream connection would be closed.
the proxy should close its client connection as a consequence.
> 
>> As we use N-Triples, I was wondering if the N-Triples parser uses the readLine method to read from the stream.
>> If there were some line that is not terminated with an EOL character, might that cause this issue?
> 
> From the information so far, not likely. The parse has not changed and this parsing path is well trodden.
> 
> What matter is that it's three terms then a DOT until end-of-stream is seen.
> 
> End-of-stream happens when the chunking transfer layer says so - that's in Apache HttpClient.

one can expect the response to have been chunked.
the proxy is not configured to cache responses.

> 
> If you see a single CPU thread at 100%, the parser is looping but there isn't a loop except delivering triples to the graph.  And the NT parse is well-used and quite simple.
> 
> so it seems to be it is one of two cases:
> 
> 1 - bytes are flowing but the parser can't send output triples in the destination - java heap pressure (you'll see multiple CPU threads at 100%)
> 
> How long do you leave it? Eventually - many minutes (20 is possible) - this case will out-of-memory.
> 
> 55Mbytes isn't a very large number of triples. 500K maybe (without knowing the data, rule of thumb 100 bytes per N-triple triple) and it's a freshly create graph.  heap has been used up by the rest of the application?

the log entries for the two researched requests indicated 398940 and 398914 statements in the respective responses.

> 
> 2 - Bytes are not flowing into the application, the parser is waiting. CPU usage 0%.
> 
> The next question is whether the same operation will fault again or if the same requestURL sometimes works.
> 
> The Jena code for all this is deterministic. There's no hidden parallelism in this case.
> 
> ----
> 
> HTTP is layered:
> 
> Transfer-Encoding [lowest level]
> Content-Encoding
> Actual stuff (Content-type).
> 
> Transfer is point-to-point, Content-Encoding is end-to-end.
> "Transfer-Encoding: chunked" is used for a stream of response bytes without Content-Length.
> 
> What intermediaries are there between the app and Dydra? There is an nginx but is that acting as a reverse proxy (and what connection method does it use) or is Dydra providing an nginx module?
> 
> Presumably there is a load balancer.
> 
> Does the app talk to a gateway?
> 
> Do any intermediaries cache?
> 
> Each hop between systems is a point-to-point "transfer".
> 
>> Model sub = ModelFactory.createDefaultModel();
>> try (TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)) {
>>    // The following part sometimes hangs:
> 
> Are you positive it returns from HttpOp.execHttpGet and enters the parser?
> 
>>    RDFParser.create()
>>        .source(stream)
>>        .lang(Lang.NTRIPLES)
>>        .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>>        .parse(sub.getGraph());
>> } catch (Exception ex) {
>>    // Handle the exception
>> }
> 
> 
> The parser does not use readLine.  NT, TTL, NQ, TriG share a tokenizer and tokens get read from the character stream.  Whitespace is discarded. The NT parsing is slightly permissive here (but you can't have """-strings).
> 
> End of (chunked) stream will happen and that is end-of-triples. The TCP connection is still open but the response stream has ended. TCP is handled by Apache HttpClient - that's quite unlikely to be broken.
> 
> 
>> Otherwise if the output stream from Dydra is not closed, or the socket is not closed?
> 
> As james says - chunking happens (transfer presumably), and if the server say "end of response", a chunk of zero bytes is sent which makes the end of the content.  If each transfer is chunked, then all close this response but the TCP connection is kept open.
> 
> HTTP is not a simple protocol!
> 
> The version of Apache Client (v4) does not support HTTP/2 so protocol upgrade in HTTP/2 is not happening. We in HTTP/1.1.
> 
>    Andy


Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.
Hi John,



On 10/07/2021 17:03, John Walker wrote:
> We're using a 120s timeout for all the requests, which should give plenty of time for the query requests to complete in regular circumstances.

That's 120s at the server?
What happens if that goes off? The response is closed? (a Q for james)

> As we use N-Triples, I was wondering if the N-Triples parser uses the readLine method to read from the stream.
> If there were some line that is not terminated with an EOL character, might that cause this issue?

 From the information so far, not likely. The parse has not changed and 
this parsing path is well trodden.

What matter is that it's three terms then a DOT until end-of-stream is seen.

End-of-stream happens when the chunking transfer layer says so - that's 
in Apache HttpClient.

If you see a single CPU thread at 100%, the parser is looping but there 
isn't a loop except delivering triples to the graph.  And the NT parse 
is well-used and quite simple.

so it seems to be it is one of two cases:

1 - bytes are flowing but the parser can't send output triples in the 
destination - java heap pressure (you'll see multiple CPU threads at 100%)

How long do you leave it? Eventually - many minutes (20 is possible) - 
this case will out-of-memory.

55Mbytes isn't a very large number of triples. 500K maybe (without 
knowing the data, rule of thumb 100 bytes per N-triple triple) and it's 
a freshly create graph.  heap has been used up by the rest of the 
application?

2 - Bytes are not flowing into the application, the parser is waiting. 
CPU usage 0%.

The next question is whether the same operation will fault again or if 
the same requestURL sometimes works.

The Jena code for all this is deterministic. There's no hidden 
parallelism in this case.

----

HTTP is layered:

Transfer-Encoding [lowest level]
Content-Encoding
Actual stuff (Content-type).

Transfer is point-to-point, Content-Encoding is end-to-end.
"Transfer-Encoding: chunked" is used for a stream of response bytes 
without Content-Length.

What intermediaries are there between the app and Dydra? There is an 
nginx but is that acting as a reverse proxy (and what connection method 
does it use) or is Dydra providing an nginx module?

Presumably there is a load balancer.

Does the app talk to a gateway?

Do any intermediaries cache?

Each hop between systems is a point-to-point "transfer".

> Model sub = ModelFactory.createDefaultModel();
> 
> try (TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)) {
>     // The following part sometimes hangs:

Are you positive it returns from HttpOp.execHttpGet and enters the parser?

>     RDFParser.create()
>         .source(stream)
>         .lang(Lang.NTRIPLES)
>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>         .parse(sub.getGraph());
> } catch (Exception ex) {
>     // Handle the exception
> }


The parser does not use readLine.  NT, TTL, NQ, TriG share a tokenizer 
and tokens get read from the character stream.  Whitespace is discarded. 
The NT parsing is slightly permissive here (but you can't have """-strings).

End of (chunked) stream will happen and that is end-of-triples. The TCP 
connection is still open but the response stream has ended. TCP is 
handled by Apache HttpClient - that's quite unlikely to be broken.


> 
> Otherwise if the output stream from Dydra is not closed, or the socket is not closed?

As james says - chunking happens (transfer presumably), and if the 
server say "end of response", a chunk of zero bytes is sent which makes 
the end of the content.  If each transfer is chunked, then all close 
this response but the TCP connection is kept open.

HTTP is not a simple protocol!

The version of Apache Client (v4) does not support HTTP/2 so protocol 
upgrade in HTTP/2 is not happening. We in HTTP/1.1.

     Andy

Re: Jena hangs while reading HTTP stream

Posted by James Anderson <an...@gmail.com>.
good evening;

> On 2021-07-10, at 18:03:59, John Walker <jo...@semaku.com> wrote:
> 
>> ...
> 
> OK, I've not been able to figure out how the Jena parser reads the stream.
> 
> As we use N-Triples, I was wondering if the N-Triples parser uses the readLine method to read from the stream.
> If there were some line that is not terminated with an EOL character, might that cause this issue?
> 
> Otherwise if the output stream from Dydra is not closed, or the socket is not closed?

the server will intend to keep the connection alive.
the response is chunked.


RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi Andy, James,

We've implemented the client timeout on the http requests and will monitor if the issue is still observed, or at least if requests are timing out.

We're using a 120s timeout for all the requests, which should give plenty of time for the query requests to complete in regular circumstances.

> -----Original Message-----
> From: Andy Seaborne <an...@apache.org>
> Sent: Wednesday, July 7, 2021 1:12 AM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> 
> On 06/07/2021 12:40, John Walker wrote:
> > Hi James
> >
> >> -----Original Message-----
> >> From: James Anderson <an...@gmail.com>
> >> Sent: Tuesday, July 6, 2021 1:00 PM
> >> To: users@jena.apache.org
> >> Subject: Re: Jena hangs while reading HTTP stream
> >>
> 
> >>
> >> a stack trace could be very helpful.

As no error is thrown, there is no stack trace logged.

We'll have to see if the addition of timeout give some handle via which we can grab one.

> >
> > There is no stack trace captured at the time of the incident and we are
> unable to reproduce.
> >
> > Given this sanitized extract from the application logs directly prior to it
> hanging:
> >
> > c.semaku.es.core.service.UpdateService   : Executing : query.rq
> > com.semaku.es.core.util.Utils            : Send request to:
> https://example.com/foo/bar/sparql?query=query.rq
> > com.semaku.es.core.util.Utils            : Received response in 1397ms for
> https://example.com/foo/bar/sparql?query=query.rq
> > c.semaku.es.core.service.UpdateService   : Loading NTriples to Jena model
> >
> > The "received response in ..." line is logged after the HttpOp.execHttpGet()
> method has been called (which returns the TypedOutputStream).
> >
> > I am not familiar enough with how these streams work in Jena and Java.
> > It is unclear if this indicates Dydra has started to return results after 1397ms,
> or if the complete response had already been received by the client.
> 
> Started.
> 
> execHttpGet opens the stream; it does not read the body (it reads the
> headers).
> 
> The body is the TypedInputStream - there is a normal java InputStream.
> 
>      Andy
> 

OK, I've not been able to figure out how the Jena parser reads the stream.

As we use N-Triples, I was wondering if the N-Triples parser uses the readLine method to read from the stream.
If there were some line that is not terminated with an EOL character, might that cause this issue?

Otherwise if the output stream from Dydra is not closed, or the socket is not closed?

John


Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.

On 06/07/2021 12:40, John Walker wrote:
> Hi James
> 
>> -----Original Message-----
>> From: James Anderson <an...@gmail.com>
>> Sent: Tuesday, July 6, 2021 1:00 PM
>> To: users@jena.apache.org
>> Subject: Re: Jena hangs while reading HTTP stream
>>

>>
>> a stack trace could be very helpful.
> 
> There is no stack trace captured at the time of the incident and we are unable to reproduce.
> 
> Given this sanitized extract from the application logs directly prior to it hanging:
> 
> c.semaku.es.core.service.UpdateService   : Executing : query.rq
> com.semaku.es.core.util.Utils            : Send request to: https://example.com/foo/bar/sparql?query=query.rq
> com.semaku.es.core.util.Utils            : Received response in 1397ms for https://example.com/foo/bar/sparql?query=query.rq
> c.semaku.es.core.service.UpdateService   : Loading NTriples to Jena model
> 
> The "received response in ..." line is logged after the HttpOp.execHttpGet() method has been called (which returns the TypedOutputStream).
> 
> I am not familiar enough with how these streams work in Jena and Java.
> It is unclear if this indicates Dydra has started to return results after 1397ms, or if the complete response had already been received by the client.

Started.

execHttpGet opens the stream; it does not read the body (it reads the 
headers).

The body is the TypedInputStream - there is a normal java InputStream.

     Andy



RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi James

> -----Original Message-----
> From: James Anderson <an...@gmail.com>
> Sent: Tuesday, July 6, 2021 1:00 PM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> > On 2021-07-06, at 12:46:47, John Walker <jo...@semaku.com>
> wrote:
> >
> > Hi Andy
> >
> >> -----Original Message-----
> >> From: Andy Seaborne <an...@apache.org>
> >> Sent: Tuesday, July 6, 2021 12:04 PM
> >> To: users@jena.apache.org
> >> Subject: Re: Jena hangs while reading HTTP stream
> >>
> ...
> >>>> John - what's the requestURL? The logs say the request is 3072
> >>>> bytes (including headers) which is possible but unusually large.
> >>>
> >>> As it is a GET request, the query text is passed as (url encoded)
> >>> query string
> >> parameter on the url.
> >>> I cannot share the query text as it is for a customer project, but
> >>> have made
> >> similar GET request from curl and it came out at 3100 bytes.
> >>
> >> But what is it doing? I guess it is a CONSTRUCT query.
> >
> > Yes, it is a CONSTRUCT.
> >
> >>
> >> At what point did it show as 3100 bytes? From "curl -v" or from logs nearer.
> >> the server? (Intermediates may be adding "Transfer-*" headers)
> >
> > To get that I just copied the request headers from curl -v output into a text
> file and check the size.
> >
> > The original 3072 bytes comes from what James observed for the request
> length on the Dydra host.
> 
> the two length values are "$request_length/$body_bytes_sent"
> 
> the first is described to be the length of the entire request.
> (http://nginx.org/en/docs/http/ngx_http_log_module.html)
> 
> the requests include the sparql query text as a url parameter.
> one of the request lines was itself 2789 bytes.
> 
> 
> >
> >>
> >>     Andy
> >>
> >>>>
> >>>> It is the unpredictability that is odd.
> >>>>
> >>>> Could you please breakpoint the process and see what code it is in?
> >>>
> >>> Will check on that.
> 
> a stack trace could be very helpful.

There is no stack trace captured at the time of the incident and we are unable to reproduce.

Given this sanitized extract from the application logs directly prior to it hanging:

c.semaku.es.core.service.UpdateService   : Executing : query.rq
com.semaku.es.core.util.Utils            : Send request to: https://example.com/foo/bar/sparql?query=query.rq
com.semaku.es.core.util.Utils            : Received response in 1397ms for https://example.com/foo/bar/sparql?query=query.rq
c.semaku.es.core.service.UpdateService   : Loading NTriples to Jena model

The "received response in ..." line is logged after the HttpOp.execHttpGet() method has been called (which returns the TypedOutputStream).

I am not familiar enough with how these streams work in Jena and Java.
It is unclear if this indicates Dydra has started to return results after 1397ms, or if the complete response had already been received by the client.

> 
> >>>
> >>>>
> >>>> 	Andy
> >>>
> >>> John


Re: Jena hangs while reading HTTP stream

Posted by James Anderson <an...@gmail.com>.
> On 2021-07-06, at 12:46:47, John Walker <jo...@semaku.com> wrote:
> 
> Hi Andy
> 
>> -----Original Message-----
>> From: Andy Seaborne <an...@apache.org>
>> Sent: Tuesday, July 6, 2021 12:04 PM
>> To: users@jena.apache.org
>> Subject: Re: Jena hangs while reading HTTP stream
>> 
...
>>>> John - what's the requestURL? The logs say the request is 3072 bytes
>>>> (including headers) which is possible but unusually large.
>>> 
>>> As it is a GET request, the query text is passed as (url encoded) query string
>> parameter on the url.
>>> I cannot share the query text as it is for a customer project, but have made
>> similar GET request from curl and it came out at 3100 bytes.
>> 
>> But what is it doing? I guess it is a CONSTRUCT query.
> 
> Yes, it is a CONSTRUCT.
> 
>> 
>> At what point did it show as 3100 bytes? From "curl -v" or from logs nearer.
>> the server? (Intermediates may be adding "Transfer-*" headers)
> 
> To get that I just copied the request headers from curl -v output into a text file and check the size.
> 
> The original 3072 bytes comes from what James observed for the request length on the Dydra host.

the two length values are "$request_length/$body_bytes_sent"

the first is described to be the length of the entire request. (http://nginx.org/en/docs/http/ngx_http_log_module.html)

the requests include the sparql query text as a url parameter.
one of the request lines was itself 2789 bytes.


> 
>> 
>>     Andy
>> 
>>>> 
>>>> It is the unpredictability that is odd.
>>>> 
>>>> Could you please breakpoint the process and see what code it is in?
>>> 
>>> Will check on that.

a stack trace could be very helpful.

>>> 
>>>> 
>>>> 	Andy
>>> 
>>> John


RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi Andy

> -----Original Message-----
> From: Andy Seaborne <an...@apache.org>
> Sent: Tuesday, July 6, 2021 12:04 PM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> 
> On 06/07/2021 10:46, John Walker wrote:
> > Hi Andy
> >
> >> -----Original Message-----
> >> From: Andy Seaborne <an...@apache.org>
> >> Sent: Tuesday, July 6, 2021 11:03 AM
> >> To: users@jena.apache.org
> >> Subject: Re: Jena hangs while reading HTTP stream
> >>
> >>
> >>
> >> On 06/07/2021 06:10, John Walker wrote:
> >>> Hi Andy
> >>>
> >>>> Rob's right - RDFParser does not close a resource that is passed
> >>>> into the parser. If given a resource, the caller is responsible -
> >>>> try-with-resources or similar is expected.
> >>>
> >>> I was reading the javadocs and these state the InputStream will be
> >>> closed when the parser is called
> >>>
> >>>
> >>
> https://jena.apache.org/documentation/javadoc/arq/org/apache/jena/rio
> >> t
> >>> /RDFParser.html#source(java.io.InputStream)
> >>>
> >>> John
> >>>
> >>
> >> So it does. Although here there is a new createHttpClient each time
> >> so there isn't a pool running out.
> >>
> >> The OP says the code gets passed the HttpOp.execHttpGet call so the
> >> connection has been established.
> >>
> >> John - what's the requestURL? The logs say the request is 3072 bytes
> >> (including headers) which is possible but unusually large.
> >
> > As it is a GET request, the query text is passed as (url encoded) query string
> parameter on the url.
> > I cannot share the query text as it is for a customer project, but have made
> similar GET request from curl and it came out at 3100 bytes.
> 
> But what is it doing? I guess it is a CONSTRUCT query.

Yes, it is a CONSTRUCT.

> 
> At what point did it show as 3100 bytes? From "curl -v" or from logs nearer.
> the server? (Intermediates may be adding "Transfer-*" headers)

To get that I just copied the request headers from curl -v output into a text file and check the size.

The original 3072 bytes comes from what James observed for the request length on the Dydra host.

> 
>      Andy
> 
> >>
> >> It is the unpredictability that is odd.
> >>
> >> Could you please breakpoint the process and see what code it is in?
> >
> > Will check on that.
> >
> >>
> >> 	Andy
> >
> > John
> >

Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.

On 06/07/2021 10:46, John Walker wrote:
> Hi Andy
> 
>> -----Original Message-----
>> From: Andy Seaborne <an...@apache.org>
>> Sent: Tuesday, July 6, 2021 11:03 AM
>> To: users@jena.apache.org
>> Subject: Re: Jena hangs while reading HTTP stream
>>
>>
>>
>> On 06/07/2021 06:10, John Walker wrote:
>>> Hi Andy
>>>
>>>> Rob's right - RDFParser does not close a resource that is passed into
>>>> the parser. If given a resource, the caller is responsible -
>>>> try-with-resources or similar is expected.
>>>
>>> I was reading the javadocs and these state the InputStream will be
>>> closed when the parser is called
>>>
>>>
>> https://jena.apache.org/documentation/javadoc/arq/org/apache/jena/riot
>>> /RDFParser.html#source(java.io.InputStream)
>>>
>>> John
>>>
>>
>> So it does. Although here there is a new createHttpClient each time so there
>> isn't a pool running out.
>>
>> The OP says the code gets passed the HttpOp.execHttpGet call so the
>> connection has been established.
>>
>> John - what's the requestURL? The logs say the request is 3072 bytes
>> (including headers) which is possible but unusually large.
> 
> As it is a GET request, the query text is passed as (url encoded) query string parameter on the url.
> I cannot share the query text as it is for a customer project, but have made similar GET request from curl and it came out at 3100 bytes.

But what is it doing? I guess it is a CONSTRUCT query.

At what point did it show as 3100 bytes? From "curl -v" or from logs 
nearer the server? (Intermediates may be adding "Transfer-*" headers)

     Andy

>>
>> It is the unpredictability that is odd.
>>
>> Could you please breakpoint the process and see what code it is in?
> 
> Will check on that.
> 
>>
>> 	Andy
> 
> John
> 

RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi Andy

> -----Original Message-----
> From: Andy Seaborne <an...@apache.org>
> Sent: Tuesday, July 6, 2021 11:03 AM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> 
> On 06/07/2021 06:10, John Walker wrote:
> > Hi Andy
> >
> >> Rob's right - RDFParser does not close a resource that is passed into
> >> the parser. If given a resource, the caller is responsible -
> >> try-with-resources or similar is expected.
> >
> > I was reading the javadocs and these state the InputStream will be
> > closed when the parser is called
> >
> >
> https://jena.apache.org/documentation/javadoc/arq/org/apache/jena/riot
> > /RDFParser.html#source(java.io.InputStream)
> >
> > John
> >
> 
> So it does. Although here there is a new createHttpClient each time so there
> isn't a pool running out.
> 
> The OP says the code gets passed the HttpOp.execHttpGet call so the
> connection has been established.
> 
> John - what's the requestURL? The logs say the request is 3072 bytes
> (including headers) which is possible but unusually large.

As it is a GET request, the query text is passed as (url encoded) query string parameter on the url.
I cannot share the query text as it is for a customer project, but have made similar GET request from curl and it came out at 3100 bytes.

> 
> It is the unpredictability that is odd.
> 
> Could you please breakpoint the process and see what code it is in?

Will check on that.

> 
> 	Andy

John

Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.

On 06/07/2021 06:10, John Walker wrote:
> Hi Andy
> 
>> Rob's right - RDFParser does not close a resource that is passed into the
>> parser. If given a resource, the caller is responsible - try-with-resources or
>> similar is expected.
> 
> I was reading the javadocs and these state the InputStream will be closed when the parser is called
> 
> https://jena.apache.org/documentation/javadoc/arq/org/apache/jena/riot/RDFParser.html#source(java.io.InputStream)
> 
> John
> 

So it does. Although here there is a new createHttpClient each time so 
there isn't a pool running out.

The OP says the code gets passed the HttpOp.execHttpGet call so the 
connection has been established.

John - what's the requestURL? The logs say the request is 3072 bytes 
(including headers) which is possible but unusually large.

It is the unpredictability that is odd.

Could you please breakpoint the process and see what code it is in?

	Andy

RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi Andy

> Rob's right - RDFParser does not close a resource that is passed into the
> parser. If given a resource, the caller is responsible - try-with-resources or
> similar is expected.

I was reading the javadocs and these state the InputStream will be closed when the parser is called

https://jena.apache.org/documentation/javadoc/arq/org/apache/jena/riot/RDFParser.html#source(java.io.InputStream)

John

RE: Jena hangs while reading HTTP stream

Posted by John Walker <jo...@semaku.com>.
Hi Andy

> -----Original Message-----
> From: Andy Seaborne <an...@apache.org>
> Sent: Monday, July 5, 2021 7:39 PM
> To: users@jena.apache.org
> Subject: Re: Jena hangs while reading HTTP stream
> 
> 
> On 05/07/2021 14:02, Martynas Jusevičius wrote:
>  > HTTPClient is not running out of connections? It is known to hang in such
> cases.
> 
> It is not reopening connections for one request.
> If parsing starts, it has the connection until the end.
> 
> On 05/07/2021 14:10, Rob Vesse wrote:
> > That's a really good suggestion.  In the normal code flow do you ever call
> stream.close() ? And is createHttpClient() re-using an existing HttpClient
> object ? And is the hang only happening after some requests have
> succeeded ?
> >
> > It is possible what is happening is that you aren't closing the stream (and I
> don't believe Jena's parsers ever close the stream for you) so after so many
> requests (10 I think by default) you are exhausting the max connections per
> route for the HTTP Client.  If that is the case wrapping the use of the stream
> in a try-with-resources block may be the solution.
> 
> Yes - try-with-resources.
> (And a transaction.)
> 
> If the code is in a loop, and connections are not managed properly HttpClient
> can run out of connections. And the OS kernel can run out of sockets for that
> matter if too many connections happen in too short a time. (Jena's test suite
> has to deal with this - and it's easier case.) This is not HttpClient's fault.
> 
> Rob's right - RDFParser does not close a resource that is passed into the
> parser. If given a resource, the caller is responsible - try-with-resources or
> similar is expected.

Ivan omitted it in his example code, but that's already the case.
So it's more like:

Model sub = ModelFactory.createDefaultModel();

try (TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)) {
    // The following part sometimes hangs:
    RDFParser.create()
        .source(stream)
        .lang(Lang.NTRIPLES)
        .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
        .parse(sub.getGraph());
} catch (Exception ex) {
    // Handle the exception
}

> 
> We are missing some facts.
> 
> 1/ What's sub.getGraph()?

The sub variable is instantiated a few lines before like so:

Model sub = ModelFactory.createDefaultModel();

> 
> 2/ (if reading to memory) Is the GC going crazy trying to free heap space
> because of other earlier work?

Perhaps, but we only observe the issue sporadically and cannot reproduce at will.

> 
> 3/ Does any data get processed then stop, or does it actually never start?

Hard to tell based on what is currently logged.

> 
> 4/ We haven't seen what the HttpClient setup is. It isn't the default.

Here's the code:

    private static HttpClient createHttpClient(String auth) {
        Header header = new BasicHeader(HttpHeaders.AUTHORIZATION, auth);
        List<Header> headers = Collections.singletonList(header);
        return HttpClients.custom().useSystemProperties().setDefaultHeaders(headers).build();
    }

I've implemented some changes to set timeouts on the default request configuration.
Hopefully that should at least prevent the application getting into this 'hung' state.

Cheers,
John

> 
>      Andy
> 
> >
> > Rob
> >
> > On 05/07/2021, 14:03, "Martynas Jusevičius" <ma...@atomgraph.com>
> wrote:
> >
> >      HTTPClient is not running out of connections? It is known to hang in such
> cases.
> >
> >      On Mon, Jul 5, 2021 at 2:58 PM james anderson <ja...@dydra.com>
> wrote:
> >      >
> >      > good afternoon;
> >      >
> >      > > On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org>
> wrote:
> >      > >
> >      > >
> >      > >
> >      > > On 05/07/2021 10:01, Ivan Lagunov wrote:
> >      > >> Hello,
> >      > >> We’re facing an issue with Jena reading n-triples stream over HTTP.
> In fact, our application hangs entirely while executing this piece of code:
> >      > >> Model sub = ModelFactory.createDefaultModel();
> >      > >> TypedInputStream stream = HttpOp.execHttpGet(requestURL,
> WebContent.contentTypeNTriples, createHttpClient(auth), null)
> >      > >> // The following part sometimes hangs:
> >      > >> RDFParser.create()
> >      > >>         .source(stream)
> >      > >>         .lang(Lang.NTRIPLES)
> >      > >>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
> >      > >>         .parse(sub.getGraph());
> >      > >> // This point is not reached
> >      > > >
> >      > >> The issue is not persistent, moreover it happens infrequently.
> >      > >
> >      > > Then it looks like the data has stopped arriving but the connection is
> still open. (or the system has gone in GC overload due to heap pressure.)
> >      > >
> >      > > Is intermittent on the same data? Or is the data changing? because
> maybe the data can't be written properly and the sender stops sending,
> though I'd expect the sender to close the connection (it's now in an unknown
> state and can't be reused).
> >      > >
> >      > >> When it occurs, the RDF store server (we use Dydra for that) logs a
> successful HTTP 200 response for our call (truncated for readability):
> >      > >> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples"
> "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"
> >      >
> >      > the situation involves an nginx proxy and an upstream sparql processor.
> >      >
> >      > >
> >      > > What do the fields mean?
> >      >
> >      > the line is an excerpt from an entry from the nginx request log. that
> line contains:
> >      >
> >      >   protocol  code  requestLength/responseLength
> upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt
> upstreamPort
> >      >
> >      > >
> >      > > Is that 3072 bytes sent (so far) of 55397664?
> >      > >
> >      > > If so, is Content-Length set (and then chunk encoding isn't needed).
> >      >
> >      > likely not, as the response is (i believe) that from a sparql request,
> which is emitted as it is generated.
> >      >
> >      > >
> >      > > Unfortunately, in HTTP, 200 really means "I started to send stuff", not
> "I completed sending stuff". There is no way in HTTP 1/1 to signal an error
> after starting the response.
> >      >
> >      > that is true, but there are indications in other logs which imply that the
> sparql processor believes the response to have been completely sent to
> nginx.
> >      > there are several reasons to believe this.
> >      > the times and the 200 response code in the nginx log indicate
> completion.
> >      > otherwise, it would either indicate that it timed out, or would include a
> 499 code, to the effect that the client closed the connection before the
> response was sent.
> >      > neither is the case.
> >      > in addition, the elapsed time is well below that for which nginx would
> time out an upstream connection.
> >      >
> >      > >
> >      > > The HttpClient - how is it configured?
> >      > >
> >      > >> So it looks like the RDF store successfully executes the SPARQL
> query, responds with HTTP 200 and starts transferring the data with the
> chunked encoding. Then something goes wrong when Jena processes the
> input stream. I expect there might be some timeout behind the scenes while
> Jena reads the stream
> >      > >
> >      > > Does any data reach the graph?
> >      > >
> >      > > There is no timeout at the client end - otherwise you would get an
> exception. The parser is reading the input stream from Apache HttpClient. If
> it hangs, it's because the data has stopped arriving but the connection is still
> open.
> >      > >
> >      > > You could try replacing .parse(graph) with parse(StreamRDF) and
> plug in a logging StreamRDF so you can see the progress, either sending on
> data to the graph or for investigation, merely logging.
> >      > >
> >      > > In HTTP 1.1, a streamed response requires chunk encoding only
> when the Content-Length isn't given.
> >      >
> >      > i believe, the content length is not given.
> >      >
> >      > >
> >      > > >
> >      > > , and it causes it to wait indefinitely. At the same time
> ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are
> logged.
> >      > >> Is there a way to configure the timeout behavior for the underlying
> Jena logic of processing HTTP stream? Ideally we want to abort the request if
> it times out and then retry it a few times until it succeeds.
> >      > >
> >      > > The HttpClient determines the transfer.
> >      > >
> >      > >    Andy
> >      > >
> >      > > FYI: RDFConnectionRemote is an abstraction to make this a little
> easier. No need to go to the low-level HttpOp.
> >      > >
> >      > >
> >      > > FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the
> HTTP code. There has to be some change anyway to get HTTP/2  (Apache
> HttpClient v5+, not v4, has HTTP/2 support).
> >      > >
> >      > > This will include a new Graph Store Protocol client.
> >      > >
> >      > >> Met vriendelijke groet, with kind regards,
> >      > >> Ivan Lagunov
> >      > >> Technical Lead / Software Architect
> >      > >> Skype: lagivan
> >      > >> Semaku B.V.
> >      > >> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
> >      >
> >
> >
> >
> >

Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.
On 05/07/2021 14:02, Martynas Jusevičius wrote:
 > HTTPClient is not running out of connections? It is known to hang in 
such cases.

It is not reopening connections for one request.
If parsing starts, it has the connection until the end.

On 05/07/2021 14:10, Rob Vesse wrote:
> That's a really good suggestion.  In the normal code flow do you ever call stream.close() ? And is createHttpClient() re-using an existing HttpClient object ? And is the hang only happening after some requests have succeeded ?
> 
> It is possible what is happening is that you aren't closing the stream (and I don't believe Jena's parsers ever close the stream for you) so after so many requests (10 I think by default) you are exhausting the max connections per route for the HTTP Client.  If that is the case wrapping the use of the stream in a try-with-resources block may be the solution.

Yes - try-with-resources.
(And a transaction.)

If the code is in a loop, and connections are not managed properly 
HttpClient can run out of connections. And the OS kernel can run out of 
sockets for that matter if too many connections happen in too short a 
time. (Jena's test suite has to deal with this - and it's easier case.)
This is not HttpClient's fault.

Rob's right - RDFParser does not close a resource that is passed into 
the parser. If given a resource, the caller is responsible - 
try-with-resources or similar is expected.

We are missing some facts.

1/ What's sub.getGraph()?

2/ (if reading to memory) Is the GC going crazy trying to free heap 
space because of other earlier work?

3/ Does any data get processed then stop, or does it actually never start?

4/ We haven't seen what the HttpClient setup is. It isn't the default.

     Andy

> 
> Rob
> 
> On 05/07/2021, 14:03, "Martynas Jusevičius" <ma...@atomgraph.com> wrote:
> 
>      HTTPClient is not running out of connections? It is known to hang in such cases.
> 
>      On Mon, Jul 5, 2021 at 2:58 PM james anderson <ja...@dydra.com> wrote:
>      >
>      > good afternoon;
>      >
>      > > On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org> wrote:
>      > >
>      > >
>      > >
>      > > On 05/07/2021 10:01, Ivan Lagunov wrote:
>      > >> Hello,
>      > >> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
>      > >> Model sub = ModelFactory.createDefaultModel();
>      > >> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
>      > >> // The following part sometimes hangs:
>      > >> RDFParser.create()
>      > >>         .source(stream)
>      > >>         .lang(Lang.NTRIPLES)
>      > >>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>      > >>         .parse(sub.getGraph());
>      > >> // This point is not reached
>      > > >
>      > >> The issue is not persistent, moreover it happens infrequently.
>      > >
>      > > Then it looks like the data has stopped arriving but the connection is still open. (or the system has gone in GC overload due to heap pressure.)
>      > >
>      > > Is intermittent on the same data? Or is the data changing? because maybe the data can't be written properly and the sender stops sending, though I'd expect the sender to close the connection (it's now in an unknown state and can't be reused).
>      > >
>      > >> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
>      > >> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"
>      >
>      > the situation involves an nginx proxy and an upstream sparql processor.
>      >
>      > >
>      > > What do the fields mean?
>      >
>      > the line is an excerpt from an entry from the nginx request log. that line contains:
>      >
>      >   protocol  code  requestLength/responseLength  upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt  upstreamPort
>      >
>      > >
>      > > Is that 3072 bytes sent (so far) of 55397664?
>      > >
>      > > If so, is Content-Length set (and then chunk encoding isn't needed).
>      >
>      > likely not, as the response is (i believe) that from a sparql request, which is emitted as it is generated.
>      >
>      > >
>      > > Unfortunately, in HTTP, 200 really means "I started to send stuff", not "I completed sending stuff". There is no way in HTTP 1/1 to signal an error after starting the response.
>      >
>      > that is true, but there are indications in other logs which imply that the sparql processor believes the response to have been completely sent to nginx.
>      > there are several reasons to believe this.
>      > the times and the 200 response code in the nginx log indicate completion.
>      > otherwise, it would either indicate that it timed out, or would include a 499 code, to the effect that the client closed the connection before the response was sent.
>      > neither is the case.
>      > in addition, the elapsed time is well below that for which nginx would time out an upstream connection.
>      >
>      > >
>      > > The HttpClient - how is it configured?
>      > >
>      > >> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream
>      > >
>      > > Does any data reach the graph?
>      > >
>      > > There is no timeout at the client end - otherwise you would get an exception. The parser is reading the input stream from Apache HttpClient. If it hangs, it's because the data has stopped arriving but the connection is still open.
>      > >
>      > > You could try replacing .parse(graph) with parse(StreamRDF) and plug in a logging StreamRDF so you can see the progress, either sending on data to the graph or for investigation, merely logging.
>      > >
>      > > In HTTP 1.1, a streamed response requires chunk encoding only when the Content-Length isn't given.
>      >
>      > i believe, the content length is not given.
>      >
>      > >
>      > > >
>      > > , and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.
>      > >> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.
>      > >
>      > > The HttpClient determines the transfer.
>      > >
>      > >    Andy
>      > >
>      > > FYI: RDFConnectionRemote is an abstraction to make this a little easier. No need to go to the low-level HttpOp.
>      > >
>      > >
>      > > FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the HTTP code. There has to be some change anyway to get HTTP/2  (Apache HttpClient v5+, not v4, has HTTP/2 support).
>      > >
>      > > This will include a new Graph Store Protocol client.
>      > >
>      > >> Met vriendelijke groet, with kind regards,
>      > >> Ivan Lagunov
>      > >> Technical Lead / Software Architect
>      > >> Skype: lagivan
>      > >> Semaku B.V.
>      > >> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
>      >
> 
> 
> 
> 

Re: Jena hangs while reading HTTP stream

Posted by Rob Vesse <rv...@dotnetrdf.org>.
That's a really good suggestion.  In the normal code flow do you ever call stream.close() ? And is createHttpClient() re-using an existing HttpClient object ? And is the hang only happening after some requests have succeeded ?

It is possible what is happening is that you aren't closing the stream (and I don't believe Jena's parsers ever close the stream for you) so after so many requests (10 I think by default) you are exhausting the max connections per route for the HTTP Client.  If that is the case wrapping the use of the stream in a try-with-resources block may be the solution.

Rob

On 05/07/2021, 14:03, "Martynas Jusevičius" <ma...@atomgraph.com> wrote:

    HTTPClient is not running out of connections? It is known to hang in such cases.

    On Mon, Jul 5, 2021 at 2:58 PM james anderson <ja...@dydra.com> wrote:
    >
    > good afternoon;
    >
    > > On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org> wrote:
    > >
    > >
    > >
    > > On 05/07/2021 10:01, Ivan Lagunov wrote:
    > >> Hello,
    > >> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
    > >> Model sub = ModelFactory.createDefaultModel();
    > >> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
    > >> // The following part sometimes hangs:
    > >> RDFParser.create()
    > >>         .source(stream)
    > >>         .lang(Lang.NTRIPLES)
    > >>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
    > >>         .parse(sub.getGraph());
    > >> // This point is not reached
    > > >
    > >> The issue is not persistent, moreover it happens infrequently.
    > >
    > > Then it looks like the data has stopped arriving but the connection is still open. (or the system has gone in GC overload due to heap pressure.)
    > >
    > > Is intermittent on the same data? Or is the data changing? because maybe the data can't be written properly and the sender stops sending, though I'd expect the sender to close the connection (it's now in an unknown state and can't be reused).
    > >
    > >> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
    > >> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"
    >
    > the situation involves an nginx proxy and an upstream sparql processor.
    >
    > >
    > > What do the fields mean?
    >
    > the line is an excerpt from an entry from the nginx request log. that line contains:
    >
    >   protocol  code  requestLength/responseLength  upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt  upstreamPort
    >
    > >
    > > Is that 3072 bytes sent (so far) of 55397664?
    > >
    > > If so, is Content-Length set (and then chunk encoding isn't needed).
    >
    > likely not, as the response is (i believe) that from a sparql request, which is emitted as it is generated.
    >
    > >
    > > Unfortunately, in HTTP, 200 really means "I started to send stuff", not "I completed sending stuff". There is no way in HTTP 1/1 to signal an error after starting the response.
    >
    > that is true, but there are indications in other logs which imply that the sparql processor believes the response to have been completely sent to nginx.
    > there are several reasons to believe this.
    > the times and the 200 response code in the nginx log indicate completion.
    > otherwise, it would either indicate that it timed out, or would include a 499 code, to the effect that the client closed the connection before the response was sent.
    > neither is the case.
    > in addition, the elapsed time is well below that for which nginx would time out an upstream connection.
    >
    > >
    > > The HttpClient - how is it configured?
    > >
    > >> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream
    > >
    > > Does any data reach the graph?
    > >
    > > There is no timeout at the client end - otherwise you would get an exception. The parser is reading the input stream from Apache HttpClient. If it hangs, it's because the data has stopped arriving but the connection is still open.
    > >
    > > You could try replacing .parse(graph) with parse(StreamRDF) and plug in a logging StreamRDF so you can see the progress, either sending on data to the graph or for investigation, merely logging.
    > >
    > > In HTTP 1.1, a streamed response requires chunk encoding only when the Content-Length isn't given.
    >
    > i believe, the content length is not given.
    >
    > >
    > > >
    > > , and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.
    > >> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.
    > >
    > > The HttpClient determines the transfer.
    > >
    > >    Andy
    > >
    > > FYI: RDFConnectionRemote is an abstraction to make this a little easier. No need to go to the low-level HttpOp.
    > >
    > >
    > > FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the HTTP code. There has to be some change anyway to get HTTP/2  (Apache HttpClient v5+, not v4, has HTTP/2 support).
    > >
    > > This will include a new Graph Store Protocol client.
    > >
    > >> Met vriendelijke groet, with kind regards,
    > >> Ivan Lagunov
    > >> Technical Lead / Software Architect
    > >> Skype: lagivan
    > >> Semaku B.V.
    > >> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
    >





Re: Jena hangs while reading HTTP stream

Posted by Martynas Jusevičius <ma...@atomgraph.com>.
HTTPClient is not running out of connections? It is known to hang in such cases.

On Mon, Jul 5, 2021 at 2:58 PM james anderson <ja...@dydra.com> wrote:
>
> good afternoon;
>
> > On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org> wrote:
> >
> >
> >
> > On 05/07/2021 10:01, Ivan Lagunov wrote:
> >> Hello,
> >> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
> >> Model sub = ModelFactory.createDefaultModel();
> >> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
> >> // The following part sometimes hangs:
> >> RDFParser.create()
> >>         .source(stream)
> >>         .lang(Lang.NTRIPLES)
> >>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
> >>         .parse(sub.getGraph());
> >> // This point is not reached
> > >
> >> The issue is not persistent, moreover it happens infrequently.
> >
> > Then it looks like the data has stopped arriving but the connection is still open. (or the system has gone in GC overload due to heap pressure.)
> >
> > Is intermittent on the same data? Or is the data changing? because maybe the data can't be written properly and the sender stops sending, though I'd expect the sender to close the connection (it's now in an unknown state and can't be reused).
> >
> >> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
> >> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"
>
> the situation involves an nginx proxy and an upstream sparql processor.
>
> >
> > What do the fields mean?
>
> the line is an excerpt from an entry from the nginx request log. that line contains:
>
>   protocol  code  requestLength/responseLength  upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt  upstreamPort
>
> >
> > Is that 3072 bytes sent (so far) of 55397664?
> >
> > If so, is Content-Length set (and then chunk encoding isn't needed).
>
> likely not, as the response is (i believe) that from a sparql request, which is emitted as it is generated.
>
> >
> > Unfortunately, in HTTP, 200 really means "I started to send stuff", not "I completed sending stuff". There is no way in HTTP 1/1 to signal an error after starting the response.
>
> that is true, but there are indications in other logs which imply that the sparql processor believes the response to have been completely sent to nginx.
> there are several reasons to believe this.
> the times and the 200 response code in the nginx log indicate completion.
> otherwise, it would either indicate that it timed out, or would include a 499 code, to the effect that the client closed the connection before the response was sent.
> neither is the case.
> in addition, the elapsed time is well below that for which nginx would time out an upstream connection.
>
> >
> > The HttpClient - how is it configured?
> >
> >> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream
> >
> > Does any data reach the graph?
> >
> > There is no timeout at the client end - otherwise you would get an exception. The parser is reading the input stream from Apache HttpClient. If it hangs, it's because the data has stopped arriving but the connection is still open.
> >
> > You could try replacing .parse(graph) with parse(StreamRDF) and plug in a logging StreamRDF so you can see the progress, either sending on data to the graph or for investigation, merely logging.
> >
> > In HTTP 1.1, a streamed response requires chunk encoding only when the Content-Length isn't given.
>
> i believe, the content length is not given.
>
> >
> > >
> > , and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.
> >> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.
> >
> > The HttpClient determines the transfer.
> >
> >    Andy
> >
> > FYI: RDFConnectionRemote is an abstraction to make this a little easier. No need to go to the low-level HttpOp.
> >
> >
> > FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the HTTP code. There has to be some change anyway to get HTTP/2  (Apache HttpClient v5+, not v4, has HTTP/2 support).
> >
> > This will include a new Graph Store Protocol client.
> >
> >> Met vriendelijke groet, with kind regards,
> >> Ivan Lagunov
> >> Technical Lead / Software Architect
> >> Skype: lagivan
> >> Semaku B.V.
> >> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
>

Re: Jena hangs while reading HTTP stream

Posted by james anderson <ja...@dydra.com>.
good afternoon;

> On 2021-07-05, at 12:36:20, Andy Seaborne <an...@apache.org> wrote:
> 
> 
> 
> On 05/07/2021 10:01, Ivan Lagunov wrote:
>> Hello,
>> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
>> Model sub = ModelFactory.createDefaultModel();
>> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
>> // The following part sometimes hangs:
>> RDFParser.create()
>>         .source(stream)
>>         .lang(Lang.NTRIPLES)
>>         .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>>         .parse(sub.getGraph());
>> // This point is not reached
> >
>> The issue is not persistent, moreover it happens infrequently.
> 
> Then it looks like the data has stopped arriving but the connection is still open. (or the system has gone in GC overload due to heap pressure.)
> 
> Is intermittent on the same data? Or is the data changing? because maybe the data can't be written properly and the sender stops sending, though I'd expect the sender to close the connection (it's now in an unknown state and can't be reused).
> 
>> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
>> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"

the situation involves an nginx proxy and an upstream sparql processor.

> 
> What do the fields mean?

the line is an excerpt from an entry from the nginx request log. that line contains:

  protocol  code  requestLength/responseLength  upstreamElapsedTime/clientElapsedTIme  acceptType  -  -  clientAgemt  upstreamPort

> 
> Is that 3072 bytes sent (so far) of 55397664?
> 
> If so, is Content-Length set (and then chunk encoding isn't needed).

likely not, as the response is (i believe) that from a sparql request, which is emitted as it is generated.

> 
> Unfortunately, in HTTP, 200 really means "I started to send stuff", not "I completed sending stuff". There is no way in HTTP 1/1 to signal an error after starting the response.

that is true, but there are indications in other logs which imply that the sparql processor believes the response to have been completely sent to nginx.
there are several reasons to believe this.
the times and the 200 response code in the nginx log indicate completion.
otherwise, it would either indicate that it timed out, or would include a 499 code, to the effect that the client closed the connection before the response was sent.
neither is the case.
in addition, the elapsed time is well below that for which nginx would time out an upstream connection.

> 
> The HttpClient - how is it configured?
> 
>> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream
> 
> Does any data reach the graph?
> 
> There is no timeout at the client end - otherwise you would get an exception. The parser is reading the input stream from Apache HttpClient. If it hangs, it's because the data has stopped arriving but the connection is still open.
> 
> You could try replacing .parse(graph) with parse(StreamRDF) and plug in a logging StreamRDF so you can see the progress, either sending on data to the graph or for investigation, merely logging.
> 
> In HTTP 1.1, a streamed response requires chunk encoding only when the Content-Length isn't given.

i believe, the content length is not given.

> 
> >
> , and it causes it to wait indefinitely. At the same time ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors are logged.
>> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.
> 
> The HttpClient determines the transfer.
> 
>    Andy
> 
> FYI: RDFConnectionRemote is an abstraction to make this a little easier. No need to go to the low-level HttpOp.
> 
> 
> FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the HTTP code. There has to be some change anyway to get HTTP/2  (Apache HttpClient v5+, not v4, has HTTP/2 support).
> 
> This will include a new Graph Store Protocol client.
> 
>> Met vriendelijke groet, with kind regards,
>> Ivan Lagunov
>> Technical Lead / Software Architect
>> Skype: lagivan
>> Semaku B.V.
>> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com


Re: Jena hangs while reading HTTP stream

Posted by Andy Seaborne <an...@apache.org>.

On 05/07/2021 10:01, Ivan Lagunov wrote:
> Hello,
> 
> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
> 
> 
> Model sub = ModelFactory.createDefaultModel();
> 
> TypedInputStream stream = HttpOp.execHttpGet(requestURL, WebContent.contentTypeNTriples, createHttpClient(auth), null)
> 
> // The following part sometimes hangs:
> RDFParser.create()
>          .source(stream)
>          .lang(Lang.NTRIPLES)
>          .errorHandler(ErrorHandlerFactory.errorHandlerStrict)
>          .parse(sub.getGraph());
> // This point is not reached
 >
> The issue is not persistent, moreover it happens infrequently.

Then it looks like the data has stopped arriving but the connection is 
still open. (or the system has gone in GC overload due to heap pressure.)

Is intermittent on the same data? Or is the data changing? because maybe 
the data can't be written properly and the sender stops sending, though 
I'd expect the sender to close the connection (it's now in an unknown 
state and can't be reused).

> When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"

What do the fields mean?

Is that 3072 bytes sent (so far) of 55397664?

If so, is Content-Length set (and then chunk encoding isn't needed).

Unfortunately, in HTTP, 200 really means "I started to send stuff", not 
"I completed sending stuff". There is no way in HTTP 1/1 to signal an 
error after starting the response.

The HttpClient - how is it configured?

> So it looks like the RDF store successfully executes the SPARQL query, responds with HTTP 200 and starts transferring the data with the chunked encoding. Then something goes wrong when Jena processes the input stream. I expect there might be some timeout behind the scenes while Jena reads the stream

Does any data reach the graph?

There is no timeout at the client end - otherwise you would get an 
exception. The parser is reading the input stream from Apache 
HttpClient. If it hangs, it's because the data has stopped arriving but 
the connection is still open.

You could try replacing .parse(graph) with parse(StreamRDF) and plug in 
a logging StreamRDF so you can see the progress, either sending on data 
to the graph or for investigation, merely logging.

In HTTP 1.1, a streamed response requires chunk encoding only when the 
Content-Length isn't given.

 >
, and it causes it to wait indefinitely. At the same time 
ErrorHandlerFactory.errorHandlerStrict does not help at all – no errors 
are logged.
> 
> Is there a way to configure the timeout behavior for the underlying Jena logic of processing HTTP stream? Ideally we want to abort the request if it times out and then retry it a few times until it succeeds.

The HttpClient determines the transfer.

     Andy

FYI: RDFConnectionRemote is an abstraction to make this a little easier. 
No need to go to the low-level HttpOp.


FYI: Jena 4.mumble.0 is likely to change to using jena.net.http as the 
HTTP code. There has to be some change anyway to get HTTP/2  (Apache 
HttpClient v5+, not v4, has HTTP/2 support).

This will include a new Graph Store Protocol client.

> Met vriendelijke groet, with kind regards,
> 
> Ivan Lagunov
> Technical Lead / Software Architect
> Skype: lagivan
> 
> Semaku B.V.
> Torenallee 20 (SFJ3D) • 5617 BC Eindhoven • www.semaku.com
> 

Re: Jena hangs while reading HTTP stream

Posted by james anderson <ja...@dydra.com>.
> On 2021-07-05, at 11:01:34, Ivan Lagunov <iv...@semaku.com> wrote:
> 
> Hello,
> 
> We’re facing an issue with Jena reading n-triples stream over HTTP. In fact, our application hangs entirely while executing this piece of code:
> 
> ...
> 
> The issue is not persistent, moreover it happens infrequently. When it occurs, the RDF store server (we use Dydra for that) logs a successful HTTP 200 response for our call (truncated for readability):
> HTTP/1.1" 200 3072/55397664 10.676/10.828 "application/n-triples" "-" "-" "Apache-Jena-ARQ/3.17.0" "127.0.0.1:8104"

an additional detail appears in other nginx log entries.
the two values "10.676/10.828", above, are nginx's upstream response time and the client connection time.
it can be the case that, for problematic requests, the second value is significantly higher than the first.
this would indicate that nginx has received a complete response from the upstream connection, but required a much longer time to complete sending the data to the client.
as, however, none of the examined entries indicated a 499 status, it appears that the client was sent all data.

this may indicate some anomaly in the encoding, respective decoding, for which a stack trace at the point of the "timeout" would be a valuable diagnostic.
---
james anderson | james@dydra.com | https://dydra.com