ema added a comment.
In esams, the WDQS query above fails with a java exception after 60s:
$ curl -v -w '%{time_connect}:%{time_starttransfer}:%{time_total}'
'https://query.wikidata.org/sparql?query=SELECT%20%0A%20%20%3Fitem%20%3Frelative%20%3FitemLabel%20%20%3FrelativeLabel%20%0A%7B%0A%20%20%20%20%3Fitem%20wdt%3AP40%20%3Frelative%20.%0A%20%20%20%20%3Fitem%20wdt%3AP31%20wd%3AQ5%20%3B%20wdt%3AP21%20wd%3AQ6581097.%0A%20%20%20%20%3Frelative%20wdt%3AP31%20wd%3AQ5%20.%0A%20%20%20%20MINUS%20%7B%20%3Frelative%20wdt%3AP22%20%3Fitem%20%7D%0A%7D'
[...]
< HTTP/2 200
[...]
<?xml version='1.0' encoding='UTF-8'?>
<sparql xmlns='http://www.w3.org/2005/sparql-results#'>
<head>
<variable name='item'/>
<variable name='relative'/>
<variable name='itemLabel'/>
<variable name='relativeLabel'/>
</head>
<results>
[...]
<result>
<binding name='item'>
<uri>http://www.wikidata.org/entity/Q14949397</uri>
</binding>
<binding name='relative'>
<uri>http://www.wikidata.org/entity/Q25350126</uri>
</binding>
</result>
<result>
<binding name='item'>
<uri>http://www.wikidata.org/entity/Q5232136</uri>
</binding>
<binding name=SPARQL-QUERY: queryStr=SELECT
?item ?relative ?itemLabel ?relativeLabel
{
?item wdt:P40 ?relative .
?item wdt:P31 wd:Q5 ; wdt:P21 wd:Q6581097.
?relative wdt:P31 wd:Q5 .
MINUS { ?relative wdt:P22 ?item }
}
[...]
java.util.concurrent.TimeoutException
at java.util.concurrent.FutureTask.get(FutureTask.java:205)
at
com.bigdata.rdf.sail.webapp.BigdataServlet.submitApiTask(BigdataServlet.java:292)
at
com.bigdata.rdf.sail.webapp.QueryServlet.doSparqlQuery(QueryServlet.java:678)
at
com.bigdata.rdf.sail.webapp.QueryServlet.doGet(QueryServlet.java:290)
at
com.bigdata.rdf.sail.webapp.RESTServlet.doGet(RESTServlet.java:240)
at
com.bigdata.rdf.sail.webapp.MultiTenancyServlet.doGet(MultiTenancyServlet.java:273)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655)
at
org.wikidata.query.rdf.blazegraph.throttling.ThrottlingFilter.doFilter(ThrottlingFilter.java:354)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:49)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.wikidata.query.rdf.blazegraph.filters.ClientIPFilter.doFilter(ClientIPFilter.java:43)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.wikidata.query.rdf.blazegraph.filters.RealAgentFilter.doFilter(RealAgentFilter.java:33)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220)
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.Server.handle(Server.java:503)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at
org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
at org.eclipse.jetty.util.thread.Reserved^M100 396k 0 396k
0 0 6663 0 --:--:-- 0:01:00 --:--:-- 88463
* Connection #0 to host query.wikidata.org left intact
ThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
at java.lang.Thread.run(Thread.java:748)
0.049749:60.739665:60.893322
The very last timing line is added by `curl -w
'%{time_connect}:%{time_starttransfer}:%{time_total}'`. The response looks like
a error to me, but it does get cached by our CDN as WDQS responds with HTTP/200
and headers that allow cacheability. WDQS really should not return errors as
200.
In ulsfo, which was recently converted from varnish to ATS, the request times
out at the ATS layer after 15 seconds:
$ curl -v --resolve query.wikidata.org:443:198.35.26.96 -w
'%{time_connect}:%{time_starttransfer}:%{time_total}'
'https://query.wikidata.org/sparql?query=SELECT%20%0A%20%20%3Fitem%20%3Frelative%20%3FitemLabel%20%20%3FrelativeLabel%20%0A%7B%0A%20%20%20%20%3Fitem%20wdt%3AP40%20%3Frelative%20.%0A%20%20%20%20%3Fitem%20wdt%3AP31%20wd%3AQ5%20%3B%20wdt%3AP21%20wd%3AQ6581097.%0A%20%20%20%20%3Frelative%20wdt%3AP31%20wd%3AQ5%20.%0A%20%20%20%20MINUS%20%7B%20%3Frelative%20wdt%3AP22%20%3Fitem%20%7D%0A%7D'
[...]
< HTTP/2 504
[...]
upstream request timeout
0.166605:15.713529:15.714274
We should likely align varnish and ATS timeouts, but in this very case I
think it's better to respond with a 504 than return a error as 200 and cache it.
TASK DETAIL
https://phabricator.wikimedia.org/T236500
EMAIL PREFERENCES
https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: ema
Cc: ema, jijiki, Aklapper, Bugreporter, darthmon_wmde, Legado_Shulgin,
DannyS712, Nandana, Davinaclare77, Qtn1293, Techguru.pc, Lahi, Gq86,
Lucas_Werkmeister_WMDE, GoranSMilovanovic, Th3d3v1ls, Hfbn0, QZanden, EBjune,
merbst, LawExplorer, Zppix, _jensen, rosalieper, Jonas, Xmlizer, Wong128hk,
jkroll, Smalyshev, Wikidata-bugs, Jdouglas, aude, Tobias1984, Manybubbles,
Southparkfan, faidon, Mbch331, Jay8g, fgiunchedi
_______________________________________________
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs
