Failure during substitutions, skipping substitution phase

1

Question,
I’m seeing error during reflection build.

is this something we can ignore?

2018-01-16 13:57:23,597 [25a18abc-6688-5fbb-70bf-7f9a15bb8e00:foreman] INFO query.logger - {“queryId”:“25a18abc-6688-5fbb-70bf-7f9a15bb8e00”,“schema”:"",“queryText”:"[Get Server Meta]",“start”:1516139843597,“finish”:1516139843597,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“server metadata; direct”}
2018-01-16 13:57:23,952 [25a18abc-1047-1342-9309-aef429cb6000:foreman] INFO query.logger - {“queryId”:“25a18abc-1047-1342-9309-aef429cb6000”,“schema”:"",“queryText”:"[Get Catalogs] Catalog Filter: pattern: “%”\nescape: “\\”\n.",“start”:1516139843948,“finish”:1516139843952,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“metadata; direct”}
2018-01-16 13:57:24,396 [25a18aba-ccaa-075f-75bf-4dda1313cd00:foreman] INFO c.d.e.p.a.s.DremioSubstitutionProvider - Failure during substitutions, skipping substitution phase.
java.lang.IllegalArgumentException: out of bounds: {2, 3, 5, 6, 9, 10, 11, 13, 14, 15, 16, 17, 19, 20, 21, 22, 23}
at org.apache.calcite.tools.RelBuilder.groupKey(RelBuilder.java:671) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.reflection.rules.AggregateProjectToJoinTransposeRule.onMatch(AggregateProjectToJoinTransposeRule.java:200) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.plan.AbstractRelOptPlanner.fireRule(AbstractRelOptPlanner.java:314) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.applyRule(HepPlanner.java:502) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.applyRules(HepPlanner.java:380) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.executeInstruction(HepPlanner.java:275) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepInstruction$RuleCollection.execute(HepInstruction.java:72) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.executeProgram(HepPlanner.java:206) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.findBestExp(HepPlanner.java:193) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.acceleration.normalization.RuleAndShuttleNormalizer.normalize(RuleAndShuttleNormalizer.java:67) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.normalization.ChainedNormalizer.normalize(ChainedNormalizer.java:41) ~[dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.DremioSubstitutionProvider.normalizeQuery(DremioSubstitutionProvider.java:329) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.DremioSubstitutionProvider.findSubstitutions(DremioSubstitutionProvider.java:134) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.AccelerationAwareSubstitutionProvider.findSubstitutions(AccelerationAwareSubstitutionProvider.java:61) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.DremioVolcanoPlanner.useApplicableMaterializations(DremioVolcanoPlanner.java:59) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:754) [calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.DremioVolcanoPlanner.findBestExp(DremioVolcanoPlanner.java:75) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.tools.Programs$RuleSetProgram.run(Programs.java:339) [calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.transform(PrelTransformer.java:392) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.convertToDrel(PrelTransformer.java:203) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.convertToDrel(PrelTransformer.java:249) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.query.NormalHandler.getPlan(NormalHandler.java:47) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.commands.HandlerToPreparePlan.plan(HandlerToPreparePlan.java:86) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.work.foreman.AttemptManager.run(AttemptManager.java:311) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
2018-01-16 13:57:24,773 [25a18aba-ccaa-075f-75bf-4dda1313cd00:foreman] INFO query.logger - {“queryId”:“25a18aba-ccaa-075f-75bf-4dda1313cd00”,“schema”:"",“queryText”:"[Prepare Statement] SELECT *\nFROM “Workspace”.“Clickstream_Analytic”",“start”:1516139844360,“finish”:1516139844773,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“prepare; query”}
2018-01-16 13:57:25,546 [25a18aba-5f2d-f33a-2fc0-12fc5b62f500:foreman] INFO query.logger - {“queryId”:“25a18aba-5f2d-f33a-2fc0-12fc5b62f500”,“schema”:"",“queryText”:"[Get Tables] Catalog Filter: pattern: “DREMIO”\nescape: “\\”\n, Schema Filter: pattern: “%”\nescape: “\\”\n, Table Filter pattern: “%”\nescape: “\\”\n.",“start”:1516139845313,“finish”:1516139845546,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“metadata; direct”}
2018-01-16 13:57:25,962 [25a18ab9-8f4f-0073-4017-74e4d7416300:foreman] INFO c.d.e.p.a.s.DremioSubstitutionProvider - Failure during substitutions, skipping substitution phase.
java.lang.IllegalArgumentException: out of bounds: {2, 3, 5, 6, 9, 10, 11, 13, 14, 15, 16, 17, 19, 20, 21, 22, 23}
at org.apache.calcite.tools.RelBuilder.groupKey(RelBuilder.java:671) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.reflection.rules.AggregateProjectToJoinTransposeRule.onMatch(AggregateProjectToJoinTransposeRule.java:200) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.plan.AbstractRelOptPlanner.fireRule(AbstractRelOptPlanner.java:314) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.applyRule(HepPlanner.java:502) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.applyRules(HepPlanner.java:380) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.executeInstruction(HepPlanner.java:275) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepInstruction$RuleCollection.execute(HepInstruction.java:72) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.executeProgram(HepPlanner.java:206) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at org.apache.calcite.plan.hep.HepPlanner.findBestExp(HepPlanner.java:193) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.acceleration.normalization.RuleAndShuttleNormalizer.normalize(RuleAndShuttleNormalizer.java:67) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.normalization.ChainedNormalizer.normalize(ChainedNormalizer.java:41) ~[dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.DremioSubstitutionProvider.normalizeQuery(DremioSubstitutionProvider.java:329) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.DremioSubstitutionProvider.findSubstitutions(DremioSubstitutionProvider.java:134) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.acceleration.substitution.AccelerationAwareSubstitutionProvider.findSubstitutions(AccelerationAwareSubstitutionProvider.java:61) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.DremioVolcanoPlanner.useApplicableMaterializations(DremioVolcanoPlanner.java:59) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:754) [calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.DremioVolcanoPlanner.findBestExp(DremioVolcanoPlanner.java:75) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at org.apache.calcite.tools.Programs$RuleSetProgram.run(Programs.java:339) [calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.transform(PrelTransformer.java:392) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.convertToDrel(PrelTransformer.java:203) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.PrelTransformer.convertToDrel(PrelTransformer.java:249) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.query.NormalHandler.getPlan(NormalHandler.java:47) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.planner.sql.handlers.commands.HandlerToPreparePlan.plan(HandlerToPreparePlan.java:86) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.exec.work.foreman.AttemptManager.run(AttemptManager.java:311) [dremio-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
2018-01-16 13:57:26,321 [25a18ab9-8f4f-0073-4017-74e4d7416300:foreman] INFO query.logger - {“queryId”:“25a18ab9-8f4f-0073-4017-74e4d7416300”,“schema”:"",“queryText”:"[Prepare Statement] SELECT “Clickstream_Analytic”.“Category” AS “Category”,\n SUM( “Clickstream_Analytic”.“Count_cookieid”) AS “sum_Count_cookieid_ok”\nFROM “Workspace”.“Clickstream_Analytic” “Clickstream_Analytic”\nGROUP BY “Clickstream_Analytic”.“Category”",“start”:1516139845926,“finish”:1516139846321,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“prepare; query”}
2018-01-16 13:57:27,921 [FABRIC-rpc-event-queue] INFO query.logger - {“queryId”:“25a18ab8-f9f6-0f39-e14b-46351cd49400”,“schema”:"",“queryText”:“SELECT “Clickstream_Analytic”.“Category” AS “Category”,\n SUM( “Clickstream_Analytic”.“Count_cookieid”) AS “sum_Count_cookieid_ok”\nFROM “Workspace”.“Clickstream_Analytic” “Clickstream_Analytic”\nGROUP BY “Clickstream_Analytic”.“Category””,“start”:1516139846672,“finish”:1516139847921,“outcome”:“COMPLETED”,“username”:“dremio”,“commandDescription”:“execute; query”}
2018-01-16 14:08:57,640 [qtp2047583728-801] WARN c.d.d.s.admin.profile.ProfileWrapper - Failed to deserialize acceleration details
java.lang.NullPointerException: null
at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:210) ~[guava-18.0.jar:na]
at com.google.common.collect.FluentIterable.(FluentIterable.java:84) ~[guava-18.0.jar:na]
at com.google.common.collect.FluentIterable$1.(FluentIterable.java:93) ~[guava-18.0.jar:na]
at com.google.common.collect.FluentIterable.from(FluentIterable.java:92) ~[guava-18.0.jar:na]
at com.dremio.dac.server.admin.profile.AccelerationWrapper.computeRelationships(AccelerationWrapper.java:41) ~[dremio-dac-backend-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.dac.server.admin.profile.AccelerationWrapper.(AccelerationWrapper.java:37) ~[dremio-dac-backend-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.dac.server.admin.profile.ProfileWrapper.(ProfileWrapper.java:105) ~[dremio-dac-backend-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.dac.admin.ProfileResource.renderProfile(ProfileResource.java:129) [dremio-dac-backend-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at com.dremio.dac.admin.ProfileResource.getProfile(ProfileResource.java:118) [dremio-dac-backend-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_151]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_151]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_151]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_151]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:205) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [jersey-common-2.25.1.jar:na]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [jersey-server-2.25.1.jar:na]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [jersey-container-servlet-core-2.25.1.jar:na]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [jersey-container-servlet-core-2.25.1.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [jersey-container-servlet-core-2.25.1.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [jersey-container-servlet-core-2.25.1.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [jersey-container-servlet-core-2.25.1.jar:na]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812) [jetty-servlet-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669) [jetty-servlet-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83) [jetty-servlets-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:365) [jetty-servlets-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) [jetty-servlet-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) [jetty-servlet-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:95) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.Server.handle(Server.java:499) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:258) [jetty-server-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544) [jetty-io-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) [jetty-util-9.2.22.v20170606.jar:9.2.22.v20170606]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) [jetty-util-9.2.22.v20170606.jar:9.2.22.v20170606]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
2018-01-16 14:11:07,188 [25a18784-3f1a-6617-ec83-3fe7e13f7600:foreman] INFO c.d.e.p.a.s.DremioSubstitutionProvider - Failure during substitutions, skipping substitution phase.
java.lang.IllegalArgumentException: out of bounds: {2, 3, 5, 6, 9, 10, 11, 13, 14, 15, 16, 17, 19, 20, 21, 22, 23}
at org.apache.calcite.tools.RelBuilder.groupKey(RelBuilder.java:671) ~[calcite-core-1.12.0-201711022309440460-bd4149e.jar:1.12.0-201711022309440460-bd4149e]
at com.dremio.reflection.rules.AggregateProjectToJoinTransposeRule.onMatch(AggregateProjectToJoinTransposeRule.java:200) ~[dremio-extra-sabot-kernel-1.3.1-201712020438070881-a7af5c8.jar:1.3.1-201712020438070881-a7af5c8]

2

Hey @rwidjaja, looks like the errors are happening at query time (not when building reflections) when Dremio is looking for suitable reflections to accelerate the query (internally we call this phase substitution).
Are you observing queries that should get accelerated fail to accelerate?

3

I supposed. and also when I turn on the reflection, it never gets build. with similar error.

4

Got it. Could you share the query profile for the failed job for the reflection?

5

2c221db1-4d32-4704-bedf-85ed62eb7737.zip (16.6 KB)

6

Hi,

This is actually known bug for which we already have a fix, and will be available in the next release.

1 Like
8

Doesn’t look like it is fixed - run the latest community version.

image
image919×420 17.1 KB

9

I have verified that the /accelerator/4077eb97-2e76-4f1d-b2a9-859b85b16b0b/116a0b75-21ca-4057-8f99-e9550c69bdb1_0 folder exits with correct permissions.

2020-08-02 20:19:36,261 [20d8e027-490d-d93d-5118-5a7376991a00/0:foreman-planning] ERROR o.a.calcite.runtime.CalciteException - org.apache.calcite.sql.validate.SqlValidatorException: Table ‘__accelerator.4077eb97-2e76-4f1d-b2a9-859b85b16b0b.116a0b75-21ca-4057-8f99-e9550c69bdb1_0’ not found
2020-08-02 20:19:36,261 [20d8e027-490d-d93d-5118-5a7376991a00/0:foreman-planning] ERROR o.a.calcite.runtime.CalciteException - org.apache.calcite.runtime.CalciteContextException: From line 2, column 6 to line 2, column 20: Table ‘__accelerator.4077eb97-2e76-4f1d-b2a9-859b85b16b0b.116a0b75-21ca-4057-8f99-e9550c69bdb1_0’ not found
2020-08-02 20:19:36,262 [20d8e027-490d-d93d-5118-5a7376991a00/0:foreman-planning] ERROR c.d.s.commandpool.CommandWrapper - command 20d8e027-490d-d93d-5118-5a7376991a00/0:foreman-planning failed
com.dremio.common.exceptions.UserException: Table ‘__accelerator.4077eb97-2e76-4f1d-b2a9-859b85b16b0b.116a0b75-21ca-4057-8f99-e9550c69bdb1_0’ not found
at com.dremio.common.exceptions.UserException$Builder.build(UserException.java:802)
at com.dremio.exec.planner.sql.SqlExceptionHelper.coerceException(SqlExceptionHelper.java:114)
at com.dremio.exec.planner.sql.handlers.query.NormalHandler.getPlan(NormalHandler.java:60)
at com.dremio.exec.planner.sql.handlers.commands.HandlerToExec.plan(HandlerToExec.java:59)
at com.dremio.exec.work.foreman.AttemptManager.plan(AttemptManager.java:418)
at com.dremio.exec.work.foreman.AttemptManager.lambda$run$1(AttemptManager.java:327)
at com.dremio.service.commandpool.CommandWrapper.run(CommandWrapper.java:62)
at com.dremio.common.concurrent.ContextMigratingExecutorService.lambda$decorate$3(ContextMigratingExecutorService.java:192)
at com.dremio.common.concurrent.ContextMigratingExecutorService$ComparableRunnable.run(ContextMigratingExecutorService.java:174)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.calcite.runtime.CalciteContextException: From line 2, column 6 to line 2, column 20: Table ‘__accelerator.4077eb97-2e76-4f1d-b2a9-859b85b16b0b.116a0b75-21ca-4057-8f99-e9550c69bdb1_0’ not found
at sun.reflect.GeneratedConstructorAccessor253.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.apache.calcite.runtime.Resources$ExInstWithCause.ex(Resources.java:463)
at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:803)
at org.apache.calcite.sql.SqlUtil.newContextException(SqlUtil.java:788)
at org.apache.calcite.sql.validate.SqlValidatorImpl.newValidationError(SqlValidatorImpl.java:4470)
at org.apache.calcite.sql.validate.IdentifierNamespace.resolveImpl(IdentifierNamespace.java:104)

11

I have figured it out - on VDS reflection, something like this will give substitution error:

select * from foo where doo between high and low. If you swap between expression’s params like this:

select * from foo where doo between low and high, no substitution error. Works fine.

On PDS, its slightly different.

select * from foo where doo between high and low. Returns nothing. No substitution error.

select * from foo where doo between low and high. Works. No substitution error.

You can reproduce this on your end.

12

@desi, thanks for pointing this out. Can you provide a profile that shows the 2 scenarios (error and non-error). Also, what version of Dremio are you seeing this with?

13

This is the version - dremio-community-4.5.0-202006180205030236_1a5d28da_1.noarch.rpm

I think you can reproduce it easily using Sample dataset.

14

@desi

I see from your screenshot that the query is accelerated. Are you just concerned about the message?

15

Query was not accelerated, it says “query accelerated” on finding that reflection exists. On actually loading up reflections, on encountering an anomaly, it gives the substitution error. Please verify this from the code as well.

16

We have the same issue and the query is not accelerated. Spent a long time in PLANING phase, error message:

Substitution terminated after timeout of 30000 milliseconds.

After 1 minutes when we have the same query, it accelerated with the correct reflection.

17

@dli16

Are you having many reflections to match? Would you be able to send us the profile?

Thanks
Bali

18

Can you post your query here? Also can you go into the respective reflections folder that this query is using and check if the reflection is physically present or deleted? If you find that this query reflection folder is empty, then check all other reflections folders. If you find all reflections have disappeared, then follow this: Exception on 90% of queries