Setting HTTP client options for federation requests with rdf4j-workbench

[tkuhn]

Hi all,

I am using the latest version of the RDF4J Workbench via Docker, and I am wondering whether there is a way to set HTTP client options (version, pooling, timeouts) for the connections made when federation is applied (so the request to URL in "service <URL> { ... }"?

We have a use case where we use this federation extensively, and it normally works well, but starts to hang after a number of hours or days. My suspicion is that it has something to do with the HTTP requests triggered by the service keywords, but I couldn't find any way how I could play around with the options of that HTTP client. Any ideas?

Tobias

[hmottestad]

I'm not sure what is possible. I'll take a look and get back to you.

It does sound like there is a missing timeout somewhere. I've experienced that myself with HttpClient where a system seems stable enough for a few days until all the connections are busy waiting for servers that will never respond.

One thing you can double check on your side is that you are closing all results iterators and closing all connections after you're done with them.

[tkuhn]

Thank you for your reply and help!

After investigating my particular problem a bit more, I realized that running several federated queries with overlapping repo URLs (on the same rdfj4-workbench instance; not sure that matters though) can get you into what seems to be a deadlock if they are fired in close succession to each other. This deadlock then persists, doesn't timeout, and doesn't produce any error messages.

Being able to set a timeout likely solves this issue, if my understanding of the situation is correct.

If more investigation is needed, I can try to make a simple reproducible example.

[tkuhn]

wrt closing connections, yes I have already looked into that, and I am closing them all properly as far as I can see.

[tkuhn]

I found a workaround for this via the config of the Nginx HTTP server running in front of rdf4j-workbench:

limit_conn_zone $uri zone=uri:10m;

server {
    ...
    location / {
        ...
        # This line limits concurrent requests per URI/repo to 1:
        limit_conn uri 1;
        proxy_pass http://127.0.1.1:8080/;
    }
}

URIs like https://example.com/rdf4j-server/repositories/demo (without query part) correspond to repos, so that's why this effectively makes sure that the same repo isn't accessed by two requests at the same time, which could cause a deadlock.

I have been running the server like this for 6 days now, and all the problems have gone. Except that I am now getting "503 Service Temporarily Unavailable" errors under high load. This is not per se a problem (it's good that it fails fast), but the overall performance of rdf4j-workbench is now quite seriously reduced, I believe, by the fact that it cannot run concurrent queries anymore.

So, it's only a workaround and not a fix, and it would be great if this issue can be somehow addressed on the RDF4J side (as I am now even more confident than before that there is an issue there). Also, I haven't really stress-tested it, so it can be that the above setting can still trigger deadlocks, but just makes them less likely.

Of course, if there is anything I can do to help fix this issue, I am more than happy to do so! Even looking at your source code, if you can point me to the place where I should start looking.

And lastly, let me take the opportunity to thank you for providing these incredibly powerful and immensely useful pieces of software! RDF4J is absolutely amazing 🙂

[hmottestad]

I believe that this is the main culprit:

rdf4j/core/http/client/src/main/java/org/eclipse/rdf4j/http/client/SharedHttpClientSessionManager.java

Line 327 in 5c956e1

.setDefaultRequestConfig(RequestConfig.custom().setCookieSpec(CookieSpecs.STANDARD).build())

We should add support for users to configure the timeout. Maybe something like this:

	private CloseableHttpClient createHttpClient() {
		HttpClientBuilder nextHttpClientBuilder = httpClientBuilder;
		if (nextHttpClientBuilder != null) {
			return nextHttpClientBuilder.build();
		}

		RequestConfig requestConfig = RequestConfig.custom()
				.setConnectTimeout(Integer.parseInt(
						System.getProperty(
								"org.eclipse.rdf4j.client.http.connectionTimeout",
								String.valueOf(24 * 60 * 60 * 1000))
				))
				.setConnectionRequestTimeout(Integer.parseInt(
						System.getProperty(
								"org.eclipse.rdf4j.client.http.connectionRequestTimeout",
								String.valueOf(24 * 60 * 60 * 1000))
				))
				.setSocketTimeout(Integer.parseInt(
						System.getProperty(
								"org.eclipse.rdf4j.client.http.socketTimeout",
								String.valueOf(24 * 60 * 60 * 1000))
				))
				.setCookieSpec(CookieSpecs.STANDARD)
				.build();

		return HttpClientBuilder.create()
				.evictExpiredConnections()
				.setRetryHandler(retryHandlerStale)
				.setServiceUnavailableRetryStrategy(serviceUnavailableRetryHandler)
				.useSystemProperties()
				.setDefaultRequestConfig(requestConfig)
				.build();
	}

[tkuhn]

Great to see that you found a potential solution. I'd be happy to test it on my side, if you want to provide me with a patch or branch with this code change.

[hmottestad]

You can take a look here: #5125

[tkuhn]

Super, thanks, will try to find time to try it out the next few days and will let you know!

[tkuhn]

I did some local tests and I can confirm that with rdf4j-workbench:5.0.3-SNAPSHOT I can no longer reproduce the errors that I was getting with rdf4j-workbench:5.0.2. I now get timeout or HTTP pooling errors after the specified timeouts run out, instead of permanent deadlocks. So the problem seems to be resolved indeed!

I was only wondering why the default timeouts seem to be set to 24h, instead of a smaller more practical amount of time?

Thanks a lot for this fast fix!

[tkuhn]

No, I did it with curl request to the end point via the command line.

Actually, trying it out some more, it seems I had another instance of deadlock that didn't time out even with the new setting. But I am not sure, it might have been something else. I have to do it again in a more systematic fashion.

I will try to make a script that loads a fresh database and then runs queries to consistently reproduce the problem. That will be able to better tell us whether the problem is properly resolved, and also possibly find out more about the problem in the first place.

I will get back to you when I have that script and some results. Probably some time next week.

[hmottestad]

Could you paste the curl command so I can see what is triggered on the sever side w.r.t. any resources that might not get closed automatically?

[tkuhn]

It's a bit complicated as with the URLs I am using there are some redirects involved that depend on my particular setting. But it boils down to curl commands like this one to our server (accessing one repo and connecting to two other repos via the service keyword):

$ curl 'https://query.knowledgepixels.com/repo/empty?query=select%20%2A%20where%20%7B%0A%20%20service%20%3Chttps%3A%2F%2Fquery.knowledgepixels.com%2Frepo%2Ffull%3E%20%7B%20select%20%2A%20%7B%20%3Fs1%20%3Fp1%20%3Fo1%20%7D%20limit%2010%20%7D%0A%20%20service%20%3Chttps%3A%2F%2Fquery.knowledgepixels.com%2Frepo%2Fmeta%3E%20%7B%20select%20%2A%20%7B%20%3Fs2%20%3Fp2%20%3Fo2%20%7D%20limit%2010%20%7D%0A%7D'

If you want to try it out locally, it would probably have to be something like this (assuming you have 3 repos named repo1, repo2, and repo3):

$ curl 'http://localhost:8080/rdf4j-server/repositories/repo1?select%20%2A%20where%20%7B%0A%20%20service%20%3Chttp%3A%2F%2Flocalhost%3A8080%2Frdf4j-server%2Frepositories%2Frepo2%3E%20%7B%20select%20%2A%20%7B%20%3Fs1%20%3Fp1%20%3Fo1%20%7D%20limit%2010%20%7D%0A%20%20service%20%3Chttp%3A%2F%2Flocalhost%3A8080%2Frdf4j-server%2Frepositories%2Frepo3%3E%20%7B%20select%20%2A%20%7B%20%3Fs2%20%3Fp2%20%3Fo2%20%7D%20limit%2010%20%7D%0A%7D'

Individually they work but if I run many of them in close succession with a loop like this:

$ for i in {1..10}; do (curl ... &); done

Then they start getting stuck.

[hmottestad]

That's very interesting. You're running them one after the other and waiting for the results from the previous one. So the previous query should be closing everything and there shouldn't really be anything from one query that holds up the next one.

I wonder if the query is running into a rate limit at the remote SERVICE endpoint.

What happens when you reduce the timeouts? Do queries return an error because the Apache HttpClient connection timed out? Do you see any errors being logged in the workbench/server logs?

I'm wondering if this is an underlying issue in RDF4J, like if something that should be closed isn't getting closed. Maybe you could try out setting the keep-alive system property for the Apache HttpClient? It should be http.keepAlive. You can see all available properties here: https://cwiki.apache.org/confluence/display/HTTPCOMPONENTS/HttpClientConfiguration

[tkuhn]

No, the curl queries run in parallel and are not waiting for the previous one to complete. Note the & that I put at the end of the curl command in the for loop.

I am pretty sure that the queries are not hanging in the HTTP client, as at some point I logged how the messages are passed, and they were still being sent to the rdf4j-server but the responses stopped coming back.

Anyway, I will try to reproduce this with a small script as I wrote above, and then I can also experiment with different timeout values etc.

[tkuhn]

OK, I managed to reproduce the problem in a few simple steps on a fresh RDF4J instance. See here: https://github.com/tkuhn/rdf4j-timeout-test

It doesn't even involve issuing many queries in close succession. A single slighlty complex query is sufficient to trigger it (Query 2). In the case of the latest release, it hangs forever. In the case of the improved branch with the timeouts, it properly times out, but in either case it remains blocked and also simpler queries (like Query 1) no longer work.

I hope that repo has all the things needed to reproduce it on your side with minimal effort. If there is anything I can do to improve this test, let me know.

[hmottestad]

Thanks.

Impressive that you've managed to trigger this with a single query. That should really help to try to understand what's going on.