You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@druid.apache.org by "paul-rogers (via GitHub)" <gi...@apache.org> on 2023/02/07 20:29:02 UTC
[GitHub] [druid] paul-rogers opened a new issue, #13765: Router does not log failed query requests
paul-rogers opened a new issue, #13765:
URL: https://github.com/apache/druid/issues/13765
### Affected Version
6.0.0-SNAPSHOT
### Description
I am testing the new catalog functionality. To do this, I send a request that looks like this:
```json
{
"query":"\nREPLACE INTO \"myWiki3\" OVERWRITE ALL\nSELECT\n TIME_PARSE(\"timestamp\") AS \"__time\",\n namespace,\n page,\n channel,\n \"user\",\n countryName,\n CASE WHEN isRobot = \\'true\\' THEN 1 ELSE 0 END AS isRobot,\n \"added\",\n \"delta\",\n CASE WHEN isNew = \\'true\\' THEN 1 ELSE 0 END AS isNew,\n CAST(\"deltaBucket\" AS DOUBLE) AS deltaBucket,\n \"deleted\"\nFROM TABLE(ext.wikiSample(\n uris => ?\n))\nPARTITIONED BY DAY\n",
"parameters":[
[
"wikipedia.json.gz"
]
],
"resultFormat":"object"
}
```
The key thing to notice is the SQL:
```sql
FROM TABLE(ext.wikiSample(
uris => ARRAY['wikipedia.json.gz']
))
```
And the parameter value: a list of strings. The task here is to get this to work in the Broker, where we've added code. However, debugging suggests that the request does not get past the broker which reports an error:
```json
{
"error":"Unknown exception",
"errorMessage":"Cannot deserialize instance of `org.apache.druid.sql.http.SqlParameter` out of START_ARRAY token\n at [Source: (org.eclipse.jetty.server.HttpInputOverHTTP); line: 1, column: 463] (through reference chain: org.apache.druid.sql.http.SqlQuery[\"parameters\"]->java.util.ArrayList[0])",
"errorClass":"com.fasterxml.jackson.databind.exc.MismatchedInputException",
"host":"None"
}
```
Clearly, something has gone wrong. This is a "developer error" not a "user error". We need to track down the issue. But, notice that there is no stack trace in the returned error. And, the point of this ticket, _there is no log file entry_. That is, if I go the router log file, I see no entry for the above error. As a result, it is very difficult to track down what is going wrong other than to guess from the error message.
The request is to log any time that the Router fails to forward a SQL query.
The error is that the `parameters` field is a list of (name, type) pairs, but I provided just the value. So, a second request is to provide a better error message, such as "Incorrect parameter format. See SqlQuery docs" or "... Parameters must be name/value maps."
A third point would be: why is the router deserializing the query request? Why isn't it a simple pass-through? And, if we must deserialize, why are we not using the same code that the Broker uses? The Broker is able to deserialize the above.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For additional commands, e-mail: commits-help@druid.apache.org
[GitHub] [druid] yuanlihan commented on issue #13765: Router does not log failed query requests
Posted by "yuanlihan (via GitHub)" <gi...@apache.org>.
yuanlihan commented on issue #13765:
URL: https://github.com/apache/druid/issues/13765#issuecomment-1487985314
Got same error on 25.0.0 release. The API request http://router:8888/druid/v2/sql/task/enabled?capabilities from Router console page triggers this error. See below exception stack
```log
2023-03-29T05:32:52,936 WARN [qtp1944213376-89] org.apache.druid.server.AsyncQueryForwardingServlet - Exception parsing query
org.apache.druid.query.QueryInterruptedException: Cannot deserialize instance of `org.apache.druid.sql.http.SqlQuery` out of START_ARRAY token
at [Source: (org.eclipse.jetty.server.HttpInputOverHTTP); line: 1, column: 1]
at org.apache.druid.query.QueryInterruptedException.wrapIfNeeded(QueryInterruptedException.java:135) ~[druid-processing-25.0.0.jar:25.0.0]
at org.apache.druid.server.AsyncQueryForwardingServlet.handleQueryParseException(AsyncQueryForwardingServlet.java:364) ~[druid-services-25.0.0.jar:25.0.0]
at org.apache.druid.server.AsyncQueryForwardingServlet.service(AsyncQueryForwardingServlet.java:286) ~[druid-services-25.0.0.jar:25.0.0]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[javax.servlet-api-3.1.0.jar:3.1.0]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.server.security.PreResponseAuthorizationCheckFilter.doFilter(PreResponseAuthorizationCheckFilter.java:82) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.server.initialization.jetty.StandardResponseHeaderFilterHolder$StandardResponseHeaderFilter.doFilter(StandardResponseHeaderFilterHolder.java:161) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.server.security.AllowHttpMethodsResourceFilter.doFilter(AllowHttpMethodsResourceFilter.java:78) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.server.security.AllowOptionsResourceFilter.doFilter(AllowOptionsResourceFilter.java:75) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.security.basic.authentication.BasicHTTPAuthenticator$BasicHTTPAuthenticationFilter.doFilter(BasicHTTPAuthenticator.java:208) ~[?:?]
at org.apache.druid.server.security.AuthenticationWrappingFilter.doFilter(AuthenticationWrappingFilter.java:59) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.apache.druid.server.security.SecuritySanityCheckFilter.doFilter(SecuritySanityCheckFilter.java:77) ~[druid-server-25.0.0.jar:25.0.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) ~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize instance of `org.apache.druid.sql.http.SqlQuery` out of START_ARRAY token
at [Source: (org.eclipse.jetty.server.HttpInputOverHTTP); line: 1, column: 1]
at com.fasterxml.jackson.databind.exc.MismatchedInputException.from(MismatchedInputException.java:59) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.DeserializationContext.reportInputMismatch(DeserializationContext.java:1445) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.DeserializationContext.handleUnexpectedToken(DeserializationContext.java:1219) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.DeserializationContext.handleUnexpectedToken(DeserializationContext.java:1171) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeFromArray(BeanDeserializerBase.java:1465) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeOther(BeanDeserializer.java:185) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:161) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4218) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3251) ~[jackson-databind-2.10.5.1.jar:2.10.5.1]
at org.apache.druid.server.AsyncQueryForwardingServlet.service(AsyncQueryForwardingServlet.java:275) ~[druid-services-25.0.0.jar:25.0.0]
... 52 more
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@druid.apache.org
For additional commands, e-mail: commits-help@druid.apache.org