Khurram Faraaz created DRILL-5573: ------------------------------------- Summary: Query profiles missing from Web UI and physical *.sys.drill file missing for query that was in CANCELLATION_REQUESTED state Key: DRILL-5573 URL: https://issues.apache.org/jira/browse/DRILL-5573 Project: Apache Drill Issue Type: Bug Components: Web Server Affects Versions: 1.11.0 Environment: 3 node CentOS cluster Reporter: Khurram Faraaz
A query that was in CANCELLATION_REQUESTED state after the Java concurrent program was terminated by issuing Ctrl-C from the command line. Next, stop and start Drillbits (Drill 1.11.0 commit id: d11aba2) on all nodes, and we see the below error message on Drill's Web UI, and we do not find the physical file <query-id>.sys.drill under drill-1.11.0/logs/profiles folder clush -a /opt/mapr/drill/drill-1.11.0/bin/drillbit.sh stop clush -a /opt/mapr/drill/drill-1.11.0/bin/drillbit.sh start http://<IPADDRESS>:8047/profiles/26c9073d-a8ff-17b0-5a86-34042bdfb494 { "errorMessage" : "VALIDATION ERROR: No profile with given query id '26c9073d-a8ff-17b0-5a86-34042bdfb494' exists. Please verify the query id.\n\n\n[Error Id: c8f1ed5c-d93f-42b7-840d-54a1ed8da132 ]" } Stack trace from drillbit.log from foreman node, for the above error id. {noformat} 2017-06-07 10:18:37,612 [main] INFO o.a.drill.exec.server.rest.WebServer - Setting up HTTP connector for web server 2017-06-07 10:18:38,601 [main] INFO o.apache.drill.exec.server.Drillbit - Startup completed (4149 ms). 2017-06-07 10:20:03,718 [qtp1575043618-89] INFO o.a.d.e.s.r.profile.ProfileResources - User Error Occurred: No profile with given query id '26c9073d-a8ff-17b0-5a86-34042bdfb494' exists. Please verify the query id. org.apache.drill.common.exceptions.UserException: VALIDATION ERROR: No profile with given query id '26c9073d-a8ff-17b0-5a86-34042bdfb494' exists. Please verify the query id. [Error Id: c8f1ed5c-d93f-42b7-840d-54a1ed8da132 ] at org.apache.drill.common.exceptions.UserException$Builder.build(UserException.java:544) ~[drill-common-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.server.rest.profile.ProfileResources.getQueryProfile(ProfileResources.java:288) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.server.rest.profile.ProfileResources.getProfile(ProfileResources.java:310) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_91] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_91] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_91] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_91] at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:171) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:387) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:331) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:103) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:269) [jersey-server-2.8.jar:na] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.8.jar:na] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.8.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.8.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.8.jar:na] at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.8.jar:na] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:297) [jersey-common-2.8.jar:na] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:252) [jersey-server-2.8.jar:na] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1023) [jersey-server-2.8.jar:na] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:372) [jersey-container-servlet-core-2.8.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:382) [jersey-container-servlet-core-2.8.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:345) [jersey-container-servlet-core-2.8.jar:na] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:220) [jersey-container-servlet-core-2.8.jar:na] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:738) [jetty-servlet-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:551) [jetty-servlet-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:219) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1111) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:478) [jetty-servlet-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1045) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.Server.handle(Server.java:462) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:279) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:232) [jetty-server-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:534) [jetty-io-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:607) [jetty-util-9.1.5.v20140505.jar:9.1.5.v20140505] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:536) [jetty-util-9.1.5.v20140505.jar:9.1.5.v20140505] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91] {noformat} Details related to the above query id (26c9073d-a8ff-17b0-5a86-34042bdfb494) from drillbit.log {noformat} ... ... 2017-06-06 18:47:57,149 [UserServer-1] INFO o.a.d.e.w.fragment.FragmentExecutor - 26c9073d-a8ff-17b0-5a86-34042bdfb494:0:0: State change requested RUNNING --> FAILED ... ... 2017-06-06 18:47:57,159 [26c9073d-a8ff-17b0-5a86-34042bdfb494:frag:0:0] INFO o.a.d.e.w.fragment.FragmentExecutor - 26c9073d-a8ff-17b0-5a86-34042bdfb494:0:0: State change requested FAILED --> FAILED ... ... 2017-06-06 18:47:57,238 [BitServer-5] INFO o.a.d.e.w.fragment.FragmentExecutor - 26c9073d-a8ff-17b0-5a86-34042bdfb494:0:0: State change requested FAILED --> CANCELLATION_REQUESTED 2017-06-06 18:47:57,238 [BitServer-5] WARN o.a.d.e.w.fragment.FragmentExecutor - 26c9073d-a8ff-17b0-5a86-34042bdfb494:0:0: Ignoring unexpected state transition FAILED --> CANCELLATION_REQUESTED ... 2017-06-07 10:18:19,006 [26c9073d-a8ff-17b0-5a86-34042bdfb494:frag:0:0] WARN o.a.drill.exec.ops.SendingAccountor - Interrupted while waiting for send complete. Continuing to wait. java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:998) ~[na:1.8.0_91] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304) ~[na:1.8.0_91] at java.util.concurrent.Semaphore.acquire(Semaphore.java:467) ~[na:1.8.0_91] at org.apache.drill.exec.ops.SendingAccountor.waitForSendComplete(SendingAccountor.java:48) ~[drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.ops.FragmentContext.waitForSendComplete(FragmentContext.java:486) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.physical.impl.BaseRootExec.close(BaseRootExec.java:134) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.physical.impl.ScreenCreator$ScreenRoot.close(ScreenCreator.java:141) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.work.fragment.FragmentExecutor.closeOutResources(FragmentExecutor.java:313) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.work.fragment.FragmentExecutor.cleanup(FragmentExecutor.java:155) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.exec.work.fragment.FragmentExecutor.run(FragmentExecutor.java:264) [drill-java-exec-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at org.apache.drill.common.SelfCleaningRunnable.run(SelfCleaningRunnable.java:38) [drill-common-1.11.0-SNAPSHOT.jar:1.11.0-SNAPSHOT] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_91] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_91] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91] ... ... Allocator(query:26c9073d-a8ff-17b0-5a86-34042bdfb494) 1048576/0/0/268435456 (res/actual/peak/limit) child allocators: 0 ledgers: 0 reservations: 0 ... 2017-06-07 10:20:03,718 [qtp1575043618-89] INFO o.a.d.e.s.r.profile.ProfileResources - User Error Occurred: No profile with given query id '26c9073d-a8ff-17b0-5a86-34042bdfb494' exists. Please verify the query id. org.apache.drill.common.exceptions.UserException: VALIDATION ERROR: No profile with given query id '26c9073d-a8ff-17b0-5a86-34042bdfb494' exists. Please verify the query id. {noformat} -- This message was sent by Atlassian JIRA (v6.3.15#6346)