[
https://issues.apache.org/jira/browse/DRILL-5573?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16170488#comment-16170488
]
Kunal Khatua commented on DRILL-5573:
-------------------------------------
[~khfaraaz] This might not be a bug. If the cancellation occurs before the
foreman is created , the file was never created. Did the query go past the
Starting phase before being issued a cancellation?
> 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.4.14#64029)
