Upgrade from 0.13.0-incubating to 0.14.2-incubating

We are planning to upgrade our 0.13.0-incubating cluster to 0.14.2-incubating. We are doing rolling upgrades as suggested in this link: https://druid.apache.org/docs/latest/operations/rolling-updates.html.

We ran into an issue when a query is reporting an exception after historical nodes have been upgraded to 0.14.2-incubating. The exception is as follows.

2019-09-16T16:57:53,862 WARN [qtp90050962-128] org.apache.druid.sql.http.SqlResource - Failed to handle query: SqlQuery{query='SELECT count(*) FROM “test-2” ', resultFormat=OBJECT, header=false, context={}}

org.apache.calcite.tools.ValidationException: org.apache.calcite.runtime.CalciteContextException: From line 1, column 22 to line 1, column 36: Object ‘test-2’ not found

at org.apache.calcite.prepare.PlannerImpl.validate(PlannerImpl.java:190) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.druid.sql.calcite.planner.DruidPlanner.plan(DruidPlanner.java:124) ~[druid-sql-RC.0.13.9-rc.1.jar:?]

at org.apache.druid.sql.calcite.planner.DruidPlanner.plan(DruidPlanner.java:97) ~[druid-sql-RC.0.13.9-rc.1.jar:?]

at org.apache.druid.sql.http.SqlResource.doPost(SqlResource.java:96) [druid-sql-RC.0.13.9-rc.1.jar:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_202]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_202]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_202]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_202]

at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409) [jersey-server-1.19.3.jar:1.19.3]

at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409) [jersey-servlet-1.19.3.jar:1.19.3]

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558) [jersey-servlet-1.19.3.jar:1.19.3]

at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733) [jersey-servlet-1.19.3.jar:1.19.3]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api-3.1.0.jar:3.1.0]

at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:286) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:276) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:181) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:120) [guice-servlet-4.1.0.jar:?]

at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:135) [guice-servlet-4.1.0.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.apache.druid.server.security.PreResponseAuthorizationCheckFilter.doFilter(PreResponseAuthorizationCheckFilter.java:84) [druid-server-RC.0.13.9-rc.1.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.apache.druid.server.security.AllowOptionsResourceFilter.doFilter(AllowOptionsResourceFilter.java:76) [druid-server-RC.0.13.9-rc.1.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.apache.druid.server.security.AllowAllAuthenticator$1.doFilter(AllowAllAuthenticator.java:85) [druid-server-RC.0.13.9-rc.1.jar:?]

at org.apache.druid.server.security.AuthenticationWrappingFilter.doFilter(AuthenticationWrappingFilter.java:60) [druid-server-RC.0.13.9-rc.1.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.apache.druid.server.security.SecuritySanityCheckFilter.doFilter(SecuritySanityCheckFilter.java:88) [druid-server-RC.0.13.9-rc.1.jar:?]

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:724) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:61) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:169) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.Server.handle(Server.java:531) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:760) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:678) [jetty-util-9.4.10.v20180503.jar:9.4.10.v20180503]

at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202]

Caused by: org.apache.calcite.runtime.CalciteContextException: From line 1, column 22 to line 1, column 36: Object ‘test-2’ not found

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.8.0_202]

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:1.8.0_202]

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.8.0_202]

at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[?:1.8.0_202]

at org.apache.calcite.runtime.Resources$ExInstWithCause.ex(Resources.java:463) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:783) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:768) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.newValidationError(SqlValidatorImpl.java:4759) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.IdentifierNamespace.resolveImpl(IdentifierNamespace.java:172) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.IdentifierNamespace.validateImpl(IdentifierNamespace.java:177) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.AbstractNamespace.validate(AbstractNamespace.java:84) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateNamespace(SqlValidatorImpl.java:967) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateQuery(SqlValidatorImpl.java:943) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateFrom(SqlValidatorImpl.java:3029) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateFrom(SqlValidatorImpl.java:3014) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateSelect(SqlValidatorImpl.java:3273) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SelectNamespace.validateImpl(SelectNamespace.java:60) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.AbstractNamespace.validate(AbstractNamespace.java:84) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateNamespace(SqlValidatorImpl.java:967) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateQuery(SqlValidatorImpl.java:943) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlSelect.validate(SqlSelect.java:225) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateScopedExpression(SqlValidatorImpl.java:918) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validate(SqlValidatorImpl.java:628) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.prepare.PlannerImpl.validate(PlannerImpl.java:188) ~[calcite-core-1.17.0.jar:1.17.0]

… 68 more

Caused by: org.apache.calcite.sql.validate.SqlValidatorException: Object ‘test-2’ not found

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.8.0_202]

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:1.8.0_202]

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.8.0_202]

at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[?:1.8.0_202]

at org.apache.calcite.runtime.Resources$ExInstWithCause.ex(Resources.java:463) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.runtime.Resources$ExInst.ex(Resources.java:572) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:783) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:768) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.newValidationError(SqlValidatorImpl.java:4759) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.IdentifierNamespace.resolveImpl(IdentifierNamespace.java:172) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.IdentifierNamespace.validateImpl(IdentifierNamespace.java:177) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.AbstractNamespace.validate(AbstractNamespace.java:84) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateNamespace(SqlValidatorImpl.java:967) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateQuery(SqlValidatorImpl.java:943) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateFrom(SqlValidatorImpl.java:3029) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateFrom(SqlValidatorImpl.java:3014) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateSelect(SqlValidatorImpl.java:3273) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SelectNamespace.validateImpl(SelectNamespace.java:60) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.AbstractNamespace.validate(AbstractNamespace.java:84) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateNamespace(SqlValidatorImpl.java:967) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateQuery(SqlValidatorImpl.java:943) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.SqlSelect.validate(SqlSelect.java:225) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validateScopedExpression(SqlValidatorImpl.java:918) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.sql.validate.SqlValidatorImpl.validate(SqlValidatorImpl.java:628) ~[calcite-core-1.17.0.jar:1.17.0]

at org.apache.calcite.prepare.PlannerImpl.validate(PlannerImpl.java:188) ~[calcite-core-1.17.0.jar:1.17.0]

… 68 more

After some debugging, we suspect that this might be caused by us setting druid.announcer.type to http in 0.13.0-incubating in query nodes and coordinator nodes. We are testing by setting druid.announcer.type back to batch and then upgrading the cluster from 0.13.0-incubating to 0.14.2-incubating. We are curious whether anyone else has seen this before.

Thanks,

Joy

Hi Joy,

This seems to be an issue with case-sensitivity. The validator is looking for a table called “test-2”, In case if your table name is “Test-2” or some-other case sensitive combination you may get this error.

Could you double-check your data source name?

Thanks and Regards,

Vaibhav

Hi Vaibhav,

I am pretty sure that the table is named “test-2”, since it can be queries in our 0.13.0-incubating cluster before the upgrade. The problem we noticed that if we are running query nodes with 0.13, while historical, middlemanager, overlord nodes are running with 0.14, we didn’t find this line like below in the query logs:

2019-09-17T17:31:40,975 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[test-2] in 53 ms (97 segments queried, 0 segments left).

So we suspect that the query node running 0.13 might have trouble to talk to historical nodes running 0.14 to refresh the metadata.

However, if I switch druid.announcer.type back to batch on query nodes running 0.13, then I don’t see this problem. Just wondering whether this is a bug with druid.announcer.type=http.

Thanks,

Joy